[pypy-svn] r68781 - in pypy/branch/logging/pypy: config rlib rlib/test rpython/memory rpython/memory/gc rpython/memory/gctransform translator/c
arigo at codespeak.net
arigo at codespeak.net
Tue Oct 27 11:46:51 CET 2009
Author: arigo
Date: Tue Oct 27 11:46:49 2009
New Revision: 68781
Modified:
pypy/branch/logging/pypy/config/translationoption.py
pypy/branch/logging/pypy/rlib/rlog.py
pypy/branch/logging/pypy/rlib/rlog_parsing.py
pypy/branch/logging/pypy/rlib/test/test_rlog.py
pypy/branch/logging/pypy/rpython/memory/gc/semispace.py
pypy/branch/logging/pypy/rpython/memory/gctransform/framework.py
pypy/branch/logging/pypy/rpython/memory/gctypelayout.py
pypy/branch/logging/pypy/translator/c/gc.py
Log:
For the GC, put both the debug_log() calls at the end of
collecting (because it can allocate more memory). Works
by overriding the time at which the first debug_log() is
called.
Modified: pypy/branch/logging/pypy/config/translationoption.py
==============================================================================
--- pypy/branch/logging/pypy/config/translationoption.py (original)
+++ pypy/branch/logging/pypy/config/translationoption.py Tue Oct 27 11:46:49 2009
@@ -72,12 +72,8 @@
"ref": [("translation.gcrootfinder", "n/a")],
"none": [("translation.gcrootfinder", "n/a")],
}),
- OptionDescription("gcconfig", "Configure garbage collectors", [
- BoolOption("debugprint", "Turn on debug printing for the GC",
- default=False),
- BoolOption("removetypeptr", "Remove the typeptr from every object",
- default=False, cmdline="--gcremovetypeptr"),
- ]),
+ BoolOption("gcremovetypeptr", "Remove the typeptr from every object",
+ default=False, cmdline="--gcremovetypeptr"),
ChoiceOption("gcrootfinder",
"Strategy for finding GC Roots (framework GCs only)",
["n/a", "shadowstack", "asmgcc"],
Modified: pypy/branch/logging/pypy/rlib/rlog.py
==============================================================================
--- pypy/branch/logging/pypy/rlib/rlog.py (original)
+++ pypy/branch/logging/pypy/rlib/rlog.py Tue Oct 27 11:46:49 2009
@@ -16,7 +16,7 @@
def has_log():
return True
-def debug_log(_category, _message, **_kwds):
+def debug_log(_category, _message, _time=None, **_kwds):
getattr(_log, _category)(_message % _kwds)
# ____________________________________________________________
@@ -66,13 +66,19 @@
cat = logcategories[s_category.const]
except KeyError:
num = len(logcategories) + 1
- logcategories[s_category.const] = LogCategory(s_category.const,
- s_message.const,
- num)
+ cat = LogCategory(s_category.const, s_message.const, num)
+ logcategories[s_category.const] = cat
else:
assert cat.message == s_message.const, (
"log category %r is used with different messages:\n\t%s\n"
"\t%s" % (s_category.const, cat.message, s_message.const))
+ for entry, _ in cat.entries:
+ name = 's_' + entry
+ assert name in kwds_s, "missing log entry %r" % (entry,)
+ del kwds_s[name]
+ if 's__time' in kwds_s:
+ del kwds_s['s__time']
+ assert not kwds_s, "unexpected log entries %r" % (kwds_s.keys(),)
return annmodel.s_None
def specialize_call(self, hop, **kwds_i):
@@ -83,17 +89,22 @@
logwriter = get_logwriter(hop.rtyper)
translator = hop.rtyper.annotator.translator
cat = translator._logcategories[hop.args_s[0].const]
+ types = cat.types
+ entries = cat.entries
+ if 'i__time' in kwds_i:
+ types = types + ['f']
+ entries = entries + [('_time', 'f')]
ann = {
'd': annmodel.SomeInteger(),
'f': annmodel.SomeFloat(),
's': annmodel.SomeString(can_be_None=True),
}
annhelper = hop.rtyper.getannmixlevel()
- args_s = [ann[t] for t in cat.types]
+ args_s = [ann[t] for t in types]
c_func = annhelper.constfunc(cat.gen_call(logwriter), args_s,
annmodel.s_None)
args_v = [c_func]
- for name, typechar in cat.entries:
+ for name, typechar in entries:
arg = kwds_i['i_'+name]
if typechar == 'd':
v = hop.inputarg(lltype.Signed, arg=arg)
@@ -149,7 +160,11 @@
def call(*args):
if not logwriter.enabled:
return
- if not logwriter.add_entry(self):
+ if len(args) > len(self.types):
+ now = args[len(self.types)]
+ else:
+ now = 0.0
+ if not logwriter.add_entry(self, now):
return
i = 0
for typechar in types:
@@ -205,6 +220,7 @@
self.write_int(-1)
self.write_float(1.0)
self.initialized_file = True
+ open_file._dont_inline_ = True
def define_new_category(self, cat):
if not self.initialized_file:
@@ -216,13 +232,15 @@
self.write_str(cat.category)
self.write_str(cat.message)
self.initialized_index[cat.index] = None
+ define_new_category._dont_inline_ = True
- def add_entry(self, cat):
+ def add_entry(self, cat, now=0.0):
if cat.index not in self.initialized_index:
self.define_new_category(cat)
if not self.enabled:
return False
- now = self.get_time()
+ if now == 0.0:
+ now = self.get_time()
timestamp_delta = now - self.curtime
self.curtime = now
self.write_int(cat.index)
Modified: pypy/branch/logging/pypy/rlib/rlog_parsing.py
==============================================================================
--- pypy/branch/logging/pypy/rlib/rlog_parsing.py (original)
+++ pypy/branch/logging/pypy/rlib/rlog_parsing.py Tue Oct 27 11:46:49 2009
@@ -1,3 +1,4 @@
+import autopath
import struct
from pypy.rlib.rarithmetic import intmask
from pypy.rlib import rlog
@@ -71,3 +72,17 @@
def parse_log(filename):
logparser = LogParser(open(filename, 'rb'))
return logparser.enum_entries()
+
+
+if __name__ == '__main__':
+ import sys, re
+ r_replace = re.compile(r"%\(\w+\)")
+ for curtime, cat, entries in parse_log(sys.argv[1]):
+ try:
+ printcode = cat.printcode
+ except AttributeError:
+ code = cat.category + ' '
+ message = cat.message.replace('\n', '\n' + ' '*len(code))
+ message = r_replace.sub("%", message)
+ printcode = cat.printcode = code + message
+ print printcode % tuple(entries)
Modified: pypy/branch/logging/pypy/rlib/test/test_rlog.py
==============================================================================
--- pypy/branch/logging/pypy/rlib/test/test_rlog.py (original)
+++ pypy/branch/logging/pypy/rlib/test/test_rlog.py Tue Oct 27 11:46:49 2009
@@ -88,6 +88,24 @@
17, 123.0, 515, "hellooo",
17, 0.0, 2873, "woooooorld"]
+def test_logwriter_force_time():
+ class FakeCategory:
+ def __init__(self, index, category, message):
+ self.index = index
+ self.category = category
+ self.message = message
+ #
+ logwriter = MyLogWriter()
+ cat5 = FakeCategory(5, "F5", "foobar")
+ logwriter.add_entry(cat5, now=100.0)
+ logwriter.add_entry(cat5)
+ #
+ assert logwriter.content == [
+ ord('R'), ord('L'), ord('o'), ord('g'), ord('\n'), -1, 1.0,
+ 0, 5, "F5", "foobar",
+ 5, 100.0,
+ 5, 23.0]
+
SIZEOF_FLOAT = rlog.LLLogWriter.SIZEOF_FLOAT
@@ -210,7 +228,8 @@
def f(x):
assert rlog.has_log()
- rlog.debug_log("Aa", "hello %(foo)d %(bar)f", foo=x, bar=-7.3)
+ rlog.debug_log("Aa", "hello %(foo)d %(bar)f", foo=x, bar=-7.3,
+ _time=0.5)
rlog.debug_log("Aa", "hello %(foo)d %(bar)f", foo=x+1, bar=x+0.5)
rlog.debug_log("Ab", "<<%(baz)s>>", baz="hi there")
assert rlog.has_log()
@@ -232,7 +251,7 @@
entries = list(rlog_parsing.parse_log(self.pypylog))
assert len(entries) == 3
#
- assert isinstance(entries[0][0], float)
+ assert entries[0][0] == 0.5
assert isinstance(entries[1][0], float)
assert isinstance(entries[2][0], float)
#
Modified: pypy/branch/logging/pypy/rpython/memory/gc/semispace.py
==============================================================================
--- pypy/branch/logging/pypy/rpython/memory/gc/semispace.py (original)
+++ pypy/branch/logging/pypy/rpython/memory/gc/semispace.py Tue Oct 27 11:46:49 2009
@@ -9,6 +9,7 @@
from pypy.rlib.debug import ll_assert
from pypy.rpython.lltypesystem.lloperation import llop
from pypy.rlib.rarithmetic import ovfcheck
+from pypy.rlib import rlog
from pypy.rpython.memory.gc.base import MovingGCBase
import sys, os, time
@@ -61,8 +62,7 @@
self.max_space_size = self.param_max_space_size
self.red_zone = 0
- if self.config.gcconfig.debugprint:
- self.program_start_time = time.time()
+ self.program_start_time = time.time()
self.tospace = llarena.arena_malloc(self.space_size, True)
ll_assert(bool(self.tospace), "couldn't allocate tospace")
self.top_of_space = self.tospace + self.space_size
@@ -213,18 +213,8 @@
# (this is also a hook for the HybridGC)
def semispace_collect(self, size_changing=False):
- if self.config.gcconfig.debugprint:
- llop.debug_print(lltype.Void)
- llop.debug_print(lltype.Void,
- ".----------- Full collection ------------------")
- start_usage = self.free - self.tospace
- llop.debug_print(lltype.Void,
- "| used before collection: ",
- start_usage, "bytes")
- start_time = time.time()
- else:
- start_time = 0 # Help the flow space
- start_usage = 0 # Help the flow space
+ start_time = time.time()
+ start_usage = self.free - self.tospace
#llop.debug_print(lltype.Void, 'semispace_collect', int(size_changing))
# Switch the spaces. We copy everything over to the empty space
@@ -254,41 +244,39 @@
self.record_red_zone()
self.execute_finalizers()
#llop.debug_print(lltype.Void, 'collected', self.space_size, size_changing, self.top_of_space - self.free)
- if self.config.gcconfig.debugprint:
+ if rlog.has_log():
+ rlog.debug_log("gc-full-{",
+ ".----------- Full collection ------------------\n"
+ "| used before collection: %(start_usage)d bytes",
+ start_usage=start_usage,
+ _time=start_time)
end_time = time.time()
elapsed_time = end_time - start_time
self.total_collection_time += elapsed_time
self.total_collection_count += 1
total_program_time = end_time - self.program_start_time
end_usage = self.free - self.tospace
- llop.debug_print(lltype.Void,
- "| used after collection: ",
- end_usage, "bytes")
- llop.debug_print(lltype.Void,
- "| freed: ",
- start_usage - end_usage, "bytes")
- llop.debug_print(lltype.Void,
- "| size of each semispace: ",
- self.space_size, "bytes")
- llop.debug_print(lltype.Void,
- "| fraction of semispace now used: ",
- end_usage * 100.0 / self.space_size, "%")
ct = self.total_collection_time
cc = self.total_collection_count
- llop.debug_print(lltype.Void,
- "| number of semispace_collects: ",
- cc)
- llop.debug_print(lltype.Void,
- "| i.e.: ",
- cc / total_program_time, "per second")
- llop.debug_print(lltype.Void,
- "| total time in semispace_collect: ",
- ct, "seconds")
- llop.debug_print(lltype.Void,
- "| i.e.: ",
- ct * 100.0 / total_program_time, "%")
- llop.debug_print(lltype.Void,
- "`----------------------------------------------")
+ rlog.debug_log(
+ "gc-full-}",
+ "| used after collection: %(end_usage)d bytes\n"
+ "| freed: %(freed)d bytes\n"
+ "| size of each semispace: %(semispace)d bytes\n"
+ "| fraction of semispace now used: %(now_used)f %%\n"
+ "| number of semispace_collects: %(cc)d\n"
+ "| i.e.: %(cc_sec)f per second\n"
+ "| total time in semispace_collect: %(ct)f seconds\n"
+ "| i.e.: %(ct_frac)f %%\n"
+ "`----------------------------------------------",
+ end_usage = end_usage,
+ freed = start_usage - end_usage,
+ semispace = self.space_size,
+ now_used = end_usage * 100.0 / self.space_size,
+ cc = cc,
+ cc_sec = cc / total_program_time,
+ ct = ct,
+ ct_frac = ct * 100.0 / total_program_time)
def starting_full_collect(self):
pass # hook for the HybridGC
Modified: pypy/branch/logging/pypy/rpython/memory/gctransform/framework.py
==============================================================================
--- pypy/branch/logging/pypy/rpython/memory/gctransform/framework.py (original)
+++ pypy/branch/logging/pypy/rpython/memory/gctransform/framework.py Tue Oct 27 11:46:49 2009
@@ -130,7 +130,7 @@
if hasattr(translator, '_jit2gc'):
self.layoutbuilder = translator._jit2gc['layoutbuilder']
else:
- if translator.config.translation.gcconfig.removetypeptr:
+ if translator.config.translation.gcremovetypeptr:
lltype2vtable = translator.rtyper.lltype2vtable
else:
lltype2vtable = {}
@@ -888,7 +888,7 @@
def gct_getfield(self, hop):
if (hop.spaceop.args[1].value == 'typeptr' and
hop.spaceop.args[0].concretetype.TO._hints.get('typeptr') and
- self.translator.config.translation.gcconfig.removetypeptr):
+ self.translator.config.translation.gcremovetypeptr):
self.transform_getfield_typeptr(hop)
else:
GCTransformer.gct_getfield(self, hop)
@@ -896,7 +896,7 @@
def gct_setfield(self, hop):
if (hop.spaceop.args[1].value == 'typeptr' and
hop.spaceop.args[0].concretetype.TO._hints.get('typeptr') and
- self.translator.config.translation.gcconfig.removetypeptr):
+ self.translator.config.translation.gcremovetypeptr):
self.transform_setfield_typeptr(hop)
else:
GCTransformer.gct_setfield(self, hop)
@@ -991,11 +991,11 @@
class JITTransformerLayoutBuilder(TransformerLayoutBuilder):
- # for the JIT: currently does not support removetypeptr
+ # for the JIT: currently does not support gcremovetypeptr
def __init__(self, config):
from pypy.rpython.memory.gc.base import choose_gc_from_config
try:
- assert not config.translation.gcconfig.removetypeptr
+ assert not config.translation.gcremovetypeptr
except AttributeError: # for some tests
pass
GCClass, _ = choose_gc_from_config(config)
Modified: pypy/branch/logging/pypy/rpython/memory/gctypelayout.py
==============================================================================
--- pypy/branch/logging/pypy/rpython/memory/gctypelayout.py (original)
+++ pypy/branch/logging/pypy/rpython/memory/gctypelayout.py Tue Oct 27 11:46:49 2009
@@ -219,8 +219,7 @@
type_id = self.type_info_group.add_member(fullinfo)
self.id_of_type[TYPE] = type_id
# store the vtable of the type (if any) immediately thereafter
- # (note that if gcconfig.removetypeptr is False, lltype2vtable
- # is empty)
+ # (note that if gcremovetypeptr is False, lltype2vtable is empty)
vtable = self.lltype2vtable.get(TYPE, None)
if vtable is not None:
# check that if we have a vtable, we are not varsize
Modified: pypy/branch/logging/pypy/translator/c/gc.py
==============================================================================
--- pypy/branch/logging/pypy/translator/c/gc.py (original)
+++ pypy/branch/logging/pypy/translator/c/gc.py Tue Oct 27 11:46:49 2009
@@ -352,7 +352,7 @@
def need_no_typeptr(self):
config = self.db.translator.config
- return config.translation.gcconfig.removetypeptr
+ return config.translation.gcremovetypeptr
def OP_GC_GETTYPEPTR_GROUP(self, funcgen, op):
# expands to a number of steps, as per rpython/lltypesystem/opimpl.py,
More information about the Pypy-commit
mailing list