Hi Thomas et al,

I was analyzing few traces with 'trace-cmd' and realized that timings weren't matching properly. For example consider this trace:

1 cat-1867 [000] d.h1 149.750891: hrtimer_expire_entry: hrtimer=ee7b3740 function=tick_sched_timer now=149740008694 2 cat-1867 [000] d.h1 149.750900: softirq_raise: vec=1 [action=TIMER] 3 cat-1867 [000] d.h1 149.750905: softirq_raise: vec=9 [action=RCU] 4 cat-1867 [000] d.h2 149.750910: sched_stat_runtime: comm=cat pid=1867 runtime=1463250 [ns] vruntime=4777557704 [ns] 5 cat-1867 [000] d.h1 149.750914: softirq_raise: vec=7 [action=SCHED] 6 cat-1867 [000] d.h1 149.750919: hrtimer_expire_exit: hrtimer=ee7b3740 7 cat-1867 [000] d.h2 149.750922: hrtimer_start: hrtimer=ee7b3740 function=tick_sched_timer expires=149745000000 softexpires=149745000000

Line 1: now=149.740008694 and trace-time: 149.750891. diff 10ms (consistently) Line 7: trace-time: 149.750922 and expires: 149.745000000, diff 5ms

So, either there is a mismatch of trace-times and required to be fixed? (@Steven)

Or we are almost always adding the tick-sched hrtimer in past?

I wasn't sure and tried to go through tick-sched and hrtimer core code again and this is what I realized.

At certain points we are trying to make sure that 'jiffies' are updated for current-time with loops like:

Lowres mode:

while (tick_nohz_reprogram(ts, now)) { now = ktime_get(); tick_do_update_jiffies64(now); }

tick_nohz_reprogram() does check if expires is in past and returns -ETIME (right?). And so we are guaranteed to updated jiffies to current time and reprogram clkevt device in future.

Highres mode: - First of all this kind of loop is missing from tick-handler: tick_sched_timer() as we are relying on hrtimer core to restart hrtimer for us and so we aren't trying to updated jiffies to latest values. And so we might (maybe always as shown in my traces) enqueue hrtimer in past.

- At some places we do have a while loop:

static void tick_nohz_restart(struct tick_sched *ts, ktime_t now) { ...

while (1) { /* Forward the time to expire in the future */ hrtimer_forward(&ts->sched_timer, now, tick_period);

if (ts->nohz_mode == NOHZ_MODE_HIGHRES) { hrtimer_start_expires(&ts->sched_timer, HRTIMER_MODE_ABS_PINNED); /* Check, if the timer was already in the past */ if (hrtimer_active(&ts->sched_timer)) break; } else { ... } ... } }

But I couldn't make out that this while loop will actually run for hres mode. Unlike tick_nohz_reprogram(), hrtimer_start_expires() never fails and calls enqueue_hrtimer() which does this: timer->state |= HRTIMER_STATE_ENQUEUED;

And so hrtimer_active() is guaranteed to return 'true' ? From the comment over hrtimer_active() here it looks we are trying to make sure that we aren't adding hrtimer in past, but code doesn't look like that.

And so there is a possibility that hrtimers are getting added in past.

I tried to go to the initial commit: 79bf2bb (tick-management: dyntick / highres functionality) and see if things were different there.

But they weren't.

Sorry for the long mail :)

-- viresh