I looked at the logs more closely and identified a minimal way to reproduce 
this: switch user to `nobody` as if we were systemd.

```
sudo systemd-run su nobody -c "/bin/true"
```

When I run that, I get this in the logs (abbreviated):

```
Sep 07 21:07:07 fling sudo[654179]:     mike : TTY=pts/3 ; PWD=/etc/cron.daily 
; USER=root ; COMMAND=/usr/bin/systemd-run su nobody -c /bin/true
Sep 07 21:07:07 fling sudo[654179]: pam_unix(sudo:session): session opened for 
user root(uid=0) by (uid=1000)
Sep 07 21:07:07 fling systemd[1]: Started 
run-r4a62261dbedd4a1cbcbab7e0f38f16db.service - /usr/bin/su nobody -c /bin/true.
Sep 07 21:07:07 fling sudo[654179]: pam_unix(sudo:session): session closed for 
user root
Sep 07 21:07:07 fling su[654182]: (to nobody) root on none
Sep 07 21:07:07 fling su[654182]: pam_unix(su:session): session opened for user 
nobody(uid=65534) by (uid=0)
Sep 07 21:07:07 fling systemd[1]: Created slice user-65534.slice - User Slice 
of UID 65534.
Sep 07 21:07:07 fling systemd[1]: Starting [email protected] - 
User Runtime Directory /run/user/65534...
Sep 07 21:07:07 fling systemd[1]: Finished [email protected] - 
User Runtime Directory /run/user/65534.
Sep 07 21:07:07 fling systemd[1]: Starting [email protected] - User Manager 
for UID 65534...
Sep 07 21:07:07 fling (systemd)[654184]: pam_unix(systemd-user:session): 
session opened for user nobody(uid=65534) by (uid=0)
Sep 07 21:07:07 fling systemd[654184]: Queued start job for default target 
default.target.
Sep 07 21:07:07 fling systemd[654184]: Created slice app.slice - User 
Application Slice.
Sep 07 21:07:07 fling systemd[654184]: Created slice session.slice - User Core 
Session Slice.
Sep 07 21:07:07 fling systemd[654184]: Reached target paths.target - Paths.
Sep 07 21:07:07 fling systemd[654184]: Reached target timers.target - Timers.
Sep 07 21:07:07 fling systemd[654184]: Starting dbus.socket - D-Bus User 
Message Bus Socket...
[...]
Sep 07 21:07:07 fling systemd[654184]: Listening on pulseaudio.socket - Sound 
System.
[...]
Sep 07 21:07:07 fling systemd[654184]: Starting pulseaudio.service - Sound 
Service...
[...]
Sep 07 21:07:07 fling pulseaudio[654201]: Failed to create secure directory 
(/nonexistent/.config/pulse): No such file or directory
```

What's happening is systemd is switching from root to nobody, and in the 
process it's activating the `default.target` for a user.

OK, why is this relevant? If you look at the journal around the daily 
pulseaudio error and scroll up a bit, you can see that the errors occur at the 
same time. It starts like this:

```
Sep 07 06:25:01 fling CRON[631236]: pam_unix(cron:session): session opened for 
user root(uid=0) by (uid=0)
Sep 07 06:25:01 fling CRON[631237]: (root) CMD (test -x /usr/sbin/anacron || { 
cd / && run-parts --report /etc/cron.daily; })
Sep 07 06:25:01 fling su[631260]: (to nobody) root on none
Sep 07 06:25:01 fling su[631260]: pam_unix(su:session): session opened for user 
nobody(uid=65534) by (uid=0)
```

I only have one functioning daily cronjob, `locate`. It eventually calls 
`updatedb.findutils` with `LOCALUSER=nobody`, and then calls:

```
su $LOCALUSER ...
```

And that's how all our trouble begins.

So a less-minimal way to reproduce this is:

```
sudo systemd-run /etc/cron.daily/locate
```

Anyway, I don't know how to solve this, but that's the cause of the noise. 
Moving the `locate` daily to a timer would (potentially) cause us to no longer 
see the errors, but it'd mask that the `nobody` user probably shouldn't cause 
all of (user) `default.target` to load. I'll leave the solution to all this to 
someone smarter.

-Mike

_______________________________________________
pkg-pulseaudio-devel mailing list
[email protected]
https://alioth-lists.debian.net/cgi-bin/mailman/listinfo/pkg-pulseaudio-devel

Reply via email to