No syslog for complete afternoon? Possible?

[Richard G]

Is it possible that there was no sylog for all afternoon? I just got these 2 emails.

Time: Tue Jun 18 18:34:56 2024 +0200
Alert: *Error* Log line flooding/looping in /var/log/messages. Reopening log file

and

Time: Tue Jun 18 18:35:01 2024 +0200
Alert: *Error* Log line flooding/looping in /var/log/messages. Reopening log file

So I went and had a look why that was, and then found something funny.

Jun 18 11:49:02 server26 systemd[1703554]: Queued start job for default target Main User Target.
Jun 18 11:49:02 server26 systemd[1703554]: Created slice User Application Slice.
Jun 18 11:49:02 server26 systemd[1703554]: Started Mark boot as successful after the user session has run 2 minutes.
Jun 18 11:49:02 server26 systemd[1703554]: Started Daily Cleanup of User's Temporary Directories.
Jun 18 11:49:02 server26 systemd[1703554]: Reached target Paths.
Jun 18 11:49:02 server26 systemd[1703554]: Reached target Timers.
Jun 18 11:49:02 server26 systemd[1703554]: Starting D-Bus User Message Bus Socket...
Jun 18 11:49:02 server26 systemd[1703554]: Starting Create User's Volatile Files and Directories...
Jun 18 11:49:02 server26 systemd[1703554]: Finished Create User's Volatile Files and Directories.
Jun 18 11:49:02 server26 systemd[1703554]: Listening on D-Bus User Message Bus Socket.
Jun 18 11:49:02 server26 systemd[1703554]: Reached target Sockets.
Jun 18 18:35:01 server26 systemd[1]: Created slice User Slice of UID 1103.
Jun 18 18:35:01 server26 systemd[1]: Starting User Runtime Directory /run/user/1103...
Jun 18 18:35:01 server26 systemd[1]: Started Session 20869 of User root.
Jun 18 18:35:01 server26 systemd[1]: Finished User Runtime Directory /run/user/1103.
Jun 18 18:35:01 server26 systemd[1]: Starting User Manager for UID 1103...
Jun 18 18:35:02 server26 systemd[3407517]: Queued start job for default target Main User Target.
Jun 18 18:35:02 server26 systemd[3407517]: Created slice User Application Slice.
Jun 18 18:35:02 server26 systemd[3407517]: Started Mark boot as successful after the user session has run 2 minutes.
Jun 18 18:35:02 server26 systemd[3407517]: Started Daily Cleanup of User's Temporary Directories.

UID 1103 is known to me, nothing wrong with that.

But this is what worries me:

Jun 18 11:49:02 server26 systemd[1703554]: Reached target Sockets.
Jun 18 18:35:01 server26 systemd[1]: Created slice User Slice of UID 1103.

no logs from 11:49 until 18:35???

 

[Richard G]

So I called rsyslogd status and then found this:

Jun 18 18:34:55 server26.mycompany.com rsyslogd[2657]: imjournal: sd_journal_next() failed: Bad message [v8.2310.0-4.el9]
Jun 18 18:34:55 server26.mycompany.com rsyslogd[2657]: imjournal: sd_journal_next() failed: Bad message [v8.2310.0-4.el9]
Jun 18 18:34:55 server26.mycompany.com rsyslogd[2657]: imjournal: trying to recover from journal error [v8.2310.0-4.el9 try https://www.rsyslog.com/e>
Jun 18 18:34:58 server26.mycompany.com rsyslogd[2657]: imjournal from <server26:systemd>: begin to drop messages due to rate-limiting
Jun 18 18:35:02 server26.mycompany.com rsyslogd[2657]: imjournal: 11538 messages lost due to rate-limiting (20000 allowed within 600 seconds)

This does not explain the missing logs from all afternoon, but I never seen that imjournal bad message line.

 

[EthernetServers]

Jun 18 18:35:02 server26.mycompany.com rsyslogd[2657]: imjournal: 11538 messages lost due to rate-limiting (20000 allowed within 600 seconds)[/code]

This would explain it.

This is a safeguard measure to prevent logs from filling the /var partition. Exercise care if you disable rate limiting, as it might fill your log partition. It is often better to investigate which process is flooding the logs with messages and resolve this issue. Often, an application will be set at a ""debug"" log level, which will cause very verbose logging. If the logging is not needed, please lower the logging level.

Source: https://knowledge.broadcom.com/external/article/124815/imuxsock-begins-to-drop-messages-from-pi.html

I've had this a couple times before, often due to named query logging.

 

[Ohm J]

maybe dns service got spamming and flood logs output. ?

 

[Richard G]

This would explain it.

Not really I guess, because it says "within 600 seconds". But there was totally no log at all for the whole afternoon starting 11:49, untill suddenly that flood message at 18:34 hours.
And normally when I get log flood messages, at least a few lines of what is causing it, are present in the syslog. Now nothing at all.
So it might explain the im_journal error, but not the fact that nothing was logged all afternoon in the /var/log/messages file.

Odd enough, all other logs were working well. And since 18:35 also the syslog is working fine again logging everything normally.
I also check apache error log, nothing weird. Was also running all day.

@Ohm J In that case I also would at least have some logs between 11:49 and 18:34 hours. Next to that, I have all bind logs in seperate files.

All has been running fine, no outages, no peaks, no su, the /var/log/secure also logged all day and nothing odd. No disk or ram issues, all running fine.

Seems rsyslog service has choked or something, not logging four hours. Never seen that before.