pulseaudio produces lots of log messages

I got the same messages, and also with serious glitches.

 0 [Intel ]: HDA-Intel - HDA Intel
                      HDA Intel at 0xfc400000 irq 22

It is probably an alsa bug and no pulseaudio bug.

Please execute the alsa-info.sh script referenced from https://wiki.ubuntu.com/DebuggingSoundProblems and attach the URL here.

ok, I put mine.
Or in this url: http://www.alsa-project.org/db/?f=0e66ab0764eee50630c23e60a8a5a7be0d32f062

And here is mine.

The message in my syslog is a little bit different:

pulseaudio[3847]: module-alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail_update() returned 0.

any news on this? some log files (syslog, user.log) are getting quite big ~130MB each

This bug seems fixed for me.

I can confirm this bug still occurring with me on version:

pulseaudio 0.9.14-0ubuntu1

My logs files are growing at a huge rate, I actually ran out of space on my / partition because of it, 2 logs files had reached ~500MB just in a few hours of use.

sorry, above version was meant to say pulseaudio 0.9.14-0ubuntu11

This started happening to me too after last update (or the update before?) when playing back on the X-Fi, not however when using the onboard nVidia device on 64 bit Jaunty.

The onboard device:

        *-multimedia
             description: Audio device
             product: MCP55 High Definition Audio
             vendor: nVidia Corporation
             physical id: f.1
             bus info: pci@0000:00:0f.1
             version: a2
             width: 32 bits
             clock: 66MHz
             capabilities: pm msi ht bus_master cap_list
             configuration: driver=HDA Intel latency=0 maxlatency=5 mingnt=2 module=snd_hda_intel

X-Fi:

           *-multimedia
                description: Multimedia audio controller
                product: SB X-Fi
                vendor: Creative Labs
                physical id: 6
                bus info: pci@0000:05:06.0
                version: 00
                width: 64 bits
                clock: 33MHz
                capabilities: pm msi bus_master cap_list
                configuration: driver=CTALSA latency=32 maxlatency=5 mingnt=4 module=ctxfi

Not fixed for me.

My / just filled. I went to investigate and found ~1.3 GB of stuff in /var/log/{syslog,user.log}.

0.9.14-0ubuntu11 amd64

Why thanks to the dupe, but my bug was revolving about the fact that pulseaudio doesn't do any kind of limiting on its output and will gladly DoS a system in an error-condition by attempting to flood the disk (since it cannot reach CPU quota due to the syslog eating just as much)

I don't know if this is related, but generally soon after a spew of the exceptionally large messages I got a :
Mar 15 17:27:37 davros kernel: [60005.939939] pulseaudio[19179]: segfault at 7f610fe23fa0 ip 00007f610fe23fa0 sp 00007fff20ad0c48 error 4 in module-null-sink.so[7f611064a000+3000]

( a few addresses), both accompanied by no sound/popping spitting instead of appropriate sound from both flash and rhythmbox.

On pulse: 0.9.14-0ubuntu11, kernel 2.6.28-9-generic #31-Ubuntu

Dave

http://www.alsa-project.org/db/?f=3791a7f441d84a0b9219aa6e3ebc24e598223403

ls -l /var/log/{user.log,user.log.0,syslog,syslog.0}
-rw-r----- 1 syslog adm 990222027 2009-03-15 21:00 /var/log/syslog
-rw-r----- 1 syslog adm 450560772 2009-03-15 08:10 /var/log/syslog.0
-rw-r----- 1 syslog adm 990206019 2009-03-15 18:47 /var/log/user.log
-rw-r----- 1 syslog adm 450442201 2009-03-14 20:04 /var/log/user.log.0

wc -l /var/log/{user.log,user.log.0,syslog,syslog.0}
   3976731 /var/log/user.log
   1808171 /var/log/user.log.0
   3976868 /var/log/syslog
   1809387 /var/log/syslog.0

Logs are flooded with PA lines...

This bug was fixed in the package pulseaudio - 0.9.14-0ubuntu12

---------------
pulseaudio (0.9.14-0ubuntu12) jaunty; urgency=low

  * 0091_workaround_alsa_horkage.patch:
    - Lower severity of logging level to prevent DoS on syslog
      LP: #320875, #343254
      LP #330814

 -- Daniel T Chen <email address hidden> Sat, 14 Mar 2009 22:39:03 -0400

http://www.alsa-project.org/db/?f=f59c789992dd1c941229ef17d9857c3ffc5027cb

The update to 0.9.14-0ubuntu13 solved the log file problem for me, however i had to add myself to the pulse-rt group to successfully play any sounds.

released in jaunty's -11.38

In Karmic, on an asus eee pc 1000he, I found these messages in user.log:

Nov 30 13:32:10 jason-laptop pulseaudio[2062]: ratelimit.c: 3 events suppressed
Nov 30 13:35:51 jason-laptop pulseaudio[2062]: ratelimit.c: 1 events suppressed
Nov 30 13:36:02 jason-laptop pulseaudio[2062]: ratelimit.c: 1 events suppressed
Nov 30 17:19:37 jason-laptop pulseaudio[2062]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Nov 30 17:19:37 jason-laptop pulseaudio[2062]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Nov 30 17:19:37 jason-laptop pulseaudio[2062]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
Nov 30 17:19:42 jason-laptop pulseaudio[2062]: ratelimit.c: 5 events suppressed

alsa info is here: http://www.alsa-project.org/db/?f=ef88cd888465f48493fcaf38355876a35a621cd1

in Karmic (9.10) kernel 2.6.31-20-generic on a HP Mini 110c 1011SO

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

Also getting loads of these messages:

MONTH DATE HH:MM:SS kenneth-netbook pulseaudio[2147]: ratelimit.c: X events suppressed

---------------------------------------------------------------------------------------------------------------
aplay -l

**** List of PLAYBACK Hardware Devices ****
card 0: Intel [HDA Intel], device 0: STAC92xx Analog [STAC92xx Analog]
  Subdevices: 0/1
  Subdevice #0: subdevice #0
---------------------------------------------------------------------------------------------------------------

lsmod | grep snd

snd_hda_codec_idt 59876 1
snd_hda_intel 26920 4
snd_hda_codec 75708 2 snd_hda_codec_idt,snd_hda_intel
snd_hwdep 7200 1 snd_hda_codec
snd_pcm_oss 37920 0
snd_mixer_oss 16028 1 snd_pcm_oss
snd_pcm 75296 4 snd_hda_intel,snd_hda_codec,snd_pcm_oss
snd_seq_dummy 2656 0
snd_seq_oss 28576 0
snd_seq_midi 6464 0
snd_rawmidi 22176 1 snd_seq_midi
snd_seq_midi_event 6940 2 snd_seq_oss,snd_seq_midi
snd_seq 50224 6 snd_seq_dummy,snd_seq_oss,snd_seq_midi,snd_seq_midi_event
snd_timer 22276 2 snd_pcm,snd_seq
snd_seq_device 6920 5 snd_seq_dummy,snd_seq_oss,snd_seq_midi,snd_rawmidi,snd_seq
snd 59204 19 snd_hda_codec_idt,snd_hda_intel,snd_hda_codec,snd_hwdep,snd_pcm_oss,snd_mixer_oss,snd_pcm,snd_seq_oss,snd_rawmidi,snd_seq,snd_timer,snd_seq_device
soundcore 7264 1 snd
snd_page_alloc 9156 2 snd_hda_intel,snd_pcm
---------------------------------------------------------------------------------------------------------------

/proc/asound/card0/codec#0:Codec: IDT 92HD81B1X5
/proc/asound/card0/codec#0:Vendor Id: 0x111d7605
/proc/asound/card0/codec#0:Subsystem Id: 0x103c308f
/proc/asound/card0/codec#0:Revision Id: 0x100402

bug is there in lucid on march, 28 2010, with fresh updates

syslog:

Mar 28 11:05:22 infrared pulseaudio[1456]: alsa-util.c: Disabling timer-based scheduling because high-resolution timers are not available from the kernel.
Mar 28 11:05:22 infrared rtkit-daemon[1320]: Sucessfully made thread 1469 of process 1456 (n/a) owned by '1000' RT at priority 5.
Mar 28 11:05:22 infrared rtkit-daemon[1320]: Supervising 5 threads of 2 processes of 2 users.
Mar 28 11:05:22 infrared pulseaudio[1456]: alsa-util.c: Disabling timer-based scheduling because high-resolution timers are not available from the kernel.
Mar 28 11:05:22 infrared pulseaudio[1456]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Mar 28 11:05:22 infrared pulseaudio[1456]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Mar 28 11:05:22 infrared pulseaudio[1456]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.

#######################################################################
$ pulseaudio --version
pulseaudio 0.9.21-63-gd3efa-dirty

$ uname -a
Linux infrared 2.6.32-17-generic #26-Ubuntu SMP Sat Mar 20 02:23:45 UTC 2010 x86_64 GNU/Linux

$ lspci |grep Audio
00:1b.0 Audio device: Intel Corporation N10/ICH 7 Family High Definition Audio Controller (rev 01)

$ aplay -l
**** Liste der Hardware-Geräte (PLAYBACK) ****
Karte 0: Intel [HDA Intel], Gerät 0: ALC662 rev1 Analog [ALC662 rev1 Analog]
  Sub-Geräte: 0/1
  Sub-Gerät #0: subdevice #0

$ lsmod | grep snd
snd_hda_codec_realtek 278794 1
snd_hda_intel 25517 5
snd_hda_codec 85727 2 snd_hda_codec_realtek,snd_hda_intel
snd_hwdep 6924 1 snd_hda_codec
snd_pcm_oss 41394 0
snd_mixer_oss 16299 1 snd_pcm_oss
snd_pcm 87850 4 snd_hda_intel,snd_hda_codec,snd_pcm_oss
snd_seq_dummy 1782 0
snd_seq_oss 31219 0
snd_seq_midi 5829 0
snd_rawmidi 23388 1 snd_seq_midi
snd_seq_midi_event 7267 2 snd_seq_oss,snd_seq_midi
snd_seq 57417 6 snd_seq_dummy,snd_seq_oss,snd_seq_midi,snd_seq_midi_event
snd_timer 23553 3 snd_pcm,snd_seq
snd_seq_device 6824 5 snd_seq_dummy,snd_seq_oss,snd_seq_midi,snd_rawmidi,snd_seq
snd 70978 20 snd_hda_codec_realtek,snd_hda_intel,snd_hda_codec,snd_hwdep,snd_pcm_oss,snd_mixer_oss,snd_pcm,snd_seq_oss,snd_rawmidi,snd_seq,snd_timer,snd_seq_device
soundcore 8052 1 snd
snd_page_alloc 8660 2 snd_hda_intel,snd_pcm

I'm not seeing those on Lucid, I'm seeing a different set:

Mar 27 12:04:19 major pulseaudio[1969]: pid.c: Daemon already running.
Mar 27 12:10:18 major pulseaudio[1789]: ratelimit.c: 4 events suppressed
Mar 27 13:25:03 major pulseaudio[1789]: ratelimit.c: 650 events suppressed
Mar 27 13:33:25 major pulseaudio[1789]: ratelimit.c: 22 events suppressed
Mar 27 13:33:37 major pulseaudio[1789]: ratelimit.c: 26 events suppressed
Mar 27 13:33:49 major pulseaudio[1789]: ratelimit.c: 198 events suppressed
Mar 27 13:34:11 major pulseaudio[1789]: ratelimit.c: 34 events suppressed
Mar 27 13:34:50 major pulseaudio[1789]: ratelimit.c: 210 events suppressed

Hi,

My Ubuntu 10.04 LTS also flood with the same message. i don't why no one is fixing this bug......
Regards,
Vipin Balakrishnan.

I have the same bug but when I added "autospawn=no" to /etc/pulse/client.conf then pulseaudio crashes and doesn't come back and it solves the problem.

However certain games and apps can't play sound now. And if I start pulseaudio manually I get that error message on the console where pulseaudio is running.

FIX THIS please. There has been nothing with trouble on my Eee 1000 since pulseaudio was introduced in 9.04 if I remember it right.

This bug has been filling my logs for a couple of releases now.

Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 4 is less than avail 6.
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers.
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: snd_pcm_dump():
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: Hardware PCM card 2 'Intel ICH5' device 0 subdevice 0
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: Its setup is:
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: stream : CAPTURE
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: access : MMAP_INTERLEAVED
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: format : S16_LE
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: subformat : STD
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: channels : 2
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: rate : 44100
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: exact rate : 44100 (44100/1)
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: msbits : 16
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: buffer_size : 16384
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: period_size : 16384
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: period_time : 371519
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: tstamp_mode : ENABLE
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: period_step : 1
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: avail_min : 16384
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: period_event : 0
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: start_threshold : -1
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: stop_threshold : 1073741824
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: silence_threshold: 0
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: silence_size : 0
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: boundary : 1073741824
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: appl_ptr : 9764858
Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: hw_ptr : 9764864
Oct 8 14:54:21 mike-desktop python: io/hpmud/pp.c 627: unable to read device-id ret=-1

>> Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 4 is less than avail 6.

>> Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: appl_ptr : 9764858
>> Oct 8 09:47:15 mike-desktop pulseaudio[1771]: alsa-util.c: hw_ptr : 9764864

can you set "log-time =yes" in pulse/daemon.conf so that timestamp is added and provide a test case which reproduce the problem with a full pulseaudio log

pulseaudio -k;pulseaudio -vvvvv

I seem to be getting errors in syslog

 [alsa-source] alsa-source.c: ALSA woke us up to read new data from the device, but there was actually nothing to read!
 [alsa-source] alsa-source.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
 [alsa-source] alsa-source.c: We were woken up with POLLIN set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.

alsa-info is here:http://www.alsa-project.org/db/?f=8897fd05b02e0e8a8e5f05ef753b4bed59bc4d9a

Hello from ubuntu 20.04, I found the same "ALSA woke us up....Most likely this is a bug in the ALSA driver 'snd_hda_intel'....." in syslog.

This bug was fixed 11 years ago. Please open a new bug for any new problem you are having.