From 9a444de20a7545d1c3d10bd242f317febded25c4 Mon Sep 17 00:00:00 2001 From: Arnaud Giersch Date: Sat, 5 Nov 2011 22:12:11 +0100 Subject: [PATCH] Avoid (almost) duplicated code in xbt_log_layout_*. Remove the dynamic log layout function. The layout functions now try to build the log string in a buffer of given length, and return success or failure. The first try is with a buffer of fixed size. In case of failure, the buffer is expanded, until it is large enough. With this change, the code is much simpler, and the only penalty is with very large log strings. --- include/xbt/log.h | 9 +- src/xbt/log.c | 70 +++++++++--- src/xbt/log_private.h | 10 +- src/xbt/xbt_log_layout_format.c | 190 ++------------------------------ src/xbt/xbt_log_layout_simple.c | 51 ++------- 5 files changed, 76 insertions(+), 254 deletions(-) diff --git a/include/xbt/log.h b/include/xbt/log.h index 2b91a5c0b5..4338b655c2 100644 --- a/include/xbt/log.h +++ b/include/xbt/log.h @@ -1,6 +1,6 @@ /* log - a generic logging facility in the spirit of log4j */ -/* Copyright (c) 2004, 2005, 2006, 2007, 2008, 2009, 2010. The SimGrid Team. +/* Copyright (c) 2004-2011. The SimGrid Team. * All rights reserved. */ /* This program is free software; you can redistribute it and/or modify it @@ -242,8 +242,6 @@ typedef struct xbt_log_category_s s_xbt_log_category_t, * Do NOT access any members of this structure directly. FIXME: move to private? */ -#define XBT_LOG_BUFF_SIZE 127 /* Size of the static string in which we build the log string */ - struct xbt_log_category_s { xbt_log_category_t parent; xbt_log_category_t firstChild; @@ -263,8 +261,8 @@ struct xbt_log_event_s { const char *functionName; int lineNum; va_list ap; - va_list ap_copy; /* need a copy to launch dynamic layouts when the static ones overflowed */ - char buffer[XBT_LOG_BUFF_SIZE]; + char *buffer; + int buffer_size; }; /** @@ -405,7 +403,6 @@ extern xbt_log_layout_t xbt_log_default_layout; _log_ev.fileName = __FILE__; \ _log_ev.functionName = _XBT_FUNCTION; \ _log_ev.lineNum = __LINE__; \ - memset(_log_ev.buffer, 0, XBT_LOG_BUFF_SIZE); \ _xbt_log_event_log(&_log_ev, __VA_ARGS__); \ } \ } while (0) diff --git a/src/xbt/log.c b/src/xbt/log.c index 6915419132..fdbe8b875a 100644 --- a/src/xbt/log.c +++ b/src/xbt/log.c @@ -1,6 +1,6 @@ /* log - a generic logging facility in the spirit of log4j */ -/* Copyright (c) 2004, 2005, 2006, 2007, 2008, 2009, 2010. The SimGrid Team. +/* Copyright (c) 2004-2011. The SimGrid Team. * All rights reserved. */ /* This program is free software; you can redistribute it and/or modify it @@ -604,30 +604,68 @@ void xbt_log_postexit(void) log_cat_exit(&_XBT_LOGV(XBT_LOG_ROOT_CAT)); } +#define XBT_LOG_STATIC_BUFFER_SIZE 2048 /* Size of the static string in which we + * build the log string */ +#define XBT_LOG_DYNAMIC_BUFFER_SIZE 256 /* Minimum size of the dynamic string in + * which we build the log string */ + void _xbt_log_event_log(xbt_log_event_t ev, const char *fmt, ...) { - xbt_log_category_t cat = ev->cat; - va_start(ev->ap, fmt); - va_start(ev->ap_copy, fmt); - while (1) { + xbt_assert(ev->priority >= 0, + "Negative logging priority naturally forbidden"); + xbt_assert(ev->priority < sizeof(xbt_log_priority_names), + "Priority %d is greater than the biggest allowed value", + ev->priority); + + do { xbt_log_appender_t appender = cat->appender; - if (appender != NULL) { - xbt_assert(cat->layout, - "No valid layout for the appender of category %s", - cat->name); - cat->layout->do_layout(cat->layout, ev, fmt, appender); + + if (!appender) + continue; /* No appender, try next */ + + xbt_assert(cat->layout, + "No valid layout for the appender of category %s", cat->name); + + /* First, try with a static buffer */ + if (XBT_LOG_STATIC_BUFFER_SIZE) { + char buff[XBT_LOG_STATIC_BUFFER_SIZE]; + int done; + ev->buffer = buff; + ev->buffer_size = sizeof buff; + va_start(ev->ap, fmt); + done = cat->layout->do_layout(cat->layout, ev, fmt); + va_end(ev->ap); + if (done) { + appender->do_append(appender, buff); + continue; /* Ok, that worked: go next */ + } } - if (!cat->additivity) - break; - cat = cat->parent; - } - va_end(ev->ap); - va_end(ev->ap_copy); + /* The static buffer was too small, use a dynamically expanded one */ + ev->buffer_size = MAX(2 * XBT_LOG_STATIC_BUFFER_SIZE, + XBT_LOG_DYNAMIC_BUFFER_SIZE); + ev->buffer = xbt_malloc(ev->buffer_size); + while (1) { + int done; + va_start(ev->ap, fmt); + done = cat->layout->do_layout(cat->layout, ev, fmt); + va_end(ev->ap); + if (done) + break; /* Got it */ + ev->buffer_size *= 2; + ev->buffer = xbt_realloc(ev->buffer, ev->buffer_size); + } + appender->do_append(appender, ev->buffer); + xbt_free(ev->buffer); + + } while (cat->additivity && (cat = cat->parent, 1)); } +#undef XBT_LOG_DYNAMIC_BUFFER_SIZE +#undef XBT_LOG_STATIC_BUFFER_SIZE + /* NOTE: * * The standard logging macros use _XBT_LOG_ISENABLED, which calls diff --git a/src/xbt/log_private.h b/src/xbt/log_private.h index 5ae1d5a626..56692e6d39 100644 --- a/src/xbt/log_private.h +++ b/src/xbt/log_private.h @@ -1,6 +1,4 @@ -/* $Id: log.c 4794 2007-10-10 12:38:37Z mquinson $ */ - -/* Copyright (c) 2007, 2008, 2009, 2010. The SimGrid Team. +/* Copyright (c) 2007-2011. The SimGrid Team. * All rights reserved. */ /* This program is free software; you can redistribute it and/or modify it @@ -17,14 +15,12 @@ struct xbt_log_appender_s { }; struct xbt_log_layout_s { - void (*do_layout) (xbt_log_layout_t l, - xbt_log_event_t event, const char *fmt, - xbt_log_appender_t appender); + int (*do_layout) (xbt_log_layout_t l, + xbt_log_event_t event, const char *fmt); void (*free_) (xbt_log_layout_t l); void *data; }; - /** * \ingroup XBT_log_implem * \param cat the category (not only its name, but the variable) diff --git a/src/xbt/xbt_log_layout_format.c b/src/xbt/xbt_log_layout_format.c index 67ab93d2cc..d8d39e03ca 100644 --- a/src/xbt/xbt_log_layout_format.c +++ b/src/xbt/xbt_log_layout_format.c @@ -1,6 +1,6 @@ /* layout_simple - a dumb log layout */ -/* Copyright (c) 2007, 2008, 2009, 2010. The SimGrid Team. +/* Copyright (c) 2007-2011. The SimGrid Team. * All rights reserved. */ /* This program is free software; you can redistribute it and/or modify it @@ -18,37 +18,6 @@ extern const char *xbt_log_priority_names[8]; static double format_begin_of_time = -1; -#define append(data,letter) \ - do { \ - if (precision == -1 && length == -1) { \ - tmp = bprintf("%" letter, data); \ - } else if (precision == -1) { \ - sprintf(tmpfmt,"%%%d" letter,length); \ - tmp = bprintf(tmpfmt, data); \ - length = -1; \ - } else if (length == -1) { \ - tmp = bprintf("%.*" letter, precision, data);\ - precision = -1; \ - } else { \ - sprintf(tmpfmt,"%%%d.*" letter,length); \ - tmp = bprintf(tmpfmt, precision, data); \ - length = precision = -1; \ - } \ - xbt_strbuff_append(buff,tmp);\ - free(tmp); \ - } while (0) - -#define append_string(data) append(data, "s") -#define append_int(data) append(data, "d") -#define append_double(data) append(data, "f") - -#define append2(fmt,elm,elm2) \ - do { \ - xbt_strbuff_append(buff, tmp=bprintf(fmt,elm,elm2)); \ - free(tmp); \ - precision = -1; \ - } while (0) - #define ERRMSG "Unknown %%%c sequence in layout format (%s).\nKnown sequences:\n" \ " what: %%m: user message %%c: log category %%p: log priority\n" \ " where:\n" \ @@ -58,155 +27,12 @@ static double format_begin_of_time = -1; " when: %%d: date %%r: app. age\n" \ " other: %%%%: %% %%n: new line %%e: plain space\n" - -static void xbt_log_layout_format_dynamic(xbt_log_layout_t l, - xbt_log_event_t ev, - const char *fmt, - xbt_log_appender_t app) -{ - xbt_strbuff_t buff = xbt_strbuff_new(); - char tmpfmt[50]; - int precision = -1; - int length = -1; - char *q = l->data; - char *tmp; - char *tmp2; - - while (*q != '\0') { - if (*q == '%') { - q++; - handle_modifier: - switch (*q) { - case '\0': - fprintf(stderr, "Layout format (%s) ending with %%\n", - (char *) l->data); - abort(); - case '%': - xbt_strbuff_append(buff, "%"); - break; - case 'n': /* platform-dependant line separator (LOG4J compliant) */ - xbt_strbuff_append(buff, "\n"); - break; - case 'e': /* plain space (SimGrid extension) */ - xbt_strbuff_append(buff, " "); - break; - - case '.': /* precision specifyier */ - q++; - sscanf(q, "%d", &precision); - q += (precision>9?2:1); - goto handle_modifier; - - case '0': - case '1': - case '2': - case '3': - case '4': - case '5': - case '6': - case '7': - case '8': - case '9': /* length modifier */ - sscanf(q, "%d", &length); - q += (length>9?2:1); - goto handle_modifier; - - case 'c': /* category name; LOG4J compliant - should accept a precision postfix to show the hierarchy */ - append_string(ev->cat->name); - break; - case 'p': /* priority name; LOG4J compliant */ - append_string(xbt_log_priority_names[ev->priority]); - break; - - case 'h': /* host name; SimGrid extension */ - append_string(gras_os_myname()); - break; - case 't': /* thread name; LOG4J compliant */ - append_string(xbt_thread_self_name()); - break; - case 'P': /* process name; SimGrid extension */ - append_string(xbt_procname()); - break; - case 'i': /* process PID name; SimGrid extension */ - append_int((*xbt_getpid) ()); - break; - - case 'F': /* file name; LOG4J compliant */ - append_string(ev->fileName); - break; - case 'l': /* location; LOG4J compliant */ - append2("%s:%d", ev->fileName, ev->lineNum); - precision = -1; /* Ignored */ - break; - case 'L': /* line number; LOG4J compliant */ - append_int(ev->lineNum); - break; - case 'M': /* method (ie, function) name; LOG4J compliant */ - append_string(ev->functionName); - break; - case 'b': /* backtrace; called %throwable in LOG4J */ - case 'B': /* short backtrace; called %throwable{short} in LOG4J */ -#if defined(HAVE_EXECINFO_H) && defined(HAVE_POPEN) && defined(ADDR2LINE) - { - xbt_ex_t e; - int i; - - e.used = backtrace((void **) e.bt, XBT_BACKTRACE_SIZE); - e.bt_strings = NULL; - e.msg = NULL; - e.remote = 0; - xbt_backtrace_current(&e); - if (*q == 'B') { - append_string(e.bt_strings[2] + 8); - } else { - for (i = 2; i < e.used; i++) { - append_string(e.bt_strings[i] + 8); - xbt_strbuff_append(buff, "\n"); - } - } - - xbt_ex_free(e); - } -#else - append_string("(no backtrace on this arch)"); -#endif - break; - - case 'd': /* date; LOG4J compliant */ - append_double(gras_os_time()); - break; - case 'r': /* application age; LOG4J compliant */ - append_double(gras_os_time() - format_begin_of_time); - break; - - case 'm': /* user-provided message; LOG4J compliant */ - tmp2 = bvprintf(fmt, ev->ap_copy); - append_string(tmp2); - free(tmp2); - break; - - default: - fprintf(stderr, ERRMSG, *q, (char *) l->data); - abort(); - } - q++; - } else { - char tmp2[2]; - tmp2[0] = *(q++); - tmp2[1] = '\0'; - xbt_strbuff_append(buff, tmp2); - } - } - app->do_append(app, buff->data); - xbt_strbuff_free(buff); -} +#define XBT_LOG_BUFF_SIZE (ev->buffer_size) #undef check_overflow #define check_overflow \ if (p - ev->buffer >= XBT_LOG_BUFF_SIZE) { /* buffer overflow */ \ - xbt_log_layout_format_dynamic(l,ev,msg_fmt,app); \ - return; \ + return 0; \ } else ((void)0) #define show_it(data,letter) \ @@ -235,10 +61,9 @@ static void xbt_log_layout_format_dynamic(xbt_log_layout_t l, #define show_int(data) show_it(data, "d") #define show_double(data) show_it(data, "f") -static void xbt_log_layout_format_doit(xbt_log_layout_t l, - xbt_log_event_t ev, - const char *msg_fmt, - xbt_log_appender_t app) +static int xbt_log_layout_format_doit(xbt_log_layout_t l, + xbt_log_event_t ev, + const char *msg_fmt) { char *p, *q; char tmpfmt[50]; @@ -405,7 +230,8 @@ static void xbt_log_layout_format_doit(xbt_log_layout_t l, } } *p = '\0'; - app->do_append(app, ev->buffer); + + return 1; } static void xbt_log_layout_format_free(xbt_log_layout_t lay) diff --git a/src/xbt/xbt_log_layout_simple.c b/src/xbt/xbt_log_layout_simple.c index 26de2a07c6..ac603b446d 100644 --- a/src/xbt/xbt_log_layout_simple.c +++ b/src/xbt/xbt_log_layout_simple.c @@ -1,6 +1,6 @@ /* layout_simple - a dumb log layout */ -/* Copyright (c) 2007, 2008, 2009, 2010. The SimGrid Team. +/* Copyright (c) 2007-2011. The SimGrid Team. * All rights reserved. */ /* This program is free software; you can redistribute it and/or modify it @@ -20,54 +20,18 @@ extern int xbt_log_no_loc; static double simple_begin_of_time = -1; -static void xbt_log_layout_simple_dynamic(xbt_log_layout_t l, - xbt_log_event_t ev, - const char *fmt, - xbt_log_appender_t app) -{ - xbt_strbuff_t buff = xbt_strbuff_new(); - char loc_buff[256]; - char *p; - - /* Put every static information in a static buffer, and copy them in the dyn one */ - p = loc_buff; - p += snprintf(p, 256 - (p - loc_buff), "["); - - if (strlen(xbt_procname())) - p += snprintf(p, 256 - (p - loc_buff), "%s:%s:(%d) ", - gras_os_myname(), xbt_procname(), (*xbt_getpid) ()); - p += snprintf(p, 256 - (p - loc_buff), "%f] ", - gras_os_time() - simple_begin_of_time); - if (ev->priority != xbt_log_priority_info && xbt_log_no_loc == 0) - p += snprintf(p, 256 - (p - loc_buff), "%s:%d: ", ev->fileName, - ev->lineNum); - p += snprintf(p, 256 - (p - loc_buff), "[%s/%s] ", ev->cat->name, - xbt_log_priority_names[ev->priority]); - - xbt_strbuff_append(buff, loc_buff); - - p = bvprintf(fmt, ev->ap_copy); - xbt_strbuff_append(buff, p); - free(p); - - xbt_strbuff_append(buff, "\n"); - - app->do_append(app, buff->data); - xbt_strbuff_free(buff); -} +#define XBT_LOG_BUFF_SIZE (ev->buffer_size) /* only used after the format using: we suppose that the buffer is big enough to display our data */ #undef check_overflow #define check_overflow \ if (p - ev->buffer >= XBT_LOG_BUFF_SIZE) { /* buffer overflow */ \ - xbt_log_layout_simple_dynamic(l,ev,fmt,app); \ - return; \ + return 0; \ } else ((void)0) -static void xbt_log_layout_simple_doit(xbt_log_layout_t l, - xbt_log_event_t ev, - const char *fmt, - xbt_log_appender_t app) +static int xbt_log_layout_simple_doit(xbt_log_layout_t l, + xbt_log_event_t ev, + const char *fmt) { char *p; const char *procname = NULL; @@ -113,7 +77,8 @@ static void xbt_log_layout_simple_doit(xbt_log_layout_t l, /* End it */ p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "\n"); check_overflow; - app->do_append(app, ev->buffer); + + return 1; } xbt_log_layout_t xbt_log_layout_simple_new(char *arg) -- 2.20.1