Index: main/logger.c =================================================================== --- main/logger.c (revision 188505) +++ main/logger.c (working copy) @@ -140,6 +140,17 @@ AST_THREADSTORAGE(log_buf, log_buf_init); #define LOG_BUF_INIT_SIZE 128 +/* + * Storage for previous log message to prevent log storms + */ +static int stored_log_level; +static int stored_log_dup_count = 0; +static char *stored_log_msg = NULL; +static const char *stored_log_file; +static int stored_log_line; +static const char *stored_log_function; +static ast_mutex_t stored_log_msg_lock; + static int make_components(char *s, int lineno) { char *w; @@ -591,6 +602,8 @@ char tmp[256]; int res = 0; + ast_mutex_init(&stored_log_msg_lock); + /* auto rotate if sig SIGXFSZ comes a-knockin */ (void) signal(SIGXFSZ,(void *) handle_SIGXFSZ); @@ -655,14 +668,14 @@ return; } -static void __attribute__((format(printf, 5, 0))) ast_log_vsyslog(int level, const char *file, int line, const char *function, const char *fmt, va_list args) +static void ast_log_syslog(int level, const char *file, int line, const char *function, const char *msg) { char buf[BUFSIZ]; char *s; if (level >= SYSLOG_NLEVELS) { /* we are locked here, so cannot ast_log() */ - fprintf(stderr, "ast_log_vsyslog called with bogus level: %d\n", level); + fprintf(stderr, "ast_log_syslog called with bogus level: %d\n", level); return; } if (level == __LOG_VERBOSE) { @@ -676,27 +689,20 @@ levels[level], (long)GETTID(), file, line, function); } s = buf + strlen(buf); - vsnprintf(s, sizeof(buf) - strlen(buf), fmt, args); + snprintf(s, sizeof(buf) - strlen(buf), "%s", msg); term_strip(s, s, strlen(s) + 1); syslog(syslog_level_map[level], "%s", buf); } -/*! - * \brief send log messages to syslog and/or the console - */ -void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...) +static void __ast_log(int level, const char *file, int line, const char *function, char *msg, int msglen) { struct logchannel *chan; - struct ast_dynamic_str *buf; time_t t; struct tm tm; char date[256]; + char buf[2048]; + int res; - va_list ap; - - if (!(buf = ast_dynamic_str_thread_get(&log_buf, LOG_BUF_INIT_SIZE))) - return; - if (AST_LIST_EMPTY(&logchannels)) { /* @@ -704,35 +710,12 @@ * so just log to stdout */ if (level != __LOG_VERBOSE) { - int res; - va_start(ap, fmt); - res = ast_dynamic_str_thread_set_va(&buf, BUFSIZ, &log_buf, fmt, ap); - va_end(ap); - if (res != AST_DYNSTR_BUILD_FAILED) { - term_filter_escapes(buf->str); - fputs(buf->str, stdout); - } + term_filter_escapes(msg); + fputs(msg, stdout); } return; } - /* don't display LOG_DEBUG messages unless option_verbose _or_ option_debug - are non-zero; LOG_DEBUG messages can still be displayed if option_debug - is zero, if option_verbose is non-zero (this allows for 'level zero' - LOG_DEBUG messages to be displayed, if the logmask on any channel - allows it) - */ - if (!option_verbose && !option_debug && (level == __LOG_DEBUG)) - return; - - /* Ignore anything that never gets logged anywhere */ - if (!(global_logmask & (1 << level))) - return; - - /* Ignore anything other than the currently debugged file if there is one */ - if ((level == __LOG_DEBUG) && !ast_strlen_zero(debug_filename) && strcasecmp(debug_filename, file)) - return; - time(&t); ast_localtime(&t, &tm, NULL); strftime(date, sizeof(date), dateformat, &tm); @@ -740,13 +723,8 @@ AST_LIST_LOCK(&logchannels); if (logfiles.event_log && level == __LOG_EVENT) { - va_start(ap, fmt); - - fprintf(eventlog, "%s asterisk[%ld]: ", date, (long)getpid()); - vfprintf(eventlog, fmt, ap); + fprintf(eventlog, "%s asterisk[%ld]: %s", date, (long)getpid(), msg); fflush(eventlog); - - va_end(ap); AST_LIST_UNLOCK(&logchannels); return; } @@ -756,18 +734,15 @@ break; /* Check syslog channels */ if (chan->type == LOGTYPE_SYSLOG && (chan->logmask & (1 << level))) { - va_start(ap, fmt); - ast_log_vsyslog(level, file, line, function, fmt, ap); - va_end(ap); + ast_log_syslog(level, file, line, function, msg); /* Console channels */ } else if ((chan->logmask & (1 << level)) && (chan->type == LOGTYPE_CONSOLE)) { char linestr[128]; char tmp1[80], tmp2[80], tmp3[80], tmp4[80]; if (level != __LOG_VERBOSE) { - int res; sprintf(linestr, "%d", line); - ast_dynamic_str_thread_set(&buf, BUFSIZ, &log_buf, + snprintf(buf, sizeof(buf), "[%s] %s[%ld]: %s:%s %s: ", date, term_color(tmp1, levels[level], colors[level], 0, sizeof(tmp1)), @@ -776,23 +751,17 @@ term_color(tmp3, linestr, COLOR_BRWHITE, 0, sizeof(tmp3)), term_color(tmp4, function, COLOR_BRWHITE, 0, sizeof(tmp4))); /*filter to the console!*/ - term_filter_escapes(buf->str); - ast_console_puts_mutable(buf->str); - - va_start(ap, fmt); - res = ast_dynamic_str_thread_set_va(&buf, BUFSIZ, &log_buf, fmt, ap); - va_end(ap); - if (res != AST_DYNSTR_BUILD_FAILED) - ast_console_puts_mutable(buf->str); + term_filter_escapes(buf); + ast_console_puts_mutable(buf); + ast_console_puts_mutable(msg); } /* File channels */ } else if ((chan->logmask & (1 << level)) && (chan->fileptr)) { - int res; - ast_dynamic_str_thread_set(&buf, BUFSIZ, &log_buf, + snprintf(buf, sizeof(buf), "[%s] %s[%ld] %s: ", date, levels[level], (long)GETTID(), file); - res = fprintf(chan->fileptr, "%s", buf->str); - if (res <= 0 && !ast_strlen_zero(buf->str)) { /* Error, no characters printed */ + res = fprintf(chan->fileptr, "%s", buf); + if (res <= 0 && !ast_strlen_zero(buf)) { /* Error, no characters printed */ fprintf(stderr,"**** Asterisk Logging Error: ***********\n"); if (errno == ENOMEM || errno == ENOSPC) { fprintf(stderr, "Asterisk logging error: Out of disk space, can't log to log file %s\n", chan->filename); @@ -801,16 +770,10 @@ manager_event(EVENT_FLAG_SYSTEM, "LogChannel", "Channel: %s\r\nEnabled: No\r\nReason: %d - %s\r\n", chan->filename, errno, strerror(errno)); chan->disabled = 1; } else { - int res; /* No error message, continue printing */ - va_start(ap, fmt); - res = ast_dynamic_str_thread_set_va(&buf, BUFSIZ, &log_buf, fmt, ap); - va_end(ap); - if (res != AST_DYNSTR_BUILD_FAILED) { - term_strip(buf->str, buf->str, buf->len); - fputs(buf->str, chan->fileptr); - fflush(chan->fileptr); - } + term_strip(msg, msg, msglen); + fputs(msg, chan->fileptr); + fflush(chan->fileptr); } } } @@ -825,6 +788,65 @@ } } +/*! + * \brief send log messages to syslog and/or the console + */ +void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...) +{ + struct ast_dynamic_str *buf; + int res; + va_list ap; + + if (!(buf = ast_dynamic_str_thread_get(&log_buf, LOG_BUF_INIT_SIZE))) + return; + + va_start(ap, fmt); + res = ast_dynamic_str_thread_set_va(&buf, BUFSIZ, &log_buf, fmt, ap); + va_end(ap); + if (res == AST_DYNSTR_BUILD_FAILED) + return; + + /* don't display LOG_DEBUG messages unless option_verbose _or_ option_debug + are non-zero; LOG_DEBUG messages can still be displayed if option_debug + is zero, if option_verbose is non-zero (this allows for 'level zero' + LOG_DEBUG messages to be displayed, if the logmask on any channel + allows it) + */ + if (!option_verbose && !option_debug && (level == __LOG_DEBUG)) + return; + + /* Ignore anything that never gets logged anywhere */ + if (!(global_logmask & (1 << level))) + return; + + /* Ignore anything other than the currently debugged file if there is one */ + if ((level == __LOG_DEBUG) && !ast_strlen_zero(debug_filename) && strcasecmp(debug_filename, file)) + return; + + ast_mutex_lock(&stored_log_msg_lock); + if (stored_log_msg == NULL || stored_log_level != level || strcmp(buf->str, stored_log_msg) != 0) { + if (stored_log_dup_count > 0) { + char buf2[1024]; + + snprintf(buf2, sizeof(buf2), "Last message repeated %d times\n", stored_log_dup_count); + __ast_log(stored_log_level, stored_log_file, stored_log_line, stored_log_function, buf2, strlen(buf2)); + } + if (stored_log_msg != NULL) + ast_free(stored_log_msg); + stored_log_msg = ast_strdup(buf->str); + stored_log_level = level; + stored_log_dup_count = 0; + stored_log_file = file; + stored_log_line = line; + stored_log_function = function; + __ast_log(level, file, line, function, buf->str, buf->len); + } + else + ++stored_log_dup_count; + + ast_mutex_unlock(&stored_log_msg_lock); +} + void ast_backtrace(void) { #ifdef linux