Bug 506487

Summary: Dies shortly after starting
Product: [Fedora] Fedora Reporter: Bastien Nocera <bnocera>
Component: pulseaudioAssignee: Lennart Poettering <lpoetter>
Status: CLOSED WORKSFORME QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 11CC: bloch, lkundrak, lpoetter, wtogami
Target Milestone: ---Keywords: Reopened
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-26 14:36:00 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
pa.log.bz2
none
Pulseaudio log none

Description Bastien Nocera 2009-06-17 14:08:47 UTC
kernel-2.6.29.4-167.fc11.x86_64
pulseaudio-0.9.15-14.fc11.x86_64
gstreamer-plugins-good-0.10.15-1.fc11.x86_64

Bus 001 Device 005: ID 0ccd:0028 TerraTec Electronic GmbH Aureon 5.1 MkII

PA dies after less than 2 minutes of playback through rhythmbox:
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: ratelimit.c: 360 events suppressed
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: ratelimit.c: 512 events suppressed
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
W: asyncq.c: q overrun, queuing locally
Soft CPU time limit exhausted, terminating.
Hard CPU time limit exhausted, terminating forcibly.
Aborted

Comment 1 Lennart Poettering 2009-06-19 15:53:34 UTC
Hmpf. Culd you get me the full debug output of such a run? i.e. in a terminal "pulseaudio -vvvvv" and then paste that? Please don't truncate the output.

Comment 2 Lennart Poettering 2009-06-19 15:54:40 UTC
the "q overrun, queuing locally" stuff is usally because of a misbehaving client which doesn't process its messages quickly enough.

Comment 3 Bastien Nocera 2009-06-19 15:58:33 UTC
Created attachment 348680 [details]
pa.log.bz2

Compressed output of pulseaudio.

Comment 4 Bastien Nocera 2009-06-22 09:32:16 UTC
Passing --no-cpu-limit avoids the assertion, and works well. How can I monitor CPU usage over time?

Comment 5 Lennart Poettering 2009-06-29 12:53:07 UTC
(In reply to comment #4)
> Passing --no-cpu-limit avoids the assertion, and works well. How can I monitor
> CPU usage over time?  

Hmm, that GNOME system monitor applet? That monitors overall CPU load, but that should be good enough, shouldn't it?

Comment 6 Bastien Nocera 2009-07-22 04:03:43 UTC
Seems to work fine now...

Comment 7 Adam Huffman 2009-10-26 14:24:23 UTC
Just encountered this for the first time on an F11 system.  Have been trying to play a video file using both Totem and VLC.  In each case, the playback freezes after approximately 2-3 minutes.  Only then did I notice the multiple:

pulseaudio[2871]: asyncq.c: q overrun, queuing locally

errors in /var/log/messages.  I will post the output of pulseaudio -vvvv separately.

Comment 8 Adam Huffman 2009-10-26 14:30:06 UTC
Created attachment 366107 [details]
Pulseaudio log

Output of 'pulseaudio -vvvvv'

Comment 9 Adam Huffman 2009-10-26 14:31:08 UTC
There are also a couple of these in /var/log/messages:

Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 6377097072356602472 bytes (326791809583 ms).
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: snd_pcm_dump():
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: Hooks PCM
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: Its setup is:
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   stream       : PLAYBACK
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   access       : MMAP_INTERLEAVED
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   format       : S16_LE
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   subformat    : STD
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   channels     : 2
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   rate         : 44100
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   exact rate   : 44100 (44100/1)
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   msbits       : 16
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   buffer_size  : 88192
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_size  : 44096
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_time  : 999909
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   tstamp_mode  : ENABLE
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_step  : 1
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   avail_min    : 87311
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_event : 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   start_threshold  : -1
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   stop_threshold   : 6205960286516543488
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   silence_threshold: 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   silence_size : 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   boundary     : 6205960286516543488
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: Slave: Hardware PCM card 2 'HDA ATI HDMI' device 3 subdevice 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c: Its setup is:
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   stream       : PLAYBACK
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   access       : MMAP_INTERLEAVED
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   format       : S16_LE
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   subformat    : STD
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   channels     : 2
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   rate         : 44100
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   exact rate   : 44100 (44100/1)
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   msbits       : 16
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   buffer_size  : 88192
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_size  : 44096
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_time  : 999909
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   tstamp_mode  : ENABLE
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_step  : 1
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   avail_min    : 87311
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   period_event : 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   start_threshold  : -1
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   stop_threshold   : 6205960286516543488
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   silence_threshold: 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   silence_size : 0
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   boundary     : 6205960286516543488
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   appl_ptr     : 181354
Oct 26 14:18:16 marcel pulseaudio[6686]: alsa-util.c:   hw_ptr       : 88196

Comment 10 Bastien Nocera 2009-10-26 14:36:00 UTC
(In reply to comment #7)
> Just encountered this for the first time on an F11 system.

Open your own bug...