On a stressed system, some logs are not being written to the log file.

[amdrsantos]

syslog-ng

Version of syslog-ng

syslog-ng 4 (4.2.0.7.g59f6cdb.dirty)
Config version: 4.2
Installer-Version: 4.2.0.7.g59f6cdb.dirty
Revision: 4.2.0.7.g59f6cdb.dirty-snapshot+20230522T195036
Compile-Date: May 22 2023 19:50:37
Module-Directory: /usr/lib/syslog-ng/4.2
Module-Path: /usr/lib/syslog-ng/4.2
Include-Path: /usr/share/syslog-ng/include
Available-Modules: affile,afmongodb,afprog,afsocket,afsql,afuser,appmodel,basicfuncs,cef,confgen,correlation,cryptofuncs,csvparser,disk-buffer,hook-commands,infinera-tls-validation,json-plugin,kvformat,linux-kmsg-format,metrics-probe,pacctformat,pseudofile,rate-limit-filter,regexp-parser,sdjournal,syslogformat,system-source,tags-parser,timestamp
Enable-Debug: off
Enable-GProf: off
Enable-Memtrace: off
Enable-IPv6: on
Enable-Spoof-Source: on
Enable-TCP-Wrapper: on
Enable-Linux-Caps: on
Enable-Systemd: on

Platform

PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"

Linux machine 4.19.139 #1 SMP PREEMPT Mon Mar 18 09:10:07 UTC 2024 aarch64 GNU/Linux

Debug bundle

Not Available

Issue

Failure

On a heavy system, some logs are not being written to the log file. They appear on journald but not on the log file.

Steps to reproduce

Load the system as much as you can, so that journal it self is suppressing messages and the tail writing of the log file is 3 minutes behind the journald.

I used a couple of traces to check if problem is occurring.
I set the following jobs in a shell:

journalctl -u cron -f --utc | grep syslog-ng-rotate &
tail -f /var/log/messages.log | grep syslog-ng-rotate &
journalctl -u systemd-journald --utc -f &
tail -f /var/log/messages.log | grep systemd-journald &

Mar 25 16:27:01 machine CRON[14289]: (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
<30>1 2024-03-25T16:24:03.483+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 13985 messages from l0serviceManager.service
Mar 25 16:27:03 machine systemd-journald[456]: Suppressed 9960 messages from l0serviceManager.service
<30>1 2024-03-25T16:24:08.952+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 1212 messages from swmd.service
<30>1 2024-03-25T16:24:33.484+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 8712 messages from l0serviceManager.service
Mar 25 16:27:34 machine systemd-journald[456]: Suppressed 11133 messages from l0serviceManager.service
Mar 25 16:27:40 machine systemd-journald[456]: Suppressed 391 messages from swmd.service
Mar 25 16:28:01 machine CRON[15589]: (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
<78>1 2024-03-25T16:25:01.837+00:00 GX-G31-NE111-machine CRON 9982 - - (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
Mar 25 16:28:04 machine systemd-journald[456]: Suppressed 12156 messages from l0serviceManager.service
<30>1 2024-03-25T16:25:03.568+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 7108 messages from l0serviceManager.service
Mar 25 16:28:11 machine systemd-journald[456]: Suppressed 854 messages from swmd.service
Mar 25 16:28:34 machine systemd-journald[456]: Suppressed 8449 messages from l0serviceManager.service
<30>1 2024-03-25T16:25:33.568+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 9406 messages from l0serviceManager.service
Mar 25 16:29:01 machine CRON[16961]: (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
Mar 25 16:29:04 machine systemd-journald[456]: Suppressed 10839 messages from l0serviceManager.service
Mar 25 16:29:11 machine systemd-journald[456]: Suppressed 409 messages from swmd.service
Mar 25 16:29:34 machine systemd-journald[456]: Suppressed 11748 messages from l0serviceManager.service
Mar 25 16:29:41 machine systemd-journald[456]: Suppressed 218 messages from swmd.service
Mar 25 16:30:01 machine CRON[18393]: (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
Mar 25 16:30:04 machine systemd-journald[456]: Suppressed 14081 messages from l0serviceManager.service
<78>1 2024-03-25T16:27:01.564+00:00 GX-G31-NE111-machine CRON 14289 - - (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
<30>1 2024-03-25T16:27:03.987+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 9960 messages from l0serviceManager.service
Mar 25 16:30:12 machine systemd-journald[456]: Suppressed 1681 messages from swmd.service
Mar 25 16:30:34 machine systemd-journald[456]: Suppressed 7802 messages from l0serviceManager.service
<30>1 2024-03-25T16:27:40.624+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 391 messages from swmd.service
<78>1 2024-03-25T16:28:01.796+00:00 GX-G31-NE111-machine CRON 15589 - - (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
<30>1 2024-03-25T16:28:04.018+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 12156 messages from l0serviceManager.service
Mar 25 16:31:01 machine CRON[19957]: (root) CMD (   /opt/local/bin/syslog-ng-rotate.sh)
Mar 25 16:31:04 machine systemd-journald[456]: Suppressed 12475 messages from l0serviceManager.service
Mar 25 16:31:12 machine systemd-journald[456]: Suppressed 818 messages from swmd.service
<30>1 2024-03-25T16:28:11.041+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 854 messages from swmd.service
Mar 25 16:31:34 machine systemd-journald[456]: Suppressed 10672 messages from l0serviceManager.service
<30>1 2024-03-25T16:28:34.019+00:00 GX-G31-NE111-machine systemd-journald 456 - - Suppressed 8449 messages from l0serviceManager.service

As you can see by the extract above,
"Mar 25 16:27:34 machine systemd-journald[456]: Suppressed 11133 messages from l0serviceManager.service"
did not reach the log file.

Configuration

In attachment

Input and output logs (if possible)

In attachment
log_stats.log
[messages.log](https://github.com/syslog-ng/syslog-ng/files/14747940
mgmt-syslog-ng.conf.txt
mgmt-syslog-ng.service.txt
syslog-ng.conf.txt
syslog-ng.service.txt
/messages.log)
tails.log

[bazsi]

Indeed, the message about log suppression is not in the tails.log you posted above.

This is a tough one to crack. I was looking at message rates, etc in log_stats.log. One line that I couldn't figure out was this:

 0 96f54c06ef73463dbcdd4e17b691f36c Mon 2024-03-25 02:18:15 UTC—Mon 2024-03-25 02:30:02 UTC

I assume this is somehow related to the range of messages present in the journal, is that right?

Also I noticed that syslog-ng was restarted at 15:19:49, which is an hour earlier than the message drop, but what happened there? did you manually restart it?

[amdrsantos]

Hey. Sorry for the delayed response.
It is the output of: journalctl --list-boots