[Zope3-checkins] CVS: Zope3/lib/python/ZEO - StorageServer.py:1.46
Guido van Rossum
guido@python.org
Thu, 19 Dec 2002 15:22:44 -0500
Update of /cvs-repository/Zope3/lib/python/ZEO
In directory cvs.zope.org:/tmp/cvs-serv25580
Modified Files:
StorageServer.py
Log Message:
Convert to using the logging module, using the sublogger machinery.
=== Zope3/lib/python/ZEO/StorageServer.py 1.45 => 1.46 ===
--- Zope3/lib/python/ZEO/StorageServer.py:1.45 Thu Dec 19 14:38:05 2002
+++ Zope3/lib/python/ZEO/StorageServer.py Thu Dec 19 15:22:43 2002
@@ -26,6 +26,7 @@
import sys
import threading
import time
+import logging
from ZEO import ClientStub
from ZEO.CommitLog import CommitLog
@@ -33,21 +34,9 @@
from ZEO.zrpc.connection import ManagedServerConnection, Delay, MTDelay
from Transaction.Transaction import Transaction
-import zLOG
from ZODB.POSException import StorageError, StorageTransactionError
from ZODB.POSException import TransactionError, ReadOnlyError
-_label = "ZSS" # Default label used for logging.
-
-def set_label():
- """Internal helper to reset the logging label (e.g. after fork())."""
- global _label
- _label = "ZSS:%s" % os.getpid()
-
-def log(message, level=zLOG.INFO, label=None, error=None):
- """Internal helper to log a message using zLOG."""
- zLOG.LOG(label or _label, level, message, error=error)
-
class StorageServerError(StorageError):
"""Error reported when an unpickleable exception is raised."""
@@ -99,12 +88,14 @@
self.addr = addr
self.storages = storages
- set_label()
+ self.logger = logging.getLogger("ZSS.%s" % os.getpid())
msg = ", ".join(
["%s:%s" % (name, storage.isReadOnly() and "RO" or "RW")
for name, storage in storages.items()])
- log("%s created %s with storages: %s" %
- (self.__class__.__name__, read_only and "RO" or "RW", msg))
+ self.logger.warn("%s created %s with storages: %s",
+ self.__class__.__name__,
+ read_only and "RO" or "RW",
+ msg)
for s in storages.values():
s._waiting = []
self.read_only = read_only
@@ -122,7 +113,7 @@
"""
z = self.ZEOStorageClass(self, self.read_only)
c = self.ManagedServerConnectionClass(sock, addr, z, self)
- log("new connection %s: %s" % (addr, `c`))
+ self.logger.warn("new connection %s: %s", addr, `c`)
return c
def register_connection(self, storage_id, conn):
@@ -211,27 +202,28 @@
self.storage_id = "uninitialized"
self.transaction = None
self.read_only = read_only
- self.log_label = _label
+ self.logger = logging.getLogger("ZSS.%d.ZEO" % os.getpid())
+ self.log_label = ""
def notifyConnected(self, conn):
self.connection = conn # For restart_other() below
self.client = self.ClientStorageStubClass(conn)
addr = conn.addr
if isinstance(addr, type("")):
- label = addr
+ self.log_label = addr
else:
host, port = addr
- label = str(host) + ":" + str(port)
- self.log_label = _label + "/" + label
+ self.log_label = str(host) + ":" + str(port)
def notifyDisconnected(self):
# When this storage closes, we must ensure that it aborts
# any pending transaction.
if self.transaction is not None:
- self.log("disconnected during transaction %s" % self.transaction)
+ self.logger.warn("%s: disconnected during transaction %s",
+ self.log_label, self.transaction)
self.abort()
else:
- self.log("disconnected")
+ self.logger.warn("%s: disconnected", self.log_label)
def __repr__(self):
tid = self.transaction and repr(self.transaction.id)
@@ -243,9 +235,6 @@
name = self.__class__.__name__
return "<%s %X trans=%s s_trans=%s>" % (name, id(self), tid, stid)
- def log(self, msg, level=zLOG.INFO, error=None):
- zLOG.LOG(self.log_label, level, msg, error=error)
-
def setup_delegation(self):
"""Delegate several methods to the storage"""
self.versionEmpty = self.storage.versionEmpty
@@ -272,15 +261,16 @@
raise ReadOnlyError()
caller = sys._getframe().f_back.f_code.co_name
if self.transaction is None:
- self.log("no current transaction: %s()" % caller, zLOG.PROBLEM)
+ self.logger.error("%s: no current transaction: %s()",
+ self.log_label, caller)
if exc is not None:
raise exc(None, tid)
else:
return 0
if self.transaction.id != tid:
- self.log("%s(%s) invalid; current transaction = %s" %
- (caller, repr(tid), repr(self.transaction.id)),
- zLOG.PROBLEM)
+ self.logger.error("%s: %s(%s) invalid; current transaction = %s",
+ self.log_label,
+ caller, repr(tid), repr(self.transaction.id))
if exc is not None:
raise exc(self.transaction.id, tid)
else:
@@ -293,11 +283,12 @@
This method must be the first one called by the client.
"""
if self.storage is not None:
- self.log("duplicate register() call")
+ self.logger.warn("%s: duplicate register() call", self.log_label)
raise ValueError, "duplicate register() call"
storage = self.server.storages.get(storage_id)
if storage is None:
- self.log("unknown storage_id: %s" % storage_id)
+ self.logger.warn("%s: unknown storage_id: %s",
+ self.log_label, storage_id)
raise ValueError, "unknown storage: %s" % storage_id
if not read_only and (self.read_only or storage.isReadOnly()):
@@ -389,9 +380,9 @@
return None
def pack_impl(self, time):
- self.log("pack(time=%s) started..." % repr(time))
+ self.logger.warn("%s: pack(time=%r) started...", self.log_label, time)
self.storage.pack(time)
- self.log("pack(time=%s) complete" % repr(time))
+ self.logger.warn("%s: pack(time=%r) complete", self.log_label, time)
# Broadcast new size statistics
self.server.invalidate(0, self.storage_id, ())
@@ -426,7 +417,8 @@
raise ReadOnlyError()
if self.transaction is not None:
if self.transaction.id == id:
- self.log("duplicate tpc_begin(%s)" % repr(id))
+ self.logger.warn("%s: duplicate tpc_begin(%r)",
+ self.log_label, id)
return
else:
raise StorageTransactionError("Multiple simultaneous tpc_begin"
@@ -507,8 +499,9 @@
if self.storage._transaction:
d = Delay()
self.storage._waiting.append((d, self))
- self.log("Transaction blocked waiting for storage. "
- "Clients waiting: %d." % len(self.storage._waiting))
+ self.logger.warn("%s: Transaction blocked waiting for storage. "
+ "Clients waiting: %d.",
+ self.log_label, len(self.storage._waiting))
return d
else:
return self.restart()
@@ -522,10 +515,11 @@
if self.restart_other(zeo_storage, delay):
if self.storage._waiting:
n = len(self.storage._waiting)
- self.log("Blocked transaction restarted. "
- "Clients waiting: %d" % n)
+ self.logger.warn("%s: Blocked transaction restarted. "
+ "Clients waiting: %d", self.log_label, n)
else:
- self.log("Blocked transaction restarted.")
+ self.logger.warn("%s: Blocked transaction restarted.",
+ self.log_label)
return
def restart_other(self, zeo_storage, delay):
@@ -534,8 +528,9 @@
try:
zeo_storage.restart(delay)
except:
- self.log("Unexpected error handling waiting transaction",
- level=zLOG.WARNING, error=sys.exc_info())
+ self.logger.error("%s: Unexpected error "
+ "handling waiting transaction",
+ self.log_label, exc_info=True)
zeo_storage.connection.close()
return 0
else:
@@ -546,7 +541,8 @@
assert isinstance(old_strategy, DelayedCommitStrategy)
self.strategy = ImmediateCommitStrategy(self.storage,
self.client,
- self.log)
+ self.logger,
+ self.log_label)
resp = old_strategy.restart(self.strategy)
if delay is not None:
delay.reply(resp)
@@ -602,12 +598,13 @@
class ImmediateCommitStrategy:
"""The storage is available so do a normal commit."""
- def __init__(self, storage, client, logmethod):
+ def __init__(self, storage, client, logger, log_label):
self.storage = storage
self.client = client
self.invalidated = []
self.serials = []
- self.log = logmethod
+ self.logger = logger
+ self.log_label = log_label
def tpc_begin(self, txn, tid, status):
self.txn = txn
@@ -634,10 +631,9 @@
except Exception, err:
if not isinstance(err, TransactionError):
# Unexpected errors are logged and passed to the client
- exc_info = sys.exc_info()
- self.log("store error: %s, %s" % exc_info[:2],
- zLOG.ERROR, error=exc_info)
- del exc_info
+ t, v = sys.exc_info()[:2]
+ self.logger.error("%s: store error: %s, %s",
+ self.log_label, t, v, exc_info=True)
# Try to pickle the exception. If it can't be pickled,
# the RPC response would fail, so use something else.
pickler = cPickle.Pickler()
@@ -646,7 +642,7 @@
pickler.dump(err, 1)
except:
msg = "Couldn't pickle storage exception: %s" % repr(err)
- self.log(msg, zLOG.ERROR)
+ self.error(msg)
err = StorageServerError(msg)
# The exception is reported back as newserial for this oid
newserial = err