SVN: ZODB/branches/3.9/src/ Merged the chrisw-error_logging branch:

Log message for revision 106150:
  Merged the chrisw-error_logging branch:
  
  Bug fixed:
  - Internal ZEO errors were logged at the INFO level, rather
    than at the error level.
  

Changed:
  U   ZODB/branches/3.9/src/CHANGES.txt
  U   ZODB/branches/3.9/src/ZEO/tests/testZEO.py
  U   ZODB/branches/3.9/src/ZEO/zrpc/connection.py

-=-
Modified: ZODB/branches/3.9/src/CHANGES.txt
===================================================================
--- ZODB/branches/3.9/src/CHANGES.txt	2009-12-01 22:09:54 UTC (rev 106149)
+++ ZODB/branches/3.9/src/CHANGES.txt	2009-12-01 22:20:36 UTC (rev 106150)
@@ -13,6 +13,9 @@
 
 - zope.testing was an unnecessary non-testing dependency.
 
+- Internal ZEO errors were logged at the INFO level, rather
+  than at the error level.
+
 3.9.3 (2009-10-23)
 ==================
 

Modified: ZODB/branches/3.9/src/ZEO/tests/testZEO.py
===================================================================
--- ZODB/branches/3.9/src/ZEO/tests/testZEO.py	2009-12-01 22:09:54 UTC (rev 106149)
+++ ZODB/branches/3.9/src/ZEO/tests/testZEO.py	2009-12-01 22:20:36 UTC (rev 106150)
@@ -438,15 +438,13 @@
                      > client_timeout_count)
 
 
-class CatastrophicClientLoopFailure(
-    ZEO.tests.ConnectionTests.CommonSetupTearDown):
-    """Test what happens when the client loop falls over
-    """
+class ZRPCConnectionTests(ZEO.tests.ConnectionTests.CommonSetupTearDown):
 
     def getConfig(self, path, create, read_only):
         return """<mappingstorage 1/>"""
 
     def checkCatastrophicClientLoopFailure(self):
+        # Test what happens when the client loop falls over
         self._storage = self.openClientStorage()
 
         class Evil:
@@ -474,13 +472,30 @@
         self.assertEqual(log[1][0], "Couldn't close a dispatcher.")
         self.assert_('exc_info' in log[1][1])
 
-class ConnectionInvalidationOnReconnect(
-    ZEO.tests.ConnectionTests.CommonSetupTearDown):
-    """Test what happens when the client loop falls over
-    """
+    def checkExceptionLogsAtError(self):
+        # Test the exceptions are logged at error
+        self._storage = self.openClientStorage()
+        conn = self._storage._connection
+        # capture logging
+        log = []
+        conn.logger.log = (
+            lambda l, m, *a, **kw: log.append((l,m % a, kw))
+            )
 
-    def getConfig(self, path, create, read_only):
-        return """<mappingstorage 1/>"""
+        # This is a deliberately bogus call to get an exception
+        # logged
+        self._storage._connection.handle_request('foo',0,'history',(1,2,3,4))
+        # test logging
+        level,message,kw = log[1]
+        self.assertEqual(level,logging.ERROR)
+        self.failUnless(message.endswith(
+                ') history() raised exception: history() takes at'
+                ' most 3 arguments (5 given)'
+                ))
+        self.assertEqual(kw,{'exc_info':True})
+        
+        # cleanup
+        del conn.logger.log
 
     def checkConnectionInvalidationOnReconnect(self):
 
@@ -1216,7 +1231,7 @@
 
 quick_test_classes = [
     FileStorageRecoveryTests, ConfigurationTests, HeartbeatTests,
-    CatastrophicClientLoopFailure, ConnectionInvalidationOnReconnect,
+    ZRPCConnectionTests,
     ]
 
 class ServerManagingClientStorage(ClientStorage):

Modified: ZODB/branches/3.9/src/ZEO/zrpc/connection.py
===================================================================
--- ZODB/branches/3.9/src/ZEO/zrpc/connection.py	2009-12-01 22:09:54 UTC (rev 106149)
+++ ZODB/branches/3.9/src/ZEO/zrpc/connection.py	2009-12-01 22:20:36 UTC (rev 106150)
@@ -586,7 +586,7 @@
         except Exception, msg:
             if not isinstance(msg, self.unlogged_exception_types):
                 self.log("%s() raised exception: %s" % (name, msg),
-                         logging.INFO, exc_info=True)
+                         logging.ERROR, exc_info=True)
             error = sys.exc_info()[:2]
             return self.return_error(msgid, flags, *error)