[Zodb-checkins] CVS: Packages/ZEO - zrpc2.py:1.1.2.10

[jeremy@digicool.com]

Update of /cvs-repository/Packages/ZEO
In directory korak:/tmp/cvs-serv28083

Modified Files:
      Tag: ZEO-ZRPC-Dev
	zrpc2.py 
Log Message:
Revised logging support.

In module log(), pass error argument through to zeolog.
Make some TRACE log message a bit more verbose to explain whether
messages are being sent or received.

If the method invoked via handle_request() raises an exception, log
the traceback.

If unexpected errors occur, e.g. async method raises exception or
decoded error, log rather than printing to stdout.

Other changes:
  import smac and trigger from ZEO package






--- Updated File zrpc2.py in package Packages/ZEO --
--- zrpc2.py	2001/04/20 19:14:09	1.1.2.9
+++ zrpc2.py	2001/04/25 20:36:20	1.1.2.10
@@ -34,16 +34,16 @@
 from cStringIO import StringIO
 
 from ZODB import POSException
-import smac
-import trigger
+from ZEO import smac, trigger
 import zeolog
 import ThreadedAsync
 
 REPLY = ".reply" # message name used for replies
 ASYNC = 1
 
-def log(message, level=zeolog.BLATHER, label="zrpc:%s" % os.getpid()):
-    zeolog.LOG(label, level, message)
+def log(message, level=zeolog.BLATHER, label="zrpc:%s" % os.getpid(),
+        error=None):
+    zeolog.LOG(label, level, message, error=error)
 
 class ZRPCError(POSException.StorageError):
     pass
@@ -174,8 +174,8 @@
                                      sys.exc_info()[1])  
 
         if __debug__:
-            log("message: %s, %s, %s, %s" % (msgid, flags, name,
-                                             repr(args)[:40]),
+            log("recv msg: %s, %s, %s, %s" % (msgid, flags, name,
+                                              repr(args)[:40]),
                 level=zeolog.TRACE)
         if name == REPLY:
             self.handle_reply(msgid, flags, args)
@@ -184,14 +184,15 @@
 
     def handle_reply(self, msgid, flags, args):
         if __debug__:
-            log("reply: %s, %s, %s" % (msgid, flags, str(args)[:40]),
+            log("recv 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):
         if __debug__:
-            log("%s%s" % (name, repr(args)[:40]), zeolog.TRACE)
+            log("call %s%s on %s" % (name, repr(args)[:40], repr(self.obj)),
+                zeolog.TRACE)
         if not self.check_method(name):
             raise ZRPCError("Invalid method name: %s" % name)
 
@@ -207,30 +208,30 @@
                 ret = meth(*args)
         except (POSException.UndoError,
                 POSException.VersionCommitError), msg:
-             return self.return_error(msgid, flags, sys.exc_info()[0],
-                                      sys.exc_info()[1])
+            error = sys.exc_info()
+            log("%s() raised exception: %s" % (name, msg), zeolog.ERROR, error)
+            return self.return_error(msgid, flags, error[0], error[1])
         except Exception, msg:
-            return self.return_error(msgid, flags, sys.exc_info()[0],
-                                     sys.exc_info()[1]) 
-        
+            error = sys.exc_info()
+            log("%s() raised exception: %s" % (name, msg), zeolog.ERROR, error)
+            return self.return_error(msgid, flags, error[0], error[1])
+
         if flags & ASYNC:
             if ret is not None:
+                log("async method %s returned value %s" % (name, repr(ret)),
+                    zeolog.ERROR)
                 raise ZRPCError("async method returned value")
         else:
             if __debug__:
-                log("%s reply %s" % (name, repr(ret)[:40]), zeolog.TRACE)
+                log("%s return %s" % (name, repr(ret)[:40]), zeolog.TRACE)
             if isinstance(ret, Delay):
                 ret.set_sender(msgid, self.send_reply)
             else:
                 self.send_reply(msgid, ret)
 
-    def handle_error(self):
-        t, v, tb = sys.exc_info()
-        if type(v) == types.StringType:
-            print t, repr(v)
-        else:
-            print t, v
-        traceback.print_tb(tb)
+    def handle_error(self, msg="No error message supplied"):
+        error = sys.exc_info()
+        log(msg, zeolog.ERROR, error=error)
 
     def check_method(self, name):
         # XXX minimal security check should go here: Is name exported?
@@ -242,12 +243,10 @@
     
     def return_error(self, msgid, flags, err_type, err_value):
         if flags is None:
-            print "Exception raised during decoding"
-            self.handle_error()
+            self.handle_error("Exception raised during decoding")
             return
         if flags & ASYNC:
-            print "Asynchronous call raised exception:"
-            self.handle_error()
+            self.handle_error("Asynchronous call raised exception")
             return
         if type(err_value) is not types.InstanceType:
             err_value = err_type, err_value
@@ -292,6 +291,8 @@
             raise DisconnectedError("This action is temporarily unavailable")
         msgid = self.msgid
         self.msgid = self.msgid + 1
+        if __debug__:
+            log("send msg: %d, 0, %s, ..." % (msgid, method))
         self.message_output(self.marshal.encode(msgid, 0, method, args))
 
         self.__reply = None
@@ -313,6 +314,8 @@
             raise DisconnectedError("This action is temporarily unavailable")
         msgid = self.msgid
         self.msgid = self.msgid + 1
+        if __debug__:
+            log("send msg: %d, %d, %s, ..." % (msgid, ASYNC, method))
         self.message_output(self.marshal.encode(msgid, ASYNC, method, args))
         self._do_io()