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

Reply via email to