[Zodb-checkins] CVS: Packages/ZEO - zeolog.py:1.1.2.1 ClientCache.py:1.14.4.4 ClientStorage.py:1.26.4.11 StorageServer.py:1.21.4.6 smac.py:1.9.6.4 zrpc2.py:1.1.2.9
jeremy@digicool.com
jeremy@digicool.com
Fri, 20 Apr 2001 15:14:09 -0400 (EDT)
Update of /cvs-repository/Packages/ZEO
In directory korak:/tmp/cvs-serv24482
Modified Files:
Tag: ZEO-ZRPC-Dev
ClientCache.py ClientStorage.py StorageServer.py smac.py
zrpc2.py
Added Files:
Tag: ZEO-ZRPC-Dev
zeolog.py
Log Message:
Big changes to logging to improve performance.
Replace use of zLOG with zeolog (a slimmed-down replacement). Protect
all calls for TRACE level inside if __debug__.
The zLOG code has a lot of extra indirections that slow down an
application. zeolog appears to be about 15% faster.
The use of __debug__ has a much more dramatic effect, because there is
a lot of logging in the lower layers of zrpc2. By putting TRACE-level
logging inside if __debug__ and running python -O, the net savings is
another 20% (measured with speed.py).
Also, add ZPL and doc string to zrpc2.py
--- Added File zeolog.py in package Packages/ZEO ---
"""ZEO-specific replacement for the zLOG module"""
import os
import sys
import time
# the logging severity constants defined by zLOG
from zLOG import TRACE, DEBUG, BLATHER, INFO, PROBLEM, WARNING, ERROR, PANIC
severity_strings = {TRACE: 'TRACE',
DEBUG: 'DEBUG',
BLATHER: 'BLATHER',
INFO: 'INFO',
PROBLEM: 'PROBLEM',
WARNING: 'WARNING',
ERROR: 'ERROR',
PANIC: 'PANIC',
}
def now():
t = time.time()
hms = time.gmtime(t)[3:6]
msec = int(1000 * (t - int(t)))
return "%2.2d:%2.2d:%2.2d." % hms + "%03d" % msec
def LOG(subsys, severity, summary, detail='', error=None,
reraise=None):
if log_file is None or severity < log_level:
return
s = "%s %7s %s %s" % (now(), severity_strings[severity], subsys, summary)
if detail:
s = "%s\n%s" % (s, detail)
print >> log_file, s
log_file.flush()
if error:
pass # XXX haven't implemented traceback writing
if reraise and error:
raise error[0], error[1], error[2]
def initialize():
"""Initialize the module from environment variables"""
global log_file, log_level
path = os.environ.get('STUPID_LOG_FILE', None)
if path is None:
log_file = None
else:
if path:
log_file = open(path, 'a')
else:
log_file = sys.stderr
severity = os.environ.get('STUPID_LOG_SEVERITY', None)
if severity:
log_level = int(severity)
else:
log_level = INFO
__all__ = ["LOG", "TRACE", "DEBUG", "BLATHER", "INFO", "PROBLEM",
"WARNING", "ERROR", "PANIC"]
initialize()
--- Updated File ClientCache.py in package Packages/ZEO --
--- ClientCache.py 2001/04/19 19:18:20 1.14.4.3
+++ ClientCache.py 2001/04/20 19:14:08 1.14.4.4
@@ -151,10 +151,10 @@
from thread import allocate_lock
import sys
-import zLOG
+import zeolog
-def log(msg, level=zLOG.INFO):
- zLOG.LOG("ZEC", level, msg)
+def log(msg, level=zeolog.INFO):
+ zeolog.LOG("ZEC", level, msg)
magic='ZEC0'
--- Updated File ClientStorage.py in package Packages/ZEO --
--- ClientStorage.py 2001/04/20 13:56:10 1.26.4.10
+++ ClientStorage.py 2001/04/20 19:14:08 1.26.4.11
@@ -108,7 +108,7 @@
from ZODB import POSException, BaseStorage
from ZODB.TimeStamp import TimeStamp
-from zLOG import LOG, PROBLEM, INFO, BLATHER
+from zeolog import LOG, PROBLEM, INFO, BLATHER
try:
from ZODB.ConflictResolution import ResolvedSerial
--- Updated File StorageServer.py in package Packages/ZEO --
--- StorageServer.py 2001/04/19 15:47:48 1.21.4.5
+++ StorageServer.py 2001/04/20 19:14:08 1.21.4.6
@@ -1,3 +1,93 @@
+##############################################################################
+#
+# Zope Public License (ZPL) Version 1.0
+# -------------------------------------
+#
+# Copyright (c) Digital Creations. All rights reserved.
+#
+# This license has been certified as Open Source(tm).
+#
+# Redistribution and use in source and binary forms, with or without
+# modification, are permitted provided that the following conditions are
+# met:
+#
+# 1. Redistributions in source code must retain the above copyright
+# notice, this list of conditions, and the following disclaimer.
+#
+# 2. Redistributions in binary form must reproduce the above copyright
+# notice, this list of conditions, and the following disclaimer in
+# the documentation and/or other materials provided with the
+# distribution.
+#
+# 3. Digital Creations requests that attribution be given to Zope
+# in any manner possible. Zope includes a "Powered by Zope"
+# button that is installed by default. While it is not a license
+# violation to remove this button, it is requested that the
+# attribution remain. A significant investment has been put
+# into Zope, and this effort will continue if the Zope community
+# continues to grow. This is one way to assure that growth.
+#
+# 4. All advertising materials and documentation mentioning
+# features derived from or use of this software must display
+# the following acknowledgement:
+#
+# "This product includes software developed by Digital Creations
+# for use in the Z Object Publishing Environment
+# (http://www.zope.org/)."
+#
+# In the event that the product being advertised includes an
+# intact Zope distribution (with copyright and license included)
+# then this clause is waived.
+#
+# 5. Names associated with Zope or Digital Creations must not be used to
+# endorse or promote products derived from this software without
+# prior written permission from Digital Creations.
+#
+# 6. Modified redistributions of any form whatsoever must retain
+# the following acknowledgment:
+#
+# "This product includes software developed by Digital Creations
+# for use in the Z Object Publishing Environment
+# (http://www.zope.org/)."
+#
+# Intact (re-)distributions of any official Zope release do not
+# require an external acknowledgement.
+#
+# 7. Modifications are encouraged but must be packaged separately as
+# patches to official Zope releases. Distributions that do not
+# clearly separate the patches from the original work must be clearly
+# labeled as unofficial distributions. Modifications which do not
+# carry the name Zope may be packaged in any form, as long as they
+# conform to all of the clauses above.
+#
+#
+# Disclaimer
+#
+# THIS SOFTWARE IS PROVIDED BY DIGITAL CREATIONS ``AS IS'' AND ANY
+# EXPRESSED OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
+# PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL DIGITAL CREATIONS OR ITS
+# CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+# SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+# LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+# USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+# ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
+# OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+# SUCH DAMAGE.
+#
+#
+# This software consists of contributions made by Digital Creations and
+# many individuals on behalf of Digital Creations. Specific
+# attributions are listed in the accompanying credits file.
+#
+##############################################################################
+"""Network ZODB storage server
+
+This server acts as a front-end for one or more real storages, like
+file storage or Berkeley storage.
+"""
+
import cPickle
import os
import sys
@@ -5,7 +95,7 @@
import ClientStub
import zrpc2
-import zLOG
+import zeolog
from zrpc2 import Dispatcher, Handler, ManagedServerConnection, Delay
from ZODB.POSException import StorageError, StorageTransactionError, \
@@ -20,8 +110,8 @@
pickler.fast = 1 # Don't use the memo
dump = pickler.dump
-def log(message, level=zLOG.INFO, label="zeoserver:%s" % os.getpid()):
- zLOG.LOG(label, level, message)
+def log(message, level=zeolog.INFO, label="zeoserver:%s" % os.getpid()):
+ zeolog.LOG(label, level, message)
class StorageServerError(StorageError):
pass
@@ -157,7 +247,7 @@
try:
self.__storage.pack(t, referencesf)
except:
- log('ZEO Server', zLOG.ERROR,
+ log('ZEO Server', zeolog.ERROR,
'Pack failed for %s' % self.__storage_id,
error=sys.exc_info())
if wait:
@@ -208,7 +298,7 @@
# IOW, Anything that ends up here is evil enough to be logged.
error = sys.exc_info()
log('store error: %s: %s' % (error[0], error[1]).
- zLOG.ERROR)
+ zeolog.ERROR)
newserial = sys.exc_info()[1]
else:
if serial != '\0\0\0\0\0\0\0\0':
@@ -218,7 +308,7 @@
nil = dump(newserial, 1)
except:
log("couldn't pickle newserial: %s" % repr(newserial),
- zLOG.ERROR)
+ zeolog.ERROR)
dump('', 1) # clear pickler
r = StorageServerError("Couldn't pickle exception %s" % \
`newserial`)
--- Updated File smac.py in package Packages/ZEO --
--- smac.py 2001/04/18 20:55:09 1.9.6.3
+++ smac.py 2001/04/20 19:14:08 1.9.6.4
@@ -88,7 +88,7 @@
__version__ = "$Revision$"[11:-2]
import asyncore, string, struct, sys, Acquisition
-from zLOG import LOG, TRACE, ERROR, INFO, BLATHER
+from zeolog import LOG, TRACE, ERROR, INFO, BLATHER
from types import StringType
class SizedMessageAsyncConnection(asyncore.dispatcher):
--- Updated File zrpc2.py in package Packages/ZEO --
--- zrpc2.py 2001/04/19 18:25:03 1.1.2.8
+++ zrpc2.py 2001/04/20 19:14:09 1.1.2.9
@@ -36,14 +36,14 @@
from ZODB import POSException
import smac
import trigger
-import zLOG
+import zeolog
import ThreadedAsync
REPLY = ".reply" # message name used for replies
ASYNC = 1
-def log(message, level=zLOG.BLATHER, label="zrpc:%s" % os.getpid()):
- zLOG.LOG(label, level, message)
+def log(message, level=zeolog.BLATHER, label="zrpc:%s" % os.getpid()):
+ zeolog.LOG(label, level, message)
class ZRPCError(POSException.StorageError):
pass
@@ -97,11 +97,11 @@
unpickler.find_global = find_global
try:
+ return unpickler.load() # msgid, flags, name, args
msgid, flags, name, args = unpickler.load()
except (cPickle.UnpicklingError, IndexError), err_msg:
- log("can't decode %s" % repr(msg), level=zLOG.ERROR)
+ log("can't decode %s" % repr(msg), level=zeolog.ERROR)
raise DecodingError(msg)
- return msgid, flags, name, args
class Delay:
"""Used to delay response to client for synchronous calls
@@ -118,43 +118,6 @@
def reply(self, obj):
self.send_reply(self.msgid, obj)
-class DebugLock:
-
- __locks = 0
-
- def __init__(self):
- self.lock = thread.allocate_lock()
- # XXX this actually needs to be locked too
- self.__lock_id = self.__locks
- self.__locks = self.__locks + 1
-
- def _debug(self):
- method = sys._getframe().f_back
- caller = method.f_back
- filename = os.path.split(caller.f_code.co_filename)[1]
- log("LOCK %s (tid %s): " \
- "%s called by %s, %s, line %s" % (self.__lock_id,
- thread.get_ident(),
- method.f_code.co_name,
- caller.f_code.co_name,
- filename,
- caller.f_lineno))
-
- def acquire(self, wait=None):
- self._debug()
- if wait is not None:
- return self.lock.acquire(wait)
- else:
- return self.lock.acquire()
-
- def release(self):
- self._debug()
- return self.lock.release()
-
- def locked(self):
- self._debug()
- return self.lock.locked()
-
class Connection(smac.SizedMessageAsyncConnection):
"""Dispatcher for RPC on object
@@ -182,7 +145,6 @@
# waiting for a response
self.__super_init(sock, addr)
self._prepare_async()
-## self.__reply_lock = DebugLock()
self.__reply_lock = thread.allocate_lock()
self.__reply_lock.acquire()
if isinstance(obj, Handler):
@@ -211,20 +173,25 @@
return self.return_error(None, None, sys.exc_info()[0],
sys.exc_info()[1])
- log("message: %s, %s, %s, %s" % (msgid, flags, name, repr(args)[:40]),
- level=zLOG.TRACE)
+ if __debug__:
+ log("message: %s, %s, %s, %s" % (msgid, flags, name,
+ repr(args)[:40]),
+ level=zeolog.TRACE)
if name == REPLY:
self.handle_reply(msgid, flags, args)
else:
self.handle_request(msgid, flags, name, args)
def handle_reply(self, msgid, flags, args):
- log("reply: %s, %s, %s" % (msgid, flags, str(args)[:40]))
+ if __debug__:
+ log("reply: %s, %s, %s" % (msgid, flags, str(args)[:40]),
+ level=zeolog.TRACE)
self.__reply = msgid, flags, args
self.__reply_lock.release() # will fail if lock is unlocked
def handle_request(self, msgid, flags, name, args):
- log("%s%s" % (name, repr(args)[:40]), zLOG.TRACE)
+ if __debug__:
+ log("%s%s" % (name, repr(args)[:40]), zeolog.TRACE)
if not self.check_method(name):
raise ZRPCError("Invalid method name: %s" % name)
@@ -250,7 +217,8 @@
if ret is not None:
raise ZRPCError("async method returned value")
else:
- log("%s reply %s" % (name, repr(ret)[:40]), zLOG.TRACE)
+ if __debug__:
+ log("%s reply %s" % (name, repr(ret)[:40]), zeolog.TRACE)
if isinstance(ret, Delay):
ret.set_sender(msgid, self.send_reply)
else:
@@ -324,7 +292,6 @@
raise DisconnectedError("This action is temporarily unavailable")
msgid = self.msgid
self.msgid = self.msgid + 1
- log("call %s %s" % (msgid, method))
self.message_output(self.marshal.encode(msgid, 0, method, args))
self.__reply = None
@@ -333,15 +300,12 @@
# lock is held again...
r_msgid, r_flags, r_args = self.__reply
self.__reply_lock.acquire()
- log("call acquired lock")
assert r_msgid == msgid, "%s != %s: %s" % (r_msgid, msgid, r_args)
if type(r_args) == types.TupleType \
and type(r_args[0]) == types.ClassType \
and issubclass(r_args[0], Exception):
- log("call %s %s raised error" % (msgid, method))
raise r_args[1]
- log("call %s %s returned" % (msgid, method))
return r_args
def callAsync(self, method, *args):
@@ -349,12 +313,14 @@
raise DisconnectedError("This action is temporarily unavailable")
msgid = self.msgid
self.msgid = self.msgid + 1
- log("async %s %s" % (msgid, method))
self.message_output(self.marshal.encode(msgid, ASYNC, method, args))
self._do_io()
# handle IO, possibly in async mode
+ def sync(self):
+ pass # XXX what is this supposed to do?
+
def _prepare_async(self):
self._async = 0
ThreadedAsync.register_loop_callback(self.set_async)
@@ -373,9 +339,10 @@
def _do_io(self, wait=0): # XXX need better name
# XXX invariant? lock must be held when calling with wait==1
# otherwise, in non-async mode, there will be no poll
-
- log("_do_io(wait=%d), async=%d" % (wait, self.is_async()),
- level=zLOG.TRACE)
+
+ if __debug__:
+ log("_do_io(wait=%d), async=%d" % (wait, self.is_async()),
+ level=zeolog.TRACE)
if self.is_async():
self.trigger.pull_trigger()
if wait:
@@ -465,12 +432,12 @@
s.connect(self.addr)
except socket.error:
if self.debug:
- log("Failed to connect to server", level=zLOG.DEBUG)
+ log("Failed to connect to server", level=zeolog.DEBUG)
if repeat:
t = self._wait(t)
else:
if self.debug:
- log("Connected to server", level=zLOG.DEBUG)
+ log("Connected to server", level=zeolog.DEBUG)
self.connected = 1
if self.connected:
c = ManagedConnection(s, self.addr, self.obj, self)
@@ -502,7 +469,6 @@
def close(self):
self.__super_close()
- log("self.__mgr = %s" % repr(self.__mgr))
self.__mgr.close(self)
class ManagedConnection(Connection):
@@ -578,7 +544,7 @@
log("accepted failed: %s" % msg)
return
c = self.factory(sock, addr, self.obj)
- log("connect from %s: %s" % (addr, c))
+ log("connect from %s: %s" % (repr(addr), c))
self.clients.append(c)
class Handler: