[Python-checkins] r46505 - python/trunk/Tools/pybench/systimes.py

Fri Jun 2 11:01:26 CEST 2006

Tim Peters wrote:
>> Author: marc-andre.lemburg
>> Date: Sun May 28 19:46:58 2006
>> New Revision: 46505
>>>> Added:
>> python/trunk/Tools/pybench/systimes.py (contents, props changed)
>> ...
>>> +def win32process_getprocesstimes_systimes():
>> + d = win32process.GetProcessTimes(win32process.GetCurrentProcess())
>> + # Note: I'm not sure whether KernelTime on Windows is the same as
>> + # system time on Unix - I've yet to see a non-zero value for
>> + # KernelTime on Windows.
>> + return (d['UserTime'] / WIN32_PROCESS_TIMES_TICKS_PER_SECOND,
>> + d['KernelTime'] / WIN32_PROCESS_TIMES_TICKS_PER_SECOND)
>> FYI, I always see a non-zero, and increasing, value for KernelTime on
> my box (WinXP Pro SP2).

Using your code I now see non-zero values as well - perhaps
KernelTime refers to calls being made to the win32 APIs ?!
I tested using standard Python code, such as long for
loops which don't call out to win32 APIs.
> Alas, these counters appear to have even worse resolution than
> time.time() on my box, incrementing a seemingly variable(!) number of
> times per second, but well under 100Hz:
>> """
> import win32process
>> def scream():
> from time import clock as now
> p = win32process.GetCurrentProcess()
> d = {}
> count = 0
> start = now()
> deadline = start + 1.0
> while now() < deadline:
> count += 1
> x = win32process.GetProcessTimes(p)
> d[x['UserTime']] = 1
> elapsed = now() - start
> print "saw", len(d), "distinct values in", \
> count, "tries across", elapsed, "seconds"
> print "user", x['UserTime'], "kernel", x['KernelTime']
> print
>> scream()
> scream()
> scream()
> """
>> One run of that here:
>> saw 74 distinct values in 134542 tries across 1.00000616787 seconds
> user 11562500 kernel 2187500
>> saw 81 distinct values in 133365 tries across 1.00000220027 seconds
> user 24062500 kernel 2968750
>> saw 68 distinct values in 132984 tries across 1.0000078902 seconds
> user 34531250 kernel 4687500

Question is whether this is really bad resolution or just the
effect of the OS not fetching the timer value in real-time,
but using some variable that is only updated at 50-100 Hz.
It is interesting to see how WinXP assigns slots to the processes
(the elapsed ticks values are number of ticks seen in 1 second).
saw 44 distinct values in 145439 tries across 1.00002849524 seconds
user 7500000 kernel 4062500
elapsed kernel ticks: 3281250
elapsed user ticks: 6718750
saw 48 distinct values in 146123 tries across 1.00000726349 seconds
user 15156250 kernel 6562500
elapsed kernel ticks: 2500000
elapsed user ticks: 7343750
saw 45 distinct values in 146262 tries across 1.00000279365 seconds
user 22187500 kernel 9531250
elapsed kernel ticks: 2968750
elapsed user ticks: 6875000
Here's the modified code:
"""
import win32process
def scream():
 from time import clock as now
 p = win32process.GetCurrentProcess()
 d = {}
 count = 0
 start = now()
 deadline = start + 1.0
 while now() < deadline:
 count += 1
 x = win32process.GetProcessTimes(p)
 d[x['UserTime']] = 1
 elapsed = now() - start
 print "saw", len(d), "distinct values in", \
 count, "tries across", elapsed, "seconds"
 print "user", x['UserTime'], "kernel", x['KernelTime']
 print
scream()
scream()
scream()
"""
-- 
Marc-Andre Lemburg
eGenix.com
Professional Python Services directly from the Source (#1, Jun 02 2006)
>>> Python/Zope Consulting and Support ... http://www.egenix.com/
>>> mxODBC.Zope.Database.Adapter ... http://zope.egenix.com/
>>> mxODBC, mxDateTime, mxTextTools ... http://python.egenix.com/
________________________________________________________________________
2006年07月03日: EuroPython 2006, CERN, Switzerland 30 days left
::: Try mxODBC.Zope.DA for Windows,Linux,Solaris,FreeBSD for free ! ::::