Re: scheduler bug: process running since 5124095h

Re: scheduler bug: process running since 5124095h

[Török Edwin]

On 03/27/2010 11:46 AM, Török Edwin wrote:
> Hi Ingo, Peter,
> 
> top has just shown me this:
> PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> 
>                                                                  6524
> edwin     20   0  228m  10m 8116 R    2  0.3  5124095h gkrellm
> 
> Now obviously that process is not running since 5124095h!
> It looks like some overflow to me, the time in nanoseconds would be
> approx 0xFFFFFE1D2D476000, which is approx. minus 34 minutes.
> Thats about consistent with the uptime, but I don't know why it became
> negative:
>  11:45:48 up 42 min,  9 users,  load average: 0.56, 0.25, 0.19
> 
> I've attached the cfs-debug-info.sh output.
> 
> This happens when using Linux 2.6.33 (actually glisse's drm-radeon tree
> which is based on 2.6.33), its the first time I noticed this.
> 
> I don't know what caused it, the last things I did was:

I have a simple way to reproduce this:
1. Boot the system, run top, confirm everything is normal
2. Run latencytop, and quit (I used version 0.5)
3. Run top, see 5124095h in the TIME column

For example:
 6649 daemon    20   0 74500 8892 3796 S    6  0.2   0:00.03 debsecan
 4255 root      20   0  8908  360  260 S    2  0.0   0:00.04 irqbalance
    1 root      20   0 10332  692  580 S    0  0.0  5124095h init

The processes that get the 5124095h seem random, but there are plenty of
them (if you sort by 'T', the entire top display is filled with
processes running since 5124095h).

Best regards,
--Edwin

Re: scheduler bug: process running since 5124095h

[Mike Galbraith]

On Sun, 2010-03-28 at 11:49 +0300, Török Edwin wrote:
> On 03/27/2010 11:46 AM, Török Edwin wrote:
> > Hi Ingo, Peter,
> > 
> > top has just shown me this:
> > PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> > 
> >                                                                  6524
> > edwin     20   0  228m  10m 8116 R    2  0.3  5124095h gkrellm
> > 
> > Now obviously that process is not running since 5124095h!
> > It looks like some overflow to me, the time in nanoseconds would be
> > approx 0xFFFFFE1D2D476000, which is approx. minus 34 minutes.
> > Thats about consistent with the uptime, but I don't know why it became
> > negative:
> >  11:45:48 up 42 min,  9 users,  load average: 0.56, 0.25, 0.19
> > 
> > I've attached the cfs-debug-info.sh output.
> > 
> > This happens when using Linux 2.6.33 (actually glisse's drm-radeon tree
> > which is based on 2.6.33), its the first time I noticed this.
> > 
> > I don't know what caused it, the last things I did was:
> 
> I have a simple way to reproduce this:
> 1. Boot the system, run top, confirm everything is normal
> 2. Run latencytop, and quit (I used version 0.5)
> 3. Run top, see 5124095h in the TIME column

Indeed, and I don't even have CONFIG_LATENCYTOP set.  It bisected to...

761b1d26df542fd5eb348837351e4d2f3bc7bffe is the first bad commit
commit 761b1d26df542fd5eb348837351e4d2f3bc7bffe
Author: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
Date:   Thu Nov 12 13:33:45 2009 +0900

    sched: Fix granularity of task_u/stime()
    
    Originally task_s/utime() were designed to return clock_t but
    later changed to return cputime_t by following commit:
    
      commit efe567fc8281661524ffa75477a7c4ca9b466c63
      Author: Christian Borntraeger <borntraeger@de.ibm.com>
      Date:   Thu Aug 23 15:18:02 2007 +0200
    
    It only changed the type of return value, but not the
    implementation. As the result the granularity of task_s/utime()
    is still that of clock_t, not that of cputime_t.
    
    So using task_s/utime() in __exit_signal() makes values
    accumulated to the signal struct to be rounded and coarse
    grained.
    
    This patch removes casts to clock_t in task_u/stime(), to keep
    granularity of cputime_t over the calculation.
    
    v2:
      Use div_u64() to avoid error "undefined reference to `__udivdi3`"
      on some 32bit systems.
    
    Signed-off-by: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
    Acked-by: Peter Zijlstra <peterz@infradead.org>
    Cc: xiyou.wangcong@gmail.com
    Cc: Spencer Candland <spencer@bluehost.com>
    Cc: Oleg Nesterov <oleg@redhat.com>
    Cc: Stanislaw Gruszka <sgruszka@redhat.com>
    LKML-Reference: <4AFB9029.9000208@jp.fujitsu.com>
    Signed-off-by: Ingo Molnar <mingo@elte.hu>

:040000 040000 9b4e832857ee9694807de86be7d88bbbc2223c50 a78e66f0b8356005c3b963de64b38269147e47e0 M	kernel
git bisect start
# good: [7f5e918e62cbc9ac27c2f47d3c3dd4b86f67ff0e] Linux 2.6.32.9
git bisect good 7f5e918e62cbc9ac27c2f47d3c3dd4b86f67ff0e
# bad: [baac35c4155a8aa826c70acee6553368ca5243a2] security: fix error return path in ima_inode_alloc
git bisect bad baac35c4155a8aa826c70acee6553368ca5243a2
# bad: [baac35c4155a8aa826c70acee6553368ca5243a2] security: fix error return path in ima_inode_alloc
git bisect bad baac35c4155a8aa826c70acee6553368ca5243a2
# bad: [baac35c4155a8aa826c70acee6553368ca5243a2] security: fix error return path in ima_inode_alloc
git bisect bad baac35c4155a8aa826c70acee6553368ca5243a2
# good: [22763c5cf3690a681551162c15d34d935308c8d7] Linux 2.6.32
git bisect good 22763c5cf3690a681551162c15d34d935308c8d7
# bad: [5f1141eb352ea79d849920039503e40dd623fffa] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/ieee1394/linux1394-2.6
git bisect bad 5f1141eb352ea79d849920039503e40dd623fffa
# bad: [d7fc02c7bae7b1cf69269992cf880a43a350cdaa] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next-2.6
git bisect bad d7fc02c7bae7b1cf69269992cf880a43a350cdaa
# good: [cfb3f91af49dff9b50de6929dc4de06100c4cfa8] ixgbe: handle parameters for tx and rx EITR, no div0
git bisect good cfb3f91af49dff9b50de6929dc4de06100c4cfa8
# good: [c3fa27d1367fac63ac8533d6f20ea851d0d70a10] Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect good c3fa27d1367fac63ac8533d6f20ea851d0d70a10
# good: [86e1d57e4f24ca27ce813bdc2afaac4adafcbaf4] Merge branch 'topic/hda' into for-linus
git bisect good 86e1d57e4f24ca27ce813bdc2afaac4adafcbaf4
# good: [8f56874bd7e8bee73ed6a1cf80dcec2753616262] Merge branch 'master' of git://git.kernel.org/pub/scm/linux/kernel/git/linville/wireless-next-2.6
git bisect good 8f56874bd7e8bee73ed6a1cf80dcec2753616262
# bad: [c2ed69cdc9da49a8d2d7b4212fd225abf902ceaa] Merge branch 'x86-cleanups-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect bad c2ed69cdc9da49a8d2d7b4212fd225abf902ceaa
# bad: [897e81bea1fcfcd2c5cdb720c9efdb25da9ff374] Merge branch 'sched-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect bad 897e81bea1fcfcd2c5cdb720c9efdb25da9ff374
# bad: [fe3bcfe1f6c1fc4ea7706ac2d05e579fd9092682] sched: More generic WAKE_AFFINE vs select_idle_sibling()
git bisect bad fe3bcfe1f6c1fc4ea7706ac2d05e579fd9092682
# good: [e2c880630438f80b474378d5487b511b07665051] cpumask: Simplify sched_rt.c
git bisect good e2c880630438f80b474378d5487b511b07665051
# good: [d8c80ce091f6ead6710bc71b58f2c32e5bf855e4] sched, no_hz: Remove unused rq->last_tick_seen field
git bisect good d8c80ce091f6ead6710bc71b58f2c32e5bf855e4
# good: [ffd44db5f02af32bcc25a8eb5981bf02a141cdab] sched: Make sure task has correct sched_class after policy change
git bisect good ffd44db5f02af32bcc25a8eb5981bf02a141cdab
# bad: [a50bde5130f65733142b32975616427d0ea50856] sched: Cleanup select_task_rq_fair()
git bisect bad a50bde5130f65733142b32975616427d0ea50856
# bad: [761b1d26df542fd5eb348837351e4d2f3bc7bffe] sched: Fix granularity of task_u/stime()
git bisect bad 761b1d26df542fd5eb348837351e4d2f3bc7bffe

Re: scheduler bug: process running since 5124095h

[Peter Zijlstra]

On Mon, 2010-03-29 at 12:52 +0200, Mike Galbraith wrote:
> > I have a simple way to reproduce this:
> > 1. Boot the system, run top, confirm everything is normal
> > 2. Run latencytop, and quit (I used version 0.5)
> > 3. Run top, see 5124095h in the TIME column
> 
> Indeed, and I don't even have CONFIG_LATENCYTOP set.  It bisected
> to...
> 
> 761b1d26df542fd5eb348837351e4d2f3bc7bffe is the first bad commit
> commit 761b1d26df542fd5eb348837351e4d2f3bc7bffe
> Author: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
> Date:   Thu Nov 12 13:33:45 2009 +0900


Oh lovely, and reverting that cures the issue?

Re: scheduler bug: process running since 5124095h

[Mike Galbraith]

On Mon, 2010-03-29 at 12:54 +0200, Peter Zijlstra wrote:
> On Mon, 2010-03-29 at 12:52 +0200, Mike Galbraith wrote:
> > > I have a simple way to reproduce this:
> > > 1. Boot the system, run top, confirm everything is normal
> > > 2. Run latencytop, and quit (I used version 0.5)
> > > 3. Run top, see 5124095h in the TIME column
> > 
> > Indeed, and I don't even have CONFIG_LATENCYTOP set.  It bisected
> > to...
> > 
> > 761b1d26df542fd5eb348837351e4d2f3bc7bffe is the first bad commit
> > commit 761b1d26df542fd5eb348837351e4d2f3bc7bffe
> > Author: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
> > Date:   Thu Nov 12 13:33:45 2009 +0900
> 
> 
> Oh lovely, and reverting that cures the issue?

Haven't done so yet, will do later this afternoon.

	-Mike

Re: scheduler bug: process running since 5124095h

[Hidetoshi Seto]

(2010/03/29 19:52), Mike Galbraith wrote:
> On Sun, 2010-03-28 at 11:49 +0300, Török Edwin wrote:
>> On 03/27/2010 11:46 AM, Török Edwin wrote:
>>> Hi Ingo, Peter,
>>>
>>> top has just shown me this:
>>> PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>>
>>>                                                                  6524
>>> edwin     20   0  228m  10m 8116 R    2  0.3  5124095h gkrellm
>>>
>>> Now obviously that process is not running since 5124095h!
>>> It looks like some overflow to me, the time in nanoseconds would be
>>> approx 0xFFFFFE1D2D476000, which is approx. minus 34 minutes.
>>> Thats about consistent with the uptime, but I don't know why it became
>>> negative:
>>>  11:45:48 up 42 min,  9 users,  load average: 0.56, 0.25, 0.19
>>>
>>> I've attached the cfs-debug-info.sh output.
>>>
>>> This happens when using Linux 2.6.33 (actually glisse's drm-radeon tree
>>> which is based on 2.6.33), its the first time I noticed this.
>>>
>>> I don't know what caused it, the last things I did was:
>>
>> I have a simple way to reproduce this:
>> 1. Boot the system, run top, confirm everything is normal
>> 2. Run latencytop, and quit (I used version 0.5)
>> 3. Run top, see 5124095h in the TIME column
> 
> Indeed, and I don't even have CONFIG_LATENCYTOP set.  It bisected to...
> 
> 761b1d26df542fd5eb348837351e4d2f3bc7bffe is the first bad commit
> commit 761b1d26df542fd5eb348837351e4d2f3bc7bffe
> Author: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
> Date:   Thu Nov 12 13:33:45 2009 +0900

Wow, it's easy to reproduce. I'll check it later... 


Thanks,
H.Seto

Re: scheduler bug: process running since 5124095h

[Hidetoshi Seto]

(2010/03/29 21:04), Hidetoshi Seto wrote:
> (2010/03/29 19:52), Mike Galbraith wrote:
>> On Sun, 2010-03-28 at 11:49 +0300, Török Edwin wrote:
>>> On 03/27/2010 11:46 AM, Török Edwin wrote:
>>>> Hi Ingo, Peter,
>>>>
>>>> top has just shown me this:
>>>> PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>>>
>>>>                                                                  6524
>>>> edwin     20   0  228m  10m 8116 R    2  0.3  5124095h gkrellm
>>>>
>>>> Now obviously that process is not running since 5124095h!
>>>> It looks like some overflow to me, the time in nanoseconds would be
>>>> approx 0xFFFFFE1D2D476000, which is approx. minus 34 minutes.
>>>> Thats about consistent with the uptime, but I don't know why it became
>>>> negative:
>>>>  11:45:48 up 42 min,  9 users,  load average: 0.56, 0.25, 0.19
>>>>
>>>> I've attached the cfs-debug-info.sh output.
>>>>
>>>> This happens when using Linux 2.6.33 (actually glisse's drm-radeon tree
>>>> which is based on 2.6.33), its the first time I noticed this.
>>>>
>>>> I don't know what caused it, the last things I did was:
>>>
>>> I have a simple way to reproduce this:
>>> 1. Boot the system, run top, confirm everything is normal
>>> 2. Run latencytop, and quit (I used version 0.5)
>>> 3. Run top, see 5124095h in the TIME column
>>
>> Indeed, and I don't even have CONFIG_LATENCYTOP set.  It bisected to...
>>
>> 761b1d26df542fd5eb348837351e4d2f3bc7bffe is the first bad commit
>> commit 761b1d26df542fd5eb348837351e4d2f3bc7bffe
>> Author: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
>> Date:   Thu Nov 12 13:33:45 2009 +0900

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);
   > 
>> >         if (stime >= 0)
   > -               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  read(5, "", 1024)                 = 0
>> 5891  write(5, "erase", 5)              = 5
   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

Re: scheduler bug: process running since 5124095h

[Mike Galbraith]

On Tue, 2010-03-30 at 15:22 +0900, Hidetoshi Seto wrote:

> 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);
>    > 
> >> >         if (stime >= 0)
>    > -               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  read(5, "", 1024)                 = 0
> >> 5891  write(5, "erase", 5)              = 5
>    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;
> }

Hm.  Dunno why that (evilness) exists.

> 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.

I looked at it in tip this morning (where task_stime doesn't exist), and
did the below to swat the underflow.  Seems ok, but I haven't yet
enabled CONFIG_LATENCYTOP.

diff --git a/kernel/sched.c b/kernel/sched.c
index 81575f1..cdf4fa4 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -3366,6 +3366,7 @@ void task_times(struct task_struct *p, cputime_t *ut, cputime_t *st)
 	 * Compare with previous values, to keep monotonicity:
 	 */
 	p->prev_utime = max(p->prev_utime, utime);
+	rtime = max(rtime, p->prev_utime);
 	p->prev_stime = max(p->prev_stime, cputime_sub(rtime, p->prev_utime));
 
 	*ut = p->prev_utime;
@@ -3396,6 +3397,7 @@ void thread_group_times(struct task_struct *p, cputime_t *ut, cputime_t *st)
 		utime = rtime;
 
 	sig->prev_utime = max(sig->prev_utime, utime);
+	rtime = max(rtime, sig->prev_utime);
 	sig->prev_stime = max(sig->prev_stime,
 			      cputime_sub(rtime, sig->prev_utime));
 

Re: scheduler bug: process running since 5124095h

[Mike Galbraith]

On Tue, 2010-03-30 at 10:07 +0200, Mike Galbraith wrote:
> On Tue, 2010-03-30 at 15:22 +0900, Hidetoshi Seto wrote:
> 
> > 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);
> >    > 
> > >> >         if (stime >= 0)
> >    > -               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  read(5, "", 1024)                 = 0
> > >> 5891  write(5, "erase", 5)              = 5
> >    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;
> > }
> 
> Hm.  Dunno why that (evilness) exists.
> 
> > 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.

I think the correct fix is to not allow resetting of those 4 fields, as
they're used elsewhere in kernel.  Latencytop doesn't seem to miss being
allowed to scribble.  Dunno why it wants to reset any of these though.

sched: fix proc_sched_set_task()

Latencytop clearing sum_exec_runtime via proc_sched_set_task() breaks
task_times().  Other places in kernel use nvcsw and nivcsw, which are
being cleared as well,  Clear task statistics only.

Signed-off-by: Mike Galbraith <efault@gmx.de>
Cc: Ingo Molnar <mingo@elte.hu>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Hidetoshi Seto <seto.hidetoshi@jp.fujitsu.com>
Reported-by: Török Edwin <edwintorok@gmail.com>
LKML-Reference: <new-submission>

diff --git a/kernel/sched_debug.c b/kernel/sched_debug.c
index 8a46a71..ea2c690 100644
--- a/kernel/sched_debug.c
+++ b/kernel/sched_debug.c
@@ -491,8 +491,4 @@ void proc_sched_set_task(struct task_struct *p)
 #ifdef CONFIG_SCHEDSTATS
 	memset(&p->se.statistics, 0, sizeof(p->se.statistics));
 #endif
-	p->se.sum_exec_runtime			= 0;
-	p->se.prev_sum_exec_runtime		= 0;
-	p->nvcsw				= 0;
-	p->nivcsw				= 0;
 }

Re: scheduler bug: process running since 5124095h

[Peter Zijlstra]

On Tue, 2010-03-30 at 15:22 +0900, Hidetoshi Seto wrote:
> 
> [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;
> } 

Urgh, that code should really die, bugger that latencytop relies on that
though. Arjan anything you can do to cure latencytop of this madness?

Re: scheduler bug: process running since 5124095h

[Mike Galbraith]

On Tue, 2010-03-30 at 11:01 +0200, Peter Zijlstra wrote:
> On Tue, 2010-03-30 at 15:22 +0900, Hidetoshi Seto wrote:
> > 
> > [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;
> > } 
> 
> Urgh, that code should really die, bugger that latencytop relies on that
> though. Arjan anything you can do to cure latencytop of this madness?

I killed those 4 fields without _seeming_ to upset it.

	-Mike

Re: scheduler bug: process running since 5124095h

[Peter Zijlstra]

On Tue, 2010-03-30 at 11:12 +0200, Mike Galbraith wrote:
> On Tue, 2010-03-30 at 11:01 +0200, Peter Zijlstra wrote:
> > On Tue, 2010-03-30 at 15:22 +0900, Hidetoshi Seto wrote:
> > > 
> > > [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;
> > > } 
> > 
> > Urgh, that code should really die, bugger that latencytop relies on that
> > though. Arjan anything you can do to cure latencytop of this madness?
> 
> I killed those 4 fields without _seeming_ to upset it.

OK, if Arjan doesn't complain I'll take it ;-)