[pulseaudio-discuss] rewind and underrun issues on start of playback

xing wang wangxingchao2011 at gmail.com
Thu May 26 01:09:25 PDT 2011


Hi baeksan,

Accidently I see your post about Pulseaudio rewind issue, that's quite
same with mine.
The background is, with timer-based feature enabled, i use default
2000ms  of tsched_size, when playback begins
there's rewind operation because of application's request latency very
low,so the final buffer size will be a small value after calculation.
then there will be nearly 3 seconds before hear the real sound. Maybe
alsa is playing silence data or didnot start to playback operations.

>From your log i see the buffer_size/period_size is not too big, so do
you have try with a big tsched_size value(such as 2 second). if we
have same result, that's maybe Pulseaudio's bug about the rewind operations.

--xingchao




=====================================================================
>From baeksan at ccrma.stanford.edu  Sun May  1 00:38:34 2011
From: baeksan at ccrma.stanford.edu (Baek Chang)
Date: Sat, 30 Apr 2011 15:38:34 -0700
Subject: [pulseaudio-discuss] rewind and underrun issues on start of playback
Message-ID: <BANLkTikQ1U6dUZzikgFQGs0oFM2Mkc5ELA at mail.gmail.com>

Hi,

I'm seeing some issue with underruns/rewinds occurring on the beginning of
every sink input playback.
I see rewind requests on alsa sink of 9600 bytes.  The alsa driver is
configured with the following buffer sizes

I: sink.c:     device.buffering.buffer_size = "9600"
I: sink.c:     device.buffering.fragment_size = "4800"

So it seems like one buffer size is always being rewinded on the beginning
of playback.
Is there a way to prevent these rewinds/underruns when starting playback?
 after the stream has started, there is no issue with audio dropouts or
underruns, just on the beginning.

If i log the data that gets sent to alsa, from pulseaudio or in the alsa
driver, i do see the beginning being dropped as well.

please see attached logs using both tshed=0 and tsched=1.

any help with this?
thanks!

I: client.c: Created 0 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 19, local 19
I: protocol-native.c: Got credentials: uid=0 gid=0 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: no
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 "/usr/palm/sounds/notification.wav" on
pcm_output with sample spec s16le 2ch 44100Hz and channel map
front-left,front-right
I: sink-input.c:     media.format = "WAV (Microsoft)"
I: sink-input.c:     media.name = "/usr/palm/sounds/notification.wav"
I: sink-input.c:     application.name = "pacat"
I: sink-input.c:     native-protocol.peer = "UNIX socket client"
I: sink-input.c:     native-protocol.version = "19"
I: sink-input.c:     application.process.id = "4474"
I: sink-input.c:     application.process.user = "root"
I: sink-input.c:     application.process.host = "PalmDevice"
I: sink-input.c:     application.process.binary = "pacat"
I: sink-input.c:     application.language = "C"
I: sink-input.c:     application.process.machine_id = "PalmDevice"
I: protocol-native.c: Requested tlength=2000.00 ms, minreq=20.00 ms
D: protocol-native.c: Traditional mode enabled, modifying sink usec only for
compat with minreq.
D: memblockq.c: memblockq requested: maxlength=4194304, tlength=352800,
base=4, prebuf=349276, minreq=3528 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=4194304, tlength=352800,
base=4, prebuf=349276, minreq=3528 maxrewind=0
I: protocol-native.c: Final latency 2054.42 ms = 1960.00 ms + 2*20.00 ms +
54.42 ms
D: protocol-native.c: Requesting rewind due to end of underrun.
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9344 bytes.
D: alsa-sink.c: before: 2336
D: alsa-sink.c: after: 2336
D: alsa-sink.c: Rewound 9344 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 9344 bytes on render memblockq.
D: source.c: Processing rewind...
D: protocol-native.c: Underrun on '/usr/palm/sounds/notification.wav', 0
bytes in queue.
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9344 bytes.
D: alsa-sink.c: before: 2336
D: alsa-sink.c: after: 2336
D: alsa-sink.c: Rewound 9344 bytes.
D: sink.c: Processing rewind...
D: source.c: Processing rewind...
D: core.c: Hmm, no streams around, trying to vacuum.
I: sink-input.c: Freeing input 0 "/usr/palm/sounds/notification.wav"
I: client.c: Freed 0 "pacat"
I: protocol-native.c: Connection died.

-- 
-baeksanchang
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://tango.0pointer.de/pipermail/pulseaudio-discuss/attachments/20110430/97c1f9a4/attachment-0001.htm>
-------------- next part --------------
root at PalmDevice:/media/internal# pulseaudio -vvvv
D: core-rtclock.c: Timer slack is set to 50 us.
D: core-util.c: setpriority() worked.
I: core-util.c: Successfully gained nice level -4.
I: main.c: Found user 'pulse' (UID 31) and group 'pulse' (GID 31).
I: main.c: Successfully dropped root privileges.
I: main.c: This is PulseAudio 0.9.22
D: main.c: Compilation host: arm-none-linux-gnueabi
D: main.c: Compilation CFLAGS: -isystem
/home/reviewdaemon/projects/nova/oe/BUILD-topaz/staging/arm-none-linux-gnueabi/include
-fexpensive-optimizations -fomit-frame-pointer -frename-registers -O2
-fno-strict-aliasing -fno-inline-functions -O3 -g -Wimplicit -O3 -Wall
-W -Wextra -pipe -Wno-long-long -Winline -Wvla -Wno-overlength-strings
-Wunsafe-loop-optimizations -Wundef -Wformat=2 -Wlogical-op
-Wsign-compare -Wformat-security -Wmissing-include-dirs
-Wformat-nonliteral -Wold-style-definition -Wpointer-arith -Winit-self
-Wdeclaration-after-statement -Wfloat-equal -Wmissing-prototypes
-Wstrict-prototypes -Wredundant-decls -Wmissing-declarations
-Wmissing-noreturn -Wshadow -Wendif-labels -Wcast-align
-Wstrict-aliasing=2 -Wwrite-strings -Wno-unused-parameter -ffast-math
-Wp,-D_FORTIFY_SOURCE=2 -fno-common -fdiagnostics-show-option
D: main.c: Running on host: Linux armv7l 2.6.35-palm-tenderloin #98
SMP PREEMPT Sat Apr 30 12:46:55 PDT 2011
D: main.c: Found 2 CPUs.
I: main.c: Page size is 4096 bytes
D: main.c: Compiled with Valgrind support: yes
D: main.c: Running in valgrind mode: no
D: main.c: Running in VM: no
D: main.c: Optimized build: yes
D: main.c: All asserts enabled.
I: main.c: Machine ID is PalmDevice.
I: main.c: Using runtime directory /var/run/pulse.
I: main.c: Using state directory /var/lib/pulse.
I: main.c: Using modules directory /usr/lib/pulse-0.9.22/modules.
I: main.c: Running in system mode: yes
I: main.c: Fresh high-resolution timers available! Bon appetit!
D: memblock.c: Using shared memory pool with 256 slots of size 64.0
KiB each, total size is 16.0 MiB, maximum usable slot size is 65496
I: cpu-arm.c: CPU flags: V7 VFP EDSP NEON VFPV3
D: alsa-util.c: Trying hw:0 with SND_PCM_NO_AUTO_FORMAT ...
D: alsa-util.c: Managed to open hw:0
I: alsa-util.c: cannot disable ALSA period wakeups
D: alsa-util.c: Maximum hw buffer size is 54 ms
D: alsa-util.c: Set buffer size first (to 88200 samples), period size
second (to 88200 samples).
I: alsa-util.c: ALSA period wakeups were not disabled
I: alsa-sink.c: Successfully opened device hw:0.
I: alsa-sink.c: Successfully enabled mmap() mode.
I: alsa-sink.c: Successfully enabled timer-based scheduling mode.
I: sink.c: Created sink 0 "pcm_output" 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 = "AIF1 wm8994-aif1-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 = "msm-audio"
I: sink.c:     alsa.long_card_name = "msm-audio (WM8994)"
I: sink.c:     device.string = "hw:0"
I: sink.c:     device.buffering.buffer_size = "9600"
I: sink.c:     device.buffering.fragment_size = "4800"
I: sink.c:     device.access_mode = "mmap+timer"
I: sink.c:     device.description = "msm-audio"
I: sink.c:     device.icon_name = "audio-card"
I: source.c: Created source 0 "pcm_output.monitor" with sample spec
s16le 2ch 44100Hz and channel map front-left,front-right
I: source.c:     device.description = "Monitor of msm-audio"
I: source.c:     device.class = "monitor"
I: source.c:     device.icon_name = "audio-input-microphone"
I: alsa-sink.c: Using 2.0 fragments of size 4800 bytes (27.21ms),
buffer size is 9600 bytes (54.42ms)
I: alsa-sink.c: Time scheduling watermark is 20.00ms
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=1518
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 0 'msm-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  : 2400
D: alsa-util.c:   period_size  : 1200
D: alsa-util.c:   period_time  : 27210
D: alsa-util.c:   tstamp_mode  : ENABLE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 1518
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : 1258291200
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1258291200
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-sink.c: Cutting sleep time for the initial iterations by half.
I: module.c: Loaded "module-alsa-sink" (index: #0; argument:
"device=hw:0 sink_name=pcm_output fragment_size=4800 fragments=2
mmap=1 tsched=1 channels=2").
D: alsa-sink.c: Wakeup from ALSA!
I: module.c: Loaded "module-native-protocol-unix" (index: #1;
argument: "auth-group=jailusers").
I: main.c: Daemon startup complete.
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: ratelimit.c: 28 events suppressed
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!
D: alsa-sink.c: Wakeup from ALSA!

I: client.c: Created 0 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 19, local 19
I: protocol-native.c: Got credentials: uid=0 gid=0 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: no
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 "/usr/palm/sounds/notification.wav"
on pcm_output with sample spec s16le 2ch 44100Hz and channel map
front-left,front-right
I: sink-input.c:     media.format = "WAV (Microsoft)"
I: sink-input.c:     media.name = "/usr/palm/sounds/notification.wav"
I: sink-input.c:     application.name = "pacat"
I: sink-input.c:     native-protocol.peer = "UNIX socket client"
I: sink-input.c:     native-protocol.version = "19"
I: sink-input.c:     application.process.id = "4492"
I: sink-input.c:     application.process.user = "root"
I: sink-input.c:     application.process.host = "PalmDevice"
I: sink-input.c:     application.process.binary = "pacat"
I: sink-input.c:     application.language = "C"
I: sink-input.c:     application.process.machine_id = "PalmDevice"
I: protocol-native.c: Requested tlength=2000.00 ms, minreq=20.00 ms
D: protocol-native.c: Traditional mode enabled, modifying sink usec
only for compat with minreq.
D: memblockq.c: memblockq requested: maxlength=4194304,
tlength=352800, base=4, prebuf=349276, minreq=3528 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=4194304,
tlength=352800, base=4, prebuf=349276, minreq=3528 maxrewind=0
I: protocol-native.c: Final latency 2054.42 ms = 1960.00 ms + 2*20.00
ms + 54.42 ms
D: alsa-sink.c: Latency set to 54.42ms
D: alsa-sink.c: hwbuf_unused=4
D: alsa-sink.c: setting avail_min=1519
D: alsa-sink.c: Requesting rewind due to latency change.
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9344 bytes.
D: alsa-sink.c: before: 2336
D: alsa-sink.c: after: 2336
D: alsa-sink.c: Rewound 9344 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 9344 bytes on render memblockq.
D: source.c: Processing rewind...
D: protocol-native.c: Requesting rewind due to end of underrun.
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9340 bytes.
D: alsa-sink.c: before: 2335
D: alsa-sink.c: after: 2335
D: alsa-sink.c: Rewound 9340 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 9340 bytes on render memblockq.
D: source.c: Processing rewind...
I: alsa-sink.c: Increasing wakeup watermark to 30.00 ms
I: alsa-sink.c: Increasing wakeup watermark to 40.00 ms
D: protocol-native.c: Underrun on '/usr/palm/sounds/notification.wav',
0 bytes in queue.
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=636
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9340 bytes.
D: alsa-sink.c: before: 2335
D: alsa-sink.c: after: 2335
D: alsa-sink.c: Rewound 9340 bytes.
D: sink.c: Processing rewind...
D: source.c: Processing rewind...
D: core.c: Hmm, no streams around, trying to vacuum.
I: sink-input.c: Freeing input 0 "/usr/palm/sounds/notification.wav"
I: client.c: Freed 0 "pacat"
I: protocol-native.c: Connection died.
-------------- next part --------------
root at PalmDevice:/media/internal# pulseaudio -vvvv
D: core-rtclock.c: Timer slack is set to 50 us.
D: core-util.c: setpriority() worked.
I: core-util.c: Successfully gained nice level -4.
I: main.c: Found user 'pulse' (UID 31) and group 'pulse' (GID 31).
I: main.c: Successfully dropped root privileges.
I: main.c: This is PulseAudio 0.9.22
D: main.c: Compilation host: arm-none-linux-gnueabi
D: main.c: Compilation CFLAGS: -isystem
/home/reviewdaemon/projects/nova/oe/BUILD-topaz/staging/arm-none-linux-gnueabi/include
-fexpensive-optimizations -fomit-frame-pointer -frename-registers -O2
-fno-strict-aliasing -fno-inline-functions -O3 -g -Wimplicit -O3 -Wall
-W -Wextra -pipe -Wno-long-long -Winline -Wvla -Wno-overlength-strings
-Wunsafe-loop-optimizations -Wundef -Wformat=2 -Wlogical-op
-Wsign-compare -Wformat-security -Wmissing-include-dirs
-Wformat-nonliteral -Wold-style-definition -Wpointer-arith -Winit-self
-Wdeclaration-after-statement -Wfloat-equal -Wmissing-prototypes
-Wstrict-prototypes -Wredundant-decls -Wmissing-declarations
-Wmissing-noreturn -Wshadow -Wendif-labels -Wcast-align
-Wstrict-aliasing=2 -Wwrite-strings -Wno-unused-parameter -ffast-math
-Wp,-D_FORTIFY_SOURCE=2 -fno-common -fdiagnostics-show-option
D: main.c: Running on host: Linux armv7l 2.6.35-palm-tenderloin #98
SMP PREEMPT Sat Apr 30 12:46:55 PDT 2011
D: main.c: Found 2 CPUs.
I: main.c: Page size is 4096 bytes
D: main.c: Compiled with Valgrind support: yes
D: main.c: Running in valgrind mode: no
D: main.c: Running in VM: no
D: main.c: Optimized build: yes
D: main.c: All asserts enabled.
I: main.c: Machine ID is PalmDevice.
I: main.c: Using runtime directory /var/run/pulse.
I: main.c: Using state directory /var/lib/pulse.
I: main.c: Using modules directory /usr/lib/pulse-0.9.22/modules.
I: main.c: Running in system mode: yes
I: main.c: Fresh high-resolution timers available! Bon appetit!
D: memblock.c: Using shared memory pool with 256 slots of size 64.0
KiB each, total size is 16.0 MiB, maximum usable slot size is 65496
I: cpu-arm.c: CPU flags: V7 VFP EDSP NEON VFPV3
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 54 ms
D: alsa-util.c: Set buffer size first (to 2400 samples), period size
second (to 1200 samples).
I: alsa-sink.c: Successfully opened device hw:0.
I: alsa-sink.c: Successfully enabled mmap() mode.
I: sink.c: Created sink 0 "pcm_output" 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 = "AIF1 wm8994-aif1-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 = "msm-audio"
I: sink.c:     alsa.long_card_name = "msm-audio (WM8994)"
I: sink.c:     device.string = "hw:0"
I: sink.c:     device.buffering.buffer_size = "9600"
I: sink.c:     device.buffering.fragment_size = "4800"
I: sink.c:     device.access_mode = "mmap"
I: sink.c:     device.description = "msm-audio"
I: sink.c:     device.icon_name = "audio-card"
I: source.c: Created source 0 "pcm_output.monitor" with sample spec
s16le 2ch 44100Hz and channel map front-left,front-right
I: source.c:     device.description = "Monitor of msm-audio"
I: source.c:     device.class = "monitor"
I: source.c:     device.icon_name = "audio-input-microphone"
I: alsa-sink.c: Using 2.0 fragments of size 4800 bytes (27.21ms),
buffer size is 9600 bytes (54.42ms)
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=1
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 0 'msm-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  : 2400
D: alsa-util.c:   period_size  : 1200
D: alsa-util.c:   period_time  : 27210
D: alsa-util.c:   tstamp_mode  : ENABLE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 1200
D: alsa-util.c:   period_event : 1
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : 1258291200
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1258291200
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.
I: module.c: Loaded "module-alsa-sink" (index: #0; argument:
"device=hw:0 sink_name=pcm_output fragment_size=4800 fragments=2
mmap=1 tsched=0 channels=2").
I: module.c: Loaded "module-native-protocol-unix" (index: #1;
argument: "auth-group=jailusers").
I: main.c: Daemon startup complete.

I: client.c: Created 0 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 19, local 19
I: protocol-native.c: Got credentials: uid=0 gid=0 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: no
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 "/usr/palm/sounds/notification.wav"
on pcm_output with sample spec s16le 2ch 44100Hz and channel map
front-left,front-right
I: sink-input.c:     media.format = "WAV (Microsoft)"
I: sink-input.c:     media.name = "/usr/palm/sounds/notification.wav"
I: sink-input.c:     application.name = "pacat"
I: sink-input.c:     native-protocol.peer = "UNIX socket client"
I: sink-input.c:     native-protocol.version = "19"
I: sink-input.c:     application.process.id = "4474"
I: sink-input.c:     application.process.user = "root"
I: sink-input.c:     application.process.host = "PalmDevice"
I: sink-input.c:     application.process.binary = "pacat"
I: sink-input.c:     application.language = "C"
I: sink-input.c:     application.process.machine_id = "PalmDevice"
I: protocol-native.c: Requested tlength=2000.00 ms, minreq=20.00 ms
D: protocol-native.c: Traditional mode enabled, modifying sink usec
only for compat with minreq.
D: memblockq.c: memblockq requested: maxlength=4194304,
tlength=352800, base=4, prebuf=349276, minreq=3528 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=4194304,
tlength=352800, base=4, prebuf=349276, minreq=3528 maxrewind=0
I: protocol-native.c: Final latency 2054.42 ms = 1960.00 ms + 2*20.00
ms + 54.42 ms
D: protocol-native.c: Requesting rewind due to end of underrun.
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9344 bytes.
D: alsa-sink.c: before: 2336
D: alsa-sink.c: after: 2336
D: alsa-sink.c: Rewound 9344 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 9344 bytes on render memblockq.
D: source.c: Processing rewind...
D: protocol-native.c: Underrun on '/usr/palm/sounds/notification.wav',
0 bytes in queue.
D: alsa-sink.c: Requested to rewind 9600 bytes.
D: alsa-sink.c: Limited to 9344 bytes.
D: alsa-sink.c: before: 2336
D: alsa-sink.c: after: 2336
D: alsa-sink.c: Rewound 9344 bytes.
D: sink.c: Processing rewind...
D: source.c: Processing rewind...
D: core.c: Hmm, no streams around, trying to vacuum.
I: sink-input.c: Freeing input 0 "/usr/palm/sounds/notification.wav"
I: client.c: Freed 0 "pacat"
I: protocol-native.c: Connection died.

>From dmcgarrett at optonline.net  Sun May  1 07:42:00 2011
From: dmcgarrett at optonline.net (Doug)
Date: Sun, 01 May 2011 01:42:00 -0400
Subject: [pulseaudio-discuss] unsubscribe me please.
Message-ID: <4DBCF2A8.8000401 at optonline.net>


-- 
Blessed are the peacekeepers...for they shall be shot at from both
sides. --A. M. Greeley


>From tanuk at iki.fi  Sun May  1 09:22:20 2011
From: tanuk at iki.fi (Tanu Kaskinen)
Date: Sun, 01 May 2011 10:22:20 +0300
Subject: [pulseaudio-discuss] rewind and underrun issues on start of
 playback
In-Reply-To: <BANLkTikQ1U6dUZzikgFQGs0oFM2Mkc5ELA at mail.gmail.com>
References: <BANLkTikQ1U6dUZzikgFQGs0oFM2Mkc5ELA at mail.gmail.com>
Message-ID: <1304234540.26939.14.camel at jarl>

On Sat, 2011-04-30 at 15:38 -0700, Baek Chang wrote:
> Hi,
>
> I'm seeing some issue with underruns/rewinds occurring on the beginning of
> every sink input playback.
> I see rewind requests on alsa sink of 9600 bytes.  The alsa driver is
> configured with the following buffer sizes
>
> I: sink.c:     device.buffering.buffer_size = "9600"
> I: sink.c:     device.buffering.fragment_size = "4800"
>
> So it seems like one buffer size is always being rewinded on the beginning
> of playback.
> Is there a way to prevent these rewinds/underruns when starting playback?

Not to my knowledge, except by changing the code.

>  after the stream has started, there is no issue with audio dropouts or
> underruns, just on the beginning.
>
> If i log the data that gets sent to alsa, from pulseaudio or in the alsa
> driver, i do see the beginning being dropped as well.
>
> please see attached logs using both tshed=0 and tsched=1.
>
> any help with this?
> thanks!

Are there any real problems with this rewinding, like the beginning of
the stream disappearing, or an audible drop-out in the audio? The sink
buffer has to be always rewound when a new stream is created, because
initially the sink buffer contains silence. That silence has to be
overwritten with the stream data, so that there's no unnecessary latency
due to waiting for the silence to be played.

That said, the underrun seems strange, because it happens after the
"Requesting rewind due to end of underrun" message. I don't know the
code well enough to be sure that it indicates any error, though. If the
messages would be ordered the other way around, then it would make more
sense: first when the stream is created, the buffer doesn't have any
data, but when the prebuffering phase ends, then a rewind is requested
on the sink to allow the stream playback to start immediately.

I don't know if this was helpful at all...

-- 
Tanu


>From baeksan at ccrma.stanford.edu  Mon May  2 05:45:43 2011
From: baeksan at ccrma.stanford.edu (Baek Chang)
Date: Sun, 1 May 2011 20:45:43 -0700
Subject: [pulseaudio-discuss] rewind and underrun issues on start of
	playback
In-Reply-To: <1304234540.26939.14.camel at jarl>
References: <BANLkTikQ1U6dUZzikgFQGs0oFM2Mkc5ELA at mail.gmail.com>
	<1304234540.26939.14.camel at jarl>
Message-ID: <BANLkTimRiSN6p-yJmXi8HbOg-8Yjhk-RdA at mail.gmail.com>

I am hearing that very very short sounds, smaller than hw buffer size,
occasionally not heard.  The initial portion of audio is silenced.  If i
remove the rewind request from protocal-native.c, then the problem is
resolved, but other issues are there, audible glitches when doing volume
changes.

On Sun, May 1, 2011 at 12:22 AM, Tanu Kaskinen <tanuk at iki.fi> wrote:

> On Sat, 2011-04-30 at 15:38 -0700, Baek Chang wrote:
> > Hi,
> >
> > I'm seeing some issue with underruns/rewinds occurring on the beginning
> of
> > every sink input playback.
> > I see rewind requests on alsa sink of 9600 bytes.  The alsa driver is
> > configured with the following buffer sizes
> >
> > I: sink.c:     device.buffering.buffer_size = "9600"
> > I: sink.c:     device.buffering.fragment_size = "4800"
> >
> > So it seems like one buffer size is always being rewinded on the
> beginning
> > of playback.
> > Is there a way to prevent these rewinds/underruns when starting playback?
>
> Not to my knowledge, except by changing the code.
>
> >  after the stream has started, there is no issue with audio dropouts or
> > underruns, just on the beginning.
> >
> > If i log the data that gets sent to alsa, from pulseaudio or in the alsa
> > driver, i do see the beginning being dropped as well.
> >
> > please see attached logs using both tshed=0 and tsched=1.
> >
> > any help with this?
> > thanks!
>
> Are there any real problems with this rewinding, like the beginning of
> the stream disappearing, or an audible drop-out in the audio? The sink
> buffer has to be always rewound when a new stream is created, because
> initially the sink buffer contains silence. That silence has to be
> overwritten with the stream data, so that there's no unnecessary latency
> due to waiting for the silence to be played.
>
> That said, the underrun seems strange, because it happens after the
> "Requesting rewind due to end of underrun" message. I don't know the
> code well enough to be sure that it indicates any error, though. If the
> messages would be ordered the other way around, then it would make more
> sense: first when the stream is created, the buffer doesn't have any
> data, but when the prebuffering phase ends, then a rewind is requested
> on the sink to allow the stream playback to start immediately.
>
> I don't know if this was helpful at all...
>
> --
> Tanu
>
> _______________________________________________
> pulseaudio-discuss mailing list
> pulseaudio-discuss at mail.0pointer.de
> https://tango.0pointer.de/mailman/listinfo/pulseaudio-discuss
>



-- 
-baeksanchang
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://tango.0pointer.de/pipermail/pulseaudio-discuss/attachments/20110501/da7986f0/attachment.htm>

>From baeksan at ccrma.stanford.edu  Mon May  2 05:52:03 2011
From: baeksan at ccrma.stanford.edu (Baek Chang)
Date: Sun, 1 May 2011 20:52:03 -0700
Subject: [pulseaudio-discuss] rewind and underrun issues on start of
	playback
In-Reply-To: <BANLkTimRiSN6p-yJmXi8HbOg-8Yjhk-RdA at mail.gmail.com>
References: <BANLkTikQ1U6dUZzikgFQGs0oFM2Mkc5ELA at mail.gmail.com>
	<1304234540.26939.14.camel at jarl>
	<BANLkTimRiSN6p-yJmXi8HbOg-8Yjhk-RdA at mail.gmail.com>
Message-ID: <BANLkTi=3A2hmDkcCUn9Abz95MppKafcCNQ at mail.gmail.com>

Also, if i revert to pulseaudio 0.9.14, i do not see this issue happening.
 I can hear the very short samples in the beginning fine.

On Sun, May 1, 2011 at 8:45 PM, Baek Chang <baeksan at ccrma.stanford.edu>wrote:

> I am hearing that very very short sounds, smaller than hw buffer size,
> occasionally not heard.  The initial portion of audio is silenced.  If i
> remove the rewind request from protocal-native.c, then the problem is
> resolved, but other issues are there, audible glitches when doing volume
> changes.
>
>
> On Sun, May 1, 2011 at 12:22 AM, Tanu Kaskinen <tanuk at iki.fi> wrote:
>
>> On Sat, 2011-04-30 at 15:38 -0700, Baek Chang wrote:
>> > Hi,
>> >
>> > I'm seeing some issue with underruns/rewinds occurring on the beginning
>> of
>> > every sink input playback.
>> > I see rewind requests on alsa sink of 9600 bytes.  The alsa driver is
>> > configured with the following buffer sizes
>> >
>> > I: sink.c:     device.buffering.buffer_size = "9600"
>> > I: sink.c:     device.buffering.fragment_size = "4800"
>> >
>> > So it seems like one buffer size is always being rewinded on the
>> beginning
>> > of playback.
>> > Is there a way to prevent these rewinds/underruns when starting
>> playback?
>>
>> Not to my knowledge, except by changing the code.
>>
>> >  after the stream has started, there is no issue with audio dropouts or
>> > underruns, just on the beginning.
>> >
>> > If i log the data that gets sent to alsa, from pulseaudio or in the alsa
>> > driver, i do see the beginning being dropped as well.
>> >
>> > please see attached logs using both tshed=0 and tsched=1.
>> >
>> > any help with this?
>> > thanks!
>>
>> Are there any real problems with this rewinding, like the beginning of
>> the stream disappearing, or an audible drop-out in the audio? The sink
>> buffer has to be always rewound when a new stream is created, because
>> initially the sink buffer contains silence. That silence has to be
>> overwritten with the stream data, so that there's no unnecessary latency
>> due to waiting for the silence to be played.
>>
>> That said, the underrun seems strange, because it happens after the
>> "Requesting rewind due to end of underrun" message. I don't know the
>> code well enough to be sure that it indicates any error, though. If the
>> messages would be ordered the other way around, then it would make more
>> sense: first when the stream is created, the buffer doesn't have any
>> data, but when the prebuffering phase ends, then a rewind is requested
>> on the sink to allow the stream playback to start immediately.
>>
>> I don't know if this was helpful at all...
>>
>> --
>> Tanu
>>
>> _______________________________________________
>> pulseaudio-discuss mailing list
>> pulseaudio-discuss at mail.0pointer.de
>> https://tango.0pointer.de/mailman/listinfo/pulseaudio-discuss
>>
>
>
>
> --
> -baeksanchang
>



-- 
-baeksanchang



More information about the pulseaudio-discuss mailing list