[Zope-Checkins] CVS: Zope/lib/python/Products/Transience - Transience.py:1.19

[Chris McDonough]

Update of /cvs-repository/Zope/lib/python/Products/Transience
In directory cvs.zope.org:/tmp/cvs-serv15197

Modified Files:
	Transience.py 
Log Message:
Added some debugging logic that logs at BLATHER if Z_TOC_DEBUG environment variable is set.


=== Zope/lib/python/Products/Transience/Transience.py 1.18 => 1.19 ===
 from AccessControl.User import nobody
 from BTrees import OOBTree
-from zLOG import LOG, WARNING
+from zLOG import LOG, WARNING, BLATHER
+import os
 import os.path
 import math
 import time
@@ -111,6 +112,14 @@
 import random
 from types import InstanceType
 
+DEBUG = os.environ.get('Z_TOC_DEBUG', '')
+
+def TLOG(*args):
+    tmp = []
+    for arg in args:
+        tmp.append(str(arg))
+    LOG('Transience DEBUG', BLATHER, ' '.join(tmp))
+
 _notfound = []
 _marker = []
 
@@ -324,6 +333,8 @@
             method = callback
 
         if callable(method):
+            if DEBUG:
+                TLOG('calling %s at object %s' % (callback, kind))
             try:
                 user = getSecurityManager().getUser()
                 try:
@@ -405,6 +416,8 @@
         # no timeout always returns last bucket
         if not self._timeout_secs:
             b, dump_after = self._ring._data[0]
+            if DEBUG:
+                TLOG('no timeout, returning first bucket')
             return b
         index = self._ring._index
         now = int(time())
@@ -415,6 +428,9 @@
         while 1:
             l = b, dump_after = self._ring._data[-1]
             if now > dump_after:
+                if DEBUG:
+                    TLOG('now is %s' % now)
+                    TLOG('dump_after for %s was %s, dumping'%(b, dump_after))
                 self._ring.turn()
                 # mutate elements in-place in the ring
                 new_dump_after = now + i
@@ -430,10 +446,20 @@
             return b
 
     def _clean(self, b, index):
-        for k, v in list(index.items()):
+        if DEBUG:
+            TLOG('building list of index items')
+        l = list(index.items())
+        if DEBUG:
+            TLOG('done building list of index items, now iterating over them')
+        tmp = []
+        for k, v in l:
             if v is b:
+                tmp.append(k)
                 self.notifyDestruct(index[k][k])
                 del index[k]
+        if DEBUG:
+            TLOG('deleted %s' % tmp)
+            TLOG('clearing %s' % b)
         b.clear()
 
     def _show(self):