Fast respawning when module-alsa-sink can't be loaded

[Joshua Solomon]

Ah, got it. Pulseaudio won't start (under my user's account) because of:

E: module.c: Failed to load module "module-alsa-sink" (argument: "device=plughw:0 rate=44100"): initialization failed.
E: main.c: Module load failed.
E: main.c: Failed to initialize daemon.

And that module was specified in ~/.pulse/default.pa, which is a leftover from the time when pulseaudio wasn't working and I was trying to do something about it.

So I deleted ~/.pulse/default.pa, stopped pulseaudio that was started by hand and polkitd is still behaving perfectly fine. Even the music is playing, although I have no pulseaudio running. :-)

Then I killed polkitd and it wasn't restarted. So I started pulseudio by hand (from my user's account) and then polkitd appeared. It's peacefully sleeping in poll() and isn't leaking memory.

--

Original report:

Binary package hint: policykit-1

Upon upgrading to the new build of Lucid, a problem I thought I had fixed with policykit has reappeared. i am getting high CPU usage and a memory leak from the process polkitd, run under policykit-1. Upon boot and logging into a fresh account, I get no problems, but once I log into my main account, the problem appears. Logging out and back into the fresh account carries the problem over to the fresh account as well. I noticed that there were three carry-over processes from the main account: indicator-sound, pulseaudio, and the root process polkitd. I thought I had fixed this through removing respawnable hidden directories in my home folder, but that hasn't worked this time.

ProblemType: Bug
DistroRelease: Ubuntu 10.04
Package: policykit-1 0.96-2
ProcVersionSignature: Ubuntu 2.6.32-21.32-generic 2.6.32.11+drm33.2
Uname: Linux 2.6.32-21-generic i686
NonfreeKernelModules: nvidia
Architecture: i386
Date: Mon Apr 26 00:17:42 2010
ExecutablePath: /usr/lib/policykit-1/polkitd
ProcEnviron:

SourcePackage: policykit-1

[The Fold (stuart-luscombe)]

I've found that by running 'rm -rf .*' in my home directory and rebooting that the problem has gone away.

Mine's a non-essential box though, so I wouldn't recommend a blanket delete like that to everyone.

[Joshua Solomon (jdsbluedevl)]

Yeah, I essentially had to do the same. Moving a single directory was impossible, as it tended to be multiple directories that caused it. First, I dragged out the non-system hidden files, then the system hidden files. Next, I restarted and moved back everything except these hidden directories:
.g-streamer-0.10
.metacity
.themes
.thumbnails
.update-notifier
.dbus
I probably could have moved these back, but I didn't want to take the risk, especially when the respawned directories work pretty well.
That pretty much takes care of the pulseaudio problem as well.

[Paul Gortmaker (paul-gortmaker)]

I had polkitd eat through all RAM and swap (approx 6G total) and trigger oom-killer on firefox overnight.

Seeing the above, and being long overdue for a housecleaning of dot files/directories, I started with a clean dir and only migrated key stuff I use daily directly (i.e. .gitconfig, .thunderbird .mozilla etc) --- all system stuff like gconf etc was left behind and started with a new dir given by adduser (and chown'd appropriately). That didn't help -- as polkitd has already gone back to 3GB and counting. So the "make a new user" thing did nothing here. Also audio doesn't work (not sure if that is related) on this generic dell optiplex 760.

  PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
13077 root 20 0 3307m 3.2g 3084 S 16 55.6 74:50.09 polkitd

I attached strace to it and it generated about 4MB of output in just a few seconds; looks like it is repeating the same thing over and over. A snippet of the 4MB log is attached.

[James Westby (james-w)]

Hi,

It looks as though something may be continually querying polkit, which is probably
causing a slow memory leak to show itself much much faster.

Nothing should be querying it that frequently, so lets work out what is.

If you kill the polkitd process and then run

  sudo /usr/lib/policykit-1/polkitd

in a terminal you should get some debugging output to the console, could you record
that and attach it please?

Thanks,

James

[Sébastien Pierre (sebastien-type-z)]

Here is what I get

[James Westby (james-w)]

On Fri, 30 Apr 2010 14:39:48 -0000, Sébastien Pierre <email address hidden> wrote:
> Here is what I get

You failed to kill any existing polkitd processes.

This may be due to dbus activation and whatever is continually making
requests causing polkitd to be respawned before you can start polkitd.

Thanks,

James

[zwj (zwj-echo)]

I have the problem too. polkitd using 25% cpu and 20% mem.

I suspect
With Debug info:DEBUG: Dropping all .pkla caches for directory `/etc/polkit-1/localauthority/50-local.d
It seems that it rescan /etc/polkit-1/localauthority over and over again.

The system call is so frequently, that the output of the strace become 100M long , after a few miniute.
the attach is the output of
strace -r -s 200 -p xxx

this is the strace system call count in 5 minute
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
 56.60 0.179198 5 39594 poll
 13.59 0.043013 0 1247400 getdents
 13.02 0.041225 0 732600 open
  7.08 0.022428 0 732797 close
  4.48 0.014183 0 633600 write
  2.04 0.006455 0 227693 24746 read
  1.04 0.003308 0 59400 lstat
  0.63 0.001985 0 84150 fstat
  0.43 0.001372 0 19800 munmap
  0.35 0.001121 0 39600 lseek
  0.31 0.000977 0 19800 mmap
  0.23 0.000739 0 14850 writev
  0.19 0.000606 0 10256 267 stat
  0.00 0.000000 0 202 brk
  0.00 0.000000 0 197 socket
  0.00 0.000000 0 197 197 connect
  0.00 0.000000 0 1 restart_syscall
------ ----------- ----------- --------- --------- ----------------
100.00 0.316610 3862137 25210 total

[zwj (zwj-echo)]

may be this would be help:
Syslog: daemon.log
May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Supervising 1 threads of 1 processes of 1 users.
May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Sucessfully made thread 32184 of process 32184 (n/a) owned by '1000' high priority at nice level -11.
May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Supervising 1 threads of 1 processes of 1 users.
May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Sucessfully made thread 32187 of process 32187 (n/a) owned by '1000' high priority at nice level -11.
May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Supervising 1 threads of 1 processes of 1 users.
May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Warning: Reached burst limit for user '1000', denying request.
May 1 20:46:50 zwj-desktop rtkit-daemon[1343]: last message repeated 365 times
May 1 20:46:50 zwj-desktop rtkit-daemon[1343]: Sucessfully made thread 841 of process 841 (n/a) owned by '1000' high priority at nice level -11.

there are hundreds of thousands of lines like that in my daemon.log
It seems that my computer is creating process at an insane rate.However I can't stat what's the name of that process, it is created and destroyed so quickly that both top and System monitor can't trace it .

Any suggestion about how to get the name of that process. Now, I think it is that process causing the high load of polkitd

[James Westby (james-w)]

On Sat, 01 May 2010 13:02:27 -0000, zwj <email address hidden> wrote:
> may be this would be help:
> Syslog: daemon.log
> May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Supervising 1 threads of 1 processes of 1 users.
> May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Sucessfully made thread 32184 of process 32184 (n/a) owned by '1000' high priority at nice level -11.
> May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Supervising 1 threads of 1 processes of 1 users.
> May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Sucessfully made thread 32187 of process 32187 (n/a) owned by '1000' high priority at nice level -11.
> May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Supervising 1 threads of 1 processes of 1 users.
> May 1 20:46:31 zwj-desktop rtkit-daemon[1343]: Warning: Reached burst limit for user '1000', denying request.
> May 1 20:46:50 zwj-desktop rtkit-daemon[1343]: last message repeated 365 times
> May 1 20:46:50 zwj-desktop rtkit-daemon[1343]: Sucessfully made thread 841 of process 841 (n/a) owned by '1000' high priority at nice level -11.
>
> there are hundreds of thousands of lines like that in my daemon.log
> It seems that my computer is creating process at an insane rate.However I can't stat what's the name of that process, it is created and destroyed so quickly that both top and System monitor can't trace it .
>
> Any suggestion about how to get the name of that process. Now, I think
> it is that process causing the high load of polkitd

rtkit is only used by pulseaudio as far as I know, and that meshes with
a couple of other comments in the bug report.

Thanks,

James

[VasiaUVI (vasiauvi)]

I've deleted some .* folders and files from some applications that I've used before and unistaled and now the system is OK (I hope).

But I think that the problem was .pulse folder from pulse-audio. After deleting this folder my CPU was in the normal state. Looking inside the folder I've seen that were appearing some files and disappearing(like some services) very quickly!

After restarting the PC the CPU is fine and also the memory!

The idea is that the problem on my system was .pulse folder. After deleting this folder and also .dbus folder everything was OK.

[James Westby (james-w)]

Another duplicate shows rtkit querying repeatedly, so I am sure this is pulseaudio
related.

Thanks,

James

[James Westby (james-w)]

So, you should look at why pulseaudio is respawning so quickly, I would assume because
it is crashing on startup.

First stop it autospawning by editing /etc/pulse/client.conf and adding "autospawn = no".

Then stop any running pulseaudio with the "pulseaudio -k" command.

The run pulseaudio using "pulseaudio --start --daemonize=false -v" and see if there
are any interesting messages output.

Thanks,

James

[Dražen Kačar (dave-fly)]

I wanted to try your suggestion, and discovered I had no pulseaudio running. I edited /etc/pulse/client.conf, and then:

{lestat}~# pulseaudio -k
E: main.c: Failed to kill daemon: No such process
{lestat}~> ps -ef | grep pulse
dave 19336 5056 0 14:18 pts/1 00:00:00 grep pulse

Then I started pulseaudio (as root) and the leakage in polkitd stopped. polkitd is currently sleeping in poll() and isn't doing anything.

However, I don't know why pulseaudio wasn't started by default.

[Dražen Kačar (dave-fly)]

Ah, got it. Pulseaudio won't start (under my user's account) because of:

E: module.c: Failed to load module "module-alsa-sink" (argument: "device=plughw:0 rate=44100"): initialization failed.
E: main.c: Module load failed.
E: main.c: Failed to initialize daemon.

And that module was specified in ~/.pulse/default.pa, which is a leftover from the time when pulseaudio wasn't working and I was trying to do something about it.

So I deleted ~/.pulse/default.pa, stopped pulseaudio that was started by hand and polkitd is still behaving perfectly fine. Even the music is playing, although I have no pulseaudio running. :-)

Then I killed polkitd and it wasn't restarted. So I started pulseudio by hand (from my user's account) and then polkitd appeared. It's peacefully sleeping in poll() and isn't leaking memory.

[James Westby (james-w)]

On Wed, 05 May 2010 12:28:33 -0000, Dražen Kačar <email address hidden> wrote:
> I wanted to try your suggestion, and discovered I had no pulseaudio
> running. I edited /etc/pulse/client.conf, and then:
>
> {lestat}~# pulseaudio -k
> E: main.c: Failed to kill daemon: No such process
> {lestat}~> ps -ef | grep pulse
> dave 19336 5056 0 14:18 pts/1 00:00:00 grep pulse
>
> Then I started pulseaudio (as root) and the leakage in polkitd stopped.
> polkitd is currently sleeping in poll() and isn't doing anything.

Don't start it as root.

Thanks,

James

[James Westby (james-w)]

On Wed, 05 May 2010 12:53:04 -0000, Dražen Kačar <email address hidden> wrote:
> Ah, got it. Pulseaudio won't start (under my user's account) because of:
>
> E: module.c: Failed to load module "module-alsa-sink" (argument: "device=plughw:0 rate=44100"): initialization failed.
> E: main.c: Module load failed.
> E: main.c: Failed to initialize daemon.
>
> And that module was specified in ~/.pulse/default.pa, which is a
> leftover from the time when pulseaudio wasn't working and I was trying
> to do something about it.
>
> So I deleted ~/.pulse/default.pa, stopped pulseaudio that was started by
> hand and polkitd is still behaving perfectly fine. Even the music is
> playing, although I have no pulseaudio running. :-)
>
> Then I killed polkitd and it wasn't restarted. So I started pulseudio by
> hand (from my user's account) and then polkitd appeared. It's peacefully
> sleeping in poll() and isn't leaking memory.

Great, thanks for the info.

Could you confirm that you have

  /usr/lib/pulse-0.9.21/modules/module-alsa-sink.so

installed?

My guess is that "device=plughw:0 rate=44100" is no longer valid on your
system, probably the device=plughw:0 bit, which means that the module
can't load.

I'm going to reassign this to pulseaudio, as it's a poor failure mode.

To the other people subscribed to this bug, please do the same
diagnostic steps that I posted before. If you see these same messages
then you have this bug, if not, please file a new bug against pulseaudio
wiht the output you get when doing the steps (you could use "ubuntu-bug
pulseaudio" to grab a bunch of logs too).

Thanks,

James

[James Westby (james-w)]

Dražen, could you tell us what the contents of ~/.pulse/default.pa were?

Thanks,

James

[Dražen Kačar (dave-fly)]

Yes, I have module-alsa-sink.

{lestat}~> ls -l /usr/lib/pulse-0.9.21/modules/module-alsa-sink.so
-rw-r--r-- 1 root root 9564 Mar 27 00:40 /usr/lib/pulse-0.9.21/modules/module-alsa-sink.so

Contents of ~/.pulse/default.pa:

#!/usr/bin/pulseaudio -nF

.include /etc/pulse/default.pa

load-module module-alsa-sink device=plughw:0 rate=44100
sink_name=mysink
set-default-sink mysink

I have some comments, though. High CPU usage by polkitd can be attributed to constant prodding by pulseaudio and there's not much polkitd can do about it. In case there should be a limit to the number of unsuccessfull start attempts, I suppose that should be the responsibility of the process which is starting pulseaudio. It could implement "restarting too fast" check, similar to the traditional init behavior.

However, polkitd is severely leaking memory if something like this happens. It should be the responsibility of polkitd to clean up the memory after its client disconnects (I'm assuming pulseaudio is it's client, correct me if I'm wrong) and the large number of clients which are accessing it sequentialy in time shouldn't render the machine unusable. I suppose it's leaking some memory per client in any case, it's just not very visible if there are only a few clients in its lifetime.

As for pulseaudio, I suppose it should change its initialization sequence to get the local resources first (meaning load the modules, but don't run them, check the readability and hopefully syntax of local configuration files, if any, etc.) and if that goes well, then get the remote resources (network services, start external processes or whatever) by running the modules. Since pulseaudio seems to be an unattended autospawn service, it's important to prevent domino effect in case some kind of error happens, be it a bug, misconfiguration, upgrade to not quite compatible version or whatever.

And if the error is permanent (a syntax error in configuration file, for example), autospawn should be turned off.

[Paul Gortmaker (paul-gortmaker)]

Aha. Now the whole switch user thing makes sense too. I (and probably others) didn't have the alsa-sink in .pulse, but there were objects in /tmp that stopped it from creating a socket:

~$pulseaudio
E: module-protocol-stub.c: Failed to create socket directory '/tmp/.esd-8023/socket': Permission denied
E: module.c: Failed to load module "module-esound-protocol-unix" (argument: ""): initialization failed.
E: main.c: Module load failed.
E: main.c: Failed to initialize daemon.
~$

and so the same underlying "respawn like crazy" issue takes over just as for the alsa-sink. Changing the user changes the hard coded (non mktmp using) path name for the socket.

[Igor Orekhov (orekhov)]

Hi.
I have а similar problem

cocos@raduga:~$ top

  PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
29275 root 20 0 1357m 777m 2136 D 3.0 78.5 57:28.44 polkitd

[KJ (cortexbuster)]

I had the same problem with pulse.
Then I did what James suggested and ran pulseaudio manually.
The following error messages appeared among others:

W: authkey.c: Failed to open cookie file '/home/username/.pulse-cookie': Permission denied
W: authkey.c: Failed to load authorization key '/home/username/.pulse-cookie': Permission denied

After I removed .pulse-cookie the process pulseaudio started without errors.
I changed autospawn to yes again in /etc/pulse/client.conf. Seems to run nicely.
I hope it stays that way.

I upgraded my ubuntu from 9.04 to 9.10 and then to 10.04

[Toby Corkindale (tjc-wintrmute)]

There's a potential duplicate of this bug in #572813

[Vincent Besançon (big-brozer)]

Hi,

Polkitd was using high CPU and memory.
Lot of lines related to pulseaudio in syslog, see attachment.

I deleted the file "~/.esd_auth" and polkitd is now normal. New file is created using my user and my group, the old one was belonging to "root:root", but I don't know why...

[Alexandre Passos (alexandre-tp)]

I had the same problem, and could reproduce pulse weirding itself out after failing to load the esound module. Removing it from /etc/pulse/default.pa completely fixed the problem.

Also, pulse wouldn't even start with the computer, and I had to manually use alsa to get the sound to work. This is also fixed now.

[Daniel van Vugt (vanvugt)]

Thank you for reporting this bug to Ubuntu.
Ubuntu 10.04 (lucid) reached end-of-life on May 9, 2013.

See this document for currently supported Ubuntu releases:
https://wiki.ubuntu.com/Releases

Please upgrade to the latest version and re-test.

[Launchpad Janitor (janitor)]

[Expired for pulseaudio (Ubuntu) because there has been no activity for 60 days.]