[pulseaudio-discuss] huge skype sound events delay

Mon Dec 17 13:47:20 PST 2012

W dniu 12.12.2012 07:21, Julian Sikorski pisze:
> W dniu 12.12.2012 06:11, Tanu Kaskinen pisze:
>> On Tue, 2012-12-11 at 21:07 +0100, Julian Sikorski wrote:
>>> Hi,
>>>
>>> I posted this on the skype community forums too, but I thought it might
>>> be wise to attack the problem on different fronts.
>>
>> This certainly sounds like a pulseaudio bug. It might be already fixed,
>> so if possible, could you try the latest git version or the 2.99.3
>> tarball (they are currently the same anyway)?
>>
> 
> I'm not sure how easy that would be. Given how basic element pulsaudio
> is, this might require me to rebuild half of the distribution.
> 
Actually I was wrong. I was able to install PA 2.99.3 package for
rawhide without pulling any extra dependencies except sbc. You were
right, the problem does not occur with 2.99.3:

I: [pulseaudio] sink-input.c: Trying to change sample rate
I: [pulseaudio] sink.c: Cannot update rate, monitor source is RUNNING
D: [pulseaudio] module-suspend-on-idle.c: Sink
alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy.
D: [pulseaudio] resampler.c: Channel matrix:
D: [pulseaudio] resampler.c:        I00
D: [pulseaudio] resampler.c:     +------
D: [pulseaudio] resampler.c: O00 | 1,000
D: [pulseaudio] resampler.c: O01 | 1,000
I: [pulseaudio] remap_sse.c: Using SSE mono to stereo remapping
I: [pulseaudio] resampler.c: Using resampler 'speex-float-3'
I: [pulseaudio] resampler.c: Using float32le as working format.
I: [pulseaudio] resampler.c: Choosing speex quality setting 3.
D: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432,
tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432,
tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
I: [pulseaudio] sink-input.c: Created input 16 "Event Sound" on
alsa_output.pci-0000_00_1b.0.analog-stereo with sample spec s16le 1ch
48000Hz and channel map mono
I: [pulseaudio] sink-input.c:     window.icon_name = "skype"
I: [pulseaudio] sink-input.c:     application.icon_name = "skype"
I: [pulseaudio] sink-input.c:     media.role = "event"
I: [pulseaudio] sink-input.c:     media.name = "Event Sound"
I: [pulseaudio] sink-input.c:     application.name = "Skype"
I: [pulseaudio] sink-input.c:     native-protocol.peer = "UNIX socket
client"
I: [pulseaudio] sink-input.c:     native-protocol.version = "27"
I: [pulseaudio] sink-input.c:     application.process.id = "9454"
I: [pulseaudio] sink-input.c:     application.process.user = "julas"
I: [pulseaudio] sink-input.c:     application.process.host = "snowball2"
I: [pulseaudio] sink-input.c:     application.process.binary = "skype"
I: [pulseaudio] sink-input.c:     application.language = "pl_PL.utf8"
I: [pulseaudio] sink-input.c:     window.x11.display = ":1"
I: [pulseaudio] sink-input.c:     application.process.machine_id =
"8be85244e4ccefd602ced279da6f6b15"
I: [pulseaudio] sink-input.c:     application.process.session_id = "11"
I: [pulseaudio] sink-input.c:     module-stream-restore.id =
"sink-input-by-media-role:event"
I: [pulseaudio] protocol-native.c: Requested tlength=20,02 ms,
minreq=20,00 ms
D: [pulseaudio] protocol-native.c: Adjust latency mode enabled,
configuring sink latency to half of overall latency.
D: [pulseaudio] protocol-native.c: Requested latency=0,00 ms, Received
latency=4,00 ms
D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304,
tlength=4224, base=2, prebuf=2306, minreq=1920 maxrewind=0
D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304,
tlength=4224, base=2, prebuf=2306, minreq=1920 maxrewind=0
I: [pulseaudio] protocol-native.c: Final latency 48,00 ms = 4,00 ms +
2*20,00 ms + 4,00 ms
D: [alsa-sink] alsa-sink.c: Latency set to 4,00ms
D: [alsa-sink] alsa-sink.c: hwbuf_unused=352096
D: [alsa-sink] alsa-sink.c: setting avail_min=88113
D: [alsa-sink] alsa-sink.c: Requesting rewind due to latency change.
D: [alsa-sink] alsa-sink.c: Requested volume: 0: 100% 1: 100%
D: [alsa-sink] alsa-sink.c:            in dB: 0: 0,00 dB 1: 0,00 dB
D: [alsa-sink] alsa-sink.c: Got hardware volume: 0: 100% 1: 100%
D: [alsa-sink] alsa-sink.c:               in dB: 0: 0,00 dB 1: 0,00 dB
D: [alsa-sink] alsa-sink.c: Calculated software volume: 0: 100% 1: 100%
(accurate-enough=yes)
D: [alsa-sink] alsa-sink.c:                      in dB: 0: 0,00 dB 1:
0,00 dB
D: [alsa-sink] sink.c: Volume not changing
D: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
D: [alsa-sink] alsa-sink.c: Limited to 2312 bytes.
D: [alsa-sink] alsa-sink.c: before: 578
D: [alsa-sink] alsa-sink.c: after: 578
D: [alsa-sink] alsa-sink.c: Rewound 2312 bytes.
D: [alsa-sink] sink.c: Processing rewind...
D: [alsa-sink] sink.c: latency = 1334
D: [alsa-sink] sink-input.c: Have to rewind 2312 bytes on render memblockq.
D: [alsa-sink] source.c: Processing rewind...
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream
added for object /org/pulseaudio/core1/playback_stream16
I: [pulseaudio] sink.c: Cannot update rate, monitor source is RUNNING
D: [alsa-sink] sink-input.c: Requesting rewind due to uncorking
D: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
D: [pulseaudio] module-suspend-on-idle.c: Sink
alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy.
D: [alsa-sink] alsa-sink.c: Limited to 128 bytes.
D: [alsa-sink] alsa-sink.c: before: 32
D: [alsa-sink] alsa-sink.c: after: 32
D: [alsa-sink] alsa-sink.c: Rewound 128 bytes.
D: [alsa-sink] sink.c: Processing rewind...
D: [alsa-sink] sink.c: latency = 1511
D: [alsa-sink] source.c: Processing rewind...
D: [alsa-sink] protocol-native.c: Requesting rewind due to end of underrun.
D: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
D: [alsa-sink] alsa-sink.c: Limited to 448 bytes.
D: [alsa-sink] alsa-sink.c: before: 112
D: [alsa-sink] alsa-sink.c: after: 112
D: [alsa-sink] alsa-sink.c: Rewound 448 bytes.
D: [alsa-sink] sink.c: Processing rewind...
D: [alsa-sink] sink.c: latency = 1196
D: [alsa-sink] sink-input.c: Have to rewind 448 bytes on render memblockq.
D: [alsa-sink] source.c: Processing rewind...
D: [alsa-sink] ratelimit.c: 1644 events suppressed
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-sink] memblock.c: Pool full
D: [alsa-source] memblock.c: Pool full
D: [alsa-sink] sink-input.c: Requesting rewind due to corking
D: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
D: [alsa-sink] alsa-sink.c: Limited to 288 bytes.
D: [alsa-sink] alsa-sink.c: before: 72
D: [alsa-sink] alsa-sink.c: after: 72
D: [alsa-sink] alsa-sink.c: Rewound 288 bytes.
D: [alsa-sink] sink.c: Processing rewind...
D: [alsa-sink] sink.c: latency = 1445
D: [alsa-sink] sink-input.c: Have to rewind 288 bytes on render memblockq.
D: [alsa-sink] sink-input.c: Have to rewind 158 bytes on implementor.
D: [alsa-sink] source.c: Processing rewind...
D: [alsa-sink] alsa-sink.c: Latency set to 20,00ms
D: [alsa-sink] alsa-sink.c: hwbuf_unused=349272
D: [alsa-sink] alsa-sink.c: setting avail_min=88025
D: [alsa-sink] alsa-sink.c: Requested volume: 0: 100% 1: 100%
D: [alsa-sink] alsa-sink.c:            in dB: 0: 0,00 dB 1: 0,00 dB
D: [alsa-sink] alsa-sink.c: Got hardware volume: 0: 100% 1: 100%
D: [alsa-sink] alsa-sink.c:               in dB: 0: 0,00 dB 1: 0,00 dB
D: [alsa-sink] alsa-sink.c: Calculated software volume: 0: 100% 1: 100%
(accurate-enough=yes)
D: [alsa-sink] alsa-sink.c:                      in dB: 0: 0,00 dB 1:
0,00 dB
D: [alsa-sink] sink.c: Volume not changing
D: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
D: [alsa-sink] alsa-sink.c: Limited to 288 bytes.
D: [alsa-sink] alsa-sink.c: before: 72
D: [alsa-sink] alsa-sink.c: after: 72
D: [alsa-sink] alsa-sink.c: Rewound 288 bytes.
D: [alsa-sink] sink.c: Processing rewind...
D: [alsa-sink] sink.c: latency = 939
D: [alsa-sink] source.c: Processing rewind...
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream
removed from object /org/pulseaudio/core1/playback_stream16
I: [pulseaudio] sink-input.c: Freeing input 16 "Event Sound"

Would it be possible to backport whatever fixed it to 2.x branch? It is
very unlikely distros would upgrade PA mid-release, and Fedora 18 is not
even out yet

Regards,
Julian