Bug 1030529

Summary: systemd-journald rate limiting does not work properly when the messages arrive in a single burst with no delays
Product: [Fedora] Fedora Reporter: Andrew J. Schorr <aschorr>
Component: systemdAssignee: systemd-maint
Status: NEW --- QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: dtardon, johannbg, lnykryn, msekleta, plautrba, systemd-maint, vpavlin, zbyszek
Target Milestone: ---Keywords: FutureFeature, Reopened, Reproducer, Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-19 10:35:42 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
/etc/rc.d/init.d/verbose to show behavior of journald rate-limiting none

Description Andrew J. Schorr 2013-11-14 16:01:06 UTC
Created attachment 824016 [details]
/etc/rc.d/init.d/verbose to show behavior of journald rate-limiting

Description of problem:
By default, the RateLimitBurst parameter tells journald to start rate limiting after 200 messages are received within 10 seconds.  There appears to be a bug where a service can log more than 200 messages if it does so without pause.

Version-Release number of selected component (if applicable):
systemd-204-17.fc19.x86_64


How reproducible:
Install the attached LSB init script in /etc/rc.d/init.d/verbose and run "systemctl start verbose" and observe that all 250 messages are logged and none are discarded.  If a "sleep 1" command is inserted after every 50 messages, then the rate limiting works properly, although journald fails to log a message
about how many messages were dropped.  Refer to bug #1030523

Steps to Reproduce:
1. Copy attached script to /etc/rc.d/init.d/verbose
2. In one window, run "journalctl -f"
3. Run "systemctl start verbose"

Actual results:
All 250 messages appear in the log.

Expected results:
The last 50 messages should be discarded due to rate limiting.

Additional info:

Comment 1 Fedora End Of Life 2015-01-09 20:35:38 UTC
This message is a notice that Fedora 19 is now at end of life. Fedora 
has stopped maintaining and issuing updates for Fedora 19. It is 
Fedora's policy to close all bug reports from releases that are no 
longer maintained. Approximately 4 (four) weeks from now this bug will
be closed as EOL if it remains open with a Fedora 'version' of '19'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 19 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 2 Fedora End Of Life 2015-02-17 19:14:48 UTC
Fedora 19 changed to end-of-life (EOL) status on 2015-01-06. Fedora 19 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 3 Zbigniew Jędrzejewski-Szmek 2015-02-20 22:08:44 UTC
I don't think anything ever happened here.

Comment 4 Jaroslav Reznik 2015-03-03 15:12:36 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 22 development cycle.
Changing version to '22'.

More information and reason for this action is here:
https://fedoraproject.org/wiki/Fedora_Program_Management/HouseKeeping/Fedora22

Comment 5 Fedora End Of Life 2016-07-19 10:35:42 UTC
Fedora 22 changed to end-of-life (EOL) status on 2016-07-19. Fedora 22 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 6 Andrew J. Schorr 2016-07-20 00:16:48 UTC
I just tested on Fedora 24 with systemd-229-8.fc24.x86_64. In this version RateLimitBurst doesn't seem to work at all, regardless of the timing. I edited /etc/systemd/journald.conf to set RateLimitBurst=200 and then rebooted the system. When I run the test "verbose" init script, all 250 messages are logged.

Comment 7 Fedora End Of Life 2017-07-25 18:36:18 UTC
This message is a reminder that Fedora 24 is nearing its end of life.
Approximately 2 (two) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 24. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '24'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 24 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 8 Zbigniew Jędrzejewski-Szmek 2017-07-25 22:29:45 UTC
https://github.com/systemd/systemd/pull/6392 might improve things...

Comment 9 David Tardon 2022-08-23 14:39:03 UTC
A minimal reproducer:

# cat > verbose.awk <<EOF
#!/usr/bin/awk
BEGIN {
	i = 1
	for (j = 1; j <= 5; j++) {
		for (k = 1; k <= 50; k++)
			print "Here is startup message #", i++
		#system("sleep 1")
	}
}
EOF
# systemd-run --wait -p LogRateLimitBurst=200 -p LogRateLimitIntervalSec=10 awk -f verbose.awk