Index: extensions/CMakeLists.txt
===================================================================
--- extensions/CMakeLists.txt	(revision 1040)
+++ extensions/CMakeLists.txt	(revision 1103)
@@ -86,4 +86,5 @@
 
 FD_EXTENSION_SUBDIR(dbg_monitor "Outputs periodical status information"              OFF)
+FD_EXTENSION_SUBDIR(dbg_msg_timings "Show some timing information for messages"      OFF)
 FD_EXTENSION_SUBDIR(dbg_rt      "Routing extension for debugging the routing module" OFF)
 FD_EXTENSION_SUBDIR(test_app    "Testing application to send dummy message to another peer, like a Diameter 'ping'" OFF)
Index: extensions/app_radgw/rgw_clients.c
===================================================================
--- extensions/app_radgw/rgw_clients.c	(revision 1033)
+++ extensions/app_radgw/rgw_clients.c	(revision 1107)
@@ -921,6 +921,8 @@
 	/* Dump the entry in debug mode */
 	if (TRACE_BOOL(FULL + 1 )) {
+		char sa_buf[sSA_DUMP_STRLEN];
+		fd_sa_sdump_numeric(sa_buf, ip_port);
 		TRACE_DEBUG(FULL, "Adding %s:", (type == RGW_CLI_NAS) ? "NAS" : "PROXY"  );
-		TRACE_sSA(FD_LOG_DEBUG, FULL, 	 "\tIP : ", ip_port, NI_NUMERICHOST | NI_NUMERICSERV, "" );
+		TRACE_DEBUG(FULL, "\tIP : %s", sa_buf );
 		TRACE_BUFFER(FD_LOG_DEBUG, FULL, "\tKey: [", *key, keylen, "]" );
 	}
@@ -941,4 +943,5 @@
 	
 	if (ret == EEXIST) {
+		char sa_buf[sSA_DUMP_STRLEN];
 		/* Check if the key is the same, then skip or return an error */
 		if ((keylen == prev->key.len ) && ( ! memcmp(*key, prev->key.data, keylen) ) && (type == prev->type)) {
@@ -950,8 +953,10 @@
 		fd_log_error("ERROR: Conflicting RADIUS clients descriptions!");
 		TRACE_ERROR("Previous entry: %s", (prev->type == RGW_CLI_NAS) ? "NAS" : "PROXY");
-		TRACE_sSA(FD_LOG_ERROR, NONE, 	 "\tIP : ", prev->sa, NI_NUMERICHOST | NI_NUMERICSERV, "" );
+		fd_sa_sdump_numeric(sa_buf, prev->sa);
+		TRACE_ERROR("\tIP : %s", sa_buf);
 		TRACE_BUFFER(FD_LOG_ERROR, NONE, "\tKey: [", prev->key.data, prev->key.len, "]" );
 		TRACE_ERROR("Conflicting entry: %s", (type == RGW_CLI_NAS) ? "NAS" : "PROXY");
-		TRACE_sSA(FD_LOG_ERROR, NONE, 	 "\tIP : ", ip_port, NI_NUMERICHOST | NI_NUMERICSERV, "" );
+		fd_sa_sdump_numeric(sa_buf, ip_port);
+		TRACE_ERROR("\tIP : %s", sa_buf);
 		TRACE_BUFFER(FD_LOG_ERROR, NONE, "\tKey: [", *key, keylen, "]" );
 	}
@@ -969,7 +974,9 @@
 	
 	for (ref = senti->next; ref != senti; ref = ref->next) {
+		char sa_buf[sSA_DUMP_STRLEN];
 		client = (struct rgw_client *)ref;
 		/* TODO: use a fct param instead of hardcoded FD_LOG_DEBUG */
-		TRACE_sSA(FD_LOG_DEBUG, NONE, 	 "  - ", client->sa, NI_NUMERICHOST | NI_NUMERICSERV, (client->type == RGW_CLI_NAS) ? "" : " [PROXY]" );
+		TODO("Replace with appropriate code");
+/*		TRACE_sSA(FD_LOG_DEBUG, NONE, 	 "  - ", client->sa, NI_NUMERICHOST | NI_NUMERICSERV, (client->type == RGW_CLI_NAS) ? "" : " [PROXY]" ); */
 	}
 }
Index: extensions/app_radgw/rgw_servers.c
===================================================================
--- extensions/app_radgw/rgw_servers.c	(revision 1027)
+++ extensions/app_radgw/rgw_servers.c	(revision 1107)
@@ -111,4 +111,5 @@
 	while (1) {
 		struct sockaddr_storage from;
+		char sa_buf[sSA_DUMP_STRLEN];
 		socklen_t fromlen = sizeof(from);
 		int len;
@@ -133,15 +134,11 @@
 		}
 		
-		{
-			char __buf[1024];
-			sSA_DUMP_NODE_SERV(__buf, sizeof(__buf), &from, NI_NUMERICHOST | NI_NUMERICSERV );
-			TRACE_DEBUG(FULL, "Received %d bytes from %s", len, __buf);
-		}
+		fd_sa_sdump_numeric(sa_buf, (sSA*)&from);
+		TRACE_DEBUG(FULL, "Received %d bytes from %s", len, sa_buf);
 		
 		/* Search the associated client definition, if any */
 		CHECK_FCT_DO( rgw_clients_search((struct sockaddr *) &from, &nas_info),
 			{
-				TRACE_NOTICE("Discarding %d bytes received from unknown IP:", len);
-				TRACE_sSA(FD_LOG_NOTICE, INFO, " ", &from, NI_NUMERICHOST | NI_NUMERICSERV, "" );
+				TRACE_NOTICE("Discarding %d bytes received from unknown IP: %s", len, sa_buf);
 				continue;
 			} );
@@ -250,4 +247,5 @@
 	int ret = 0;
 	struct sockaddr_storage sto;
+	char sa_buf[sSA_DUMP_STRLEN];
 	
 	/* Find the appropriate socket to use (not sure if it is important) */
@@ -276,9 +274,6 @@
 	}
 	
-	{
-		char __buf[1024];
-		sSA_DUMP_NODE_SERV(__buf, sizeof(__buf), &sto, NI_NUMERICHOST | NI_NUMERICSERV );
-		TRACE_DEBUG(FULL, "Sending %zd bytes to %s", buflen, __buf);
-	}
+	fd_sa_sdump_numeric(sa_buf, (sSA*)&sto);
+	TRACE_DEBUG(FULL, "Sending %zd bytes to %s", buflen, sa_buf);
 		
 	/* Send */
Index: extensions/dbg_msg_timings/CMakeLists.txt
===================================================================
--- extensions/dbg_msg_timings/CMakeLists.txt	(revision 1103)
+++ extensions/dbg_msg_timings/CMakeLists.txt	(revision 1103)
@@ -0,0 +1,12 @@
+# Messages timing extension
+PROJECT("Messages timing extension" C)
+FD_ADD_EXTENSION(dbg_msg_timings dbg_msg_timings.c)
+
+
+####
+## INSTALL section ##
+
+INSTALL(TARGETS dbg_msg_timings
+	LIBRARY DESTINATION ${INSTALL_EXTENSIONS_SUFFIX}
+	COMPONENT freeDiameter-debug-tools)
+
Index: extensions/dbg_msg_timings/dbg_msg_timings.c
===================================================================
--- extensions/dbg_msg_timings/dbg_msg_timings.c	(revision 1103)
+++ extensions/dbg_msg_timings/dbg_msg_timings.c	(revision 1103)
@@ -0,0 +1,134 @@
+/*********************************************************************************************************
+* 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.								 *
+*********************************************************************************************************/
+
+/* This extension uses the hooks mechanism to compute some timing information related to messages */
+
+#include <freeDiameter/extension.h>
+
+struct fd_hook_permsgdata {
+	struct timespec received_on;
+	struct timespec sent_on;
+};
+
+static struct fd_hook_data_hdl *mt_data_hdl = NULL;
+static struct fd_hook_hdl *mt_hdl = NULL;
+
+/* The callback called when messages are received and sent */
+static void mt_hook_cb(enum fd_hook_type type, struct msg * msg, struct peer_hdr * peer, void * other, struct fd_hook_permsgdata *pmd, void * regdata)
+{
+	struct msg_hdr * hdr;
+	char * buf = NULL;
+	size_t len;
+	
+	ASSERT(pmd);
+	
+	if (type == HOOK_DATA_RECEIVED) {
+		/* We just store the timestamp it was received on */
+		(void)clock_gettime(CLOCK_REALTIME, &pmd->received_on);
+		return;
+	}
+	
+	ASSERT(msg);
+	
+	/* Check if this message is request or answer */
+	CHECK_FCT_DO( fd_msg_hdr(msg, &hdr), return);
+	
+	if (type == HOOK_MESSAGE_RECEIVED) {
+		ASSERT(pmd->received_on.tv_sec); /* otherwise it means the HOOK_DATA_RECEIVED hook was not trigged for this message */
+		if (hdr->msg_flags & CMD_FLAG_REQUEST) {
+			/* We have received a new request, nothing special to do */
+		} else {
+			/* This is an answer, check how long it took to get it */
+			struct fd_hook_permsgdata *qpmd = fd_hook_get_request_pmd(mt_data_hdl, msg);
+			struct timespec delay;
+			ASSERT(qpmd); /* If we do not have it, we must find out why */
+			ASSERT(qpmd->sent_on.tv_sec); /* same, would mean the HOOK_MESSAGE_SENT hook was not trigged */
+			TS_DIFFERENCE( &delay, &qpmd->sent_on, &pmd->received_on );
+			CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return );
+			LOG_N("[TIMING] RCV ANS %ld.%06ld sec: %s", (long)delay.tv_sec, delay.tv_nsec / 1000, buf);
+		}
+	} else if (type == HOOK_MESSAGE_SENT) {
+		DiamId_t source = NULL;
+		size_t slen = 0;
+		
+		(void)clock_gettime(CLOCK_REALTIME, &pmd->sent_on);
+		
+		/* Is this a forwarded message ? */
+		CHECK_FCT_DO( fd_msg_source_get(msg, &source, &slen), return );
+		if (source) {
+			struct timespec delay;
+			ASSERT(pmd->received_on.tv_sec);
+			TS_DIFFERENCE( &delay, &pmd->received_on, &pmd->sent_on );
+			CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return );
+			LOG_N("[TIMING] FWD %ld.%06ld sec: %s", (long)delay.tv_sec, delay.tv_nsec / 1000, buf);
+		} else if (hdr->msg_flags & CMD_FLAG_REQUEST) {
+			/* We are sending a request issued locally, nothing special to log */
+		} else {
+			/* We have generated an anwer, log the time it took since the corresponding request was received */
+			struct fd_hook_permsgdata *qpmd = fd_hook_get_request_pmd(mt_data_hdl, msg);
+			if (qpmd->received_on.tv_sec) {
+				struct timespec delay;
+				TS_DIFFERENCE( &delay, &qpmd->received_on, &pmd->sent_on );
+				CHECK_MALLOC_DO( fd_msg_dump_summary(&buf, &len, NULL, msg, NULL, 0, 1), return );
+				LOG_N("[TIMING] ANS %ld.%06ld sec: %s", (long)delay.tv_sec, delay.tv_nsec / 1000, buf);
+			}
+		}
+	}
+		
+	free(buf);
+}
+
+/* Entry point */
+static int mt_main(char * conffile)
+{
+	TRACE_ENTRY("%p", conffile);
+	
+	CHECK_FCT( fd_hook_data_register( sizeof(struct fd_hook_permsgdata), NULL, NULL, &mt_data_hdl ) );
+	
+	CHECK_FCT( fd_hook_register( ((1 << HOOK_MESSAGE_RECEIVED) | (1 << HOOK_MESSAGE_SENT) | (1 << HOOK_DATA_RECEIVED)), 
+					mt_hook_cb, NULL, mt_data_hdl, &mt_hdl) );
+	
+	return 0;
+}
+
+/* Cleanup */
+void fd_ext_fini(void)
+{
+	TRACE_ENTRY();
+	CHECK_FCT_DO( fd_hook_unregister( mt_hdl ), );
+	return ;
+}
+
+EXTENSION_ENTRY("dbg_msg_timing", mt_main);
