[Erp5-report] r38033 leonardo - in /erp5/trunk/utils/Products.LongRequestLogger/Products/Lo...

[nobody at svn.erp5.org]

Author: leonardo
Date: Thu Aug 26 13:53:08 2010
New Revision: 38033

URL: http://svn.erp5.org?rev=38033&view=rev
Log:
add time information and retry count to request logging

Modified:
    erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/dumper.py
    erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/tests/testLongRequestLogger.py

Modified: erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/dumper.py
URL: http://svn.erp5.org/erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/dumper.py?rev=38033&r1=38032&r2=38033&view=diff
==============================================================================
--- erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/dumper.py [utf8] (original)
+++ erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/dumper.py [utf8] Thu Aug 26 13:53:08 2010
@@ -57,19 +57,20 @@ log.propagate = False
 handler = NullHandler()
 log.addHandler(handler)
 
+formatter = logging.Formatter("%(asctime)s - %(message)s")
+
 DEFAULT_TIMEOUT = 2
 DEFAULT_INTERVAL = 1
 
 def do_enable():
     global handler
-    # this function is not exactly threadsafe, but it shouldn't matter.
+    # this function is not exactly thread-safe, but it shouldn't matter.
     # The worse that can happen is that a change in longrequestlogger_file
-    # will interfere with an already running request and stop or change its
-    # logging destination.
+    # will stop or change the logging destination of an already running request
     logfile = os.environ.get('longrequestlogger_file')
     if logfile:
         if logfile != 'null':
-            # to immitate FileHandler
+            # to imitate FileHandler
             logfile = os.path.abspath(logfile)
         if handler.baseFilename != logfile:
             log.removeHandler(handler)
@@ -78,6 +79,7 @@ def do_enable():
                 handler = NullHandler()
             else:
                 handler = logging.FileHandler(logfile)
+                handler.formatter = formatter
             log.addHandler(handler)
         return log # which is also True as boolean
     return None # so that Dumpers know they are disabled
@@ -93,6 +95,7 @@ def get_configuration():
 REQUEST_FORMAT = """
 request:
 URL: %(method)s %(url)s
+retry count: %(retries)s
 form: %(form)s
 other: %(other)s
 """.strip()

Modified: erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/tests/testLongRequestLogger.py
URL: http://svn.erp5.org/erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/tests/testLongRequestLogger.py?rev=38033&r1=38032&r2=38033&view=diff
==============================================================================
--- erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/tests/testLongRequestLogger.py [utf8] (original)
+++ erp5/trunk/utils/Products.LongRequestLogger/Products/LongRequestLogger/tests/testLongRequestLogger.py [utf8] Thu Aug 26 13:53:08 2010
@@ -124,6 +124,7 @@ check_publishing_1_interval_log = Simple
 Products.LongRequestLogger.dumper WARNING
   Thread ...: Running for 2.0 secs; request:
 URL: GET http://localhost
+retry count: 0
 form: {}
 other: {'ACTUAL_URL': 'http://localhost',
  'PARENTS': [],
@@ -152,6 +153,7 @@ Traceback:
 Products.LongRequestLogger.dumper WARNING
   Thread ...: Running for 3.0 secs; request:
 URL: GET http://localhost
+retry count: 0
 form: {}
 other: {'ACTUAL_URL': 'http://localhost',
  'PARENTS': [],
@@ -182,6 +184,7 @@ Traceback:
 check_request_formating = SimpleOutputChecker('''
 request:
 URL: GET http://localhost/foo/bar
+retry count: 0
 form: {}
 other: {'RESPONSE': HTTPResponse(''),
  'SERVER_URL': 'http://localhost',
@@ -189,6 +192,30 @@ other: {'RESPONSE': HTTPResponse(''),
  'method': 'GET'}
 ''')
 
+check_monitor_environment_log = SimpleOutputChecker('''
+Products.LongRequestLogger.dumper WARNING
+  Thread ...: Running for 3.5 secs; [No request]
+Traceback:
+...
+  File ".../LongRequestLogger/tests/common.py", line 41, in sleep
+    self._sleep1()
+  File ".../LongRequestLogger/tests/common.py", line 44, in _sleep1
+    self._sleep2()
+  File ".../LongRequestLogger/tests/common.py", line 47, in _sleep2
+    time.sleep(self.interval)
+Products.LongRequestLogger.dumper WARNING
+  Thread ...: Running for 5.5 secs; [No request]
+Traceback:
+...
+  File ".../LongRequestLogger/tests/common.py", line 41, in sleep
+    self._sleep1()
+  File ".../LongRequestLogger/tests/common.py", line 44, in _sleep1
+    self._sleep2()
+  File ".../LongRequestLogger/tests/common.py", line 47, in _sleep2
+    time.sleep(self.interval)
+''')
+
+
 config_env_variables = dict(
     longrequestlogger_file='null',
     longrequestlogger_timeout=None,
@@ -310,7 +337,7 @@ class TestLongRequestLogger(unittest.Tes
         m.stop()
         check_monitor_2_intervals_log(str(self.loghandler))
 
-    def testMonitorDisabled(self):
+    def testMonitorConfigurationDisabled(self):
         from Products.LongRequestLogger.monitor import Monitor
         os.environ['longrequestlogger_file'] = ''
         m = Monitor()
@@ -328,7 +355,15 @@ class TestLongRequestLogger(unittest.Tes
         self.assertFalse(self.loghandler.records)
 
     def testMonitorWithEnvorinmentConfigutation(self):
-        self.fail('TODO')
+        from Products.LongRequestLogger.monitor import Monitor
+        os.environ['longrequestlogger_timeout'] = '3.5'
+        os.environ['longrequestlogger_interval'] = '2'
+        m = Monitor()
+        s = Sleeper(m.timeout + m.interval + 0.5) 
+        # sleep a little more than the timeout to be on the safe side
+        s.sleep()
+        m.stop()
+        check_monitor_environment_log(str(self.loghandler))
 
     def testIsPatched(self):
         import ZPublisher.Publish