Bug in recent kernel timer implementation

[Pavel <biohumanoid.lists@gmail.com>]

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