logger: Add custom logging capabilities

Adds the ability for users to log to custom log levels
by providing custom log level names in logger.conf. Also
adds a logger show levels CLI command.

ASTERISK-29529

Change-Id: If082703cf81a436ae5a565c75225fa8c0554b702

apps/app_verbose.c

@@ -33,6 +33,7 @@
 #include "asterisk/module.h"
 #include "asterisk/app.h"
 #include "asterisk/channel.h"
+#include "asterisk/logger.h"
 
 static char *app_verbose = "Verbose";
 static char *app_log = "Log";
@@ -61,7 +62,8 @@ static char *app_log = "Log";
 		<syntax>
 			<parameter name="level" required="true">
 				<para>Level must be one of <literal>ERROR</literal>, <literal>WARNING</literal>, <literal>NOTICE</literal>,
-				<literal>DEBUG</literal>, <literal>VERBOSE</literal> or <literal>DTMF</literal>.</para>
+				<literal>DEBUG</literal>, <literal>VERBOSE</literal>, <literal>DTMF</literal>, or
+				the name of a custom dynamic logging level.</para>
 			</parameter>
 			<parameter name="message" required="true">
 				<para>Output text message.</para>
@@ -135,7 +137,7 @@ static int log_exec(struct ast_channel *chan, const char *data)
 	} else if (!strcasecmp(args.level, "DTMF")) {
 		lnum = __LOG_DTMF;
 	} else {
-		ast_log(LOG_ERROR, "Unknown log level: '%s'\n", args.level);
+		lnum = ast_logger_get_dynamic_level(args.level);
 	}
 
 	if (lnum > -1) {
@@ -143,6 +145,9 @@ static int log_exec(struct ast_channel *chan, const char *data)
 		snprintf(extension, sizeof(extension), "Ext. %s", ast_channel_exten(chan));
 
 		ast_log(lnum, extension, ast_channel_priority(chan), context, "%s\n", args.msg);
+	} else {
+		ast_log(LOG_ERROR, "Unknown log level: '%s'\n", args.level);
+		return 0;
 	}
 
 	return 0;

configs/samples/logger.conf.sample

@@ -85,6 +85,11 @@
 ; The default is 1000
 ;logger_queue_limit = 250
 ;
+; Any custom logging levels you may want to use, which can then
+; be sent to logging channels. The maximum number of custom
+; levels is 16, but not all of these may be available if modules
+; in Asterisk define their own.
+;custom_levels = foobar,important,compliance
 ;
 [logfiles]
 ;
@@ -130,6 +135,7 @@
 ;    dtmf
 ;    fax
 ;    security
+;    <customlevel>
 ;
 ; Verbose takes an optional argument, in the form of an integer level. The
 ; verbose level can be set per logfile. Verbose messages with higher levels
@@ -176,3 +182,5 @@ messages.log => notice,warning,error
 ;
 ;syslog.local0 => notice,warning,error
 ;
+; A log level defined in 'custom_levels' above
+;important.log = important

doc/CHANGES-staging/logger.txt

@@ -0,0 +1,5 @@
+Subject: logger
+
+Added the ability to define custom log levels in logger.conf
+and use them in the Log dialplan application. Also adds a
+logger show levels CLI command.

include/asterisk/logger.h

@@ -329,6 +329,14 @@ unsigned int ast_debug_get_by_module(const char *module);
  */
 int ast_logger_register_level(const char *name);
 
+/*!
+ * \brief Retrieve dynamic logging level id
+ * \param name The name of the level
+ * \retval The unique integer id for the given level
+ * \retval -1 if level name not found
+ */
+int ast_logger_get_dynamic_level(const char *name);
+
 /*!
  * \brief Unregister a previously registered logger level
  * \param name The name of the level to be unregistered

main/logger.c

@@ -74,6 +74,10 @@
 /*** DOCUMENTATION
  ***/
 
+static int logger_register_level(const char *name);
+static int logger_unregister_level(const char *name);
+static int logger_get_dynamic_level(const char *name);
+
 static char dateformat[256] = "%b %e %T";		/* Original Asterisk Format */
 
 static char queue_log_name[256] = QUEUELOG;
@@ -211,6 +215,15 @@ static char *levels[NUMLOGLEVELS] = {
 	"DTMF",
 };
 
+/*! \brief Custom dynamic logging levels added by the user
+ *
+ * The first 16 levels are reserved for system usage, and the remaining
+ * levels are reserved for usage by dynamic levels registered via
+ * ast_logger_register_level.
+ */
+
+static char *custom_dynamic_levels[NUMLOGLEVELS];
+
 /*! \brief Colors used in the console for logging */
 static const int colors[NUMLOGLEVELS] = {
 	COLOR_BRGREEN,
@@ -696,6 +709,26 @@ void ast_init_logger_for_socket_console(void)
 	ast_config_destroy(cfg);
 }
 
+/*!
+ * \brief Checks if level exists in array of level names
+ * \param levels Array of level names
+ * \param level Name to search for
+ * \len Size of levels
+ *
+ * \retval 1 Found
+ * \retval 0 Not Found
+ */
+static int custom_level_still_exists(char **levels, char *level, size_t len)
+{
+	int i;
+	for (i = 0; i < len; i++) {
+		if (!strcmp(levels[i], level)) {
+			return 1;
+		}
+	}
+	return 0;
+}
+
 /*!
  * \brief Read config, setup channels.
  * \param altconf Alternate configuration file to read.
@@ -809,6 +842,39 @@ static int init_logger_chain(const char *altconf)
 		}
 	}
 
+	/* Custom dynamic logging levels defined by user */
+	if ((s = ast_variable_retrieve(cfg, "general", "custom_levels"))) {
+		char *customlogs = ast_strdupa(s);
+		char *logfile;
+		char *new_custom_levels[16] = { };
+		unsigned int level, new_level = 0;
+
+		/* get the custom levels we need to register or reload */
+		while ((logfile = strsep(&customlogs, ","))) {
+			new_custom_levels[new_level++] = logfile;
+		}
+
+		/* unregister existing custom levels, if they're not still
+			specified in customlogs, to make room for new levels */
+		for (level = 16; level < ARRAY_LEN(levels); level++) {
+			if (levels[level] && custom_dynamic_levels[level] &&
+				!custom_level_still_exists(new_custom_levels, levels[level], ARRAY_LEN(new_custom_levels))) {
+				logger_unregister_level(levels[level]);
+				custom_dynamic_levels[level] = 0;
+			}
+		}
+
+		new_level = 0;
+		while ((logfile = new_custom_levels[new_level++])) {
+			/* Lock already held, so directly register the level,
+				unless it's already registered (as during reload) */
+			if (logger_get_dynamic_level(logfile) == -1) {
+				int custom_level = logger_register_level(logfile);
+				custom_dynamic_levels[custom_level] = logfile;
+			}
+		}
+	}
+
 	var = ast_variable_browse(cfg, "logfiles");
 	for (; var; var = var->next) {
 		chan = make_logchannel(var->name, var->value, var->lineno, 0);
@@ -1403,6 +1469,35 @@ static char *handle_logger_show_channels(struct ast_cli_entry *e, int cmd, struc
 	return CLI_SUCCESS;
 }
 
+/*! \brief CLI command to show logging levels */
+static char *handle_logger_show_levels(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
+{
+#define FORMATL2	"%5s %s\n"
+	unsigned int level;
+	switch (cmd) {
+	case CLI_INIT:
+		e->command = "logger show levels";
+		e->usage =
+			"Usage: logger show levels\n"
+			"       List configured logger levels.\n";
+		return NULL;
+	case CLI_GENERATE:
+		return NULL;
+	}
+	ast_cli(a->fd, FORMATL2, "Level", "Name");
+	ast_cli(a->fd, FORMATL2, "-----", "----");
+	AST_RWLIST_RDLOCK(&logchannels);
+	for (level = 0; level < ARRAY_LEN(levels); level++) {
+		if (levels[level]) {
+			ast_cli(a->fd, "%5d %s\n", level, levels[level]);
+		}
+	}
+	AST_RWLIST_UNLOCK(&logchannels);
+	ast_cli(a->fd, "\n");
+
+	return CLI_SUCCESS;
+}
+
 int ast_logger_create_channel(const char *log_channel, const char *components)
 {
 	struct logchannel *chan;
@@ -1545,6 +1640,7 @@ static char *handle_logger_remove_channel(struct ast_cli_entry *e, int cmd, stru
 
 static struct ast_cli_entry cli_logger[] = {
 	AST_CLI_DEFINE(handle_logger_show_channels, "List configured log channels"),
+	AST_CLI_DEFINE(handle_logger_show_levels, "List configured log levels"),
 	AST_CLI_DEFINE(handle_logger_reload, "Reopens the log files"),
 	AST_CLI_DEFINE(handle_logger_rotate, "Rotates and reopens the log files"),
 	AST_CLI_DEFINE(handle_logger_set_level, "Enables/Disables a specific logging level for this console"),
@@ -2348,19 +2444,14 @@ static void update_logchannels(void)
 {
 	struct logchannel *cur;
 
-	AST_RWLIST_WRLOCK(&logchannels);
-
 	global_logmask = 0;
 
 	AST_RWLIST_TRAVERSE(&logchannels, cur, list) {
 		make_components(cur);
 		global_logmask |= cur->logmask;
 	}
-
-	AST_RWLIST_UNLOCK(&logchannels);
 }
 
-
 #ifdef AST_DEVMODE
 
 AST_THREADSTORAGE_RAW(trace_indent);
@@ -2452,13 +2543,12 @@ void __ast_trace(const char *file, int line, const char *func, enum ast_trace_in
 }
 #endif
 
-int ast_logger_register_level(const char *name)
+/* Lock should be held before calling this function */
+static int logger_register_level(const char *name)
 {
 	unsigned int level;
 	unsigned int available = 0;
 
-	AST_RWLIST_WRLOCK(&logchannels);
-
 	for (level = 0; level < ARRAY_LEN(levels); level++) {
 		if ((level >= 16) && !available && !levels[level]) {
 			available = level;
@@ -2469,7 +2559,6 @@ int ast_logger_register_level(const char *name)
 			ast_log(LOG_WARNING,
 				"Unable to register dynamic logger level '%s': a standard logger level uses that name.\n",
 				name);
-			AST_RWLIST_UNLOCK(&logchannels);
 
 			return -1;
 		}
@@ -2479,15 +2568,12 @@ int ast_logger_register_level(const char *name)
 		ast_log(LOG_WARNING,
 			"Unable to register dynamic logger level '%s'; maximum number of levels registered.\n",
 			name);
-		AST_RWLIST_UNLOCK(&logchannels);
 
 		return -1;
 	}
 
 	levels[available] = ast_strdup(name);
 
-	AST_RWLIST_UNLOCK(&logchannels);
-
 	ast_debug(1, "Registered dynamic logger level '%s' with index %u.\n", name, available);
 
 	update_logchannels();
@@ -2495,42 +2581,79 @@ int ast_logger_register_level(const char *name)
 	return available;
 }
 
-void ast_logger_unregister_level(const char *name)
+int ast_logger_register_level(const char *name)
 {
-	unsigned int found = 0;
-	unsigned int x;
+	int available = 0;
 
 	AST_RWLIST_WRLOCK(&logchannels);
+	available = logger_register_level(name);
+	AST_RWLIST_UNLOCK(&logchannels);
+
+	return available;
+}
+
+static int logger_get_dynamic_level(const char *name)
+{
+	int level = -1;
+	unsigned int x;
 
 	for (x = 16; x < ARRAY_LEN(levels); x++) {
 		if (!levels[x]) {
 			continue;
 		}
-
-		if (strcasecmp(levels[x], name)) {
-			continue;
+		if (!strcasecmp(levels[x], name)) {
+			level = x;
+			break;
 		}
-
-		found = 1;
-		break;
 	}
 
-	if (found) {
-		/* take this level out of the global_logmask, to ensure that no new log messages
-		 * will be queued for it
-		 */
+	return level;
+}
 
-		global_logmask &= ~(1 << x);
+int ast_logger_get_dynamic_level(const char *name)
+{
+	int level = -1;
 
-		ast_free(levels[x]);
-		levels[x] = NULL;
-		AST_RWLIST_UNLOCK(&logchannels);
+	AST_RWLIST_RDLOCK(&logchannels);
 
-		ast_debug(1, "Unregistered dynamic logger level '%s' with index %u.\n", name, x);
+	level = logger_get_dynamic_level(name);
 
+	AST_RWLIST_UNLOCK(&logchannels);
+
+	return level;
+}
+
+static int logger_unregister_level(const char *name) {
+	unsigned int x;
+
+	x = logger_get_dynamic_level(name);
+	if (x == -1) {
+		return 0;
+	}
+	/* take this level out of the global_logmask, to ensure that no new log messages
+	 * will be queued for it
+	 */
+	global_logmask &= ~(1 << x);
+	ast_free(levels[x]);
+	levels[x] = NULL;
+	return x;
+}
+
+void ast_logger_unregister_level(const char *name)
+{
+	int x;
+
+	AST_RWLIST_WRLOCK(&logchannels);
+	x = logger_unregister_level(name);
+
+	if (x) {
 		update_logchannels();
-	} else {
-		AST_RWLIST_UNLOCK(&logchannels);
+	}
+
+	AST_RWLIST_UNLOCK(&logchannels);
+
+	if (x) {
+		ast_debug(1, "Unregistered dynamic logger level '%s' with index %u.\n", name, x);
 	}
 }