Bug 500657 - HDA playback stuck in 2s loop, PCM: hw_ptr skipping! spew in dmesg
Summary: HDA playback stuck in 2s loop, PCM: hw_ptr skipping! spew in dmesg
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 11
Hardware: All
OS: Linux
low
high
Target Milestone: ---
Assignee: Jaroslav Kysela
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-05-13 15:18 UTC by Dimi Paun
Modified: 2010-06-28 12:31 UTC (History)
12 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2010-06-28 12:31:31 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
mesg (41.87 KB, text/plain)
2009-05-15 14:13 UTC, Dimi Paun
no flags Details
thread apply bt full (3.36 KB, text/plain)
2009-05-15 14:14 UTC, Dimi Paun
no flags Details
pa -vvvvv output (288.94 KB, text/plain)
2009-05-16 13:46 UTC, Dimi Paun
no flags Details
PA backtrace (3.42 KB, text/plain)
2009-05-16 13:52 UTC, Dimi Paun
no flags Details
start of pulseaudio -vvvvvv (53.68 KB, text/plain)
2009-05-20 14:59 UTC, Dimi Paun
no flags Details
alsa-info.sh output while broken; no change after resetting pulseaudio made sound work again (23.59 KB, text/plain)
2009-07-17 18:37 UTC, Jason Merrill
no flags Details
pulseaudio -vvvvv (2.27 KB, text/plain)
2009-09-22 02:18 UTC, Bill McGonigle
no flags Details
dmesg (14.45 KB, text/plain)
2009-09-22 02:18 UTC, Bill McGonigle
no flags Details
backtrace during loop (5.01 KB, text/plain)
2009-10-20 19:25 UTC, Bill McGonigle
no flags Details
alsa-info.sh --no-upload (not looping) (21.44 KB, text/plain)
2009-10-27 13:09 UTC, Bill McGonigle
no flags Details
alas-info.sh --no-upload (while looping) (24.31 KB, text/plain)
2009-10-29 05:22 UTC, Bill McGonigle
no flags Details
dmesg during looping audio (10.03 KB, text/plain)
2009-10-29 05:28 UTC, Bill McGonigle
no flags Details

Description Dimi Paun 2009-05-13 15:18:41 UTC
Description of problem:
Last night around 1PM I watched a few youtube clips. All night the box was not used, this morning at 11AM I decided to play a song in Rythmbox. PA got into an infinite loop playing the first ~2s of the song.

Version-Release number of selected component (if applicable):
pulseaudio-0.9.15-11.fc11.i586

How reproducible:
Very.

Additional info:
I have reported this problem before here:
    https://bugzilla.redhat.com/show_bug.cgi?id=497550
it has been incorrectly marked as a DUP of this
    https://bugzilla.redhat.com/show_bug.cgi?id=493788

Please note that I have disabled module-combine so it can not be related to that.

Comment 1 Lennart Poettering 2009-05-14 15:31:41 UTC
The data you included in bug 497550 shows that this was a bug in module-combine.

If you now disabled module-combine, please get me the output of "pulseaudio -vvvvv" when this happens, of 'dmesg' and a full bt over all threads when this loop happens, would be good, too.

Comment 2 Dimi Paun 2009-05-14 16:18:38 UTC
I don't think it shows that, this is how you interpreted it, which is now clear that's not correct :)

This information is not easy to get, I've spent hours gathering all that stuff that you asked me to, it's a pitty to just dump it.

Comment 3 Dimi Paun 2009-05-15 14:13:22 UTC
Created attachment 344155 [details]
mesg

Comment 4 Dimi Paun 2009-05-15 14:14:03 UTC
Created attachment 344156 [details]
thread apply bt full

Comment 5 Dimi Paun 2009-05-15 14:18:16 UTC
I don't have "pulseaudio -vvvvv" for now, I'm trying to reproduce again to get that too. Meanwhile, check out the backtrace and the dmesg.

Comment 6 Dimi Paun 2009-05-16 13:46:22 UTC
Created attachment 344265 [details]
pa -vvvvv output

Comment 7 Dimi Paun 2009-05-16 13:52:54 UTC
Created attachment 344266 [details]
PA backtrace

another thread apply all bt full of PA, in synch with the pa -vvvvv output that I've attached.

Comment 8 Dimi Paun 2009-05-16 13:59:09 UTC
I've again left Rhythmbox runnning over nigh, found PA stuck on an infinite loop (this time it seemed shorter than 2s, but it's hard to say).

I don't think I had reliable sound (with Rawhide/F11) for more than 24h. This problem alone has been 100% reproducible by just leaving the computer playing music overnight. I can't really see why am I the only one seeing this bug, but my guess is that other folks just don't try to push the system enough.

BTW Lennart, did you try to leave the computer playing music overnight?

Comment 9 Lennart Poettering 2009-05-17 23:12:31 UTC
Hmm, those backtraces and pa -vvv ouputs show nothing wrong.

If I am understanding correctly PA still reacts to all client requests, but just doesn't play audio anymore?

COuld you please run "pacmd" when this happens, and then type "suspend 1" followed by "suspend 0"? This should close/reopen the audio device.

Comment 10 Dimi Paun 2009-05-20 04:26:10 UTC
I got again the infinite ~2s sample playing. I've left the computer running and Rhythmbox playing sound from an internet radio.

I did the suspend 1/0 from pacmd, but after that when I press play again in Rb it crashed.

Here is the last few lines of output from pulseaudio -vvvvv:

D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
I: module-suspend-on-idle.c: Source alsa_input.pci_8086_284b_sound_card_0 idle for too long, suspending ...
I: alsa-source.c: Device suspended...
I: client.c: Created 45 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 15, local 15
I: protocol-native.c: Got credentials: uid=500 gid=500 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: yes
D: module-augment-properties.c: Looking for .desktop file for rhythmbox
I: client.c: Created 46 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 15, local 15
I: protocol-native.c: Got credentials: uid=500 gid=500 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: yes
D: module-augment-properties.c: Looking for .desktop file for bug-buddy
D: alsa-sink.c: Wakeup from ALSA!

Comment 11 Dimi Paun 2009-05-20 04:28:57 UTC
Here is the bug report for the Rb crash:
http://crash.gnome.org/report/index/8a3d7778-44f6-11de-9ff8-0007e9333148?date=2009-05-20-04

Comment 12 Dimi Paun 2009-05-20 04:37:25 UTC
And one more thing -- indeed, after I do the suspend 1/0, I regain sound in Flash (no more infinite loop).

Comment 13 Lennart Poettering 2009-05-20 14:40:16 UTC
(In reply to comment #11)
> Here is the bug report for the Rb crash:
> http://crash.gnome.org/report/index/8a3d7778-44f6-11de-9ff8-0007e9333148?date=2009-05-20-04  

http 503. :-(q

Hmm, the pa -vvvv output you attached is truncated. I'd like to have a peek at the startup phase of PA in that output. Could you please start pulseaudio -vvvvv and attach the first 100 lines of output (until it gets boring...) or so?

Comment 14 Dimi Paun 2009-05-20 14:58:41 UTC
Yeah, there is a problem at gnome.org, hopefully they'll fix it soon.

And yeah, I've included that _last_ part of the log, where I though the problem appeared.

I've restarted the pa, I'll attach the output.

Comment 15 Dimi Paun 2009-05-20 14:59:28 UTC
Created attachment 344821 [details]
start of pulseaudio -vvvvvv

Comment 16 Dimi Paun 2009-05-22 14:27:36 UTC
Every morning now I experience this infinite loop business. suspend 1/0 from pacmd fixes it.

Comment 17 Dimi Paun 2009-05-30 17:10:46 UTC
Any news on this bug? Previous comment still stands...

Comment 18 Bug Zapper 2009-06-09 15:45:25 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 11 development cycle.
Changing version to '11'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 19 Lennart Poettering 2009-06-29 14:09:55 UTC
Hmm, that output shows nothing wrong.

So, do reproduce this what do I need to do? Leave PA running for 24h and have some song playing in rb for the same time?

Comment 20 Lennart Poettering 2009-06-29 14:10:11 UTC
s/do/to

Comment 21 Dimi Paun 2009-06-29 14:35:43 UTC
Yeah, that's about it -- I just play a radio station (Virgin Xtreme) in Rb, and let it play overnight. A lot of times this results in the loop.

Comment 22 Brad Smith 2009-07-14 21:26:45 UTC
I am seeing the same thing listening to streams in F11. Suspend/resume also works for me.

Comment 23 Jason Merrill 2009-07-17 18:29:36 UTC
I periodically hit what I assume is this same bug with the incoming message sound from Pidgin.  Right now it has been playing that sound over and over for a few hours; periodically I unmute to see if it's still going on.  Often in the past I have been able to make it stop by hitting the volume up/down/mute buttons, though not always; at the moment those buttons aren't controlling the volume at all for some reason.

After this started, I got these messages in /var/log/messages:

Jul 17 17:45:29 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 1.00 ms
Jul 17 17:45:31 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 2.00 ms
Jul 17 17:45:35 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 4.00 ms
Jul 17 17:45:39 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 8.00 ms
Jul 17 17:45:48 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 16.00 ms
Jul 17 17:45:51 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 26.00 ms
Jul 17 17:46:24 gemini pulseaudio[2382]: alsa-source.c: Increasing wakeup watermark to 15.99 ms
Jul 17 17:46:26 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 36.00 ms
Jul 17 17:46:36 gemini pulseaudio[2382]: alsa-source.c: Increasing wakeup watermark to 25.99 ms
Jul 17 17:46:37 gemini pulseaudio[2382]: alsa-source.c: Increasing minimal latency to 46.00 ms
Jul 17 17:49:01 gemini pulseaudio[2382]: alsa-source.c: Increasing wakeup watermark to 35.99 ms

suspend 1/0 resets it successfully.

I don't know if it's related, but at another time recently I noticed the error

Jul 16 22:38:55 gemini pulseaudio[2382]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Jul 16 22:38:55 gemini pulseaudio[2382]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Jul 16 22:38:55 gemini pulseaudio[2382]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.

in /var/log/messages.

Comment 24 Jason Merrill 2009-07-17 18:37:45 UTC
Created attachment 354187 [details]
alsa-info.sh output while broken; no change after resetting pulseaudio made sound work again

Comment 25 Brad Smith 2009-07-17 20:20:42 UTC
re comment 23, I have seen the same problem, in addition to loops when playing streams and local music files. suspend/resume works in all cases, but it's still annoying.

Comment 26 Brad Smith 2009-07-27 18:35:30 UTC
Possibly related?

https://bugzilla.redhat.com/show_bug.cgi?id=514005

Comment 27 Bill McGonigle 2009-09-22 02:16:58 UTC
Saw this again, recent updates applied.  The trigger was Firefox's PSM 'bloop', when installing a certificate.  I bet they never knew that in a 2 second loop it sounds like chinese water torture.

Sep 21 21:50:09 aughra pulseaudio[2260]: alsa-source.c: Increasing minimal latency to 1.00 ms
Sep 21 21:50:21 aughra pulseaudio[2260]: alsa-source.c: Increasing minimal latency to 2.00 ms
Sep 21 21:50:24 aughra pulseaudio[2260]: alsa-source.c: Increasing minimal latency to 4.00 ms
Sep 21 21:50:38 aughra pulseaudio[2260]: alsa-source.c: Increasing minimal latency to 8.00 ms
Sep 21 21:50:47 aughra pulseaudio[2260]: alsa-source.c: Increasing minimal latency to 16.00 ms

I'll attach the kernel messages, they're much larger, but just a sample for context:

Sep 21 21:50:45 aughra kernel: __ratelimit: 17 callbacks suppressed                                             
Sep 21 21:50:45 aughra kernel: ALSA sound/core/pcm_lib.c:275: PCM: hw_ptr skipping! [Q] (pos=1, delta=-1444921407, period=44096, jdelta=370/56294/0)
                                                                            
Sep 21 21:50:45 aughra kernel: ALSA sound/core/pcm_lib.c:352: PCM: hw_ptr skipping! (pos=520, delta=44616, period=44096, jdelta=12/1011)                                                                                        
Sep 21 21:50:45 aughra kernel: ALSA sound/core/pcm_lib.c:352: PCM: hw_ptr skipping! (pos=520, delta=44616, period=44096, jdelta=12/1011)                                                                                        
Sep 21 21:50:45 aughra kernel: ALSA sound/core/pcm_lib.c:352: PCM: hw_ptr skipping! (pos=520, delta=44616, period=44096, jdelta=12/1011)                                                                                        
Sep 21 21:50:46 aughra kernel: ALSA sound/core/pcm_lib.c:275: PCM: hw_ptr skipping! [Q] (pos=44097, delta=-1444849535, period=44096, jdelta=1000/57923/0)                                                                       
Sep 21 21:50:47 aughra kernel: ALSA sound/core/pcm_lib.c:275: PCM: hw_ptr skipping! [Q] (pos=1, delta=-1444899399, period=44096, jdelta=869/56793/0)   

pulseaudio-libs-0.9.15-17.fc11.i586
alsa-plugins-pulseaudio-1.0.21-2.fc11.i586
pulseaudio-0.9.15-17.fc11.i586
kernel-2.6.30.5-43.fc11.i586
alsa-lib-1.0.21-3.fc11.i586

I'm afraid I jumped the gun and hit 'mute' in the pulseaudio control panel which masked the symptom before I got a stacktrace (I did one anyway, but assume it's useless).  However, I did notice that in the control panel there were no sound level meters for applications or the output device before I hit mute, and then when I did un-mute, the sound-level meters came back.

Comment 28 Bill McGonigle 2009-09-22 02:18:04 UTC
Created attachment 362024 [details]
pulseaudio -vvvvv

Comment 29 Bill McGonigle 2009-09-22 02:18:52 UTC
Created attachment 362025 [details]
dmesg

Comment 30 Bill McGonigle 2009-10-20 19:25:46 UTC
Created attachment 365411 [details]
backtrace during loop

got a proper backtrace this time.  I have a corresponding dmesg, strace, and /proc//fd on my drive here if any are useful (don't want to add unnecessary clutter).

2.6.30.8-64.fc11.i586

Comment 31 Lennart Poettering 2009-10-27 03:13:27 UTC
Hmm, the backtrace shows nothing wrong. PA is waiting for events from the sound card or timeout for all audio devices. it hangs sanely in poll() as it should.

Given the kernel log msgs you posted i'd hence argue that this is a kernel bug. Reassigning.

Bill, please include the output of "alsa-info.sh --no-upload on your card here".

Comment 32 Bill McGonigle 2009-10-27 13:09:16 UTC
Created attachment 366262 [details]
alsa-info.sh --no-upload (not looping)

is there a way for me to catch whatever is happening to the kernel driver when I kill/start pulseaudio?  I assume something's being reset to make the behavior clear up.

Comment 33 Bill McGonigle 2009-10-29 05:22:48 UTC
Created attachment 366554 [details]
alas-info.sh --no-upload (while looping)

Comment 34 Bill McGonigle 2009-10-29 05:28:00 UTC
Created attachment 366555 [details]
dmesg during looping audio

pulseaudio -k, pulseaudio --start, re-launch my player (kaffeine) and back in business, but doing so didn't appear to log any additional info.

Comment 35 Lennart Poettering 2009-10-30 16:19:19 UTC
That dmesg issue looks like it points to the real issue here.

Comment 36 Bug Zapper 2010-04-27 14:18:36 UTC
This message is a reminder that Fedora 11 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 11.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '11'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 11's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 11 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 37 Bug Zapper 2010-06-28 12:31:31 UTC
Fedora 11 changed to end-of-life (EOL) status on 2010-06-25. Fedora 11 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.