Bug 497615 - Pulseaudio figuring at the top in powertop output
Summary: Pulseaudio figuring at the top in powertop output
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: pulseaudio
Version: 10
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
Assignee: Lennart Poettering
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-04-25 05:49 UTC by Amit Shah
Modified: 2009-04-30 20:29 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-04-30 20:29:40 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Amit Shah 2009-04-25 05:49:10 UTC
Description of problem:

Powertop output:

     PowerTOP version 1.10      (C) 2007 Intel Corporation

Cn                Avg residency       P-states (frequencies)
C0 (cpu running)        (54.7%)         2.41 Ghz    51.2%
C0                0.0ms ( 0.0%)         2.40 Ghz     0.2%
C1                0.0ms ( 0.0%)         1.60 Ghz     0.0%
C2                0.0ms ( 0.2%)          800 Mhz    48.6%
C4                0.8ms (45.1%)

Wakeups-from-idle per second : 598.9    interval: 10.0s
no ACPI power usage estimate available

Top causes for wakeups:
  34.3% (312.9)        pulseaudio : __mod_timer (process_timeout)
  26.2% (238.8)        pulseaudio : sys_timer_settime (posix_timer_fn)
  13.3% (121.2)       <interrupt> : PS/2 keyboard/mouse/touchpad
  11.2% (101.8)           firefox : futex_wait (hrtimer_wakeup)
   4.1% ( 37.1)      <kernel IPI> : Rescheduling interrupts
   3.0% ( 27.0)       <interrupt> : uhci_hcd:usb3, eth0
   2.5% ( 23.1)          knotify4 : __mod_timer (process_timeout)
   1.8% ( 16.8)       <interrupt> : ahci, uhci_hcd:usb6, i915@pci:0000:00:02.0
   1.2% ( 11.1)           konsole : __mod_timer (process_timeout)
   0.6% (  5.4)       <interrupt> : uhci_hcd:usb7, HDA Intel, iwlagn
   0.4% (  3.4)               ssh : mod_timer (tcp_write_timer)
   0.4% (  3.3)             kded4 : mod_timer (tcp_delack_timer)
   0.2% (  2.0)            amarok : __mod_timer (process_timeout)
   0.1% (  1.1)                 X : __mod_timer (process_timeout)
   0.1% (  1.0)           klipper : __mod_timer (process_timeout)
   0.1% (  1.0)   setroubleshootd : __mod_timer (process_timeout)
   0.1% (  0.6)                 X : queue_delayed_work (delayed_work_timer_fn)
   0.1% (  0.5)               gpm : do_nanosleep (hrtimer_wakeup)
   0.1% (  0.5)    NetworkManager : mod_timer (e1000_watchdog)
   0.0% (  0.4)         gpg-agent : __mod_timer (process_timeout)
   0.0% (  0.3)            plasma : __mod_timer (process_timeout)
   0.0% (  0.2)          events/1 : mod_timer (dev_watchdog)
   0.0% (  0.2)    NetworkManager : __mod_timer (process_timeout)
   0.0% (  0.2)          kwalletd : __mod_timer (process_timeout)


I'm using F10 with KDE and gstreamer as the backend. No audio was playing when this snapshot was taken. pulseaudio's cpu utilisation is way above than even firefox!

This definitely hurts my battery life..

$ rpm -qa pulseaudio
pulseaudio-0.9.14-1.fc10.x86_64

$ rpm -qa kdebase
kdebase-4.2.2-3.fc10.x86_64

Comment 1 Lennart Poettering 2009-04-25 14:58:35 UTC
PA dynamically adjusts the wakeup intervals depending on how many drop outs you got and on the latency requirements of the clients connected to it.

If you get a drop-out PA will make sure it wakes up earlier next time to make sure you don't get those dropouts anymore. It will log that to syslog. COuld you please check if there's anything about that in your syslog?

Also, while PA initializes the sound card for 2s of buffer that could be used to bring the wakeups down to once per second the FC10 kernel does not allow that and artificially limits the buffer size to 64k (i.e. 370ms). This got fixed in the F11 kernel.

Please paste the output of "ls" in pacmd here when this happens. This should tell us what the latency requirements of the connected clients are and why the wakeup frequency got increased so much.

Comment 2 Amit Shah 2009-04-27 07:21:42 UTC
I switched the backend from gstreamer to xine and things were normal -- I don't have the pacmd ls output before the switch, sorry.. but I have this pulseaudio-specific output from the old /var/log/messages (the last one should be the interesting one):

Apr 25 09:39:04 amit-x200 pulseaudio[2860]: main.c: Called SUID root and real-time and/or high-priority scheduling was requested in the configuration. However, we lack the necessary privileges:
Apr 25 09:39:04 amit-x200 pulseaudio[2860]: main.c: We are not in group 'pulse-rt', PolicyKit refuse to grant us the requested privileges and we have no increase RLIMIT_NICE/RLIMIT_RTPRIO resource limits.
Apr 25 09:39:04 amit-x200 pulseaudio[2860]: main.c: For enabling real-time/high-priority scheduling please acquire the appropriate PolicyKit privileges, or become a member of 'pulse-rt', or increase the RLIMIT_NICE/RLIMIT_RTPRIO resource limits for this user.
Apr 25 09:39:07 amit-x200 pulseaudio[2865]: alsa-util.c: Cannot find fallback mixer control "Mic".
Apr 25 09:39:08 amit-x200 pulseaudio[2886]: pid.c: Daemon already running.
Apr 25 09:40:03 amit-x200 acpid: client connected from 2947[0:0]
Apr 25 09:40:46 amit-x200 pulseaudio[3728]: pid.c: Stale PID file, overwriting.
Apr 25 09:40:46 amit-x200 pulseaudio[3728]: alsa-util.c: Cannot find fallback mixer control "Mic".

Apr 25 09:53:13 amit-x200 pulseaudio[3728]: 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 PulseAudio developers.

Comment 3 Lennart Poettering 2009-04-30 20:29:40 UTC
Those syslog messages shouldn't be much of a problem. They should not appear anymore on F11.

Since the problems seem to be gone I'll close this bug now. Feel free to reopen if the problem appears again and make sure to post the output of "ls" in pacmd then here! Thanks!


Note You need to log in before you can comment on or make changes to this bug.