Bug 508999
| Summary: | pulseaudio loops on an alsa-sink error msg | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Guy Streeter <streeter> | ||||
| Component: | pulseaudio | Assignee: | Lennart Poettering <lpoetter> | ||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | low | ||||||
| Version: | 11 | CC: | awilliam, joachim.backes, lkundrak, louizatakk, lpoetter, ncrubel, nobody, ohreallyfool, wtogami | ||||
| Target Milestone: | --- | ||||||
| Target Release: | --- | ||||||
| Hardware: | All | ||||||
| OS: | Linux | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2009-10-23 19:17:27 UTC | Type: | --- | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Attachments: |
|
||||||
Any ideas on this? Anything else you need to know? I can't listen to music on this machine because pulseaudio hangs frequently. I am getting this same error message loop. It also comes on after a few minutes using any of the music players and all music formats. My sound info is here: http://www.alsa-project.org/db/?f=519998a2a4456353e8fad0dedce14500bc7a12b7 also, silly question, but I had wanted to post my pulseaudio -vvv as well but where IS the output written I tried "pulseaudio -vvv > log" and also looked in /etc I am getting the same. pulseuadio gets high cpu and found these messages in messages. Aug 12 23:15:57 nc3700amd pulseaudio[2075]: ratelimit.c: 2803 events suppressed Aug 12 23:15:57 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 50.00 ms Aug 12 23:16:02 nc3700amd pulseaudio[2075]: ratelimit.c: 9098 events suppressed Aug 12 23:16:03 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 60.00 ms Aug 12 23:16:03 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 70.00 ms Aug 12 23:16:07 nc3700amd pulseaudio[2075]: ratelimit.c: 7961 events suppressed Aug 12 23:16:10 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 80.00 ms Aug 12 23:16:17 nc3700amd pulseaudio[2075]: ratelimit.c: 4230 events suppressed Aug 12 23:16:17 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 90.00 ms Aug 12 23:16:22 nc3700amd pulseaudio[2075]: ratelimit.c: 8763 events suppressed Aug 12 23:16:23 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 100.00 ms Aug 12 23:16:42 nc3700amd pulseaudio[2075]: ratelimit.c: 1872 events suppressed Aug 12 23:16:47 nc3700amd pulseaudio[2075]: ratelimit.c: 9067 events suppressed Aug 12 23:16:48 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 110.00 ms Aug 12 23:17:02 nc3700amd kernel: usb 1-3: reset high speed USB device using ehci_hcd and address 2 Aug 12 23:19:09 nc3700amd pulseaudio[2075]: ratelimit.c: 1567 events suppressed Aug 12 23:19:09 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 120.00 ms Aug 12 23:19:14 nc3700amd pulseaudio[2075]: ratelimit.c: 8846 events suppressed Aug 12 23:19:15 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 130.00 ms Aug 12 23:20:31 nc3700amd pulseaudio[2075]: ratelimit.c: 1789 events suppressed Aug 12 23:20:31 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 140.00 ms Aug 12 23:20:36 nc3700amd pulseaudio[2075]: ratelimit.c: 6563 events suppressed Aug 12 23:20:38 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 150.00 ms Aug 12 23:20:39 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 160.00 ms Aug 12 23:20:41 nc3700amd pulseaudio[2075]: ratelimit.c: 8223 events suppressed Aug 12 23:20:45 nc3700amd pulseaudio[2075]: alsa-sink.c: Increasing wakeup watermark to 170.00 ms Aug 12 23:20:46 nc3700amd pulseaudio[2075]: ratelimit.c: 7309 events suppressed Aug 12 23:20:47 nc3700amd pulseaudio[2075]: cpulimit.c: Received request to terminate due to CPU overload. Can confirm similar behaviour during playing a DVD with totem (each time after about 1 min playing correctly) : suddenly the sound stops, getting high CPU load. After logging out an relogging in, the same behaviour. uname -r 2.6.29.6-217.2.8.fc11.i586 rpm -qa '*pulse*' pulseaudio-module-zeroconf-0.9.15-14.fc11.i586 xmms-pulse-0.9.4-7.fc11.i586 pulseaudio-module-gconf-0.9.15-14.fc11.i586 pulseaudio-module-bluetooth-0.9.15-14.fc11.i586 pulseaudio-0.9.15-14.fc11.i586 pulseaudio-module-jack-0.9.15-14.fc11.i586 xine-lib-pulseaudio-1.1.16.3-2.fc11.i586 pulseaudio-esound-compat-0.9.15-14.fc11.i586 alsa-plugins-pulseaudio-1.0.20-2.fc11.i586 pulseaudio-utils-0.9.15-14.fc11.i586 wine-pulseaudio-1.1.23-1.fc11.i586 pulseaudio-libs-glib2-0.9.15-14.fc11.i586 pulseaudio-libs-zeroconf-0.9.15-14.fc11.i586 pulseaudio-module-x11-0.9.15-14.fc11.i586 pulseaudio-libs-0.9.15-14.fc11.i586 akode-pulseaudio-2.0.2-5.fc9.i386 /var/log/messages: Aug 25 09:56:22 eule pulseaudio[2281]: alsa-sink.c: Increasing wakeup watermark to 30.00 ms Aug 25 09:57:02 eule pulseaudio[2281]: alsa-sink.c: Increasing wakeup watermark to 40.00 ms Aug 25 09:57:02 eule pulseaudio[2281]: alsa-sink.c: Increasing wakeup watermark to 50.00 ms Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 4294957568 bytes (22369570 ms). Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers. Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: snd_pcm_dump(): Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: Hardware PCM card 0 'NVidia nForce2' device 0 subdevice 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: Its setup is: Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: stream : PLAYBACK Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: access : MMAP_INTERLEAVED Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: format : S16_LE Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: subformat : STD Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: channels : 2 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: rate : 48000 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: exact rate : 48000 (48000/1) Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: msbits : 16 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: buffer_size : 16384 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_size : 16384 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_time : 341333 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: tstamp_mode : ENABLE Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_step : 1 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: avail_min : 16384 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_event : 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: start_threshold : -1 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: stop_threshold : 1073741824 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: silence_threshold: 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: silence_size : 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: boundary : 1073741824 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: appl_ptr : 1935776 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: hw_ptr : 1916960 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 417632 bytes (2175 ms). Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers. Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: snd_pcm_dump(): Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: Hardware PCM card 0 'NVidia nForce2' device 0 subdevice 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: Its setup is: Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: stream : PLAYBACK Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: access : MMAP_INTERLEAVED Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: format : S16_LE Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: subformat : STD Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: channels : 2 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: rate : 48000 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: exact rate : 48000 (48000/1) Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: msbits : 16 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: buffer_size : 16384 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_size : 16384 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_time : 341333 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: tstamp_mode : ENABLE Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_step : 1 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: avail_min : 16384 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: period_event : 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: start_threshold : -1 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: stop_threshold : 1073741824 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: silence_threshold: 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: silence_size : 0 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: boundary : 1073741824 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: appl_ptr : 2022176 Aug 25 09:57:02 eule pulseaudio[2281]: alsa-util.c: hw_ptr : 1917768 Aug 25 09:57:07 eule pulseaudio[2281]: ratelimit.c: 749 events suppressed Aug 25 09:57:12 eule pulseaudio[2281]: ratelimit.c: 701 events suppressed Aug 25 09:57:14 eule pulseaudio[2281]: alsa-sink.c: Increasing wakeup watermark Joachim, your issue is unrelated and a kernel bug that is tracked in bug 506075 (In reply to comment #5) > Joachim, your issue is unrelated and a kernel bug that is tracked in bug 506075 Thank you for clarification. I confirm, I have the exact same pulseaudio -vvv output, and the problem is the same (crackling after one or two minutes of listening music or watching a movie) I tried some downgrade : # rpm -qa | grep pulse pulseaudio-utils-0.9.15-14.fc11.x86_64 pulseaudio-libs-glib2-0.9.15-14.fc11.x86_64 pulseaudio-0.9.15-11.fc11.x86_64 xine-lib-pulseaudio-1.1.16.3-2.fc11.x86_64 alsa-plugins-pulseaudio-1.0.18-3.fc11.x86_64 pulseaudio-libs-0.9.15-14.fc11.x86_64 but I still experience this bug To get full PA logs, run the following in a console: pulseaudio -k pulseaudio -vvvv then reproduce the problem. That kills the running PA and starts a new one running in the console with high verbosity, so you get all the output there. Can we please have alsa-info.sh --no-upload output from each reporter, so we know what hardware is involved here? Thanks. Please also confirm whether you are still seeing the issue with latest F11 kernel / pulseaudio (kernel went up to 2.6.30, so it's worth checking). For extra optional bonus credit, it'd be great if you could see if it happens with F12 Beta, so we know whether it happens with the newer kernel / PA / ALSA in that release. Thanks! -- Fedora Bugzappers volunteer triage team https://fedoraproject.org/wiki/BugZappers I am not able to reproduce this on current F11 software. OK, closing then. If anyone manages to reproduce this, please reopen. |
Created attachment 350011 [details] pulseaudio -vvv log showing the error After a few minutes of playing music through a gstreamer-based app, pulseaudio stops responding and loops on printing these 3 error messages: D: protocol-native.c: Requesting rewind due to rewrite. D: alsa-sink.c: Requested to rewind 65536 bytes. D: alsa-sink.c: Mhmm, actually there is nothing to rewind. I will attach -vvv output from a run.