From: erickson <erickson@dcc99617-32d9-48b4-a31d-7c20da2025e4>
Date: Mon, 5 Feb 2007 19:17:19 +0000 (+0000)
Subject: added logger xid support
X-Git-Url: https://old-git.evergreen-ils.org/?a=commitdiff_plain;h=4776bd84f91b8d1c27edcee4841fbe4a8e6b9aa7;p=Evergreen.git

added logger xid support


git-svn-id: svn://svn.open-ils.org/ILS/branches/rel_1_0@6884 dcc99617-32d9-48b4-a31d-7c20da2025e4
---

diff --git a/OpenSRF/src/perlmods/OpenSRF/Transport.pm b/OpenSRF/src/perlmods/OpenSRF/Transport.pm
index bfc25d1724..4ee322c3ba 100644
--- a/OpenSRF/src/perlmods/OpenSRF/Transport.pm
+++ b/OpenSRF/src/perlmods/OpenSRF/Transport.pm
@@ -89,6 +89,7 @@ sub handler {
 	my $body	= $helper->get_body();
 	my $type	= $helper->get_msg_type();
 
+   $logger->set_osrf_xid($helper->get_osrf_xid);
 
 	if (defined($type) and $type eq 'error') {
 		throw OpenSRF::EX::Session ("$remote_id IS NOT CONNECTED TO THE NETWORK!!!");
diff --git a/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/Client.pm b/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/Client.pm
index e2374f4a6f..1122457269 100644
--- a/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/Client.pm
+++ b/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/Client.pm
@@ -413,7 +413,7 @@ sub send {
 	$msg->setBody( $body );
 	$msg->set_router_command( $router_command );
 	$msg->set_router_class( $router_class );
-
+   $msg->set_osrf_xid($logger->get_osrf_xid);
 
 	$logger->transport( 
 			"JabberClient Sending message to $to with thread $thread and body: \n$body", INTERNAL );
diff --git a/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/MessageWrapper.pm b/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/MessageWrapper.pm
index b337dff725..3f5393c516 100644
--- a/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/MessageWrapper.pm
+++ b/OpenSRF/src/perlmods/OpenSRF/Transport/SlimJabber/MessageWrapper.pm
@@ -111,4 +111,16 @@ sub set_router_class {
 	}
 }
 
+sub set_osrf_xid {
+   my( $self, $xid ) = @_;
+   $self->{msg_node}->setAttribute( osrf_xid => $xid );
+}
+
+
+sub get_osrf_xid {
+   my $self = shift;
+   $self->{msg_node}->getAttribute('osrf_xid');
+}
+
+
 1;
diff --git a/OpenSRF/src/perlmods/OpenSRF/Utils/Logger.pm b/OpenSRF/src/perlmods/OpenSRF/Utils/Logger.pm
index 69d79d251a..bbeff7acaf 100644
--- a/OpenSRF/src/perlmods/OpenSRF/Utils/Logger.pm
+++ b/OpenSRF/src/perlmods/OpenSRF/Utils/Logger.pm
@@ -53,6 +53,8 @@ sub DEBUG		{ return 4;	}
 sub INTERNAL	{ return 5;	}
 sub ALL			{ return 100; }
 
+my $isclient;  # true if we control the osrf_xid
+
 # load up our config options
 sub set_config {
 
@@ -97,7 +99,7 @@ sub set_config {
 
 	} else { $actfile = "$logdir/$actfile"; }
 
-	#warn "Level: $loglevel, Fac: $facility, Act: $actfac\n";
+	$isclient = (OpenSRF::Utils::Config->current->bootstrap->client =~ /^true$/iog) ?  1 : 0;
 }
 
 sub _fac_to_const {
@@ -186,7 +188,26 @@ sub transport {
 }
 
 
+# ----------------------------------------------------------------------
+# creates a new xid if necessary
+# ----------------------------------------------------------------------
+my $osrf_xid = '';
+my $osrf_xid_inc = 0;
+sub mk_osrf_xid {
+   return unless $isclient;
+   $osrf_xid_inc++;
+   return $osrf_xid = "$^T${$}$osrf_xid_inc";
+}
+
+sub set_osrf_xid { 
+   return if $isclient; # if we're a client, we control our xid
+   $osrf_xid = $_[1]; 
+}
+
+sub get_osrf_xid { return $osrf_xid; }
+# ----------------------------------------------------------------------
 
+   
 sub _log_message {
 	my( $msg, $level ) = @_;
 	return if $level > $loglevel;
@@ -201,12 +222,13 @@ sub _log_message {
 	elsif ($level == INTERNAL())	{$l = LOG_DEBUG; $n = "INTL"; }
 	elsif ($level == ACTIVITY())	{$l = LOG_INFO; $n = "ACT"; $fac = $actfac; }
 
-	#my( $pack, $file, $line_no ) = @caller;
+	my( undef, $file, $line_no ) = caller(1);
+   $file =~ s#/.*/##og;
 
 	# help syslog with the formatting
 	$msg =~ s/\%/\%\%/gso if( is_act_syslog() or is_syslog() );
 
-	$msg = "[$n:"."$$".":::] $msg";
+	$msg = "[$n:"."$$".":$file:$line_no:$osrf_xid] $msg";
 
 	$msg = substr($msg, 0, 1536); 
 
diff --git a/OpenSRF/src/router/osrf_router.c b/OpenSRF/src/router/osrf_router.c
index 4e61992ab6..8308851ce5 100644
--- a/OpenSRF/src/router/osrf_router.c
+++ b/OpenSRF/src/router/osrf_router.c
@@ -136,6 +136,8 @@ int osrfRouterClassHandleIncoming( osrfRouter* router, char* classname, osrfRout
 
 	while( (msg = client_recv( class->connection, 0 )) ) {
 
+      osrfLogSetXid(msg->osrf_xid);
+
 		if( msg->sender ) {
 
 			osrfLogDebug(OSRF_LOG_MARK, 
@@ -166,6 +168,7 @@ int osrfRouterClassHandleIncoming( osrfRouter* router, char* classname, osrfRout
 			}
 		}
 
+      osrfLogClearXid();
 		message_free( msg );
 	}
 
@@ -270,6 +273,7 @@ transport_message* osrfRouterClassHandleBounce(
 			transport_message* error = message_init( 
 				node->lastMessage->body, node->lastMessage->subject, 
 				node->lastMessage->thread, node->lastMessage->router_from, node->lastMessage->recipient );
+         message_set_osrf_xid(error, node->lastMessage->osrf_xid);
 			set_msg_error( error, "cancel", 501 );
 	
 			/* send the error message back to the original sender */
@@ -287,6 +291,7 @@ transport_message* osrfRouterClassHandleBounce(
 				lastSent = message_init( node->lastMessage->body,
 					node->lastMessage->subject, node->lastMessage->thread, "", node->lastMessage->router_from );
 				message_set_router_info( lastSent, node->lastMessage->router_from, NULL, NULL, NULL, 0 );
+            message_set_osrf_xid( lastSent, node->lastMessage->osrf_xid );
 			}
 		} else {
 
@@ -324,6 +329,7 @@ int osrfRouterClassHandleMessage(
 		transport_message* new_msg= message_init(	msg->body, 
 				msg->subject, msg->thread, node->remoteId, msg->sender );
 		message_set_router_info( new_msg, msg->sender, NULL, NULL, NULL, 0 );
+      message_set_osrf_xid( new_msg, msg->osrf_xid );
 
 		osrfLogInfo( OSRF_LOG_MARK,  "Routing message:\nfrom: [%s]\nto: [%s]", 
 				new_msg->router_from, new_msg->recipient );
@@ -390,6 +396,9 @@ void osrfRouterClassFree( char* classname, void* c ) {
 	while( (node = osrfHashIteratorNext(rclass->itr)) ) 
 		osrfRouterClassRemoveNode( rclass->router, classname, node->remoteId );
 
+   osrfHashIteratorFree(rclass->itr);
+   osrfHashFree(rclass->nodes);
+
 	free(rclass);
 }
 
diff --git a/OpenSRF/src/utils/log.c b/OpenSRF/src/utils/log.c
index 92791c2940..be2abe02c3 100644
--- a/OpenSRF/src/utils/log.c
+++ b/OpenSRF/src/utils/log.c
@@ -7,6 +7,12 @@ char* __osrfLogFile				= NULL;
 char* __osrfLogAppname			= NULL;
 int __osrfLogLevel				= OSRF_LOG_INFO;
 int __osrfLogActivityEnabled	= 1;
+int __osrfLogIsClient         = 0;
+
+
+int __osrfLogXidInc              = 0; /* increments with each new xid for uniqueness */
+char* __osrfLogXid            = NULL; /* current xid */
+char* __osrfLogXidPfx         = NULL; /* xid prefix string */
 
 
 void osrfLogCleanup() {
@@ -23,6 +29,42 @@ void osrfLogInit( int type, const char* appname, int maxlevel ) {
 		openlog(__osrfLogAppname, 0, __osrfLogFacility );
 }
 
+static void __osrfLogSetXid(char* xid) {
+   if(xid) {
+      if(__osrfLogXid) free(__osrfLogXid);
+      __osrfLogXid = strdup(xid);
+   }
+}
+
+void osrfLogClearXid() { __osrfLogSetXid(""); }
+void osrfLogSetXid(char* xid) {
+   if(!__osrfLogIsClient) __osrfLogSetXid(xid);
+}
+
+void osrfLogMkXid() {
+   if(__osrfLogIsClient) {
+      char buf[32];
+      memset(buf, 0x0, 32);
+      snprintf(buf, 32, "%s%d", __osrfLogXidPfx, __osrfLogXidInc);
+      __osrfLogSetXid(buf);
+      __osrfLogXidInc++;
+   }
+}
+
+char* osrfLogGetXid() {
+   return __osrfLogXid;
+}
+
+void osrfLogSetIsClient(int is) {
+   __osrfLogIsClient = is;
+   if(!is) return;
+   /* go ahead and create the xid prefix so it will be consistent later */
+   static char buff[32];
+   memset(buff, 0x0, 32);
+   snprintf(buff, 32, "%d%d", (int)time(NULL), getpid());
+   __osrfLogXidPfx = buff;
+}
+
 void osrfLogSetType( int logtype ) { 
 	if( logtype != OSRF_LOG_TYPE_FILE &&
 			logtype != OSRF_LOG_TYPE_SYSLOG ) {
@@ -124,6 +166,8 @@ void _osrfLogDetail( int level, const char* filename, int line, char* msg ) {
 			break;
 	}
 
+   char* xid = (__osrfLogXid) ? __osrfLogXid : "";
+
 	if(__osrfLogType == OSRF_LOG_TYPE_SYSLOG ) {
 		char buf[1536];  
 		memset(buf, 0x0, 1536);
@@ -133,11 +177,11 @@ void _osrfLogDetail( int level, const char* filename, int line, char* msg ) {
 		buf[1533] = '.';
 		buf[1534] = '.';
 		buf[1535] = '\0';
-		syslog( fac | lvl, "[%s:%d:%s:%d] %s", l, getpid(), filename, line, buf );
+		syslog( fac | lvl, "[%s:%d:%s:%d:%s] %s", l, getpid(), filename, line, xid, buf );
 	}
 
 	else if( __osrfLogType == OSRF_LOG_TYPE_FILE )
-		_osrfLogToFile("[%s:%d:%s:%d] %s", l, getpid(), filename, line, msg );
+		_osrfLogToFile("[%s:%d:%s:%d:%s] %s", l, getpid(), filename, line, xid, msg );
 
 }
 
diff --git a/OpenSRF/src/utils/log.h b/OpenSRF/src/utils/log.h
index 8764443cca..588bb1b98f 100644
--- a/OpenSRF/src/utils/log.h
+++ b/OpenSRF/src/utils/log.h
@@ -59,6 +59,12 @@ void osrfLogActivity( const char* file, int line, const char* msg, ... );
 
 void osrfLogCleanup();
 
+void osrfLogClearXid();
+void osrfLogSetXid(char* xid);
+void osrfLogMkXid();
+void osrfLogSetIsClient(int is);
+char* osrfLogGetXid();
+
 /* sets the activity flag */
 void osrfLogSetActivityEnabled( int enabled );