diff libfdproto/messages.c @ 687:026802543f57

Prepare for new message log facility
author Sebastien Decugis <sdecugis@nict.go.jp>
date Wed, 19 Jan 2011 17:08:21 +0900
parents f83d9878bf66
children 8c3dc8584dab
line wrap: on
line diff
--- a/libfdproto/messages.c	Wed Jan 19 14:35:14 2011 +0900
+++ b/libfdproto/messages.c	Wed Jan 19 17:08:21 2011 +0900
@@ -660,20 +660,20 @@
 #define INOBJHDRVAL 	indent<0 ? 1 : indent, indent<0 ? "-" : "|"
 
 /* Dump a msg_t object */
-static void obj_dump_msg (struct msg * msg, int indent )
+static void obj_dump_msg (struct msg * msg, int indent, FILE * fstr )
 {
 	int ret = 0;
 	
-	fd_log_debug("%*sMSG: %p\n", INOBJHDRVAL, msg);
+	fd_log_debug_fstr(fstr, "%*sMSG: %p\n", INOBJHDRVAL, msg);
 	
 	if (!CHECK_MSG(msg)) {
-		fd_log_debug(INOBJHDR "INVALID!\n", INOBJHDRVAL);
+		fd_log_debug_fstr(fstr, INOBJHDR "INVALID!\n", INOBJHDRVAL);
 		return;
 	}
 	
 	if (!msg->msg_model) {
 		
-		fd_log_debug(INOBJHDR "(no model)\n", INOBJHDRVAL);
+		fd_log_debug_fstr(fstr, INOBJHDR "(no model)\n", INOBJHDRVAL);
 		
 	} else {
 		
@@ -681,19 +681,19 @@
 		struct dict_cmd_data  dictdata;
 		ret = fd_dict_gettype(msg->msg_model, &dicttype);
 		if (ret || (dicttype != DICT_COMMAND)) {
-			fd_log_debug(INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
+			fd_log_debug_fstr(fstr, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
 			goto public;
 		}
 		ret = fd_dict_getval(msg->msg_model, &dictdata);
 		if (ret != 0) {
-			fd_log_debug(INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
+			fd_log_debug_fstr(fstr, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
 			goto public;
 		}
-		fd_log_debug(INOBJHDR "model : v/m:" DUMP_CMDFL_str "/" DUMP_CMDFL_str ", %u \"%s\"\n", INOBJHDRVAL, 
+		fd_log_debug_fstr(fstr, INOBJHDR "model : v/m:" DUMP_CMDFL_str "/" DUMP_CMDFL_str ", %u \"%s\"\n", INOBJHDRVAL, 
 			DUMP_CMDFL_val(dictdata.cmd_flag_val), DUMP_CMDFL_val(dictdata.cmd_flag_mask), dictdata.cmd_code, dictdata.cmd_name);
 	}
 public:	
-	fd_log_debug(INOBJHDR "public: V:%d L:%d fl:" DUMP_CMDFL_str " CC:%u A:%d hi:%x ei:%x\n", INOBJHDRVAL, 
+	fd_log_debug_fstr(fstr, INOBJHDR "public: V:%d L:%d fl:" DUMP_CMDFL_str " CC:%u A:%d hi:%x ei:%x\n", INOBJHDRVAL, 
 		msg->msg_public.msg_version,
 		msg->msg_public.msg_length,
 		DUMP_CMDFL_val(msg->msg_public.msg_flags),
@@ -702,24 +702,24 @@
 		msg->msg_public.msg_hbhid,
 		msg->msg_public.msg_eteid
 		);
-	fd_log_debug(INOBJHDR "intern: rwb:%p rt:%d cb:%p(%p) qry:%p asso:%d sess:%p src:%s\n", 
+	fd_log_debug_fstr(fstr, INOBJHDR "intern: rwb:%p rt:%d cb:%p(%p) qry:%p asso:%d sess:%p src:%s\n", 
 			INOBJHDRVAL, msg->msg_rawbuffer, msg->msg_routable, msg->msg_cb.fct, msg->msg_cb.data, msg->msg_query, msg->msg_associated, msg->msg_sess, msg->msg_src_id?:"(nil)");
 }
 
 /* Dump an avp object */
-static void obj_dump_avp ( struct avp * avp, int indent )
+static void obj_dump_avp ( struct avp * avp, int indent, FILE * fstr )
 {
 	int ret = 0;
 	enum dict_avp_basetype type = -1;
 	
 	if (!CHECK_AVP(avp)) {
-		fd_log_debug(INOBJHDR "INVALID!\n", INOBJHDRVAL);
+		fd_log_debug_fstr(fstr, INOBJHDR "INVALID!\n", INOBJHDRVAL);
 		return;
 	}
 	
 	if (!avp->avp_model) {
 		
-		fd_log_debug(INOBJHDR "(no model)\n", INOBJHDRVAL);
+		fd_log_debug_fstr(fstr, INOBJHDR "(no model)\n", INOBJHDRVAL);
 		
 	} else {
 		
@@ -727,15 +727,15 @@
 		struct dict_avp_data dictdata;
 		ret = fd_dict_gettype(avp->avp_model, &dicttype);
 		if (ret || (dicttype != DICT_AVP)) {
-			fd_log_debug(INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
+			fd_log_debug_fstr(fstr, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
 			goto public;
 		}
 		ret = fd_dict_getval(avp->avp_model, &dictdata);
 		if (ret != 0) {
-			fd_log_debug(INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
+			fd_log_debug_fstr(fstr, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
 			goto public;
 		}
-		fd_log_debug(INOBJHDR "model : v/m:" DUMP_AVPFL_str "/" DUMP_AVPFL_str ", %12s, %u \"%s\"\n", INOBJHDRVAL, 
+		fd_log_debug_fstr(fstr, INOBJHDR "model : v/m:" DUMP_AVPFL_str "/" DUMP_AVPFL_str ", %12s, %u \"%s\"\n", INOBJHDRVAL, 
 			DUMP_AVPFL_val(dictdata.avp_flag_val), 
 			DUMP_AVPFL_val(dictdata.avp_flag_mask), 
 			type_base_name[dictdata.avp_basetype], 
@@ -744,7 +744,7 @@
 		type = dictdata.avp_basetype;
 	}
 public:	
-	fd_log_debug(INOBJHDR "public: C:%u fl:" DUMP_AVPFL_str " L:%d V:%u  data:@%p\n", INOBJHDRVAL, 
+	fd_log_debug_fstr(fstr, INOBJHDR "public: C:%u fl:" DUMP_AVPFL_str " L:%d V:%u  data:@%p\n", INOBJHDRVAL, 
 		avp->avp_public.avp_code,
 		DUMP_AVPFL_val(avp->avp_public.avp_flags),
 		avp->avp_public.avp_len,
@@ -754,17 +754,17 @@
 	/* Dump the value if set */
 	if (avp->avp_public.avp_value) {
 		if (!avp->avp_model) {
-			fd_log_debug(INOBJHDR "(data set but no model: ERROR)\n", INOBJHDRVAL);
+			fd_log_debug_fstr(fstr, INOBJHDR "(data set but no model: ERROR)\n", INOBJHDRVAL);
 		} else {
-			fd_dict_dump_avp_value(avp->avp_public.avp_value, avp->avp_model, indent);
+			fd_dict_dump_avp_value(avp->avp_public.avp_value, avp->avp_model, indent, fstr);
 		}
 	}
 
-	fd_log_debug(INOBJHDR "intern: src:%p mf:%d raw:%p(%d)\n", INOBJHDRVAL, avp->avp_source, avp->avp_mustfreeos, avp->avp_rawdata, avp->avp_rawlen);
+	fd_log_debug_fstr(fstr, INOBJHDR "intern: src:%p mf:%d raw:%p(%d)\n", INOBJHDRVAL, avp->avp_source, avp->avp_mustfreeos, avp->avp_rawdata, avp->avp_rawlen);
 }
 
 /* Dump a single object content */
-static void msg_dump_intern ( int level, msg_or_avp * obj, int indent )
+static void msg_dump_intern ( int level, msg_or_avp * obj, int indent, FILE * fstr )
 {
 	/* Log only if we are at least at level */
 	if ( ! TRACE_BOOL(level) )
@@ -772,18 +772,18 @@
 	
 	/* Check the object */
 	if (!VALIDATE_OBJ(obj)) {
-		fd_log_debug( ">>> invalid object (%p)!.\n", obj);
+		fd_log_debug_fstr(fstr, ">>> invalid object (%p)!.\n", obj);
 		return;
 	}
 	
 	/* Dump the object */
 	switch (_C(obj)->type) {
 		case MSG_AVP:
-			obj_dump_avp ( _A(obj), indent );
+			obj_dump_avp ( _A(obj), indent, fstr );
 			break;
 		
 		case MSG_MSG:
-			obj_dump_msg ( _M(obj), indent );
+			obj_dump_msg ( _M(obj), indent, fstr );
 			break;
 		
 		default:
@@ -791,6 +791,21 @@
 	}
 }
 
+/* Dump a message to a specified file stream */
+static void fd_msg_dump_fstr ( struct msg * msg, FILE * fstr )
+{
+	msg_or_avp * ref = msg;
+	int indent = 2;
+	do {
+		msg_dump_intern ( NONE, ref, indent, fstr );
+		
+		/* Now find the next object */
+		CHECK_FCT_DO(  fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break  );
+		
+		/* dump next object */
+	} while (ref);
+}
+
 /* Dump a message content -- for debug mostly */
 void fd_msg_dump_walk ( int level, msg_or_avp *obj )
 {
@@ -799,7 +814,7 @@
 	
 	TRACE_DEBUG(level, "------ Dumping object %p (w)-------", obj);
 	do {
-		msg_dump_intern ( level, ref, indent );
+		msg_dump_intern ( level, ref, indent, fd_g_debug_fstr );
 		
 		/* Now find the next object */
 		CHECK_FCT_DO(  fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break  );
@@ -814,7 +829,7 @@
 void fd_msg_dump_one ( int level, msg_or_avp * obj )
 {
 	TRACE_DEBUG(level, "------ Dumping object %p (s)-------", obj);
-	msg_dump_intern ( level, obj, 1 );
+	msg_dump_intern ( level, obj, 1, fd_g_debug_fstr );
 	TRACE_DEBUG(level, "------ /end of object %p -------", obj);
 }
 
@@ -1644,7 +1659,7 @@
 		
 		if (mandatory && (avp->avp_public.avp_flags & AVP_FLAG_MANDATORY)) {
 			TRACE_DEBUG(INFO, "Unsupported mandatory AVP found:");
-			msg_dump_intern(INFO, avp, 2);
+			msg_dump_intern(INFO, avp, 2, fd_g_debug_fstr);
 			if (error_info) {
 				error_info->pei_errcode = "DIAMETER_AVP_UNSUPPORTED";
 				error_info->pei_avp = avp;
@@ -2308,3 +2323,123 @@
 	CHECK_POSIX_DO(pthread_rwlock_unlock(&fd_disp_lock), /* ignore */ );
 	return ret;
 }
+
+
+/***************************************************************************************************************/
+/* messages logging facility */
+#include <stdarg.h>
+
+static struct {
+	struct {
+		enum fd_msg_log_method 	meth;
+		const char * 		metharg;
+	} causes[FD_MSG_LOG_MAX + 1];
+	pthread_mutex_t lock;
+	int		init;
+} ml_conf = { .lock = PTHREAD_MUTEX_INITIALIZER, .init = 0 };
+
+static void ml_conf_init(void) 
+{
+	memset(&ml_conf.causes, 0, sizeof(ml_conf.causes));
+	ml_conf.init = 1;
+}
+
+/* Set a configuration property */
+int fd_msg_log_config(enum fd_msg_log_cause cause, enum fd_msg_log_method method, const char * arg)
+{
+	/* Check the parameters are valid */
+	TRACE_ENTRY("%d %d %p", cause, method, arg);
+	CHECK_PARAMS( (cause >= 0) && (cause <= FD_MSG_LOG_MAX) );
+	CHECK_PARAMS( (method >= FD_MSG_LOGTO_DEBUGONLY) && (method <= FD_MSG_LOGTO_DIR) );
+	CHECK_PARAMS( (method == FD_MSG_LOGTO_DEBUGONLY) || (arg != NULL) );
+	
+	/* Lock the configuration */
+	CHECK_POSIX( pthread_mutex_lock(&ml_conf.lock) );
+	if (!ml_conf.init) {
+		ml_conf_init();
+	}
+	
+	/* Now set the parameter */
+	ml_conf.causes[cause].meth = method;
+	ml_conf.causes[cause].metharg = arg;
+	
+	if (method) {
+		TRACE_DEBUG(INFO, "Logging %s messages set to %s '%s'", 
+			(cause == FD_MSG_LOG_DROPPED) ? "DROPPED" :
+				(cause == FD_MSG_LOG_RECEIVED) ? "RECEIVED" :
+					(cause == FD_MSG_LOG_SENT) ? "SENT" :
+						"???",
+			(method == FD_MSG_LOGTO_FILE) ? "file" :
+				(method == FD_MSG_LOGTO_DIR) ? "directory" :
+					"???",
+			arg);
+	}
+	
+	CHECK_POSIX( pthread_mutex_unlock(&ml_conf.lock) );
+	
+	/* Done */
+	return 0;
+}
+
+/* Do not log anything within this one, since log lock is held */
+static void fd_cleanup_mutex_silent( void * mutex )
+{
+	(void)pthread_mutex_unlock((pthread_mutex_t *)mutex);
+}
+
+/* Really log the message */
+void fd_msg_log( enum fd_msg_log_cause cause, struct msg * msg, const char * prefix_format, ... )
+{
+	va_list ap;
+	enum fd_msg_log_method 	meth;
+	const char * 		metharg;
+	FILE * fstr;
+	
+	TRACE_ENTRY("%d %p %p", cause, msg, prefix_format);
+	CHECK_PARAMS_DO( (cause >= 0) && (cause <= FD_MSG_LOG_MAX),
+	{
+		TRACE_DEBUG(INFO, "Invalid cause received (%d)! Message was:", cause);
+		fd_msg_dump_walk(INFO, msg);
+	} );
+	
+	/* First retrieve the config for this message */
+	CHECK_POSIX_DO( pthread_mutex_lock(&ml_conf.lock), );
+	if (!ml_conf.init) {
+		ml_conf_init();
+	}
+	meth    = ml_conf.causes[cause].meth;
+	metharg = ml_conf.causes[cause].metharg;
+	CHECK_POSIX_DO( pthread_mutex_unlock(&ml_conf.lock), );
+	
+	/* Okay, now we will create the file descriptor */
+	switch (meth) {
+		case FD_MSG_LOGTO_DEBUGONLY:
+			fstr = fd_g_debug_fstr;
+			break;
+			
+		case FD_MSG_LOGTO_FILE:
+			TODO("Log to arg file");
+			break;
+		case FD_MSG_LOGTO_DIR:
+			TODO("Log to arg directory in a new file");
+			break;
+	}
+	
+	/* Then dump the prefix message to this stream */
+	(void)pthread_mutex_lock(&fd_log_lock);
+	pthread_cleanup_push(fd_cleanup_mutex_silent, &fd_log_lock);
+	va_start(ap, prefix_format);
+	vfprintf( fstr, prefix_format, ap);
+	va_end(ap);
+	fflush(fstr);
+	pthread_cleanup_pop(0);
+	(void)pthread_mutex_unlock(&fd_log_lock);
+	fd_log_debug_fstr(fstr, "\n\n");
+	
+	/* And now the message itself */
+	fd_msg_dump_fstr(msg, fstr);
+	
+	/* And finally close the stream if needed */
+	TODO("close?");
+}
+
"Welcome to our mercurial repository"