Author: Carl Friedrich Bolz-Tereick <cfb...@gmx.de>
Branch: expose-gc-time
Changeset: r95376:24e0860e66ac
Date: 2018-11-28 15:27 +0100
http://bitbucket.org/pypy/pypy/changeset/24e0860e66ac/
Log: switch to use time.time() instead of read_timestamp for the GC time
measuring in hooks and stats
- this gives much more directly useful results
- it's plenty fast enough: on my machine one time.time call takes
~40ns, read_timestamp about ~10ns, while a minor gc step takes
~9000ns
diff --git a/pypy/goal/targetpypystandalone.py
b/pypy/goal/targetpypystandalone.py
--- a/pypy/goal/targetpypystandalone.py
+++ b/pypy/goal/targetpypystandalone.py
@@ -368,7 +368,7 @@
def get_gchooks(self):
from pypy.module.gc.hook import LowLevelGcHooks
if self.space is None:
- raise Exception("get_gchooks must be called afeter
get_entry_point")
+ raise Exception("get_gchooks must be called after get_entry_point")
return self.space.fromcache(LowLevelGcHooks)
def get_entry_point(self, config):
diff --git a/pypy/module/gc/hook.py b/pypy/module/gc/hook.py
--- a/pypy/module/gc/hook.py
+++ b/pypy/module/gc/hook.py
@@ -7,6 +7,8 @@
from pypy.interpreter.typedef import TypeDef, interp_attrproperty,
GetSetProperty
from pypy.interpreter.executioncontext import AsyncAction
+inf = float("inf")
+
class LowLevelGcHooks(GcHooks):
"""
These are the low-level hooks which are called directly from the GC.
@@ -126,9 +128,9 @@
def reset(self):
self.count = 0
- self.duration = r_longlong(0)
- self.duration_min = r_longlong(longlongmax)
- self.duration_max = r_longlong(0)
+ self.duration = 0.0
+ self.duration_min = inf
+ self.duration_max = 0.0
def fix_annotation(self):
# the annotation of the class and its attributes must be completed
@@ -136,9 +138,9 @@
# annotated with the correct types
if NonConstant(False):
self.count = NonConstant(-42)
- self.duration = NonConstant(r_longlong(-42))
- self.duration_min = NonConstant(r_longlong(-42))
- self.duration_max = NonConstant(r_longlong(-42))
+ self.duration = NonConstant(-53.2)
+ self.duration_min = NonConstant(-53.2)
+ self.duration_max = NonConstant(-53.2)
self.total_memory_used = NonConstant(r_uint(42))
self.pinned_objects = NonConstant(-42)
self.fire()
@@ -166,9 +168,9 @@
def reset(self):
self.count = 0
- self.duration = r_longlong(0)
- self.duration_min = r_longlong(longlongmax)
- self.duration_max = r_longlong(0)
+ self.duration = 0.0
+ self.duration_min = inf
+ self.duration_max = 0.0
def fix_annotation(self):
# the annotation of the class and its attributes must be completed
@@ -176,9 +178,9 @@
# annotated with the correct types
if NonConstant(False):
self.count = NonConstant(-42)
- self.duration = NonConstant(r_longlong(-42))
- self.duration_min = NonConstant(r_longlong(-42))
- self.duration_max = NonConstant(r_longlong(-42))
+ self.duration = NonConstant(-53.2)
+ self.duration_min = NonConstant(-53.2)
+ self.duration_max = NonConstant(-53.2)
self.oldstate = NonConstant(-42)
self.newstate = NonConstant(-42)
self.fire()
@@ -276,10 +278,14 @@
# just a shortcut to make the typedefs shorter
-def wrap_many_ints(cls, names):
+def wrap_many(cls, names):
d = {}
for name in names:
- d[name] = interp_attrproperty(name, cls=cls, wrapfn="newint")
+ if "duration" in name:
+ wrapfn = "newfloat"
+ else:
+ wrapfn = "newint"
+ d[name] = interp_attrproperty(name, cls=cls, wrapfn=wrapfn)
return d
@@ -303,7 +309,7 @@
W_GcMinorStats.typedef = TypeDef(
"GcMinorStats",
- **wrap_many_ints(W_GcMinorStats, (
+ **wrap_many(W_GcMinorStats, (
"count",
"duration",
"duration_min",
@@ -319,7 +325,7 @@
STATE_SWEEPING = incminimark.STATE_SWEEPING,
STATE_FINALIZING = incminimark.STATE_FINALIZING,
GC_STATES = tuple(incminimark.GC_STATES),
- **wrap_many_ints(W_GcCollectStepStats, (
+ **wrap_many(W_GcCollectStepStats, (
"count",
"duration",
"duration_min",
@@ -330,7 +336,7 @@
W_GcCollectStats.typedef = TypeDef(
"GcCollectStats",
- **wrap_many_ints(W_GcCollectStats, (
+ **wrap_many(W_GcCollectStats, (
"count",
"num_major_collects",
"arenas_count_before",
diff --git a/pypy/module/gc/test/test_hook.py b/pypy/module/gc/test/test_hook.py
--- a/pypy/module/gc/test/test_hook.py
+++ b/pypy/module/gc/test/test_hook.py
@@ -26,11 +26,11 @@
@unwrap_spec(ObjSpace)
def fire_many(space):
- gchooks.fire_gc_minor(5, 0, 0)
- gchooks.fire_gc_minor(7, 0, 0)
- gchooks.fire_gc_collect_step(5, 0, 0)
- gchooks.fire_gc_collect_step(15, 0, 0)
- gchooks.fire_gc_collect_step(22, 0, 0)
+ gchooks.fire_gc_minor(5.0, 0, 0)
+ gchooks.fire_gc_minor(7.0, 0, 0)
+ gchooks.fire_gc_collect_step(5.0, 0, 0)
+ gchooks.fire_gc_collect_step(15.0, 0, 0)
+ gchooks.fire_gc_collect_step(22.0, 0, 0)
gchooks.fire_gc_collect(1, 2, 3, 4, 5, 6)
cls.w_fire_gc_minor = space.wrap(interp2app(fire_gc_minor))
diff --git a/rpython/memory/gc/incminimark.py b/rpython/memory/gc/incminimark.py
--- a/rpython/memory/gc/incminimark.py
+++ b/rpython/memory/gc/incminimark.py
@@ -74,7 +74,6 @@
from rpython.rlib.debug import ll_assert, debug_print, debug_start, debug_stop
from rpython.rlib.objectmodel import specialize
from rpython.rlib import rgc
-from rpython.rlib.rtimer import read_timestamp
from rpython.memory.gc.minimarkpage import out_of_memory
#
@@ -193,15 +192,6 @@
# ____________________________________________________________
-def count_gc_time(meth):
- def timing_meth(self, *args):
- t1 = time.time()
- res = meth(self, *args)
- t2 = time.time()
- self.total_gc_time += t2 - t1
- return res
- timing_meth.func_name = meth.func_name + "_timing"
- return timing_meth
class IncrementalMiniMarkGC(MovingGCBase):
@@ -1653,12 +1643,11 @@
# ----------
# Nursery collection
- @count_gc_time
def _minor_collection(self):
"""Perform a minor collection: find the objects from the nursery
that remain alive and move them out."""
#
- start = read_timestamp()
+ start = time.time()
debug_start("gc-minor")
#
# All nursery barriers are invalid from this point on. They
@@ -1857,7 +1846,8 @@
self.root_walker.finished_minor_collection()
#
debug_stop("gc-minor")
- duration = read_timestamp() - start
+ duration = time.time() - start
+ self.total_gc_time += duration
self.hooks.fire_gc_minor(
duration=duration,
total_memory_used=total_memory_used,
@@ -2262,9 +2252,8 @@
# Note - minor collections seem fast enough so that one
# is done before every major collection step
- @count_gc_time
def major_collection_step(self, reserving_size=0):
- start = read_timestamp()
+ start = time.time()
debug_start("gc-collect-step")
oldstate = self.gc_state
debug_print("starting gc state: ", GC_STATES[self.gc_state])
@@ -2508,7 +2497,8 @@
debug_print("stopping, now in gc state: ", GC_STATES[self.gc_state])
debug_stop("gc-collect-step")
- duration = read_timestamp() - start
+ duration = time.time() - start
+ self.total_gc_time += duration
self.hooks.fire_gc_collect_step(
duration=duration,
oldstate=oldstate,
@@ -3110,7 +3100,6 @@
return llmemory.NULL
- @count_gc_time
def rrc_invoke_callback(self):
if self.rrc_enabled and self.rrc_dealloc_pending.non_empty():
self.rrc_dealloc_trigger_callback()
diff --git a/rpython/memory/gc/test/test_hook.py
b/rpython/memory/gc/test/test_hook.py
--- a/rpython/memory/gc/test/test_hook.py
+++ b/rpython/memory/gc/test/test_hook.py
@@ -70,7 +70,7 @@
assert self.gc.hooks.minors == [
{'total_memory_used': 0, 'pinned_objects': 0}
]
- assert self.gc.hooks.durations[0] > 0
+ assert self.gc.hooks.durations[0] > 0.
self.gc.hooks.reset()
#
# these objects survive, so the total_memory_used is > 0
@@ -103,7 +103,7 @@
]
assert len(self.gc.hooks.durations) == 4 # 4 steps
for d in self.gc.hooks.durations:
- assert d > 0
+ assert d > 0.0
self.gc.hooks.reset()
#
self.stackroots.append(self.malloc(S))
_______________________________________________
pypy-commit mailing list
pypy-commit@python.org
https://mail.python.org/mailman/listinfo/pypy-commit
