[asterisk-commits] file: branch file/logqueue r42010 - /team/file/logqueue/main/logger.c

asterisk-commits at lists.digium.com asterisk-commits at lists.digium.com
Mon Sep 4 15:55:43 MST 2006


Author: file
Date: Mon Sep  4 17:55:43 2006
New Revision: 42010

URL: http://svn.digium.com/view/asterisk?rev=42010&view=rev
Log:
This *may* or *may not* be a non-blocking logger.

Modified:
    team/file/logqueue/main/logger.c

Modified: team/file/logqueue/main/logger.c
URL: http://svn.digium.com/view/asterisk/team/file/logqueue/main/logger.c?rev=42010&r1=42009&r2=42010&view=diff
==============================================================================
--- team/file/logqueue/main/logger.c (original)
+++ team/file/logqueue/main/logger.c Mon Sep  4 17:55:43 2006
@@ -69,6 +69,7 @@
 #include "asterisk/utils.h"
 #include "asterisk/manager.h"
 #include "asterisk/threadstorage.h"
+#include "asterisk/strings.h"
 
 #if defined(__linux__) && !defined(__NR_gettid)
 #include <asm/unistd.h>
@@ -110,6 +111,27 @@
 };
 
 static AST_LIST_HEAD_STATIC(logchannels, logchannel);
+
+enum logmsgtypes {
+	LOGMSG_NORMAL = 0,
+	LOGMSG_VERBOSE,
+};
+
+struct logmsg {
+	enum logmsgtypes type;
+	char date[256];
+	int level;
+	const char *file;
+	int line;
+	const char *function;
+	char *str;
+	AST_LIST_ENTRY(logmsg) list;
+};
+
+static AST_LIST_HEAD_STATIC(logmsgs, logmsg);
+static pthread_t logthread = AST_PTHREADT_NULL;
+static ast_cond_t logcond;
+static int close_logger_thread = 0;
 
 static FILE *eventlog = NULL;
 static FILE *qlog = NULL;
@@ -575,6 +597,167 @@
 	return 0;
 }
 
+static void ast_log_vsyslog(int level, const char *file, int line, const char *function, char *str)
+{
+	char buf[BUFSIZ];
+
+	if (level >= SYSLOG_NLEVELS) {
+		/* we are locked here, so cannot ast_log() */
+		fprintf(stderr, "ast_log_vsyslog called with bogus level: %d\n", level);
+		return;
+	}
+
+	if (level == __LOG_VERBOSE) {
+		snprintf(buf, sizeof(buf), "VERBOSE[%ld]: %s", (long)GETTID(), str);
+		level = __LOG_DEBUG;
+	} else if (level == __LOG_DTMF) {
+		snprintf(buf, sizeof(buf), "DTMF[%ld]: %s", (long)GETTID(), str);
+		level = __LOG_DEBUG;
+	} else {
+		snprintf(buf, sizeof(buf), "%s[%ld]: %s:%d in %s: %s",
+			 levels[level], (long)GETTID(), file, line, function, str);
+        }
+
+        term_strip(buf, buf, strlen(buf) + 1);
+        syslog(syslog_level_map[level], "%s", buf);
+}
+
+/* Print a normal log message to the channels */
+static void logger_print_normal(struct logmsg *logmsg)
+{
+	struct logchannel *chan = NULL;
+	char buf[BUFSIZ];
+
+	AST_LIST_LOCK(&logchannels);
+
+	if (logfiles.event_log && logmsg->level == __LOG_EVENT) {
+		fprintf(eventlog, "%s asterisk[%ld]: %s", logmsg->date, (long)getpid(), logmsg->str);
+		fflush(eventlog);
+		AST_LIST_UNLOCK(&logchannels);
+		return;
+	}
+
+	if (!AST_LIST_EMPTY(&logchannels)) {
+		AST_LIST_TRAVERSE(&logchannels, chan, list) {
+			/* If the channel is disabled, then move on to the next one */
+			if (chan->disabled)
+				continue;
+			/* Check syslog channels */
+			if (chan->type == LOGTYPE_SYSLOG && (chan->logmask & (1 << logmsg->level))) {
+				ast_log_vsyslog(logmsg->level, logmsg->file, logmsg->line, logmsg->function, logmsg->str);
+			/* Console channels */
+			} else if (chan->type == LOGTYPE_CONSOLE && (chan->logmask & (1 << logmsg->level))) {
+				char linestr[128];
+				char tmp1[80], tmp2[80], tmp3[80], tmp4[80];
+
+				/* If the level is verbose, then skip it */
+				if (logmsg->level == __LOG_VERBOSE)
+					continue;
+
+				/* Turn the numerical line number into a string */
+				snprintf(linestr, sizeof(linestr), "%d", logmsg->line);
+				/* Build string to print out */
+				snprintf(buf, sizeof(buf), "[%s] %s[%ld]: %s:%s %s: %s",
+					 logmsg->date,
+					 term_color(tmp1, levels[logmsg->level], colors[logmsg->level], 0, sizeof(tmp1)),
+					 (long)GETTID(),
+					 term_color(tmp2, logmsg->file, COLOR_BRWHITE, 0, sizeof(tmp2)),
+					 term_color(tmp3, linestr, COLOR_BRWHITE, 0, sizeof(tmp3)),
+					 term_color(tmp4, logmsg->function, COLOR_BRWHITE, 0, sizeof(tmp4)),
+					 logmsg->str);
+				/* Print out */
+				ast_console_puts_mutable(buf);
+			/* File channels */
+			} else if (chan->type == LOGTYPE_FILE && (chan->logmask & (1 << logmsg->level))) {
+				int res = 0;
+
+				/* If no file pointer exists, skip it */
+				if (!chan->fileptr)
+					continue;
+				
+				/* Print out to the file */
+				res = fprintf(chan->fileptr, "[%s] %s[%ld] %s: %s",
+					      logmsg->date, levels[logmsg->level], (long)GETTID(), logmsg->file, logmsg->str);
+				if (res <= 0 && !ast_strlen_zero(logmsg->str)) {
+					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);
+					else
+						fprintf(stderr, "Logger Warning: Unable to write to log file '%s': %s (disabled)\n", chan->filename, strerror(errno));
+					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 if (logmsg->level != __LOG_VERBOSE) {
+		fputs(logmsg->str, stdout);
+	}
+
+	AST_LIST_UNLOCK(&logchannels);
+
+	/* If we need to reload because of the file size, then do so */
+	if (filesize_reload_needed) {
+		reload_logger(1);
+		ast_log(LOG_EVENT, "Rotated Logs Per SIGXFSZ (Exceeded file size limit)\n");
+		if (option_verbose)
+			ast_verbose("Rotated Logs Per SIGXFSZ (Exceeded file size limit)\n");
+	}
+
+	return;
+}
+
+/* Print a verbose message to the verbosers */
+static void logger_print_verbose(struct logmsg *logmsg)
+{
+	struct verb *v = NULL;
+
+	/* Iterate through the list of verbosers and pass them the log message string */
+	AST_LIST_LOCK(&verbosers);
+	AST_LIST_TRAVERSE(&verbosers, v, list)
+		v->verboser(logmsg->str);
+	AST_LIST_UNLOCK(&verbosers);
+
+	return;
+}
+
+/* Actual logging thread */
+static void *logger_thread(void *data)
+{
+	struct logmsg *next = NULL, *msg = NULL;
+
+	for (;;) {
+		/* We lock the message list, and see if any message exists... if not we wait on the condition to be signalled */
+		AST_LIST_LOCK(&logmsgs);
+		if (AST_LIST_EMPTY(&logmsgs))
+			ast_cond_wait(&logcond, &logmsgs.lock);
+		next = AST_LIST_FIRST(&logmsgs);
+		AST_LIST_HEAD_INIT_NOLOCK(&logmsgs);
+		AST_LIST_UNLOCK(&logmsgs);
+
+		/* If we should stop, then stop */
+		if (close_logger_thread)
+			break;
+
+		/* Otherwise go through and process each message in the order added */
+		while ((msg = next)) {
+			/* Get the next entry now so that we can free our current structure later */
+			next = AST_LIST_NEXT(msg, list);
+
+			/* Depending on the type, send it to the proper function */
+			if (msg->type == LOGMSG_NORMAL)
+				logger_print_normal(msg);
+			else if (msg->type == LOGMSG_VERBOSE)
+				logger_print_verbose(msg);
+
+			/* Free the data since we are done */
+			free(msg->str);
+			free(msg);
+		}
+	}
+
+	return NULL;
+}
+
 int init_logger(void)
 {
 	char tmp[256];
@@ -582,6 +765,13 @@
 
 	/* auto rotate if sig SIGXFSZ comes a-knockin */
 	(void) signal(SIGXFSZ,(void *) handle_SIGXFSZ);
+
+	/* start logger thread */
+	ast_cond_init(&logcond, NULL);
+	if (ast_pthread_create(&logthread, NULL, logger_thread, NULL) < 0) {
+		ast_cond_destroy(&logcond);
+		return -1;
+	}
 
 	/* register the relaod logger cli command */
 	ast_cli_register(&reload_logger_cli);
@@ -618,7 +808,13 @@
 
 void close_logger(void)
 {
-	struct logchannel *f;
+	struct logchannel *f = NULL;
+
+	/* Stop logger thread */
+	AST_LIST_LOCK(&logmsgs);
+	close_logger_thread = 1;
+	ast_cond_signal(&logcond);
+	AST_LIST_UNLOCK(&logmsgs);
 
 	AST_LIST_LOCK(&logchannels);
 
@@ -646,43 +842,16 @@
 	return;
 }
 
-static void ast_log_vsyslog(int level, const char *file, int line, const char *function, const char *fmt, va_list args) 
-{
-	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);
-		return;
-	}
-	if (level == __LOG_VERBOSE) {
-		snprintf(buf, sizeof(buf), "VERBOSE[%ld]: ", (long)GETTID());
-		level = __LOG_DEBUG;
-	} else if (level == __LOG_DTMF) {
-		snprintf(buf, sizeof(buf), "DTMF[%ld]: ", (long)GETTID());
-		level = __LOG_DEBUG;
-	} else {
-		snprintf(buf, sizeof(buf), "%s[%ld]: %s:%d in %s: ",
-			 levels[level], (long)GETTID(), file, line, function);
-	}
-	s = buf + strlen(buf);
-	vsnprintf(s, sizeof(buf) - strlen(buf), fmt, args);
-	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, ...)
 {
-	struct logchannel *chan;
-	struct ast_dynamic_str *buf;
+	struct logmsg *logmsg = NULL;
+	struct ast_dynamic_str *buf = NULL;
+	struct tm tm;
 	time_t t;
-	struct tm tm;
-	char date[256];
-
+	int res = 0;
 	va_list ap;
 
 	if (!(buf = ast_dynamic_str_thread_get(&log_buf, LOG_BUF_INIT_SIZE)))
@@ -705,110 +874,45 @@
 	if ((level == __LOG_DEBUG) && !ast_strlen_zero(debug_filename) && strcasecmp(debug_filename, file))
 		return;
 
+	/* Create a new logging message */
+	if (!(logmsg = ast_calloc(1, sizeof(*logmsg))))
+		return;
+
+	/* Set type to be normal */
+	logmsg->type = LOGMSG_NORMAL;
+
+	/* Create our date/time */
 	time(&t);
 	localtime_r(&t, &tm);
-	strftime(date, sizeof(date), dateformat, &tm);
-
-	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);
-		fflush(eventlog);
-
-		va_end(ap);
-		AST_LIST_UNLOCK(&logchannels);
-		return;
-	}
-
-	if (!AST_LIST_EMPTY(&logchannels)) {
-		AST_LIST_TRAVERSE(&logchannels, chan, list) {
-			if (chan->disabled)
-				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);
-			/* 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,
-						"[%s] %s[%ld]: %s:%s %s: ",
-						date,
-						term_color(tmp1, levels[level], colors[level], 0, sizeof(tmp1)),
-						(long)GETTID(),
-						term_color(tmp2, file, COLOR_BRWHITE, 0, sizeof(tmp2)),
-						term_color(tmp3, linestr, COLOR_BRWHITE, 0, sizeof(tmp3)),
-						term_color(tmp4, function, COLOR_BRWHITE, 0, sizeof(tmp4)));
-
-					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);
-				}
-			/* File channels */
-			} else if ((chan->logmask & (1 << level)) && (chan->fileptr)) {
-				int res;
-				ast_dynamic_str_thread_set(&buf, BUFSIZ, &log_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 */
-					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);
-					} else
-						fprintf(stderr, "Logger Warning: Unable to write to log file '%s': %s (disabled)\n", chan->filename, strerror(errno));
-					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);
-					}
-				}
-			}
-		}
-	} else {
-		/* 
-		 * we don't have the logger chain configured yet,
-		 * 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)
-				fputs(buf->str, stdout);
-		}
-	}
-
-	AST_LIST_UNLOCK(&logchannels);
-
-	if (filesize_reload_needed) {
-		reload_logger(1);
-		ast_log(LOG_EVENT,"Rotated Logs Per SIGXFSZ (Exceeded file size limit)\n");
-		if (option_verbose)
-			ast_verbose("Rotated Logs Per SIGXFSZ (Exceeded file size limit)\n");
-	}
+	strftime(logmsg->date, sizeof(logmsg->date), dateformat, &tm);
+
+	/* Copy over data */
+	logmsg->level = level;
+	logmsg->file = file;
+	logmsg->line = line;
+	logmsg->function = function;
+
+	/* Build string */
+	va_start(ap, fmt);
+	res = ast_dynamic_str_thread_set_va(&buf, 0, &verbose_buf, fmt, ap);
+	va_end(ap);
+
+	/* If the build failed, then abort and free this structure */
+	if (res == AST_DYNSTR_BUILD_FAILED) {
+		free(logmsg);
+		return;
+	}
+
+	/* Copy string over */
+	logmsg->str = ast_strdup(buf->str);
+
+	/* Add it to the list at the tail end, and prod the logging thread */
+	AST_LIST_LOCK(&logmsgs);
+	AST_LIST_INSERT_TAIL(&logmsgs, logmsg, list);
+	ast_cond_signal(&logcond);
+	AST_LIST_UNLOCK(&logmsgs);
+
+	return;
 }
 
 void ast_backtrace(void)
@@ -842,10 +946,16 @@
 
 void ast_verbose(const char *fmt, ...)
 {
-	struct verb *v;
-	struct ast_dynamic_str *buf;
-	int res;
+	struct logmsg *logmsg = NULL;
+	struct ast_dynamic_str *buf = NULL;
+	int res = 0;
 	va_list ap;
+
+	if (!(buf = ast_dynamic_str_thread_get(&verbose_buf, VERBOSE_BUF_INIT_SIZE)))
+		return;
+
+	if (!(logmsg = ast_calloc(1, sizeof(*logmsg))))
+		return;
 
 	if (ast_opt_timestamp) {
 		time_t t;
@@ -861,22 +971,29 @@
 		fmt = datefmt;
 	}
 
-	if (!(buf = ast_dynamic_str_thread_get(&verbose_buf, VERBOSE_BUF_INIT_SIZE)))
-		return;
-
+	/* Set type */
+	logmsg->type = LOGMSG_VERBOSE;
+	
+	/* Build string */
 	va_start(ap, fmt);
 	res = ast_dynamic_str_thread_set_va(&buf, 0, &verbose_buf, fmt, ap);
 	va_end(ap);
 
-	if (res == AST_DYNSTR_BUILD_FAILED)
-		return;
-
-	AST_LIST_LOCK(&verbosers);
-	AST_LIST_TRAVERSE(&verbosers, v, list)
-		v->verboser(buf->str);
-	AST_LIST_UNLOCK(&verbosers);
-
+	/* If the build failed then we can drop this allocated message */
+	if (res == AST_DYNSTR_BUILD_FAILED) {
+		free(logmsg);
+		return;
+	}
+
+	/* Duplicate it in the logging message */
+	logmsg->str = ast_strdup(buf->str);
 	ast_log(LOG_VERBOSE, "%s", buf->str);
+
+	/* Add to the list and poke the thread */
+	AST_LIST_LOCK(&logmsgs);
+	AST_LIST_INSERT_TAIL(&logmsgs, logmsg, list);
+	ast_cond_signal(&logcond);
+	AST_LIST_UNLOCK(&logmsgs);
 }
 
 int ast_register_verbose(void (*v)(const char *string)) 



More information about the asterisk-commits mailing list