[CC'ing lkml this time]
Hi,
I've observed that smp_apic_timer_interrupt() is sometimes called
two or more times a second on a nohz_full core which has a single
task taking 100% of the core. In one of the calls, hrtimer_interrupt()
runs tick_sched_timer(), but in others it doesn't call any handler.
Here's an example (Linus HEAD f34157878):
<...>-1831 [008] 1060.115578: funcgraph_entry: |
smp_apic_timer_interrupt() {
<...>-1831 [008] 1060.115578: funcgraph_entry: |
hrtimer_interrupt() {
<...>-1831 [008] 1060.115578: hrtimer_expire_entry:
hrtimer=0xffff8edfefd12d60 function=tick_sched_timer now=1060079001980
<...>-1831 [008] 1060.115578: funcgraph_entry: 1.172 us |
tick_sched_timer();
<...>-1831 [008] 1060.115580: funcgraph_exit: 1.757 us | }
<...>-1831 [008] 1060.115580: hrtimer_start:
hrtimer=0xffff8edfefd12d60 function=tick_sched_timer expires=1061079000000
softexpires=1061079000000
<...>-1831 [008] 1060.115581: funcgraph_exit: 3.026 us | }
<...>-1831 [008] 1061.115577: funcgraph_entry: |
smp_apic_timer_interrupt() {
<...>-1831 [008] 1061.115577: funcgraph_entry: 0.261 us |
hrtimer_interrupt(); <---------- NO handler called
<...>-1831 [008] 1061.115578: funcgraph_exit: 1.349 us | }
<...>-1831 [008] 1061.115579: funcgraph_entry: |
smp_apic_timer_interrupt() {
<...>-1831 [008] 1061.115579: funcgraph_entry: |
hrtimer_interrupt() {
<...>-1831 [008] 1061.115579: hrtimer_expire_entry:
hrtimer=0xffff8edfefd12d60 function=tick_sched_timer now=1061079001473
<...>-1831 [008] 1061.115580: funcgraph_entry: 1.413 us |
tick_sched_timer();
<...>-1831 [008] 1061.115581: funcgraph_exit: 2.124 us | }
<...>-1831 [008] 1061.115582: hrtimer_start:
hrtimer=0xffff8edfefd12d60 function=tick_sched_timer expires=1062079000000
softexpires=1062079000000
<...>-1831 [008] 1061.115582: funcgraph_exit: 3.255 us | }
Is this expected for some reason?
I guess what's happening is that the deadline timer is firing
earlier than expected. From a few dozen to a few hundreds
nanoseconds earlier. When this happens, hrtimer_interrupt()
skips calling the hrtimer handler (since it's early) and the
apic is programmed to fire in the next microsecond.
On further research I saw that Nicolai tried to fix a very similar
problem last year:
commit 1a9e4c564ab174e53ed86def922804a5ddc63e7d
Author: Nicolai Stange <[email protected]>
Date: Thu Jul 14 17:22:54 2016 +0200
x86/timers/apic: Fix imprecise timer interrupts by eliminating TSC
clockevents frequency roundoff error
I noticed the following bug/misbehavior on certain Intel systems: with a
single task running on a NOHZ CPU on an Intel Haswell, I recognized
that I did not only get the one expected local_timer APIC interrupt, but
two per second at minimum. (!)
Maybe this issue is still present?
