Bug 506075

Summary: snd_intel8x0: snd_pcm_avail()/ snd_pcm_delay() overflow
Product: [Fedora] Fedora Reporter: Tomasz Torcz <tomek>
Component: kernelAssignee: Jaroslav Kysela <jkysela>
Status: CLOSED NEXTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 11CC: adam, ambijat, amlau, andreypetrov, antonio.montagnani, aquarichy, awilliam, bestis+rh, bgamari, bnocera, bob.bogo, bruno, camilo, Colin.Simpson, cpanceac, c.shoemaker, dcantrell, dimmu299792458, dkbatson, doubleOTeC, dragomir.dan, elryno, fdor6, goodyca48, graybeard, itamar, james, james, jbacik, jdy, jesusr, jgxenite, jkysela, jlcarroll, jns, jon.dufresne, josep.puigdemont, jpazdziora, juhani.jaakola, kernel-maint, lkundrak, lpoetter, luya, mario.ganz, marklee_nospam, martin.nad89, mathieu-acct, matthias_haase, maud.peyrin, mishu, nathankohagen, naveed, n.coghill, netllama, nuttchr, orders, oxben, pbrobinson, p, pedrofsilva, petr.tuma, pingou, pnewell0705, proteus, rick.hendricksen, rob.townley, sd227, sergio.lietti, sjensen, sta040, ste.sachse, talcite, ucfagls, ulrich, uno, vic, ville, wedgef5, wojtekjs
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:15:01 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
PCM positioning fix & commits it depends on
none
Output of /var/log/messages when the crash occures none

Description Tomasz Torcz 2009-06-15 13:41:13 UTC
Description of problem:
I found following messages in error log:
pulseaudio[7692]: alsa-source.c: Increasing wakeup watermark to 75,99 ms
pulseaudio[7692]: alsa-source.c: Increasing wakeup watermark to 85,99 ms
pulseaudio[7692]: alsa-sink.c: Increasing minimal latency to 136,00 ms
pulseaudio[7692]: alsa-util.c: snd_pcm_avail() zwróciło wyjątkowo dużą wartość: 18446744073709536472 bajty (418293516324 ms). ¹
pulseaudio[7692]: alsa-util.c: Prawdopodobnie jest to błąd sterownika ALSA "snd_intel8x0". Proszę zgłosić ten problem programistom ALSA. ²
pulseaudio[7692]: alsa-util.c: snd_pcm_dump():
pulseaudio[7692]: alsa-util.c: Hardware PCM card 0 'Intel ICH7' device 0 subdevice 0
pulseaudio[7692]: alsa-util.c: Its setup is:
pulseaudio[7692]: alsa-util.c:   stream       : CAPTURE
pulseaudio[7692]: alsa-util.c:   access       : MMAP_INTERLEAVED
pulseaudio[7692]: alsa-util.c:   format       : S16_LE
pulseaudio[7692]: alsa-util.c:   subformat    : STD
pulseaudio[7692]: alsa-util.c:   channels     : 2
pulseaudio[7692]: alsa-util.c:   rate         : 44100
pulseaudio[7692]: alsa-util.c:   exact rate   : 44100 (44100/1)
pulseaudio[7692]: alsa-util.c:   msbits       : 16
pulseaudio[7692]: alsa-util.c:   buffer_size  : 16384
pulseaudio[7692]: alsa-util.c:   period_size  : 16384
pulseaudio[7692]: alsa-util.c:   period_time  : 371519
pulseaudio[7692]: alsa-util.c:   tstamp_mode  : ENABLE
pulseaudio[7692]: alsa-util.c:   period_step  : 1
pulseaudio[7692]: alsa-util.c:   avail_min    : 16384
pulseaudio[7692]: alsa-util.c:   period_event : 0
pulseaudio[7692]: alsa-util.c:   start_threshold  : -1
pulseaudio[7692]: alsa-util.c:   stop_threshold   : 4611686018427387904
pulseaudio[7692]: alsa-util.c:   silence_threshold: 0
pulseaudio[7692]: alsa-util.c:   silence_size : 0
pulseaudio[7692]: alsa-util.c:   boundary     : 4611686018427387904
pulseaudio[7692]: alsa-util.c:   appl_ptr     : 136351434
pulseaudio[7692]: alsa-util.c:   hw_ptr       : 136347648
pulseaudio[7692]: alsa-util.c: snd_pcm_delay() zwróciło wyjątkowo dużą wartość: -642432 bajty (-3641 ms). ¹
pulseaudio[7692]: alsa-util.c: Prawdopodobnie jest to błąd sterownika ALSA "snd_intel8x0". Proszę zgłosić ten problem programistom ALSA.²
pulseaudio[7692]: alsa-util.c: snd_pcm_dump():
pulseaudio[7692]: alsa-util.c: Hardware PCM card 0 'Intel ICH7' device 0 subdevice 0
pulseaudio[7692]: alsa-util.c: Its setup is:
pulseaudio[7692]: alsa-util.c:   stream       : CAPTURE
pulseaudio[7692]: alsa-util.c:   access       : MMAP_INTERLEAVED
pulseaudio[7692]: alsa-util.c:   format       : S16_LE
pulseaudio[7692]: alsa-util.c:   subformat    : STD
pulseaudio[7692]: alsa-util.c:   channels     : 2
pulseaudio[7692]: alsa-util.c:   rate         : 44100
pulseaudio[7692]: alsa-util.c:   exact rate   : 44100 (44100/1)
pulseaudio[7692]: alsa-util.c:   msbits       : 16
pulseaudio[7692]: alsa-util.c:   buffer_size  : 16384
pulseaudio[7692]: alsa-util.c:   period_size  : 16384
pulseaudio[7692]: alsa-util.c:   period_time  : 371519
pulseaudio[7692]: alsa-util.c:   tstamp_mode  : ENABLE
pulseaudio[7692]: alsa-util.c:   period_step  : 1
pulseaudio[7692]: alsa-util.c:   avail_min    : 16384
pulseaudio[7692]: alsa-util.c:   period_event : 0
pulseaudio[7692]: alsa-util.c:   start_threshold  : -1
pulseaudio[7692]: alsa-util.c:   stop_threshold   : 4611686018427387904
pulseaudio[7692]: alsa-util.c:   silence_threshold: 0
pulseaudio[7692]: alsa-util.c:   silence_size : 0
pulseaudio[7692]: alsa-util.c:   boundary     : 4611686018427387904
pulseaudio[7692]: alsa-util.c:   appl_ptr     : 136515274
pulseaudio[7692]: alsa-util.c:   hw_ptr       : 136354666
pulseaudio[7692]: ratelimit.c: 5156 events suppressed
pulseaudio[7692]: ratelimit.c: 7679 events suppressed
pulseaudio[7692]: cpulimit.c: Received request to terminate due to CPU overload.
pulseaudio[7692]: memblock.c: Memory pool destroyed but not all memory blocks freed! 1261 remain.

rough translation of polish messages is:
¹ (function) returned exceptionally large values: XXX bytes (YYY ms)
² this is probably error in alsa driver "snd_intel8x0". Please report to alsa developers.


Version-Release number of selected component (if applicable):
kernel-2.6.29.4-167.fc11.x86_64
pulseaudio-0.9.15-11.fc11.x86_64
alsa-lib-1.0.20-1.fc11.x86_64

00:1e.2 Multimedia audio controller: Intel Corporation 82801G (ICH7 Family) AC'97 Audio Controller (rev 01)

 0 [ICH7           ]: ICH4 - Intel ICH7
                      Intel ICH7 with AD1981B at irq 23

Hardware is Dell Optiplex GX620, intel chipset from Pentium 4 HT era.
http://www.smolts.org/client/show/pub_66b53b8f-baf2-4205-958b-9740b2becee2

Comment 1 Lubomir Rintel 2009-07-28 03:57:50 UTC
*** Bug 513778 has been marked as a duplicate of this bug. ***

Comment 2 Lubomir Rintel 2009-07-28 04:00:41 UTC
Jaroslav: This seems pretty easily reproducible. Is there something we can do to help hunt down the issue?

Comment 3 Lennart Poettering 2009-07-28 13:20:05 UTC
*** Bug 513801 has been marked as a duplicate of this bug. ***

Comment 4 Trevor Christian 2009-07-28 16:26:16 UTC
I booted to previous kernel.
From kernel-2.6.29.6-213 to kernel 2.6.29.5-191 and the problem has thus far not resurfaced. My kernel update according to the yum log happened on the 23rd of July, one day ahead of my 24th July updates and subsequent audio difficulties.

Comment 5 Naveed Hasan 2009-07-28 18:14:15 UTC
*** Bug 513575 has been marked as a duplicate of this bug. ***

Comment 6 Tomasz Torcz 2009-07-28 19:21:08 UTC
I'm still getting those:

Jul 28 17:01:15 mother pulseaudio[876]: alsa-util.c: snd_pcm_avail() zwróciło wyjątkowo dużą wartość: 4294951516 bajty (24347797 ms).
Jul 28 17:01:15 mother pulseaudio[876]: alsa-util.c: snd_pcm_delay() zwróciło wyjątkowo dużą wartość: 367984 bajty (2086 ms).

2.6.29.6-213.fc11.i686.PAE, pulseaudio-0.9.15-14.fc11.i586
 0 [nForce2        ]: NFORCE - NVidia nForce2
                      NVidia nForce2 with ALC650F at irq 21

(this is on other computer than initial report).

Comment 7 Lubomir Rintel 2009-07-28 20:08:27 UTC
Soo, I compiled snd-intel8x0 from alsa-kernel.git and inserted it in my 2.6.30-1.fc12 kernel, problem seems to be gone. Looking at the changelog I noticed commit f708eb1 which looks like it fixes this issue. In meanwhile, it seems to have been merged for 2.6.31:

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=f708eb1d71dc8ffb184da9f0bc53461c6dc10653

If it proves to solve the issue, could that be applied to F-11 kernel?

Comment 8 Lubomir Rintel 2009-07-28 22:06:09 UTC
Created attachment 355470 [details]
PCM positioning fix & commits it depends on

Here are the commits that are needed for the patch to apply against 2.6.29.6-217. Verified to work well with 82801EB/ER.

Comment 9 Jaroslav Kysela 2009-07-29 07:44:21 UTC
*** Bug 514213 has been marked as a duplicate of this bug. ***

Comment 10 Jaroslav Kysela 2009-07-29 08:12:09 UTC
*** Bug 509054 has been marked as a duplicate of this bug. ***

Comment 11 Pierre-YvesChibon 2009-07-29 13:47:28 UTC
*** Bug 514279 has been marked as a duplicate of this bug. ***

Comment 12 Lennart Poettering 2009-07-29 14:41:24 UTC
*** Bug 514097 has been marked as a duplicate of this bug. ***

Comment 13 Pierre-YvesChibon 2009-07-29 15:15:37 UTC
$ uname -r
2.6.29.6-217.fc11.i586

Tried this kernel downloaded from koji and it is still crashing (see attachment)

Comment 14 Pierre-YvesChibon 2009-07-29 15:16:44 UTC
Created attachment 355564 [details]
Output of /var/log/messages when the crash occures

Comment 15 James T Perkins 2009-07-30 01:25:22 UTC
I tried the attachment from comment #8 applied to kernel-2.6.29.6-213.fc11.x86_64 any my problems with intel8x0 are gone...

Comment 16 Pádraig Brady 2009-07-30 09:30:37 UTC
Thanks Lubomir!

I tried the attachment from comment #8 applied to 2.6.29.6-213.fc11.i586
and my problems with intel8x0 are gone...

Comment 17 Chuck Ebbert 2009-07-31 06:04:13 UTC
We are working on a 2.6.30 kernel for F-11 which will have those fixes. The new 2.6.29.6 update is for security problems.

Comment 18 Lubomir Rintel 2009-08-03 08:12:32 UTC
*** Bug 497198 has been marked as a duplicate of this bug. ***

Comment 19 Lubomir Rintel 2009-08-03 08:16:49 UTC
*** Bug 513818 has been marked as a duplicate of this bug. ***

Comment 20 Lubomir Rintel 2009-08-03 08:30:25 UTC
*** Bug 515151 has been marked as a duplicate of this bug. ***

Comment 21 Martin Naď 2009-08-05 19:40:42 UTC
I tried 2.6.30.4-6.rc1.sg_test.fc11.x86_64 that`s is really good

Comment 22 Andrey Petrov 2009-08-06 06:36:40 UTC
> We are working on a 2.6.30 kernel for F-11 which will have those fixes.
Is there a repository where I could get this kernel from? It's not in updates or updates-testing...

Comment 23 Benjamin Thery 2009-08-13 14:03:10 UTC
Any chance to have this bug fixed soon in F11?

This one is really annoying, I can't listen to music (or watch video or Flash) more than a couple of minutes, before pulseaudio reports the snd_pcm_avail()/ snd_pcm_delay() error and starts eating 99% CPU.

Do you have an estimated date for the kernel containing the fix?
Or should I switch to an earlier kernel? (in this case, which one?)

Comment 24 Pádraig Brady 2009-08-13 14:07:52 UTC
Bah who needs sound (or suspend). Back to work!

Comment 25 Bob Hill 2009-08-13 14:16:06 UTC
FYI, on my system, kernel-2.6.29.5-191.fc11.i586 does NOT have this problem,
and music and video and flash can be played fine for any length of time.

Comment 26 Colin.Simpson 2009-08-13 14:23:57 UTC
I've had to revert to a test kernel 2.6.29.6-209.rc1.fc11, as (from memory) the last two updated kernels: 

kernel-2.6.29.6-217.2.3.fc11
kernel-2.6.29.6-213.fc11

, have this bug and the first updated kernel 

kernel-2.6.29.5-191.fc11

, has an annoying NFS server bug #508174 which basically is broken as an NFS server to any other version of RH, Fedora.

So if you use NFS server the rc kernel I'm using has the NFS bug fixed and working audio. Or the original F11 base distro kernel is probably OK, but not exactly ideal either I'd have thought. 

I've been very unlucky with F11 so far , I haven't had a good updated kernel that works with my usage requirements (but I don't think NFS server and audio working is too extreme a case!)

Comment 27 Tomasz Torcz 2009-08-13 14:29:54 UTC
There's 2.6.30 kernel for fc11 brewing at koji.fedoraproject.org.

Comment 28 Lennart Poettering 2009-08-13 14:51:39 UTC
*** Bug 516446 has been marked as a duplicate of this bug. ***

Comment 29 Lonni J Friedman 2009-08-13 16:25:09 UTC
I'm also seeing this problem on F11-i686 with 2.6.29.6-217.2.3.fc11.i586

Comment 30 Lubomir Rintel 2009-08-13 16:46:58 UTC
(In reply to comment #29)
> I'm also seeing this problem on F11-i686 with 2.6.29.6-217.2.3.fc11.i586  

That was said multiple times above (like ... ten? :).
Would you mind grabbing the 2.6.30-based kernel package from Koji and giving it a try?

Comment 31 Lonni J Friedman 2009-08-13 16:53:42 UTC
Is this the kernel you meant?
http://koji.fedoraproject.org/koji/buildinfo?buildID=127064

Comment 32 Benjamin Thery 2009-08-13 17:04:26 UTC
Thanks for the tips on the working kernels.
I'll try to revert to one of these ones.

BTW, I still don't see any 2.6.30 kernel in F11-testing repository. 
Where are we supposed to grab it (comment #30) to test it? 
Directly from koji? (I'm not sure it is safe enough for me)

Comment 33 Pedro Silva 2009-08-13 17:17:39 UTC
I've tested 2.6.30.4-25.fc11 from koji and the problem seems to be gone.

Comment 34 Wesley Tanaka 2009-08-14 06:32:48 UTC
http://kojipkgs.fedoraproject.org/packages/kernel/2.6.30.4/25.fc11/i686/kernel-PAE-2.6.30.4-25.fc11.i686.rpm improves the situation for me also.

High load still causes the error in the title, but the subsequent CPU spinning doesn't seem to happen.

...
N: alsa-sink.c: Increasing wakeup watermark to 105.99 ms
N: alsa-sink.c: Increasing minimal latency to 116.00 ms
E: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 349676 bytes (1982 ms).
E: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers.
E: alsa-util.c: snd_pcm_dump():
E: alsa-util.c: Hardware PCM card 0 'Intel ICH5' device 0 subdevice 0
E: alsa-util.c: Its setup is:
E: alsa-util.c:   stream       : PLAYBACK
E: alsa-util.c:   access       : MMAP_INTERLEAVED
E: alsa-util.c:   format       : S16_LE
E: alsa-util.c:   subformat    : STD
E: alsa-util.c:   channels     : 2
E: alsa-util.c:   rate         : 44100
E: alsa-util.c:   exact rate   : 44100 (44100/1)
E: alsa-util.c:   msbits       : 16
E: alsa-util.c:   buffer_size  : 16384
E: alsa-util.c:   period_size  : 16384
E: alsa-util.c:   period_time  : 371519
E: alsa-util.c:   tstamp_mode  : ENABLE
E: alsa-util.c:   period_step  : 1
E: alsa-util.c:   avail_min    : 16384
E: alsa-util.c:   period_event : 0
E: alsa-util.c:   start_threshold  : -1
E: alsa-util.c:   stop_threshold   : 1073741824
E: alsa-util.c:   silence_threshold: 0
E: alsa-util.c:   silence_size : 0
E: alsa-util.c:   boundary     : 1073741824
E: alsa-util.c:   appl_ptr     : 110600601
E: alsa-util.c:   hw_ptr       : 110673920
N: alsa-sink.c: Increasing wakeup watermark to 105.99 ms
N: alsa-sink.c: Increasing wakeup watermark to 115.99 ms
N: alsa-sink.c: Increasing wakeup watermark to 125.99 ms
N: alsa-sink.c: Increasing minimal latency to 126.00 ms
...

Comment 35 Lubomir Rintel 2009-08-14 21:55:10 UTC
*** Bug 517585 has been marked as a duplicate of this bug. ***

Comment 36 Colin.Simpson 2009-08-15 19:21:47 UTC
Test kernel 2.6.30.4-25.fc11 from koji seems to have fixed the problem for me too.

Comment 37 Glenn McKechnie 2009-08-16 04:20:28 UTC
Another vote of confidence for a koji.fedoraproject.org kernel - this one is kernel-2.6.30.5-28.rc2.fc11 by kyle. Along with the headers and devel rpms, akmod from rpmfusion built the Nvidia driver and now Rhythmbox and (most importantly) MythTV are working as previously with pulse audio.

http://koji.fedoraproject.org/koji/buildinfo?buildID=127365

Comment 38 James Gregory-Monk 2009-08-16 21:19:55 UTC
Vote +1 for kernel-2.6.30.5-28.rc2.fc11 - just updated to it myself and sound appears to be working fine.

Comment 39 Trevor Christian 2009-08-17 13:52:30 UTC
Vote +1 for kernel-2.6.30.5-28.rc2.fc11 - just updated to it myself and sound
appears to be working fine.

Comment 40 Lennart Poettering 2009-08-17 19:16:58 UTC
*** Bug 514197 has been marked as a duplicate of this bug. ***

Comment 41 Rosen Nedyalkov 2009-08-17 19:36:27 UTC
*** Bug 517496 has been marked as a duplicate of this bug. ***

Comment 42 Martin Naď 2009-08-22 08:03:59 UTC
Vote +1 for kernel-2.6.30.5-28.rc2.fc11 - sound work fine (but nvidia-bin-drv+X with this kernel has less stability ofcourse this is bug in nvidia)

Comment 43 Fdor 2009-08-23 12:46:34 UTC
An easy way to install kernel 2.6.30:

  yum --enablerepo=updates-testing update '*kernel*'

Kernel 2.6.30 fixes the bug for me. But I'm using it only for playing
media. When I need to use Internet, I'm booting a stable (2.6.29)
kernel.


Finally a reflexion: Having no media (video/audio) at Summer, is like
having no toys at Christmas. Do you see the point? What I mean is 
that I think this bug should have been marked as URGENT/CRITICAL, 
since it affects all media playing. More than two months to solve 
this bug is too much time. A normal user will have been 2 months with
out media playing.

Hollywood will be happy ("all those fedora linux hackers couldn't 
freely watch our films at Summer, muhahahahaha....") ;-)

Comment 44 Pierre-YvesChibon 2009-08-23 14:02:52 UTC
(In reply to comment #43)
> Kernel 2.6.30 fixes the bug for me. But I'm using it only for playing
> media. When I need to use Internet, I'm booting a stable (2.6.29)
> kernel.
I use it for every thing without problem

> 
> 
> Finally a reflexion: Having no media (video/audio) at Summer, is like
> having no toys at Christmas. Do you see the point? What I mean is 
> that I think this bug should have been marked as URGENT/CRITICAL, 
> since it affects all media playing. More than two months to solve 
> this bug is too much time. A normal user will have been 2 months with
> out media playing.
> 
> Hollywood will be happy ("all those fedora linux hackers couldn't 
> freely watch our films at Summer, muhahahahaha....") ;-)  
I did yum remove kernel-thatdoesn'twork so that grub booted directly on a kernel which worked...

Comment 45 Uno Engborg 2009-08-23 16:07:08 UTC
(In reply to comment #43)
> An easy way to install kernel 2.6.30:
> 
>   yum --enablerepo=updates-testing update '*kernel*'
> 
> Kernel 2.6.30 fixes the bug for me. But I'm using it only for playing
> media. When I need to use Internet, I'm booting a stable (2.6.29)
> kernel.
> 
> 
> Finally a reflexion: Having no media (video/audio) at Summer, is like
> having no toys at Christmas. Do you see the point? What I mean is 
> that I think this bug should have been marked as URGENT/CRITICAL, 
> since it affects all media playing. More than two months to solve 
> this bug is too much time. A normal user will have been 2 months with
> out media playing.
> 
> Hollywood will be happy ("all those fedora linux hackers couldn't 
> freely watch our films at Summer, muhahahahaha....") ;-)  


It looks like it works, I have tested on some quite long you tupe Android presentations without any problems.

However, It breaks compiz "Desktop Effects". When Desktop Effects is turned on, the mouse the computer freezes displaying just the desktop background and a frozen curser. I'm using Intel Corporation 82852/855GM Integrated Graphics Device (rev 02)  graphics. So it seams that it is not only nvidia that is problematic

Comment 46 Luya Tshimbalanga 2009-08-24 05:47:22 UTC
This kernel update fixed driver issue from Intel Corporation 82852/855GM that runs LG LT20. Unlike #45, Desktop Effects is working fine with wobble and cube mode enabled.

Comment 47 Josep 2009-08-24 07:50:02 UTC
Kernel 2.6.30.5-32.fc11.i686.PAE from testing fixes the problem here too.
The hardware is "Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) AC'97 Audio Controller (rev 03)".

Comment 48 rick 2009-08-24 09:14:18 UTC
another vote for kernel 2.6.30.5-32, audio works fine again, and the nvidia installer package installs perfectly. (NVIDIA-Linux-x86-185.18.14-pkg1.run)
i am using "Audio Adapter  ICH4 - Intel ICH5"
and an Nvidia GeForce 6200/AGP/SSE2 graphics card.

Comment 49 Jani Ollikainen 2009-08-24 10:41:16 UTC
Tested kernel-2.6.30.5-32.fc11.i586 and it works.

Some similar messages in messages log file, but the sound keeps working, tested with 1 hour of youtube/spotify(wine).

Aug 24 12:41:23 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 1.00 ms
Aug 24 12:41:26 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 2.00 ms
Aug 24 12:41:38 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 4.00 ms
Aug 24 12:41:47 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 8.00 ms
Aug 24 12:41:53 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 16.00 ms
Aug 24 12:42:55 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 26.00 ms
Aug 24 12:42:55 k5 pulseaudio[2157]: alsa-sink.c: Increasing wakeup watermark to 15.99 ms
Aug 24 12:47:11 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 36.00 ms
Aug 24 12:48:11 k5 pulseaudio[2157]: alsa-sink.c: Increasing wakeup watermark to 25.99 ms
Aug 24 12:56:29 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 46.00 ms
Aug 24 13:19:54 k5 pulseaudio[2157]: alsa-sink.c: Increasing wakeup watermark to 35.99 ms
Aug 24 13:23:32 k5 pulseaudio[2157]: alsa-sink.c: Increasing minimal latency to 56.00 ms

Comment 50 Lennart Poettering 2009-08-24 14:37:36 UTC
*** Bug 515121 has been marked as a duplicate of this bug. ***

Comment 51 Lennart Poettering 2009-08-24 14:41:48 UTC
*** Bug 518732 has been marked as a duplicate of this bug. ***

Comment 52 Colin.Simpson 2009-08-26 08:46:33 UTC
I'm seeing the same kind of messages with 2.6.30.4-25.fc11.x86_64 but sound keeps going:

Aug 25 11:17:56 localhost pulseaudio[405]: reserve-wrap.c: Failed to acquire reservation lock on device 'Audio0': Input/output error
Aug 25 11:18:00 localhost pulseaudio[405]: alsa-sink.c: Increasing wakeup watermark to 89.80 ms
Aug 25 11:18:01 localhost pulseaudio[405]: alsa-sink.c: Increasing wakeup watermark to 99.80 ms
Aug 25 11:18:03 localhost pulseaudio[405]: alsa-sink.c: Increasing wakeup watermark to 109.80 ms
Aug 25 11:18:04 localhost pulseaudio[405]: alsa-sink.c: Increasing wakeup watermark to 119.80 ms
Aug 25 11:20:48 localhost pulseaudio[405]: reserve-wrap.c: Failed to acquire reservation lock on device 'Audio0': Input/output error
Aug 25 11:20:52 localhost pulseaudio[405]: alsa-sink.c: Increasing wakeup watermark to 89.80 ms

Comment 53 Fedora Update System 2009-08-28 22:28:31 UTC
kernel-2.6.30.5-43.fc11 has been submitted as an update for Fedora 11.
http://admin.fedoraproject.org/updates/kernel-2.6.30.5-43.fc11

Comment 54 Ville Törhönen 2009-09-01 11:09:14 UTC
Tested kernel-2.6.30.5-43.fc11 and it seems to be working. Still seeing some "increasing wakeup watermark" messages, but everything works fine.

Comment 55 Martin Naď 2009-09-02 20:45:32 UTC
with kernel-2.6.30.5-43.fc11

Aug 31 20:41:13 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 20,00 ms
Aug 31 20:41:13 martin pulseaudio[1732]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Aug 31 20:41:13 martin pulseaudio[1732]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers.
Aug 31 20:41:13 martin pulseaudio[1732]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
Aug 31 20:41:18 martin pulseaudio[1732]: ratelimit.c: 18 events suppressed
Aug 31 20:41:18 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 30,00 ms
Aug 31 20:41:44 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 40,00 ms
Aug 31 20:46:58 martin yum: Installed: nerolinux-3.5.3.1-1.x86_64
Aug 31 20:47:18 martin pulseaudio[1732]: ratelimit.c: 19 events suppressed
Aug 31 20:47:18 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 50,00 ms
Aug 31 20:49:10 martin pulseaudio[1732]: ratelimit.c: 20 events suppressed
Aug 31 20:49:10 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 60,00 ms
Aug 31 20:49:19 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 70,00 ms
Aug 31 21:03:48 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 80,00 ms
Aug 31 21:20:31 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 90,00 ms
Aug 31 21:20:32 martin pulseaudio[1732]: alsa-sink.c: Increasing wakeup watermark to 100,00 ms

Comment 56 Petr Tuma 2009-09-04 12:00:43 UTC
*** Bug 520571 has been marked as a duplicate of this bug. ***

Comment 57 Fedora Update System 2009-09-06 20:44:09 UTC
kernel-2.6.30.5-43.fc11 has been pushed to the Fedora 11 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 58 antonio montagnani 2009-09-07 07:32:26 UTC
 
I don't know if it is connected but after some time od radio streaming, musinc stops and I get final messages from pulseaudio -vv

Requesting rewind due to corking
D: module-suspend-on-idle.c: Sink alsa_output.pci_8086_284b_sound_card_0 becomes idle.
I: module-suspend-on-idle.c: Sink alsa_output.pci_8086_284b_sound_card_0 idle for too long, suspending ...
I: alsa-sink.c: Device suspended...

System is fully updated to today, latest kernel installed, this system is ICH7 intel, but I am experiencing same issue on another system with different chips ICH5

Comment 59 antonio montagnani 2009-09-07 07:47:19 UTC
sorry, it is an ICH7 chip

Comment 60 antonio montagnani 2009-09-07 07:53:41 UTC
on another system with ICH5/ICH5R Ac97 audio controller, streaming stops (after 45 min) and I get:


D: protocol-native.c: Underrun on 'dialog-warning', 0 bytes in queue.
D: module-augment-properties.c: Looking for .desktop file for thunderbird-bin
D: alsa-sink.c: Requested volume: 0:  80% 1:  80%
D: alsa-sink.c: Got hardware volume: 0:  81% 1:  81%
D: alsa-sink.c: Calculated software volume: 0:  98% 1:  98%
D: alsa-sink.c: Latency set to 90,00ms
D: alsa-sink.c: hwbuf_unused=49660
D: alsa-sink.c: setting avail_min=14621
D: alsa-sink.c: Requested to rewind 65536 bytes.
D: alsa-sink.c: Limited to 8448 bytes.
D: alsa-sink.c: before: 2112
D: alsa-sink.c: after: 2112
D: alsa-sink.c: Rewound 8448 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 8448 bytes on render memblockq.
D: source.c: Processing rewind...
I: sink-input.c: Freeing input 5 "dialog-warning"
D: sink-input.c: Requesting rewind due to corking
D: module-suspend-on-idle.c: Sink alsa_output.pci_8086_24d5_sound_card_0 becomes idle.
I: module-suspend-on-idle.c: Sink alsa_output.pci_8086_24d5_sound_card_0 idle for too long, suspending ...
I: alsa-sink.c: Device suspended...
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockAcquired
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockAcquired
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockReleased
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockReleased
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockAcquired
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockAcquired
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=PropertyModified
D: module-hal-detect.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockReleased
D: module-console-kit.c: dbus: interface=org.freedesktop.Hal.Device, path=/org/freedesktop/Hal/devices/computer, member=InterfaceLockReleased

shall I open a different bug??

Comment 61 Lennart Poettering 2009-09-07 15:57:12 UTC
*** Bug 520230 has been marked as a duplicate of this bug. ***

Comment 62 Chris Nutt 2009-09-08 07:59:47 UTC
Kernel update has resolved my issue,

Comment 63 antonio montagnani 2009-09-08 13:44:29 UTC
breakages as per comment 58,59,60 have been solved by changing a parameter in /etc/pulse/daemon.conf - flat-volumes = no .

Hope it can help solve part of the problem

Comment 64 antonio montagnani 2009-09-08 14:26:32 UTC
(In reply to comment #63)
> breakages as per comment 58,59,60 have been solved by changing a parameter in
> /etc/pulse/daemon.conf - flat-volumes = no .
> 
> Hope it can help solve part of the problem  

unfortunately, I was too optimistic....it broke after 6.30 hours :-(

Comment 65 Josep 2009-09-08 15:33:30 UTC
Kernel 2.6.30.5-32.fc11.i686.PAE from testing solved the problem for me here. On the other hand the latest one from updates (2.6.30.5-43.fc11.i686.PAE), has introduced a problem with an application that runs under wine to play music:

The sound is chopped and seemigly playing much slowly than it should. I can sometimes play one song without a problem, but the second song will always be distorted. This is not a problem for other applications like rythmbox.
I don't see anything in /var/logs/messages other than the "Increasing wakeup watermark" that other people has already reported above.

This probably belongs to another bug report, but could it be related to this one? It must be due to something introduced between 2.6.30.5-32 and 2.6.30.5-43.

Comment 66 Peter Robinson 2009-09-08 15:38:36 UTC
Its much improved over 2.6.29 for me in that I actually have sound but its very quiet. Using the 2.6.31 kernel from rawhide makes it sound as loud as it should though.

Comment 67 Peter Robinson 2009-09-29 21:32:49 UTC
On Fedora 11 on my Dell D630 sound is now completely dead again using kernel 2.6.30.5-43.fc11.x86_64

Comment 68 Jessica Sterling 2009-10-03 17:31:58 UTC
Updating to kernel 2.6.30.8-64.fc11.i586 has resolved the issue for me.

Comment 69 Jesse Keating 2009-10-21 22:16:19 UTC
Can anybody with these problems try the latest Fedora 12 kernel, as this is on a Fedora 12 blocker list.

Comment 70 Adam Williamson 2009-10-23 15:56:52 UTC
I don't see any report on here for F12, in fact, nor do any of the duplicates seem to be from F12 testing. I'm going to take this off the F12Blocker list as we're shadow-boxing at the moment. If anyone experiences this problem on F12, please file a new bug and set it to block the bug 'F12Blocker' (Lennart, if you're aware of anyone hitting this in F12, please do that!)

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

Comment 71 Lennart Poettering 2009-10-23 19:14:21 UTC
I think this one actually got fixed by now, so I'd suggest closing this and if someone manages to reproduce this he should open a new bug or even reopen this one.

Comment 72 Sebastian Paul Avarvarei 2010-01-13 22:38:13 UTC
I just installed Fedora 12 and my log is flooded every 5 seconds with:

Jan 13 23:27:28 hermes pulseaudio[2446]: ratelimit.c: 157 events suppressed
Jan 13 23:27:33 hermes pulseaudio[2446]: ratelimit.c: 162 events suppressed
Jan 13 23:27:38 hermes pulseaudio[2446]: ratelimit.c: 160 events suppressed
Jan 13 23:27:43 hermes pulseaudio[2446]: ratelimit.c: 157 events suppressed
Jan 13 23:27:48 hermes pulseaudio[2446]: ratelimit.c: 162 events suppressed

I'm not sure what's causing this, as currently I don't even have speakers connected to the PC. I did notice that it stopped when I stopped the mail-notification application, but when I restarted the application the error messages didn't show up again in the log.

Comment 73 Robert Townley 2010-04-28 23:16:13 UTC
ALSA-driver-snd_intel8x0

2.6.30.10-105.2.23.fc11.i586 #1 SMP Thu Feb 11 06:51:26 UTC 2010 i686 i686 i386 GNU/Linux
Multimedia audio controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) AC'97 Audio Controller (rev 03)

lspci -vv
00:1e.2 Multimedia audio controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) AC'97 Audio Controller (rev 03)
	Subsystem: Hewlett-Packard Company Device 300d
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0
	Interrupt: pin A routed to IRQ 21
	Region 0: I/O ports at 1000 [size=256]
	Region 1: I/O ports at 1400 [size=64]
	Region 2: Memory at cfdc0400 (32-bit, non-prefetchable) [size=512]
	Region 3: Memory at cfdc0600 (32-bit, non-prefetchable) [size=256]
	Capabilities: [50] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
	Kernel driver in use: Intel ICH
	Kernel modules: snd-intel8x0


/var/log/messages:
Apr 28 17:49:20 ec239dict kernel: usb 4-1: reset low speed USB device using uhci_hcd and address 2
Apr 28 17:49:20 ec239dict kernel: ata1.00: configured for MWDMA2
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 443160 bytes (2512 ms).
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers.
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c: snd_pcm_dump():
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c: Hardware PCM card 0 'Intel ICH6' device 0 subdevice 0
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c: Its setup is:
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   stream       : PLAYBACK
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   access       : MMAP_INTERLEAVED
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   format       : S16_LE
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   subformat    : STD
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   channels     : 2
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   rate         : 44100
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   exact rate   : 44100 (44100/1)
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   msbits       : 16
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   buffer_size  : 16384
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   period_size  : 16384
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   period_time  : 371519
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   tstamp_mode  : ENABLE
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   period_step  : 1
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   avail_min    : 16384
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   period_event : 0
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   start_threshold  : -1
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   stop_threshold   : 1073741824
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   silence_threshold: 0
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   silence_size : 0
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   boundary     : 1073741824
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   appl_ptr     : 169613824
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-util.c:   hw_ptr       : 169708230
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-sink.c: Increasing minimal latency to 1.00 ms
Apr 28 17:49:20 ec239dict kernel: Restarting tasks ... done.
Apr 28 17:49:20 ec239dict pulseaudio[2385]: alsa-sink.c: snd_pcm_rewind() failed: File descriptor in bad state

Comment 74 Robert Townley 2010-04-29 01:50:37 UTC
alsa-info HP DC 5100 SFF: 
http://www.alsa-project.org/db/?f=f6ee9e12ef8761fc90a463a71cbf77dd42703b74

i mixed up my FC11 and FC12 machines.  All will be on FC12 soon and will repost then.