I’m seeing the same issue, but that isn’t the cause:
[root@Nethserver ~]# systemctl status dbus
● dbus.service - D-Bus System Message Bus
Loaded: loaded (/usr/lib/systemd/system/dbus.service; static; vendor preset: disabled)
Active: active (running) since Fri 2018-03-09 16:27:39 PST; 2 months 7 days ago
Main PID: 1057 (dbus-daemon)
CGroup: /system.slice/dbus.service
└─1057 /bin/dbus-daemon --system --address=systemd: --nofork --nop...
May 16 14:40:16 Nethserver.BogoLinux.net dbus[1057]: [system] Successfully ac...
May 16 14:40:16 Nethserver.BogoLinux.net dbus-daemon[1057]: dbus[1057]: [syst...
May 16 14:45:16 Nethserver.BogoLinux.net dbus[1057]: [system] Activating via ...
May 16 14:45:16 Nethserver.BogoLinux.net dbus-daemon[1057]: dbus[1057]: [syst...
May 16 14:45:16 Nethserver.BogoLinux.net dbus-daemon[1057]: dbus[1057]: [syst...
May 16 14:45:16 Nethserver.BogoLinux.net dbus[1057]: [system] Successfully ac...
May 16 14:50:17 Nethserver.BogoLinux.net dbus-daemon[1057]: dbus[1057]: [syst...
May 16 14:50:17 Nethserver.BogoLinux.net dbus[1057]: [system] Activating via ...
May 16 14:50:17 Nethserver.BogoLinux.net dbus-daemon[1057]: dbus[1057]: [syst...
May 16 14:50:17 Nethserver.BogoLinux.net dbus[1057]: [system] Successfully ac...
Hint: Some lines were ellipsized, use -l to show in full.
[root@Nethserver ~]# systemctl status smwingsd
● smwingsd.service - Server Manager DB cache Daemon
Loaded: loaded (/usr/lib/systemd/system/smwingsd.service; static; vendor preset: disabled)
Active: active (running) since Tue 2018-05-01 18:13:33 PDT; 2 weeks 0 days ago
Docs: https://github.com/NethServer/nethserver-httpd-admin
Main PID: 2402 (smwingsd)
CGroup: /system.slice/smwingsd.service
└─2402 /usr/bin/perl /usr/libexec/nethserver/smwingsd
May 01 18:13:32 Nethserver.BogoLinux.net systemd[1]: Starting Server Manager ...
May 01 18:13:33 Nethserver.BogoLinux.net smwingsd[2402]: Process Backgrounded
May 01 18:13:33 Nethserver.BogoLinux.net smwingsd[2402]: 2018/05/01-18:13:33 ...
May 01 18:13:33 Nethserver.BogoLinux.net systemd[1]: Started Server Manager D...
May 01 18:13:33 Nethserver.BogoLinux.net smwingsd[2402]: Binding to UNIX sock...
May 01 18:13:33 Nethserver.BogoLinux.net smwingsd[2402]: Setting gid to "4 4"
May 01 18:13:33 Nethserver.BogoLinux.net smwingsd[2402]: Setting uid to "995"
Hint: Some lines were ellipsized, use -l to show in full.
[root@Nethserver ~]#
You are right, I thought it could be related but it’s a different message.
I checked the log files of my servers and couldn’t find an occurrence of every 5 mins.
You can trigger the message with signal-event nethserver-ntp-save or signal-event nethserver-ntp-update. So reboots/updates/config changes/service restarts may be responsible for the entries too. Did you change NTP settings?
I spotted the “problem” yesterday. I’d not changed the ntp settings since I’d installed the system, so I don’t think that’s the cause either. I’ve changed the ntp settings since I spotted to the “problem” to test if that was the cause and things havn’t changed - which also suggests it’s not the ntp settings.
I’ve manually started the systemd-timedated.service and it runs for a few mins then is stopped again.
Something is automatically starting and stopping the systemd-timedated.service every 5mins.
Please note that dbus-org.freedesktop.timedate1.service seems to activate systemd-timedated.service
My system shows similar behaviour. Updates on the 15th of May and then the dbus messages start every 5mins. HOWEVER, there was a period on 13th May when the dbus messages appeared every 5mins, but it has become a regular occurrence since 15th of May.
The following updates were applied on 15th May:
May 15 20:40:16 Installed: yum-cron-3.4.3-158.el7.centos.noarch
May 15 20:40:28 Installed: puppet-agent-1.6.2-1.el7.x86_64
May 15 20:40:28 Installed: perl-Email-Valid-1.198-1.el7.noarch
May 15 20:40:29 Installed: nethserver-yum-cron-1.0.0-1.ns7.noarch
May 15 20:40:29 Installed: nethserver-subscription-3.0.2-1.ns7.noarch
May 15 20:40:29 Installed: nethserver-subscription-ui-3.0.2-1.ns7.noarch
May 15 20:40:28 Installed: puppet-agent-1.6.2-1.el7.x86_64
NMS is a python daemon which monitor the status of all services registered inside the configuration db. Each service is checked every 300 seconds, if the status of a service changes, NMS writes a notification to Collectd socket.
then here:
line 33 refers to
/usr/libexec/nethserver/read-service-status
running this script from the command prompt causes the freedesktop.timedate messages to appear in the log.
I can confirm what you found out. Great work!
The only solution I see for now is to suppress these messages in the logfile. I found similar issue with sogo here and in the docs and changed it to fit to our needs:
echo "if \$programname == \"dbus\" and (\$msg contains \"Activating via systemd: service name='org.freedesktop.timedate1'\" or \$msg contains \"Successfully activated service 'org.freedesktop.timedate1'\") then stop" > /etc/rsyslog.d/ignore-dbus-timedate.conf
systemctl restart rsyslog
@giacomo, do you see another way to get rid of these messages triggered by the subscription module?
if $programname == "systemd" and ($msg contains "Starting Time & Date Service..." or $msg contains "Started Time & Date Service.") then stop
if ($msg contains "Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service'") then stop
if ($msg contains "Successfully activated service 'org.freedesktop.timedate1'") then stop
IIRC the database initialization access chronyd via DBUS which generates these lines.
Adding the suggested configuration to rsyslog will surely work, but we can’t apply such fix.
In fact rsyslog can’t be restarted without human supervision because sometime, after the restart, journalctl stops sending messages to it.
I don’t know why, I couldn’t reproduce the problem but I know it exists.
I will try to find a way to avoid such log directly from db code, but probably there is no solution.