changeset 950:51c15f98a965

merge current version from 1.1 branch (927:877592751fee).
author Thomas Klausner <tk@giga.or.at>
date Thu, 21 Feb 2013 11:57:32 +0100
parents ad5c976e0dc7 (diff) 877592751fee (current diff)
children f97fa305467f
files include/freeDiameter/libfdproto.h libfdcore/fdd.l libfdcore/fdd.y libfdcore/peers.c libfdcore/sctp.c
diffstat 12 files changed, 112 insertions(+), 105 deletions(-) [+]
line wrap: on
line diff
--- a/.hgtags	Thu Feb 14 17:52:57 2013 +0100
+++ b/.hgtags	Thu Feb 21 11:57:32 2013 +0100
@@ -29,3 +29,4 @@
 5c4cf8d15ef0e298734daf16203278d7fa62fa7a 1.1.5-rc1
 226f5957186ae4369467b070aeb61b1c631c9a5c 1.1.5-rc2
 ae96ae28f3ddc48b9e2676e9538008eab2b9d60a 1.1.5
+8500947421cb412b5f4f2dfffdf1a35b6fb369e0 FORK
--- a/extensions/acl_wl/aw_conf.y	Thu Feb 14 17:52:57 2013 +0100
+++ b/extensions/acl_wl/aw_conf.y	Thu Feb 21 11:57:32 2013 +0100
@@ -63,7 +63,7 @@
 /* Parse the configuration file */
 int aw_conf_handle(char * conffile)
 {
-	extern FILE * aw_confin;
+	FILE * aw_confin;
 	int ret;
 	
 	TRACE_ENTRY("%p", conffile);
--- a/include/freeDiameter/libfdcore.h	Thu Feb 14 17:52:57 2013 +0100
+++ b/include/freeDiameter/libfdcore.h	Thu Feb 21 11:57:32 2013 +0100
@@ -86,7 +86,7 @@
 const char *fd_core_version(void);
 
 /* Parse the freeDiameter.conf configuration file, load the extensions */
-int fd_core_parseconf(char * conffile);
+int fd_core_parseconf(const char * conffile);
 
 /* Start the server & client threads */
 int fd_core_start(void);
@@ -110,7 +110,7 @@
 struct fd_config {
 	int		 cnf_eyec;	/* Eye catcher: EYEC_CONFIG */
 	
-	char		*cnf_file;	/* Configuration file to parse, default is DEFAULT_CONF_FILE */
+	const char	*cnf_file;	/* Configuration file to parse, default is DEFAULT_CONF_FILE */
 	
 	DiamId_t  	 cnf_diamid;	/* Diameter Identity of the local peer (FQDN -- ASCII) */
 	size_t		 cnf_diamid_len;/* cached length of the previous string */
@@ -349,7 +349,7 @@
  *  (other standard errors may be returned, too, with their standard meaning. Example:
  *    ENOMEM 	: Memory allocation for the new object element failed.)
  */
-int fd_peer_add ( struct peer_info * info, char * orig_dbg, void (*cb)(struct peer_info *, void *), void * cb_data );
+int fd_peer_add ( struct peer_info * info, const char * orig_dbg, void (*cb)(struct peer_info *, void *), void * cb_data );
 
 /*
  * FUNCTION:	fd_peer_getbyid
--- a/include/freeDiameter/libfdproto.h	Thu Feb 14 17:52:57 2013 +0100
+++ b/include/freeDiameter/libfdproto.h	Thu Feb 21 11:57:32 2013 +0100
@@ -109,24 +109,25 @@
 
 
 /*
- * FUNCTION:	fd_log_debug_fstr
+ * FUNCTION:	fd_log
  * MACRO:	fd_log_debug
  *
  * PARAMETERS:
- *  fstr	: Stream where the text will be sent (default: stdout) 
+ *  loglevel	: Integer, how important the message is
  *  format 	: Same format string as in the printf function
  *  ...		: Same list as printf
  *
  * DESCRIPTION: 
- *  Log internal information for use of developpers only.
+ * Write information to log.
  * The format and arguments may contain UTF-8 encoded data. The
- * output medium (file or console) is expected to support this encoding.
+ * output medium is expected to support this encoding.
  *
  * RETURN VALUE:
  *  None.
  */
-void fd_log_debug_fstr ( FILE * fstr, const char * format, ... );
-#define fd_log_debug(format,args...) fd_log_debug_fstr(NULL, format, ## args)
+void fd_log ( int, const char *, ... );
+#define fd_log_debug(format,args...) fd_log(FD_LOG_DEBUG, format, ## args)
+void fd_log_debug_fstr( FILE *, const char *, ... );
 
 /* these are internal objects of the debug facility, 
 might be useful to control the behavior from outside */
@@ -173,7 +174,7 @@
  * MACRO:
  *
  * PARAMETERS:
- *  fstr        : Stream where the text will be sent to (default: stdout)
+ *  loglevel    : priority of the message
  *  format      : Same format string as in the printf function
  *  va_list     : Argument list
  *
@@ -183,7 +184,7 @@
  * RETURN VALUE:
  * int          : Success or failure
  */
-int fd_log_handler_register ( void (*logger)(const char * format, va_list *args) );
+int fd_log_handler_register ( void (*logger)(int loglevel, const char * format, va_list args) );
 
 /*
  * FUNCTION:    fd_log_handler_unregister
@@ -208,7 +209,11 @@
 #define ASSERT(x) assert(x)
 #endif /* ASSERT */
 
-/* levels definitions */
+/* log levels definitions */
+#define FD_LOG_DEBUG 0
+#define FD_LOG_ERROR 5
+
+/* print level definitions */
 #define NONE 0	/* Display no debug message */
 #define INFO 1	/* Display errors only */
 #define FULL 2  /* Display additional information to follow code execution */
@@ -254,6 +259,7 @@
 #endif /* DEBUG */
 
 
+#define STD_TRACE_FMT_STRING "thread %s in %s@%s:%d: "
 /*************
  The general debug macro, each call results in two lines of debug messages (change the macro for more compact output) 
  *************/
@@ -261,12 +267,9 @@
 /* In DEBUG mode, we add (a lot of) meta-information along each trace. This makes multi-threading problems easier to debug. */
 #define TRACE_DEBUG(level,format,args... ) {											\
 	if ( TRACE_BOOL(level) ) {												\
-		char __buf[25];													\
 		const char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed");					\
-		fd_log_debug("\t | tid:%-20s\t%s\tin %s@%s:%d\n"								\
-			  "\t%s|%*s" format "\n",  										\
-					__thn, fd_log_time(NULL, __buf, sizeof(__buf)), __PRETTY_FUNCTION__, __FILE__, __LINE__,\
-					(level < FULL)?"@":" ",level, "", ## args); 						\
+		fd_log(level, STD_TRACE_FMT_STRING format, \
+					__thn, __PRETTY_FUNCTION__, __FILE__, __LINE__, ## args); 						\
 	}															\
 }
 #else /* DEBUG */
@@ -274,14 +277,11 @@
 #define TRACE_DEBUG(level,format,args... ) {												\
 	if ( TRACE_BOOL(level) ) {													\
 		if (fd_g_debug_lvl > FULL) {												\
-			char __buf[25];													\
 			const char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed");					\
-			fd_log_debug("\t | tid:%-20s\t%s\tin %s@%s:%d\n"								\
-				  "\t%s|%*s" format "\n",  										\
-						__thn, fd_log_time(NULL, __buf, sizeof(__buf)), __PRETTY_FUNCTION__, __FILE__, __LINE__,\
-						(level < FULL)?"@":" ",level, "", ## args); 						\
+                        fd_log(level, STD_TRACE_FMT_STRING format,      \
+                               __thn, __PRETTY_FUNCTION__, __FILE__, __LINE__, ## args);  \
 		} else {														\
-			fd_log_debug(format "\n", ## args); 										\
+			fd_log(level, format, ## args);           \
 		}															\
 	}																\
 }
@@ -315,19 +315,16 @@
 /* Trace a binary buffer content */
 #define TRACE_DEBUG_BUFFER(level, prefix, buf, bufsz, suffix ) {								\
 	if ( TRACE_BOOL(level) ) {												\
-		char __ts[25];													\
 		int __i;													\
 		size_t __sz = (size_t)(bufsz);											\
 		uint8_t * __buf = (uint8_t *)(buf);										\
 		char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed");					\
-		fd_log_debug("\t | tid:%-20s\t%s\tin %s@%s:%d\n"								\
-			  "\t%s|%*s" prefix ,  											\
-					__thn, fd_log_time(NULL, __ts, sizeof(__ts)), __PRETTY_FUNCTION__, __FILE__, __LINE__,	\
-					(level < FULL)?"@":" ",level, ""); 							\
+                fd_log(level, STD_TRACE_FMT_STRING prefix,              \
+                       __thn, __PRETTY_FUNCTION__, __FILE__, __LINE__);	\
 		for (__i = 0; __i < __sz; __i++) {										\
-			fd_log_debug("%02.2hhx", __buf[__i]);									\
+			fd_log(level, "%02.2hhx", __buf[__i]);         \
 		}														\
-		fd_log_debug(suffix "\n");											\
+		fd_log(level, suffix);                        \
 	}															\
 }
 
@@ -344,7 +341,7 @@
 					0 ) ) )
 
 /* Dump one sockaddr Node information */
-#define sSA_DUMP_NODE( sa, flag ) {				\
+#define sSA_DUMP_NODE( buf, bufsize, sa, flag ) {                \
 	sSA * __sa = (sSA *)(sa);				\
 	char __addrbuf[INET6_ADDRSTRLEN];			\
 	if (__sa) {						\
@@ -356,15 +353,15 @@
 			0,					\
 			flag);					\
 	  if (__rc)						\
-	  	fd_log_debug("%s", (char *)gai_strerror(__rc));	\
+		snprintf(buf, bufsize, "%s", gai_strerror(__rc));	\
 	  else							\
-	  	fd_log_debug("%s", &__addrbuf[0]);		\
+		snprintf(buf, bufsize, "%s", &__addrbuf[0]);       \
 	} else {						\
-		fd_log_debug("(NULL / ANY)");			\
+		snprintf(buf, bufsize, "(NULL / ANY)");             \
 	}							\
 }
 /* Same but with the port (service) also */
-#define sSA_DUMP_NODE_SERV( sa, flag ) {				\
+#define sSA_DUMP_NODE_SERV( buf, bufsize, sa, flag ) {                  \
 	sSA * __sa = (sSA *)(sa);					\
 	char __addrbuf[INET6_ADDRSTRLEN];				\
 	char __servbuf[32];						\
@@ -377,25 +374,22 @@
 			sizeof(__servbuf),				\
 			flag);						\
 	  if (__rc)							\
-	  	fd_log_debug("%s", (char *)gai_strerror(__rc));		\
+		snprintf(buf, bufsize, "%s", gai_strerror(__rc));  \
 	  else								\
-	  	fd_log_debug("[%s]:%s", &__addrbuf[0],&__servbuf[0]);	\
+		snprintf(buf, bufsize, "[%s]:%s", &__addrbuf[0],&__servbuf[0]); \
 	} else {							\
-		fd_log_debug("(NULL / ANY)");				\
+		snprintf(buf, bufsize,"(NULL / ANY)");         \
 	}								\
 }
 
 /* Inside a debug trace */
 #define TRACE_DEBUG_sSA(level, prefix, sa, flags, suffix ) {										\
 	if ( TRACE_BOOL(level) ) {												\
-		char __buf[25];													\
+		char buf[1024]; \
 		char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed");					\
-		fd_log_debug("\t | tid:%-20s\t%s\tin %s@%s:%d\n"								\
-			  "\t%s|%*s" prefix ,  											\
-					__thn, fd_log_time(NULL, __buf, sizeof(__buf)), __PRETTY_FUNCTION__, __FILE__, __LINE__,\
-					(level < FULL)?"@":" ",level, ""); 							\
-		sSA_DUMP_NODE_SERV( sa, flags );										\
-		fd_log_debug(suffix "\n");											\
+		sSA_DUMP_NODE_SERV(buf, sizeof(buf), sa, flags );       \
+		fd_log(level, STD_TRACE_FMT_STRING "%s%s%s",              \
+                       __thn, __PRETTY_FUNCTION__, __FILE__, __LINE__, prefix, buf, suffix); \
 	}															\
 }
 
@@ -417,7 +411,7 @@
 #define TRACE_DEBUG_BUFFER(level, prefix, buf, bufsz, suffix )
 #define TRACE_DEBUG_sSA(level, prefix, sa, flags, suffix )
 #define TRACE_DEBUG_ERROR(format,args... ) {	\
-	fd_log_debug(format "\n", ## args); 	\
+	fd_log(FD_LOG_ERROR, format, ## args); 	\
 }
 #endif /* STRIP_DEBUG_CODE */
 
--- a/libfdcore/cnxctx.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdcore/cnxctx.c	Thu Feb 21 11:57:32 2013 +0100
@@ -228,9 +228,9 @@
 	CHECK_SYS_DO( cli_sock = accept(serv->cc_socket, (sSA *)&ss, &ss_len), return NULL );
 	
 	if (TRACE_BOOL(INFO)) {
-		fd_log_debug("%s : accepted new client [", fd_cnx_getid(serv));
-		sSA_DUMP_NODE( &ss, NI_NUMERICHOST );
-		fd_log_debug("].\n");
+		char buf[1024];
+		sSA_DUMP_NODE( buf, sizeof(buf), &ss, NI_NUMERICHOST );
+		fd_log_debug("%s : accepted new client [%s].\n", fd_cnx_getid(serv), buf);
 	}
 	
 	CHECK_MALLOC_DO( cli = fd_cnx_init(1), { shutdown(cli_sock, SHUT_RDWR); close(cli_sock); return NULL; } );
@@ -311,9 +311,9 @@
 	}
 	
 	if (TRACE_BOOL(INFO)) {
-		fd_log_debug("Connection established to server '");
-		sSA_DUMP_NODE_SERV( sa, NI_NUMERICSERV);
-		fd_log_debug("' (TCP:%d).\n", sock);
+		char buf[1024];
+		sSA_DUMP_NODE_SERV( buf, sizeof(buf), sa, NI_NUMERICSERV);
+		fd_log_debug("Connection established to server '%s' (TCP:%d).\n", buf, sock);
 	}
 	
 	/* Once the socket is created successfuly, prepare the remaining of the cnx */
@@ -403,9 +403,9 @@
 		cnx->cc_sctp_para.pairs = cnx->cc_sctp_para.str_in;
 	
 	if (TRACE_BOOL(INFO)) {
-		fd_log_debug("Connection established to server '");
-		sSA_DUMP_NODE_SERV( &primary, NI_NUMERICSERV);
-		fd_log_debug("' (SCTP:%d, %d/%d streams).\n", sock, cnx->cc_sctp_para.str_in, cnx->cc_sctp_para.str_out);
+		char buf[1024];
+		sSA_DUMP_NODE_SERV( buf, sizeof(buf), &primary, NI_NUMERICSERV);
+		fd_log_debug("Connection established to server '%s' (SCTP:%d, %d/%d streams).\n", buf, sock, cnx->cc_sctp_para.str_in, cnx->cc_sctp_para.str_out);
 	}
 	
 	/* Generate the names for the object */
--- a/libfdcore/config.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdcore/config.c	Thu Feb 21 11:57:32 2013 +0100
@@ -229,7 +229,7 @@
 int fd_conf_parse()
 {
 	extern FILE * fddin;
-	char * orig = NULL;
+	const char * orig = NULL;
 	
 	/* Attempt to find the configuration file */
 	if (!fd_g_config->cnf_file)
@@ -237,23 +237,18 @@
 	
 	fddin = fopen(fd_g_config->cnf_file, "r");
 	if ((fddin == NULL) && (*fd_g_config->cnf_file != '/')) {
+		char * new_cnf = NULL;
 		/* We got a relative path, attempt to add the default directory prefix */
 		orig = fd_g_config->cnf_file;
-		CHECK_MALLOC( fd_g_config->cnf_file = malloc(strlen(orig) + strlen(DEFAULT_CONF_PATH) + 2) ); /* we will not free it, but not important */
-		sprintf( fd_g_config->cnf_file, DEFAULT_CONF_PATH "/%s", orig );
+		CHECK_MALLOC( new_cnf = malloc(strlen(orig) + strlen(DEFAULT_CONF_PATH) + 2) ); /* we will not free it, but not important */
+		sprintf( new_cnf, DEFAULT_CONF_PATH "/%s", orig );
+		fd_g_config->cnf_file = new_cnf;
 		fddin = fopen(fd_g_config->cnf_file, "r");
 	}
 	if (fddin == NULL) {
 		int ret = errno;
-		if (orig) {
-			fprintf(stderr, "Unable to open configuration file for reading\n"
-					"Tried the following locations:\n"
-					" - %s\n"
-					" - %s\n"
-					"Error: %s\n", orig, fd_g_config->cnf_file, strerror(ret));
-		} else {
-			fprintf(stderr, "Unable to open '%s' for reading: %s\n", fd_g_config->cnf_file, strerror(ret));
-		}
+		TRACE_DEBUG_ERROR("Unable to open configuration file for reading; tried the following locations: %s%s%s; Error: %s\n",
+				  orig ?: "", orig? " and " : "", fd_g_config->cnf_file, strerror(ret));
 		return ret;
 	}
 	
@@ -351,9 +346,9 @@
 				li = li->prev;
 				fd_list_unlink(&ep->chain);
 				if (TRACE_BOOL(INFO)) {
-					fd_log_debug("Info: Removing local address conflicting with the flags no_IP / no_IP6 : ");
-					sSA_DUMP_NODE( &ep->sa, NI_NUMERICHOST );
-					fd_log_debug("\n");
+					char buf[1024];
+					sSA_DUMP_NODE( buf, sizeof(buf), &ep->sa, NI_NUMERICHOST );
+					fd_log_debug("Info: Removing local address conflicting with the flags no_IP / no_IP6 : %s\n", buf);
 				}
 				free(ep);
 			}
--- a/libfdcore/core.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdcore/core.c	Thu Feb 21 11:57:32 2013 +0100
@@ -225,7 +225,7 @@
 }
 
 /* Parse the freeDiameter.conf configuration file, load the extensions */
-int fd_core_parseconf(char * conffile)
+int fd_core_parseconf(const char * conffile)
 {
 	TRACE_ENTRY("%p", conffile);
 	
--- a/libfdcore/endpoints.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdcore/endpoints.c	Thu Feb 21 11:57:32 2013 +0100
@@ -58,12 +58,12 @@
 	}
 	
 	if (TRACE_BOOL(ANNOYING + 1)) {
+		char buf[1024];
+		sSA_DUMP_NODE_SERV( buf, sizeof(buf), sa, NI_NUMERICHOST | NI_NUMERICSERV );
 		TRACE_DEBUG(ANNOYING, "  DEBUG:fd_ep_add_merge  Current list:");
 		fd_ep_dump( 4, list );
 		TRACE_DEBUG(ANNOYING, "  DEBUG:fd_ep_add_merge  Adding:");
-		fd_log_debug("    ");
-		sSA_DUMP_NODE_SERV( sa, NI_NUMERICHOST | NI_NUMERICSERV );
-		fd_log_debug(" {%s%s%s%s}\n", 
+		fd_log_debug("    %s {%s%s%s%s}\n", buf,
 				(flags & EP_FL_CONF) 	? "C" : "-",
 				(flags & EP_FL_DISC)	    ? "D" : "-",
 				(flags & EP_FL_ADV)	    ? "A" : "-",
@@ -335,18 +335,16 @@
 
 void fd_ep_dump_one( char * prefix, struct fd_endpoint * ep, char * suffix )
 {
-	if (prefix)
-		fd_log_debug("%s", prefix);
+	char buf[1024];
 	
-	sSA_DUMP_NODE_SERV( &ep->sa, NI_NUMERICHOST | NI_NUMERICSERV );
-	fd_log_debug(" {%s%s%s%s}", 
+	sSA_DUMP_NODE_SERV( buf, sizeof(buf), &ep->sa, NI_NUMERICHOST | NI_NUMERICSERV );
+	fd_log_debug("%s%s {%s%s%s%s}%s", prefix ?: "", buf,
 			(ep->flags & EP_FL_CONF) 	? "C" : "-",
 			(ep->flags & EP_FL_DISC) 	? "D" : "-",
 			(ep->flags & EP_FL_ADV) 	? "A" : "-",
 			(ep->flags & EP_FL_LL) 		? "L" : "-",
-			(ep->flags & EP_FL_PRIMARY) 	? "P" : "-");
-	if (suffix)
-		fd_log_debug("%s", suffix);
+			(ep->flags & EP_FL_PRIMARY) 	? "P" : "-",
+			suffix ?: "");
 }
 
 void fd_ep_dump( int indent, struct fd_list * eps )
--- a/libfdcore/peers.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdcore/peers.c	Thu Feb 21 11:57:32 2013 +0100
@@ -90,7 +90,7 @@
 }
 
 /* Add a new peer entry */
-int fd_peer_add ( struct peer_info * info, char * orig_dbg, void (*cb)(struct peer_info *, void *), void * cb_data )
+int fd_peer_add ( struct peer_info * info, const char * orig_dbg, void (*cb)(struct peer_info *, void *), void * cb_data )
 {
 	struct fd_peer *p = NULL;
 	struct fd_list * li, *li_inf;
--- a/libfdcore/sctp.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdcore/sctp.c	Thu Feb 21 11:57:32 2013 +0100
@@ -908,6 +908,8 @@
 		return ENOTSUP;
 	}
 	if (TRACE_BOOL(SCTP_LEVEL)) {
+		char buf[1024];
+		sSA_DUMP_NODE_SERV(buf, sizeof(buf), &status.sstat_primary.spinfo_address, NI_NUMERICHOST | NI_NUMERICSERV );
 		fd_log_debug( "SCTP_STATUS : sstat_state                  : %i\n" , status.sstat_state);
 		fd_log_debug( "              sstat_rwnd  	          : %u\n" , status.sstat_rwnd);
 		fd_log_debug( "		     sstat_unackdata	          : %hu\n", status.sstat_unackdata);
@@ -915,9 +917,7 @@
 		fd_log_debug( "		     sstat_instrms  	          : %hu\n", status.sstat_instrms);
 		fd_log_debug( "		     sstat_outstrms 	          : %hu\n", status.sstat_outstrms);
 		fd_log_debug( "		     sstat_fragmentation_point    : %u\n" , status.sstat_fragmentation_point);
-		fd_log_debug( "		     sstat_primary.spinfo_address : ");
-		sSA_DUMP_NODE_SERV(&status.sstat_primary.spinfo_address, NI_NUMERICHOST | NI_NUMERICSERV );
-		fd_log_debug( "\n" );
+		fd_log_debug( "		     sstat_primary.spinfo_address : %s\n" , buf);
 		fd_log_debug( "		     sstat_primary.spinfo_state   : %d\n" , status.sstat_primary.spinfo_state);
 		fd_log_debug( "		     sstat_primary.spinfo_cwnd    : %u\n" , status.sstat_primary.spinfo_cwnd);
 		fd_log_debug( "		     sstat_primary.spinfo_srtt    : %u\n" , status.sstat_primary.spinfo_srtt);
--- a/libfdproto/dictionary.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdproto/dictionary.c	Thu Feb 21 11:57:32 2013 +0100
@@ -1277,8 +1277,6 @@
 	else
 		_OBINFO(obj).dump_data(&obj->data);
 	
-	fd_log_debug("\n");
-	
 	if (depth) {
 		int i;
 		for (i=0; i<NB_LISTS_PER_OBJ; i++) {
@@ -1469,7 +1467,6 @@
 	}
 	
 	/* Done! */
-	CHECK_FCT( dump_add_str(outstr, offset, outlen, "\n") );
 	return 0;
 }
 
--- a/libfdproto/log.c	Thu Feb 14 17:52:57 2013 +0100
+++ b/libfdproto/log.c	Thu Feb 21 11:57:32 2013 +0100
@@ -43,6 +43,8 @@
 pthread_key_t	fd_log_thname;
 int fd_g_debug_lvl = INFO;
 
+static void fd_internal_logger( int, const char *, va_list );
+
 /* These may be used to pass specific debug requests via the command-line parameters */
 char * fd_debug_one_function = NULL;
 char * fd_debug_one_file = NULL;
@@ -52,28 +54,29 @@
 int fd_breakhere(void) { return ++fd_breaks; }
 
 /* Allow passing of the log and debug information from base stack to extensions */
-void (*fd_external_logger)( const char * format, va_list *args ) = NULL;
+void (*fd_logger)( int loglevel, const char * format, va_list args ) = fd_internal_logger;
 
-/* Register an dexternal call back for tracing and debug */
-int fd_log_handler_register( void (*logger)(const char * format, va_list *args))
+/* Register an external call back for tracing and debug */
+int fd_log_handler_register( void (*logger)(int loglevel, const char * format, va_list args) )
 {
         CHECK_PARAMS( logger );
 
-        if ( fd_external_logger != NULL )
+        if ( fd_logger != fd_internal_logger )
         {
                return EALREADY; /* only one registration allowed */
         }
         else
         {
-               fd_external_logger = logger;
+               fd_logger = logger;
         }
+
         return 0;
 }
 
 /* Implement a simple reset function here */
 int fd_log_handler_unregister ( void )
 {
-        fd_external_logger = NULL;
+        fd_logger = fd_internal_logger;
         return 0; /* Successfull in all cases. */
 }
 
@@ -82,8 +85,25 @@
 	(void)pthread_mutex_unlock((pthread_mutex_t *)mutex);
 }
 
+
+static void fd_internal_logger( int loglevel, const char *format, va_list ap )
+{
+    char buf[25];
+    FILE *fstr = fd_g_debug_fstr ?: stdout;
+
+    /* logging has been decided by macros outside already */
+
+    /* add timestamp */
+    fprintf(fd_g_debug_fstr, "%s\t", fd_log_time(NULL, buf, sizeof(buf)));
+    vfprintf(fd_g_debug_fstr, format, ap);
+    if (format && (format[strlen(format)-1] != '\n')) {
+        fprintf(fd_g_debug_fstr, "\n");
+    }
+    fflush(fd_g_debug_fstr);
+}
+
 /* Log a debug message */
-void fd_log_debug_fstr ( FILE * fstr, const char * format, ... )
+void fd_log ( int loglevel, const char * format, ... )
 {
 	va_list ap;
 	
@@ -92,15 +112,7 @@
 	pthread_cleanup_push(fd_cleanup_mutex_silent, &fd_log_lock);
 	
 	va_start(ap, format);
-        if ( fd_external_logger != NULL )
-        {
-               fd_external_logger( format, &ap );
-        }
-        else
-        {
-               vfprintf( fstr ?: stdout, format, ap);
-               fflush(fstr ?: stdout);
-        }
+	fd_logger(loglevel, format, ap);
 	va_end(ap);
 
 	pthread_cleanup_pop(0);
@@ -108,6 +120,16 @@
 	(void)pthread_mutex_unlock(&fd_log_lock);
 }
 
+/* Log debug message to file. */
+void fd_log_debug_fstr( FILE * fstr, const char * format, ... )
+{
+	va_list ap;
+	
+	va_start(ap, format);
+	vfprintf(fstr, format, ap);
+	va_end(ap);
+}
+
 /* Function to set the thread's friendly name */
 void fd_log_threadname ( const char * name )
 {
"Welcome to our mercurial repository"