changeset 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
files include/freeDiameter/libfdproto.h libfdcore/dict_base_proto.c libfdproto/dictionary.c libfdproto/fdproto-internal.h libfdproto/init.c libfdproto/log.c libfdproto/messages.c
diffstat 7 files changed, 253 insertions(+), 71 deletions(-) [+]
line wrap: on
line diff
--- a/include/freeDiameter/libfdproto.h	Wed Jan 19 14:35:14 2011 +0900
+++ b/include/freeDiameter/libfdproto.h	Wed Jan 19 17:08:21 2011 +0900
@@ -94,9 +94,11 @@
 
 
 /*
- * FUNCTION:	fd_log_debug
+ * FUNCTION:	fd_log_debug_fstr
+ * MACRO:	fd_log_debug
  *
  * PARAMETERS:
+ *  fstr	: Stream where the text will be sent (default: stdout) 
  *  format 	: Same format string as in the printf function
  *  ...		: Same list as printf
  *
@@ -111,7 +113,9 @@
  * RETURN VALUE:
  *  None.
  */
-void fd_log_debug ( const char * format, ... );
+void fd_log_debug_fstr ( FILE * fstr, const char * format, ... );
+#define fd_log_debug(format,args...) fd_log_debug_fstr(NULL, format, ## args)
+
 extern pthread_mutex_t	fd_log_lock;
 extern char * fd_debug_one_function;
 extern char * fd_debug_one_file;
@@ -1009,7 +1013,7 @@
 	char 			*type_name;	/* The name of this type */
 	dict_avpdata_interpret	 type_interpret;/* cb to convert the AVP value in more comprehensive format (or NULL) */
 	dict_avpdata_encode	 type_encode;	/* cb to convert formatted data into an AVP value (or NULL) */
-	void			(*type_dump)(union avp_value * val);	/* cb called by fd_msg_dump_one for this type of data (if != NULL), to dump the AVP value in debug */
+	void			(*type_dump)(union avp_value * val, FILE * fstr);	/* cb called by fd_msg_dump_one for this type of data (if != NULL), to dump the AVP value in fstr */
 };
 
 /* The criteria for searching a type object in the dictionary */
@@ -2032,6 +2036,36 @@
 void fd_msg_dump_walk ( int level, msg_or_avp *obj );
 void fd_msg_dump_one  ( int level, msg_or_avp *obj );
 
+/*
+ * FUNCTION:	fd_msg_log
+ *
+ * PARAMETERS:
+ *  cause	 : Context for calling this function. This allows the log facility to be configured precisely.
+ *  msg		 : The message to log.
+ *  prefix_format: Printf-style format message that is printed ahead of the message. Might be reason for drop or so.
+ *
+ * DESCRIPTION: 
+ *   This function is called when a Diameter message reaches some particular points in the fD framework.
+ * The actual effect is configurable: log in a separate file, dump in the debug log, etc.
+ *
+ * RETURN VALUE:
+ *   -
+ */
+enum fd_msg_log_cause {
+	FD_MSG_LOG_DROPPED = 0,  /* message has been dropped by the framework */ 
+	FD_MSG_LOG_RECEIVED,     /* message received from the network */ 
+	FD_MSG_LOG_SENT          /* message sent to another peer */ 
+};
+#define FD_MSG_LOG_MAX FD_MSG_LOG_SENT
+void fd_msg_log( enum fd_msg_log_cause cause, struct msg * msg, const char * prefix_format, ... );
+
+/* configure the msg_log facility */
+enum fd_msg_log_method {
+	FD_MSG_LOGTO_DEBUGONLY = 0, /* Simply log the message with other debug information, at the INFO level. This is default */
+	FD_MSG_LOGTO_FILE,    /* Messages are dumped in a single file, defined in arg */
+	FD_MSG_LOGTO_DIR    /* Messages are dumped in different files within one directory defined in arg. */
+};
+int fd_msg_log_config(enum fd_msg_log_cause cause, enum fd_msg_log_method method, const char * arg);
 
 /*********************************************/
 /*   Message metadata management functions   */
--- a/libfdcore/dict_base_proto.c	Wed Jan 19 14:35:14 2011 +0900
+++ b/libfdcore/dict_base_proto.c	Wed Jan 19 17:08:21 2011 +0900
@@ -144,7 +144,7 @@
 }
 
 /* Dump the content of an Address AVP */
-static void Address_dump(union avp_value * avp_value)
+static void Address_dump(union avp_value * avp_value, FILE * fstr)
 {
 	union {
 		sSA	sa;
@@ -158,7 +158,7 @@
 	
 	/* The first two octets represent the address family, http://www.iana.org/assignments/address-family-numbers/ */
 	if (avp_value->os.len < 2) {
-		fd_log_debug("[invalid length: %d]", avp_value->os.len);
+		fd_log_debug_fstr(fstr, "[invalid length: %d]", avp_value->os.len);
 		return;
 	}
 	
@@ -169,7 +169,7 @@
 			/* IP */
 			s.sa.sa_family = AF_INET;
 			if (avp_value->os.len != 6) {
-				fd_log_debug("[invalid IP length: %d]", avp_value->os.len);
+				fd_log_debug_fstr(fstr, "[invalid IP length: %d]", avp_value->os.len);
 				return;
 			}
 			memcpy(&s.sin.sin_addr.s_addr, avp_value->os.data + 2, 4);
@@ -178,25 +178,33 @@
 			/* IP6 */
 			s.sa.sa_family = AF_INET6;
 			if (avp_value->os.len != 18) {
-				fd_log_debug("[invalid IP6 length: %d]", avp_value->os.len);
+				fd_log_debug_fstr(fstr, "[invalid IP6 length: %d]", avp_value->os.len);
 				return;
 			}
 			memcpy(&s.sin6.sin6_addr.s6_addr, avp_value->os.data + 2, 16);
 			break;
 		default:
-			fd_log_debug("[unsupported family: 0x%hx]", fam);
+			fd_log_debug_fstr(fstr, "[unsupported family: 0x%hx]", fam);
 			return;
 	}
-
-	sSA_DUMP_NODE(&s.sa, NI_NUMERICHOST);
+	
+	{
+		char addrbuf[INET6_ADDRSTRLEN];
+		int rc = getnameinfo(&s.sa, sSAlen(&s.sa), addrbuf, INET6_ADDRSTRLEN, NULL, 0, NI_NUMERICHOST);
+		if (rc)
+			fd_log_debug_fstr(fstr, "%s", (char *)gai_strerror(rc));
+		else
+			fd_log_debug_fstr(fstr, "%s", addrbuf);
+		
+	}
 }
 
-static void UTF8String_dump(union avp_value * avp_value)
+static void UTF8String_dump(union avp_value * avp_value, FILE * fstr)
 {
 	size_t len = avp_value->os.len;
 	if (len > 42)
 		len = 42; /* avoid very long strings */
-	fd_log_debug("%.*s", len, avp_value->os.data);
+	fd_log_debug_fstr(fstr, "%.*s", len, avp_value->os.data);
 }
 
 
--- a/libfdproto/dictionary.c	Wed Jan 19 14:35:14 2011 +0900
+++ b/libfdproto/dictionary.c	Wed Jan 19 17:08:21 2011 +0900
@@ -1303,50 +1303,50 @@
 /**************************** Dump AVP values ********************************/
 
 /* Default dump functions */
-static void dump_val_os(union avp_value * value)
+static void dump_val_os(union avp_value * value, FILE * fstr)
 {
 	int i;
 	for (i = 0; i < value->os.len; i++) {
 		if (i == 24) { /* Dump only up to 24 bytes of the buffer */
-			fd_log_debug("[...] (len=%zd)", value->os.len);
+			fd_log_debug_fstr(fstr, "[...] (len=%zd)", value->os.len);
 			break;
 		}
-		fd_log_debug("%02.2X ", value->os.data[i]);
+		fd_log_debug_fstr(fstr, "%02.2X ", value->os.data[i]);
 	}
 }
 
-static void dump_val_i32(union avp_value * value)
+static void dump_val_i32(union avp_value * value, FILE * fstr)
 {
-	fd_log_debug("%i (0x%x)", value->i32, value->i32);
+	fd_log_debug_fstr(fstr, "%i (0x%x)", value->i32, value->i32);
 }
 
-static void dump_val_i64(union avp_value * value)
+static void dump_val_i64(union avp_value * value, FILE * fstr)
 {
-	fd_log_debug("%lli (0x%llx)", value->i64, value->i64);
+	fd_log_debug_fstr(fstr, "%lli (0x%llx)", value->i64, value->i64);
 }
 
-static void dump_val_u32(union avp_value * value)
+static void dump_val_u32(union avp_value * value, FILE * fstr)
 {
-	fd_log_debug("%u (0x%x)", value->u32, value->u32);
+	fd_log_debug_fstr(fstr, "%u (0x%x)", value->u32, value->u32);
 }
 
-static void dump_val_u64(union avp_value * value)
+static void dump_val_u64(union avp_value * value, FILE * fstr)
 {
-	fd_log_debug("%llu (0x%llx)", value->u64, value->u64);
+	fd_log_debug_fstr(fstr, "%llu (0x%llx)", value->u64, value->u64);
 }
 
-static void dump_val_f32(union avp_value * value)
+static void dump_val_f32(union avp_value * value, FILE * fstr)
 {
-	fd_log_debug("%f", value->f32);
+	fd_log_debug_fstr(fstr, "%f", value->f32);
 }
 
-static void dump_val_f64(union avp_value * value)
+static void dump_val_f64(union avp_value * value, FILE * fstr)
 {
-	fd_log_debug("%g", value->f64);
+	fd_log_debug_fstr(fstr, "%g", value->f64);
 }
 
 /* Get the dump function for basic dict_avp_basetype */
-static void (*get_default_dump_val_cb(enum dict_avp_basetype datatype))(union avp_value *)
+static void (*get_default_dump_val_cb(enum dict_avp_basetype datatype))(union avp_value *, FILE *)
 {
 	switch (datatype) {
 		case AVP_TYPE_OCTETSTRING:
@@ -1381,34 +1381,34 @@
 #define INOBJHDRVAL 	indent<0 ? 1 : indent, indent<0 ? "-" : "|"
 
 /* Formater for the AVP value dump line */
-static void dump_avp_val(union avp_value *avp_value, void (*dump_val_cb)(union avp_value *avp_value), enum dict_avp_basetype datatype, char * type_name, char * const_name, int indent)
+static void dump_avp_val(union avp_value *avp_value, void (*dump_val_cb)(union avp_value *, FILE *), enum dict_avp_basetype datatype, char * type_name, char * const_name, int indent, FILE * fstr)
 {
 	/* Header for all AVP values dumps: */
-	fd_log_debug(INOBJHDR "value ", INOBJHDRVAL);
+	fd_log_debug_fstr(fstr, INOBJHDR "value ", INOBJHDRVAL);
 	
 	/* If the type is provided, write it */
 	if (type_name)
-		fd_log_debug("t: '%s' ", type_name);
+		fd_log_debug_fstr(fstr, "t: '%s' ", type_name);
 	
 	/* Always give the base datatype anyway */
-	fd_log_debug("(%s) ", type_base_name[datatype]);
+	fd_log_debug_fstr(fstr, "(%s) ", type_base_name[datatype]);
 	
 	/* Now, the value */
-	fd_log_debug("v: ");
+	fd_log_debug_fstr(fstr, "v: ");
 	if (const_name)
-		fd_log_debug("'%s' (", const_name);
-	(*dump_val_cb)(avp_value);
+		fd_log_debug_fstr(fstr, "'%s' (", const_name);
+	(*dump_val_cb)(avp_value, fstr);
 	if (const_name)
-		fd_log_debug(")");
+		fd_log_debug_fstr(fstr, ")");
 	
 	/* Done! */
-	fd_log_debug("\n");
+	fd_log_debug_fstr(fstr, "\n");
 }
 
 /* Dump the value of an AVP of known type */
-void fd_dict_dump_avp_value(union avp_value *avp_value, struct dict_object * model, int indent)
+void fd_dict_dump_avp_value(union avp_value *avp_value, struct dict_object * model, int indent, FILE * fstr)
 {
-	void (*dump_val_cb)(union avp_value *avp_value);
+	void (*dump_val_cb)(union avp_value *avp_value, FILE * fstr);
 	struct dict_object * type = NULL;
 	char * type_name = NULL;
 	char * const_name = NULL;
@@ -1443,7 +1443,7 @@
 	}
 	
 	/* And finally, dump the value */
-	dump_avp_val(avp_value, dump_val_cb, model->data.avp.avp_basetype, type_name, const_name, indent);
+	dump_avp_val(avp_value, dump_val_cb, model->data.avp.avp_basetype, type_name, const_name, indent, fstr);
 }
 
 /*******************************************************************************************************/
--- a/libfdproto/fdproto-internal.h	Wed Jan 19 14:35:14 2011 +0900
+++ b/libfdproto/fdproto-internal.h	Wed Jan 19 17:08:21 2011 +0900
@@ -47,12 +47,15 @@
 int fd_sess_init(void);
 void fd_sess_fini(void);
 
+/* Where debug messages are sent */
+FILE * fd_g_debug_fstr;
+
 /* Iterator on the rules of a parent object */
 int fd_dict_iterate_rules ( struct dict_object *parent, void * data, int (*cb)(void *, struct dict_rule_data *) );
 
 /* Dispatch / messages / dictionary API */
 int fd_dict_disp_cb(enum dict_object_type type, struct dict_object *obj, struct fd_list ** cb_list);
-void fd_dict_dump_avp_value(union avp_value *avp_value, struct dict_object * model, int indent);
+void fd_dict_dump_avp_value(union avp_value *avp_value, struct dict_object * model, int indent, FILE * fstr);
 int fd_disp_call_cb_int( struct fd_list * cb_list, struct msg ** msg, struct avp *avp, struct session *sess, enum disp_action *action, 
 			struct dict_object * obj_app, struct dict_object * obj_cmd, struct dict_object * obj_avp, struct dict_object * obj_enu);
 extern pthread_rwlock_t fd_disp_lock;
--- a/libfdproto/init.c	Wed Jan 19 14:35:14 2011 +0900
+++ b/libfdproto/init.c	Wed Jan 19 17:08:21 2011 +0900
@@ -50,6 +50,9 @@
 		return ret;
 	}
 	
+	/* Set the debug stream */
+	fd_g_debug_fstr = stdout;
+	
 	/* Initialize the modules that need it */
 	fd_msg_eteid_init();
 	CHECK_FCT( fd_sess_init() );
--- a/libfdproto/log.c	Wed Jan 19 14:35:14 2011 +0900
+++ b/libfdproto/log.c	Wed Jan 19 17:08:21 2011 +0900
@@ -54,9 +54,8 @@
 	(void)pthread_mutex_unlock((pthread_mutex_t *)mutex);
 }
 
-
 /* Log a debug message */
-void fd_log_debug ( const char * format, ... )
+void fd_log_debug_fstr ( FILE * fstr, const char * format, ... )
 {
 	va_list ap;
 	
@@ -65,9 +64,9 @@
 	pthread_cleanup_push(fd_cleanup_mutex_silent, &fd_log_lock);
 	
 	va_start(ap, format);
-	vfprintf( stdout, format, ap);
+	vfprintf( fstr ?: stdout, format, ap);
 	va_end(ap);
-	fflush(stdout);
+	fflush(fstr ?: stdout);
 
 	pthread_cleanup_pop(0);
 	
--- 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"