journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hello,

I have noticed that sometimes log messages are dropped in one of my systemd-based system (systemd 219).

Apps log through syslog (/dev/log). rsyslogd listens at /run/systemd/journal/syslog

I decided to compare the logging performance (using loggen tool: https://www.syslog-ng.com/technical-documents/doc/syslog-ng-open-source-edition/3.16/administration-guide/87 ) in two cases:

1. If it logs to /dev/log
2. If it logs to /run/systemd/journal/syslog

All the setup was the same. I can share the script I used to test if needed but the idea was pretty simple - for every tested logging rate, log for 5 minute. Then count number of lines in the log and compare it with the number of lines sent by loggen tool.

I expected certain degradation as promised by rsyslog manual: ("It must be noted, however, that the journal tends to drop messages when it becomes busy instead of forwarding them to the system log socket. This is because the journal uses an
async log socket interface for forwarding instead of the traditional synchronous one").

However I was shocked by the results.

Max rate at which log messages are NOT dropped is 17250 msg/s for logging to /run/systemd/journal/syslog.  And only 47 messages per second for logging to /dev/log.

Example of the loggen cmdline:

./loggen --unix -D --interval 300 --rate 35 --size 512 /dev/log

journald.conf:

[Journal]
#
# Configuration in order to send logs to rsyslog
#
Storage=none
#Storage=auto
ForwardToSyslog=yes
MaxLevelSyslog=debug
#
# These configurations are if the storage is set to auto
# this is just configured in order to limit the log size
#
SystemMaxUse=400M
SystemKeepFree=200M
SystemMaxFileSize=20M
RuntimeMaxUse=1000M
RuntimeKeepFree=1000M
RuntimeMaxFileSize=100M
MaxRetentionSec=1month
MaxFileSec=1week

(I have checked with "journalctl -f" that logs are not stored in the binary journal)

I was shocked by the results. My first idea was that there is something with buffers not being flushed somewhere in the chain at the end of the test.

But I can see that last messages in the log are the last messages sent by loggen tool.  It looks unbelievably bad.

Do I measure something wrong? Or is there any known setting I have to apply to journald to make forwarding more efficient?

Any ideas are appreciated.

Thank you in advance!
--
WBR & WBW, Vitaly
_______________________________________________
systemd-devel mailing list
systemd-devel@xxxxxxxxxxxxxxxxxxxxx
https://lists.freedesktop.org/mailman/listinfo/systemd-devel

[Index of Archives]     [LARTC]     [Bugtraq]     [Yosemite Forum]     [Photo]

  Powered by Linux