Bug 501769

Summary: intel hda: snd_pcm_avail/snd_pcm_delay overflows
Product: [Fedora] Fedora Reporter: Wolfgang Rupprecht <wolfgang.rupprecht>
Component: kernelAssignee: Jaroslav Kysela <jkysela>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 12CC: ajschult784, andreas.mack, awilliam, benny+bugzilla, bill-bugzilla.redhat.com, bloch, brunojcm, bugzilla, camilo, chris, christof, crash70, gavinflower, itamar, james, jensk.maps, juhani.jaakola, kernel-maint, lkundrak, louisgtwo, lpoetter, mishu, mrunge, nuno.lists, pda2, scottt.tw, temp, thaytan, tore, vedran, wtogami, yaneti
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: 2010-12-05 06:54:02 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:
Description Flags
/var/log/messages relating to the sound-preferences-tool running
none
messages log, 2 incidences of "snd_pcm_avail() returned a value that is exceptionally large"
none
pulse audio diagnostics with #define DEBUG_MMAP
none
mesages log - PA diagnostics
none
alsa gripes from 2.6.29.6-217.2.16.fc11.x86_64
none
stdout/err from pulseaudio -v when crash is being reproduced none

Description Wolfgang Rupprecht 2009-05-20 16:10:22 UTC
Created attachment 344837 [details]
/var/log/messages relating to the sound-preferences-tool running

Description of problem:

opening the "sound preferences" tool causes a string of errors in /var/log/messages and all sound stops.

Version-Release number of selected component (if applicable):

alsa-lib.x86_64                         1.0.20-1.fc11                  installed
alsa-lib-devel.x86_64                   1.0.20-1.fc11                  installed
alsa-plugins-pulseaudio.x86_64          1.0.18-3.fc11                  installed
alsa-utils.x86_64                       1.0.20-3.fc11                  installed
kernel.x86_64                           2.6.29.3-140.fc11              installed
pulseaudio.x86_64                       0.9.15-11.fc11                 installed
pulseaudio-libs.x86_64                  0.9.15-11.fc11                 installed
pulseaudio-libs-glib2.x86_64            0.9.15-11.fc11                 installed
pulseaudio-libs-zeroconf.x86_64         0.9.15-11.fc11                 installed
pulseaudio-module-bluetooth.x86_64      0.9.15-11.fc11                 installed
pulseaudio-module-gconf.x86_64          0.9.15-11.fc11                 installed
pulseaudio-module-x11.x86_64            0.9.15-11.fc11                 installed
pulseaudio-utils.x86_64                 0.9.15-11.fc11                 installed


How reproducible:
very

Steps to Reproduce:
1. play something with sound (like a flash *.flv from the net)
2. try to adjust the volume by opening the sound preferences tool
   (right click the speaker icon on the top bar)
3. notice the tool hangs for 30 seconds or so.  
4. notice that all sound has now stopped
5. notice all sorts of errors in /var/log/messages
  
Actual results:
sound stops

Expected results:
sound doesn't stop

Additional info:

This is an Asus m3a78t motherboard w. built in hda sound.  The volume has always been on the low side under linux, as if some scaling isn't done right.  The volume sliders must all be at max and the hardware volume control on the speakers must be all the way up against the stop.  The sound is still very quiet.

"alsamixer -c 0" also shows all the outputs cranked to maximum.

Comment 1 Lennart Poettering 2009-05-20 17:56:29 UTC
Hmm, snd_pcm_delay overflows. That's a kernel bug.

Comment 2 Jan Schmidt 2009-06-08 16:24:51 UTC
I see snd_pcm_delay() overflow messages here too, although I don't see the primary behaviour of gnome-volume-control causing it - it just seems to happen from time to time, and it seems to cause the current pulseaudio daemon to exit - which makes any open applications (mixer_applet, gnome-volume-control, firefox) to not play sound until they are restarted. Another variant on the "snd_pcm_delay() returns bogus info" theme also occurs:

Jun  4 22:21:36 fancy pulseaudio[2724]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 1480729504 bytes (8394158 ms).
Jun  4 22:21:36 fancy pulseaudio[2724]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

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

Jun  6 02:18:19 fancy pulseaudio[2681]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 1480743712 bytes (8394238 ms).
Jun  6 02:18:19 fancy pulseaudio[2681]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

Jun  6 19:09:29 fancy pulseaudio[28957]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Jun  6 19:09:29 fancy pulseaudio[28957]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

Jun  6 19:09:29 fancy pulseaudio[28957]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.

Jun  7 03:35:42 fancy pulseaudio[28957]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 1480729760 bytes (8394159 ms).
Jun  7 03:35:42 fancy pulseaudio[28957]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

Jun  8 03:27:01 fancy pulseaudio[2675]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 1484621856 bytes (8416223 ms).
Jun  8 03:27:01 fancy pulseaudio[2675]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

I notice that in all the cases above, the delay it's reporting is around 2.5 hours, and the bytes value is large enough to be pointing toward an arithmetic overflow somewhere.

I'm currently running 2.6.29.4-167.fc11.i686.PAE

Comment 3 Bug Zapper 2009-06-09 16:11:31 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 4 Matthias Runge 2009-06-16 07:04:41 UTC
same here on T43, even in 2.6.30-6 kernel from koji (http://koji.fedoraproject.org/koji/buildinfo?buildID=105938)

Comment 5 Nivag 2009-07-12 09:48:50 UTC
I noticed in the messages log, several alsa errors (twice today, and probably on previous days), such as 
"
Jul 12 15:49:16 saturn pulseaudio[1642]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -8574853690509200220 bytes (-360287948188 ms).
Jul 12 15:49:16 saturn pulseaudio[1642]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Jul 12 15:49:16 saturn pulseaudio[1642]: alsa-util.c: snd_pcm_dump():
"


each incident was followed by (and related diagnostics): 
"
Jul 12 17:16:27 saturn gdm-simple-greeter[3098]: WARNING: StartSessionWhenReady org.freedesktop.DBus.Error.NoReply raised: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.#012
"

This is odd, may be a coincidence, I will report the StartSessionWhenReady issue as a separate bug.

I will include the whole of today's log, in case other thngs may be relevant background.

Let me know if you want me to look at the earlier log (the machine has only been going since about Monday, less than 7 days.).

I can'
t comment on sound quality, as the machine has no speakers yet!

# uname -a
Linux saturn 2.6.29.5-191.fc11.x86_64.debug #1 SMP Tue Jun 16 23:09:06 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

Additional info:
up to date Fedora 11 install
AMD 810 quad core 64 bit
8 GB DDR3 RAM
5 * 500GB in software RAID-6 configuration
ASUS M4A78T-E motherboard

Comment 6 Nivag 2009-07-12 09:54:22 UTC
Created attachment 351383 [details]
messages log, 2 incidences of "snd_pcm_avail() returned a value that is exceptionally large"

Comment 7 Jaroslav Kysela 2009-07-20 09:25:03 UTC
Could you do alsa-lib test described in bug#497636 (comment 10)?

Comment 8 Nivag 2009-07-23 01:10:26 UTC
Jaroslav - just seen your request, I've been away from home for a few days, I'll look into further testing/diagnostics later today (NZ time).

What is 'PA'?  Or is that explained in the tar ball documentation? If it is, don't bother replying!

Comment 9 Jan Schmidt 2009-07-23 06:58:51 UTC
PA is pulseaudio

Comment 10 Nivag 2009-07-23 10:00:54 UTC
I killed all instances of pulseaudio first.

Here are the results so far (I'll leave it running overnight, and attach selected log file excerpts if anything interesting shows up):

$ pwd
/home/gavin/AAA/updates/alsa/alsa-lib-1.0.20/src/.libs
$ date ; LD_PRELOAD=/home/gavin/AAA/updates/alsa/alsa-lib-1.0.20/src/.libs/libasound.so pulseaudio --start --log-target=syslog
Thu Jul 23 21:01:57 NZST 2009
[WARN 26096] polkit-session.c:144:polkit_session_set_uid(): session != NULL
 Not built with -rdynamic so unable to print a backtrace
$ grep DEBUG_MMAP ../pcm/pcm_hw.c
#define DEBUG_MMAP		/* debug mmap_commit */
#ifdef DEBUG_MMAP

Jul 23 21:01:57 saturn pulseaudio[26096]: polkit.c: Cannot set UID on session object.
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=256, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=384, bytes=384, size=12288, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=384, bytes=384, size=12288, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=384, bytes=384, size=12288, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=512, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn kernel: ALSA sound/pci/hda/hda_intel.c:1101: Too big adjustment 32: adj=128, bytes=128, size=4096, periods=32
Jul 23 21:01:57 saturn pulseaudio[26098]: alsa-sink.c: Unable to set switch: Operation not permitted
Jul 23 21:01:57 saturn pulseaudio[26098]: alsa-sink.c: Increasing wakeup watermark to 30.00 ms
Jul 23 21:01:58 saturn pulseaudio[26098]: alsa-sink.c: Increasing wakeup watermark to 40.00 ms
Jul 23 21:01:58 saturn pulseaudio[26098]: alsa-sink.c: Increasing wakeup watermark to 50.00 ms
Jul 23 21:10:56 saturn kernel: [drm] Resetting GPU
Jul 23 21:10:56 saturn kernel: mtrr: base(0xd0000000) is not aligned on a size(0xfff0000) boundary
Jul 23 21:10:56 saturn kernel: [drm] Setting GART location based on new memory map
Jul 23 21:10:56 saturn kernel: [drm] Loading RS780 CP Microcode
Jul 23 21:10:56 saturn kernel: [drm] Loading RS780 PFP Microcode
Jul 23 21:10:56 saturn kernel: [drm] Resetting GPU
Jul 23 21:10:56 saturn kernel: [drm] writeback test succeeded in 1 usecs
Jul 23 21:11:06 saturn pulseaudio[26098]: alsa-sink.c: Increasing wakeup watermark to 60.00 ms
Jul 23 21:11:07 saturn pulseaudio[26604]: pid.c: Daemon already running.
Jul 23 21:17:45 saturn pulseaudio[26998]: polkit.c: Cannot set UID on session object.
Jul 23 21:17:45 saturn pulseaudio[27000]: module-alsa-card.c: Card '0' doesn't exist: Permission denied
Jul 23 21:17:45 saturn pulseaudio[27000]: module.c: Failed to load  module "module-alsa-card" (argument: "device_id=0 name=pci_1002_4383_sound_card_0 card_name=alsa_card.pci_1002_4383_sound_card_0 tsched=1"): initialization failed.
Jul 23 21:17:45 saturn pulseaudio[27000]: module-alsa-card.c: Card '1' doesn't exist: Permission denied
Jul 23 21:17:45 saturn pulseaudio[27000]: module.c: Failed to load  module "module-alsa-card" (argument: "device_id=1 name=pci_1002_960f_sound_card_0 card_name=alsa_card.pci_1002_960f_sound_card_0 tsched=1"): initialization failed.
Jul 23 21:17:45 saturn pulseaudio[27000]: module.c: Failed to load  module "module-alsa-card" (argument: "device_id=1 name=pci_1002_960f_sound_card_0 card_name=alsa_card.pci_1002_960f_sound_card_0 tsched=1"): initialization failed.
Jul 23 21:20:47 saturn ntpd[1966]: synchronized to LOCAL(0), stratum 10
Jul 23 21:22:59 saturn ntpd[1966]: synchronized to 192.168.1.205, stratum 2

Comment 11 Jaroslav Kysela 2009-07-23 11:05:03 UTC
Many appl_forward: messages should appear. Please, use 'LD_PRELOAD=<your_alsa_lib.so> pulseaudio -vvvv' and run an audio application.

Comment 12 Lennart Poettering 2009-07-23 12:42:39 UTC
*** Bug 513334 has been marked as a duplicate of this bug. ***

Comment 13 Nivag 2009-07-23 14:26:30 UTC
Created attachment 354869 [details]
pulse audio diagnostics with #define DEBUG_MMAP

Comment 14 Nivag 2009-07-23 14:28:41 UTC
$ date ; LD_PRELOAD=/home/gavin/AAA/updates/alsa/alsa-lib-1.0.20/src/.libs/libasound.so pulseaudio  -vvvv --start --log-target=syslog
Fri Jul 24 02:09:52 NZST 2009
[WARN  3605] polkit-session.c:144:polkit_session_set_uid(): session != NULL
 Not built with -rdynamic so unable to print a backtrace
$ uname -a
Linux saturn 2.6.29.6-213.fc11.x86_64.debug #1 SMP Tue Jul 7 20:45:52 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux
$ 


Note I've applied all updates, including a new kernel as few a few hours ago.

Comment 15 Nivag 2009-07-25 02:38:53 UTC
Created attachment 355126 [details]
mesages log - PA diagnostics

Note that the curent debug version was started on the 24th, but I included all the log from the last boot time.

LD_PRELOAD=/home/gavin/AAA/updates/alsa/alsa-lib-1.0.20/src/.libs/libasound.so pulseaudio -vvvv --start --log-target=syslog

Comment 16 Nivag 2009-07-27 20:30:55 UTC
Please let me know if you want more diagnostics - I am quite happy to try experimental versions.

Comment 17 Bruno Medeiros 2009-07-28 02:12:03 UTC
I'm the reporter of #513334 and I'm experiencing a very similar error here.
Is there a way I could help?

Comment 18 Juhani Jaakola 2009-07-29 11:24:59 UTC
I have the same problem with ThinkPad R50p with kernel-2.6.29.6-213.fc11.i586. However, I have driver snd_intel8x0 instead of snd_hda_intel. Here is what I get in /var/log/messages:

pulseaudio[4539]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 465476 bytes (2638 ms).
pulseaudio[4539]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers.

Comment 19 Jaroslav Kysela 2009-07-29 11:38:27 UTC
(In reply to comment #18)
> I have the same problem with ThinkPad R50p with kernel-2.6.29.6-213.fc11.i586.
> However, I have driver snd_intel8x0 instead of snd_hda_intel. Here is what I
> get in /var/log/messages:
> 
> pulseaudio[4539]: alsa-util.c: snd_pcm_delay() returned a value that is
> exceptionally large: 465476 bytes (2638 ms).
> pulseaudio[4539]: alsa-util.c: Most likely this is a bug in the ALSA driver
> 'snd_intel8x0'. Please report this issue to the ALSA developers.  

Bug for intel8x0 is bug#506075 . Please, report only snd-hda-intel issues here.

Comment 20 Nivag 2009-08-08 20:56:15 UTC
(In reply to comment #19)

I have an AMD processor, and on an ASUS M4A78T-E motherboard (see comment #5).

I am curious "snd_hda_intel" appears in my messages log, even though I'm using AMD!

Jaroslav, your comment may inadvertently discourage people like me from commenting here - as I would not haver expected my problem had anything to do with Intel, because only now when I saw your comment did I check the log in enough detail to see the 'intel' reference,

Comment 21 Bruno Medeiros 2009-08-10 12:26:18 UTC
I'm the reporter of #513334 and now, using the kernel 2.6.29.6-213.fc11.x86_64, my sound problems are gone. pavucontrol works fine, so the problem reported in #513334 has gone too.

I think people having severe problems in https://bugzilla.redhat.com/show_bug.cgi?id=498401 actually have this bug instead of 498401. They should be marked as related, shouldn't they?

Comment 22 Lennart Poettering 2009-08-11 21:24:27 UTC
Hmm, I got bitten by this badly again, on rawhide.

 snd_pcm_avail() returned a value that is exceptionally large: 8574853690513222948 bytes (360287969140 ms).

snd_pcm_delay() returned a value that is exceptionally large: -8574853690509001712 bytes (-360287947154 ms)

One on snd_hda_codec_atihdmi, the other on snd_hda_codec_realtek.

Kernel is 2.6.31-0.139.rc5.git3.fc12.x86_64

Comment 23 Lennart Poettering 2009-08-19 19:59:04 UTC
*** Bug 518282 has been marked as a duplicate of this bug. ***

Comment 24 PieterJ 2009-08-24 08:02:21 UTC
This is really frustrating!

It seems that the only way to get the sound working again, is to install Fedora Core 8. 

Please fix this.

Comment 25 Wolfgang Rupprecht 2009-08-27 11:24:09 UTC
Created attachment 358850 [details]
alsa gripes from  2.6.29.6-217.2.16.fc11.x86_64

alsa gripes from kernel 2.6.29.6-217.2.16.fc11.x86_64

http://www.smolts.org/client/show/pub_d9629819-667e-43e1-85fb-372cf84876b9

Comment 26 Nuno Maltez 2009-09-02 14:08:36 UTC
I think I had this exact problem on a HP Pavillion dv3 notebook

Aug 31 11:14:24 neuromancer pulseaudio[13597]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 6377097072356438156 bytes (326791808651 ms).
Aug 31 11:14:24 neuromancer pulseaudio[13597]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

Aug 31 11:14:24 neuromancer pulseaudio[13597]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -6377097072355997188 bytes (-326791806151 ms).
Aug 31 11:14:24 neuromancer pulseaudio[13597]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.


After spending a lot of time googling the issue I finally solved it by adding "enable_msi=1" to my configuration file /etc/modprobe.d/alsa.conf

options snd-hda-intel model=hp-dv5 enable_msi=1

current kernel:
2.6.29.6-217.2.16.fc11.x86_64 #1 SMP Mon Aug 24 17:17:40 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

No more pulseaudio crashes and all audio plays perfectly now.

Comment 27 Nivag 2009-09-02 21:33:27 UTC
I don't have a
    /etc/modprobe.d/alsa.conf
file.

# ll /etc/modprobe.d
total 28
-rw-r--r--. 1 root root   52 2009-01-12 06:34 anaconda.conf
-rw-r--r--. 1 root root  845 2009-04-10 06:40 blacklist.conf
-rw-r--r--. 1 root root   16 2008-01-04 21:43 blacklist-visor.conf
-rw-r--r--. 1 root root 5616 2009-05-20 13:56 dist.conf
-rw-r--r--. 1 root root  473 2009-05-20 13:56 dist-oss.conf
-rw-r--r--. 1 root root   53 2009-06-30 23:50 floppy-pnp.conf
# 

Also I have an ASUS M4A78T-E motherboard (see comment #5).  So I suspect that 'model=hp-dv5' would not be appropriate.

I note that I have not had the problem for a while, as snd_pcm_avail errors of 'exceptionally large' values have not been logged since 19-Aug-09

# grep snd_pcm_avail /var/log/messages*
/var/log/messages-20090809:Aug  5 05:10:31 saturn pulseaudio[2654]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 5814144 bytes (32960 ms).
/var/log/messages-20090809:Aug  6 20:33:31 saturn pulseaudio[2872]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
/var/log/messages-20090823:Aug 19 01:50:03 saturn pulseaudio[2757]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 13874536 bytes (78653 ms).
# 

I was thinking of creating a file
    /etc/modprobe.d/alsa.conf
with the line
    options snd-hda-intel enable_msi=1
based on the suggestions in
    http://forums.fedoraforum.org/showthread.php?t=223886
but since the error does not seem to have occurred for a while, and I don't have any speakers attached, I won't.

Possibly the problem has been resolved, as the result of kernel and other upgrades, in the normal cause of events?

Comment 28 Nivag 2009-09-02 21:41:51 UTC
I rechecked the log, looking for 'snd_pcm_delay', but this merely confirms my conclusions of Comment #27 above!

# grep snd_pcm_delay /var/log/messages*
/var/log/messages-20090809:Aug  5 05:10:32 saturn pulseaudio[2654]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -5344976 bytes (-30300 ms).
/var/log/messages-20090823:Aug 19 01:50:04 saturn pulseaudio[2757]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -13370088 bytes (-75794 ms).
#

Comment 29 Adam Williamson 2009-10-23 15:43:29 UTC
So, this was added to the F12 blocker list by Lennart after he hit it in Rawhide (comment #22), but this bug is for F11 and most reporters are testing with F11.

That is...not optimal :)

Lennart, if you're still hitting this with latest F12 kernel, can you file a new bug, so we can put _that_ one on the blocker list and not have the F11 confusion? If anyone else is experiencing this on F12, please comment on the new bug when it's filed, not on this one. Let's keep this report for F11.

-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 30 Lennart Poettering 2009-10-23 19:12:36 UTC
(In reply to comment #29)

> Lennart, if you're still hitting this with latest F12 kernel, can you file a
> new bug, so we can put _that_ one on the blocker list and not have the F11
> confusion? If anyone else is experiencing this on F12, please comment on the
> new bug when it's filed, not on this one. Let's keep this report for F11.

This bug did not get entirely fixed in neither F11 nor F12. On the ATI HDMI audio cards this still exists. Given that those are probably still exotic and HDMI doesn't really work too well anyway it certainly makes sense to drop this as F12Blocker, but keep it open.

I really don't see much value in opening a second bug report about this, given that the actual problem is not fully fixed yet.

Comment 31 Adam Williamson 2009-10-26 21:11:15 UTC
it's a process thing - it's hard to track the status of a problem in two releases via a single bug report. Our current best option for the situation is to have two reports, one for each release. Ideally, Bugzilla would handle the multiple release situation more elegantly, like Launchpad does.

Dropping it as an F12Blocker does address my immediate concern, though (by making me stop caring about it until F12 is done and I can relax :>)

-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 32 Lennart Poettering 2009-10-26 21:16:21 UTC
*** Bug 531069 has been marked as a duplicate of this bug. ***

Comment 33 Lennart Poettering 2009-10-26 21:19:16 UTC
(In reply to comment #31)
> it's a process thing - it's hard to track the status of a problem in two
> releases via a single bug report. 

Right now the status in both distros is the same, so there is not much of a problem, is there?

Comment 34 Adam Williamson 2009-10-27 01:34:44 UTC
the problem comes when/if they diverge. if they don't then it's ok, but it's hard to predict that in advance. the two key components for sound - PA and kernel - are often (in fact, usually) at different revision levels in different releases of Fedora.

-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 35 Adam Huffman 2009-10-27 23:28:47 UTC
Probably worth pointing out that this problem doesn't seem to be present with kernel 2.6.31.5-96.fc12.x86_64 on the same hardware I've reported on elsewhere.

While there are lots of messages like:

pulseaudio[2226]: ratelimit.c: 564 events suppressed

the stalls I was seeing under F11 after 2-3 minutes aren't present.

Comment 36 Tore Anderson 2009-11-18 19:23:02 UTC
Created attachment 370169 [details]
stdout/err from pulseaudio -v when crash is being reproduced

I see this problem in a newly installed F12.  All I have to do is to to reproduce it is to start "pulseaudio -v" and then start "pavucontrol".  It's not necessary to have any sound playing.  I'm attaching a log of stdout/err from doing so, with a "MARK" line showing exactly when I started "pavucontrol".

My sound hardware is snd_hda_intel (and my smolt uuid is 
e2468016-5dad-4668-82a9-b7b3ba0bcf68).

Tore

Comment 37 andreas.mack@konsec.com 2009-12-02 09:21:00 UTC
I have an ati video card and I got this error also, because this card seems to have hdmi audio. Normal audio is snd-hda-intel. My solution was to add snd-hda-codec-atihdmi to /etc/modprobe.d/blacklist.conf.
Works fine now.

Comment 38 Adam Huffman 2010-01-05 11:30:13 UTC
Just saw this reappear on my box, now running fully-updated F12.  Have followed the fix suggested in https://bugzilla.redhat.com/show_bug.cgi?id=501769#c37 and that seems to be an effective workaround.

Comment 39 Chris Jones 2010-02-14 18:29:22 UTC
I have exactly this issue with my F12 installation. The workaround suggested in 37 above does NOT work for me.

My system is
Linux localhost.localdomain 2.6.31.12-174.2.3.fc12.x86_64 #1 SMP Mon Jan 18 19:52:07 UTC 2010 x86_64 x86_64 x86_64 GNU/Linux

and is hosted on an AMD x2 6000 on a Gigabyte GA-MA790X-DS4 motherboard.

My sound is from the motherboard and also (apparently) from my graphics card - an ATI RV630 [Radeon HD 2600]

Extract from /var/log/messages for the latest issue is:
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Slave: Hardware PCM card 1 'HDA ATI HDMI' device 3 subdevice 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Its setup is:
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   stream       : PLAYBACK
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   access       : MMAP_INTERLEAVED
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   format       : S16_LE
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   subformat    : STD
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   channels     : 2
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   rate         : 48000
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   exact rate   : 48000 (48000/1)
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   msbits       : 16
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   buffer_size  : 16384
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_size  : 8192
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_time  : 170666
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   tstamp_mode  : ENABLE
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_step  : 1
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   avail_min    : 15424
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_event : 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   start_threshold  : -1
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   stop_threshold   : 4611686018427387904
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   silence_threshold: 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   silence_size : 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   boundary     : 4611686018427387904
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   appl_ptr     : 17597
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   hw_ptr       : 27
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 725640 bytes (3779 ms).
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: snd_pcm_dump():
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Hooks PCM
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Its setup is:
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   stream       : PLAYBACK
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   access       : MMAP_INTERLEAVED
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   format       : S16_LE
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   subformat    : STD
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   channels     : 2
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   rate         : 48000
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   exact rate   : 48000 (48000/1)
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   msbits       : 16
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   buffer_size  : 16384
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_size  : 8192
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_time  : 170666
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   tstamp_mode  : ENABLE
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_step  : 1
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   avail_min    : 15424
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_event : 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   start_threshold  : -1
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   stop_threshold   : 4611686018427387904
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   silence_threshold: 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   silence_size : 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   boundary     : 4611686018427387904
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Slave: Hardware PCM card 1 'HDA ATI HDMI' device 3 subdevice 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c: Its setup is:
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   stream       : PLAYBACK
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   access       : MMAP_INTERLEAVED
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   format       : S16_LE
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   subformat    : STD
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   channels     : 2
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   rate         : 48000
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   exact rate   : 48000 (48000/1)
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   msbits       : 16
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   buffer_size  : 16384
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_size  : 8192
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_time  : 170666
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   tstamp_mode  : ENABLE
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_step  : 1
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   avail_min    : 15424
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   period_event : 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   start_threshold  : -1
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   stop_threshold   : 4611686018427387904
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   silence_threshold: 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   silence_size : 0
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   boundary     : 4611686018427387904
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   appl_ptr     : 181437
Feb 14 18:18:19 legolas pulseaudio[16540]: alsa-util.c:   hw_ptr       : 27
Feb 14 18:18:20 legolas rtkit-daemon[15769]: Sucessfully made thread 16578 of process 16578 (/usr/bin/pulseaudio) owned by '500' high priority at nice level -11.
Feb 14 18:18:20 legolas pulseaudio[16578]: pid.c: Stale PID file, overwriting.
Feb 14 18:18:20 legolas rtkit-daemon[15769]: Sucessfully made thread 16584 of process 16584 (/usr/bin/pulseaudio) owned by '500' high priority at nice level -11.
Feb 14 18:18:20 legolas pulseaudio[16584]: pid.c: Daemon already running.
Feb 14 18:18:25 legolas pulseaudio[16578]: ratelimit.c: 24 events suppressed

All I want to do is to get the sound working on this system (as it did on Fedora 11 - and previous releases).

Comment 40 andreas.mack@konsec.com 2010-02-17 07:09:22 UTC
(In reply to comment #39)
> I have exactly this issue with my F12 installation. The workaround suggested in
> 37 above does NOT work for me.

Have you rebooted?
The line in /etc/modprobe.d/blacklist.conf should read:
blacklist snd-hda-codec-atihdmi
Then the module will never be loaded. You can check this in the PA Manager under the devices tab.

Comment 41 Chris Jones 2010-02-17 18:52:46 UTC
Yes. I have actually had to reboot a couple of times.

However, the entry you suggest was not in the blacklist.conf so I have now added it, but will not be able to test this out until I return home on Friday.

Comment 42 Bug Zapper 2010-11-04 11:13:42 UTC
This message is a reminder that Fedora 12 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 12.  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 '12'.

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 12'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 12 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 43 Bug Zapper 2010-12-05 06:54:02 UTC
Fedora 12 changed to end-of-life (EOL) status on 2010-12-02. Fedora 12 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.