Re: [systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-21 Thread Lennart Poettering
On So, 20.09.20 16:09, Vitaly Repin (vitaly_re...@fsfe.org) wrote:

> Hello,
>
> Thanks for the answer!
>
> However, it looks like that imjournal module is not an option for me.
>
> rsyslog imjournal module documentation
> (https://www.rsyslog.com/doc/v8-stable/configuration/modules/imjournal.html)
> clearly recommends to use imuxsock module in my case:
>
> [begin quote]
> As such, the performance of a configuration utilizing this module may
> be notably slower than when using imuxsock.
> The journal provides imuxsock with a copy of all “classical” syslog
> messages, however, it does not provide structured data. '
> Only if that structured data is needed, imjournal must be used.
> Otherwise, imjournal may simply be replaced by imuxsock, and we highly
> suggest doing so.
> [end quote]
>
> I do not need structural data and I need performance. My system
> generates a substantial amount of logs. I want to be able to store
> messages with an arrival rate of 10 000 messages per second at
> least.

The rsyslog maintainer doesn't like systemd very much. Much of what he
puts in the docs as big fat warnings is quite a bit FUDdy.

Lennart

--
Lennart Poettering, Berlin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-21 Thread Lennart Poettering
On So, 20.09.20 12:07, Vitaly Repin (vitaly_re...@fsfe.org) wrote:

> Any ideas are appreciated.

Note that you compare apples with oranges. journald spends much time
on collecting log metadata (i.e. process identity, user identity,
cgroup stuff, …), which the others simply don't.

That said, for starters, try running something a bit newer than a
version from 215. 5 years is an eternity in software.

The metadata colleciton code gained support for caching much of the
metadata, which makes a major difference in particular if you have
only a few log sources which log a lot (in contrast to many different
log sources that log at the same time).

Lennart

--
Lennart Poettering, Berlin
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-21 Thread Michael Biebl
Hm, some performance penalty is certainly expected but 350times slower
looks like something is odd.
Would be interesting to know, if you can reproduce the performance
issue with a more recent version.
Afaik, using imuxsock and syslog forwarding should be more performant
then imjournal (which was suggested earlier).

You could configure systemd, to not do syslog forwarding and let
rsyslog handle syslog messages directly.
This has a few downsides though:
- syslog messages don't end up in the journal
- non-syslog messages from journald don't end up in your syslog, say
messages from systemd or services logging to stdout/stderr.
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-20 Thread Reindl Harald


Am 20.09.20 um 16:09 schrieb Vitaly Repin:
> Thanks for the answer!

please avoid off-list copies and top-posting when you got an answer with
proper quoting (you break threading and produce unreadable conversations
by permanently switch between quoting styles)

> However, it looks like that imjournal module is not an option for me.
> 
> rsyslog imjournal module documentation
> (https://www.rsyslog.com/doc/v8-stable/configuration/modules/imjournal.html)
> clearly recommends to use imuxsock module in my case:
> 
> [begin quote]
> As such, the performance of a configuration utilizing this module may
> be notably slower than when using imuxsock.
> The journal provides imuxsock with a copy of all “classical” syslog
> messages, however, it does not provide structured data. '
> Only if that structured data is needed, imjournal must be used.
> Otherwise, imjournal may simply be replaced by imuxsock, and we highly
> suggest doing so.
> [end quote]
> 
> I do not need structural data and I need performance. My system
> generates a substantial amount of logs. I want to be able to store
> messages with an arrival rate of 10 000 messages per second at least.

with "Storage=volatile" there is is not space for "database corruption"
and given that it *reads* the journal on that channel is not much space
for ratelimiting unless you hit the ratelimits of journald itself

[root@srv-rhsoft:~]$ cat /etc/systemd/journald.conf
[Journal]
Storage=volatile
RateLimitInterval=1s
RateLimitBurst=2
RuntimeMaxUse=100M
ForwardToSyslog=no

>> 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.
> 
> 
> Den sön 20 sep. 2020 kl 12:26 skrev Reindl Harald :
>>
>>
>>
>> Am 20.09.20 um 12:07 schrieb Vitaly Repin:
>>
>>> ForwardToSyslog=yes
>>
>> this is long obsolete
>>
>>
>> $WorkDirectory /var/lib/rsyslog
>>
>> module(load="imjournal" StateFile="imjournal.state"
>> WorkAroundJournalBug="on" Ratelimit.Interval="600" Ratelimit.Burst="5")

___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-20 Thread Vitaly Repin
Hello,

Thanks for the answer!

However, it looks like that imjournal module is not an option for me.

rsyslog imjournal module documentation
(https://www.rsyslog.com/doc/v8-stable/configuration/modules/imjournal.html)
clearly recommends to use imuxsock module in my case:

[begin quote]
As such, the performance of a configuration utilizing this module may
be notably slower than when using imuxsock.
The journal provides imuxsock with a copy of all “classical” syslog
messages, however, it does not provide structured data. '
Only if that structured data is needed, imjournal must be used.
Otherwise, imjournal may simply be replaced by imuxsock, and we highly
suggest doing so.
[end quote]

I do not need structural data and I need performance. My system
generates a substantial amount of logs. I want to be able to store
messages with an arrival rate of 10 000 messages per second at least.

> 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.


Den sön 20 sep. 2020 kl 12:26 skrev Reindl Harald :
>
>
>
> Am 20.09.20 um 12:07 schrieb Vitaly Repin:
>
> > ForwardToSyslog=yes
>
> this is long obsolete
>
>
> $WorkDirectory /var/lib/rsyslog
>
> module(load="imjournal" StateFile="imjournal.state"
> WorkAroundJournalBug="on" Ratelimit.Interval="600" Ratelimit.Burst="5")
> ___
> systemd-devel mailing list
> systemd-devel@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/systemd-devel



-- 
WBR & WBW, Vitaly
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-20 Thread Reindl Harald



Am 20.09.20 um 12:07 schrieb Vitaly Repin:

> ForwardToSyslog=yes

this is long obsolete


$WorkDirectory /var/lib/rsyslog

module(load="imjournal" StateFile="imjournal.state"
WorkAroundJournalBug="on" Ratelimit.Interval="600" Ratelimit.Burst="5")
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


[systemd-devel] journald forwarding to rsyslogd. Huge (350 times) performance degradation. What am I doing wrong???

2020-09-20 Thread Vitaly Repin
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@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel