[pypy-svn] r68766 - in pypy/branch/logging/pypy/rlib: . test

[arigo at codespeak.net]

Author: arigo
Date: Mon Oct 26 19:28:58 2009
New Revision: 68766

Modified:
   pypy/branch/logging/pypy/rlib/rlog.py
   pypy/branch/logging/pypy/rlib/test/test_rlog.py
Log:
Write the time at which each log entry is produced.


Modified: pypy/branch/logging/pypy/rlib/rlog.py
==============================================================================
--- pypy/branch/logging/pypy/rlib/rlog.py	(original)
+++ pypy/branch/logging/pypy/rlib/rlog.py	Mon Oct 26 19:28:58 2009
@@ -104,12 +104,14 @@
 
 
 class AbstractLogWriter(object):
+    get_time = time.time
 
     def __init__(self):
         self.enabled = True
         self.initialized_file = False
         self.initialized_index = {}
         self.fd = -1
+        self.curtime = 0.0
 
     def get_filename(self):
         return os.environ.get('PYPYLOG')
@@ -146,7 +148,13 @@
         if cat.index not in self.initialized_index:
             self.define_new_category(cat)
         if self.enabled:
+            now = self.get_time()
+            timestamp_delta = now - self.curtime
+            self.curtime = now
             self.write_int(cat.index)
+            self.write_float(timestamp_delta)
+            # NB. we store the delta since the last log entry to get a good
+            # precision even though it's encoded as a 4-bytes 'C float'
 
     def add_subentry_d(self, num):
         if self.enabled:

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	Mon Oct 26 19:28:58 2009
@@ -32,6 +32,8 @@
 class MyLogWriter(rlog.AbstractLogWriter):
     _path = udir.join('test_rlog.logwriter')
 
+    def get_time(self):
+        return 123.0
     def get_filename(self):
         return str(self._path)
     def create_buffer(self):
@@ -64,11 +66,11 @@
     assert logwriter.content == [
         ord('R'), ord('L'), ord('o'), ord('g'), ord('\n'), -1, 1.0,
         0, 5, "F5", "foobar",
-        5,
-        5,
+        5, 123.0,
+        5, 0.0,
         0, 7, "F7", "baz",
-        7,
-        5]
+        7, 0.0,
+        5, 0.0]
 
 def test_logcategory_call():
     message = "abc%(foo)ddef%(bar)sghi"
@@ -81,8 +83,8 @@
     assert logwriter.content == [
         ord('R'), ord('L'), ord('o'), ord('g'), ord('\n'), -1, 1.0,
         0, 17, "Aa", message,
-        17, 515, "hellooo",
-        17, 2873, "woooooorld"]
+        17, 123.0, 515, "hellooo",
+        17, 0.0, 2873, "woooooorld"]
 
 
 TIMESTAMP = object()
@@ -201,7 +203,7 @@
     COUNTER = 0
 
     def f(x):
-        rlog.debug_log("Aa", "hello %(foo)d %(bar)d", foo=x, bar=7)
+        rlog.debug_log("Aa", "hello %(foo)d %(bar)f", foo=x, bar=-7.3)
         rlog.debug_log("Ab", "<<%(baz)s>>", baz="hi there")
 
     def setup_method(self, _):