At Mon, 31 Oct 2011 23:28:49 +0000, David Laight <david%l8s.co.uk@localhost>
wrote:
Subject: Re: getrusage() problems with user vs. system time reporting
>
> On Mon, Oct 31, 2011 at 04:08:13PM -0700, Greg A. Woods wrote:
> >
> > So, if I understand the way SYSCALL_TIMES_PROCTIMES is implemented it
> > effectively converts the struct proc p_*ticks fields into cycle counts
> > instead of stathz tick counts. (though it seems enabling this does not
> > disable the additional accumulation of stathz ticks, nor does it adjust
> > the calculations in kern_resource.c to give expected values)
>
> It doesn't matter. With the cycle counter values, the stathz ticks
> are noise. The counts are then a bit like doing the stathz count
> on every tick of the cycle counter!
Ah, yes, of course! I realized that shortly after posting while I was
adding #ifdef's to turn off the counting in statclock(). :-)
> > Because they do use cpu_counter32(), I'm surprised they would be that
> > expensive to keep.
>
> If a cpu's TSC rate changes (eg with power saving) they they'll give
> different results. So you'd really need a nanotime function.
> OTOH using the valuse to split the total execution time is probably
> always better than the current code.
Wikipedia's entry on "Time Stamp Counter" (and Intel's app-note about
using RDTSC for performance monitoring) also mention that on any
processor since the Pentium Pro with out-of-order execution an accurate
cycle count can only be obtained by preceding the RDTSC instruction with
something like CPUID, or on CPUs which support one, the RDTSCP
instruction.
It is also mentioned that some processors run the time-stamp cycle
counter at a constant rate (not the actual current CPU clock rate)
(though apparently this quirk can be identified
And of course there's the issue of multiple processors, since as I
understand it the TSC on different cores are not synchronised.
Finally though I'm still learning more about virtual TSCs on VMware and
VirtualBox, I'm not so sure the TSC will be at all useful in such a
virtual machine environment.
Indeed with all this doom and gloom about TSC it seems it might be
better just to use binuptime() -- that probably won't be as fast
though.... Perhaps if I'm inspired tomorrow I'll try to re-do the
sysctl_stats.h macros to use it instead of cpu_counter32(), and then use
this real measure of system time in calcru() instead of pretending the
stathz ticks mean anything.
> Getting the TSC is (IIRC) 30-40 clocks on i386 - because it is a
> synchronising instruction. But it might be the delays only really
> affect back to back reads. ad@ knows more - it will be in the
> archives somewhere.
I found some references saying that it could be 150-200 cycles, and
another saying that it was closer to 80 cycles.
BTW, I don't seem to have any luck identifying the CPU in the VirtualBox
VM that I'm running NetBSD-5 in:
# cpuctl identify 0
cpuctl: cpuset_create: Cannot allocate memory
ktrace seems to say the error is coming from sysctl(), not calloc():
354 1 cpuctl CALL __sysctl(0xbfbfe954,2,0x80758e0,0xbfbfe95c,0,0)
354 1 cpuctl RET __sysctl 0
354 1 cpuctl CALL open(0x806b261,2,0x51)
354 1 cpuctl NAMI "/dev/cpuctl"
354 1 cpuctl RET open 3
354 1 cpuctl CALL __sysctl(0xbfbfe888,2,0xbfbfe8e0,0xbfbfe8e4,0,0)
354 1 cpuctl RET __sysctl 0
354 1 cpuctl CALL __sysctl(0xbfbfe858,2,0xbfbfe8b0,0xbfbfe8b4,0,0)
354 1 cpuctl RET __sysctl 0
354 1 cpuctl CALL __sysctl(0x8072130,2,0xbfbfe8e0,0xbfbfe8e4,0,0)
354 1 cpuctl RET __sysctl -1 errno 12 Cannot allocate memory
I was about to try to copy over a sysctl.debug symbol file from my build
machine, after turning on the network, and I got a crash as I started
the rcp, and it's the first time I've seen such a crash and the only
difference is that I've turned on SYSCALL_TIMES_PROCTIMES et al.
Mutex error: lockdebug_barrier: spin lock held
lock address : 0x00000000c0d4de54 type : spin
initialized : 0x00000000c04e7086
shared holds : 0 exclusive: 1
shares wanted: 0 exclusive: 0
current cpu : 0 last held: 0
current lwp : 0x00000000d3d02840 last held: 0x00000000d3d02840
last locked : 0x00000000c04e622c unlocked : 0x00000000c04e624b
owner field : 0x0000000000010700 wait/spin: 0/1
panic: LOCKDEBUG
Begin traceback...
copyright(c0d50643,0,0,c0c36d90,d2a69c40,d2a69bd8,c0d4de54,c0c33a24,d3d02840,c04e622c)
at 0xc0b8d29d
End traceback...
dumping to dev 0,1 offset 2000263
dump 51 50 49 48 47 46 45 44 43 42 41 40 39 38 37 36 35 34 33 32 31 30 29 28 27
26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 succeeded
rebooting...
(gdb) where
#0 0xc05d246c in cpu_reboot ()
#1 0xc04fbe30 in panic ()
#2 0xc04f476b in lockdebug_abort1 ()
#3 0xc04d54ca in rw_vector_enter ()
#4 0xc0466531 in vm_map_lock_read ()
#5 0xc045f472 in uvm_fault_internal ()
#6 0xc05d5a0e in trap ()
#7 0xc010ccd7 in calltrap ()
#8 0xc04e62e1 in dosetitimer ()
#9 0xc04e646e in sys_setitimer ()
#10 0xc05d4ebf in syscall ()
#11 0xc010058e in syscall1 ()
It's not an immediately repeatable crash though -- I was able to rcp the
debug symbol file over and confirm that the netbsd-5 branch still has
the bug in cpuset.c fixed by this change from over a year ago:
revision 1.16
date: 2010/09/21 02:03:29; author: rmind; state: Exp; lines: +3 -2
_cpuset_create: initialize size argument for sysctl call.
From PR/43837 by Sandy Snaman.
Now I go cry out again for FreeBSD's "merge-from-current" policy to be
enacted by NetBSD release engineering such that all such fixes always be
merged to the supported release branch(es) by default without need for a
pull-up ticket! (or that pull-up tickets automatically be generated for
all commits which fix bugs or which only add minor new features which
can easily be pulled up)
--
Greg A. Woods
Planix, Inc.
<woods%planix.com@localhost> +1 250 762-7675 http://www.planix.com/
Attachment:
pgpfnspA5n0RV.pgp
Description: PGP signature