[pulseaudio-discuss] No audio heard from loopback

Sriram Gopalan mgsram at gmail.com
Mon Sep 26 11:35:06 PDT 2011


Hello everybody,
We are facing an issue with loopback in pulse audio 0.9.22. We recently
ported pulseaudio to an ARM 11 based evaluation board and are running
pulseaudio in system mode. The application being targeted is
In-vehicle-Infotainment and the board has a Mono Mic ( 16-bit, 1 channel)
and a Stereo Speaker ( 2 channels, 16-bit, 44.1 Khz).

1) With gstreamer we are able to playback audio to the speakers using the
following command. pulseaudio promptly gets into action and plays the file
at 44.1 Khz without a glitch -
#gst-launch filesrc location=/home/test/songs/test.mp3 ! mad ! alsasink

2) When we do a capture with the mic using the command below, again it works
fine ( By default arecord and aplay use 8Khz, 8-bit mono channel for capture
and playback) -
#arecord test.wav
#aplay test.wav

3) However, when we attempt the followings, it does not work. We cannot hear
any audio, whereas the same works on my Ubuntu 10.10 desktop
#arecord | aplay
#gst-launch alsasrc ! alsasink
#pactl load-module module-loopback

With the first 2 commands, there is only silence. With the third option,
pulse audio dies after sometime with a floating point exception.

Based on some preliminary debugging using log traces, I could see that
pa_source_output_push is getting called and the chunk has some data.
Similarly for the sink input, i could see pa_sink_render_into being called
with some data. Beyond that I have no clue. Sincerely appreciate any
guidance to move forward.
1) Could it be an issue with resampling?
2) Should I dump the chunk to a file and analyze its contents?

Thanks & regards,
Sriram
P.S. Here is an excerpt from the log of the session.

root at ARM11EVB:~# pulseaudio --system -vvvvv &
root at ARM11EVB:~# W: main.c: Running in system mode, but --disallow-exit not
set!
D: alsa-sink.c: Probed mixer paths:
D: alsa-mixer.c: Path Set 0x56fb0, direction=1, probed=yes
D: alsa-mixer.c: Path analog-output (Analog Output), direction=1,
priority=99, probed=yes, supported=yes, has_mute=no, has_volume=no,
has_dB=no, min_volume=0, max_volume=0, min_dB0
I: sink.c: Created sink 0 "alsa_output.platform-soc-audio.0.analog-stereo"
with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: sink.c:     alsa.resolution_bits = "16"
I: sink.c:     device.api = "alsa"
I: sink.c:     device.class = "sound"
I: sink.c:     alsa.class = "generic"
I: sink.c:     alsa.subclass = "generic-mix"
I: sink.c:     alsa.name = ""
I: sink.c:     alsa.id = "Audio FDA001-0"
I: sink.c:     alsa.subdevice = "0"
I: sink.c:     alsa.subdevice_name = "subdevice #0"
I: sink.c:     alsa.device = "0"
I: sink.c:     alsa.card = "0"
I: sink.c:     alsa.card_name = "EVB2065_AUDIO"
I: sink.c:     alsa.long_card_name = "EVB2065_AUDIO (FDA001)"
I: sink.c:     device.bus_path = "platform-soc-audio.0"
I: sink.c:     sysfs.path = "/devices/platform/soc-audio.0/sound/card0"
I: sink.c:     device.string = "hw:0"
I: sink.c:     device.buffering.buffer_size = "130048"
I: sink.c:     device.buffering.fragment_size = "4064"
I: sink.c:     device.access_mode = "mmap+timer"
I: sink.c:     device.profile.name = "analog-stereo"
I: sink.c:     device.profile.description = "Analog Stereo"
I: sink.c:     device.description = "EVB2065_AUDIO Analog Stereo"
I: sink.c:     module-udev-detect.discovered = "1"
I: sink.c:     device.icon_name = "audio-card"
I: source.c: Created source 0
"alsa_output.platform-soc-audio.0.analog-stereo.monitor" with sample spec
s16le 2ch 44100Hz and channel map front-left,front-right
I: source.c:     device.description = "Monitor of EVB2065_AUDIO Analog
Stereo"
I: source.c:     device.class = "monitor"
I: source.c:     alsa.card = "0"
I: source.c:     alsa.card_name = "EVB2065_AUDIO"
I: source.c:     alsa.long_card_name = "EVB2065_AUDIO (FDA001)"
I: source.c:     device.bus_path = "platform-soc-audio.0"
I: source.c:     sysfs.path = "/devices/platform/soc-audio.0/sound/card0"
I: source.c:     device.string = "0"
I: source.c:     module-udev-detect.discovered = "1"
I: source.c:     device.icon_name = "audio-card"
I: alsa-sink.c: Using 32.0 fragments of size 4064 bytes (23.04ms), buffer
size is 130048 bytes (737.23ms)
I: alsa-sink.c: Time scheduling watermark is 20.00ms
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=31630
D: alsa-mixer.c: Activating path analog-output
D: alsa-mixer.c: Path analog-output (Analog Output), direction=1,
priority=99, probed=yes, supported=yes, has_mute=no, has_volume=no,
has_dB=no, min_volume=0, max_volume=0, min_dB0
I: alsa-sink.c: Driver does not support hardware volume control, falling
back to software volume control.
I: alsa-sink.c: Driver does not support hardware mute control, falling back
to software mute control.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 0 'EVB2065_AUDIO' device 0 subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 2
D: alsa-util.c:   rate         : 44100
D: alsa-util.c:   exact rate   : 44100 (44100/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 32512
D: alsa-util.c:   period_size  : 1016
D: alsa-util.c:   period_time  : 23038
D: alsa-util.c:   tstamp_mode  : ENABLE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 31630
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : 2130706432
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 2130706432
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0
D: alsa-sink.c: Thread starting up
D: core-util.c: SCHED_RR|SCHED_RESET_ON_FORK worked.
I: core-util.c: Successfully enabled SCHED_RR scheduling for thread, with
priority 5.
I: alsa-sink.c: Starting playback.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-util.c: Trying hw:0 with SND_PCM_NO_AUTO_FORMAT ...
D: alsa-util.c: Managed to open hw:0
D: alsa-util.c: Maximum hw buffer size is 4064 ms
D: alsa-util.c: Set buffer size first (to 32000 samples), period size second
(to 32000 samples).
I: alsa-util.c: Device hw:0 doesn't support 44100 Hz, changed to 16000 Hz.
I: alsa-source.c: Successfully opened device hw:0.
I: alsa-source.c: Selected mapping 'Analog Mono' (analog-mono).
I: alsa-source.c: Successfully enabled mmap() mode.
I: alsa-source.c: Successfully enabled timer-based scheduling mode.
I: alsa-mixer.c: Successfully attached to mixer 'hw:0'
D: alsa-mixer.c: Probing path 'analog-input'
D: alsa-mixer.c: Probe of element 'Capture' failed.
D: alsa-mixer.c: Probing path 'analog-input-microphone'
D: alsa-mixer.c: Probe of element 'Mic' failed.
D: alsa-mixer.c: Probing path 'analog-input-linein'
D: alsa-mixer.c: Probe of element 'Line' failed.
D: alsa-mixer.c: Probing path 'analog-input'
D: alsa-mixer.c: Probe of element 'Aux' failed.
D: alsa-source.c: Probed mixer paths:
D: alsa-mixer.c: Path Set 0x5d2e0, direction=2, probed=yes
I: source.c: Created source 1 "alsa_input.platform-soc-audio.0.analog-mono"
with sample spec s16le 1ch 16000Hz and channel map mono
I: source.c:     alsa.resolution_bits = "16"
I: source.c:     device.api = "alsa"
I: source.c:     device.class = "sound"
I: source.c:     alsa.class = "generic"
I: source.c:     alsa.subclass = "generic-mix"
I: source.c:     alsa.name = ""
I: source.c:     alsa.id = "Audio FDA001-0"
I: source.c:     alsa.subdevice = "0"
I: source.c:     alsa.subdevice_name = "subdevice #0"
I: source.c:     alsa.device = "0"
I: source.c:     alsa.card = "0"
I: source.c:     alsa.card_name = "EVB2065_AUDIO"
I: source.c:     alsa.long_card_name = "EVB2065_AUDIO (FDA001)"
I: source.c:     device.bus_path = "platform-soc-audio.0"
I: source.c:     sysfs.path = "/devices/platform/soc-audio.0/sound/card0"
I: source.c:     device.string = "hw:0"
I: source.c:     device.buffering.buffer_size = "64000"
I: source.c:     device.buffering.fragment_size = "4000"
I: source.c:     device.access_mode = "mmap+timer"
I: source.c:     device.profile.name = "analog-mono"
I: source.c:     device.profile.description = "Analog Mono"
I: source.c:     device.description = "EVB2065_AUDIO Analog Mono"
I: source.c:     module-udev-detect.discovered = "1"
I: source.c:     device.icon_name = "audio-card"
I: alsa-source.c: Using 16.0 fragments of size 4000 bytes (125.00ms), buffer
size is 64000 bytes (2000.00ms)
I: alsa-source.c: Time scheduling watermark is 20.00ms
D: alsa-source.c: hwbuf_unused=0
D: alsa-source.c: setting avail_min=31681
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 0 'EVB2065_AUDIO' device 0 subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : CAPTURE
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 1
D: alsa-util.c:   rate         : 16000
D: alsa-util.c:   exact rate   : 16000 (16000/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 32000
D: alsa-util.c:   period_size  : 2000
D: alsa-util.c:   period_time  : 125000
D: alsa-util.c:   tstamp_mode  : ENABLE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 31681
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : 2097152000
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 2097152000
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0
D: alsa-source.c: Thread starting up
D: core-util.c: SCHED_RR|SCHED_RESET_ON_FORK worked.
I: core-util.c: Successfully enabled SCHED_RR scheduling for thread, with
priority 5.
I: alsa-source.c: Starting capture.

root at ARM11EVB:~#
root at ARM11EVB:~#
root at ARM11EVB:~# pactl load-module module-loopback
I: client.c: Created 0 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 16, local 16
I: protocol-native.c: Got credentials: uid=0 gid=0 success=1
D: protocol-native.c: SHM possible: no
D: protocol-native.c: Negotiated SHM: no
D: module-stream-restore.c: Not restoring device for stream
sink-input-by-media-role:abstract, because already set to
'alsa_output.platform-soc-audio.0.analog-stereo'.
D: sink.c: Suspend cause of sink
alsa_output.platform-soc-audio.0.analog-stereo is 0x0000, resuming
I: alsa-sink.c: Trying resume...
D: alsa-util.c: Maximum hw buffer size is 737 ms
D: alsa-util.c: Set buffer size first (to 32512 samples), period size second
(to 1016 samples).
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=31630
I: alsa-sink.c: Resumed successfully...
I: alsa-sink.c: Starting playback.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: module-suspend-on-idle.c: Sink
alsa_output.platform-soc-audio.0.analog-stereo becomes idle, timeout in 5
seconds.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: module-suspend-on-idle.c: Sink
alsa_output.platform-soc-audio.0.analog-stereo becomes busy.
I: resampler.c: Resampler 'ffmpeg' cannot do variable rate, reverting to
resampler 'auto'.
I: resampler.c: Using resampler 'speex-float-3'
I: resampler.c: Using float32le as working format.
I: resampler.c: Choosing speex quality setting 3.
D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4,
prebuf=0, minreq=1 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432,
base=4, prebuf=0, minreq=4 maxrewind=0
I: sink-input.c: Created input 0 "Loopback of EVB2065_AUDIO Analog Mono" on
alsa_output.platform-soc-audio.0.analog-stereo with sample spec s16le 2ch
44100Hz and channel map frontt
I: sink-input.c:     media.name = "Loopback of EVB2065_AUDIO Analog Mono"
I: sink-input.c:     media.icon_name = "audio-card"
I: sink-input.c:     media.role = "abstract"
I: sink-input.c:     module-stream-restore.id =
"sink-input-by-media-role:abstract"
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: module-stream-restore.c: Not restoring device for stream
source-output-by-media-role:abstract, because already set
D: source.c: Suspend cause of source
alsa_input.platform-soc-audio.0.analog-mono is 0x0000, resuming
I: alsa-source.c: Trying resume...
D: alsa-util.c: Maximum hw buffer size is 4064 ms
D: alsa-util.c: Set buffer size first (to 32000 samples), period size second
(to 2000 samples).
D: alsa-source.c: hwbuf_unused=0
D: alsa-source.c: setting avail_min=31681
I: alsa-source.c: Resumed successfully...
I: alsa-source.c: Starting capture.
D: module-suspend-on-idle.c: Source
alsa_input.platform-soc-audio.0.analog-mono becomes idle, timeout in 5
seconds.
D: module-suspend-on-idle.c: Source
alsa_input.platform-soc-audio.0.analog-mono becomes busy.
D: resampler.c: Channel matrix:
D: resampler.c:        I00
D: resampler.c:     +------
D: resampler.c: O00 | 1.000
D: resampler.c: O01 | 1.000
I: remap.c: Using mono to stereo remapping
I: resampler.c: Using resampler 'ffmpeg'
I: resampler.c: Using s16le as working format.
D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=2,
prebuf=0, minreq=1 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432,
base=2, prebuf=0, minreq=2 maxrewind=0
I: source-output.c: Created output 0 "Loopback to EVB2065_AUDIO Analog
Stereo" on alsa_input.platform-soc-audio.0.analog-mono with sample spec
s16le 2ch 44100Hz and channel map frt
I: source-output.c:     media.name = "Loopback to EVB2065_AUDIO Analog
Stereo"
I: source-output.c:     media.icon_name = "audio-card"
I: source-output.c:     media.role = "abstract"
I: source-output.c:     module-stream-restore.id =
"source-output-by-media-role:abstract"
D: memblockq.c: memblockq requested: maxlength=16777216, tlength=16777216,
base=4, prebuf=0, minreq=0 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=16777216, tlength=16777216,
base=4, prebuf=0, minreq=4 maxrewind=0
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Latency set to 66.67ms
D: alsa-sink.c: hwbuf_unused=118292
D: alsa-sink.c: setting avail_min=31631
I: module-loopback.c: Max request changed
D: alsa-sink.c: Requesting rewind due to latency change.
I: module-loopback.c: Max request changed
D: alsa-sink.c: Requested to rewind 130048 bytes.
D: alsa-sink.c: Limited to 93216 bytes.
D: alsa-sink.c: before: 23304
D: alsa-sink.c: after: 23304
D: alsa-sink.c: Rewound 93216 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 93216 bytes on render memblockq.
D: source.c: Processing rewind...
D: core-subscribe.c: Dropped redundant event due to change event.
I: module-loopback.c: Skipping 0 bytes
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=747
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=747
I: alsa-source.c: Overrun!
I: alsa-source.c: Increasing wakeup watermark to 30.00 ms
I: alsa-source.c: Overrun!
I: alsa-source.c: Increasing wakeup watermark to 40.00 ms
D: module-loopback.c: Requesting rewind due to end of underrun.
D: module-loopback.c: Requesting rewind due to end of underrun.
D: module-loopback.c: Requesting rewind due to end of underrun.
D: core-subscribe.c: Dropped redundant event due to change event.
I: module.c: Loaded "module-loopback" (index: #13; argument: "").
13
root at ARM11EVB:~# I: module-loopback.c: Loopback overall latency is 0.00 ms +
962.74 ms + 0.00 ms = 962.74 ms
I: module-loopback.c: Should buffer 23512 bytes, buffered at minimum 64896
bytes
I: module-loopback.c: Old rate 44100 Hz, new rate 45134 Hz
I: module-loopback.c: Loopback overall latency is 0.00 ms + 905.24 ms + 0.00
ms = 905.24 ms
I: module-loopback.c: Should buffer 24064 bytes, buffered at minimum 88112
bytes
I: module-loopback.c: Old rate 45134 Hz, new rate 45701 Hz
D: alsa-source.c: Wakeup from ALSA!
I: alsa-source.c: Overrun!
I: alsa-source.c: Increasing wakeup watermark to 50.00 ms
D: module-loopback.c: Requesting rewind due to end of underrun.
D: core-subscribe.c: Dropped redundant event due to change event.
I: client.c: Freed 0 "pactl"
I: protocol-native.c: Connection died.
D: alsa-source.c: Wakeup from ALSA!
I: alsa-source.c: Increasing wakeup watermark to 56.62 ms
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 1.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 2.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 4.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 8.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 16.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 26.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 36.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 46.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
D: module-loopback.c: Requesting rewind due to end of underrun.
I: alsa-source.c: Increasing minimal latency to 56.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
I: alsa-source.c: Increasing minimal latency to 66.00 ms
D: alsa-source.c: latency set to 66.67ms
D: alsa-source.c: hwbuf_unused=61868
D: alsa-source.c: setting avail_min=161
I: alsa-source.c: Increasing minimal latency to 76.00 ms
D: alsa-source.c: latency set to 76.00ms
D: alsa-source.c: hwbuf_unused=61568
D: alsa-source.c: setting avail_min=311
I: alsa-source.c: Increasing wakeup watermark to 66.00 ms
I: alsa-source.c: Increasing minimal latency to 86.00 ms
D: alsa-source.c: latency set to 86.00ms
D: alsa-source.c: hwbuf_unused=61248
D: alsa-source.c: setting avail_min=321
I: alsa-source.c: Increasing wakeup watermark to 76.00 ms
I: alsa-source.c: Increasing minimal latency to 96.00 ms
D: alsa-source.c: latency set to 96.00ms
D: alsa-source.c: hwbuf_unused=60928
D: alsa-source.c: setting avail_min=321
I: alsa-source.c: Increasing wakeup watermark to 86.00 ms
I: alsa-source.c: Increasing minimal latency to 106.00 ms
D: alsa-source.c: latency set to 106.00ms
D: alsa-source.c: hwbuf_unused=60608
D: alsa-source.c: setting avail_min=321
I: alsa-source.c: Increasing wakeup watermark to 96.00 ms
I: alsa-source.c: Increasing minimal latency to 116.00 ms
D: alsa-source.c: latency set to 116.00ms
D: alsa-source.c: hwbuf_unused=60288
D: alsa-source.c: setting avail_min=321
I: alsa-sink.c: Increasing wakeup watermark to 30.00 ms
I: alsa-source.c: Increasing wakeup watermark to 106.00 ms
I: alsa-source.c: Increasing minimal latency to 126.00 ms
D: alsa-source.c: latency set to 126.00ms
D: alsa-source.c: hwbuf_unused=59968
D: alsa-source.c: setting avail_min=321

root at ARM11EVB:~#
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/pulseaudio-discuss/attachments/20110927/1b96b184/attachment-0001.htm>


More information about the pulseaudio-discuss mailing list