[Zodb-checkins] SVN: ZODB/trunk/ Merge rev 28769 from 3.3 branch.

[Tim Peters]

Log message for revision 28770:
  Merge rev 28769 from 3.3 branch.
  
  Forward-port from ZODB 3.2.
  
  Collector 1503:  excessive logging.
  
  ClientStorage._wait_sync():  Don't log more than one "waiting for cache
  verification to finish" message per 5 minutes.
  

Changed:
  U   ZODB/trunk/NEWS.txt
  U   ZODB/trunk/src/ZEO/ClientStorage.py

-=-
Modified: ZODB/trunk/NEWS.txt
===================================================================
--- ZODB/trunk/NEWS.txt	2005-01-07 21:21:13 UTC (rev 28769)
+++ ZODB/trunk/NEWS.txt	2005-01-07 21:23:44 UTC (rev 28770)
@@ -78,6 +78,15 @@
 - Fixed a bug wherein an object removed from the client cache didn't
   properly mark the file slice it occupied as being available for reuse.
 
+ZEO
+---
+
+Collector 1503:  excessive logging.  It was possible for a ZEO client to
+log "waiting for cache verification to finish" messages at a very high
+rate, producing gigabytes of such messages in short order.
+``ClientStorage._wait_sync()`` was changed to log no more than one
+such message per 5 minutes.
+
 persistent
 ----------
 
@@ -112,7 +121,6 @@
 undefined global while it was trying to raise ``CorruptedError``.  It
 raises ``CorruptedError``, as it always intended, in these cases now.
 
-
 Install
 -------
 

Modified: ZODB/trunk/src/ZEO/ClientStorage.py
===================================================================
--- ZODB/trunk/src/ZEO/ClientStorage.py	2005-01-07 21:21:13 UTC (rev 28769)
+++ ZODB/trunk/src/ZEO/ClientStorage.py	2005-01-07 21:23:44 UTC (rev 28770)
@@ -353,21 +353,29 @@
             self._wait_sync(deadline)
 
     def _wait_sync(self, deadline=None):
-        # If there is no mainloop running, this code needs
-        # to call poll() to cause asyncore to handle events.
-        while 1:
-            if self._ready.isSet():
-                break
-            if deadline and time.time() > deadline:
+        # Log no more than one "waiting" message per LOG_THROTTLE seconds.
+        LOG_THROTTLE = 300 # 5 minutes
+        next_log_time = time.time()
+
+        while not self._ready.isSet():
+            now = time.time()
+            if deadline and now > deadline:
                 log2("Timed out waiting for connection", level=logging.WARNING)
                 break
-            log2("Waiting for cache verification to finish")
+            if now >= next_log_time:
+                log2("Waiting for cache verification to finish")
+                next_log_time = now + LOG_THROTTLE
             if self._connection is None:
                 # If the connection was closed while we were
                 # waiting for it to become ready, start over.
-                return self._wait(deadline - time.time())
-            else:
-                self._connection.pending(30)
+                if deadline is None:
+                    timeout = None
+                else:
+                    timeout = deadline - now
+                return self._wait(timeout)
+            # No mainloop ia running, so we need to call something fancy to
+            # handle asyncore events.
+            self._connection.pending(30)
 
     def close(self):
         """Storage API: finalize the storage, releasing external resources."""