Usage of printk_ratelimit()

printk is used in kernel programming to print,logs, messages, errors etc  as we can not access the usual printf of the user space. The general syntax of prtink is
printk(  " statement", arguments);

The various Log levels and their meanings are listed in the file linux/kernel.h

While programming we can use a huge number of printk statements to debug or to track the flow of the code. But what if we want to control the logging to a certain limit to make sure that the logs don't get filled with messages.
For eg: on an error a module might repeatedly print error message every second filling up the logs with the same error. 
To handle such situations and control the amount pf logging we can use the printk_ratelimit function.
The kernel by default defines a limit of how many messages will it print before it stops printing for a while. The limit on the number of messages is set in
/proc/sys/kernel/printk_ratelimit_burst. 
After the above mentioned number of prints, kernel would stop printing for a predefined number of seconds which is set in the file
/proc/sys/kerne/printk_ratelimit. 

To use this rate limit feature of printk  we have to use the function printk_ratelimit().  The function returns true as long as the limit of number of messages printed does not excedd the limit set. Once the limit exceeds the functions starts retuning "0" .

Hence using this function with in a "if" condition we can limit the printing of our module .
if(printk_ratelimit())
 printk( "message");
This is depicted in the example module below. The values of the two proc entries are as follows
$ cat /proc/sys/kernel/printk_ratelimit_burst
10
$ cat /proc/sys/kernel/printk_ratelimit
5

In the module below we will try to print 20 messages continously. As see above , the limit set in the proc entry is for 10 messages. So we should be able to see only the first 10 prints of the 20 prints we are attempting.


****************************rate_limit.c********************************************
#include
#include


int rate_limit_init(void) {
int i;
unsigned long j0,j1;

j0 = jiffies;
j1 = jiffies + 30*HZ;

for(i=0;i<20;i++) {
if(printk_ratelimit()) {
printk(KERN_INFO"Printing %d", i);
    }
}

return 0;
}
void rate_limit_exit(void){
printk(KERN_INFO "Done");

}
module_init(rate_limit_init);
module_exit(rate_limit_exit);
******************************************************************************************

Use the following makefile to compile the module.

******************************Makefile***************************************************
ifneq ($(KERNELRELEASE),)
   obj-m := rate_limit.o
else

KERNELDIR ?= /lib/modules/$(shell uname -r)/build

PWD := $(shell pwd)

default:
    $(MAKE) -C $(KERNELDIR) M=$(PWD) modules 
clean:
    $(MAKE) -C $(KERNELDIR) M=$(PWD) clean
endif

*******************************************************************************************



Once compiled load it using insmod.

$insmod rate_limit.ko
$dmesg | tail -10[ 6886.360547] __ratelimit: 10 callbacks suppressed
[ 6886.360555] Printing 0
[ 6886.360559] Printing 1
[ 6886.360564] Printing 2
[ 6886.360567] Printing 3
[ 6886.360570] Printing 4
[ 6886.360574] Printing 5
[ 6886.360577] Printing 6
[ 6886.360580] Printing 7
[ 6886.360584] Printing 8
[ 6886.360587] Printing 9

The first line in the output says that 10 call backs were suppressed. So out of the 20 prints we tried only 10 successed and the other 10 were suppressed by the kernel because we used the function printk_ratelimit().


Now let us modify the code a little, and add a delay after the first failure to print i.e when we exceed the limit number of prints.
The wait time mentioned in proc entry is 5, so if we wait for 5 or more seconds we should see our prints again appear in the logs .

*********************************rate_limit_wait.c****************************************************************
#include
#include
#include

int rate_limit_init(void) {
int i;
unsigned long j0,j1;

j0 = jiffies;
j1 = jiffies + 30*HZ; // A wait for approximately 30 seconds

for(i=0;i<20;i++) {

if(printk_ratelimit()) {
printk(KERN_INFO"Printing %d", i);
   
    }

else {
    while(time_before(jiffies,j1));

    }
}

return 0;
}
void rate_limit_exit(void){

}
module_init(rate_limit_init);
module_exit(rate_limit_exit);
*********************************************************************************************************************
Use the same makefile shown above, just change the name of the module to rate_limit_wait.o or what ever you have named it as.

load the module using insmod

$insmod rate_limit.ko
$dmesg |tail -20
[15438.590395] Printing 0
[15438.590399] Printing 1
[15438.590403] Printing 2
[15438.590406] Printing 3
[15438.590410] Printing 4
[15438.590413] Printing 5
[15438.590416] Printing 6
[15438.590420] Printing 7
[15438.590423] Printing 8
[15438.590426] Printing 9
[15468.588021] __ratelimit: 1 callbacks suppressed
[15468.588029] Printing 11
[15468.588033] Printing 12
[15468.588037] Printing 13
[15468.588040] Printing 14
[15468.588043] Printing 15
[15468.588047] Printing 16
[15468.588050] Printing 17
[15468.588054] Printing 18
[15468.588057] Printing 19
As seen in the output of dmesg, after a delay of some seconds the printing regains again only one print has been missed which was right after the first 10
prints. Because of the delay introduced after reaching the limit, the prints after 10th print have also appeared in the logs.