Re: PROBLEM: Scheduling latency not respected in CFS with HRTICK enabled

From: Wanpeng Li
Date: Tue May 10 2016 - 20:53:14 EST


2016-05-06 23:43 GMT+08:00 Tomasz Grabiec <tgrabiec@xxxxxxxxxxxx>:
[...]
> prev_comm=python prev_pid=873 prev_prio=120 prev_state=R ==>
> next_comm=python next_pid=874 next_prio=120
> python 874 [002] 3273334.932741: probe:hrtick: (ffffffff8109b430)
> python 874 [002] 3273334.932742: sched:sched_stat_runtime:
> comm=python pid=874 runtime=503174 [ns] vruntime=1549788942230752 [ns]

hrtick fire after almost 0.5ms(the time slice process 874 get).

> python 874 [002] 3273334.932743: sched:sched_stat_runtime:
> comm=python pid=874 runtime=948 [ns] vruntime=1549788942231700 [ns]
> python 874 [002] 3273334.936240: probe:scheduler_tick: (ffffffff810a1f30)
> python 874 [002] 3273334.936241: sched:sched_stat_runtime:
> comm=python pid=874 runtime=3497530 [ns] vruntime=1549788945729230
> [ns]

continue to run another 3.4ms until next normal scheduler tick fire.

> python 874 [002] 3273334.936249: sched:sched_stat_runtime:
> comm=python pid=874 runtime=8553 [ns] vruntime=1549788945737783 [ns]
> python 874 [002] 3273334.936250: sched:sched_stat_wait:
> comm=python pid=873 delay=4010205 [ns]
> python 874 [002] 3273334.936250: probe:hrtick_start: (ffffffff8109f4f0)
> python 874 [002] 3273334.936251: sched:sched_switch:
> prev_comm=python prev_pid=874 prev_prio=120 prev_state=R ==>
> next_comm=python next_pid=873 next_prio=120

So the process 874 continue to run util next scheduler fick event if
hrtick has already fired. I think Peterz can give any light.

Ping Peterz :-)

Regards,
Wanpeng Li