Discussion:
How to quiet cron sessions logging with systemd-212?
(too old to reply)
Leho Kraav
2014-06-09 06:33:30 UTC
Permalink
After upgrading systemd 208 -> 212, every single cron job creates this
flood in systemd journal:

juuni 09 09:20:01 xps14 crond[15112]: pam_unix(crond:session): session
opened for user root by (uid=0)
juuni 09 09:20:01 xps14 systemd[15113]: pam_unix(systemd-user:session):
session opened for user root by (uid=0)
juuni 09 09:20:01 xps14 systemd[1]: Starting user-0.slice.
juuni 09 09:20:01 xps14 systemd[1]: Created slice user-0.slice.
juuni 09 09:20:01 xps14 systemd[1]: Starting User Manager for UID 0...
juuni 09 09:20:01 xps14 systemd[1]: Starting Session 107 of user root.
juuni 09 09:20:01 xps14 systemd[1]: Started Session 107 of user root.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Default.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Default.
juuni 09 09:20:02 xps14 systemd[15113]: Startup finished in 31ms.
juuni 09 09:20:02 xps14 systemd[1]: Started User Manager for UID 0.
juuni 09 09:20:02 xps14 CROND[15116]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
juuni 09 09:20:02 xps14 CROND[15112]: pam_unix(crond:session): session
closed for user root
juuni 09 09:20:02 xps14 systemd[1]: Stopping User Manager for UID 0...
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Default.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Default.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Shutdown.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Shutdown.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Exit the Session...
juuni 09 09:20:02 xps14 systemd[15113]: Received SIGRTMIN+24 from PID
15128 (kill).
juuni 09 09:20:02 xps14 systemd[15114]: pam_unix(systemd-user:session):
session closed for user root
juuni 09 09:20:02 xps14 systemd[1]: Stopped User Manager for UID 0.
juuni 09 09:20:02 xps14 systemd[1]: Stopping user-0.slice.
juuni 09 09:20:02 xps14 systemd[1]: Removed slice user-0.slice.

Can I quiet this down somehow?
Leho Kraav
2014-06-09 07:48:31 UTC
Permalink
nobody cares because the developers point of view is that what is
interesting for them needs to be also faced by the sysadmin
otherwise this would be only logged in debug-mode and bugreports
not closed: https://bugzilla.redhat.com/show_bug.cgi?id=1072368#c3
frankly if that messages would at least have a prefix or a different
process than systemd one could filter them out with rsyslog.conf
without supress relevant boot messages
Thanks for the info. I tried googling for this relatively hard, couldn't
find that bug.

Language on that bug is probably counterproductive, but other than that,
some reasonably sensible way should exist to simply stop logging crap,
not relying on just output filtering.
Leonid Isaev
2014-06-09 15:28:45 UTC
Permalink
Date: Mon, 09 Jun 2014 10:48:31 +0300
Subject: Re: [systemd-devel] How to quiet cron sessions logging with
systemd-212?
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:24.0) Gecko/20100101
Thunderbird/24.5.0
nobody cares because the developers point of view is that what is
interesting for them needs to be also faced by the sysadmin
otherwise this would be only logged in debug-mode and bugreports
not closed: https://bugzilla.redhat.com/show_bug.cgi?id=1072368#c3
frankly if that messages would at least have a prefix or a different
process than systemd one could filter them out with rsyslog.conf
without supress relevant boot messages
Thanks for the info. I tried googling for this relatively hard, couldn't
find that bug.
Language on that bug is probably counterproductive, but other than that,
some reasonably sensible way should exist to simply stop logging crap, not
relying on just output filtering.
What you see are authpriv-level logs, so it would be a really bad idea to
suppress them, regardless of their source.

Currently, journald doesn't provide any means of log processing, so your only
choice is to filter logs when viewing them using journalctl command line or
grep/awk; you can not control what is logged when and where.

If you want log processing (multiple log directories, advanced filtering,
etc.), use syslog-ng or rsyslog. For example, one can setup a special logfile
for systemd-related messages with a given syslog facility (authpriv, daemon,
etc.).

HTH,
--
Leonid Isaev
GPG fingerprints: DA92 034D B4A8 EC51 7EA6 20DF 9291 EE8A 043C B8C4
C0DF 20D0 C075 C3F1 E1BE 775A A7AE F6CB 164B 5A6D
Reindl Harald
2014-06-09 18:08:43 UTC
Permalink
Post by Leonid Isaev
Date: Mon, 09 Jun 2014 10:48:31 +0300
Subject: Re: [systemd-devel] How to quiet cron sessions logging with
systemd-212?
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:24.0) Gecko/20100101
Thunderbird/24.5.0
nobody cares because the developers point of view is that what is
interesting for them needs to be also faced by the sysadmin
otherwise this would be only logged in debug-mode and bugreports
not closed: https://bugzilla.redhat.com/show_bug.cgi?id=1072368#c3
frankly if that messages would at least have a prefix or a different
process than systemd one could filter them out with rsyslog.conf
without supress relevant boot messages
Thanks for the info. I tried googling for this relatively hard, couldn't
find that bug.
Language on that bug is probably counterproductive, but other than that,
some reasonably sensible way should exist to simply stop logging crap, not
relying on just output filtering.
What you see are authpriv-level logs, so it would be a really bad idea to
suppress them, regardless of their source
no user needs them, there are already logs which command was
started for which user from crond with just 3 lines

Jun 9 19:01:01 rawhide CROND[1696]: (root) CMD (run-parts /etc/cron.hourly)
Jun 9 19:01:01 rawhide run-parts[1696]: (/etc/cron.hourly) starting 0anacron
Jun 9 19:01:01 rawhide run-parts[1705]: (/etc/cron.hourly) finished 0anacron
Jun 9 20:01:01 rawhide CROND[1735]: (root) CMD (run-parts /etc/cron.hourly)
Jun 9 20:01:01 rawhide run-parts[1735]: (/etc/cron.hourly) starting 0anacron
Jun 9 20:01:01 rawhide run-parts[1744]: (/etc/cron.hourly) finished 0anacron

they are introduced in that floody way with recent systemd

all the decades before crond did run fine, logs exactly what
you need to know if /var/log/secure and /var/log/crond
without writing *hundret thousands* loglines all day long
on machines with a lot of cronjobs
Leonid Isaev
2014-06-09 19:07:58 UTC
Permalink
Date: Mon, 09 Jun 2014 20:08:43 +0200
Subject: Re: [systemd-devel] How to quiet cron sessions logging with
systemd-212?
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:24.0) Gecko/20100101
Thunderbird/24.5.0
Post by Leonid Isaev
Date: Mon, 09 Jun 2014 10:48:31 +0300
Subject: Re: [systemd-devel] How to quiet cron sessions logging with
systemd-212?
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:24.0) Gecko/20100101
Thunderbird/24.5.0
nobody cares because the developers point of view is that what is
interesting for them needs to be also faced by the sysadmin
otherwise this would be only logged in debug-mode and bugreports
not closed: https://bugzilla.redhat.com/show_bug.cgi?id=1072368#c3
frankly if that messages would at least have a prefix or a different
process than systemd one could filter them out with rsyslog.conf
without supress relevant boot messages
Thanks for the info. I tried googling for this relatively hard, couldn't
find that bug.
Language on that bug is probably counterproductive, but other than that,
some reasonably sensible way should exist to simply stop logging crap, not
relying on just output filtering.
What you see are authpriv-level logs, so it would be a really bad idea to
suppress them, regardless of their source
no user needs them, there are already logs which command was
started for which user from crond with just 3 lines
If you don't need them -- OK, but don't speak for the others. Why systemd
should be treated any differently than other programs? If it generates authpriv
messages -- they should be collected, not ignored. What about normal, i.e.
user-initiated logins -- should they be logged?
Jun 9 19:01:01 rawhide CROND[1696]: (root) CMD (run-parts /etc/cron.hourly)
Jun 9 19:01:01 rawhide run-parts[1696]: (/etc/cron.hourly) starting 0anacron
Jun 9 19:01:01 rawhide run-parts[1705]: (/etc/cron.hourly) finished 0anacron
Jun 9 20:01:01 rawhide CROND[1735]: (root) CMD (run-parts /etc/cron.hourly)
Jun 9 20:01:01 rawhide run-parts[1735]: (/etc/cron.hourly) starting 0anacron
Jun 9 20:01:01 rawhide run-parts[1744]: (/etc/cron.hourly) finished 0anacron
they are introduced in that floody way with recent systemd
all the decades before crond did run fine, logs exactly what
you need to know if /var/log/secure and /var/log/crond
without writing *hundret thousands* loglines all day long
on machines with a lot of cronjobs
But why can't you write a syslog filter which uses facility as well as program
name? So if you believe that systemd-generated messages are useless, drop them,
or store them in a volatile location like /run/log. Something like this (in
syslog-ng language):
---
destination d_systemd { file("/run/log/systemd.log"); };
filter f_daemon { facility(daemon) and not level(debug) and not \
program(systemd); };
filter f_systemd { program(systemd); };
log { source(src); filter(f_systemd); destination(d_systemd); };
---
--
Leonid Isaev
GPG fingerprints: DA92 034D B4A8 EC51 7EA6 20DF 9291 EE8A 043C B8C4
C0DF 20D0 C075 C3F1 E1BE 775A A7AE F6CB 164B 5A6D
Reindl Harald
2014-06-09 19:19:20 UTC
Permalink
Post by Leonid Isaev
Post by Reindl Harald
all the decades before crond did run fine, logs exactly what
you need to know if /var/log/secure and /var/log/crond
without writing *hundret thousands* loglines all day long
on machines with a lot of cronjobs
If you don't need them -- OK, but don't speak for the others. Why systemd
should be treated any differently than other programs?
because Lennart to ospeaks for others the way he closed
that bugreport? why can't there be at least a config
option to disable creating them at all?

because other programs *never ever* procude *that lot* of
loglines all day long - look at the simple calculation
in the bugreport

on our production infrastrcuture these messages would be
*a lot* more than all other logs summarized

*and* they are spitted to /var/log/messages to make things worst
Post by Leonid Isaev
But why can't you write a syslog filter which uses facility as well as program
name? So if you believe that systemd-generated messages are useless, drop them
because you *can not* distinguish between *that* user messages
and system message sbecause they have systemd as program name
common, the PID changes and you don't want to drop *system
messages* from systemd

if they would contain a unique string / prefix to distinguish
from cronjobs triggered messages i would have written a rsyslog
filter as for a lot of other noise long ago

however - the *large amount* of that messages even if you
drop them consumes useless ressources on virtualization
clusters and blow up the systemd-journal
Leonid Isaev
2014-06-09 20:32:48 UTC
Permalink
Post by Reindl Harald
[...]
on our production infrastrcuture these messages would be
*a lot* more than all other logs summarized
*and* they are spitted to /var/log/messages to make things worst
Post by Leonid Isaev
But why can't you write a syslog filter which uses facility as well as program
name? So if you believe that systemd-generated messages are useless, drop them
because you *can not* distinguish between *that* user messages
and system message sbecause they have systemd as program name
common, the PID changes and you don't want to drop *system
messages* from systemd
So, systemd starts certain things on _any_ user "login": be it a real user, or
a daemon. However, if you already have logs from the daemon (cron) or a login
program (login), why keep systemd-generated messages? I'd put them in a
separate file...
Post by Reindl Harald
if they would contain a unique string / prefix to distinguish
Do you have something concrete in mind?
Post by Reindl Harald
from cronjobs triggered messages i would have written a rsyslog
filter as for a lot of other noise long ago
however - the *large amount* of that messages even if you
drop them consumes useless ressources on virtualization
clusters and blow up the systemd-journal
If resources are an issue, don't use the journal. In my experience, it consumes
~4x space compared to syslog (on a firewall machine, after 2 months uptime)...
--
Leonid Isaev
GPG fingerprints: DA92 034D B4A8 EC51 7EA6 20DF 9291 EE8A 043C B8C4
C0DF 20D0 C075 C3F1 E1BE 775A A7AE F6CB 164B 5A6D
Reindl Harald
2014-06-09 20:42:17 UTC
Permalink
Post by Leonid Isaev
Post by Reindl Harald
[...]
on our production infrastrcuture these messages would be
*a lot* more than all other logs summarized
*and* they are spitted to /var/log/messages to make things worst
Post by Leonid Isaev
But why can't you write a syslog filter which uses facility as well as program
name? So if you believe that systemd-generated messages are useless, drop them
because you *can not* distinguish between *that* user messages
and system message sbecause they have systemd as program name
common, the PID changes and you don't want to drop *system
messages* from systemd
So, systemd starts certain things on _any_ user "login": be it a real user, or
a daemon. However
* why do it need to do that much stuff
* why can't it keep that stuff long-running

you have already "/usr/lib/systemd/systemd --user" and "(sd-pam)"
processes for every userid ever started a cronjob running all
the time - so why flood the logs every minute again?
Post by Leonid Isaev
if you already have logs from the daemon (cron) or a login
program (login), why keep systemd-generated messages? I'd put them in a
separate file...
if i can put them in a seperate file i can filter them out
Post by Leonid Isaev
Post by Reindl Harald
if they would contain a unique string / prefix to distinguish
Do you have something concrete in mind?
systemd-user: or whatever

that would also make clear the we *do not* start all sorts
of targets, the flooding log in misleading anyways

that below is just *not true* from the users point of view

Jun 9 22:36:07 rawhide systemd[1]: Starting User Manager for UID 0...
Jun 9 22:36:07 rawhide systemd[607]: Starting Paths.
Jun 9 22:36:07 rawhide systemd[607]: Reached target Paths.
Jun 9 22:36:07 rawhide systemd[607]: Starting Timers.
Jun 9 22:36:07 rawhide systemd[607]: Reached target Timers.
Jun 9 22:36:07 rawhide systemd[607]: Starting Sockets.
Jun 9 22:36:07 rawhide systemd[607]: Reached target Sockets.
Jun 9 22:36:07 rawhide systemd[607]: Starting Basic System.
Jun 9 22:36:07 rawhide systemd[607]: Reached target Basic System.
Jun 9 22:36:07 rawhide systemd[607]: Starting Default.
Jun 9 22:36:07 rawhide systemd[607]: Reached target Default.
Jun 9 22:36:07 rawhide systemd[607]: Startup finished in 9ms.
Jun 9 22:36:07 rawhide systemd[1]: Started User Manager for UID 0.
Post by Leonid Isaev
Post by Reindl Harald
from cronjobs triggered messages i would have written a rsyslog
filter as for a lot of other noise long ago
however - the *large amount* of that messages even if you
drop them consumes useless ressources on virtualization
clusters and blow up the systemd-journal
If resources are an issue, don't use the journal. In my experience, it consumes
~4x space compared to syslog (on a firewall machine, after 2 months uptime)...
i don't use the journal, the configuration of journald is like below
the log-flood makes things even worser because it leads to early
rotation and purges "systemctl status whatever.service" informations
by purging the memory-journal

if it comes to ressource usage:

all that dropped messages (if you could drop/filter them) are
producing data and overhead in general, only because you manage
to not see things that don't mean they produce no overhead

[***@rawhide ~]# cat /etc/systemd/journald.conf
[Journal]
Storage=volatile
Compress=no
RateLimitInterval=10s
RateLimitBurst=500
RuntimeMaxUse=15M
Mike Gilbert
2014-06-10 03:32:28 UTC
Permalink
Post by Reindl Harald
Post by Leonid Isaev
Post by Reindl Harald
[...]
on our production infrastrcuture these messages would be
*a lot* more than all other logs summarized
*and* they are spitted to /var/log/messages to make things worst
Post by Leonid Isaev
But why can't you write a syslog filter which uses facility as well as program
name? So if you believe that systemd-generated messages are useless, drop them
because you *can not* distinguish between *that* user messages
and system message sbecause they have systemd as program name
common, the PID changes and you don't want to drop *system
messages* from systemd
So, systemd starts certain things on _any_ user "login": be it a real user, or
a daemon. However
* why do it need to do that much stuff
* why can't it keep that stuff long-running
you have already "/usr/lib/systemd/systemd --user" and "(sd-pam)"
processes for every userid ever started a cronjob running all
the time - so why flood the logs every minute again?
Now that you mention it, you can cut down on a lot of the log spam by
enabling "linger" for root and other users which run cron jobs.

loginctl enable-linger <user>

This will keep a systemd user instance running so that a new one is
not spawned every time cron wakes up.
Ivan Shapovalov
2014-06-10 10:31:20 UTC
Permalink
Post by Mike Gilbert
Post by Reindl Harald
Post by Leonid Isaev
Post by Reindl Harald
[...]
on our production infrastrcuture these messages would be
*a lot* more than all other logs summarized
*and* they are spitted to /var/log/messages to make things worst
Post by Leonid Isaev
But why can't you write a syslog filter which uses facility as well as program
name? So if you believe that systemd-generated messages are useless, drop them
because you *can not* distinguish between *that* user messages
and system message sbecause they have systemd as program name
common, the PID changes and you don't want to drop *system
messages* from systemd
So, systemd starts certain things on _any_ user "login": be it a real user, or
a daemon. However
* why do it need to do that much stuff
* why can't it keep that stuff long-running
you have already "/usr/lib/systemd/systemd --user" and "(sd-pam)"
processes for every userid ever started a cronjob running all
the time - so why flood the logs every minute again?
Now that you mention it, you can cut down on a lot of the log spam by
enabling "linger" for root and other users which run cron jobs.
loginctl enable-linger <user>
This will keep a systemd user instance running so that a new one is
not spawned every time cron wakes up.
It's more interesting, why a logind session is ever being created for the cron job...
It shouldn't be that way, or do I misunderstand something?
--
Ivan Shapovalov / intelfx /
Lennart Poettering
2014-06-10 16:04:49 UTC
Permalink
Post by Ivan Shapovalov
It's more interesting, why a logind session is ever being created for the cron job...
It shouldn't be that way, or do I misunderstand something?
We should create a logind session for all sessions of normal users. It
doesn't matter if its just a background job or foreground, logind should
know about it, we should set up its full environment (including the
per-user systemd), and set all security limits and stuff.

For system users (i.e. those with an uid < 1000), for all that stuff
that is just an implementation detail of the OS however there shouldn't
really be any PAM or logind session created by cron. It should just
setresuid() and invoke whatever it needs to invoke... Setting up a full
PAM session is quite unnecessary then...

Lennart
--
Lennart Poettering, Red Hat
Mantas Mikulėnas
2014-06-09 09:01:56 UTC
Permalink
I think there's also another problem – logind starts the user manager
instance for cronjobs while it shouldn't do so for batch stuff. Probably a
PAM configuration issue.
--
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates this
juuni 09 09:20:01 xps14 crond[15112]: pam_unix(crond:session): session
opened for user root by (uid=0)
session opened for user root by (uid=0)
juuni 09 09:20:01 xps14 systemd[1]: Starting user-0.slice.
juuni 09 09:20:01 xps14 systemd[1]: Created slice user-0.slice.
juuni 09 09:20:01 xps14 systemd[1]: Starting User Manager for UID 0...
juuni 09 09:20:01 xps14 systemd[1]: Starting Session 107 of user root.
juuni 09 09:20:01 xps14 systemd[1]: Started Session 107 of user root.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Default.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Default.
juuni 09 09:20:02 xps14 systemd[15113]: Startup finished in 31ms.
juuni 09 09:20:02 xps14 systemd[1]: Started User Manager for UID 0.
juuni 09 09:20:02 xps14 CROND[15116]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
juuni 09 09:20:02 xps14 CROND[15112]: pam_unix(crond:session): session
closed for user root
juuni 09 09:20:02 xps14 systemd[1]: Stopping User Manager for UID 0...
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Default.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Default.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Basic System.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Paths.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Timers.
juuni 09 09:20:02 xps14 systemd[15113]: Stopping Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Stopped target Sockets.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Shutdown.
juuni 09 09:20:02 xps14 systemd[15113]: Reached target Shutdown.
juuni 09 09:20:02 xps14 systemd[15113]: Starting Exit the Session...
juuni 09 09:20:02 xps14 systemd[15113]: Received SIGRTMIN+24 from PID
15128 (kill).
session closed for user root
juuni 09 09:20:02 xps14 systemd[1]: Stopped User Manager for UID 0.
juuni 09 09:20:02 xps14 systemd[1]: Stopping user-0.slice.
juuni 09 09:20:02 xps14 systemd[1]: Removed slice user-0.slice.
Can I quiet this down somehow?
_______________________________________________
systemd-devel mailing list
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Lennart Poettering
2014-06-10 10:18:54 UTC
Permalink
I think there's also another problem – logind starts the user manager
instance for cronjobs while it shouldn't do so for batch stuff. Probably a
PAM configuration issue.
Nope. This is intentional. A session is a session is a session, and we
should provide the same functionality to all session,s including all
services on the bus and all services systemd manages... We shouldn't end
up providing only half a session if the trigger for something was only
time, instead of some other reason...

That said, certain system-level cronjobs should probably not be PAM
sessions... PAM sessions are really mostly for stuff that really is a
"session" of some kind, and not just system services that just need some
code executed by time.

The same way as a daemon that drops priviliges shouldn't do so through
PAM, a system cronjob shouldn't involve PAM. But that of course would
require changes to cron, to understand what a system and what a user
cronjob was...

Lennart
--
Lennart Poettering, Red Hat
Lennart Poettering
2014-06-10 10:20:57 UTC
Permalink
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates
Can I quiet this down somehow?
The idea with the journal is that we log everything that happens on the
system, without exceptions, without hiding anything. And filtering is
then applied when you view things, based on the big pool of data you
have. This can be annoying, of course, but I am so very sure we should't
suppress these things, because soemtimes they are useful to know about.

journalctl has powerful filtering capabilities, we have them to make
this huge datase palatable...

Lennart
--
Lennart Poettering, Red Hat
Leho Kraav
2014-06-10 10:24:40 UTC
Permalink
Post by Lennart Poettering
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates
Can I quiet this down somehow?
The idea with the journal is that we log everything that happens on the
system, without exceptions, without hiding anything. And filtering is
then applied when you view things, based on the big pool of data you
have. This can be annoying, of course, but I am so very sure we should't
suppress these things, because soemtimes they are useful to know about.
journalctl has powerful filtering capabilities, we have them to make
this huge datase palatable...
I'm actually all for getting the upstream i.e. cron/PAM acting more sane
so we don't even arrive at the "logging huge amounts of
low-effectiveness information" problem, but as you wrote in your other
reply, that might be a whole separate project.

In the meantime mgilbert's suggestion for using loginctl --linger
parameter seems to accomplish the goal of quieting cron logging. Any
side effects to consider?
Lennart Poettering
2014-06-10 16:01:00 UTC
Permalink
Post by Leho Kraav
Post by Lennart Poettering
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates
Can I quiet this down somehow?
The idea with the journal is that we log everything that happens on the
system, without exceptions, without hiding anything. And filtering is
then applied when you view things, based on the big pool of data you
have. This can be annoying, of course, but I am so very sure we should't
suppress these things, because soemtimes they are useful to know about.
journalctl has powerful filtering capabilities, we have them to make
this huge datase palatable...
I'm actually all for getting the upstream i.e. cron/PAM acting more
sane so we don't even arrive at the "logging huge amounts of
low-effectiveness information" problem, but as you wrote in your
other reply, that might be a whole separate project.
In the meantime mgilbert's suggestion for using loginctl --linger
parameter seems to accomplish the goal of quieting cron logging. Any
side effects to consider?
Well, you keep the systemd user instance running all the time then
instead of just when it is used... Doing that for root is fine, but if
you do that for all users, then well, you got an additional process
running for each one of them...

Lennart
--
Lennart Poettering, Red Hat
Leho Kraav
2014-06-10 16:03:30 UTC
Permalink
Post by Lennart Poettering
In the meantime mgilbert's suggestion for using EDIT **loginctl enable-linger**
command seems to accomplish the goal of quieting cron logging. Any
side effects to consider?
Well, you keep the systemd user instance running all the time then
instead of just when it is used... Doing that for root is fine, but if
you do that for all users, then well, you got an additional process
running for each one of them...
Right. For time being, root cron jobs are the primary issue. I'll see
what happens with the others.

enable-linger persists across reboots?
Lennart Poettering
2014-06-10 17:23:20 UTC
Permalink
Post by Leho Kraav
Post by Lennart Poettering
In the meantime mgilbert's suggestion for using EDIT **loginctl enable-linger**
command seems to accomplish the goal of quieting cron logging. Any
side effects to consider?
Well, you keep the systemd user instance running all the time then
instead of just when it is used... Doing that for root is fine, but if
you do that for all users, then well, you got an additional process
running for each one of them...
Right. For time being, root cron jobs are the primary issue. I'll
see what happens with the others.
enable-linger persists across reboots?
Yes.

Lennart
--
Lennart Poettering, Red Hat
Reindl Harald
2014-06-10 16:42:12 UTC
Permalink
Post by Lennart Poettering
Post by Leho Kraav
Post by Lennart Poettering
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates
Can I quiet this down somehow?
The idea with the journal is that we log everything that happens on the
system, without exceptions, without hiding anything. And filtering is
then applied when you view things, based on the big pool of data you
have. This can be annoying, of course, but I am so very sure we should't
suppress these things, because soemtimes they are useful to know about.
journalctl has powerful filtering capabilities, we have them to make
this huge datase palatable...
I'm actually all for getting the upstream i.e. cron/PAM acting more
sane so we don't even arrive at the "logging huge amounts of
low-effectiveness information" problem, but as you wrote in your
other reply, that might be a whole separate project.
In the meantime mgilbert's suggestion for using loginctl --linger
parameter seems to accomplish the goal of quieting cron logging. Any
side effects to consider?
Well, you keep the systemd user instance running all the time then
instead of just when it is used... Doing that for root is fine, but if
you do that for all users, then well, you got an additional process
running for each one of them...
which is cheaper than fire up a complete session again and again
with all the logs recent systemd generates and you *already*
have long running processes for each user ever started a cronjob
also under Fedora 20 which don't flood the logs otherwise

they already annoy me a lot because the last decades that
all was not there and cronjobs where just fine

vmware 4030 0.0 0.0 74208 2064 ? S Jun08 0:00 (sd-pam)
harry 4351 0.0 0.0 74208 2132 ? S Jun08 0:00 (sd-pam)
root 9806 0.0 0.0 74208 2208 ? S Jun08 0:00 (sd-pam)
wwwcron 10894 0.0 0.0 74208 2224 ? S Jun08 0:00 (sd-pam)
apache 10918 0.0 0.0 74208 2236 ? S Jun08 0:00 (sd-pam)
Reindl Harald
2014-06-10 10:47:30 UTC
Permalink
Post by Lennart Poettering
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates
Can I quiet this down somehow?
The idea with the journal is that we log everything that happens on the
system, without exceptions, without hiding anything. And filtering is
then applied when you view things, based on the big pool of data you
have. This can be annoying, of course, but I am so very sure we should't
suppress these things, because soemtimes they are useful to know about
if things are only *sometimes* useful that means most of the time they
are not and for anybody who is not a systemd-developer or debugging
something they are just noise

at least the "enable-linger" should be default because you anyways
have all the disturbing sd-pam processes long running which you
need to kill after updates on libraries to get anything in
listed with "lsof | grep DEL | grep /usr" clean

so don't start a complete systemd session for a simple cronjob
which did his job decades before systemd existed or just don't
stop it all the time

the "started target..." messages are in *any case* misleading
Leho Kraav
2014-06-10 17:05:33 UTC
Permalink
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates this
juuni 09 09:20:01 xps14 crond[15112]: pam_unix(crond:session): session
opened for user root by (uid=0)
session opened for user root by (uid=0)
juuni 09 09:20:01 xps14 systemd[1]: Starting user-0.slice.
...
juuni 09 09:20:02 xps14 systemd[1]: Started User Manager for UID 0.
juuni 09 09:20:02 xps14 CROND[15116]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
juuni 09 09:20:02 xps14 CROND[15112]: pam_unix(crond:session): session
closed for user root
juuni 09 09:20:02 xps14 systemd[1]: Stopping User Manager for UID 0...
...
juuni 09 09:20:02 xps14 systemd[1]: Stopped User Manager for UID 0.
juuni 09 09:20:02 xps14 systemd[1]: Stopping user-0.slice.
juuni 09 09:20:02 xps14 systemd[1]: Removed slice user-0.slice.
Another related question to trying to filter this output: why some lines
are logged with program "crond" and some "CROND"?

With "loginctl linger-enable" a shorter version of a cron run looks like
this now:

...
juuni 10 19:30:01 xps14 crond[21310]: pam_unix(crond:session): session
opened for user root by (uid=0)
juuni 10 19:30:01 xps14 CROND[21311]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
juuni 10 19:30:01 xps14 systemd[1]: Starting Session 99 of user root.
juuni 10 19:30:01 xps14 systemd[1]: Started Session 99 of user root.
juuni 10 19:30:01 xps14 CROND[21310]: pam_unix(crond:session): session
closed for user root
...

I am considering filtering "crond" out of the human-visible status
window and that's how the uppercase vs lowercase question arose.
Lennart Poettering
2014-06-10 17:24:34 UTC
Permalink
Post by Leho Kraav
Post by Leho Kraav
After upgrading systemd 208 -> 212, every single cron job creates this
juuni 09 09:20:01 xps14 crond[15112]: pam_unix(crond:session): session
opened for user root by (uid=0)
session opened for user root by (uid=0)
juuni 09 09:20:01 xps14 systemd[1]: Starting user-0.slice.
...
juuni 09 09:20:02 xps14 systemd[1]: Started User Manager for UID 0.
juuni 09 09:20:02 xps14 CROND[15116]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
juuni 09 09:20:02 xps14 CROND[15112]: pam_unix(crond:session): session
closed for user root
juuni 09 09:20:02 xps14 systemd[1]: Stopping User Manager for UID 0...
...
juuni 09 09:20:02 xps14 systemd[1]: Stopped User Manager for UID 0.
juuni 09 09:20:02 xps14 systemd[1]: Stopping user-0.slice.
juuni 09 09:20:02 xps14 systemd[1]: Removed slice user-0.slice.
Another related question to trying to filter this output: why some
lines are logged with program "crond" and some "CROND"?
No idea. cron sends that string, we merely display it...

Lennart
--
Lennart Poettering, Red Hat
Loading...