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. Should something go bezerk and log tons of messages in a tight loop, this will prevent memory escalation. When the limit is reached, a WARNING is logged to that effect and messages are discarded until the queue is empty again. At that time another WARNING will be logged with the count of discarded messages. There's no "low water mark" for this queue because the logger thread empties the entire queue and processes it in 1 batch before going back and waiting on the queue again. Implementing a low water mark would mean additional locking as the thread processes each message and it's not worth it. A "test" was added to test_logger.c but since the outcome is non-deterministic, it's really just a cli command, not a unit test. Change-Id: Ib4520c95e1ca5325dbf584c7989ce391649836d1
276 lines
7.1 KiB
C
276 lines
7.1 KiB
C
/*
|
|
* Asterisk -- An open source telephony toolkit.
|
|
*
|
|
* Copyright (C) 2009, Digium, Inc.
|
|
*
|
|
* Kevin P. Fleming <kpfleming@digium.com>
|
|
*
|
|
* See http://www.asterisk.org for more information about
|
|
* the Asterisk project. Please do not directly contact
|
|
* any of the maintainers of this project for assistance;
|
|
* the project provides a web site, mailing lists and IRC
|
|
* channels for your use.
|
|
*
|
|
* This program is free software, distributed under the terms of
|
|
* the GNU General Public License Version 2. See the LICENSE file
|
|
* at the top of the source tree.
|
|
*/
|
|
|
|
/*! \file
|
|
*
|
|
* \brief Test module for the logging subsystem
|
|
*
|
|
* \author\verbatim Kevin P. Fleming <kpfleming@digium.com> \endverbatim
|
|
*
|
|
* \ingroup tests
|
|
*/
|
|
|
|
/*** MODULEINFO
|
|
<depend>TEST_FRAMEWORK</depend>
|
|
<support_level>core</support_level>
|
|
***/
|
|
|
|
#include "asterisk.h"
|
|
|
|
#include "asterisk/file.h"
|
|
#include "asterisk/channel.h"
|
|
#include "asterisk/pbx.h"
|
|
#include "asterisk/module.h"
|
|
#include "asterisk/lock.h"
|
|
#include "asterisk/app.h"
|
|
#include "asterisk/cli.h"
|
|
|
|
struct test {
|
|
const char *name;
|
|
unsigned int x_success;
|
|
unsigned int x_failure;
|
|
unsigned int u_success;
|
|
unsigned int u_failure;
|
|
};
|
|
|
|
static void output_tests(struct test *tests, size_t num_tests, int fd)
|
|
{
|
|
unsigned int x;
|
|
|
|
for (x = 0; x < num_tests; x++) {
|
|
ast_cli(fd, "Test %u: %s\n", x + 1, tests[x].name);
|
|
ast_cli(fd, "\tExpected Successes: %u\n", tests[x].x_success);
|
|
ast_cli(fd, "\tExpected Failures: %u\n", tests[x].x_failure);
|
|
ast_cli(fd, "\tUnexpected Successes: %u\n", tests[x].u_success);
|
|
ast_cli(fd, "\tUnexpected Failures: %u\n", tests[x].u_failure);
|
|
ast_cli(fd, "Test %u Result: %s\n", x + 1, (tests[x].u_success + tests[x].u_failure) ? "FAIL" : "PASS");
|
|
}
|
|
}
|
|
|
|
static char *handle_cli_dynamic_level_test(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
|
|
{
|
|
unsigned int level;
|
|
unsigned int x;
|
|
unsigned int test;
|
|
struct test tests[] = {
|
|
{ .name = "Simple register/message/unregister",
|
|
},
|
|
{ .name = "Register multiple levels",
|
|
},
|
|
};
|
|
|
|
switch (cmd) {
|
|
case CLI_INIT:
|
|
e->command = "logger test dynamic";
|
|
e->usage = ""
|
|
"Usage: logger test dynamic\n"
|
|
"";
|
|
return NULL;
|
|
case CLI_GENERATE:
|
|
return NULL;
|
|
}
|
|
|
|
for (test = 0; test < ARRAY_LEN(tests); test++) {
|
|
ast_cli(a->fd, "Test %u: %s.\n", test + 1, tests[test].name);
|
|
switch (test) {
|
|
case 0:
|
|
if ((level = ast_logger_register_level("test")) != -1) {
|
|
ast_cli(a->fd, "Test: got level %u\n", level);
|
|
ast_log_dynamic_level(level, "Logger Dynamic Test: Test 1\n");
|
|
ast_logger_unregister_level("test");
|
|
tests[test].x_success++;
|
|
} else {
|
|
ast_cli(a->fd, "Test: Failed, could not register level 'test'.\n");
|
|
tests[test].u_failure++;
|
|
}
|
|
break;
|
|
case 1:
|
|
{
|
|
char level_name[18][8];
|
|
|
|
for (x = 0; x < ARRAY_LEN(level_name); x++) {
|
|
sprintf(level_name[x], "level%02u", x);
|
|
if ((level = ast_logger_register_level(level_name[x])) == -1) {
|
|
if (x < 16) {
|
|
tests[test].u_failure++;
|
|
} else {
|
|
tests[test].x_failure++;
|
|
}
|
|
level_name[x][0] = '\0';
|
|
} else {
|
|
ast_cli(a->fd, "Test: registered '%s', got level %u\n", level_name[x], level);
|
|
if (x < 16) {
|
|
tests[test].x_success++;
|
|
} else {
|
|
tests[test].u_success++;
|
|
}
|
|
}
|
|
}
|
|
|
|
for (x = 0; x < ARRAY_LEN(level_name); x++) {
|
|
if (!ast_strlen_zero(level_name[x])) {
|
|
ast_logger_unregister_level(level_name[x]);
|
|
}
|
|
}
|
|
}
|
|
}
|
|
}
|
|
|
|
output_tests(tests, ARRAY_LEN(tests), a->fd);
|
|
|
|
return CLI_SUCCESS;
|
|
}
|
|
|
|
static char *handle_cli_performance_test(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
|
|
{
|
|
unsigned int level;
|
|
unsigned int test;
|
|
struct test tests[] = {
|
|
{ .name = "Log 10,000 messages",
|
|
},
|
|
};
|
|
|
|
switch (cmd) {
|
|
case CLI_INIT:
|
|
e->command = "logger test performance";
|
|
e->usage = ""
|
|
"Usage: logger test performance\n"
|
|
"";
|
|
return NULL;
|
|
case CLI_GENERATE:
|
|
return NULL;
|
|
}
|
|
|
|
for (test = 0; test < ARRAY_LEN(tests); test++) {
|
|
ast_cli(a->fd, "Test %u: %s.\n", test + 1, tests[test].name);
|
|
switch (test) {
|
|
case 0:
|
|
if ((level = ast_logger_register_level("perftest")) != -1) {
|
|
unsigned int x;
|
|
struct timeval start, end;
|
|
int elapsed;
|
|
|
|
ast_cli(a->fd, "Test: got level %u\n", level);
|
|
start = ast_tvnow();
|
|
for (x = 0; x < 10000; x++) {
|
|
ast_log_dynamic_level(level, "Performance test log message\n");
|
|
}
|
|
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_logger_unregister_level("perftest");
|
|
tests[test].x_success++;
|
|
} else {
|
|
ast_cli(a->fd, "Test: Failed, could not register level 'perftest'.\n");
|
|
tests[test].u_failure++;
|
|
}
|
|
break;
|
|
}
|
|
}
|
|
|
|
output_tests(tests, ARRAY_LEN(tests), a->fd);
|
|
|
|
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)
|
|
{
|
|
ast_cli_unregister_multiple(cli_logger, ARRAY_LEN(cli_logger));
|
|
return 0;
|
|
}
|
|
|
|
static int load_module(void)
|
|
{
|
|
ast_cli_register_multiple(cli_logger, ARRAY_LEN(cli_logger));
|
|
return AST_MODULE_LOAD_SUCCESS;
|
|
}
|
|
|
|
AST_MODULE_INFO_STANDARD(ASTERISK_GPL_KEY, "Logger Test Module");
|