Quick report:
The reason why this commit have bisected is because it changed
the type of time values from signed clock_t to unsigned cputime_t,
so that the following if-block become to be always taken:
> - stime = nsec_to_clock_t(p->se.sum_exec_runtime) -
> - cputime_to_clock_t(task_utime(p));
> + stime = nsecs_to_cputime(p->se.sum_exec_runtime) - task_utime(p);
> - p->prev_stime = max(p->prev_stime, clock_t_to_cputime(stime));
> + p->prev_stime = max(p->prev_stime, stime);
>
> return p->prev_stime;
From strace of latancytop, it does write to /proc/<pid>/sched:
5891 open("/proc/1/sched", O_RDWR) = 5
5891 fstat(5, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
5891 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7fc6668f3000
5891 read(5, "init (1, #threads: 1)\n----------"..., 1024) = 776
5891 close(5) = 0
It results in:
[kernel/sched_debug.c]
void proc_sched_set_task(struct task_struct *p)
{
:
p->se.sum_exec_runtime = 0;
p->se.prev_sum_exec_runtime = 0;
p->nvcsw = 0;
p->nivcsw = 0;
}
So soon some task will have great (in fact negative) stime.
There would be no doubt that this initialize in sched_debug.c
will break monotonicity of sum_exec_runtime. I confirmed that
the issue is disappeared by comment-out of lines above.
Reverting the bisected commit is wrong solution, because it
will bring another issue, i.e. lost of runtime, and u/stime
seems to be frozen because these values restart from 0 so
prev_* is used for a while.
How to fix? Is this a bug of latencytop? Kernel?
Please comment.
Thanks,
H.Seto
--
