[systemd-devel] Failing UnitTest for Journald

[Andreas Krueger]

Hi Folks,

for a customer I have to verify the behavior of the logger in its system (Linux debianVM 4.19.0-6-amd64 #1 SMP Debian 4.19.67-2+deb10u1 (2019-09-20) x86_64 GNU/Linux), which is journald (systemd 241 (241)).
For this, I have written some unit tests that work all well, when executed separately. But running together they lead to some erroneous behavior that I cannot explain -  maybe you have an idea what's going wrong...

Essentially there are 4 tests with increasing complexity:

  1.  The first one just sends 5 small messages (~20 bytes) with priority Debug, Info, Warning, Error and Critical (the customer only needs these priorities). After that, the logger's storage is synchronized and analyzed if all messages have been arrived correctly (via APIs sd_journal_...).
  2.  The second test sends 10,000 small messages (~20 bytes) to the logger with priority Debug. After that, the logger's storage is synchronized and analyzed if all messages have been arrived correctly (via APIs sd_journal_...).
  3.  The third one sends 10,000 big messages (~10,000 bytes) to the logger with priority Debug, which are good to compress. After that, the logger's storage is synchronized and analyzed if all messages have been arrived correctly (via APIs sd_journal_...).
  4.  The last one sends 10,000 big messages (~10,000 bytes) to the logger with priority Debug, which are hard to compress. After that, the logger's storage is synchronized and analyzed if all messages have been arrived correctly (via APIs sd_journal_...).

The following observations can be made now:

  *   If all tests are started separately, all is fine.
  *   If test 3 + 4 are started together, all is fine.
  *   If test 2 + 3 + 4 are started together, all is fine.
  *   If test 1 + 2 + 3 + 4 are started together, test 4 has lost one message, which is always the last one.

In my test collection there is another quite simple test, which is a bit more complex than test 1 - let's call it 1a. When test 1 + 1a + 2 + 3 + 4 are started together, test 4 loses about 10 messages, which are always the last messages sent to the logger. This can be verified just by using the command journalctl -no-pager -n 20.

Suspecting that this may be a timing issue, I have delayed the execution of test 4 by 10 seconds, but without success. Does anyone have an idea for this behavior?

Attached next you will find the corresponding configuration.

With regards,
Andreas




[Journal]
Storage=persistent
Compress=yes
Seal=yes
SplitMode=none
#SyncIntervalSec=5m
#RateLimitIntervalSec=30s
#RateLimitBurst=10000
SystemMaxUse=500M
#SystemKeepFree=
SystemMaxFileSize=50M
SystemMaxFiles=13
#RuntimeMaxUse=
#RuntimeKeepFree=
#RuntimeMaxFileSize=
#RuntimeMaxFiles=100
MaxRetentionSec=12month
#MaxFileSec=1month
#ForwardToSyslog=yes
#ForwardToKMsg=no
#ForwardToConsole=no
#ForwardToWall=yes
#TTYPath=/dev/console
#MaxLevelStore=debug
#MaxLevelSyslog=debug
#MaxLevelKMsg=notice
#MaxLevelConsole=info
#MaxLevelWall=emerg
#LineMax=48K
#ReadKMsg=yes




-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/systemd-devel/attachments/20210705/b08fc8f0/attachment.htm>