Re: [PATCH] possible fix for the runtime going backwards warnings

On Tuesday 21 February 2006 21:36, Kris Kennaway wrote:
> On Tue, Feb 21, 2006 at 10:47:04AM -0500, John Baldwin wrote:
> > The latest round of calcru() changes accidentally changed calccru() to
> > use the wrong rusage_ext structure (p->p_rux vs p->p_crux) when
> > calculating usage times for children.  The patch fixes calccru() to use
> > p->p_crux again.  It also moves the ruadd() in exit1() even later in the
> > function so that it takes the dying thread's last time slice into
> > account.  Please test it and let me know if it makes the messages go away
> > (or if it makes things worse!)  Thanks!
> >
> > http://www.FreeBSD.org/~jhb/patches/calccru.patch
>
> I think you committed this already, right?

Yes.

> I'm still getting calcru spam on the 3 SMP machines that I upgraded
> with fresh sources:

Is it more or less than before the patch?  Also, what happens if you just back 
out the kern_exit.c change?

>    Working revision:    1.284   Wed Feb 22 00:27:32 2006
>    Repository revision: 1.284   /c/ncvs/src/sys/kern/kern_exit.c,v
>
>    Working revision:    1.155   Wed Feb 22 00:27:33 2006
>    Repository revision: 1.155   /c/ncvs/src/sys/kern/kern_resource.c,v
>
> calcru: runtime went backwards from 140475 usec to 140458 usec for pid 724
> (csh) u 9:54457/54961 s 14:86017/85496 i 0:1/1
> calcru: runtime went backwards from 3855 usec to 3854 usec for pid 719
> (csh) u 0:0/0 s 1:3855/3854 i 0:0/0
> calcru: runtime went backwards from 19044 usec to 19043 usec for pid 713
> (tcsh) u 2:8888/12695 s 1:10156/6347 i 0:0/1
> calcru: runtime went backwards from 41540 usec to 41531 usec for pid 454
> (nfsd) u 4:27693/27687 s 2:13846/13843 i 0:1/1
> calcru: runtime went backwards from 4552 usec to 4551 usec for pid 452
> (mountd) u 0:0/0 s 1:4552/4551 i 0:0/0
> calcru: runtime went backwards from 564 usec to 563 usec for pid 140
> (adjkerntz) u 0:0/0 s 1:564/563 i 0:0/0
> calcru: runtime went backwards from 78654 usec to 78637 usec for pid 20
> (swi6: task queue) u 0:0/0 s 0:0/0 i 4:78654/78637
> calcru: runtime went backwards from 38428 usec to 38420 usec for pid 0
> (swapper) u 0:0/0 s 11:38428/38420 i 0:0/0
>
>
> calcru: runtime went backwards from 1496715 usec to 1496579 usec for pid 32
> (pagezero) u 0:0/0 s 199:1496715/1496579 i 0:0/0
> calcru: runtime went backwards from 102337 usec to 102327 usec for pid 0
> (swapper) u 0:0/0 s 41:102337/102327 i 0:0/0
>
>
> calcru: runtime went backwards from 1461648 usec to 1461600 usec for pid 32
> (pagezero) u 0:0/0 s 194:1461648/1461600 i 0:0/0
> calcru: runtime went backwards from 100852 usec to 100848 usec for pid 0
> (swapper) u 0:0/0 s 42:100852/100848 i 0:0/0

The pagezero ones are truly odd.  calcru() shouldn't be called for kthreads 
very often (if at all).  I wonder if your tickrate is changing out from under 
you.  Try editing sys/i386/i386/tsc.c and where it does 'set_cputicker(rdtsc, 
tsc_freq, 1)' change the last parameter to '0' and see if they go away.

-- 
John Baldwin <jhb_at_FreeBSD.org>  <><  http://www.FreeBSD.org/~jhb/
"Power Users Use the Power to Serve"  =  http://www.FreeBSD.org