Author: Carl Friedrich Bolz-Tereick <cfb...@gmx.de> Branch: Changeset: r95390:c8b8ee6787e9 Date: 2018-11-30 16:20 +0100 http://bitbucket.org/pypy/pypy/changeset/c8b8ee6787e9/
Log: merge expose-gc-time: expose the total time spent in the GC, also switch to using seconds in the GC hooks diff --git a/pypy/doc/whatsnew-head.rst b/pypy/doc/whatsnew-head.rst --- a/pypy/doc/whatsnew-head.rst +++ b/pypy/doc/whatsnew-head.rst @@ -51,3 +51,8 @@ .. branch: rlock-in-rpython Backport CPython fix for `thread.RLock` + + +.. branch: expose-gc-time + +Make GC hooks measure time in seconds (as opposed to an opaque unit). 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/app_referents.py b/pypy/module/gc/app_referents.py --- a/pypy/module/gc/app_referents.py +++ b/pypy/module/gc/app_referents.py @@ -57,12 +57,14 @@ 'total_allocated_memory', 'jit_backend_allocated', 'peak_memory', 'peak_allocated_memory', 'total_arena_memory', 'total_rawmalloced_memory', 'nursery_size', - 'peak_arena_memory', 'peak_rawmalloced_memory'): + 'peak_arena_memory', 'peak_rawmalloced_memory', + ): setattr(self, item, self._format(getattr(self._s, item))) self.memory_used_sum = self._format(self._s.total_gc_memory + self._s.total_memory_pressure + self._s.jit_backend_used) self.memory_allocated_sum = self._format(self._s.total_allocated_memory + self._s.total_memory_pressure + self._s.jit_backend_allocated) + self.total_gc_time = self._s.total_gc_time def _format(self, v): if v < 1000000: @@ -92,6 +94,8 @@ raw assembler allocated: %s%s ----------------------------- Total: %s + + Total time spent in GC: %s """ % (self.total_gc_memory, self.peak_memory, self.total_arena_memory, self.total_rawmalloced_memory, @@ -106,7 +110,8 @@ self.nursery_size, self.jit_backend_allocated, extra, - self.memory_allocated_sum) + self.memory_allocated_sum, + self.total_gc_time / 1000.0) def get_stats(memory_pressure=False): 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/referents.py b/pypy/module/gc/referents.py --- a/pypy/module/gc/referents.py +++ b/pypy/module/gc/referents.py @@ -189,6 +189,7 @@ self.peak_arena_memory = rgc.get_stats(rgc.PEAK_ARENA_MEMORY) self.peak_rawmalloced_memory = rgc.get_stats(rgc.PEAK_RAWMALLOCED_MEMORY) self.nursery_size = rgc.get_stats(rgc.NURSERY_SIZE) + self.total_gc_time = rgc.get_stats(rgc.TOTAL_GC_TIME) W_GcStats.typedef = TypeDef("GcStats", total_memory_pressure=interp_attrproperty("total_memory_pressure", @@ -215,6 +216,8 @@ cls=W_GcStats, wrapfn="newint"), nursery_size=interp_attrproperty("nursery_size", cls=W_GcStats, wrapfn="newint"), + total_gc_time=interp_attrproperty("total_gc_time", + cls=W_GcStats, wrapfn="newint"), ) @unwrap_spec(memory_pressure=bool) 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 @@ -62,6 +62,7 @@ # XXX old_objects_pointing_to_young (IRC 2014-10-22, fijal and gregor_w) import sys import os +import time from rpython.rtyper.lltypesystem import lltype, llmemory, llarena, llgroup from rpython.rtyper.lltypesystem.lloperation import llop from rpython.rtyper.lltypesystem.llmemory import raw_malloc_usage @@ -73,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 # @@ -192,6 +192,8 @@ # ____________________________________________________________ + + class IncrementalMiniMarkGC(MovingGCBase): _alloc_flavor_ = "raw" inline_simple_malloc = True @@ -374,6 +376,7 @@ self.raw_malloc_might_sweep = self.AddressStack() self.rawmalloced_total_size = r_uint(0) self.rawmalloced_peak_size = r_uint(0) + self.total_gc_time = 0.0 self.gc_state = STATE_SCANNING # @@ -1644,7 +1647,7 @@ """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 @@ -1843,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, @@ -2249,7 +2253,7 @@ # Note - minor collections seem fast enough so that one # is done before every major collection step 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]) @@ -2493,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, @@ -3000,6 +3005,8 @@ self.ac.total_memory_used)) elif stats_no == rgc.NURSERY_SIZE: return intmask(self.nursery_size) + elif stats_no == rgc.TOTAL_GC_TIME: + return int(self.total_gc_time * 1000) return 0 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)) diff --git a/rpython/rlib/rgc.py b/rpython/rlib/rgc.py --- a/rpython/rlib/rgc.py +++ b/rpython/rlib/rgc.py @@ -704,7 +704,7 @@ (TOTAL_MEMORY, TOTAL_ALLOCATED_MEMORY, TOTAL_MEMORY_PRESSURE, PEAK_MEMORY, PEAK_ALLOCATED_MEMORY, TOTAL_ARENA_MEMORY, TOTAL_RAWMALLOCED_MEMORY, PEAK_ARENA_MEMORY, PEAK_RAWMALLOCED_MEMORY, - NURSERY_SIZE) = range(10) + NURSERY_SIZE, TOTAL_GC_TIME) = range(11) @not_rpython def get_stats(stat_no): diff --git a/rpython/translator/c/test/test_newgc.py b/rpython/translator/c/test/test_newgc.py --- a/rpython/translator/c/test/test_newgc.py +++ b/rpython/translator/c/test/test_newgc.py @@ -1812,7 +1812,20 @@ res = self.run("ignore_finalizer") assert res == 1 # translated: x1 is removed from the list + def define_total_gc_time(cls): + def f(): + l = [] + for i in range(1000000): + l.append(str(i)) + l = [] + for i in range(10): + rgc.collect() + return rgc.get_stats(rgc.TOTAL_GC_TIME) + return f + def test_total_gc_time(self): + res = self.run("total_gc_time") + assert res > 0 # should take a few microseconds # ____________________________________________________________________ class TaggedPointersTest(object): _______________________________________________ pypy-commit mailing list pypy-commit@python.org https://mail.python.org/mailman/listinfo/pypy-commit