Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 466530 - Hard CPU time limit exhausted, terminating forcibly.
Summary: Hard CPU time limit exhausted, terminating forcibly.
Keywords:
Status: CLOSED DUPLICATE of bug 462200
Alias: None
Product: Fedora
Classification: Fedora
Component: pulseaudio
Version: rawhide
Hardware: All
OS: Linux
medium
high
Target Milestone: ---
Assignee: Lennart Poettering
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: F10DesktopBlocker
TreeView+ depends on / blocked
 
Reported: 2008-10-10 19:00 UTC by Mads Kiilerich
Modified: 2008-10-20 10:53 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2008-10-19 20:47:37 UTC
Type: ---
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Launchpad 237443 0 None None None Never

Description Mads Kiilerich 2008-10-10 19:00:08 UTC 
Description of problem:

pulseaudio dies because of exhaustion. Seen when flash playing from myspace. I think I have noticed on my load monitor that something starts eating cpu just before pulse dies.

I think my setup is quite normal and should work.

$ pulseaudio -v
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
I: caps.c: Dropping root priviliges.
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
I: main.c: We're in the group 'pulse-rt', allowing high-priority scheduling.
I: core-util.c: Successfully gained nice level -11.
I: main.c: Giving up CAP_NICE
I: main.c: This is PulseAudio 0.9.13
I: main.c: Page size is 4096 bytes
I: main.c: Machine ID is 7364f81f52869091316dde0046824401.
I: main.c: Using runtime directory /home/mk/.pulse/7364f81f52869091316dde0046824401:runtime.
I: main.c: Using state directory /home/mk/.pulse.
I: main.c: Running in system mode: no
I: main.c: Fresh high-resolution timers available! Bon appetit!
I: module-hal-detect.c: Trying capability alsa
I: module-alsa-sink.c: Successfully opened device front:0.
I: module-alsa-sink.c: Successfully enabled mmap() mode.
I: module-alsa-sink.c: Successfully enabled timer-based scheduling mode.
I: (alsa-lib)control.c: Invalid CTL front:0
I: alsa-util.c: Unable to attach to mixer front:0: No such file or directory
I: alsa-util.c: Successfully attached to mixer 'hw:0'
I: alsa-util.c: Using mixer control "Master".
I: sink.c: Created sink 0 "alsa_output.pci_8086_284b_sound_card_0_alsa_playback_0" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: source.c: Created source 0 "alsa_output.pci_8086_284b_sound_card_0_alsa_playback_0.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module-alsa-sink.c: Using 2 fragments of size 32768 bytes, buffer time is 371.52ms
I: module-alsa-sink.c: Time scheduling watermark is 20.00ms
I: module-alsa-sink.c: Volume ranges from 0 to 63.
I: module-alsa-sink.c: Volume ranges from -94.50 dB to 0.00 dB.
I: alsa-util.c: ALSA device lacks independant volume controls for each channel.
I: module-alsa-sink.c: Using hardware volume control. Hardware dB scale supported.
I: module-alsa-sink.c: Starting playback.
I: module.c: Loaded "module-alsa-sink" (index: #0; argument: "device_id=0 sink_name=alsa_output.pci_8086_284b_sound_card_0_alsa_playback_0 tsched=1").

...

I: module-alsa-sink.c: Underrun!
N: module-alsa-sink.c: Increasing wakeup watermark to 80.00 ms
Soft CPU time limit exhausted, terminating.
E: cpulimit.c: Recevied request to terminate due to CPU overload.
I: main.c: Daemon shutdown initiated.
I: module.c: Unloading "module-alsa-sink" (index: #0).
I: module-device-restore.c: Restoring volume for sink auto_null.
I: module-device-restore.c: Restoring mute state for sink auto_null.
I: sink.c: Created sink 1 "auto_null" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module-device-restore.c: Restoring volume for source auto_null.monitor.
I: module-device-restore.c: Restoring mute state for source auto_null.monitor.
I: source.c: Created source 2 "auto_null.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module.c: Loaded "module-null-sink" (index: #14; argument: "sink_name=auto_null").
I: protocol-native.c: Requested tlength=2040.00 ms, minreq=20.00 ms
I: module-rescue-streams.c: Sucessfully moved sink input 13 "Adobe Flash" to auto_null.
I: sink.c: Freeing sink 0 "alsa_output.pci_8086_284b_sound_card_0_alsa_playback_0"
I: source.c: Freeing source 0 "alsa_output.pci_8086_284b_sound_card_0_alsa_playback_0.monitor"
I: module.c: Unloaded "module-alsa-sink" (index: #0).
I: module.c: Unloading "module-alsa-source" (index: #1).
Hard CPU time limit exhausted, terminating forcibly.
Aborted


I assume this is OK:
$ tail /etc/security/limits.conf

# End of file

## Automatically appended by jack-audio-connection-kit
@jackuser - rtprio 20
@jackuser - memlock 4194304

## Automatically appended by jack-audio-connection-kit
@pulse-rt - rtprio 20
@pulse-rt - nice -20


https://bugs.launchpad.net/ubuntu/+source/pulseaudio/+bug/202089 might be similar ...


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

pulseaudio-libs-0.9.13-2.fc10.i386
pulseaudio-module-x11-0.9.13-2.fc10.i386
pulseaudio-esound-compat-0.9.13-2.fc10.i386
pulseaudio-module-gconf-0.9.13-2.fc10.i386
pulseaudio-0.9.13-2.fc10.i386
pulseaudio-utils-0.9.13-2.fc10.i386
pulseaudio-core-libs-0.9.13-2.fc10.i386
pulseaudio-libs-glib2-0.9.13-2.fc10.i386
gstreamer-plugins-pulse-0.9.7-1.fc10.i386
xine-lib-pulseaudio-1.1.15-1.fc10.1.i386
alsa-plugins-pulseaudio-1.0.18-1.rc3.fc10.i386
flash-plugin-9.0.124.0-release.i386
libflashsupport-000-0.5.svn20070904.i386
nspluginwrapper-1.1.0-11.fc10.i386
kernel-2.6.27-1.fc10.i686

How reproducible:

happened a couple of times after half en hour
Comment 1 Matt Hirsch 2008-10-14 20:32:59 UTC 
I also experience this bug. I'm running Fedora 9 x86_64, fully updated:

kernel-2.6.26.5-45.fc9.x86_64
pulseaudio-0.9.10-2.fc9.x86_64
alsa-plugins-pulseaudio-1.0.16-4.fc9.x86_64
alsa-utils-1.0.17-2.fc9.x86_64
alsa-lib-1.0.17-2.fc9.x86_64

After running for awhile, the pulseaudio daemon dies. If I restart it on the terminal, after awhile I get this:

Soft CPU time limit exhausted, terminating.
Hard CPU time limit exhausted, terminating forcibly.
Aborted

This may be related to the adobe flash player crashing (which seems to happen a lot on my system). However, it does not happen every time the flash player crashes, nor does the flash player crash every time it happens.

I haven't changed the default pulseaudio configuration, though I upgraded the system from F7 -> F8 -> F9 through yum update.
Comment 2 Matt Hirsch 2008-10-14 20:36:52 UTC 
http://www.pulseaudio.org/ticket/207

This pulseaudio bug may be related. 

Why isn't the pulseaudio bugtracker an option in external bugs in bugzilla?
Comment 3 Mads Kiilerich 2008-10-14 23:39:22 UTC 
Matthew:

I am quite sure that I have seen the problem on an un-resumed machine.

I also thought this (or a similar) problem was related to flash. But the problem has also appeared without flash or nspluginwrapper running, just pidgin and rhythmbox playing ogg.

I don't know how much the audio infrastructure has changed between f9 and f10, but I don't think we should assume that they have similar problems.
Comment 4 Matt Hirsch 2008-10-15 00:51:49 UTC 
I never suspend or hibernate my machine, and I still get this problem. Since the symptom is so similar it seems reasonable that they are related problems.
Comment 5 Matthias Clasen 2008-10-16 00:43:22 UTC 
I am seeing this problem too. pulseaudio commits suicide after playing ~ 1 cd worth of music in rhythmbox. The only other client open was pavucontrol. 

Full log of pa -vvv available upon request.
Comment 6 Mads Kiilerich 2008-10-16 01:15:32 UTC 
This is perhaps the same as or related to

Bug 466316 - Daemon hangs, starts eating up CPU cycles, rhythmbox freezes 
Bug 466338 -  I: memblock.c: Pool full
Comment 7 Mads Kiilerich 2008-10-16 15:45:52 UTC 
I just got
Oct 16 17:33:21 dev-mk pulseaudio[3265]: cpulimit.c: Recevied request to terminate due to CPU overload.

That was when playing an ogg from rhythmbox. flash-plugin not installed. (livna plugins is installed but not used.) Rhythmbox was hanging and didn't redraw after that. I assume that that is a rhythmbox bug ...

5 seconds before the suicide something (the pulseaudio process, I assume) started using 100% of one cpu (on my dual-core system). So the problem isn't that pulseaudio terminates, but that it starts using all cpu.

With log-level = debug nothing was logged when it started eating cpu.

I am setting the severity to high.
Comment 8 Lennart Poettering 2008-10-17 10:38:30 UTC 
Which driver is this?
Comment 9 Mads Kiilerich 2008-10-17 12:48:12 UTC 
I don't know how to answer that - does the following answer it?

==> /proc/asound/modules <==
 0 snd_hda_intel

==> /proc/asound/card0/codec#0 <==
Codec: Analog Devices AD1983
Address: 0
Vendor Id: 0x11d41983
Subsystem Id: 0x102801da
Revision Id: 0x100400
No Modem Function Group found
Default PCM:
    rates [0x7f]: 8000 11025 16000 22050 32000 44100 48000
    bits [0xe]: 16 20 24
    formats [0x1]: PCM
Comment 10 Lennart Poettering 2008-10-19 20:34:58 UTC 
Yes it does.

Could you please generate a bit of profiling for me? 

http://pulseaudio.org/wiki/HowToUseOProfile

This will help me understand where exactly PA starts to spin in a 100%-CPU-Loop.

Please make sure to run the newest kernel from rawhide when doing this.
Comment 11 Lennart Poettering 2008-10-19 20:47:37 UTC 
Oh and this actually looks like yet another dupe of 462200...

*** This bug has been marked as a duplicate of bug 462200 ***
Comment 12 Mads Kiilerich 2008-10-20 10:53:21 UTC 
I can confirm that with the latest updates it seems to work a lot better.

Stressing the machine still gives

Oct 20 12:03:37 dev-mk pulseaudio[3360]: protocol-native.c: Requested tlength=200.00 ms, minreq=10.00 ms
Oct 20 12:03:37 dev-mk pulseaudio[3360]: protocol-native.c: Final latency 380.00 ms = 180.00 ms + 2*10.00 ms + 180.00 ms
Oct 20 12:30:51 dev-mk kernel: [drm] Num pipes: 1
Oct 20 12:31:14 dev-mk pulseaudio[3360]: module-alsa-sink.c: Underrun!
Oct 20 12:31:14 dev-mk pulseaudio[3360]: module-alsa-sink.c: Increasing wakeup watermark to 40.00 ms
Oct 20 12:31:14 dev-mk pulseaudio[3360]: module-alsa-sink.c: Underrun!
Oct 20 12:31:14 dev-mk pulseaudio[3360]: module-alsa-sink.c: Increasing wakeup watermark to 80.00 ms
Oct 20 12:31:24 dev-mk pulseaudio[3360]: module-alsa-sink.c: Device suspended...
Oct 20 12:32:03 dev-mk pulseaudio[3360]: sink-input.c: Freeing input 12 "'Last Night When We Were Young' by 'Caroline Henderson'"
Oct 20 12:32:11 dev-mk pulseaudio[3360]: client.c: Freed 20 "Rhythmbox"
Oct 20 12:32:11 dev-mk pulseaudio[3360]: protocol-native.c: Connection died.
Oct 20 12:32:30 dev-mk pulseaudio[3360]: client.c: Created 21 "Native client (UNIX socket client)"
Oct 20 12:32:30 dev-mk pulseaudio[3360]: protocol-native.c: Got credentials: uid=500 gid=500 success=1
Oct 20 12:32:39 dev-mk pulseaudio[3360]: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:Rhythmbox.
Oct 20 12:32:39 dev-mk pulseaudio[3360]: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:Rhythmbox.
Oct 20 12:32:39 dev-mk pulseaudio[3360]: module-alsa-sink.c: Trying resume...
Oct 20 12:32:40 dev-mk pulseaudio[3360]: (alsa-lib)conf.c: Unknown parameters 0
Oct 20 12:32:40 dev-mk pulseaudio[3360]: (alsa-lib)pcm.c: Unknown PCM front:0
Oct 20 12:32:40 dev-mk pulseaudio[3360]: module-alsa-sink.c: Error opening PCM device front:0: Invalid argument
Oct 20 12:32:40 dev-mk pulseaudio[3360]: resampler.c: Forcing resampler 'copy', because of fixed, identical sample rates.
Oct 20 12:32:40 dev-mk pulseaudio[3360]: resampler.c: Using resampler 'copy'
Oct 20 12:32:40 dev-mk pulseaudio[3360]: resampler.c: Using float32le as working format.
Oct 20 12:32:40 dev-mk pulseaudio[3360]: sink-input.c: Created input 13 "Playback Stream" on alsa_output.pci_8086_284b_sound_card_0_alsa_playback_0 with sample spec float32le 2ch 44100Hz and channel map front-left,front-right
Oct 20 12:32:40 dev-mk pulseaudio[3360]: protocol-native.c: Requested tlength=200.00 ms, minreq=10.00 ms
Oct 20 12:32:40 dev-mk pulseaudio[3360]: protocol-native.c: Final latency 380.00 ms = 180.00 ms + 2*10.00 ms + 180.00 ms
Oct 20 12:32:50 dev-mk pulseaudio[3360]: sink-input.c: Assertion 'i->thread_info.rewrite_nbytes == 0' failed at pulsecore/sink-input.c:1147, function pa_sink_input_request_rewind(). Aborting.

Which causes Rhythmbox to hang.

Is an oprofile interesting in that situation too?
Note You need to log in before you can comment on or make changes to this bug.