# HG changeset patch
# User Sebastien Decugis <sdecugis@freediameter.net>
# Date 1367307477 -28800
# Node ID 74bba7975864680628c9a24ca34fab811bdccfb7
# Parent  544fa1be79a9a079ed0b812e09a9c4f739c4dbdf
Cleanup the timing data and fd_msg_log feature that will be replaced by the new hooks mechanism. Kept the calls to fd_msg_log in comments to find the locations easily. WORK IN PROGRESS.

diff -r 544fa1be79a9 -r 74bba7975864 doc/dbg_interactive.py.sample
--- a/doc/dbg_interactive.py.sample	Tue Apr 30 12:09:32 2013 +0800
+++ b/doc/dbg_interactive.py.sample	Tue Apr 30 15:37:57 2013 +0800
@@ -363,7 +363,6 @@
 # Create empt (as for avps, pass None or a dictionary object as 1st param, and flags as optional 2nd param)y
 a_msg = msg()
 a_msg.dump()
-a_msg.log(FD_MSG_LOG_DROPPED, "Check libfdproto for more details. Configure with fd_msg_log_config.")
 del a_msg
 
 # It is also possible to pass MSGFL_* flags in second parameter (ALLOC_ETEID is default)
diff -r 544fa1be79a9 -r 74bba7975864 extensions/dbg_interactive/messages.i
--- a/extensions/dbg_interactive/messages.i	Tue Apr 30 12:09:32 2013 +0800
+++ b/extensions/dbg_interactive/messages.i	Tue Apr 30 15:37:57 2013 +0800
@@ -296,11 +296,6 @@
 			fd_msg_dump_one(0, $self);
 	}
 	
-	/* Log to file (depending on config)  */
-	void log ( enum fd_msg_log_cause cause, char * message ) {
-		fd_msg_log( cause, $self, message );
-	}
-	
 	/* Model */
 	struct dict_object * model() {
 		struct dict_object * m = NULL;
diff -r 544fa1be79a9 -r 74bba7975864 freeDiameterd/main.c
--- a/freeDiameterd/main.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/freeDiameterd/main.c	Tue Apr 30 15:37:57 2013 +0800
@@ -48,7 +48,6 @@
 
 static char *conffile = NULL;
 static int gnutls_debug = 0;
-static int fd_msg_log_enabled = 0; /* all logs disabled by default, this field is a bitfield of enabled FD_MSG_LOG_* */
 
 /* gnutls debug */
 static void fd_gnutls_debug(int level, const char * str) {
@@ -87,25 +86,6 @@
 		TRACE_DEBUG(INFO, "Enabled GNUTLS debug at level %d", gnutls_debug);
 	}
 	
-	/* set messages logging */
-	if (fd_msg_log_enabled) {
-		if (fd_msg_log_enabled & (1 << FD_MSG_LOG_DROPPED)) {
-			CHECK_FCT( fd_msg_log_config(FD_MSG_LOG_DROPPED, FD_MSG_LOGTO_DEBUGONLY, NULL) );
-		}
-		if (fd_msg_log_enabled & (1 << FD_MSG_LOG_RECEIVED)) {
-			CHECK_FCT( fd_msg_log_config(FD_MSG_LOG_RECEIVED, FD_MSG_LOGTO_DEBUGONLY, NULL) );
-		}
-		if (fd_msg_log_enabled & (1 << FD_MSG_LOG_SENT)) {
-			CHECK_FCT( fd_msg_log_config(FD_MSG_LOG_SENT, FD_MSG_LOGTO_DEBUGONLY, NULL) );
-		}
-		if (fd_msg_log_enabled & (1 << FD_MSG_LOG_NODELIVER)) {
-			CHECK_FCT( fd_msg_log_config(FD_MSG_LOG_NODELIVER, FD_MSG_LOGTO_DEBUGONLY, NULL) );
-		}
-		if (fd_msg_log_enabled & (1 << FD_MSG_LOG_TIMING)) {
-			CHECK_FCT( fd_msg_log_config(FD_MSG_LOG_TIMING, FD_MSG_LOGTO_DEBUGONLY, NULL) );
-		}
-	}
-		
 	/* Allow SIGINT and SIGTERM from this point to terminate the application */
 	CHECK_POSIX( pthread_create(&signals_thr, NULL, catch_signals, NULL) );
 	
@@ -168,9 +148,7 @@
 	printf( "  -h, --help             Print help and exit\n"
   		"  -V, --version          Print version and exit\n"
   		"  -c, --config=filename  Read configuration from this file instead of the \n"
-		"                           default location (" DEFAULT_CONF_PATH "/" FD_DEFAULT_CONF_FILENAME ").\n"
-		"  -M, --enable_msg_log=( DROPPED | RECEIVED | SENT | NODELIVER | TIMING )\n"
-		"                         Enable logging of these messages in the output.\n");
+		"                           default location (" DEFAULT_CONF_PATH "/" FD_DEFAULT_CONF_FILENAME ").\n");
  	printf( "\nDebug:\n"
   		"  These options are mostly useful for developers\n"
   		"  -l, --dbglocale        Set the locale for error messages\n"
@@ -196,7 +174,6 @@
 		{ "dbg_func",	required_argument, 	NULL, 'f' },
 		{ "dbg_file",	required_argument, 	NULL, 'F' },
 		{ "dbg_gnutls",	required_argument, 	NULL, 'g' },
-		{ "enable_msg_log",	optional_argument, 	NULL, 'M' },
 		{ NULL,		0, 			NULL, 0 }
 	};
 	
@@ -231,30 +208,6 @@
 				}
 				break;
 				
-			case 'M':	/* disable logging of these messages */
-				if (optarg) {
-					if (!strcmp(optarg, "DROPPED")) {
-						fd_msg_log_enabled |= 1 << FD_MSG_LOG_DROPPED;
-					} else
-					if (!strcmp(optarg, "RECEIVED")) {
-						fd_msg_log_enabled |= 1 << FD_MSG_LOG_RECEIVED;
-					} else
-					if (!strcmp(optarg, "SENT")) {
-						fd_msg_log_enabled |= 1 << FD_MSG_LOG_SENT;
-					} else
-					if (!strcmp(optarg, "NODELIVER")) {
-						fd_msg_log_enabled |= 1 << FD_MSG_LOG_NODELIVER;
-					} else
-					if (!strcmp(optarg, "TIMING")) {
-						fd_msg_log_enabled |= 1 << FD_MSG_LOG_TIMING;
-					} else {
-						main_help();
-						exit(0);
-					}
-				} else {
-					fd_msg_log_enabled = -1; /* all logs enabled */
-				}
-
 			case 'd':	/* Increase verbosity of debug messages.  */
 				fd_g_debug_lvl++;
 				break;
diff -r 544fa1be79a9 -r 74bba7975864 include/freeDiameter/libfdproto.h
--- a/include/freeDiameter/libfdproto.h	Tue Apr 30 12:09:32 2013 +0800
+++ b/include/freeDiameter/libfdproto.h	Tue Apr 30 15:37:57 2013 +0800
@@ -2339,43 +2339,22 @@
  */
 void fd_msg_dump_walk ( int level, msg_or_avp *obj );
 void fd_msg_dump_one  ( int level, msg_or_avp *obj );
-/* Dump full message to log */
-void fd_msg_dump_full ( int level, struct dictionary *dict, const char *prefix, msg_or_avp *obj );
-
-/*
- * FUNCTION:	fd_msg_log
+
+/* Helper functions to get a dump of an object in the logs. Several formats are available.
+ *  buf   : a buffer that can be reallocated if needed. *buf==NULL is also accepted for first allocation
+ *  buflen: the length of the buffer buf.
+ *  dict  : optional, the dictionary to use for resolving objects, if force_parsing != 0
+ *  obj   : the message or AVP to dump.
  *
- * 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:
- *   -
+ * After use, the buf pointer should be freed.
  */
-enum fd_msg_log_cause {
-	FD_MSG_LOG_DROPPED = 1,  /* 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 */ 
-	FD_MSG_LOG_NODELIVER,    /* message could not be delivered to any peer */
-	FD_MSG_LOG_TIMING	 /* profiling messages */
-};
-#define FD_MSG_LOG_MAX FD_MSG_LOG_TIMING
-void fd_msg_log( enum fd_msg_log_cause cause, struct msg * msg, const char * prefix_format, ... ) _ATTRIBUTE_PRINTFLIKE_(3,4);
-
-/* configure the msg_log facility */
-enum fd_msg_log_method {
-	FD_MSG_LOGTO_NONE = 0, /* The message is not dumped. This is the default. */
-	FD_MSG_LOGTO_DEBUGONLY, /* Simply log the message with other debug information, at the INFO level. */
-	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);
-void fd_msg_log_init(struct dictionary *dict);
+/* one-line dump with only short information */
+void fd_msg_dump_summary( char ** buf, size_t buflen, struct dictionary *dict, msg_or_avp *obj, int force_parsing);
+/* one-line dump with all the contents of the message */
+void fd_msg_dump_full( char ** buf, size_t buflen, struct dictionary *dict, msg_or_avp *obj, int force_parsing);
+/* multi-line human-readable dump similar to wireshark output */
+void fd_msg_dump_treeview( char ** buf, size_t buflen, struct dictionary *dict, msg_or_avp *obj, int force_parsing);
+
 
 /*********************************************/
 /*   Message metadata management functions   */
@@ -2529,28 +2508,6 @@
 int fd_msg_source_get( struct msg * msg, DiamId_t *diamid, size_t * diamidlen );
 
 /*
- * FUNCTION:	fd_msg_ts_*
- *
- * PARAMETERS:
- *  msg		: A msg object.
- *  ts		: A struct timespec pointer, indexed on CLOCK_REALTIME
- *
- * DESCRIPTION: 
- *   Associate or retrieve timestamps meaningful for the message.
- *  A timestamp with a value of { 0, 0 } means: not set.
- *
- * RETURN VALUE:
- *  0      	: Operation complete.
- *  !0      	: an error occurred.
- */
-/* when msg was received from network */
-int fd_msg_ts_set_recv( struct msg * msg, struct timespec * ts );
-int fd_msg_ts_get_recv( struct msg * msg, struct timespec * ts );
-int fd_msg_ts_set_sent( struct msg * msg, struct timespec * ts );
-int fd_msg_ts_get_sent( struct msg * msg, struct timespec * ts );
-
-
-/*
  * FUNCTION:	fd_msg_eteid_get
  *
  * PARAMETERS:
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/cnxctx.c
--- a/libfdcore/cnxctx.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/cnxctx.c	Tue Apr 30 15:37:57 2013 +0800
@@ -643,8 +643,6 @@
 		fd_cnx_markerror(conn);
 	}
 	
-	CHECK_SYS_DO( clock_gettime(CLOCK_REALTIME, &conn->cc_tls_para.recvon), /* continue */ );
-	
 	return ret;
 }
 
@@ -700,7 +698,6 @@
 		size_t  length;
 		ssize_t ret = 0;
 		size_t	received = 0;
-		struct timespec recv_on;
 
 		do {
 			ret = fd_cnx_s_recv(conn, &header[received], sizeof(header) - received);
@@ -738,10 +735,6 @@
 			received += ret;
 		}
 		
-		/* Piggy-tail the timestamp of reception */
-		CHECK_SYS_DO( clock_gettime(CLOCK_REALTIME, &recv_on), /* continue */ );
-		memcpy(newmsg + length, &recv_on, sizeof(struct timespec));
-		
 		/* We have received a complete message, pass it to the daemon */
 		CHECK_FCT_DO( fd_event_send( fd_cnx_target_queue(conn), FDEVP_CNX_MSG_RECV, length, newmsg), /* continue or destroy everything? */);
 		
@@ -929,13 +922,10 @@
 /* The function that receives TLS data and re-builds a Diameter message -- it exits only on error or cancelation */
 int fd_tls_rcvthr_core(struct cnxctx * conn, gnutls_session_t session)
 {
-	struct timespec * rcv_on = &conn->cc_tls_para.recvon;
-	
 #ifndef DISABLE_SCTP
 	void * ptr = gnutls_transport_get_ptr(session);
 	if (ptr != conn) {
 		struct sctps_ctx * ctx = (struct sctps_ctx *) ptr;
-		rcv_on = &ctx->recvon;
 	}
 #endif /* DISABLE_SCTP */
 	
@@ -984,9 +974,6 @@
 			received += ret;
 		}
 		
-		/* The timestamp of the last TLS chunk received for this rebuilt message lives close to the session pointer, we piggyback it */
-		memcpy(newmsg + length, rcv_on, sizeof(struct timespec));
-		
 		/* We have received a complete message, pass it to the daemon */
 		CHECK_FCT_DO( ret = fd_event_send( fd_cnx_target_queue(conn), FDEVP_CNX_MSG_RECV, length, newmsg), 
 			{ 
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/core.c
--- a/libfdcore/core.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/core.c	Tue Apr 30 15:37:57 2013 +0800
@@ -208,9 +208,6 @@
 	fd_g_config = &g_conf;
 	CHECK_FCT( fd_conf_init() );
 	
-	/* Initialize the message logging facility */
-	fd_msg_log_init(fd_g_config->cnf_dict);
-
 	/* Add definitions of the base protocol */
 	CHECK_FCT( fd_dict_base_protocol(fd_g_config->cnf_dict) );
 	
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/messages.c
--- a/libfdcore/messages.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/messages.c	Tue Apr 30 15:37:57 2013 +0800
@@ -414,7 +414,7 @@
 		} while (0);
 		
 		/* Just discard */
-		fd_msg_log( FD_MSG_LOG_DROPPED, m, "Answer not compliant to dictionary's ABNF (%s)", pei.pei_errcode  );
+		//fd_msg_log( FD_MSG_LOG_DROPPED, m, "Answer not compliant to dictionary's ABNF (%s)", pei.pei_errcode  );
 		CHECK_FCT( fd_msg_free( m ) );
 		*msg = NULL;
 	}
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/p_ce.c
--- a/libfdcore/p_ce.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/p_ce.c	Tue Apr 30 15:37:57 2013 +0800
@@ -649,7 +649,7 @@
 	fd_cnx_destroy(*recv_cnx);
 	*recv_cnx = NULL;
 	if (*cer) {
-		fd_msg_log(FD_MSG_LOG_DROPPED, *cer, "An error occurred while rejecting a CER.");
+		//fd_msg_log(FD_MSG_LOG_DROPPED, *cer, "An error occurred while rejecting a CER.");
 		fd_msg_free(*cer);
 		*cer = NULL;
 	}
@@ -719,7 +719,7 @@
 	/* If the state is not WAITCEA, just discard the message */
 	if (req || ((st = fd_peer_getstate(peer)) != STATE_WAITCEA)) {
 		if (*msg) {
-			fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Received CER/CEA while in '%s' state.", STATE_STR(st));
+			//fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Received CER/CEA while in '%s' state.", STATE_STR(st));
 			CHECK_FCT_DO( fd_msg_free(*msg), /* continue */);
 			*msg = NULL;
 		}
@@ -986,7 +986,7 @@
 	
 cleanup:
 	if (msg) {
-		fd_msg_log(FD_MSG_LOG_DROPPED, msg, "An error occurred while processing a CER.");
+		//fd_msg_log(FD_MSG_LOG_DROPPED, msg, "An error occurred while processing a CER.");
 		fd_msg_free(msg);
 	}
 	fd_p_ce_clear_cnx(peer, NULL);
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/p_out.c
--- a/libfdcore/p_out.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/p_out.c	Tue Apr 30 15:37:57 2013 +0800
@@ -44,7 +44,6 @@
 	size_t sz;
 	int ret;
 	uint32_t bkp_hbh = 0;
-	struct timespec senton;
 	struct msg * cpy_for_logs_only;
 	
 	TRACE_ENTRY("%p %x %p %p %p", msg, flags, cnx, hbh, srl);
@@ -72,31 +71,8 @@
 		CHECK_FCT_DO( ret = fd_p_sr_store(srl, msg, &hdr->msg_hbhid, bkp_hbh), goto out );
 	}
 	
-	CHECK_SYS_DO( clock_gettime(CLOCK_REALTIME, &senton), /* ... */ );
-	CHECK_FCT_DO( fd_msg_ts_set_sent(cpy_for_logs_only, &senton), /* ... */ );
-	
 	/* Log the message */
-	fd_msg_log( FD_MSG_LOG_SENT, cpy_for_logs_only, "Sent to '%s'", fd_cnx_getid(cnx));
-	
-	{
-		struct timespec rcvon, delay;
-		
-		(void) fd_msg_ts_get_recv(cpy_for_logs_only, &rcvon);
-		if (rcvon.tv_sec != 0 || rcvon.tv_nsec != 0) {
-			TS_DIFFERENCE( &delay, &rcvon, &senton);
-			fd_msg_log( FD_MSG_LOG_TIMING, cpy_for_logs_only, "Forwarded in %ld.%6.6ld sec", (long)delay.tv_sec, delay.tv_nsec/1000);
-		} else { /* We log the answer time only for answers generated locally */
-			if (!msg_is_a_req) {
-				/* get the matching request */
-				struct msg * req;
-				struct timespec reqrcvon;
-				(void) fd_msg_answ_getq(cpy_for_logs_only, &req);
-				(void) fd_msg_ts_get_recv(req, &reqrcvon);
-				TS_DIFFERENCE( &delay, &reqrcvon, &senton);
-				fd_msg_log( FD_MSG_LOG_TIMING, cpy_for_logs_only, "Answered in %ld.%6.6ld sec", (long)delay.tv_sec, delay.tv_nsec/1000);
-			}
-		}
-	}
+	// fd_msg_log( FD_MSG_LOG_SENT, cpy_for_logs_only, "Sent to '%s'", fd_cnx_getid(cnx));
 	
 	/* Send the message */
 	CHECK_FCT_DO( ret = fd_cnx_send(cnx, buf, sz, flags), );
@@ -121,7 +97,7 @@
 	struct msg *msg = arg;
 	CHECK_FCT_DO(fd_fifo_post(fd_g_outgoing, &msg),
 		{
-			fd_msg_log( FD_MSG_LOG_DROPPED, msg, "An error occurred while attempting to requeue this message during cancellation of the sending function");
+			//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "An error occurred while attempting to requeue this message during cancellation of the sending function");
 			CHECK_FCT_DO(fd_msg_free(msg), /* What can we do more? */);
 		} );
 }
@@ -154,7 +130,7 @@
 		CHECK_FCT_DO( ret = do_send(&msg, 0, peer->p_cnxctx, &peer->p_hbh, &peer->p_sr),
 			{
 				if (msg) {
-					fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Internal error: Problem while sending (%s)", strerror(ret) );
+					//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Internal error: Problem while sending (%s)", strerror(ret) );
 					fd_msg_free(msg);
 				}
 			} );
@@ -206,7 +182,7 @@
 		CHECK_FCT_DO( ret = do_send(msg, flags, cnx, hbh, peer ? &peer->p_sr : NULL),
 			{
 				if (msg) {
-					fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Internal error: Problem while sending (%s)", strerror(ret) );
+					//fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Internal error: Problem while sending (%s)", strerror(ret) );
 					fd_msg_free(*msg);
 					*msg = NULL;
 				}
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/p_psm.c
--- a/libfdcore/p_psm.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/p_psm.c	Tue Apr 30 15:37:57 2013 +0800
@@ -240,7 +240,7 @@
 			
 			case FDEVP_CNX_INCOMING: {
 				struct cnx_incoming * evd = ev->data;
-				fd_msg_log( FD_MSG_LOG_DROPPED, evd->cer, "Message discarded while cleaning peer state machine queue." );
+				//fd_msg_log( FD_MSG_LOG_DROPPED, evd->cer, "Message discarded while cleaning peer state machine queue." );
 				CHECK_FCT_DO( fd_msg_free(evd->cer), /* continue */);
 				fd_cnx_destroy(evd->cnx);
 			}
@@ -488,10 +488,6 @@
 	if (event == FDEVP_CNX_MSG_RECV) {
 		struct msg * msg = NULL;
 		struct msg_hdr * hdr;
-		struct timespec rcvon;
-		
-		/* Retrieve the piggytailed timestamp */
-		memcpy(&rcvon, ev_data+ev_sz, sizeof(struct timespec));
 		
 		/* Parse the received buffer */
 		CHECK_FCT_DO( fd_msg_parse_buffer( (void *)&ev_data, ev_sz, &msg), 
@@ -502,18 +498,16 @@
 				goto psm_loop;
 			} );
 			
-		CHECK_FCT_DO( fd_msg_ts_set_recv(msg, &rcvon), /* ... */ );
-		
 		/* If the current state does not allow receiving messages, just drop it */
 		if (cur_state == STATE_CLOSED) {
 			/* In such case, just discard the message */
-			fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Purged from peer '%s''s queue (CLOSED state).", peer->p_hdr.info.pi_diamid );
+			//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Purged from peer '%s''s queue (CLOSED state).", peer->p_hdr.info.pi_diamid );
 			fd_msg_free(msg);
 			goto psm_loop;
 		}
 		
 		/* Log incoming message */
-		fd_msg_log( FD_MSG_LOG_RECEIVED, msg, "Received %zdb from '%s' (%s)", ev_sz, peer->p_hdr.info.pi_diamid, STATE_STR(cur_state) );
+		//fd_msg_log( FD_MSG_LOG_RECEIVED, msg, "Received %zdb from '%s' (%s)", ev_sz, peer->p_hdr.info.pi_diamid, STATE_STR(cur_state) );
 	
 		/* Extract the header */
 		CHECK_FCT_DO( fd_msg_hdr(msg, &hdr), goto psm_end );
@@ -524,7 +518,7 @@
 			/* Search matching request (same hbhid) */
 			CHECK_FCT_DO( fd_p_sr_fetch(&peer->p_sr, hdr->msg_hbhid, &req), goto psm_end );
 			if (req == NULL) {
-				fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Answer received with no corresponding sent request." );
+				//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Answer received with no corresponding sent request." );
 				fd_msg_free(msg);
 				goto psm_loop;
 			}
@@ -534,10 +528,7 @@
 			
 			/* Display the delay to receive the answer */
 			{
-				struct timespec reqsent, delay;
-				(void) fd_msg_ts_get_sent(req, &reqsent);
-				TS_DIFFERENCE( &delay, &reqsent, &rcvon );
-				fd_msg_log( FD_MSG_LOG_TIMING, msg, "Answer received in %ld.%6.6ld sec.", (long)delay.tv_sec, delay.tv_nsec / 1000 );
+				//fd_msg_log( FD_MSG_LOG_TIMING, msg, "Answer received in %ld.%6.6ld sec.", (long)delay.tv_sec, delay.tv_nsec / 1000 );
 			}
 		} else {
 			/* Mark the incoming request so that we know we have pending answers for this peer */
@@ -585,7 +576,7 @@
 				case STATE_CLOSED:
 				default:
 					/* In such case, just discard the message */
-					fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Received from peer '%s' while connection was not in state %s.", peer->p_hdr.info.pi_diamid, STATE_STR(cur_state) );
+					//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Received from peer '%s' while connection was not in state %s.", peer->p_hdr.info.pi_diamid, STATE_STR(cur_state) );
 					fd_msg_free(msg);
 			}
 			goto psm_loop;
@@ -602,7 +593,7 @@
 					CHECK_FCT_DO( ret = fd_out_send(&msg, NULL, peer, FD_CNX_ORDERED),  );
 					if (msg) {
 						/* Only if an error occurred & the message was not saved / dumped */
-						fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Internal error: Problem while sending (%s)", strerror(ret) );
+						//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Internal error: Problem while sending (%s)", strerror(ret) );
 						CHECK_FCT_DO( fd_msg_free(msg), goto psm_end);
 					}
 				} else {
@@ -651,7 +642,7 @@
 				
 				/* Cleanup the message if not done */
 				if (msg) {
-					fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Received un-handled non-routable command from peer '%s'.", peer->p_hdr.info.pi_diamid );
+					//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Received un-handled non-routable command from peer '%s'.", peer->p_hdr.info.pi_diamid );
 					CHECK_FCT_DO( fd_msg_free(msg), /* continue */);
 					msg = NULL;
 				}
@@ -659,7 +650,7 @@
 		
 		/* At this point the message must have been fully handled already */
 		if (msg) {
-			fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Internal error ('%s'): unhandled message.", peer->p_hdr.info.pi_diamid );
+			//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Internal error ('%s'): unhandled message.", peer->p_hdr.info.pi_diamid );
 			fd_msg_free(msg);
 		}
 		
@@ -745,7 +736,7 @@
 			params->cnx = NULL;
 		}
 		if (params->cer) {
-			fd_msg_log( FD_MSG_LOG_DROPPED, params->cer, "Internal error: this CER was not handled as expected." );
+			//fd_msg_log( FD_MSG_LOG_DROPPED, params->cer, "Internal error: this CER was not handled as expected." );
 			CHECK_FCT_DO( fd_msg_free(params->cer), );
 			params->cer = NULL;
 		}
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/p_sr.c
--- a/libfdcore/p_sr.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/p_sr.c	Tue Apr 30 15:37:57 2013 +0800
@@ -118,7 +118,7 @@
 	
 	/* If the callback did not dispose of the message, do it now */
 	if (ed->request) {
-		fd_msg_log(FD_MSG_LOG_DROPPED, ed->request, "Expiration period completed without an answer, and the expiry callback did not dispose of the message.");
+		//fd_msg_log(FD_MSG_LOG_DROPPED, ed->request, "Expiration period completed without an answer, and the expiry callback did not dispose of the message.");
 		CHECK_FCT_DO( fd_msg_free(ed->request), /* ignore */ );
 	}
 	
@@ -324,12 +324,12 @@
 			/* Requeue for sending to another peer */
 			CHECK_FCT_DO( ret = fd_fifo_post(fd_g_outgoing, &sr->req),
 				{
-					fd_msg_log( FD_MSG_LOG_DROPPED, sr->req, "Internal error: error while requeuing during failover: %s", strerror(ret) );
+					//fd_msg_log( FD_MSG_LOG_DROPPED, sr->req, "Internal error: error while requeuing during failover: %s", strerror(ret) );
 					CHECK_FCT_DO(fd_msg_free(sr->req), /* What can we do more? */)
 				});
 		} else {
 			/* Just free the request. */
-			fd_msg_log( FD_MSG_LOG_DROPPED, sr->req, "Sent & unanswered local message discarded during failover." );
+			//fd_msg_log( FD_MSG_LOG_DROPPED, sr->req, "Sent & unanswered local message discarded during failover." );
 			CHECK_FCT_DO(fd_msg_free(sr->req), /* Ignore */);
 		}
 		free(sr);
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/peers.c
--- a/libfdcore/peers.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/peers.c	Tue Apr 30 15:37:57 2013 +0800
@@ -244,7 +244,7 @@
 		CHECK_FCT_DO(fd_fifo_post(fd_g_outgoing, &m), 
 			{
 				/* fallback: destroy the message */
-				fd_msg_log(FD_MSG_LOG_DROPPED, m, "Internal error: unable to requeue this message during failover process");
+				//fd_msg_log(FD_MSG_LOG_DROPPED, m, "Internal error: unable to requeue this message during failover process");
 				CHECK_FCT_DO(fd_msg_free(m), /* What can we do more? */)
 			} );
 	}
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/queues.c
--- a/libfdcore/queues.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/queues.c	Tue Apr 30 15:37:57 2013 +0800
@@ -73,7 +73,7 @@
 		CHECK_FCT(ret);
 		
 		/* We got one! */
-		fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Message lost because framework is terminating." );
+		//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Message lost because framework is terminating." );
 		fd_msg_free(msg);
 	}
 	
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/routing_dispatch.c
--- a/libfdcore/routing_dispatch.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/routing_dispatch.c	Tue Apr 30 15:37:57 2013 +0800
@@ -392,7 +392,7 @@
 			CHECK_FCT( fd_peer_getbyid( id, idlen, 0, (void *)&peer ) );
 
 			if (!peer) {
-				fd_msg_log(FD_MSG_LOG_DROPPED, *pmsg, "Unable to send error '%s' to deleted peer '%s' in reply to this message.", error_code, id);
+				//fd_msg_log(FD_MSG_LOG_DROPPED, *pmsg, "Unable to send error '%s' to deleted peer '%s' in reply to this message.", error_code, id);
 				fd_msg_free(*pmsg);
 				*pmsg = NULL;
 				return 0;
@@ -449,7 +449,7 @@
 				CHECK_FCT( fd_fifo_post(fd_g_outgoing, &msgptr) );
 			}
 			if (msgptr) {	/* another error happen'd */
-				fd_msg_log( FD_MSG_LOG_DROPPED, msgptr,  "An unexpected error occurred while parsing the message (%s)", strerror(ret));
+				//fd_msg_log( FD_MSG_LOG_DROPPED, msgptr,  "An unexpected error occurred while parsing the message (%s)", strerror(ret));
 				CHECK_FCT_DO( fd_msg_free(msgptr), /* continue */);
 			}
 			/* We're done with this one */
@@ -510,7 +510,7 @@
 				}
 				
 				if (!is_req) {
-					fd_msg_log( FD_MSG_LOG_DROPPED, msgptr,  "Internal error: Answer received to locally issued request, but not handled by any handler.");
+					//fd_msg_log( FD_MSG_LOG_DROPPED, msgptr,  "Internal error: Answer received to locally issued request, but not handled by any handler.");
 					fd_msg_free(msgptr);
 					break;
 				}
@@ -755,7 +755,7 @@
 			TRACE_DEBUG(ANNOYING, "Calling next FWD callback on %p : %p", msgptr, rh->rt_fwd_cb);
 			CHECK_FCT_DO( ret = (*rh->rt_fwd_cb)(rh->cbdata, &msgptr),
 				{
-					fd_msg_log( FD_MSG_LOG_DROPPED, msgptr, "Internal error: a FWD routing callback returned an error (%s)", strerror(ret));
+					//fd_msg_log( FD_MSG_LOG_DROPPED, msgptr, "Internal error: a FWD routing callback returned an error (%s)", strerror(ret));
 					fd_msg_free(msgptr);
 					msgptr = NULL;
 				} );
@@ -814,7 +814,7 @@
 		/* Find the peer corresponding to this name */
 		CHECK_FCT( fd_peer_getbyid( qry_src, qry_src_len, 0, (void *) &peer ) );
 		if (fd_peer_getstate(peer) != STATE_OPEN) {
-			fd_msg_log( FD_MSG_LOG_DROPPED, msgptr, "Unable to forward answer to deleted / closed peer '%s'.", qry_src);
+			//fd_msg_log( FD_MSG_LOG_DROPPED, msgptr, "Unable to forward answer to deleted / closed peer '%s'.", qry_src);
 			fd_msg_free(msgptr);
 			return 0;
 		}
@@ -899,7 +899,7 @@
 			TRACE_DEBUG(ANNOYING, "Calling next OUT callback on %p : %p (prio %d)", msgptr, rh->rt_out_cb, rh->prio);
 			CHECK_FCT_DO( ret = (*rh->rt_out_cb)(rh->cbdata, msgptr, candidates),
 				{
-					fd_msg_log( FD_MSG_LOG_DROPPED, msgptr, "Internal error: an OUT routing callback returned an error (%s)", strerror(ret));
+					//fd_msg_log( FD_MSG_LOG_DROPPED, msgptr, "Internal error: an OUT routing callback returned an error (%s)", strerror(ret));
 					fd_msg_free(msgptr);
 					msgptr = NULL;
 					break;
@@ -947,7 +947,7 @@
 
 	/* If the message has not been sent, return an error */
 	if (msgptr) {
-		fd_msg_log( FD_MSG_LOG_NODELIVER, msgptr, "No suitable candidate to route the message to." );
+		//fd_msg_log( FD_MSG_LOG_NODELIVER, msgptr, "No suitable candidate to route the message to." );
 		return_error( &msgptr, "DIAMETER_UNABLE_TO_DELIVER", "No suitable candidate to route the message to", NULL);
 	}
 
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/sctp.c
--- a/libfdcore/sctp.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/sctp.c	Tue Apr 30 15:37:57 2013 +0800
@@ -1067,7 +1067,6 @@
 	size_t 			 bufsz = 0, datasize = 0;
 	size_t			 mempagesz = sysconf(_SC_PAGESIZE); /* We alloc buffer by memory pages for efficiency */
 	int 			 timedout = 0;
-	struct timespec 	 recv_on;
 	
 	TRACE_ENTRY("%p %p %p %p %p", conn, strid, buf, len, event);
 	CHECK_PARAMS( conn && buf && len && event );
@@ -1188,10 +1187,6 @@
 		return 0;
 	}
 	
-	/* Piggy-tail the timestamp of reception */
-	CHECK_SYS_DO( clock_gettime(CLOCK_REALTIME, &recv_on), /* continue */ );
-	memcpy(data + datasize, &recv_on, sizeof(struct timespec));
-		
 	/* From this point, we have received a message */
 	*event = FDEVP_CNX_MSG_RECV;
 	*buf = data;
diff -r 544fa1be79a9 -r 74bba7975864 libfdcore/server.c
--- a/libfdcore/server.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdcore/server.c	Tue Apr 30 15:37:57 2013 +0800
@@ -168,7 +168,7 @@
 	CHECK_FCT_DO( fd_msg_parse_buffer( &buf, bufsz, &msg ), /* Parsing failed */ goto cleanup );
 	
 	/* Log incoming message */
-	fd_msg_log( FD_MSG_LOG_RECEIVED, msg, "Received %zdb from new client '%s'", bufsz, fd_cnx_getid(c->conn) );
+	//fd_msg_log( FD_MSG_LOG_RECEIVED, msg, "Received %zdb from new client '%s'", bufsz, fd_cnx_getid(c->conn) );
 	
 	/* We expect a CER, it must parse with our dictionary and rules */
 	CHECK_FCT_DO( fd_msg_parse_rules( msg, fd_g_config->cnf_dict, NULL ), /* Parsing failed -- trace details ? */ goto cleanup );
@@ -194,7 +194,7 @@
 	
 	/* Cleanup the parsed message if any */
 	if (msg) {
-		fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Received invalid/unexpected message from connecting client '%s'", fd_cnx_getid(c->conn) );
+		//fd_msg_log( FD_MSG_LOG_DROPPED, msg, "Received invalid/unexpected message from connecting client '%s'", fd_cnx_getid(c->conn) );
 		CHECK_FCT_DO( fd_msg_free(msg), /* continue */);
 	}
 	
diff -r 544fa1be79a9 -r 74bba7975864 libfdproto/CMakeLists.txt
--- a/libfdproto/CMakeLists.txt	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdproto/CMakeLists.txt	Tue Apr 30 15:37:57 2013 +0800
@@ -12,7 +12,6 @@
 	lists.c
 	log.c
 	messages.c
-	msg_log.c
 	ostr.c
 	portability.c
 	rt_data.c
diff -r 544fa1be79a9 -r 74bba7975864 libfdproto/dispatch.c
--- a/libfdproto/dispatch.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdproto/dispatch.c	Tue Apr 30 15:37:57 2013 +0800
@@ -96,7 +96,7 @@
 		/* We have a match, the cb must be called. */
 		CHECK_FCT_DO( (r = (*hdl->cb)(msg, avp, sess, hdl->opaque, action)),
 			{
-				fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Internal error: a DISPATCH callback returned an error (%s)", strerror(r));
+				//fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Internal error: a DISPATCH callback returned an error (%s)", strerror(r));
 				fd_msg_free(*msg);
 				*msg = NULL;
 			}
diff -r 544fa1be79a9 -r 74bba7975864 libfdproto/messages.c
--- a/libfdproto/messages.c	Tue Apr 30 12:09:32 2013 +0800
+++ b/libfdproto/messages.c	Tue Apr 30 15:37:57 2013 +0800
@@ -128,8 +128,6 @@
 		}		 msg_cb;		/* Callback to be called when an answer is received, or timeout expires, if not NULL */
 	DiamId_t		 msg_src_id;		/* Diameter Id of the peer this message was received from. This string is malloc'd and must be freed */
 	size_t			 msg_src_id_len;	/* cached length of this string */
-	struct timespec		 msg_ts_rcv;		/* Timestamp when this message was received from the network */
-	struct timespec		 msg_ts_sent;		/* Timestamp when this message was sent to the network */
 	
 };
 
@@ -733,17 +731,6 @@
 		return 0;
 	}
 	
-	if ((msg->msg_ts_rcv.tv_sec != 0) || (msg->msg_ts_rcv.tv_nsec != 0)) {
-		tsoffset += strftime(buftime + tsoffset, sizeof(buftime) - tsoffset, "%D,%T", localtime_r( &msg->msg_ts_rcv.tv_sec , &tm ));
-		tsoffset += snprintf(buftime + tsoffset, sizeof(buftime) - tsoffset, ".%6.6ld", msg->msg_ts_rcv.tv_nsec / 1000);
-		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "Received: %s|", INOBJHDRVAL, buftime) );
-	}
-	if ((msg->msg_ts_sent.tv_sec != 0) || (msg->msg_ts_sent.tv_nsec != 0)) {
-		tsoffset += strftime(buftime + tsoffset, sizeof(buftime) - tsoffset, "%D,%T", localtime_r( &msg->msg_ts_sent.tv_sec , &tm ));
-		tsoffset += snprintf(buftime + tsoffset, sizeof(buftime) - tsoffset, ".%6.6ld", msg->msg_ts_sent.tv_nsec / 1000);
-		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "Sent    : %s|", INOBJHDRVAL, buftime) );
-	}
-	
 	if (!msg->msg_model) {
 		
 		CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(no model)|", INOBJHDRVAL) );
@@ -997,7 +984,8 @@
 }
 
 /* Dump full message */
-void fd_msg_dump_full ( int level, struct dictionary *dict, const char *prefix, msg_or_avp *obj )
+// TODO: need align with new prototype & behavior
+void fd_msg_dump_full_TODO ( int level, struct dictionary *dict, const char *prefix, msg_or_avp *obj )
 {
 	msg_or_avp * ref = obj;
 	char *outstr;
@@ -1363,54 +1351,6 @@
 	return 0;
 }
 
-int fd_msg_ts_set_recv( struct msg * msg, struct timespec * ts )
-{
-	TRACE_ENTRY("%p %p", msg, ts);
-	
-	/* Check we received valid parameters */
-	CHECK_PARAMS( CHECK_MSG(msg) );
-	CHECK_PARAMS( ts );
-	
-	memcpy(&msg->msg_ts_rcv, ts, sizeof(struct timespec));
-	return 0;
-}
-
-int fd_msg_ts_get_recv( struct msg * msg, struct timespec * ts )
-{
-	TRACE_ENTRY("%p %p", msg, ts);
-	
-	/* Check we received valid parameters */
-	CHECK_PARAMS( CHECK_MSG(msg) );
-	CHECK_PARAMS( ts );
-	
-	memcpy(ts, &msg->msg_ts_rcv, sizeof(struct timespec));
-	return 0;
-}
-
-int fd_msg_ts_set_sent( struct msg * msg, struct timespec * ts )
-{
-	TRACE_ENTRY("%p %p", msg, ts);
-	
-	/* Check we received valid parameters */
-	CHECK_PARAMS( CHECK_MSG(msg) );
-	CHECK_PARAMS( ts );
-	
-	memcpy(&msg->msg_ts_sent, ts, sizeof(struct timespec));
-	return 0;
-}
-
-int fd_msg_ts_get_sent( struct msg * msg, struct timespec * ts )
-{
-	TRACE_ENTRY("%p %p", msg, ts);
-	
-	/* Check we received valid parameters */
-	CHECK_PARAMS( CHECK_MSG(msg) );
-	CHECK_PARAMS( ts );
-	
-	memcpy(ts, &msg->msg_ts_sent, sizeof(struct timespec));
-	return 0;
-}
-
 /* Associate a session with a message, use only when the session was just created */
 int fd_msg_sess_set(struct msg * msg, struct session * session)
 {
@@ -2638,7 +2578,7 @@
 				*error_code = "DIAMETER_APPLICATION_UNSUPPORTED";
 			*action = DISP_ACT_ERROR;
 		} else {
-			fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Internal error: Received this answer to a local query with an unsupported application %d", (*msg)->msg_public.msg_appl);
+			//fd_msg_log( FD_MSG_LOG_DROPPED, *msg, "Internal error: Received this answer to a local query with an unsupported application %d", (*msg)->msg_public.msg_appl);
 			fd_msg_free(*msg);
 			*msg = NULL;
 		}
diff -r 544fa1be79a9 -r 74bba7975864 libfdproto/msg_log.c
--- a/libfdproto/msg_log.c	Tue Apr 30 12:09:32 2013 +0800
+++ /dev/null	Thu Jan 01 00:00:00 1970 +0000
@@ -1,206 +0,0 @@
-/*********************************************************************************************************
-* Software License Agreement (BSD License)                                                               *
-* Author: Sebastien Decugis <sdecugis@freediameter.net>							 *
-*													 *
-* Copyright (c) 2013, WIDE Project and NICT								 *
-* All rights reserved.											 *
-* 													 *
-* Redistribution and use of this software in source and binary forms, with or without modification, are  *
-* permitted provided that the following conditions are met:						 *
-* 													 *
-* * Redistributions of source code must retain the above 						 *
-*   copyright notice, this list of conditions and the 							 *
-*   following disclaimer.										 *
-*    													 *
-* * Redistributions in binary form must reproduce the above 						 *
-*   copyright notice, this list of conditions and the 							 *
-*   following disclaimer in the documentation and/or other						 *
-*   materials provided with the distribution.								 *
-* 													 *
-* * Neither the name of the WIDE Project or NICT nor the 						 *
-*   names of its contributors may be used to endorse or 						 *
-*   promote products derived from this software without 						 *
-*   specific prior written permission of WIDE Project and 						 *
-*   NICT.												 *
-* 													 *
-* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND ANY EXPRESS OR IMPLIED *
-* WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A *
-* PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE FOR *
-* ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT 	 *
-* LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS 	 *
-* INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR *
-* TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF   *
-* ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.								 *
-*********************************************************************************************************/
-
-/* messages logging facility */
-#include "fdproto-internal.h"
-#include <stdarg.h>
-
-/* Configuration of this module */
-static struct {
-	struct {
-		enum fd_msg_log_method 	meth;
-		const char * 		metharg;
-	} causes[FD_MSG_LOG_MAX + 1];
-	pthread_mutex_t lock;
-	int		init;
-	struct dictionary *dict;	
-} ml_conf = { .lock = PTHREAD_MUTEX_INITIALIZER, .init = 0 };
-
-
-/* Initialize the module, with a dictionary to use to better parse the messages */
-void fd_msg_log_init(struct dictionary *dict) 
-{
-	memset(&ml_conf.causes, 0, sizeof(ml_conf.causes));
-	ml_conf.init = 1;
-	ml_conf.dict = dict;
-}
-
-/* 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_NONE) && (method <= FD_MSG_LOGTO_DIR) );
-	CHECK_PARAMS( (method == FD_MSG_LOGTO_NONE) || (method == FD_MSG_LOGTO_DEBUGONLY) || (arg != NULL) );
-	
-	/* Lock the configuration */
-	CHECK_POSIX( pthread_mutex_lock(&ml_conf.lock) );
-	if (!ml_conf.init) {
-		ASSERT(0);
-	}
-	
-	/* 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" :
-					(cause == FD_MSG_LOG_NODELIVER) ? "NODELIVER" :
-					(cause == FD_MSG_LOG_TIMING) ? "TIMING" :
-						"???",
-			(method == FD_MSG_LOGTO_NONE) ? "none" :
-				(method == FD_MSG_LOGTO_DEBUGONLY) ? "debug" :
-				(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;
-	
-	char buftime[256];
-	size_t offset = 0;
-	struct timespec ts;
-	struct tm tm;
-	
-	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) {
-		ASSERT(0);
-	}
-	meth    = ml_conf.causes[cause].meth;
-	metharg = ml_conf.causes[cause].metharg;
-	CHECK_POSIX_DO( pthread_mutex_unlock(&ml_conf.lock), );
-	
-	/* Return now when loging is not requested */
-	if ((meth == FD_MSG_LOGTO_NONE) 
-	 || ((meth == FD_MSG_LOGTO_DEBUGONLY) && (fd_g_debug_lvl < INFO))) {
-		return;
-	}
-	
-	/* Get current time */
-	CHECK_SYS_DO( clock_gettime(CLOCK_REALTIME, &ts), /* continue */);
-	offset += strftime(buftime + offset, sizeof(buftime) - offset, "%D,%T", localtime_r( &ts.tv_sec , &tm ));
-	offset += snprintf(buftime + offset, sizeof(buftime) - offset, ".%6.6ld", ts.tv_nsec / 1000);
-	
-
-	/* 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");
-			TODO("Log a note to debug stream");
-			TRACE_DEBUG(INFO, "%s", metharg);
-			break;
-		case FD_MSG_LOGTO_DIR:
-			TODO("Log to arg directory in a new file");
-			TODO("Log a note to debug stream");
-			break;
-		default:
-			break;
-	}
-	
-	/* For file methods, let's parse the message so it looks better */
-	if (((meth != FD_MSG_LOGTO_DEBUGONLY) || (fd_g_debug_lvl > FULL)) && ml_conf.dict) {
-		CHECK_FCT_DO( fd_msg_parse_dict( msg, ml_conf.dict, NULL ), );
-	}
-	
-	/* Then dump the prefix message to this stream, & to debug stream */
-	(void)pthread_mutex_lock(&fd_log_lock);
-	pthread_cleanup_push(fd_cleanup_mutex_silent, &fd_log_lock);
-	fprintf( fstr, "\n");
-	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, " Logged: %s", buftime);
-	
-	/* And now the message itself */
-	if ((meth == FD_MSG_LOGTO_DEBUGONLY) && (fd_g_debug_lvl <= INFO)) {
-		/* dump only the header */
-		fd_msg_dump_fstr_one(msg, fstr);
-	} else {
-		/* dump the full content */
-		fd_msg_dump_fstr(msg, fstr);
-	}
-	
-	/* And finally close the stream if needed */
-	switch (meth) {
-		case FD_MSG_LOGTO_FILE:
-			TODO("close?");
-			break;
-		case FD_MSG_LOGTO_DIR:
-			TODO("close?");
-			break;
-		default:
-			break;
-	}
-}
-
diff -r 544fa1be79a9 -r 74bba7975864 tests/tests.h
--- a/tests/tests.h	Tue Apr 30 12:09:32 2013 +0800
+++ b/tests/tests.h	Tue Apr 30 15:37:57 2013 +0800
@@ -215,9 +215,6 @@
 	/* Initialize the config */
 	CHECK( 0, fd_conf_init() );
 
-	/* Initialize the message logging facility */
-	fd_msg_log_init(fd_g_config->cnf_dict);
-
 	/* Add definitions of the base protocol */
 	CHECK( 0, fd_dict_base_protocol(fd_g_config->cnf_dict) );