barman icon indicating copy to clipboard operation
barman copied to clipboard

Published 20 hours ago • verified publisher icon EnterpriseDB

Cron job spams syslog and makes it unusable

Open hlovdal opened this issue 3 years ago • 2 comments

I installed barman some time ago but have not started using it yet. However I discovered that having it just "passively" running has a huge negative impact. Due to the default cron setup every single minute the following chunk of logtext is dumped to the system log:

2022-02-25T18:30:01.866365+01:00 myhostname crond[1607]: (*system*) RELOAD (/etc/cron.d/barman)
2022-02-25T18:30:01.922757+01:00 myhostname systemd[1]: Created slice User Slice of UID 965.
2022-02-25T18:30:01.924322+01:00 myhostname systemd[1]: Starting User runtime directory /run/user/965...
2022-02-25T18:30:01.950427+01:00 myhostname systemd[1]: Started User runtime directory /run/user/965.
2022-02-25T18:30:01.954519+01:00 myhostname systemd[1]: Starting User Manager for UID 965...
2022-02-25T18:30:01.996940+01:00 myhostname systemd[16468]: pam_unix(systemd-user:session): session opened for user barman by (uid=0)
2022-02-25T18:30:02.120026+01:00 myhostname systemd[16468]: Reached target Paths.
2022-02-25T18:30:02.122056+01:00 myhostname systemd[16468]: Listening on Multimedia System.
2022-02-25T18:30:02.124744+01:00 myhostname systemd[16468]: Starting D-Bus User Message Bus Socket.
2022-02-25T18:30:02.125586+01:00 myhostname systemd[16468]: Listening on Sound System.
2022-02-25T18:30:02.125799+01:00 myhostname systemd[16468]: Reached target Timers.
2022-02-25T18:30:02.144299+01:00 myhostname systemd[16468]: Listening on D-Bus User Message Bus Socket.
2022-02-25T18:30:02.144561+01:00 myhostname systemd[16468]: Reached target Sockets.
2022-02-25T18:30:02.144676+01:00 myhostname systemd[16468]: Reached target Basic System.
2022-02-25T18:30:02.146341+01:00 myhostname systemd[1]: Started User Manager for UID 965.
2022-02-25T18:30:02.146590+01:00 myhostname systemd[16468]: Starting Sound Service...
2022-02-25T18:30:02.149931+01:00 myhostname systemd[1]: Started Session 59 of user barman.
2022-02-25T18:30:02.167593+01:00 myhostname CROND[16493]: (barman) CMD (  [ -x /usr/bin/barman ] && /usr/bin/barman -q cron)
2022-02-25T18:30:02.687318+01:00 myhostname dbus-daemon[1115]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.5596' (uid=965 pid=16491 comm="/usr/bin/pulseaudio --daemonize=no --log-target=jo" label="unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023")
2022-02-25T18:30:02.688352+01:00 myhostname dbus-daemon[1115]: [system] Activation via systemd failed for unit 'dbus-org.bluez.service': Unit dbus-org.bluez.service not found.
2022-02-25T18:30:02.694378+01:00 myhostname rtkit-daemon[1104]: Supervising 0 threads of 0 processes of 1 users.
2022-02-25T18:30:02.727905+01:00 myhostname rtkit-daemon[1104]: Supervising 0 threads of 0 processes of 1 users.
2022-02-25T18:30:02.762348+01:00 myhostname rtkit-daemon[1104]: Supervising 0 threads of 0 processes of 1 users.
2022-02-25T18:30:02.795724+01:00 myhostname rtkit-daemon[1104]: Supervising 0 threads of 0 processes of 1 users.
2022-02-25T18:30:02.831309+01:00 myhostname rtkit-daemon[1104]: Supervising 0 threads of 0 processes of 1 users.
2022-02-25T18:30:02.870446+01:00 myhostname systemd[16468]: Started D-Bus User Message Bus.
2022-02-25T18:30:02.899298+01:00 myhostname systemd[16468]: Started Sound Service.
2022-02-25T18:30:02.899840+01:00 myhostname systemd[16468]: Reached target Default.
2022-02-25T18:30:02.899961+01:00 myhostname pulseaudio[16491]: GetManagedObjects() failed: org.freedesktop.systemd1.NoSuchUnit: Unit dbus-org.bluez.service not found.
2022-02-25T18:30:02.901143+01:00 myhostname systemd[16468]: Startup finished in 887ms.
2022-02-25T18:30:02.948592+01:00 myhostname systemd[1]: session-59.scope: Succeeded.
2022-02-25T18:30:13.184611+01:00 myhostname systemd[1]: Stopping User Manager for UID 965...
2022-02-25T18:30:13.190898+01:00 myhostname systemd[16468]: Stopping D-Bus User Message Bus...
2022-02-25T18:30:13.192123+01:00 myhostname systemd[16468]: Stopped target Default.
2022-02-25T18:30:13.197833+01:00 myhostname systemd[16468]: Stopped D-Bus User Message Bus.
2022-02-25T18:30:13.198149+01:00 myhostname systemd[16468]: Stopped target Basic System.
2022-02-25T18:30:13.198388+01:00 myhostname systemd[16468]: Stopped target Paths.
2022-02-25T18:30:13.198513+01:00 myhostname systemd[16468]: Stopped target Sockets.
2022-02-25T18:30:13.198618+01:00 myhostname systemd[16468]: Closed Multimedia System.
2022-02-25T18:30:13.198736+01:00 myhostname systemd[16468]: Closed Sound System.
2022-02-25T18:30:13.198844+01:00 myhostname systemd[16468]: Stopped target Timers.
2022-02-25T18:30:13.198943+01:00 myhostname systemd[16468]: Closed D-Bus User Message Bus Socket.
2022-02-25T18:30:13.199047+01:00 myhostname systemd[16468]: Reached target Shutdown.
2022-02-25T18:30:13.199150+01:00 myhostname systemd[16468]: Started Exit the Session.
2022-02-25T18:30:13.199275+01:00 myhostname systemd[16468]: Reached target Exit the Session.
2022-02-25T18:30:13.204591+01:00 myhostname systemd[16474]: pam_unix(systemd-user:session): session closed for user barman
2022-02-25T18:30:13.208525+01:00 myhostname systemd[1]: [email protected]: Succeeded.
2022-02-25T18:30:13.209450+01:00 myhostname systemd[1]: Stopped User Manager for UID 965.
2022-02-25T18:30:13.214742+01:00 myhostname systemd[1]: Stopping User runtime directory /run/user/965...
2022-02-25T18:30:13.235311+01:00 myhostname systemd[1]: run-user-965.mount: Succeeded.
2022-02-25T18:30:13.239048+01:00 myhostname systemd[1]: [email protected]: Succeeded.
2022-02-25T18:30:13.239384+01:00 myhostname systemd[1]: Stopped User runtime directory /run/user/965.
2022-02-25T18:30:13.242758+01:00 myhostname systemd[1]: Removed slice User Slice of UID 965.
2022-02-25T18:31:01.944150+01:00 myhostname crond[1607]: (*system*) RELOAD (/etc/cron.d/barman)

(well except for the first and last line which was triggered by temporarely enabling the cron job again to generate this sample output).

Every single minute. This makes barman completely unusable for me.

I do not know the history and decisions behind using cron for this, but starting a cron job as frequent as every minute seems rather excessive and to me and seems to be something that rather should be done by a process that sleeps a bit between each check.

Is it possible to not use cron? Is this something that is on your roadmap?

hlovdal avatar Feb 25 '22 18:02 hlovdal

That certainly does seem like an excessive amount of logging. What Linux distribution are you using?

mikewallace1979 avatar Feb 26 '22 07:02 mikewallace1979

CentOS Stream 8.

Could you not create an additional service command that does the same as the cron except that instead of only once, it sleeps and repeats so that it could run as a service under systemctl or alternatives.

I recognize that the required changes would be a bit more than the following, but in principle it would do the job:

def service(args):
    """
    Run maintenance tasks repeatedly as a service (global command)
    """
    while True:
        non_exiting_version_of_cron_cli_function(args)
        time.sleep(60)

That way users can chose if they want to run as cron job or service.

hlovdal avatar Mar 03 '22 21:03 hlovdal