From 182cadaf7ed085e00356f6c700875aeeae9c8660 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=A0=D1=83=D1=81=D0=BB=D0=B0=D0=BD=20=D0=98=D0=B6=D0=B1=D1?= =?UTF-8?q?=83=D0=BB=D0=B0=D1=82=D0=BE=D0=B2?= Date: Sat, 1 Oct 2011 18:50:52 +0400 Subject: [PATCH 3/5] Further refinements to the logger * Added GNUNET_ERROR_TYPE_UNSPECIFIED enum value, to hold -1. Its corresponding string is NULL. * Changed the logger calls as Grothoff suggested - to use static int to hold the result of runtime evaluation of logability. Logging can be unconditionally disabled in advance by defining GNUNET_LOG_CALL_STATUS to 0, and enabled in advance by defining it to 1. * Added GNUNET_CULL_LOGGING, which, if defined, completely culls out all logging calls at compile time. * Log definition parsing is only done once, results are cached. * Changed definition format, now it looks like this: [component|*|];[file|*|];[function|*|];[from_line[-to_line]];level/[component...] All field separators are mandatory (but some fields could be empty or be '*'). Line definition must be either empty or "number" or "number-number" Level definition must not be empty, and is a string representation of the level (i.e. DEBUG, WARNING, INFO, etc). Definition entry must end with a slash, whether or not there's another entry after it. File name is matched to the end of __FILE__, which allows file name to match not only the base name, but also directories leading to it. * Removed default WARNING loglevel from program and service utility code. Now they default to NULL (UNSPECIFIED) level, which can be overriden by GNUNET_LOG definition, if no level is specified via config or commandline. Log levels from config or commandline are overriden by GNUNET_FORCE_LOG. If GNUNET_*LOG are undefined, and no levels came from config or commandline, logger internally defaults to WARNING level. --- src/include/gnunet_common.h | 51 ++++--- src/util/common_logging.c | 379 +++++++++++++++++++++++-------------------- src/util/program.c | 4 +- src/util/service.c | 4 +- 4 files changed, 238 insertions(+), 200 deletions(-) diff --git a/src/include/gnunet_common.h b/src/include/gnunet_common.h index c14363f..5be11df 100644 --- a/src/include/gnunet_common.h +++ b/src/include/gnunet_common.h @@ -138,6 +138,7 @@ typedef int (*GNUNET_FileNameCallback) (void *cls, const char *filename); */ enum GNUNET_ErrorType { + GNUNET_ERROR_TYPE_UNSPECIFIED = -1, GNUNET_ERROR_TYPE_NONE = 0, GNUNET_ERROR_TYPE_ERROR = 1, GNUNET_ERROR_TYPE_WARNING = 2, @@ -171,7 +172,10 @@ extern enum GNUNET_ErrorType min_level; * Number of log calls to ignore. */ extern unsigned int skip_log; - +#if !defined(GNUNET_CULL_LOGGING) +int +get_log_call_status (int caller_level, const char *comp, const char *file, const char *function, int line); +#endif /** * Main log function. * @@ -200,14 +204,9 @@ GNUNET_log_nocheck (enum GNUNET_ErrorType kind, const char *message, ...); #define GN_UNLIKELY(expr) (expr) #endif -#define GNUNET_log(kind,...) do {\ - if (GN_UNLIKELY(skip_log > 0)) {skip_log--;}\ - else {\ - if (GN_UNLIKELY(((kind) & (~GNUNET_ERROR_TYPE_BULK)) <= min_level))\ - GNUNET_log_nocheck (kind, __VA_ARGS__);\ - }\ -} while (0) - +#if !defined(GNUNET_LOG_CALL_STATUS) +#define GNUNET_LOG_CALL_STATUS -1 +#endif /** * Log function that specifies an alternative component. @@ -222,20 +221,32 @@ void GNUNET_log_from_nocheck (enum GNUNET_ErrorType kind, const char *comp, const char *message, ...); -#define GNUNET_log_from(kind,...) \ -do\ -{\ - if (GN_UNLIKELY(skip_log > 0))\ - {\ - skip_log--;\ - }\ - else\ - {\ - if (GN_UNLIKELY(((kind) & (~GNUNET_ERROR_TYPE_BULK)) <= min_level))\ - GNUNET_log_from_nocheck (kind, __VA_ARGS__);\ +#if !defined(GNUNET_CULL_LOGGING) +#define GNUNET_log_from(kind,comp,...) do { int log_line = __LINE__;\ + static int log_call_enabled = GNUNET_LOG_CALL_STATUS;\ + if (GN_UNLIKELY(log_call_enabled == -1))\ + log_call_enabled = get_log_call_status ((kind) & (~GNUNET_ERROR_TYPE_BULK), comp, __FILE__, __FUNCTION__, log_line);\ + if (GN_UNLIKELY(skip_log > 0)) {skip_log--;}\ + else {\ + if (GN_UNLIKELY(log_call_enabled))\ + GNUNET_log_from_nocheck (kind, comp, __VA_ARGS__);\ }\ } while (0) +#define GNUNET_log(kind,...) do { int log_line = __LINE__;\ + static int log_call_enabled = GNUNET_LOG_CALL_STATUS;\ + if (GN_UNLIKELY(log_call_enabled == -1))\ + log_call_enabled = get_log_call_status ((kind) & (~GNUNET_ERROR_TYPE_BULK), NULL, __FILE__, __FUNCTION__, log_line);\ + if (GN_UNLIKELY(skip_log > 0)) {skip_log--;}\ + else {\ + if (GN_UNLIKELY(log_call_enabled))\ + GNUNET_log_nocheck (kind, __VA_ARGS__);\ + }\ +} while (0) +#else +#define GNUNET_log(...) +#define GNUNET_log_from(...) +#endif /** * Ignore the next n calls to the log function. diff --git a/src/util/common_logging.c b/src/util/common_logging.c index cb63f2f..06f5f76 100644 --- a/src/util/common_logging.c +++ b/src/util/common_logging.c @@ -115,6 +115,11 @@ static char last_bulk_comp[COMP_TRACK_SIZE + 1]; static char *component; /** + * Running component (without pid). + */ +static char *component_nopid; + +/** * Minimum log level. */ enum GNUNET_ErrorType min_level; @@ -134,6 +139,26 @@ unsigned int skip_log; */ static FILE *GNUNET_stderr; +struct LogDef +{ + char *component; + char *file; + int strlen_file; + char *function; + int from_line; + int to_line; + int level; + int force; +}; + +struct LogDef *logdefs = NULL; +int logdefs_size = 0; +int logdefs_len = 0; + +int gnunet_log_parsed = GNUNET_NO; +int gnunet_force_log_parsed = GNUNET_NO; +int gnunet_force_log_present = GNUNET_NO; + #ifdef WINDOWS /** * Contains the number of performance counts per second. @@ -151,6 +176,8 @@ LARGE_INTEGER performance_frequency; static enum GNUNET_ErrorType get_type (const char *log) { + if (log == NULL) + return GNUNET_ERROR_TYPE_UNSPECIFIED; if (0 == strcasecmp (log, _("DEBUG"))) return GNUNET_ERROR_TYPE_DEBUG; if (0 == strcasecmp (log, _("INFO"))) @@ -163,193 +190,205 @@ get_type (const char *log) return GNUNET_ERROR_TYPE_NONE; return GNUNET_ERROR_TYPE_INVALID; } +#if !defined(GNUNET_CULL_LOGGING) +static void +resize_logdefs () +{ + logdefs_size = (logdefs_size + 1) * 2; + logdefs = GNUNET_realloc (logdefs, logdefs_size * sizeof (struct LogDef)); +} static void -process_definition (char *name, const char *comp, int blevel, int tlevel, int *bot, int *top) +add_definition (char *component, char *file, char *function, int from_line, int to_line, int level, int force) { - if (name[0] != '*' && strcmp (name, comp) != 0) - return; - if (blevel != -1 && blevel > *bot) - *bot = blevel; - if (tlevel != -1 && (tlevel < *top || *top < 0)) - *top = tlevel; + if (logdefs_size == logdefs_len) + resize_logdefs (); + struct LogDef n; + memset (&n, 0, sizeof (n)); + if (strlen (component) > 0 && component[0] != '*') + n.component = strdup (component); + if (strlen (file) > 0 && file[0] != '*') + { + n.file = strdup (file); + n.strlen_file = strlen (file); + } + if (strlen (function) > 0 && function[0] != '*') + n.function = strdup (function); + n.from_line = from_line; + n.to_line = to_line; + n.level = level; + n.force = force; + logdefs[logdefs_len++] = n; +} + +int +get_log_call_status (int caller_level, const char *comp, const char *file, const char *function, int line) +{ + struct LogDef *ld; + int i; + int force_only; + size_t strlen_file; + if (comp == NULL) + comp = component_nopid; + if (min_level >= 0 && gnunet_force_log_present == GNUNET_NO) + return caller_level <= min_level; + force_only = min_level >= 0; + strlen_file = strlen (file); + for (i = 0; i < logdefs_len; i++) + { + ld = &logdefs[i]; + if ((!force_only || ld->force) && + (caller_level <= ld->level) && + (line >= ld->from_line && line <= ld->to_line) && + (ld->component == NULL || strcmp (comp, ld->component) == 0) && + (ld->file == NULL || + (ld->strlen_file <= strlen_file && + strcmp (&file[strlen_file - ld->strlen_file], ld->file) == 0)) && + (ld->function == NULL || strcmp (function, ld->function) == 0) + ) + { + return 1; + } + } + if (min_level >= 0) + return caller_level <= min_level; + /* All programs/services previously defaulted to WARNING. + * Now WE default to WARNING, and THEY default to NULL. + */ + return caller_level <= GNUNET_ERROR_TYPE_WARNING; } /** - * Get a string component loglevel definition from the environment, - * and match @comp against it. If it matches, set @bot and @top to - * the values from the definition (or to defaults, if definition omits them). - * Definition format looks like this: - * name[/bottomlevel[/toplevel]]/... - * name must not include slashes, and must begin with a non-digit char. - * name may be * to indicate that this applies to all components - * (there is, however, no wildcard matching algorithm at the moment). - * bottomlevel and toplevel must be valid non-negative integers. - * bottomlevel and toplevel can be zero-length (useful, if you want to - * specify toplevel, but not bottomlevel). - * - * @param comp component name to match - * @param bot pointer to an integer receiving bottom log threshold - * @param top pointer to an integer receiving top log threshold + * Definition format: + * component;file;function;from_line-to_line;level/component... + * All entries are mandatory, but may be empty. + * Empty entries for component, file and function are treated as + * "matches anything". + * Empty line entry is treated as "from 0 to INT_MAX" + * Line entry with only one line is treated as "this line only" + * Entry for level MUST NOT be empty. + * Entries for component, file and function that consist of a + * single character "*" are treated (at the moment) the same way + * empty entries are treated (wildcard matching is not implemented (yet?)). + * file entry is matched to the end of __FILE__. That is, it might be + * a base name, or a base name with leading directory names. */ -static void -get_component_log_levels (const char *comp, int *bot, int *top) +static int +parse_definitions (const char *constname, int force) { - const char *logdef; + char *def; + const char *tmp; + char *comp = NULL; + char *file = NULL; + char *function = NULL; char *p; char *start; + char *t; short state; - char *tmp; - char *name = NULL; - int blevel, tlevel; - logdef = getenv ("GNUNET_LOG"); - if (logdef == NULL) - return; - tmp = strdup (logdef); - for (p = tmp, state = 0, start = tmp; p[0] != '\0'; p++) + int level; + int from_line, to_line; + int counter = 0; + tmp = getenv (constname); + if (tmp == NULL) + return 0; + def = strdup (tmp); + level = -1; + from_line = 0; + to_line = INT_MAX; + for (p = def, state = 0, start = def; p[0] != '\0'; p++) { - if (state == 0) + switch (p[0]) { - /* beginning of the string - must not be digit, and must not be slash */ - if ((p[0] >= '0' && p[0] <= '9') || (p[0] == '/')) + case ';': + p[0] = '\0'; + switch (state) { - free (tmp); - return; - } - blevel = -1; - tlevel = -1; - state = 1; - continue; - } - if (state == 1) - { - /* within a name, ends with a slash */ - if (p[0] == '/') - { - p[0] = '\0'; - state = 2; - name = start; - start = p + 1; - } - continue; - } - if (state == 2) - { - /* after a name there will be either another name, or bottomlevel */ - if (p[0] >= '0' && p[1] <= '9') - { - /* bottomlevel */ - state = 3; - } - else if (p[0] == '/') - { - blevel = -1; - /* bottomlevel is 0-length, look for toplevel */ - state = 4; - start = p + 1; - } - else - { - state = 0; - start = p; - /* another name starts, process what we've got */ - process_definition (name, comp, blevel, tlevel, bot, top); - p--; - } - continue; - } - if (state == 3) - { - /* within a bottomlevel, consists of digits, ends with a slash */ - if (p[0] == '/') - { - p[0] = '\0'; + case 0: /* within a component name */ + comp = start; + break; + case 1: + /* after a component name there must be a file name */ + file = start; + break; + case 2: + /* after a file name there must be a function name */ + function = start; + break; + case 3: + /* after a function name there must be a from-to line definition */ if (strlen (start) > 0) { errno = 0; - blevel = strtol (start, NULL, 10); - if (errno != 0 || blevel < 0) + from_line = strtol (start, &t, 10); + if (errno != 0 || from_line < 0) { - free (tmp); - return; + free (def); + return counter; } + if (t < p && t[0] == '-') + { + errno = 0; + start = t + 1; + to_line = strtol (start, &t, 10); + if (errno != 0 || to_line < 0 || t != p) + { + free (def); + return counter; + } + } + else + to_line = from_line; } - start = p + 1; - /* look for toplevel or for a new name */ - state = 4; - } - else if (p[0] < '0' || p[1] > '9') - { - free (tmp); - return; - } - continue; - } - if (state == 4) - { - /* after a bottomlevel there will be either a new name, or toplevel */ - if (p[0] >= '0' && p[1] <= '9') - { - /* toplevel */ - state = 5; - } - else if (p[0] == '/') - { - tlevel = -1; - /* toplevel is 0-length, look for a new name */ - state = 0; - start = p + 1; - /* process what we've got */ - process_definition (name, comp, blevel, tlevel, bot, top); - } - else - { - state = 0; - start = p; - /* another name starts, process what we've got */ - process_definition (name, comp, blevel, tlevel, bot, top); - p--; + else + { + from_line = 0; + to_line = INT_MAX; + } + break; } - continue; - } - if (state == 5) - { - /* within a toplevel, consists of digits, ends with a slash */ - if (p[0] == '/') + start = p + 1; + state += 1; + break; + case '/': + switch (state) { + case 4: + /* after a from-to line definition there must be a level definition */ p[0] = '\0'; - if (strlen (start) > 0) + state = 0; + level = get_type ((const char *) start); + if (level == GNUNET_ERROR_TYPE_INVALID || level == GNUNET_ERROR_TYPE_UNSPECIFIED) { - errno = 0; - tlevel = strtol (start, NULL, 10); - if (errno != 0 || tlevel < 0) - { - free (tmp); - return; - } + free (def); + return counter; } + add_definition (comp, file, function, from_line, to_line, level, force); + counter += 1; start = p + 1; - /* look for a new name */ - state = 0; - /* another name starts, process what we've got */ - process_definition (name, comp, blevel, tlevel, bot, top); + break; + default: + break; } - else if (p[0] < '0' || p[1] > '9') - { - free (tmp); - return; - } - continue; + default: + break; } - free (tmp); - return; - } - if (state == 2) - { } + free (def); + return counter; } +static void +parse_all_definitions () +{ + if (gnunet_log_parsed == GNUNET_NO) + parse_definitions ("GNUNET_LOG", 0); + gnunet_log_parsed = GNUNET_YES; + if (gnunet_force_log_parsed == GNUNET_NO) + gnunet_force_log_present = parse_definitions ("GNUNET_FORCE_LOG", 1) > 0 ? GNUNET_YES : GNUNET_NO; + gnunet_force_log_parsed = GNUNET_YES; +} +#endif /** * Setup logging. * @@ -364,33 +403,18 @@ GNUNET_log_setup (const char *comp, const char *loglevel, const char *logfile) FILE *altlog; int dirwarn; char *fn; - const char *env_loglevel; - int env_bottom_level = 0; - int env_top_level = 100000; - int comp_bottom_level = -1; - int comp_top_level = -1; + min_level = get_type (loglevel); +#if !defined(GNUNET_CULL_LOGGING) + parse_all_definitions (); +#endif #ifdef WINDOWS QueryPerformanceFrequency (&performance_frequency); #endif GNUNET_free_non_null (component); GNUNET_asprintf (&component, "%s-%d", comp, getpid ()); - env_loglevel = getenv ("GNUNET_BOTTOM_LOGLEVEL"); - if (env_loglevel != NULL) - env_bottom_level = get_type (env_loglevel); - env_loglevel = getenv ("GNUNET_TOP_LOGLEVEL"); - if (env_loglevel != NULL) - env_top_level = get_type (env_loglevel); - get_component_log_levels (comp, &comp_bottom_level, &comp_top_level); - if (comp_bottom_level != -1) - env_bottom_level = comp_bottom_level; - if (comp_top_level != -1) - env_top_level = comp_top_level; - min_level = get_type (loglevel); - if (env_bottom_level > min_level) - min_level = env_bottom_level; - if (env_top_level < min_level) - min_level = env_top_level; + GNUNET_free_non_null (component_nopid); + component_nopid = strdup (comp); if (logfile == NULL) return GNUNET_OK; fn = GNUNET_STRINGS_filename_expand (logfile); @@ -659,6 +683,9 @@ GNUNET_log_from_nocheck (enum GNUNET_ErrorType kind, const char *comp, va_list va; char comp_w_pid[128]; + if (comp == NULL) + comp = component_nopid; + va_start (va, message); GNUNET_snprintf (comp_w_pid, sizeof (comp_w_pid), "%s-%d", comp, getpid ()); mylog (kind, comp_w_pid, message, va); diff --git a/src/util/program.c b/src/util/program.c index d89b65a..b092153 100644 --- a/src/util/program.c +++ b/src/util/program.c @@ -210,7 +210,7 @@ GNUNET_PROGRAM_run (int argc, char *const *argv, const char *binaryName, cnt += sizeof (defoptions) / sizeof (struct GNUNET_GETOPT_CommandLineOption); qsort (allopts, cnt, sizeof (struct GNUNET_GETOPT_CommandLineOption), &cmd_sorter); - loglev = GNUNET_strdup ("WARNING"); + loglev = NULL; cc.cfgfile = GNUNET_strdup (GNUNET_DEFAULT_USER_CONFIG_FILE); lpfx = GNUNET_strdup (binaryName); if (NULL != (spc = strstr (lpfx, " "))) @@ -248,7 +248,7 @@ GNUNET_PROGRAM_run (int argc, char *const *argv, const char *binaryName, /* clean up */ GNUNET_CONFIGURATION_destroy (cfg); GNUNET_free_non_null (cc.cfgfile); - GNUNET_free (loglev); + GNUNET_free_non_null (loglev); GNUNET_free_non_null (logfile); return GNUNET_OK; } diff --git a/src/util/service.c b/src/util/service.c index dc6a733..ad74d27 100644 --- a/src/util/service.c +++ b/src/util/service.c @@ -1542,7 +1542,7 @@ GNUNET_SERVICE_run (int argc, char *const *argv, const char *serviceName, err = 1; do_daemonize = 0; logfile = NULL; - loglev = GNUNET_strdup ("WARNING"); + loglev = NULL; cfg_fn = GNUNET_strdup (GNUNET_DEFAULT_USER_CONFIG_FILE); memset (&sctx, 0, sizeof (sctx)); sctx.options = opt; @@ -1611,7 +1611,7 @@ shutdown: GNUNET_free_non_null (sctx.addrs); GNUNET_free_non_null (sctx.addrlens); GNUNET_free_non_null (logfile); - GNUNET_free (loglev); + GNUNET_free_non_null (loglev); GNUNET_free (cfg_fn); GNUNET_free_non_null (sctx.v4_denied); GNUNET_free_non_null (sctx.v6_denied); -- 1.7.4