# HG changeset patch # User Thomas Klausner # Date 1360669112 -3600 # Node ID 5d9229144cacae395abd0c730d79ea4a501b6c58 # Parent 284608b307eef7818abb0dee8c33c09d21691d25 Change macro so complete lines can be logged at once. Make some macros share their format string. Adapt users. diff -r 284608b307ee -r 5d9229144cac include/freeDiameter/libfdproto.h --- a/include/freeDiameter/libfdproto.h Tue Feb 12 11:56:53 2013 +0100 +++ b/include/freeDiameter/libfdproto.h Tue Feb 12 12:38:32 2013 +0100 @@ -259,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) *************/ @@ -266,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(level, "\t | tid:%-20s\t%s\tin %s@%s:%d\n" \ - "\t%s|%*s" format, \ - __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 */ @@ -279,12 +277,9 @@ #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(level, "\t | tid:%-20s\t%s\tin %s@%s:%d\n" \ - "\t%s|%*s" format, \ - __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(level, format, ## args); \ } \ @@ -320,15 +315,12 @@ /* 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(level, "\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(level, "%02.2hhx", __buf[__i]); \ } \ @@ -349,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) { \ @@ -361,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]; \ @@ -382,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(level, "\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(level, suffix); \ + 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); \ } \ } diff -r 284608b307ee -r 5d9229144cac libfdcore/cnxctx.c --- a/libfdcore/cnxctx.c Tue Feb 12 11:56:53 2013 +0100 +++ b/libfdcore/cnxctx.c Tue Feb 12 12:38: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 */ diff -r 284608b307ee -r 5d9229144cac libfdcore/config.c --- a/libfdcore/config.c Tue Feb 12 11:56:53 2013 +0100 +++ b/libfdcore/config.c Tue Feb 12 12:38:32 2013 +0100 @@ -351,9 +351,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); } diff -r 284608b307ee -r 5d9229144cac libfdcore/endpoints.c --- a/libfdcore/endpoints.c Tue Feb 12 11:56:53 2013 +0100 +++ b/libfdcore/endpoints.c Tue Feb 12 12:38: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 ) diff -r 284608b307ee -r 5d9229144cac libfdcore/sctp.c --- a/libfdcore/sctp.c Tue Feb 12 11:56:53 2013 +0100 +++ b/libfdcore/sctp.c Tue Feb 12 12:38: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);