diff options
| -rw-r--r-- | CHANGES | 9 | ||||
| -rw-r--r-- | configs/samples/logger.conf.sample | 8 | ||||
| -rw-r--r-- | include/asterisk/logger.h | 16 | ||||
| -rw-r--r-- | main/logger.c | 187 | ||||
| -rw-r--r-- | tests/test_logger.c | 67 |
5 files changed, 228 insertions, 59 deletions
@@ -31,6 +31,15 @@ res_rtp_asterisk for a response that can never come until we give up on the response. Multiple subnets may be listed. +Logging +------------------- + * Added logger_queue_limit to the configuration options. + All log messages go to a queue serviced by a single thread + which does all the IO. This setting controls how big that + queue can get (and therefore how much memory is allocated) + before new messages are discarded. + The default is 1000. + res_pjsip_config_wizard ------------------ * Two new parameters have been added to the pjsip config wizard. diff --git a/configs/samples/logger.conf.sample b/configs/samples/logger.conf.sample index b504467ec..e5f0c551a 100644 --- a/configs/samples/logger.conf.sample +++ b/configs/samples/logger.conf.sample @@ -78,6 +78,14 @@ ; Directory for log files is configures in asterisk.conf ; option astlogdir ; +; All log messages go to a queue serviced by a single thread +; which does all the IO. This setting controls how big that +; queue can get (and therefore how much memory is allocated) +; before new messages are discarded. +; The default is 1000 +;logger_queue_limit = 250 +; +; [logfiles] ; ; Format is: diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h index 2f629dfbe..849f986b3 100644 --- a/include/asterisk/logger.h +++ b/include/asterisk/logger.h @@ -507,6 +507,22 @@ void ast_verb_console_set(int verb_level); */ int ast_is_logger_initialized(void); +/*! + * \brief Set the maximum number of messages allowed in the processing queue + * + * \param queue_limit + * + * \return Nothing + */ +void ast_logger_set_queue_limit(int queue_limit); + +/*! + * \brief Get the maximum number of messages allowed in the processing queue + * + * \return Queue limit + */ +int ast_logger_get_queue_limit(void); + #if defined(__cplusplus) || defined(c_plusplus) } #endif diff --git a/main/logger.c b/main/logger.c index 8c8162d71..6060b3c4d 100644 --- a/main/logger.c +++ b/main/logger.c @@ -86,6 +86,11 @@ static int display_callids; AST_THREADSTORAGE(unique_callid); +static int logger_queue_size; +static int logger_queue_limit = 1000; +static int logger_messages_discarded; +static unsigned int high_water_alert; + static enum rotatestrategy { NONE = 0, /* Do not rotate log files at all, instead rely on external mechanisms */ SEQUENTIAL = 1 << 0, /* Original method - create a new file, in order */ @@ -719,6 +724,16 @@ static int init_logger_chain(const char *altconf) fprintf(stderr, "rotatetimestamp option has been deprecated. Please use rotatestrategy instead.\n"); } } + if ((s = ast_variable_retrieve(cfg, "general", "logger_queue_limit"))) { + if (sscanf(s, "%30d", &logger_queue_limit) != 1) { + fprintf(stderr, "logger_queue_limit has an invalid value. Leaving at default of %d.\n", + logger_queue_limit); + } + if (logger_queue_limit < 10) { + fprintf(stderr, "logger_queue_limit must be >= 10. Setting to 10.\n"); + logger_queue_limit = 10; + } + } var = ast_variable_browse(cfg, "logfiles"); for (; var; var = var->next) { @@ -1297,6 +1312,7 @@ static char *handle_logger_show_channels(struct ast_cli_entry *e, int cmd, struc case CLI_GENERATE: return NULL; } + ast_cli(a->fd, "Logger queue limit: %d\n\n", logger_queue_limit); ast_cli(a->fd, FORMATL, "Channel", "Type", "Formatter", "Status"); ast_cli(a->fd, "Configuration\n"); ast_cli(a->fd, FORMATL, "-------", "----", "---------", "------"); @@ -1585,6 +1601,79 @@ static void logger_print_normal(struct logmsg *logmsg) return; } +static struct logmsg * __attribute__((format(printf, 7, 0))) format_log_message_ap(int level, + int sublevel, const char *file, int line, const char *function, ast_callid callid, + const char *fmt, va_list ap) +{ + struct logmsg *logmsg = NULL; + struct ast_str *buf = NULL; + struct ast_tm tm; + struct timeval now = ast_tvnow(); + int res = 0; + char datestring[256]; + + if (!(buf = ast_str_thread_get(&log_buf, LOG_BUF_INIT_SIZE))) { + return NULL; + } + + /* Build string */ + res = ast_str_set_va(&buf, BUFSIZ, fmt, ap); + + /* If the build failed, then abort and free this structure */ + if (res == AST_DYNSTR_BUILD_FAILED) { + return NULL; + } + + /* Create a new logging message */ + if (!(logmsg = ast_calloc_with_stringfields(1, struct logmsg, res + 128))) { + return NULL; + } + + /* Copy string over */ + ast_string_field_set(logmsg, message, ast_str_buffer(buf)); + + /* Set type */ + if (level == __LOG_VERBOSE) { + logmsg->type = LOGMSG_VERBOSE; + } else { + logmsg->type = LOGMSG_NORMAL; + } + + if (display_callids && callid) { + logmsg->callid = callid; + } + + /* Create our date/time */ + ast_localtime(&now, &tm, NULL); + ast_strftime(datestring, sizeof(datestring), dateformat, &tm); + ast_string_field_set(logmsg, date, datestring); + + /* Copy over data */ + logmsg->level = level; + logmsg->sublevel = sublevel; + logmsg->line = line; + ast_string_field_set(logmsg, level_name, levels[level]); + ast_string_field_set(logmsg, file, file); + ast_string_field_set(logmsg, function, function); + logmsg->lwp = ast_get_tid(); + + return logmsg; +} + +static struct logmsg * __attribute__((format(printf, 7, 0))) format_log_message(int level, + int sublevel, const char *file, int line, const char *function, ast_callid callid, + const char *fmt, ...) +{ + struct logmsg *logmsg; + va_list ap; + + va_start(ap, fmt); + logmsg = format_log_message_ap(level, sublevel, file, line, function, callid, fmt, ap); + va_end(ap); + + return logmsg; +} + /*! \brief Actual logging thread */ static void *logger_thread(void *data) { @@ -1601,8 +1690,21 @@ static void *logger_thread(void *data) ast_cond_wait(&logcond, &logmsgs.lock); } } + + if (high_water_alert) { + msg = format_log_message(__LOG_WARNING, 0, "logger", 0, "***", 0, + "Logging resumed. %d message%s discarded.\n", + logger_messages_discarded, logger_messages_discarded == 1 ? "" : "s"); + if (msg) { + AST_LIST_INSERT_TAIL(&logmsgs, msg, list); + } + high_water_alert = 0; + logger_messages_discarded = 0; + } + next = AST_LIST_FIRST(&logmsgs); AST_LIST_HEAD_INIT_NOLOCK(&logmsgs); + logger_queue_size = 0; AST_LIST_UNLOCK(&logmsgs); /* Otherwise go through and process each message in the order added */ @@ -1861,79 +1963,36 @@ void ast_callid_threadstorage_auto_clean(ast_callid callid, int callid_created) /*! * \brief send log messages to syslog and/or the console */ -static void __attribute__((format(printf, 7, 0))) ast_log_full(int level, int sublevel, const char *file, int line, const char *function, ast_callid callid, const char *fmt, va_list ap) +static void __attribute__((format(printf, 7, 0))) ast_log_full(int level, int sublevel, + const char *file, int line, const char *function, ast_callid callid, + const char *fmt, va_list ap) { struct logmsg *logmsg = NULL; - struct ast_str *buf = NULL; - struct ast_tm tm; - struct timeval now = ast_tvnow(); - int res = 0; - char datestring[256]; if (level == __LOG_VERBOSE && ast_opt_remote && ast_opt_exec) { return; } - if (!(buf = ast_str_thread_get(&log_buf, LOG_BUF_INIT_SIZE))) - return; - - if (level != __LOG_VERBOSE && AST_RWLIST_EMPTY(&logchannels)) { - /* - * we don't have the logger chain configured yet, - * so just log to stdout - */ - int result; - result = ast_str_set_va(&buf, BUFSIZ, fmt, ap); /* XXX BUFSIZ ? */ - if (result != AST_DYNSTR_BUILD_FAILED) { - term_filter_escapes(ast_str_buffer(buf)); - fputs(ast_str_buffer(buf), stdout); + AST_LIST_LOCK(&logmsgs); + if (logger_queue_size >= logger_queue_limit && !close_logger_thread) { + logger_messages_discarded++; + if (!high_water_alert && !close_logger_thread) { + logmsg = format_log_message(__LOG_WARNING, 0, "logger", 0, "***", 0, + "Log queue threshold (%d) exceeded. Discarding new messages.\n", logger_queue_limit); + AST_LIST_INSERT_TAIL(&logmsgs, logmsg, list); + high_water_alert = 1; + ast_cond_signal(&logcond); } + AST_LIST_UNLOCK(&logmsgs); return; } + AST_LIST_UNLOCK(&logmsgs); - /* Ignore anything that never gets logged anywhere */ - if (level != __LOG_VERBOSE && !(global_logmask & (1 << level))) - return; - - /* Build string */ - res = ast_str_set_va(&buf, BUFSIZ, fmt, ap); - - /* If the build failed, then abort and free this structure */ - if (res == AST_DYNSTR_BUILD_FAILED) + logmsg = format_log_message_ap(level, sublevel, file, line, function, callid, fmt, ap); + if (!logmsg) { return; - - /* Create a new logging message */ - if (!(logmsg = ast_calloc_with_stringfields(1, struct logmsg, res + 128))) - return; - - /* Copy string over */ - ast_string_field_set(logmsg, message, ast_str_buffer(buf)); - - /* Set type */ - if (level == __LOG_VERBOSE) { - logmsg->type = LOGMSG_VERBOSE; - } else { - logmsg->type = LOGMSG_NORMAL; } - if (display_callids && callid) { - logmsg->callid = callid; - } - - /* Create our date/time */ - ast_localtime(&now, &tm, NULL); - ast_strftime(datestring, sizeof(datestring), dateformat, &tm); - ast_string_field_set(logmsg, date, datestring); - - /* Copy over data */ - logmsg->level = level; - logmsg->sublevel = sublevel; - logmsg->line = line; - ast_string_field_set(logmsg, level_name, levels[level]); - ast_string_field_set(logmsg, file, file); - ast_string_field_set(logmsg, function, function); - logmsg->lwp = ast_get_tid(); - /* If the logger thread is active, append it to the tail end of the list - otherwise skip that step */ if (logthread != AST_PTHREADT_NULL) { AST_LIST_LOCK(&logmsgs); @@ -1942,6 +2001,7 @@ static void __attribute__((format(printf, 7, 0))) ast_log_full(int level, int su logmsg_free(logmsg); } else { AST_LIST_INSERT_TAIL(&logmsgs, logmsg, list); + logger_queue_size++; ast_cond_signal(&logcond); } AST_LIST_UNLOCK(&logmsgs); @@ -2300,3 +2360,12 @@ const char *ast_logger_get_dateformat(void) return dateformat; } +void ast_logger_set_queue_limit(int queue_limit) +{ + logger_queue_limit = queue_limit; +} + +int ast_logger_get_queue_limit(void) +{ + return logger_queue_limit; +} diff --git a/tests/test_logger.c b/tests/test_logger.c index 07a4c369b..59ee3e6c1 100644 --- a/tests/test_logger.c +++ b/tests/test_logger.c @@ -188,9 +188,76 @@ static char *handle_cli_performance_test(struct ast_cli_entry *e, int cmd, struc return CLI_SUCCESS; } +static char *handle_cli_queue_test(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a) +{ + unsigned int level; + int current_queue_limit; + unsigned int x; + struct timeval start, end; + int elapsed; + char tmppath[] = "/tmp/asterisk_logger_queue.XXXXXX"; + int fd; + + switch (cmd) { + case CLI_INIT: + e->command = "logger test queue"; + e->usage = "" + "Usage: logger test queue\n" + ""; + return NULL; + case CLI_GENERATE: + return NULL; + } + + fd = mkstemp(tmppath); + if (fd < 0) { + ast_cli(a->fd, "Test: Failed, could not create temporary log file '%s'.\n", tmppath); + return CLI_SUCCESS; + } + + level = ast_logger_register_level("queuetest"); + if (level < 0) { + ast_cli(a->fd, "Test: Failed, could not register level 'queuetest'.\n"); + return CLI_SUCCESS; + } + ast_cli(a->fd, "Test: got level %u for 'queuetest'.\n", level); + + if (ast_logger_create_channel(tmppath, "queuetest") != AST_LOGGER_SUCCESS) { + ast_cli(a->fd, "Test: Unable to create logger channel '%s'\n", tmppath); + goto error; + } + + current_queue_limit = ast_logger_get_queue_limit(); + ast_cli(a->fd, "Test: Current queue limit: %d. Setting to 100 for test.\n", current_queue_limit); + ast_logger_set_queue_limit(100); + + ast_cli(a->fd, "Test: You should see SOME 'exceeded' and 'resumed' messages after the test " + "is completed. How many is dependent on system resources.\n"); + + start = ast_tvnow(); + for (x = 0; x < 10000; x++) { + ast_log_dynamic_level(level, "Performance test log message %2d\n", x); + } + end = ast_tvnow(); + elapsed = ast_tvdiff_ms(end, start); + ast_cli(a->fd, "Test: 10,000 messages in %f seconds.\n", (float) elapsed / 1000); + ast_cli(a->fd, "Test: Completed. Resetting queue limit to %d.\n", current_queue_limit); + ast_logger_set_queue_limit(current_queue_limit); + +error: + + ast_logger_remove_channel(tmppath); + ast_logger_unregister_level("queuetest"); + close(fd); + unlink(tmppath); + + return CLI_SUCCESS; +} + static struct ast_cli_entry cli_logger[] = { AST_CLI_DEFINE(handle_cli_dynamic_level_test, "Test the dynamic logger level implementation"), AST_CLI_DEFINE(handle_cli_performance_test, "Test the logger performance"), + AST_CLI_DEFINE(handle_cli_queue_test, "Test the logger queue"), }; static int unload_module(void) |