DevHeads.net

f26->f27 server upgrade, starting system activity accounting tool every 10 minutes

Fedora 26 Server was upgraded to Fedora 27 with 'dnf system-upgrade'
so it is no longer strictly the Server product I guess:
$ cat /etc/fedora-release
Fedora release 27 (Twenty Seven)

I'm seeing in the journal, a lot more activity than I'm used to.
Usually it's just once an hour, dnf makecache timer triggers. But I
noticed many reached and stopped target Basic System:

Nov 12 06:25:02 f27s.localdomain systemd[5593]: Reached target Basic System.
Nov 12 06:25:52 f27s.localdomain systemd[5593]: Stopped target Basic System.
Nov 12 06:28:01 f27s.localdomain systemd[5647]: Reached target Basic System.
Nov 12 06:28:51 f27s.localdomain systemd[5647]: Stopped target Basic System.
Nov 12 06:55:02 f27s.localdomain systemd[5716]: Reached target Basic System.
Nov 12 06:55:52 f27s.localdomain systemd[5716]: Stopped target Basic System.
Nov 12 06:58:01 f27s.localdomain systemd[5765]: Reached target Basic System.
Nov 12 06:58:52 f27s.localdomain systemd[5765]: Stopped target Basic System.
Nov 12 07:25:01 f27s.localdomain systemd[5870]: Reached target Basic System.
Nov 12 07:25:51 f27s.localdomain systemd[5870]: Stopped target Basic System.
Nov 12 07:28:02 f27s.localdomain systemd[5916]: Reached target Basic System.
Nov 12 07:28:52 f27s.localdomain systemd[5916]: Stopped target Basic System.
Nov 12 07:55:01 f27s.localdomain systemd[5992]: Reached target Basic System.
Nov 12 07:55:51 f27s.localdomain systemd[5992]: Stopped target Basic System.

But I can't really figure out why. And so then I noticed the system
activity accounting tool only starts, but keeps starting every 10
minutes.

Nov 12 10:00:11 f27s.localdomain systemd[1]: Starting system activity
accounting tool...
Nov 12 10:00:11 f27s.localdomain systemd[1]: Started system activity
accounting tool.
Nov 12 10:10:06 f27s.localdomain systemd[1]: Starting system activity
accounting tool...
Nov 12 10:10:06 f27s.localdomain systemd[1]: Started system activity
accounting tool.
Nov 12 10:20:06 f27s.localdomain systemd[1]: Starting system activity
accounting tool...
Nov 12 10:20:06 f27s.localdomain systemd[1]: Started system activity
accounting tool.

There's also many instances of creating and removing slice User Slice
of pcp. But I don't understand it well enough yet to figure out if
these are related or separate.

I relabeled the system after the upgrade, and 'ausearch -m AVC' turns
up nothing, but the journal does have many USER_AVC messages in it.

Nov 12 08:28:26 f27s.localdomain audit[727]: USER_AVC pid=727 uid=81
auid=4294967295 ses=4294967295
subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc: denied
{ send_msg } for msgtype=method_return dest=:1.273 spid=1 tpid=6216
scontext=system_u:system_r:init_t:s0
tcontext=system_u:system_r:system_cronjob_t:s0-s0:c0.c1023 tclass=dbus
permissive=0

Anyway, I'm going to post the complete journal while I'm still digging
into it. There may be more than one thing going on here...

Default
<a href="https://drive.google.com/open?id=1lc9b_-OQmm27L7Ubg5eGOikv-KjZdk4f" title="https://drive.google.com/open?id=1lc9b_-OQmm27L7Ubg5eGOikv-KjZdk4f">https://drive.google.com/open?id=1lc9b_-OQmm27L7Ubg5eGOikv-KjZdk4f</a>

Monotonic time
<a href="https://drive.google.com/open?id=1WhT1pTwWKMUQuSbL6Nxx1ay0kicju9M4" title="https://drive.google.com/open?id=1WhT1pTwWKMUQuSbL6Nxx1ay0kicju9M4">https://drive.google.com/open?id=1WhT1pTwWKMUQuSbL6Nxx1ay0kicju9M4</a>

Comments

Re: f26->f27 server upgrade, starting system activity accounting

By Chris Murphy at 11/12/2017 - 18:09

The accounting tool has a timer.

[chris@f27s ~]$ sudo systemctl status sysstat-collect.timer
‚óŹ sysstat-collect.timer - Run system activity accounting tool every 10 minutes
Loaded: loaded (/usr/lib/systemd/system/sysstat-collect.timer;
enabled; vendor preset: enabled)
Active: active (waiting) since Sat 2017-11-11 21:04:17 MST; 18h ago
Trigger: Sun 2017-11-12 15:30:00 MST; 3min 27s left

Nov 11 21:04:17 f27s.localdomain systemd[1]: Started Run system
activity accounting tool every 10 minutes.

And it pretty much starts and stops instantly.
Nov 12 15:20:11 f27s.localdomain systemd[1]: Starting system activity
accounting tool...
Nov 12 15:20:11 f27s.localdomain systemd[1]: Started system activity
accounting tool.
Nov 12 15:20:11 f27s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=sysstat-collect comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=?
res=success'
Nov 12 15:20:11 f27s.localdomain audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=sysstat-collect comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=?
res=success'

So that's one mystery solved.

There's still the issue of creating/removing slice User Slice of pcp,
and the Starting/Stopping User Manager fo UID 989 that keeps
happening.

Re: f26->f27 server upgrade, starting system activity accounting

By Michal Schmidt at 11/15/2017 - 09:17

On 11/13/2017 12:09 AM, Chris Murphy wrote:
Those are triggered by cron jobs in the "pcp" package:
/etc/cron.d/pcp-pmie
/etc/cron.d/pcp-pmlogger

Michal