Bug 705427

Summary: Hourly logging from cron fills up /var/log/secure
Product: [Fedora] Fedora Reporter: Philip Prindeville <philipp>
Component: systemdAssignee: Lennart Poettering <lpoetter>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 15CC: johannbg, lpoetter, metherid, mschmidt, notting, philipp, plautrba, theinric, udovdh
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: systemd-26-4.fc15 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-06-21 17:25:10 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Philip Prindeville 2011-05-17 16:12:14 UTC
Description of problem:

Apparently the routine operation of running /etc/cron.hourly is generating logging in /var/log/secure. Since this is entirely expected and unextraordinary behavior, it would be better to omit it.

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

26-1

How reproducible:

Normal install.

Steps to Reproduce:
1.
2.
3.
  
Actual results:

Seeing in /var/log/secure:

May 17 09:01:01 localhost /usr/sbin/crond[8441]: pam_systemd(crond:session): Moving new user session for root into control group /user/root/47.
May 17 09:01:01 localhost /USR/SBIN/CROND[8441]: pam_systemd(crond:session): Moving remaining processes of user session 47 of root into control group /user/root/master.

and similar message every hour. Also note that the path to the executable has been converted to uppercase.

Expected results:

We can safely omit this logging.

Additional info:

Comment 1 Michal Schmidt 2011-05-18 07:00:28 UTC
There is a patch in upstream git to downgrade the messages to the LOG_DEBUG level:
http://cgit.freedesktop.org/systemd/commit/?id=53d5582fa006b0eb528f5dc3f4ba978abd8ac5a3

I don't know if it will stop them appearing in /var/log/secure though. The default /etc/rsyslog.conf has:
  authpriv.*              /var/log/secure
which suggests that all levels (including debug) go there.


The uppercasing of the process name is done by cron itself:
http://git.fedorahosted.org/git/?p=cronie.git;a=blob;f=src/do_command.c;h=e1f54017c97369a7f64f27068af6ce773cd7eb2e;hb=HEAD#l92

Comment 2 Philip Prindeville 2011-05-18 15:09:26 UTC
(In reply to comment #1)
> There is a patch in upstream git to downgrade the messages to the LOG_DEBUG
> level:
> http://cgit.freedesktop.org/systemd/commit/?id=53d5582fa006b0eb528f5dc3f4ba978abd8ac5a3
> 
> I don't know if it will stop them appearing in /var/log/secure though. The
> default /etc/rsyslog.conf has:
>   authpriv.*              /var/log/secure
> which suggests that all levels (including debug) go there.
> 
> 
> The uppercasing of the process name is done by cron itself:
> http://git.fedorahosted.org/git/?p=cronie.git;a=blob;f=src/do_command.c;h=e1f54017c97369a7f64f27068af6ce773cd7eb2e;hb=HEAD#l92


Should /etc/rsyslog.conf be patched to log at 'info' then?

Comment 3 Fedora Update System 2011-05-25 19:10:28 UTC
systemd-26-2.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/systemd-26-2.fc15

Comment 4 Philip Prindeville 2011-05-26 15:52:28 UTC
There's still a lot of chatter to /var/log/secure -- probably because /etc/rsyslog.conf still contains:

authpriv.*                                              /var/log/secure

do we also need a defect to change this to:

authpriv.info                                           /var/log/secure

instead?

Comment 5 Michal Schmidt 2011-05-26 16:00:58 UTC
I have a patch to make pam_systemd.so emit the debug messages only if it is configured in PAM with a "debug=on" option. That's similar to how other PAM modules do it.
I sent the patch to the upstream mailing list today, but it does not seem to have reached there. I'll check my email config and resend later today.

Comment 6 Fedora Update System 2011-05-26 21:56:19 UTC
Package systemd-26-2.fc15:
* should fix your issue,
* was pushed to the Fedora 15 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing systemd-26-2.fc15'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/systemd-26-2.fc15
then log in and leave karma (feedback).

Comment 7 Philip Prindeville 2011-05-27 03:11:56 UTC
Picked it up from koji. Works great, after I edit /etc/rsyslog.conf and restart rsyslog.

Didn't need to reboot.

Comment 8 Michal Schmidt 2011-05-27 07:43:05 UTC
I believe changing the rsyslog configuration should not be necessary. pam_systemd should stop producing debug messages by default. This is the patch I mentioned:
http://lists.freedesktop.org/archives/systemd-devel/2011-May/002531.html
Moving back to ASSIGNED.

Comment 9 Fedora Update System 2011-05-28 23:59:49 UTC
systemd-26-2.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 10 Philip Prindeville 2011-05-29 00:09:18 UTC
(In reply to comment #5)
> I have a patch to make pam_systemd.so emit the debug messages only if it is
> configured in PAM with a "debug=on" option. That's similar to how other PAM
> modules do it.
> I sent the patch to the upstream mailing list today, but it does not seem to
> have reached there. I'll check my email config and resend later today.

As there weren't any patches attached to this bug, I'm not sure if the patch you mentioned was part of this defect fix or not. Was it?

Comment 11 Michal Schmidt 2011-05-30 11:16:01 UTC
(In reply to comment #10)
> As there weren't any patches attached to this bug, I'm not sure if the patch
> you mentioned was part of this defect fix or not. Was it?

It was not.

Reopening. Let's wait for Lennart's decision on the patch
http://lists.freedesktop.org/archives/systemd-devel/2011-May/002531.html

Comment 12 Michal Schmidt 2011-06-15 21:50:33 UTC
The patch has been merged:
http://cgit.freedesktop.org/systemd/commit/?id=0e318cad06d483624076777c105bdcdd6aca3596

Comment 13 Fedora Update System 2011-06-15 21:58:02 UTC
systemd-26-4.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/systemd-26-4.fc15

Comment 14 Fedora Update System 2011-06-15 23:53:46 UTC
Package systemd-26-4.fc15:
* should fix your issue,
* was pushed to the Fedora 15 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing systemd-26-4.fc15'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/systemd-26-4.fc15
then log in and leave karma (feedback).

Comment 15 udo 2011-06-19 11:26:21 UTC
Hmm.
I dunno but I still see stuff like:
Jun 19 13:15:02 bla klogd: /USR/SBIN/CROND[16079]: (root) CMD (LANG=C LC_ALL=C /usr/bin/mrtg /etc/mrtg/mrtg.cfg --lock-file /var/lock/mrtg/mrtg_l --confcache-file /var/lib/mrtg/mrtg.ok)

being logged every five minutes in /var/log/messages even though syslog.conf says cron.none.
Why is this changed from Fedora 14?
Why the caps?

Also dbus is filling up messages with kinds of non-error logging.
How can this be tamed?

The classical controls that cron gave us don't appear to work...

Comment 16 Michal Schmidt 2011-06-20 11:28:18 UTC
(In reply to comment #15)
> I dunno but I still see stuff like:
> Jun 19 13:15:02 bla klogd: /USR/SBIN/CROND[16079]: (root) CMD (LANG=C LC_ALL=C
> /usr/bin/mrtg /etc/mrtg/mrtg.cfg --lock-file /var/lock/mrtg/mrtg_l
> --confcache-file /var/lib/mrtg/mrtg.ok)
> 
> being logged every five minutes in /var/log/messages even though syslog.conf
> says cron.none.

Since Fedora 8 the default syslog implementation is rsyslog
(http://fedoraproject.org/wiki/Releases/FeatureRsyslog). Perhaps you could try using that instead of sysklogd, which does not seem to be actively maintained.

> Why is this changed from Fedora 14?

I don't know.

> Why the caps?

See comment #1.

> Also dbus is filling up messages with kinds of non-error logging.
> How can this be tamed?
> The classical controls that cron gave us don't appear to work...

From this description I have no idea what's going on.

None of this is related to this BZ, which was about excessive logging from pam_systemd. I suggest discussing this with cronie or sysklogd maintainers.

Comment 17 udo 2011-06-20 13:38:18 UTC
rsyslog does the same.
I don't need cron in messages, just in /var/log/cron.
If both crons have teh same issue then somethign more could be going on.
User error.
Or a bug.
How can we find out?

Comment 18 Michal Schmidt 2011-06-20 13:54:20 UTC
I don't know. I can only repeat myself: Talk to cronie maintainers/developers.

Comment 19 Fedora Update System 2011-06-21 17:24:57 UTC
systemd-26-4.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.