| Summary: | severe underruns with usb audio, works with pa 3.0 - buffer setup seems wrong | ||
|---|---|---|---|
| Product: | PulseAudio | Reporter: | David Mansfield <freedesktop-bugzilla> |
| Component: | core | Assignee: | pulseaudio-bugs |
| Status: | RESOLVED MOVED | QA Contact: | pulseaudio-bugs |
| Severity: | normal | ||
| Priority: | medium | CC: | adam, lennart, mickael9, mkj |
| Version: | unspecified | ||
| Hardware: | Other | ||
| OS: | All | ||
| Whiteboard: | |||
| i915 platform: | i915 features: | ||
| Attachments: |
log of running with PA 3.0 version from Centos 7
log of running with PA 5.0 version from Fedora 20 force tsched even in "BATCH" mode and on KVM. |
||
Created attachment 109437 [details]
log of running with PA 5.0 version from Fedora 20
Created attachment 109438 [details] [review] force tsched even in "BATCH" mode and on KVM. The attached patch fixes the problem by essentially reversing commit 826c8f69d34ef49e86fe0ab6c93c1ffba8916131 (alsa: Disable timer-scheduling for PCMs with the BATCH flag). Without tsched, the buffers are miniscule and we get overruns constantly. With tsched (by design) the buffers are huge. Not sure what the implications are. NOTE: I also forced enablement of tsched on KVM. I'm having the exact same problem in a VM, and it is MUCH better with the patch although still not "glitch-free" which it is (with the patch) on bare-metal. NOTE: In kvm I am using USB passthrough, not emulated hardware audio device. info_batch mean driver can only report hwptr at period boundary +I: [pulseaudio] alsa-sink.c: Using 4.0 fragments of size 4408 bytes (24.99ms), buffer size is 17632 bytes (99.95ms) this mean pulseaudio configure usb audio using fix latency at 4 * 24.99 ms by default pulseaudio should reject client requset any latency below 99.95ms [pulseaudio] sink-input.c: module-stream-restore.id = "sink-input-by-media-role:phone" I: [pulseaudio] protocol-native.c: Requested tlength=20.00 ms, minreq=4.99 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=5.01 ms, Received latency=99.95 ms D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304, tlength=9696, base=2, prebuf=9258, minreq=440 maxrewind=0 D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304, tlength=9696, base=2, prebuf=9258, minreq=440 maxrewind=0 underrun occur because requested length 20ms is less than fragment time 24.99ms timer scheduling require two hardware feateures report granularity in dma brust and disable period wakeup I: [pulseaudio] alsa-sink.c: Using 4.0 fragments of size 4408 bytes (24.99ms), buffer size is 17632 bytes (99.95ms) I: [pulseaudio] protocol-native.c: Requested tlength=20.00 ms, minreq=4.99 ms try paplay -v --latency-msec=100 any.wav Can someone "in the know" comment on what this part of the diff means: -D: [pulseaudio] alsa-sink.c: setting avail_min=87319 +D: [pulseaudio] alsa-sink.c: setting avail_min=1 As I understand, for glitch-free audio, the playback stream should only start when at least two buffers are full. Is this saying that it will start immediately? (1 byte?) Perhaps that is the issue. In my specific case, the audio data to "play" is coming from an RTP stream, and is therefore paced by some external network client, and perhaps the stream is being kicked off too soon, and/or not rebuffering correctly on underrun. How can I diagnose this further? The "paplay" example in comment#5 works with no underruns. So lets assume for a second that this is a bug in the application (jitsi, the VOIP client). Is there any way (env. variables or anything) to manipulate the buffering parameters without recompiling the code. Or a way with "pacmd" to manipulate the sink params while running? Also, I'm really curious about min_avail=1 - what does this mean ? http://git.alsa-project.org/?p=alsa-lib.git;a=commitdiff;h=b0b7d0280f977dee1bbff0a1b4cd0c50068d2371;hp=1cf37d72c4e77fac55f2b1792bdcf12744a5a51a @ -5577,6 +5577,12 @@ int snd_pcm_sw_params_set_avail_min(snd_pcm_t *pcm, snd_pcm_sw_params_t *params, #endif { assert(pcm && params); + /* Fix avail_min if it's below period size. The period_size + * defines the minimal wake-up timing accuracy, so it doesn't + * make sense to set below that. + */ + if (val < pcm->period_size) + val = pcm->period_size; params->avail_min = val; return 0; } seem any value below period size is changed to period size, the hw_ptr of most drivers change by a period when interrupt occur, not all driver can report dma_brust size granularity like snd-hda-intel controller , when data in FIFO below FIFO threshold and trigger DMA transfer , the hw_ptr position is accurate up to DMA brust size which is less than period size (pulseaudio use 4 fragments and 25 ms fragment time ) but dma brust size is about 32 frames you can change the fragments and fragment time in daemon.conf (In reply to David Mansfield from comment #7) > The "paplay" example in comment#5 works with no underruns. > did paplay still work when using latency lower than 100ms ? paplay -v --latency-msec=50 any.wav what is the lowest latency which paplay works with no underrun? pulseaudio] alsa-sink.c: setting avail_min=1 D: [pulseaudio] alsa-util.c: snd_pcm_dump(): D: [pulseaudio] alsa-util.c: Hardware PCM card 3 'Plantronics .Audio 648 USB' device 0 subdevice 0 D: [pulseaudio] alsa-util.c: Its setup is: D: [pulseaudio] alsa-util.c: stream : PLAYBACK D: [pulseaudio] alsa-util.c: access : MMAP_INTERLEAVED D: [pulseaudio] alsa-util.c: format : S16_LE D: [pulseaudio] alsa-util.c: subformat : STD D: [pulseaudio] alsa-util.c: channels : 2 D: [pulseaudio] alsa-util.c: rate : 44100 D: [pulseaudio] alsa-util.c: exact rate : 44100 (44100/1) D: [pulseaudio] alsa-util.c: msbits : 16 D: [pulseaudio] alsa-util.c: buffer_size : 4408 D: [pulseaudio] alsa-util.c: period_size : 1102 D: [pulseaudio] alsa-util.c: period_time : 24988 D: [pulseaudio] alsa-util.c: tstamp_mode : ENABLE D: [pulseaudio] alsa-util.c: period_step : 1 D: [pulseaudio] alsa-util.c: avail_min : 1102 D: [pulseaudio] alsa-util.c: period_event : 1 D: [pulseaudio] alsa-util.c: start_threshold : -1 D: [pulseaudio] alsa-util.c: stop_threshold : 4962966789362286592 D: [pulseaudio] alsa-util.c: silence_threshold: 0 D: [pulseaudio] alsa-util.c: silence_size : 0 D: [pulseaudio] alsa-util.c: boundary : 4962966789362286592 D: [pulseaudio] alsa-util.c: appl_ptr : 0 D: [pulseaudio] alsa-util.c: hw_ptr : 0 http://mailman.alsa-project.org/pipermail/alsa-devel/2014-September/081501.html you can try Alexander's pcm_avail.c to find out whether you usb audio sound card can report accurate hw_ptr position ? (In reply to David Mansfield from comment #2) > Created attachment 109438 [details] [review] [review] > force tsched even in "BATCH" mode and on KVM. > > The attached patch fixes the problem by essentially reversing commit > 826c8f69d34ef49e86fe0ab6c93c1ffba8916131 (alsa: Disable timer-scheduling for > PCMs with the BATCH flag). > > Without tsched, the buffers are miniscule and we get overruns constantly. > With tsched (by design) the buffers are huge. > > Not sure what the implications are. > > NOTE: I also forced enablement of tsched on KVM. I'm having the exact same > problem in a VM, and it is MUCH better with the patch although still not > "glitch-free" which it is (with the patch) on bare-metal. > > NOTE: In kvm I am using USB passthrough, not emulated hardware audio device. http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/src/modules/alsa/alsa-sink.c?id=53b046d5c9593d848270e85017c2999a61256e0e the patch was designed for those emulated sound card inside vm , this mean that you have to differentiate usb passthrough and emulated sound card (In reply to David Mansfield from comment #6) > Can someone "in the know" comment on what this part of the diff means: > > -D: [pulseaudio] alsa-sink.c: setting avail_min=87319 > +D: [pulseaudio] alsa-sink.c: setting avail_min=1 the major difference are two seconds buffer and 100 ms buffer [pulseaudio] alsa-sink.c: Using 2.0 fragments of size 176400 bytes (1000.00ms), buffer size is 352800 bytes (2000.00ms) I: [pulseaudio] alsa-sink.c: Time scheduling watermark is 20.00ms D: [pulseaudio] alsa-sink.c: hwbuf_unused=0 D: [pulseaudio] alsa-sink.c: setting avail_min=87319 http://mailman.alsa-project.org/pipermail/alsa-devel/2014-December/085207.html do you get similar result ? http://cgit.freedesktop.org/pulseaudio/pulseaudio/tree/src/pulsecore/rtpoll.c if you enabke DEBUG_TIMING in rtpoll.c do the pulseaudio log show process time euqal to 0 but slept time sometime greater than the fragment time ? I have built pulseaudio from git and also want to figure out how to use tsched with my USB devices. The 99.95ms fixed latency is horrible. The same quick hack (of not disabling tsched in BATCH mode) appears to work for me. Now I get "configured latency: 16.00 ms; range is 16.00 .. 743.04 ms". Note that if I use module-jack-sink I get a fixed latency of 2.67ms (as configured by jack), so the hardware can do much better than 16ms, just not directly from module-alsa-sink. What can we do to fix this? How accurate can you usb audio hw_ptr increase ? http://mailman.alsa-project.org/pipermail/alsa-devel/2014-September/081501.html you can try Alexander's pcm_avail.c Here is one of the USB devices: min_period_size: 48 frames, dir: 0 Playback hwparams: FIFO size is 0 Hardware PCM card 4 'USB Audio DAC' device 0 subdevice 0 Its setup is: stream : PLAYBACK access : RW_INTERLEAVED format : S16_LE subformat : STD channels : 2 rate : 48000 exact rate : 48000 (48000/1) msbits : 16 buffer_size : 4096 period_size : 1024 period_time : 21333 tstamp_mode : NONE tstamp_type : MONOTONIC period_step : 1 avail_min : 1024 period_event : 0 start_threshold : 1024 stop_threshold : 4096 silence_threshold: 0 silence_size : 0 boundary : 4611686018427387904 appl_ptr : 0 hw_ptr : 0 Playing silence Available: 0, loop iteration: 0 Available: 288, loop iteration: 34594 Available: 528, loop iteration: 42664 Available: 768, loop iteration: 50793 Available: 1056, loop iteration: 58969 Available: 1296, loop iteration: 65564 Available: 1536, loop iteration: 72406 Available: 1824, loop iteration: 81002 Available: 2064, loop iteration: 88159 Available: 2304, loop iteration: 95332 Available: 2592, loop iteration: 103934 Available: 2832, loop iteration: 111106 Available: 3072, loop iteration: 118338 Available: 3360, loop iteration: 126252 Available: 3600, loop iteration: 133532 Available: 3840, loop iteration: 140668 Here is the Scarlett 18i8 (I had to change the format to 32 bit and the channels to 8): min_period_size: 6 frames, dir: 0 Playback hwparams: FIFO size is 0 Hardware PCM card 3 'Scarlett 18i8 USB' device 0 subdevice 0 Its setup is: stream : PLAYBACK access : RW_INTERLEAVED format : S32_LE subformat : STD channels : 8 rate : 48000 exact rate : 48000 (48000/1) msbits : 32 buffer_size : 4096 period_size : 1024 period_time : 21333 tstamp_mode : NONE tstamp_type : MONOTONIC period_step : 1 avail_min : 1024 period_event : 0 start_threshold : 1024 stop_threshold : 4096 silence_threshold: 0 silence_size : 0 boundary : 4611686018427387904 appl_ptr : 0 hw_ptr : 0 Playing silence Available: 0, loop iteration: 0 Available: 240, loop iteration: 22750 Available: 460, loop iteration: 28976 Available: 680, loop iteration: 34986 Available: 901, loop iteration: 41240 Available: 1028, loop iteration: 47730 Available: 1232, loop iteration: 54658 Available: 1436, loop iteration: 60702 Available: 1640, loop iteration: 64736 Available: 1844, loop iteration: 71131 Available: 2048, loop iteration: 77716 Available: 2257, loop iteration: 84263 Available: 2461, loop iteration: 90799 Available: 2665, loop iteration: 97406 Available: 2869, loop iteration: 104008 Available: 3073, loop iteration: 110432 Available: 3277, loop iteration: 116537 Available: 3486, loop iteration: 123147 Available: 3690, loop iteration: 129559 Available: 3894, loop iteration: 136035 http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/src?id=f97faae006c0acbcd33056008196f3651fe5b0d3 if hw_ptr increment in (240 to 288 frames), you need to set a larger value of rewind safeguard ( about twice of your results ) (In reply to David Mansfield from comment #2) > Created attachment 109438 [details] [review] [review] > force tsched even in "BATCH" mode and on KVM. > > The attached patch fixes the problem by essentially reversing commit > 826c8f69d34ef49e86fe0ab6c93c1ffba8916131 (alsa: Disable timer-scheduling for > PCMs with the BATCH flag). > > Without tsched, the buffers are miniscule and we get overruns constantly. > With tsched (by design) the buffers are huge. > > Not sure what the implications are. > > NOTE: I also forced enablement of tsched on KVM. I'm having the exact same > problem in a VM, and it is MUCH better with the patch although still not > "glitch-free" which it is (with the patch) on bare-metal. > > NOTE: In kvm I am using USB passthrough, not emulated hardware audio device. those emulated ac97 or hda-intel does not work with timer scheduling so you have to post your patch in mailing list for review if those usb audio incement hwptr in interval of 5 or 6 ms , pulseaudio server have to reject client request latency less than 10ms instead of pretending support low latency you can try run pcm_avail.c with emulated ac97 or hda-intel inside kvm to find out the result which is larger than the period size 1024 , user still need to adjust default fragment * default period time to about 160ms Ideally, pulseaudio would dynamically monitor the increment of hw_ptr in the normal course of doing business and make the proper adjustments on an ongoing basis. Barring that, is there something we could add to the kernel that could be used to accurately report the true increment? https://git.kernel.org/cgit/linux/kernel/git/tiwai/sound.git/commit/sound/usb?id=976b6c064a957445eb0573b270f2d0282630e9b9 you need to ask the developers why you get 5ms and 6ms for your two usb audio devices (In reply to Adam Goode from comment #24) > Ideally, pulseaudio would dynamically monitor the increment of hw_ptr in the > normal course of doing business and make the proper adjustments on an > ongoing basis. because hda-intel can disable period interrupt, it need to wake up just before buffer is empty for power saving http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/src?id=826c8f69d34ef49e86fe0ab6c93c1ffba8916131 it is this patch disable timer scheduling , but your result indicate the granularity seem better than period size PCM Devices which have the BATCH flag set update the PCM pointer only with period size granularity. Using timer based scheduling does not have any advantage in this mode. For one devices which have that flag set usually update the position pointer in software after getting the period interrupt. https://git.kernel.org/cgit/linux/kernel/git/tiwai/sound.git/commit/sound/usb?id=49045d3d4dc7c43310b1fca693e29fcdbe68faba (In reply to Adam Goode from comment #24) > Ideally, pulseaudio would dynamically monitor the increment of hw_ptr in the > normal course of doing business and make the proper adjustments on an > ongoing basis. > do the result of two usb audio with pcm_available.c becom steady/constant when you modified it to use period time 20ms instead of period size 1024? the result may be different if add a constraint to limit the period time to multiple of 1ms intervals instead of allow application to select arbitrary period size I think I know what you would like me to do (something with snd_pcm_hw_params_set_period_time?). If you have code for me to run I will be able to get you these results soon, otherwise I have some other stuff to get to before working on this code. Thanks. (In reply to Adam Goode from comment #30) > I think I know what you would like me to do (something with > snd_pcm_hw_params_set_period_time?). > > If you have code for me to run I will be able to get you these results soon, > otherwise I have some other stuff to get to before working on this code. > Thanks. http://mailman.alsa-project.org/pipermail/alsa-devel/2015-June/093901.html you can try new version and follow up your case in the above thread http://mailman.alsa-project.org/pipermail/alsa-devel/2015-June/094032.html aplay with buffer time 2ms without xrun on his usb audio ======= testing hw:3 ======= min_period_size: 48 frames, dir: 0 FIFO size is 0 Hardware PCM card 3 'USB Audio DAC' device 0 subdevice 0 Its setup is: stream : PLAYBACK access : RW_INTERLEAVED format : S16_LE subformat : STD channels : 2 rate : 48000 exact rate : 48000 (48000/1) msbits : 16 buffer_size : 4096 period_size : 64 period_time : 1333 tstamp_mode : NONE tstamp_type : MONOTONIC period_step : 1 avail_min : 64 period_event : 0 start_threshold : 64 stop_threshold : 4096 silence_threshold: 0 silence_size : 0 boundary : 4611686018427387904 appl_ptr : 0 hw_ptr : 0 Playing silence Available: 0, loop iteration: 0, diff: 0, timestamp diff: 3 usec Available: 96, loop iteration: 4668, diff: 4668, timestamp diff: 2095 usec Available: 144, loop iteration: 5822, diff: 1154, timestamp diff: 1997 usec Available: 192, loop iteration: 6948, diff: 1126, timestamp diff: 2000 usec Available: 288, loop iteration: 8128, diff: 1180, timestamp diff: 2007 usec Available: 336, loop iteration: 9749, diff: 1621, timestamp diff: 1993 usec Available: 384, loop iteration: 11966, diff: 2217, timestamp diff: 2000 usec Available: 480, loop iteration: 14223, diff: 2257, timestamp diff: 2001 usec Available: 528, loop iteration: 16487, diff: 2264, timestamp diff: 1998 usec Available: 576, loop iteration: 18757, diff: 2270, timestamp diff: 1999 usec Available: 672, loop iteration: 21024, diff: 2267, timestamp diff: 2001 usec Available: 720, loop iteration: 22165, diff: 1141, timestamp diff: 1002 usec Available: 768, loop iteration: 23468, diff: 1303, timestamp diff: 996 usec Available: 864, loop iteration: 26200, diff: 2732, timestamp diff: 2001 usec Available: 912, loop iteration: 27544, diff: 1344, timestamp diff: 999 usec Available: 960, loop iteration: 28906, diff: 1362, timestamp diff: 1001 usec Available: 1056, loop iteration: 31621, diff: 2715, timestamp diff: 1999 usec Available: 1104, loop iteration: 32941, diff: 1320, timestamp diff: 1001 usec Available: 1152, loop iteration: 34289, diff: 1348, timestamp diff: 998 usec Available: 1248, loop iteration: 37017, diff: 2728, timestamp diff: 2000 usec Available: 1296, loop iteration: 38375, diff: 1358, timestamp diff: 1000 usec Available: 1344, loop iteration: 39762, diff: 1387, timestamp diff: 1000 usec Available: 1440, loop iteration: 42543, diff: 2781, timestamp diff: 2000 usec Available: 1488, loop iteration: 43929, diff: 1386, timestamp diff: 1000 usec Available: 1536, loop iteration: 45319, diff: 1390, timestamp diff: 1000 usec Available: 1632, loop iteration: 48078, diff: 2759, timestamp diff: 1999 usec Available: 1680, loop iteration: 49462, diff: 1384, timestamp diff: 1001 usec Available: 1728, loop iteration: 50850, diff: 1388, timestamp diff: 999 usec Available: 1824, loop iteration: 53593, diff: 2743, timestamp diff: 2000 usec Available: 1872, loop iteration: 54977, diff: 1384, timestamp diff: 1000 usec Available: 1920, loop iteration: 56330, diff: 1353, timestamp diff: 1001 usec Available: 2016, loop iteration: 59106, diff: 2776, timestamp diff: 2000 usec Available: 2064, loop iteration: 60488, diff: 1382, timestamp diff: 999 usec Available: 2112, loop iteration: 61875, diff: 1387, timestamp diff: 1001 usec Available: 2208, loop iteration: 64655, diff: 2780, timestamp diff: 1999 usec Available: 2256, loop iteration: 66044, diff: 1389, timestamp diff: 1000 usec Available: 2304, loop iteration: 67421, diff: 1377, timestamp diff: 1004 usec Available: 2400, loop iteration: 70057, diff: 2636, timestamp diff: 1998 usec Available: 2448, loop iteration: 71411, diff: 1354, timestamp diff: 1001 usec Available: 2496, loop iteration: 72768, diff: 1357, timestamp diff: 999 usec Available: 2592, loop iteration: 75473, diff: 2705, timestamp diff: 2000 usec Available: 2640, loop iteration: 76791, diff: 1318, timestamp diff: 999 usec Available: 2688, loop iteration: 78138, diff: 1347, timestamp diff: 1000 usec Available: 2784, loop iteration: 80900, diff: 2762, timestamp diff: 1999 usec Available: 2832, loop iteration: 82287, diff: 1387, timestamp diff: 1001 usec Available: 2880, loop iteration: 83676, diff: 1389, timestamp diff: 999 usec Available: 2976, loop iteration: 86399, diff: 2723, timestamp diff: 2000 usec Available: 3024, loop iteration: 87786, diff: 1387, timestamp diff: 1000 usec Available: 3072, loop iteration: 89174, diff: 1388, timestamp diff: 1000 usec Available: 3168, loop iteration: 91957, diff: 2783, timestamp diff: 2000 usec Available: 3216, loop iteration: 93329, diff: 1372, timestamp diff: 1003 usec Available: 3264, loop iteration: 94681, diff: 1352, timestamp diff: 997 usec Available: 3360, loop iteration: 97451, diff: 2770, timestamp diff: 2000 usec Available: 3408, loop iteration: 98817, diff: 1366, timestamp diff: 1000 usec Available: 3456, loop iteration: 100187, diff: 1370, timestamp diff: 1000 usec Available: 3552, loop iteration: 102926, diff: 2739, timestamp diff: 2000 usec Available: 3600, loop iteration: 104306, diff: 1380, timestamp diff: 1000 usec Available: 3648, loop iteration: 105690, diff: 1384, timestamp diff: 1000 usec Available: 3744, loop iteration: 108473, diff: 2783, timestamp diff: 2000 usec Available: 3792, loop iteration: 109865, diff: 1392, timestamp diff: 1002 usec Available: 3840, loop iteration: 111248, diff: 1383, timestamp diff: 1001 usec Available: 3936, loop iteration: 113968, diff: 2720, timestamp diff: 1999 usec Available: 3984, loop iteration: 115335, diff: 1367, timestamp diff: 1000 usec Available: 4032, loop iteration: 116693, diff: 1358, timestamp diff: 1000 usec ======= testing hw:1 ======= min_period_size: 6 frames, dir: 0 FIFO size is 0 Hardware PCM card 1 'Scarlett 18i8 USB' device 0 subdevice 0 Its setup is: stream : PLAYBACK access : RW_INTERLEAVED format : S32_LE subformat : STD channels : 8 rate : 48000 exact rate : 48000 (48000/1) msbits : 32 buffer_size : 4096 period_size : 64 period_time : 1333 tstamp_mode : NONE tstamp_type : MONOTONIC period_step : 1 avail_min : 64 period_event : 0 start_threshold : 64 stop_threshold : 4096 silence_threshold: 0 silence_size : 0 boundary : 4611686018427387904 appl_ptr : 0 hw_ptr : 0 Playing silence Available: 0, loop iteration: 0, diff: 0, timestamp diff: 3 usec Available: 66, loop iteration: 9066, diff: 9066, timestamp diff: 1395 usec Available: 132, loop iteration: 11289, diff: 2223, timestamp diff: 1622 usec Available: 192, loop iteration: 13351, diff: 2062, timestamp diff: 1625 usec Available: 258, loop iteration: 15600, diff: 2249, timestamp diff: 1625 usec Available: 325, loop iteration: 17822, diff: 2222, timestamp diff: 1625 usec Available: 385, loop iteration: 20092, diff: 2270, timestamp diff: 1626 usec Available: 451, loop iteration: 22045, diff: 1953, timestamp diff: 1625 usec Available: 512, loop iteration: 24239, diff: 2194, timestamp diff: 1630 usec Available: 578, loop iteration: 26305, diff: 2066, timestamp diff: 1619 usec Available: 644, loop iteration: 28447, diff: 2142, timestamp diff: 1626 usec Available: 705, loop iteration: 30674, diff: 2227, timestamp diff: 1625 usec Available: 771, loop iteration: 32561, diff: 1887, timestamp diff: 1374 usec Available: 832, loop iteration: 34626, diff: 2065, timestamp diff: 1500 usec Available: 898, loop iteration: 36533, diff: 1907, timestamp diff: 1376 usec Available: 964, loop iteration: 38592, diff: 2059, timestamp diff: 1499 usec Available: 1025, loop iteration: 40641, diff: 2049, timestamp diff: 1500 usec Available: 1091, loop iteration: 42522, diff: 1881, timestamp diff: 1375 usec Available: 1157, loop iteration: 44545, diff: 2023, timestamp diff: 1501 usec Available: 1218, loop iteration: 46425, diff: 1880, timestamp diff: 1376 usec Available: 1284, loop iteration: 48473, diff: 2048, timestamp diff: 1498 usec Available: 1344, loop iteration: 50540, diff: 2067, timestamp diff: 1501 usec Available: 1411, loop iteration: 52418, diff: 1878, timestamp diff: 1374 usec Available: 1477, loop iteration: 54499, diff: 2081, timestamp diff: 1501 usec Available: 1537, loop iteration: 56370, diff: 1871, timestamp diff: 1375 usec Available: 1603, loop iteration: 58444, diff: 2074, timestamp diff: 1498 usec Available: 1664, loop iteration: 60506, diff: 2062, timestamp diff: 1501 usec Available: 1730, loop iteration: 62391, diff: 1885, timestamp diff: 1375 usec Available: 1796, loop iteration: 64458, diff: 2067, timestamp diff: 1500 usec Available: 1857, loop iteration: 66513, diff: 2055, timestamp diff: 1500 usec Available: 1923, loop iteration: 68382, diff: 1869, timestamp diff: 1376 usec Available: 1984, loop iteration: 70456, diff: 2074, timestamp diff: 1507 usec Available: 2050, loop iteration: 72343, diff: 1887, timestamp diff: 1369 usec Available: 2116, loop iteration: 74410, diff: 2067, timestamp diff: 1499 usec Available: 2177, loop iteration: 76487, diff: 2077, timestamp diff: 1499 usec Available: 2243, loop iteration: 78392, diff: 1905, timestamp diff: 1375 usec Available: 2304, loop iteration: 80476, diff: 2084, timestamp diff: 1500 usec Available: 2370, loop iteration: 82365, diff: 1889, timestamp diff: 1375 usec Available: 2436, loop iteration: 84412, diff: 2047, timestamp diff: 1500 usec Available: 2496, loop iteration: 86473, diff: 2061, timestamp diff: 1500 usec Available: 2563, loop iteration: 88343, diff: 1870, timestamp diff: 1375 usec Available: 2629, loop iteration: 90401, diff: 2058, timestamp diff: 1501 usec Available: 2689, loop iteration: 92306, diff: 1905, timestamp diff: 1376 usec Available: 2756, loop iteration: 94387, diff: 2081, timestamp diff: 1498 usec Available: 2816, loop iteration: 96466, diff: 2079, timestamp diff: 1500 usec Available: 2882, loop iteration: 98327, diff: 1861, timestamp diff: 1376 usec Available: 2949, loop iteration: 100372, diff: 2045, timestamp diff: 1499 usec Available: 3009, loop iteration: 102248, diff: 1876, timestamp diff: 1376 usec Available: 3075, loop iteration: 104315, diff: 2067, timestamp diff: 1499 usec Available: 3136, loop iteration: 106383, diff: 2068, timestamp diff: 1500 usec Available: 3202, loop iteration: 108278, diff: 1895, timestamp diff: 1376 usec Available: 3268, loop iteration: 110311, diff: 2033, timestamp diff: 1498 usec Available: 3329, loop iteration: 112355, diff: 2044, timestamp diff: 1502 usec Available: 3395, loop iteration: 114259, diff: 1904, timestamp diff: 1374 usec Available: 3456, loop iteration: 116332, diff: 2073, timestamp diff: 1501 usec Available: 3522, loop iteration: 118177, diff: 1845, timestamp diff: 1374 usec Available: 3588, loop iteration: 120240, diff: 2063, timestamp diff: 1500 usec Available: 3649, loop iteration: 122303, diff: 2063, timestamp diff: 1500 usec Available: 3715, loop iteration: 124195, diff: 1892, timestamp diff: 1375 usec Available: 3781, loop iteration: 126258, diff: 2063, timestamp diff: 1500 usec Available: 3842, loop iteration: 128133, diff: 1875, timestamp diff: 1375 usec Available: 3908, loop iteration: 130199, diff: 2066, timestamp diff: 1501 usec Available: 3968, loop iteration: 132231, diff: 2032, timestamp diff: 1499 usec Available: 4034, loop iteration: 134139, diff: 1908, timestamp diff: 1375 usec https://bugs.freedesktop.org/show_bug.cgi?id=86262#c33 is this usb audio device a high speed/full speed device ? if application is allowed to select period time 1.33ms, the driver should ensure the number of packets lower or equal to period time, i.e. time diff should not be 2ms ,at leaset force the application to use more than two periods so that in average is still equal to 1.33ms https://bugs.freedesktop.org/show_bug.cgi?id=86262#c33 it is bug of driver to allow the application to select 1.33ms when all time diff are higher than period time as underrun always happen in this case I have the exact same problem with Jitsi + Pulseaudio + USB sound devices. I have tested with 3 different USB devices on different machines running Debian Jessie (comes with PA 6.0), and experience the same problems. Onboard soundcards works perfectly. However, I've tested with Ekiga + Pulseaudio + USB sound devices, and this setup doesnt seem to have underrun problems. According to Ekiga no packets gets dropped. Using USB devices, I do get slightly higher latency than using onboard sound card when talking to myself through Asterisk Echo() test. -- GitLab Migration Automatic Message -- This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity. You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/issues/62. |
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.
Created attachment 109436 [details] log of running with PA 3.0 version from Centos 7 Description of problem: Constant and severe audio underruns when using Jitsi (voip softphone). When using the pulseaudio 3.0 version from Centos 7 (rhel) audio is perfectly smooth. Version-Release number of selected component (if applicable): pulseaudio-5.0-7.fc20.x86_64 How reproducible: 100% Steps to Reproduce: 1. install jitsi, set up a sip account, use USB audio headset (e.g. plantronics) 2. make a call 3. audio (playback) is choppy and jitsi reports "discarded packets" Actual results: choppy audio, tons of underruns reported by PA Expected results: smooth audio Additional info: Installing the pulseaudio rpms from centos 7 "cures" the problem. I have run PA in debug mode and captured the log from the startup of PA through hanging up the call both with the 3.0 PA version (current C7) and 5.0 PA version (current F20). I'll attach the logs. Diffing the two logs (old (-) = 3.0, new (+) = 5.0), it looks like the significant difference in tho logs has to do with buffering setup (as expected): I: [pulseaudio] card.c: Created 1 "alsa_card.usb-Plantronics_Plantronics_.Audio_648_USB-00-USB" +I: [pulseaudio] module-card-restore.c: Storing profile and port latency offsets for card alsa_card.usb-Plantronics_Plantronics_.Audio_648_USB-00-USB. +D: [pulseaudio] module-alsa-card.c: Found 0 jacks. D: [pulseaudio] reserve-wrap.c: Successfully create reservation lock monitor for device 'Audio3' D: [pulseaudio] alsa-util.c: Trying front:3 with SND_PCM_NO_AUTO_FORMAT ... D: [pulseaudio] alsa-util.c: Managed to open front:3 -I: [pulseaudio] alsa-util.c: cannot disable ALSA period wakeups +I: [pulseaudio] alsa-util.c: Disabling tsched mode since BATCH flag is set D: [pulseaudio] alsa-util.c: Maximum hw buffer size is 5944 ms -D: [pulseaudio] alsa-util.c: Set buffer size first (to 88200 samples), period size second (to 88200 samples). -I: [pulseaudio] alsa-util.c: ALSA period wakeups were not disabled +D: [pulseaudio] alsa-util.c: Set buffer size first (to 4408 samples), period size second (to 1102 samples). I: [pulseaudio] alsa-sink.c: Successfully opened device front:3. I: [pulseaudio] alsa-sink.c: Selected mapping 'Analog Stereo' (analog-stereo). +I: [pulseaudio] alsa-sink.c: Cannot enable timer-based scheduling, falling back to sound IRQ scheduling. I: [pulseaudio] alsa-sink.c: Successfully enabled mmap() mode. -I: [pulseaudio] alsa-sink.c: Successfully enabled timer-based scheduling mode. I: [pulseaudio] (alsa-lib)control.c: Invalid CTL front:3 I: [pulseaudio] alsa-util.c: Unable to attach to mixer front:3: No such file or directory I: [pulseaudio] alsa-util.c: Successfully attached to mixer 'hw:3' @@ -1055,9 +1173,9 @@ I: [pulseaudio] sink.c: device.product.name = "Plantronics .Audio 648 USB" I: [pulseaudio] sink.c: device.serial = "Plantronics_Plantronics_.Audio_648_USB" I: [pulseaudio] sink.c: device.string = "front:3" -I: [pulseaudio] sink.c: device.buffering.buffer_size = "352800" -I: [pulseaudio] sink.c: device.buffering.fragment_size = "176400" -I: [pulseaudio] sink.c: device.access_mode = "mmap+timer" +I: [pulseaudio] sink.c: device.buffering.buffer_size = "17632" +I: [pulseaudio] sink.c: device.buffering.fragment_size = "4408" +I: [pulseaudio] sink.c: device.access_mode = "mmap" I: [pulseaudio] sink.c: device.profile.name = "analog-stereo" I: [pulseaudio] sink.c: device.profile.description = "Analog Stereo" I: [pulseaudio] sink.c: device.description = "Plantronics .Audio 648 USB Analog Stereo" @@ -1085,16 +1203,16 @@ I: [pulseaudio] source.c: device.string = "3" I: [pulseaudio] source.c: module-udev-detect.discovered = "1" I: [pulseaudio] source.c: device.icon_name = "audio-card-usb" -I: [pulseaudio] alsa-sink.c: Using 2.0 fragments of size 176400 bytes (1000.00ms), buffer size is 352800 bytes (2000.00ms) -I: [pulseaudio] alsa-sink.c: Time scheduling watermark is 20.00ms +I: [pulseaudio] alsa-sink.c: Using 4.0 fragments of size 4408 bytes (24.99ms), buffer size is 17632 bytes (99.95ms) D: [pulseaudio] alsa-sink.c: hwbuf_unused=0 -D: [pulseaudio] alsa-sink.c: setting avail_min=87319 +D: [pulseaudio] alsa-sink.c: setting avail_min=1 Also, theres this difference in realtime prio: -D: [alsa-sink] alsa-sink.c: Thread starting up -I: [alsa-sink] core-util.c: Failed to acquire real-time scheduling: Permission denied -I: [alsa-sink] alsa-sink.c: Starting playback. -D: [alsa-sink] alsa-sink.c: Cutting sleep time for the initial iterations by half. -D: [alsa-sink] alsa-sink.c: Cutting sleep time for the initial iterations by half. +D: [pulseaudio] alsa-sink.c: Read hardware volume: front-left: 34131 / 52% / -17.00 dB, front-right: 34131 / 52% / -17.00 dB +D: [alsa-sink-USB Audio] alsa-sink.c: Thread starting up +D: [alsa-sink-USB Audio] core-util.c: RealtimeKit worked. +I: [alsa-sink-USB Audio] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 5. +I: [alsa-sink-USB Audio] alsa-sink.c: Starting playback.