Bug in recent kernel timer implementation
From: Pavel
Date: Mon Dec 14 2020 - 00:07:25 EST
Hi,
Seems like kernel timer implementation is buggy since some kernel
version (between 3.16.0 and 4.9.0).
Comments for add_timer in timer.c:
* The kernel will do a ->function(@timer) callback from the
* timer interrupt at the ->expires point in the future. The
* current time is 'jiffies'.
Linux x86, Linux x64. HZ=250.
init_timer(&my_timer);
my_timer.function = testjiffy_timer_function;
my_timer.expires = jiffies + 1;
add_timer(&my_timer);
So, according to comments in add_timer, testjiffy_timer_function should
be called next timer tick, 4ms later.
If you will run this code in Linux 3.16.0 - it will call
testjiffy_timer_function in the next timer tick (4ms later), as expected.
If you will run this code in Linux 4.9.0 - it will call
testjiffy_timer_function in the on second timer tick (8ms later)...
If you will modify code for Linux > 4.15 (setup_timer/mod_timer) - you
will get the same strange behaviour...
You can get code from here
https://stackoverflow.com/questions/16920238/reliability-of-linux-kernel-add-timer-at-resolution-of-one-jiffy
3.16.0
[52728.313029] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[52728.313720] testjiffy_timer_function: runcount 1, jif=13110976,
oldjif=13110975, delta=1
[52728.318743] testjiffy_timer_function: runcount 2, jif=13110977,
oldjif=13110976, delta=1
[52728.323304] testjiffy_timer_function: runcount 3, jif=13110978,
oldjif=13110977, delta=1
[52728.325824] testjiffy_timer_function: runcount 4, jif=13110979,
oldjif=13110978, delta=1
[52728.330811] testjiffy_timer_function: runcount 5, jif=13110980,
oldjif=13110979, delta=1
[52728.335802] testjiffy_timer_function: runcount 6, jif=13110981,
oldjif=13110980, delta=1
[52728.338305] testjiffy_timer_function: runcount 7, jif=13110982,
oldjif=13110981, delta=1
[52728.343298] testjiffy_timer_function: runcount 8, jif=13110983,
oldjif=13110982, delta=1
[52728.345806] testjiffy_timer_function: runcount 9, jif=13110984,
oldjif=13110983, delta=1
[52728.350885] testjiffy_timer_function: runcount 10, jif=13110985,
oldjif=13110984, delta=1
[52729.317263] Exit testjiffy
4.9.0
[52073.085341] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[52073.092322] testjiffy_timer_function: runcount 1, jif=4307910976,
oldjif=4307910974, delta=2
[52073.099818] testjiffy_timer_function: runcount 2, jif=4307910978,
oldjif=4307910976, delta=2
[52073.109830] testjiffy_timer_function: runcount 3, jif=4307910980,
oldjif=4307910978, delta=2
[52073.117362] testjiffy_timer_function: runcount 4, jif=4307910982,
oldjif=4307910980, delta=2
[52073.124845] testjiffy_timer_function: runcount 5, jif=4307910984,
oldjif=4307910982, delta=2
[52073.132315] testjiffy_timer_function: runcount 6, jif=4307910986,
oldjif=4307910984, delta=2
[52073.139816] testjiffy_timer_function: runcount 7, jif=4307910988,
oldjif=4307910986, delta=2
[52073.149824] testjiffy_timer_function: runcount 8, jif=4307910990,
oldjif=4307910988, delta=2
[52073.157303] testjiffy_timer_function: runcount 9, jif=4307910992,
oldjif=4307910990, delta=2
[52073.164824] testjiffy_timer_function: runcount 10, jif=4307910994,
oldjif=4307910992, delta=2
[52074.089574] Exit testjiffy