ratelimit: Do not lose messages under limit

Currently "suppressed" messages will be printed once in a second for unseeded/urandom warnings, but there is already custom message which says how many warnings are missing. So, let's skip suppressed messages until crng_init == 2.

Quoted 7 lines · Dmitry Safonov

Currently "suppressed" messages will be printed once in a second for
unseeded/urandom warnings, but there is already custom message which
says how many warnings are missing. So, let's skip suppressed messages
until crng_init == 2.

I'm not sure what you are trying to fix? The whole point of the ratelimit system is to nly allow no more than <burst> packages in a particular time interval. Once that time interval has expired, messages allowed again until they exceed the burst limit. So printing
messages once a second is, in fact, working as intended.

Ok, then what's the purpose of those messages?
: pr_notice("random: %d get_random_xx warning(s) missed "
: "due to ratelimiting\n",
: unseeded_warning.missed);
: pr_notice("random: %d urandom warning(s) missed "
: "due to ratelimiting\n",
: urandom_warning.missed);

I thought you want to print the summary after initializing random, not once per second?

From my testing, it is *NOT* double-printing ratelimit messages today.

Quoted 9 lines · Dmitry Safonov

Ok, then what's the purpose of those messages?
: pr_notice("random: %d get_random_xx warning(s) missed "
: "due to ratelimiting\n",
: unseeded_warning.missed);
: pr_notice("random: %d urandom warning(s) missed "
: "due to ratelimiting\n",
: urandom_warning.missed);

Quoted 2 lines

I thought you want to print the summary after initializing random, not once per second?

Yes, and that's what is happening today. The "output lines suppressed
due to ratelimiting" message is only printed out by printk_ratelimit()
function, which we are *not* using.

random uses __ratelimit() which calls ___ratelimit() with a function name. Depending on !RATELIMIT_MSG_ON_RELEASE it prints how many messages were suppressed every ratelimit interval (1 second for random) and flushes ratelimit_state::missed:

Quoted 6 lines · Dmitry Safonov

random uses __ratelimit() which calls ___ratelimit() with a function
name. Depending on !RATELIMIT_MSG_ON_RELEASE it prints how many messages were suppressed every ratelimit interval (1 second for random)
and flushes ratelimit_state::missed:

So the thing about the ratelimit system is that if you have a burst of
1,000,000 within the one second burst window, and then nothing ever again, you will never see a message accounting for those 1,000,000 "callbacks" (which is a terrible wording; it just confuses people).

If you have a burst of 1,000,000 calls to ratelimit, and then a month goes by, and *then* a single call to __ratelimit is called by printk, only *the* does the message about the suppressed "callback" get printed.

So in the case of the random driver, once the random driver is fully intialized, there will never be a call to __ratelimit() for the urandom ratelimit structures, so we manually print out the final number of suppressed message so there is proper accounting for them.

It is not a double-count. If we didn't do that, those suppressed warnings would never be mentioned by the kernel.

Quoted 14 lines · Theodore Y. Ts'o

Quoted 6 lines · Dmitry Safonov

random uses __ratelimit() which calls ___ratelimit() with a function
name. Depending on !RATELIMIT_MSG_ON_RELEASE it prints how many messages were suppressed every ratelimit interval (1 second for random)
and flushes ratelimit_state::missed:

So the thing about the ratelimit system is that if you have a burst of
1,000,000 within the one second burst window, and then nothing ever again, you will never see a message accounting for those 1,000,000 "callbacks" (which is a terrible wording; it just confuses people).

Quoted 6 lines

If you have a burst of 1,000,000 calls to ratelimit, and then a month
goes by, and *then* a single call to __ratelimit is called by printk,
only *the* does the message about the suppressed "callback" get printed.

Yes, if the initialization time of driver is lesser than a second. If it's 1.1 sec - you'll have prints from ___ratelimit() and from your
driver too. And they differ in format.

Quoted 6 lines

So in the case of the random driver, once the random driver is fully
intialized, there will never be a call to __ratelimit() for the urandom ratelimit structures, so we manually print out the final number of suppressed message so there is proper accounting for them.

So, there is this flag, AFAICS, which perfectly fits your purpose RATELIMIT_MSG_ON_RELEASE which will omit printing how many messages were suppressed every interval of ___ratelimit(). And that will allow you to print total in the end.

Quoted 2 lines

It is not a double-count. If we didn't do that, those suppressed warnings would never be mentioned by the kernel.

Yeah, but what you print is not total sum, it's since the last interval
because without mentioned flag ___ratelimit() will flush missed counter
and print "suppressed" message.
They might even double if say other proccess has called get_random_bytes() got to ___ratelimit() and got preempted. This thread
finishes initializing random driver and prints this not-proper-sum statistics, and when the code flow is back in the first context, it will print statistics again from ___ratelimit() function.

Quoted 8 lines

Yeah, but what you print is not total sum, it's since the last interval because without mentioned flag ___ratelimit() will flush missed counter and print "suppressed" message. They might even double if say other proccess has called get_random_bytes() got to ___ratelimit() and got preempted. This thread finishes initializing random driver and prints this not-proper-sum statistics, and when the code flow is back in the first context, it will print statistics again from ___ratelimit() function.

So, does it make sense to you, Theodore?
If not - I'll just resend second patch rebasing and dropping this one.

Quoted 9 lines · Dmitry Safonov

Quoted 8 lines

Yeah, but what you print is not total sum, it's since the last interval because without mentioned flag ___ratelimit() will flush missed counter and print "suppressed" message. They might even double if say other proccess has called get_random_bytes() got to ___ratelimit() and got preempted. This thread finishes initializing random driver and prints this not-proper-sum statistics, and when the code flow is back in the first context, it will print statistics again from ___ratelimit() function.

Quoted 3 lines

So, does it make sense to you, Theodore?
If not - I'll just resend second patch rebasing and dropping this one.

Yes, it's correct that it's not the total sum. I guess your complaint
is that some of the messages are using the "callbacks suppressed" message, and the last one is using the random drvier's custom message which I think is much more user-friendly. That being said, although I
think "callbacks suppressed is a terrible message, I agree that using a single message makes more sense. So setting the RATELIMIT_MSG_ON_RELEASE and then calling ratelimit_state_exit() from crng_reseed() does make sense.

In the future I'd like to push for some way to customize --- or perhaps just fix --- "callbacks suppressed" to something more sane like, "messages ratelimited", but that's more of an aesthetics issue.