[Zodb-checkins] CVS: StandaloneZODB/ZEO - StorageServer.py:1.34.2.6 smac.py:1.14.2.3
Jeremy Hylton
jeremy@zope.com
Tue, 26 Mar 2002 00:59:10 -0500
Update of /cvs-repository/StandaloneZODB/ZEO
In directory cvs.zope.org:/tmp/cvs-serv22457
Modified Files:
Tag: zeo-1_0-debug-branch
StorageServer.py smac.py
Log Message:
Add per-method logging for some methods at blather level.
This logging is less verbose than the debug level logging, but still
notes all transactions boundaries, loads, and stores.
Format oids and txnids using ZODB.utils.U64 for easier reading.
XXX There seems to be an intermittent error in this branch w/ python
-O! Perhaps once every four test runs I see the
checkCommitLockOnAbort test fail with a release unlocked lock error
raised on the server side.
The terse asyncore exception points to message_input() line 201. Not
sure if this is on the client side or the server side. Assume it must
be the client, since the server doesn't get returns.
The client-side traceback is in a tpc_finish() / __call__() of zrpc
with the std "see server log for real traceback" method. But the
server log doesn't have anything!
=== StandaloneZODB/ZEO/StorageServer.py 1.34.2.5 => 1.34.2.6 ===
from ZODB.Transaction import Transaction
from ZODB.referencesf import referencesf
+from ZODB.utils import U64
from ZEO import trigger
from ZEO import asyncwrap
@@ -190,7 +191,8 @@
self._ncalls = 0
SizedMessageAsyncConnection.__init__(self, sock, addr, debug=debug)
- log.info('Connect %s %s' % (id(self), `addr`))
+ self.logaddr = repr(addr) # form of addr suitable for logging
+ log.info('Connect %s %s' % (id(self), self.logaddr))
def stats(self):
# This method is called via the status() command. The stats
@@ -250,8 +252,8 @@
if self.__storage is None:
if __debug__:
- log.debug("register connection to %s from %s" % (message,
- self.addr))
+ log.blather("register connection to %s from %s" % (message,
+ self.logaddr))
# This is the first communication from the client
self.__storage, self.__storage_id = (
self.__server.register_connection(self, message))
@@ -272,7 +274,7 @@
self._last_method = name
self._ncalls = self._ncalls + 1
log.debug("call %s%s from %s" % (name, format_msg(args),
- self.addr))
+ self.logaddr))
if not storage_method(name):
log.warning("Invalid method name: %s" % name)
@@ -285,12 +287,12 @@
r=apply(getattr(self.__storage, name), args)
if r is _noreturn:
if __debug__:
- log.debug("no return to %s" % `self.addr`)
+ log.debug("no return to %s" % self.logaddr)
self._t_end = time.time()
return
except (UndoError, VersionCommitError), err:
if __debug__:
- log.debug("return error %s to %s" % (err, self.addr))
+ log.debug("return error %s to %s" % (err, self.logaddr))
self._t_end = time.time()
# These are normal usage errors. No need to log them.
self.return_error(sys.exc_info()[0], sys.exc_info()[1])
@@ -303,7 +305,7 @@
return
if __debug__:
- log.debug("return %s to %s" % (format_msg(r), self.addr))
+ log.debug("return %s to %s" % (format_msg(r), self.logaddr))
self._t_end = time.time()
r=dump(r,1)
@@ -350,6 +352,8 @@
}
def zeoLoad(self, oid):
+ if __debug__:
+ log.blather("zeoLoad(%s) %s" % (U64(oid), self.logaddr))
storage=self.__storage
v=storage.modifiedInVersion(oid)
if v: pv, sv = storage.load(oid, v)
@@ -366,6 +370,8 @@
def beginZeoVerify(self):
+ if __debug__:
+ log.blather("beginZeoVerify() %s" % self.logaddr)
self.message_output('bN.')
return _noreturn
@@ -382,6 +388,8 @@
return _noreturn
def endZeoVerify(self):
+ if __debug__:
+ log.blather("endZeoVerify() %s" % self.logaddr)
self.message_output('eN.')
return _noreturn
@@ -439,6 +447,9 @@
def storea(self, oid, serial, data, version, id,
dump=dump):
+ if __debug__:
+ log.blather("storea(%s, [%d], %s) %s" % (U64(oid), len(data),
+ U64(id), self.logaddr))
try:
t=self._transaction
if t is None or id != t.id:
@@ -478,12 +489,17 @@
return self.__storage.tpc_vote(t)
def transactionalUndo(self, trans_id, id):
+ if __debug__:
+ log.blather("transactionalUndo(%s, %s) %s" % (trans_id,
+ U64(id), self.logaddr))
t=self._transaction
if t is None or id != t.id:
raise POSException.StorageTransactionError(self, id)
return self.__storage.transactionalUndo(trans_id, self._transaction)
def undo(self, transaction_id):
+ if __debug__:
+ log.blather("undo(%s) %s" % (transaction_id, self.logaddr))
oids=self.__storage.undo(transaction_id)
if oids:
self.__server.invalidate(
@@ -539,6 +555,12 @@
onerror()
def tpc_abort(self, id):
+ if __debug__:
+ try:
+ log.blather("tpc_abort(%s) %s" % (U64(id), self.logaddr))
+ except:
+ print repr(id)
+ raise
t = self._transaction
if t is None or id != t.id:
return
@@ -554,6 +576,8 @@
self.message_output('UN.')
def tpc_begin(self, id, user, description, ext):
+ if __debug__:
+ log.blather("tpc_begin(%s) %s" % (U64(id), self.logaddr))
t = self._transaction
if t is not None:
if id == t.id:
@@ -567,7 +591,8 @@
if storage._transaction is not None:
self.commitlock_suspend(self.unlock, (), self.close)
return 1 # Return a flag indicating a lock condition.
-
+
+ assert id != 't'
self._transaction=t=Transaction()
t.id=id
t.user=user
@@ -604,6 +629,8 @@
return 1
def tpc_finish(self, id, user, description, ext):
+ if __debug__:
+ log.blather("tpc_finish(%s) %s" % (U64(id), self.logaddr))
t = self._transaction
if id != t.id:
return
=== StandaloneZODB/ZEO/smac.py 1.14.2.2 => 1.14.2.3 ===
'__init__')(self, sock, map)
self.addr=addr
- if debug is not None:
+ if debug is None and __debug__:
+ self._debug = zLogger("smac")
+ else:
self._debug = debug
- elif not hasattr(self, '_debug'):
- self._debug = __debug__ and zLogger("smac")
self.__state=None
self.__inp=None
self.__inpl=0