[Zodb-checkins] CVS: ZODB3/ZEO1 - ClientCache.py:1.2.2.1

Guido van Rossum guido@python.org
Thu, 29 Aug 2002 12:07:14 -0400


Update of /cvs-repository/ZODB3/ZEO1
In directory cvs.zope.org:/tmp/cvs-serv7906

Modified Files:
      Tag: zeo_trace_branch
	ClientCache.py 
Log Message:
Add tracing support, like for ZEO 2.

This is in a branch that exists for just this file -- you must use
"cvs update -r zeo_trace_branch ClientCache.py" in the ZEO1 directory
to get at this code.


=== ZODB3/ZEO1/ClientCache.py 1.2 => 1.2.2.1 ===
--- ZODB3/ZEO1/ClientCache.py:1.2	Wed Aug 28 18:10:48 2002
+++ ZODB3/ZEO1/ClientCache.py	Thu Aug 29 12:07:12 2002
@@ -76,9 +76,10 @@
 
 __version__ = "$Revision$"[11:-2]
 
-import os, tempfile
+import os, time, tempfile
 from struct import pack, unpack
 from thread import allocate_lock
+from ZODB.utils import U64
 import zLOG
 
 magic='ZEC0'
@@ -143,6 +144,7 @@
 
         self._limit=size/2
         self._current=current
+        self._setup_trace()
 
     def close(self):
         try:
@@ -169,7 +171,9 @@
         self._acquire()
         try:
             p=self._get(oid, None)
-            if p is None: return None
+            if p is None:
+                self._trace("inva miss", oid, version)
+                return None
             f=self._f[p < 0]
             ap=abs(p)
             f.seek(ap)
@@ -177,8 +181,10 @@
             if h != oid: return
             f.seek(p+8) # Switch from reading to writing
             if version:
+                self._trace("inva upda", oid, version)
                 f.write('n')
             else:
+                self._trace("inva dele", oid, version)
                 del self._index[oid]
                 f.write('i')
         finally: self._release()
@@ -187,7 +193,9 @@
         self._acquire()
         try:
             p=self._get(oid, None)
-            if p is None: return None
+            if p is None:
+                self._trace("load miss", oid, version)
+                return None
             f=self._f[p < 0]
             ap=abs(p)
             seek=f.seek
@@ -202,33 +210,49 @@
                 return None
 
             if h[8]=='n':
-                if version: return None
+                if version:
+                    self._trace("load inva", oid, version)
+                    return None
                 if not dlen:
                     del self._index[oid]
+                    self._trace("load dele", oid, version)
                     return None
 
             if not vlen or not version:
-                if dlen: return read(dlen), h[19:]
-                else: return None
+                if dlen:
+                    data = read(dlen)
+                    self._trace("load hit ", oid, version, h[19:], data)
+                    return data, h[19:]
+                else:
+                    self._trace("load nove", oid, version)
+                    return None
 
             if dlen: seek(dlen, 1)
             v=read(vlen)
             if version != v:
                 if dlen:
-                    seek(-dlen-vlen, 1)
-                    return read(dlen), h[19:]
+                    seek(p+27)
+                    data = read(dlen)
+                    self._trace("load nvhi", oid, version, h[19:], data)
+                    return data, h[19:]
                 else:
+                    self._trace("load vmis", oid, version)
                     return None
 
-            dlen=unpack(">i", read(4))[0]
-            return read(dlen), read(8)
-        finally: self._release()
+            vdlen = unpack(">i", read(4))[0]
+            vdata = read(vdlen)
+            vserial = read(8)
+            self._trace("load vhit", oid, version, vserial, vdata)
+            return vdata, vserial
+        finally:
+            self._release()
 
     def update(self, oid, serial, version, data):
         self._acquire()
         try:
             if version:
                 # We need to find and include non-version data
+                self._trace("upda vers", oid, version, serial, data)
                 p=self._get(oid, None)
                 if p is None:
                     return self._store(oid, '', '', version, data, serial)
@@ -255,6 +279,7 @@
                 self._store(oid, p, s, version, data, serial)
             else:
                 # Simple case, just store new data:
+                self._trace("upda nove", oid, version, serial, data)
                 self._store(oid, data, serial, '', None, None)
         finally: self._release()
 
@@ -262,7 +287,9 @@
         self._acquire()
         try:
             p=self._get(oid, None)
-            if p is None: return None
+            if p is None:
+                self._trace("modV miss", oid)
+                return None
             f=self._f[p < 0]
             ap=abs(p)
             seek=f.seek
@@ -276,12 +303,19 @@
                 del self._index[oid]
                 return None
 
-            if h[8]=='n': return None
+            if h[8]=='n':
+                self._trace("modV unkn", oid)
+                return None
 
-            if not vlen: return ''
+            if not vlen:
+                self._trace("modV nove", oid, '')
+                return ''
             seek(dlen, 1)
-            return read(vlen)
-        finally: self._release()
+            version = read(vlen)
+            self._trace("modV vers", oid, version)
+            return version
+        finally:
+            self._release()
 
     def checkSize(self, size):
         self._acquire()
@@ -291,6 +325,7 @@
             if self._pos+size > self._limit:
                 current=not self._current
                 self._current=current
+                self._trace("Flip-file %s" % time.ctime(time.time()))
                 # Delete the half of the index that's no longer valid
                 index = self._index
                 for oid in index.keys():
@@ -315,9 +350,12 @@
                 self._pos=pos=4
         finally: self._release()
 
-
     def store(self, oid, p, s, version, pv, sv):
         self._acquire()
+        if s:
+            self._trace("stor nove", oid, version, s, p)
+        else:
+            self._trace("stor vers", oid, version, sv, pv)
         try: self._store(oid, p, s, version, pv, sv)
         finally: self._release()
 
@@ -352,6 +390,37 @@
         else: self._index[oid]=pos
 
         self._pos=pos+tlen
+
+    def _setup_trace(self):
+        # See if cache tracing is requested through $ZEO_CACHE_TRACE.
+        # If not, or if we can't write to the trace file,
+        # disable tracing by setting self._trace to a dummy function.
+        self._tracefile = None
+        tfn = os.environ.get("ZEO_CACHE_TRACE")
+        if tfn:
+            try:
+                self._tracefile = open(tfn, "a")
+                self._tracefile.write("\n") # Force start of new line
+                self._trace("Tracefile %s" % time.ctime(time.time()))
+            except IOError:
+                self._tracefile = None
+        if self._tracefile is None:
+            def notrace(*args):
+                pass
+            self._trace = notrace
+
+    def _trace(self, msg, oid=None, version=None, serial=None, data=None):
+        # When tracing is disabled, this method is hidden by a dummy.
+        parts = ["%14.3f" % time.time(), "%d" % self._current, msg]
+        if oid is not None:
+            parts.append("%016x" % U64(oid))
+            if version is not None:
+                parts.append("v=%r" % version)
+                if serial is not None:
+                    parts.append("s=%016x" % U64(serial))
+                    if data is not None:
+                        parts.append("n=%d" % len(data))
+        self._tracefile.write(" ".join(parts) + "\n")
 
 def read_index(index, serial, f, current):
     LOG("read_index(%s)" % f.name)