added support for log transaction IDs

git-svn-id: svn://svn.open-ils.org/OpenSRF/trunk@1298 9efc2488-bf62-4759-914b-345cdb29e865

diff --git a/src/python/osrf/http_translator.py b/src/python/osrf/http_translator.py
index 6439db1..3a4966b 100644 (file)
--- a/src/python/osrf/http_translator.py
+++ b/src/python/osrf/http_translator.py
@@ -23,7 +23,7 @@ Example Apache mod_python config:
 '''
 
 OSRF_HTTP_HEADER_TO = 'X-OpenSRF-to'
-OSRF_HTTP_HEADER_XID = 'X-OpenSRF-thread'
+OSRF_HTTP_HEADER_XID = 'X-OpenSRF-xid'
 OSRF_HTTP_HEADER_FROM = 'X-OpenSRF-from'
 OSRF_HTTP_HEADER_THREAD = 'X-OpenSRF-thread'
 OSRF_HTTP_HEADER_TIMEOUT = 'X-OpenSRF-timeout'
@@ -85,8 +85,11 @@ def child_init(req):
 def handler(req):
     ''' Create the translator and tell it to process the request. '''
     child_init(req)
-    status = HTTPTranslator(req).process()
+    translator = HTTPTranslator(req)
+    status = translator.process()
     osrf.log.log_debug("translator call resulted in status %d" % int(status))
+    if translator.local_xid:
+        osrf.log.clear_xid()
     return status
 
 class HTTPTranslator(object):
@@ -96,6 +99,9 @@ class HTTPTranslator(object):
         if apreq.header_only: 
             return
 
+        for k,v in apreq.headers_in.iteritems():
+            osrf.log.log_internal('HEADER: %s = %s' % (k, v))
+
         try:
             post = util.parse_qsl(apreq.read(int(apreq.headers_in['Content-length'])))
             osrf.log.log_debug('post = ' + str(post))
@@ -129,6 +135,15 @@ class HTTPTranslator(object):
         self.remote_host = self.apreq.get_remote_host(apache.REMOTE_NOLOOKUP)
         self.cache = osrf.cache.CacheClient()
 
+        if OSRF_HTTP_HEADER_XID in apreq.headers_in:
+            osrf.log.log_debug('read XID from client %s' % apreq.headers_in.get(OSRF_HTTP_HEADER_XID))
+            osrf.log.set_xid(apreq.headers_in.get(OSRF_HTTP_HEADER_XID))
+            self.local_xid = False
+        else:
+            osrf.log.make_xid()
+            osrf.log.log_debug('created new XID %s' % osrf.log.get_xid())
+            self.local_xid = True
+
 
     def process(self):
 

diff --git a/src/python/osrf/log.py b/src/python/osrf/log.py
index f5fa558..273e0fe 100644 (file)
--- a/src/python/osrf/log.py
+++ b/src/python/osrf/log.py
@@ -13,7 +13,7 @@
 # GNU General Public License for more details.
 # -----------------------------------------------------------------------
 
-import traceback, sys, os, re, threading
+import traceback, sys, os, re, threading, time
 from osrf.const import OSRF_LOG_DEBUG, OSRF_LOG_ERR, OSRF_LOG_INFO, \
     OSRF_LOG_INTERNAL, OSRF_LOG_TYPE_FILE, OSRF_LOG_TYPE_STDERR, \
     OSRF_LOG_TYPE_SYSLOG, OSRF_LOG_WARN
@@ -25,11 +25,17 @@ LOG_TYPE = OSRF_LOG_TYPE_STDERR
 LOG_FILE = None
 FRGX = re.compile('/.*/')
 
+_xid = '' # the current XID
+_xid_pfx = '' # our XID prefix
+_xid_ctr = 0
+_xid_is_client = False # true if we are the request origin
 
-def initialize(level, facility=None, logfile=None):
+
+def initialize(level, facility=None, logfile=None, is_client=False):
     """Initialize the logging subsystem."""
-    global LOG_LEVEL, LOG_TYPE, LOG_FILE
+    global LOG_LEVEL, LOG_TYPE, LOG_FILE, _xid_is_client
 
+    _xid_is_client = is_client
     LOG_LEVEL = level
 
     if facility: 
@@ -47,6 +53,24 @@ def initialize(level, facility=None, logfile=None):
         LOG_TYPE = OSRF_LOG_TYPE_FILE
         LOG_FILE = logfile
 
+def make_xid():
+    global _xid, _xid_pfx, _xid_is_client, _xid_ctr
+    if _xid_is_client:
+        if not _xid_pfx:
+            _xid_pfx = "%s%s" % (time.time(), os.getpid())
+        _xid = "%s%d" % (_xid_pfx, _xid_ctr)
+        _xid_ctr += 1
+         
+def clear_xid():
+    global _xid
+    _xid =  ''
+
+def set_xid(xid):
+    global _xid
+    _xid = xid
+
+def get_xid():
+    return _xid
 
 # -----------------------------------------------------------------------
 # Define wrapper functions for the log levels
@@ -90,7 +114,7 @@ def __log(level, msg):
         lvl = 'ERR '
 
     filename = FRGX.sub('', tb[0])
-    msg = '[%s:%d:%s:%s:%s] %s' % (lvl, os.getpid(), filename, tb[1], threading.currentThread().getName(), msg)
+    msg = '[%s:%d:%s:%s:%s:%s] %s' % (lvl, os.getpid(), filename, tb[1], threading.currentThread().getName(), _xid, msg)
 
     if LOG_TYPE == OSRF_LOG_TYPE_SYSLOG:
         __log_syslog(level, msg)

diff --git a/src/python/osrf/net.py b/src/python/osrf/net.py
index a13d1ce..3e4d91e 100644 (file)
--- a/src/python/osrf/net.py
+++ b/src/python/osrf/net.py
@@ -66,6 +66,7 @@ class NetworkMessage(object):
     body - the body of the message
     thread - the message thread
     locale - locale of the message
+    osrf_xid - The logging transaction ID
     """
 
     def __init__(self, message=None, **args):
@@ -80,6 +81,10 @@ class NetworkMessage(object):
                 self.sender = message.xmlnode.prop('router_from')
             else:
                 self.sender = message.get_from().as_utf8()
+            if message.xmlnode.hasProp('osrf_xid'):
+                self.xid = message.xmlnode
+            else:
+                self.xid = ''
         else:
             self.sender = args.get('sender')
             self.recipient = args.get('recipient')
@@ -87,6 +92,7 @@ class NetworkMessage(object):
             self.thread = args.get('thread')
             self.router_command = args.get('router_command')
             self.router_class = args.get('router_class')
+            self.xid = osrf.log.get_xid()
 
     @staticmethod
     def from_xml(xml):
@@ -104,6 +110,8 @@ class NetworkMessage(object):
             msg.xmlnode.newProp('router_command', self.router_command)
         if self.router_class:
             msg.xmlnode.newProp('router_class', self.router_class)
+        if self.xid:
+            msg.xmlnode.newProp('osrf_xid', self.xid)
         return msg
 
     def to_xml(self):

diff --git a/src/python/osrf/ses.py b/src/python/osrf/ses.py
index 799b1cf..cdafb11 100644 (file)
--- a/src/python/osrf/ses.py
+++ b/src/python/osrf/ses.py
@@ -134,6 +134,8 @@ class ClientSession(Session):
         if self.state != OSRF_APP_SESSION_CONNECTED:
             self.reset_remote_id()
 
+        osrf.log.make_xid()
+
         osrf.log.log_debug("Sending request %s -> %s " % (self.service, method))
         req = ClientRequest(self, self.next_id, method, arr, self.locale)
         self.requests[str(self.next_id)] = req

diff --git a/src/python/osrf/system.py b/src/python/osrf/system.py
index 331b76d..accf45c 100644 (file)
--- a/src/python/osrf/system.py
+++ b/src/python/osrf/system.py
@@ -39,12 +39,13 @@ class System(object):
         # parse the config file
         config_parser = osrf.conf.Config(config_file, config_context)
         config_parser.parse_config()
-        
+
         # set up logging
         osrf.log.initialize(
             osrf.conf.get('loglevel'), 
             osrf.conf.get_no_ex('syslog'),
-            osrf.conf.get_no_ex('logfile'))
+            osrf.conf.get_no_ex('logfile'),
+            osrf.conf.get_no_ex('client') == 'true')
 
         # connect to the opensrf network
         network = Network(