Mercurial > hg > freeDiameter
changeset 965:9b37f34c1b1f
Some modifications to logging code:
- Added a FD_LOG_NOTICE level for the logger function
- Separated the internal debug levels (NONE, INFO, ...) from the "printlevel" for the logger
- Renamed TRACE_DEBUG_ERROR to TRACE_ERROR for symetry
- Renamed TRACE_DEBUG_BUFFER and TRACE_DEBUG_sSA. There take now the printlevel as parameter
- Added new TRACE_NOTICE, fd_log_notice and fd_log_error macros.
* sorry if I forgot some changes...
| author | Sebastien Decugis <sdecugis@freediameter.net> |
|---|---|
| date | Tue, 12 Mar 2013 17:23:37 +0100 |
| parents | 992ef1167344 |
| children | 8862d9dece66 |
| files | extensions/acl_wl/aw_conf.l extensions/app_radgw/rgw_clients.c extensions/app_radgw/rgw_servers.c extensions/app_radgw/rgwx_acct.c include/freeDiameter/libfdproto.h libfdcore/config.c libfdcore/fdd.l libfdcore/fdd.y libfdcore/sctp.c libfdcore/sctps.c libfdcore/tcp.c libfdproto/log.c |
| diffstat | 12 files changed, 188 insertions(+), 121 deletions(-) [+] |
line wrap: on
line diff
--- a/extensions/acl_wl/aw_conf.l Sat Mar 09 16:55:20 2013 +0100 +++ b/extensions/acl_wl/aw_conf.l Tue Mar 12 17:23:37 2013 +0100 @@ -95,7 +95,7 @@ /* No match */ <*>[[:alnum:]]+ | /* This rule is only useful to print a complete token in error messages */ <*>. { - TRACE_DEBUG_ERROR("Unrecognized text on line %d col %d: '%s'.\n", yylloc->first_line, yylloc->first_column, yytext); + TRACE_ERROR("Unrecognized text on line %d col %d: '%s'.\n", yylloc->first_line, yylloc->first_column, yytext); return LEX_ERROR; }
--- a/extensions/app_radgw/rgw_clients.c Sat Mar 09 16:55:20 2013 +0100 +++ b/extensions/app_radgw/rgw_clients.c Tue Mar 12 17:23:37 2013 +0100 @@ -921,8 +921,8 @@ /* Dump the entry in debug mode */ if (TRACE_BOOL(FULL + 1 )) { TRACE_DEBUG(FULL, "Adding %s:", (type == RGW_CLI_NAS) ? "NAS" : "PROXY" ); - TRACE_DEBUG_sSA(FULL, "\tIP : ", ip_port, NI_NUMERICHOST | NI_NUMERICSERV, "" ); - TRACE_DEBUG_BUFFER(FULL, "\tKey: [", *key, keylen, "]" ); + TRACE_sSA(FD_LOG_DEBUG, FULL, "\tIP : ", ip_port, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_BUFFER(FD_LOG_DEBUG, FULL, "\tKey: [", *key, keylen, "]" ); } /* Lock the lists */ @@ -947,13 +947,13 @@ goto end; } - fd_log_debug("ERROR: Conflicting RADIUS clients descriptions!\n"); - TRACE_DEBUG(NONE, "Previous entry: %s", (prev->type == RGW_CLI_NAS) ? "NAS" : "PROXY"); - TRACE_DEBUG_sSA(NONE, "\tIP : ", prev->sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); - TRACE_DEBUG_BUFFER(NONE, "\tKey: [", prev->key.data, prev->key.len, "]" ); - TRACE_DEBUG(NONE, "Conflicting entry: %s", (type == RGW_CLI_NAS) ? "NAS" : "PROXY"); - TRACE_DEBUG_sSA(NONE, "\tIP : ", ip_port, NI_NUMERICHOST | NI_NUMERICSERV, "" ); - TRACE_DEBUG_BUFFER(NONE, "\tKey: [", *key, keylen, "]" ); + fd_log_erre("ERROR: Conflicting RADIUS clients descriptions!\n"); + 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, "" ); + 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, "" ); + TRACE_BUFFER(FD_LOG_ERROR, NONE, "\tKey: [", *key, keylen, "]" ); } end: /* release the lists */ @@ -969,7 +969,8 @@ for (ref = senti->next; ref != senti; ref = ref->next) { client = (struct rgw_client *)ref; - TRACE_DEBUG_sSA(NONE, " - ", client->sa, NI_NUMERICHOST | NI_NUMERICSERV, (client->type == RGW_CLI_NAS) ? "" : " [PROXY]" ); + /* 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]" ); } }
--- a/extensions/app_radgw/rgw_servers.c Sat Mar 09 16:55:20 2013 +0100 +++ b/extensions/app_radgw/rgw_servers.c Tue Mar 12 17:23:37 2013 +0100 @@ -133,13 +133,13 @@ } TRACE_DEBUG(FULL, "Received %d bytes", len); - TRACE_DEBUG_sSA(FULL, " from ", &from, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_sSA(FD_LOG_DEBUG, FULL, " from ", &from, NI_NUMERICHOST | NI_NUMERICSERV, "" ); /* Search the associated client definition, if any */ CHECK_FCT_DO( rgw_clients_search((struct sockaddr *) &from, &nas_info), { - TRACE_DEBUG(INFO, "Discarding %d bytes received from unknown IP:", len); - TRACE_DEBUG_sSA(INFO, " ", &from, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_NOTICE("Discarding %d bytes received from unknown IP:", len); + TRACE_sSA(FD_LOG_NOTICE, INFO, " ", &from, NI_NUMERICHOST | NI_NUMERICSERV, "" ); continue; } ); @@ -273,7 +273,7 @@ } TRACE_DEBUG(FULL, "Sending %d bytes", buflen); - TRACE_DEBUG_sSA(FULL, " to ", &sto, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_sSA(FD_LOG_DEBUG, FULL, " to ", &sto, NI_NUMERICHOST | NI_NUMERICSERV, "" ); /* Send */ ret = sendto(SERVERS[idx].sock, buf, buflen, 0, (struct sockaddr *)&sto, sSAlen(&sto));
--- a/extensions/app_radgw/rgwx_acct.c Sat Mar 09 16:55:20 2013 +0100 +++ b/extensions/app_radgw/rgwx_acct.c Tue Mar 12 17:23:37 2013 +0100 @@ -434,8 +434,8 @@ /* And now compare with the received value */ if (memcmp(&save[0], &rad_req->hdr->authenticator[0], MD5_MAC_LEN)) { /* Invalid authenticator */ - TRACE_DEBUG_BUFFER(FULL+1, "Received ReqAuth: ", &save[0], MD5_MAC_LEN, "" ); - TRACE_DEBUG_BUFFER(FULL+1, "Expected ReqAuth: ", &rad_req->hdr->authenticator[0], MD5_MAC_LEN, "" ); + TRACE_BUFFER(FD_LOG_DEBUG, FULL+1, "Received ReqAuth: ", &save[0], MD5_MAC_LEN, "" ); + TRACE_BUFFER(FD_LOG_DEBUG, FULL+1, "Expected ReqAuth: ", &rad_req->hdr->authenticator[0], MD5_MAC_LEN, "" ); TRACE_DEBUG(INFO, "[acct.rgwx] Invalid Request Authenticator in Account-Request from %s, discarding the message.", rgw_clients_id(cli)); return EINVAL; }
--- a/include/freeDiameter/libfdproto.h Sat Mar 09 16:55:20 2013 +0100 +++ b/include/freeDiameter/libfdproto.h Tue Mar 12 17:23:37 2013 +0100 @@ -111,6 +111,8 @@ /* * FUNCTION: fd_log * MACRO: fd_log_debug + * MACRO: fd_log_notice + * MACRO: fd_log_error * * PARAMETERS: * loglevel : Integer, how important the message is @@ -126,7 +128,10 @@ * None. */ void fd_log ( int, const char *, ... ); -#define fd_log_debug(format,args...) fd_log(FD_LOG_DEBUG, format, ## args) +#define fd_log_debug(format,args...) fd_log(FD_LOG_DEBUG, format, ## args) +#define fd_log_notice(format,args...) fd_log(FD_LOG_NOTICE, format, ## args) +#define fd_log_error(format,args...) fd_log(FD_LOG_ERROR, format, ## args) + void fd_log_debug_fstr( FILE *, const char *, ... ); /* these are internal objects of the debug facility, @@ -210,8 +215,9 @@ #endif /* ASSERT */ /* log levels definitions */ -#define FD_LOG_DEBUG 0 -#define FD_LOG_ERROR 5 +#define FD_LOG_DEBUG 0 /* Verbose information for developers use */ +#define FD_LOG_NOTICE 3 /* Normal execution states worth noting */ +#define FD_LOG_ERROR 5 /* Error conditions, both recoverable or not */ /* print level definitions */ #define NONE 0 /* Display no debug message */ @@ -251,36 +257,50 @@ #endif /* DEBUG */ -#define STD_TRACE_FMT_STRING "thread %s in %s@%s:%d: " +#define STD_TRACE_FMT_STRING "pid:%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) *************/ #ifdef DEBUG /* 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... ) { \ +#define TRACE(printlevel,level,format,args... ) { \ if ( TRACE_BOOL(level) ) { \ const char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed"); \ - fd_log(level, STD_TRACE_FMT_STRING format, \ - __thn, __PRETTY_FUNCTION__, __FILE__, __LINE__, ## args); \ + fd_log((printlevel), STD_TRACE_FMT_STRING format, \ + __thn, __PRETTY_FUNCTION__, __STRIPPED_FILE__, __LINE__, ## args); \ } \ } #else /* DEBUG */ -/* Do not print thread, function, ... only the message itself in this case, unless the debug level is set > FULL. */ -#define TRACE_DEBUG(level,format,args... ) { \ - if ( TRACE_BOOL(level) ) { \ - if (fd_g_debug_lvl > FULL) { \ - const char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed"); \ - fd_log(level, STD_TRACE_FMT_STRING format, \ - __thn, __PRETTY_FUNCTION__, __FILE__, __LINE__, ## args); \ - } else { \ - fd_log(level, format, ## args); \ - } \ - } \ +/* Do not print thread, function, ... only the message itself in this case */ +#define TRACE(printlevel,level,format,args... ) { \ + if ( TRACE_BOOL(level) ) { \ + fd_log((printlevel), format, ## args); \ + } \ } #endif /* DEBUG */ +/* Report debug information */ +#define TRACE_DEBUG(level,format,args... ) \ + TRACE(FD_LOG_DEBUG,(level),format,##args) + +/* Report a normal message that is usefull for normal admin monitoring */ +#define TRACE_NOTICE(format,args... ) \ + TRACE(FD_LOG_NOTICE,INFO,format,##args) + +/* Report an error */ +#define TRACE_ERROR(format,args... ) \ + TRACE(FD_LOG_ERROR, NONE, format, ##args) + +/* +TRACE_NOTICE(...) and fd_log_notice(...) are equivalent when the code is not compiled in DEBUG mode, +but there is more contextual information when compiled in DEBUG with the TRACE_NOTICE macro, +hence it is recommended to use this one except for formatted output (e.g. fd_*_dump function) + +resp. TRACE_DEBUG and TRACE_ERROR. +*/ + /************* - Derivatives from this macro + Derivatives for debug ************/ /* Helper for function entry -- for very detailed trace of the execution */ #define TRACE_ENTRY(_format,_args... ) \ @@ -305,20 +325,37 @@ #endif /* ERRORS_ON_TODO */ /* Trace a binary buffer content */ -#define TRACE_DEBUG_BUFFER(level, prefix, buf, bufsz, suffix ) { \ +#ifdef DEBUG +/* In DEBUG mode, we add (a lot of) meta-information along each trace. This makes multi-threading problems easier to debug. */ +#define TRACE_BUFFER(printlevel, level, prefix, buf, bufsz, suffix ) { \ if ( TRACE_BOOL(level) ) { \ int __i; \ size_t __sz = (size_t)(bufsz); \ uint8_t * __buf = (uint8_t *)(buf); \ + char __strbuf[1024+1]; \ char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed"); \ - 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]); \ + for (__i = 0; (__i < __sz) && (__i<(sizeof(__strbuf)/2)); __i++) { \ + sprintf(__strbuf + (2 * __i), "%2.2hhx", __buf[__i]); \ } \ - fd_log(level, suffix); \ + fd_log(printlevel, STD_TRACE_FMT_STRING "%s%s%s", \ + __thn, __PRETTY_FUNCTION__, __STRIPPED_FILE__, __LINE__, (prefix), __strbuf, (suffix)); \ } \ } +#else /* DEBUG */ +/* Do not print thread, function, ... only the message itself in this case */ +#define TRACE_BUFFER(printlevel, level, prefix, buf, bufsz, suffix ) { \ + if ( TRACE_BOOL(level) ) { \ + int __i; \ + size_t __sz = (size_t)(bufsz); \ + uint8_t * __buf = (uint8_t *)(buf); \ + char __strbuf[1024+1]; \ + for (__i = 0; (__i < __sz) && (__i<(sizeof(__strbuf)/2)); __i++) { \ + sprintf(__strbuf + (2 * __i), "%2.2hhx", __buf[__i]); \ + } \ + fd_log(printlevel, "%s%s%s", (prefix), __strbuf, (suffix)); \ + } \ +} +#endif /* DEBUG */ /* Some aliases to socket addresses structures */ #define sSS struct sockaddr_storage @@ -333,24 +370,24 @@ 0 ) ) ) /* Dump one sockaddr Node information */ -#define sSA_DUMP_NODE( buf, bufsize, sa, flag ) { \ - sSA * __sa = (sSA *)(sa); \ - char __addrbuf[INET6_ADDRSTRLEN]; \ - if (__sa) { \ - int __rc = getnameinfo(__sa, \ - sSAlen(__sa), \ - __addrbuf, \ - sizeof(__addrbuf), \ - NULL, \ - 0, \ - flag); \ - if (__rc) \ +#define sSA_DUMP_NODE( buf, bufsize, sa, flag ) { \ + sSA * __sa = (sSA *)(sa); \ + char __addrbuf[INET6_ADDRSTRLEN]; \ + if (__sa) { \ + int __rc = getnameinfo(__sa, \ + sSAlen(__sa), \ + __addrbuf, \ + sizeof(__addrbuf), \ + NULL, \ + 0, \ + (flag)); \ + if (__rc) \ snprintf(buf, bufsize, "%s", gai_strerror(__rc)); \ - else \ - snprintf(buf, bufsize, "%s", &__addrbuf[0]); \ - } else { \ - snprintf(buf, bufsize, "(NULL / ANY)"); \ - } \ + else \ + snprintf(buf, bufsize, "%s", &__addrbuf[0]); \ + } else { \ + snprintf(buf, bufsize, "(NULL / ANY)"); \ + } \ } /* Same but with the port (service) also */ #define sSA_DUMP_NODE_SERV( buf, bufsize, sa, flag ) { \ @@ -364,7 +401,7 @@ sizeof(__addrbuf), \ __servbuf, \ sizeof(__servbuf), \ - flag); \ + (flag)); \ if (__rc) \ snprintf(buf, bufsize, "%s", gai_strerror(__rc)); \ else \ @@ -374,37 +411,60 @@ } \ } -/* Inside a debug trace */ -#define TRACE_DEBUG_sSA(level, prefix, sa, flags, suffix ) { \ +#ifdef DEBUG +/* In DEBUG mode, we add (a lot of) meta-information along each trace. This makes multi-threading problems easier to debug. */ +#define TRACE_sSA(printlevel, level, prefix, sa, flags, suffix ) { \ if ( TRACE_BOOL(level) ) { \ - char buf[1024]; \ + char __buf[1024]; \ char * __thn = ((char *)pthread_getspecific(fd_log_thname) ?: "unnamed"); \ - 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); \ + sSA_DUMP_NODE_SERV(__buf, sizeof(__buf), sa, flags ); \ + fd_log(printlevel, STD_TRACE_FMT_STRING "%s%s%s" , \ + __thn, __PRETTY_FUNCTION__, __STRIPPED_FILE__, __LINE__, (prefix), __buf, (suffix)); \ } \ } - -/* Report an error */ -#define TRACE_DEBUG_ERROR(format,args... ) \ - TRACE_DEBUG(INFO, format, ##args) +#else /* DEBUG */ +/* Do not print thread, function, ... only the message itself in this case */ +#define TRACE_sSA(printlevel, level, prefix, sa, flags, suffix ) { \ + if ( TRACE_BOOL(level) ) { \ + char __buf[1024]; \ + sSA_DUMP_NODE_SERV(__buf, sizeof(__buf), sa, flags ); \ + fd_log(printlevel, "%s%s%s" , (prefix), __buf, (suffix)); \ + } \ +} +#endif /* DEBUG */ /****************** Optimized code: remove all debugging code **/ #ifdef STRIP_DEBUG_CODE #undef TRACE_DEBUG +#undef TRACE_NOTICE +#undef TRACE_ERROR #undef TRACE_BOOL -#undef TRACE_DEBUG_sSA -#undef TRACE_DEBUG_BUFFER -#undef TRACE_DEBUG_ERROR -#define TRACE_DEBUG(level,format,args... ) -#define TRACE_BOOL(_level_) (0) -#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(FD_LOG_ERROR, format, ## args); \ -} +#undef TRACE_BUFFER +#undef TRACE_sSA + +#define TRACE_DEBUG(level,format,args... ) /* noop */ +#define TRACE_BOOL(_level_) (0) /* always false */ +#define TRACE_NOTICE fd_log_notice +#define TRACE_ERROR fd_log_error +#define TRACE_BUFFER(printlevel, level, prefix, buf, bufsz, suffix ) { \ + if (printlevel > FD_LOG_DEBUG) { \ + int __i; \ + size_t __sz = (size_t)(bufsz); \ + uint8_t * __buf = (uint8_t *)(buf); \ + char * __strbuf[1024+1]; \ + for (__i = 0; (__i < __sz) && (__i<(sizeof(__strbuf)/2); __i++) { \ + sprintf(__strbuf + (2 * __i), "%02.2hhx", __buf[__i]); \ + } \ + fd_log(printlevel, prefix"%s"suffix, __strbuf); \ + } +#define TRACE_sSA(printlevel, level, prefix, sa, flags, suffix ) { \ + if (printlevel > FD_LOG_DEBUG) { \ + char __buf[1024]; \ + sSA_DUMP_NODE_SERV(__buf, sizeof(__buf), sa, flags ); \ + fd_log(printlevel, prefix "%s" suffix, __buf); \ + } #endif /* STRIP_DEBUG_CODE */ @@ -423,7 +483,7 @@ __ret__ = (__call__); \ if (__ret__ < 0) { \ int __err__ = errno; /* We may handle EINTR here */ \ - TRACE_DEBUG_ERROR("ERROR: in '" #__call__ "' :\t%s", strerror(__err__));\ + TRACE_ERROR("ERROR: in '" #__call__ "' :\t%s", strerror(__err__));\ __fallback__; \ } \ } @@ -434,7 +494,7 @@ __ret__ = (__call__); \ if (__ret__ < 0) { \ int __err__ = errno; /* We may handle EINTR here */ \ - TRACE_DEBUG_ERROR("ERROR: in '" #__call__ "' :\t%s", strerror(__err__));\ + TRACE_ERROR("ERROR: in '" #__call__ "' :\t%s", strerror(__err__));\ return __err__; \ } \ } @@ -448,7 +508,7 @@ if (__ret__ == (__speval__)) { \ __fallback1__; \ } else { \ - TRACE_DEBUG_ERROR("ERROR: in '" #__call__ "':\t%s", strerror(__ret__)); \ + TRACE_ERROR("ERROR: in '" #__call__ "':\t%s", strerror(__ret__)); \ __fallback2__; \ } \ } \ @@ -471,7 +531,7 @@ __ret__ = (void *)( __call__ ); \ if (__ret__ == NULL) { \ int __err__ = errno; \ - TRACE_DEBUG_ERROR("ERROR: in '" #__call__ "':\t%s", strerror(__err__)); \ + TRACE_ERROR("ERROR: in '" #__call__ "':\t%s", strerror(__err__)); \ __fallback__; \ } \ } @@ -485,7 +545,7 @@ #define CHECK_PARAMS_DO( __bool__, __fallback__ ) \ TRACE_DEBUG_ALL( "Check PARAMS: " #__bool__ ); \ if ( ! (__bool__) ) { \ - TRACE_DEBUG_ERROR("Warning: Invalid parameter received in '" #__bool__ "'"); \ + TRACE_ERROR("Warning: Invalid parameter received in '" #__bool__ "'"); \ __fallback__; \ } /* Check parameters at function entry, return EINVAL if the boolean is false (similar to assert) */ @@ -498,7 +558,7 @@ TRACE_DEBUG_ALL( "Check FCT: " #__call__ ); \ __ret__ = (__call__); \ if (__ret__ != 0) { \ - TRACE_DEBUG_ERROR("ERROR: in '" #__call__ "':\t%s", strerror(__ret__)); \ + TRACE_ERROR("ERROR: in '" #__call__ "':\t%s", strerror(__ret__)); \ __fallback__; \ } \ }
--- a/libfdcore/config.c Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdcore/config.c Tue Mar 12 17:23:37 2013 +0100 @@ -247,7 +247,7 @@ } if (fddin == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("Unable to open configuration file for reading; tried the following locations: %s%s%s; Error: %s\n", + TRACE_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; }
--- a/libfdcore/fdd.l Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdcore/fdd.l Tue Mar 12 17:23:37 2013 +0100 @@ -51,7 +51,7 @@ #define YY_USER_ACTION { \ yylloc->first_column = yylloc->last_column + 1; \ yylloc->last_column = yylloc->first_column + yyleng - 1; \ - TRACE_DEBUG_ERROR( \ + TRACE_ERROR( \ "(%d:%d-%d:%d) matched rule %d, length=%d, txt='%s'\n", \ yylloc->first_line, yylloc->first_column, \ yylloc->last_line, yylloc->last_column, \ @@ -83,7 +83,7 @@ int globerrfct(const char *epath, int eerrno) { - TRACE_DEBUG_ERROR("Failed to scan %s: %s\n", epath, strerror(eerrno)); + TRACE_ERROR("Failed to scan %s: %s\n", epath, strerror(eerrno)); return 1; } @@ -118,14 +118,14 @@ char * buf = strdup(yytext+1); if (buf[yyleng-2] != '"') { - TRACE_DEBUG_ERROR("Unterminated string: %s\n", yytext); + TRACE_ERROR("Unterminated string: %s\n", yytext); return LEX_ERROR; } buf[yyleng-2] = '\0'; if (current_nested_level >= MAX_NESTED_CONF_FILES) { - TRACE_DEBUG_ERROR("Too many recursion levels in configuration files includes\n"); + TRACE_ERROR("Too many recursion levels in configuration files includes\n"); return LEX_ERROR; } @@ -134,12 +134,12 @@ if (globerror == GLOB_NOSPACE) { - TRACE_DEBUG_ERROR("Not enough memory to parse include directive.\n"); + TRACE_ERROR("Not enough memory to parse include directive.\n"); return LEX_ERROR; } if (globerror == GLOB_ABORTED) { - TRACE_DEBUG_ERROR("An error was encountered in include directive.\n"); + TRACE_ERROR("An error was encountered in include directive.\n"); return LEX_ERROR; } if (globerror == GLOB_NOMATCH) @@ -149,7 +149,7 @@ } if (globerror) { - TRACE_DEBUG_ERROR("Unexpected error in glob (%d).\n", globerror); + TRACE_ERROR("Unexpected error in glob (%d).\n", globerror); return LEX_ERROR; } @@ -165,7 +165,7 @@ if ( ! yyin ) { - TRACE_DEBUG_ERROR("Error in %s: %s", nested_conffiles[current_nested_level].filelist.gl_pathv[0], strerror(errno)); + TRACE_ERROR("Error in %s: %s", nested_conffiles[current_nested_level].filelist.gl_pathv[0], strerror(errno)); return LEX_ERROR; } @@ -205,7 +205,7 @@ if ( ! yyin ) { - TRACE_DEBUG_ERROR("Error in %s: %s", nested_conffiles[current_nested_level].filelist.gl_pathv[nested_conffiles[current_nested_level].current_file], strerror(errno)); + TRACE_ERROR("Error in %s: %s", nested_conffiles[current_nested_level].filelist.gl_pathv[nested_conffiles[current_nested_level].current_file], strerror(errno)); return LEX_ERROR; } @@ -233,7 +233,7 @@ int ret = sscanf(yytext, "%i", &yylval->integer); if (ret != 1) { /* No matching: an error occurred */ - TRACE_DEBUG_ERROR("Unable to convert the value '%s' to a valid number: %s\n", yytext, strerror(errno)); + TRACE_ERROR("Unable to convert the value '%s' to a valid number: %s\n", yytext, strerror(errno)); return LEX_ERROR; /* trig an error in yacc parser */ /* Maybe we could REJECT instead of failing here? */ } @@ -276,7 +276,7 @@ <*>[[:alnum:]]+ | /* This rule is only useful to print a complete token in error messages */ /* Unrecognized character */ <*>. { - TRACE_DEBUG_ERROR("Unrecognized text on line %d col %d: '%s'.\n", yylloc->first_line, yylloc->first_column, yytext); + TRACE_ERROR("Unrecognized text on line %d col %d: '%s'.\n", yylloc->first_line, yylloc->first_column, yytext); return LEX_ERROR; }
--- a/libfdcore/fdd.y Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdcore/fdd.y Tue Mar 12 17:23:37 2013 +0100 @@ -62,11 +62,11 @@ void yyerror (YYLTYPE *ploc, struct fd_config * conf, char const *s) { if (ploc->first_line != ploc->last_line) { - TRACE_DEBUG_ERROR("%s:%d.%d-%d.%d : %s\n", conf->cnf_file, ploc->first_line, ploc->first_column, ploc->last_line, ploc->last_column, s); + TRACE_ERROR("%s:%d.%d-%d.%d : %s\n", conf->cnf_file, ploc->first_line, ploc->first_column, ploc->last_line, ploc->last_column, s); } else if (ploc->first_column != ploc->last_column) { - TRACE_DEBUG_ERROR("%s:%d.%d-%d : %s\n", conf->cnf_file, ploc->first_line, ploc->first_column, ploc->last_column, s); + TRACE_ERROR("%s:%d.%d-%d : %s\n", conf->cnf_file, ploc->first_line, ploc->first_column, ploc->last_column, s); } else { - TRACE_DEBUG_ERROR("%s:%d.%d : %s\n", conf->cnf_file, ploc->first_line, ploc->first_column, s); + TRACE_ERROR("%s:%d.%d : %s\n", conf->cnf_file, ploc->first_line, ploc->first_column, s); } } @@ -327,7 +327,7 @@ } if (fd == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("WARNING: Unable to open extension file %s for reading: %s\nLD_LIBRARY_PATH will be used.\n", fname, strerror(ret)); + TRACE_ERROR("WARNING: Unable to open extension file %s for reading: %s\nLD_LIBRARY_PATH will be used.\n", fname, strerror(ret)); } else { fclose(fd); } @@ -500,7 +500,7 @@ fd = fopen($3, "r"); if (fd == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("Unable to open certificate file %s for reading: %s\n", $3, strerror(ret)); + TRACE_ERROR("Unable to open certificate file %s for reading: %s\n", $3, strerror(ret)); yyerror (&yylloc, conf, "Error on file name"); YYERROR; } @@ -508,7 +508,7 @@ fd = fopen($5, "r"); if (fd == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("Unable to open private key file %s for reading: %s\n", $5, strerror(ret)); + TRACE_ERROR("Unable to open private key file %s for reading: %s\n", $5, strerror(ret)); yyerror (&yylloc, conf, "Error on file name"); YYERROR; } @@ -531,7 +531,7 @@ fd = fopen($3, "rb"); if (fd == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("Unable to open CA file %s for reading: %s\n", $3, strerror(ret)); + TRACE_ERROR("Unable to open CA file %s for reading: %s\n", $3, strerror(ret)); yyerror (&yylloc, conf, "Error on file name"); YYERROR; } @@ -571,7 +571,7 @@ fd = fopen($3, "rb"); if (fd == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("Unable to open CRL file %s for reading: %s\n", $3, strerror(ret)); + TRACE_ERROR("Unable to open CRL file %s for reading: %s\n", $3, strerror(ret)); yyerror (&yylloc, conf, "Error on file name"); YYERROR; } @@ -614,7 +614,7 @@ conf->cnf_sec_data.prio_string, &err_pos), { yyerror (&yylloc, conf, "Error setting Priority parameter."); - TRACE_DEBUG_ERROR("Error at position : %s\n", err_pos); + TRACE_ERROR("Error at position : %s\n", err_pos); YYERROR; } ); } ; @@ -631,7 +631,7 @@ fd = fopen($3, "r"); if (fd == NULL) { int ret = errno; - TRACE_DEBUG_ERROR("Unable to open DH file %s for reading: %s\n", $3, strerror(ret)); + TRACE_ERROR("Unable to open DH file %s for reading: %s\n", $3, strerror(ret)); yyerror (&yylloc, conf, "Error on file name"); YYERROR; }
--- a/libfdcore/sctp.c Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdcore/sctp.c Tue Mar 12 17:23:37 2013 +0100 @@ -747,7 +747,7 @@ ptr.sa = sar; fd_log_debug("Calling sctp_bindx with the following address array:\n"); for (i = 0; i < count; i++) { - TRACE_DEBUG_sSA(FULL, " - ", ptr.sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_sSA(FD_LOG_DEBUG, FULL, " - ", ptr.sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); ptr.buf += (ptr.sa->sa_family == AF_INET) ? sizeof(sSA4) : sizeof(sSA6) ; } } @@ -775,7 +775,7 @@ fd_log_debug("SCTP server bound on :\n"); for (ptr.sa = sar; sz-- > 0; ptr.buf += (ptr.sa->sa_family == AF_INET) ? sizeof(sSA4) : sizeof(sSA6)) { - TRACE_DEBUG_sSA(FULL, " - ", ptr.sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_sSA(FD_LOG_DEBUG, FULL, " - ", ptr.sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); } sctp_freeladdrs(sar); } @@ -841,7 +841,7 @@ int i; ptr.buf = sar.buf; for (i=0; i< count; i++) { - TRACE_DEBUG_sSA(FULL, " - ", ptr.sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_sSA(FD_LOG_DEBUG, FULL, " - ", ptr.sa, NI_NUMERICHOST | NI_NUMERICSERV, "" ); ptr.buf += (ptr.sa->sa_family == AF_INET) ? sizeof(sSA4) : sizeof(sSA6); } } @@ -1150,7 +1150,7 @@ case SCTP_PEER_ADDR_CHANGE: TRACE_DEBUG(FULL, "Received SCTP_PEER_ADDR_CHANGE notification"); - TRACE_DEBUG_sSA(SCTP_LEVEL, " intf_change : ", &(notif->sn_paddr_change.spc_aaddr), NI_NUMERICHOST | NI_NUMERICSERV, "" ); + TRACE_sSA(FD_LOG_DEBUG, SCTP_LEVEL, " intf_change : ", &(notif->sn_paddr_change.spc_aaddr), NI_NUMERICHOST | NI_NUMERICSERV, "" ); TRACE_DEBUG(SCTP_LEVEL, " state : %d", notif->sn_paddr_change.spc_state); TRACE_DEBUG(SCTP_LEVEL, " error : %d", notif->sn_paddr_change.spc_error);
--- a/libfdcore/sctps.c Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdcore/sctps.c Tue Mar 12 17:23:37 2013 +0100 @@ -342,7 +342,7 @@ CHECK_PARAMS_DO( sto && key.data && data.data, return -1 ); CHECK_POSIX_DO( pthread_rwlock_wrlock(&sto->lock), return -1 ); - TRACE_DEBUG_BUFFER(GNUTLS_DBG_LEVEL, "Session store [key ", key.data, key.size, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, GNUTLS_DBG_LEVEL, "Session store [key ", key.data, key.size, "]"); li = find_or_next(sto, key, &match); if (match) { @@ -351,9 +351,9 @@ /* Check the data is the same */ if ((data.size != sr->data.size) || memcmp(data.data, sr->data.data, data.size)) { TRACE_DEBUG(INFO, "GnuTLS tried to store a session with same key and different data!"); - TRACE_DEBUG_BUFFER(INFO, "Session store [key ", key.data, key.size, "]"); - TRACE_DEBUG_BUFFER(INFO, " -- old data [", sr->data.data, sr->data.size, "]"); - TRACE_DEBUG_BUFFER(INFO, " -- new data [", data.data, data.size, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, INFO, "Session store [key ", key.data, key.size, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, INFO, " -- old data [", sr->data.data, sr->data.size, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, INFO, " -- new data [", data.data, data.size, "]"); ret = -1; } else { @@ -396,7 +396,7 @@ CHECK_PARAMS_DO( sto && key.data, return -1 ); CHECK_POSIX_DO( pthread_rwlock_wrlock(&sto->lock), return -1 ); - TRACE_DEBUG_BUFFER(GNUTLS_DBG_LEVEL, "Session delete [key ", key.data, key.size, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, GNUTLS_DBG_LEVEL, "Session delete [key ", key.data, key.size, "]"); li = find_or_next(sto, key, &match); if (match) { @@ -429,7 +429,7 @@ CHECK_PARAMS_DO( sto && key.data, return error ); CHECK_POSIX_DO( pthread_rwlock_rdlock(&sto->lock), return error ); - TRACE_DEBUG_BUFFER(GNUTLS_DBG_LEVEL, "Session fetch [key ", key.data, key.size, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, GNUTLS_DBG_LEVEL, "Session fetch [key ", key.data, key.size, "]"); li = find_or_next(sto, key, &match); if (match) { @@ -556,7 +556,7 @@ uint8_t id[256]; size_t ids = sizeof(id); CHECK_GNUTLS_DO( gnutls_session_get_id(conn->cc_tls_para.session, id, &ids), /* continue */ ); - TRACE_DEBUG_BUFFER(GNUTLS_DBG_LEVEL, "Master session id: [", id, ids, "]"); + TRACE_BUFFER(FD_LOG_DEBUG, GNUTLS_DBG_LEVEL, "Master session id: [", id, ids, "]"); } }
--- a/libfdcore/tcp.c Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdcore/tcp.c Tue Mar 12 17:23:37 2013 +0100 @@ -136,7 +136,7 @@ /* Cleanup if we are cancelled */ pthread_cleanup_push(fd_cleanup_socket, &s); - TRACE_DEBUG_sSA(FULL, "Attempting TCP connection with peer: ", sa, NI_NUMERICHOST | NI_NUMERICSERV, "..." ); + TRACE_sSA(FD_LOG_DEBUG, FULL, "Attempting TCP connection with peer: ", sa, NI_NUMERICHOST | NI_NUMERICSERV, "..." ); /* Try connecting to the remote address */ ret = connect(s, sa, salen);
--- a/libfdproto/log.c Sat Mar 09 16:55:20 2013 +0100 +++ b/libfdproto/log.c Tue Mar 12 17:23:37 2013 +0100 @@ -94,7 +94,13 @@ /* logging has been decided by macros outside already */ /* add timestamp */ - fprintf(fd_g_debug_fstr, "%s\t", fd_log_time(NULL, buf, sizeof(buf))); + fprintf(fd_g_debug_fstr, "%s ", fd_log_time(NULL, buf, sizeof(buf))); + switch(loglevel) { + case FD_LOG_DEBUG: fprintf(fd_g_debug_fstr, " DBG "); break; + case FD_LOG_NOTICE: fprintf(fd_g_debug_fstr, "NOTI "); break; + case FD_LOG_ERROR: fprintf(fd_g_debug_fstr, "ERROR "); break; + default: fprintf(fd_g_debug_fstr, " ??? "); + } vfprintf(fd_g_debug_fstr, format, ap); if (format && (format[strlen(format)-1] != '\n')) { fprintf(fd_g_debug_fstr, "\n");