[asterisk-commits] jrose: trunk r360785 - in /trunk: ./ apps/ configs/ include/asterisk/ main/
SVN commits to the Asterisk project
asterisk-commits at lists.digium.com
Thu Mar 29 14:54:40 CDT 2012
Author: jrose
Date: Thu Mar 29 14:54:35 2012
New Revision: 360785
URL: http://svnview.digium.com/svn/asterisk?view=rev&rev=360785
Log:
Introducing the log message unique call identifiers feature
Log messages will now display a call number that they are tied to (ordered for calls
based on when they started). This feature is made to be minimally invasive without
requiring changes to many of the existing log messages. These IDs won't show up for
verbose messages on CLI (but they will in log files) This is currently in phase II
of production, see more about this feature on the wiki --
https://wiki.asterisk.org/wiki/display/AST/Unique+Call-ID+Logging
Review: https://reviewboard.asterisk.org/r/1823/
Modified:
trunk/ (props changed)
trunk/CHANGES
trunk/apps/app_mixmonitor.c
trunk/configs/logger.conf.sample
trunk/include/asterisk/bridging.h
trunk/include/asterisk/logger.h
trunk/main/dial.c
trunk/main/features.c
trunk/main/logger.c
trunk/main/pbx.c
Propchange: trunk/
------------------------------------------------------------------------------
automerge = *
Propchange: trunk/
------------------------------------------------------------------------------
automerge-email = jrose at digium.com
Propchange: trunk/
------------------------------------------------------------------------------
svnmerge-integrated = /trunk:1-360732
Modified: trunk/CHANGES
URL: http://svnview.digium.com/svn/asterisk/trunk/CHANGES?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/CHANGES (original)
+++ trunk/CHANGES Thu Mar 29 14:54:35 2012
@@ -23,6 +23,10 @@
modules that are loaded into Asterisk, since they should only be called once
in any single process. If desired, this feature can be disabled by supplying
the "--disable-asteriskssl" option to the configure script.
+ * Threads belonging to a particular call are now linked with callids which get
+ added to any log messages produced by those threads. Log messages can now be
+ easily identified as involved with a certain call by looking at their call id.
+ This feature can be disabled in logger.conf with the display_callids option.
CLI Changes
-------------------
Modified: trunk/apps/app_mixmonitor.c
URL: http://svnview.digium.com/svn/asterisk/trunk/apps/app_mixmonitor.c?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/apps/app_mixmonitor.c (original)
+++ trunk/apps/app_mixmonitor.c Thu Mar 29 14:54:35 2012
@@ -240,6 +240,7 @@
struct mixmonitor {
struct ast_audiohook audiohook;
+ struct ast_callid *callid;
char *filename;
char *filename_read;
char *filename_write;
@@ -395,6 +396,10 @@
ast_free(mixmonitor->name);
ast_free(mixmonitor->post_process);
}
+
+ if (mixmonitor->callid) {
+ ast_callid_unref(mixmonitor->callid);
+ }
ast_free(mixmonitor);
}
}
@@ -440,6 +445,11 @@
int errflag = 0;
struct ast_format format_slin;
+ /* Keep callid association before any log messages */
+ if (mixmonitor->callid) {
+ ast_callid_threadassoc_add(mixmonitor->callid);
+ }
+
ast_verb(2, "Begin MixMonitor Recording %s\n", mixmonitor->name);
fs = &mixmonitor->mixmonitor_ds->fs;
@@ -673,6 +683,9 @@
mixmonitor_free(mixmonitor);
return;
}
+
+ /* reference be released at mixmonitor destruction */
+ mixmonitor->callid = ast_read_threadstorage_callid();
ast_pthread_create_detached_background(&thread, NULL, mixmonitor_thread, mixmonitor);
}
Modified: trunk/configs/logger.conf.sample
URL: http://svnview.digium.com/svn/asterisk/trunk/configs/logger.conf.sample?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/configs/logger.conf.sample (original)
+++ trunk/configs/logger.conf.sample Thu Mar 29 14:54:35 2012
@@ -18,6 +18,11 @@
;
;dateformat=%F %T ; ISO 8601 date format
;dateformat=%F %T.%3q ; with milliseconds
+;
+;
+; This makes Asterisk write callids to log messages
+; (defaults to yes)
+;use_callids = no
;
; This appends the hostname to the name of the log files.
;appendhostname = yes
Modified: trunk/include/asterisk/bridging.h
URL: http://svnview.digium.com/svn/asterisk/trunk/include/asterisk/bridging.h?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/include/asterisk/bridging.h (original)
+++ trunk/include/asterisk/bridging.h Thu Mar 29 14:54:35 2012
@@ -165,6 +165,8 @@
struct ast_bridge_tech_optimizations tech_args;
/*! Queue of DTMF digits used for DTMF streaming */
char dtmf_stream_q[8];
+ /*! Call ID associated with bridge channel */
+ struct ast_callid *callid;
/*! Linked list information */
AST_LIST_ENTRY(ast_bridge_channel) entry;
};
@@ -243,9 +245,11 @@
size_t array_num;
/*! Number of channels the array can handle */
size_t array_size;
+ /*! Call ID associated with the bridge */
+ struct ast_callid *callid;
/*! Linked list of channels participating in the bridge */
AST_LIST_HEAD_NOLOCK(, ast_bridge_channel) channels;
-};
+ };
/*! \brief Create a new bridge
*
Modified: trunk/include/asterisk/logger.h
URL: http://svnview.digium.com/svn/asterisk/trunk/include/asterisk/logger.h?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/include/asterisk/logger.h (original)
+++ trunk/include/asterisk/logger.h Thu Mar 29 14:54:35 2012
@@ -59,6 +59,24 @@
void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...)
__attribute__((format(printf, 5, 6)));
+
+/* XXX needs documentation */
+struct ast_callid;
+
+/*! \brief Used for sending a log message with a known call_id
+ This is a modified logger function which is functionally identical to the above logger function,
+ it just include a call_id argument as well. If NULL is specified here, no attempt will be made to
+ join the log message with a call_id.
+
+ \param level Type of log event
+ \param file Will be provided by the AST_LOG_* macro
+ \param line Will be provided by the AST_LOG_* macro
+ \param function Will be provided by the AST_LOG_* macro
+ \param callid This is the ast_callid that is associated with the log message. May be NULL.
+ \param fmt This is what is important. The format is the same as your favorite breed of printf. You know how that works, right? :-)
+*/
+void ast_log_callid(int level, const char *file, int line, const char *function, struct ast_callid *callid, const char *fmt, ...)
+ __attribute__((format(printf, 6, 7)));
void ast_backtrace(void);
@@ -214,6 +232,56 @@
* \since 1.8
*/
void ast_logger_unregister_level(const char *name);
+
+/*!
+ * \brief factory function to create a new uniquely identifying callid.
+ *
+ * \retval ast_callid struct pointer containing the call id
+ *
+ * \note The newly created callid will be referenced upon creation and this function should be
+ * paired with a call to ast_callid_unref()
+ */
+struct ast_callid *ast_create_callid(void);
+
+/*!
+ * \brief extracts the callerid from the thread
+ *
+ * \retval ast_callid reference to call_id related to the thread
+ * \retval NULL if no call_id is present in the thread
+ *
+ * This reference must be unreffed before it loses scope to prevent memory leaks.
+ */
+struct ast_callid *ast_read_threadstorage_callid(void);
+
+/*!
+ * \brief Increase callid reference count
+ *
+ * \param c the ast_callid
+ *
+ * \retval c always
+ */
+#define ast_callid_ref(c) ({ ao2_ref(c, +1); (c); })
+
+/*!
+ * \brief Decrease callid reference count
+ *
+ * \param c the ast_callid
+ *
+ * \retval NULL always
+ */
+#define ast_callid_unref(c) ({ ao2_ref(c, -1); (NULL); })
+
+/*!
+ * \brief Adds a known callid to thread storage of the calling thread
+ *
+ * \retval 0 - success
+ * \retval non-zero - failure
+ */
+int ast_callid_threadassoc_add(struct ast_callid *callid);
+
+/*
+ * May need a function to clean the threadstorage if we want to repurpose a thread.
+ */
/*!
* \brief Send a log message to a dynamically registered log level
Modified: trunk/main/dial.c
URL: http://svnview.digium.com/svn/asterisk/trunk/main/dial.c?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/main/dial.c (original)
+++ trunk/main/dial.c Thu Mar 29 14:54:35 2012
@@ -50,6 +50,7 @@
void *user_data; /*!< Attached user data */
AST_LIST_HEAD(, ast_dial_channel) channels; /*!< Channels being dialed */
pthread_t thread; /*!< Thread (if running in async) */
+ struct ast_callid *callid; /*!< callid pointer (if running in async) */
ast_mutex_t lock; /*! Lock to protect the thread information above */
};
@@ -705,6 +706,9 @@
static void *async_dial(void *data)
{
struct ast_dial *dial = data;
+ if (dial->callid) {
+ ast_callid_threadassoc_add(dial->callid);
+ }
/* This is really really simple... we basically pass monitor_dial a NULL owner and it changes it's behavior */
monitor_dial(dial, NULL);
@@ -738,6 +742,8 @@
/* If we are running async spawn a thread and send it away... otherwise block here */
if (async) {
+ /* reference be released at dial destruction if it isn't NULL */
+ dial->callid = ast_read_threadstorage_callid();
dial->state = AST_DIAL_RESULT_TRYING;
/* Try to create a thread */
if (ast_pthread_create(&dial->thread, NULL, async_dial, dial)) {
@@ -913,6 +919,11 @@
/* Lock be gone! */
ast_mutex_destroy(&dial->lock);
+ /* Get rid of the reference to the ast_callid */
+ if (dial->callid) {
+ ast_callid_unref(dial->callid);
+ }
+
/* Free structure */
ast_free(dial);
Modified: trunk/main/features.c
URL: http://svnview.digium.com/svn/asterisk/trunk/main/features.c?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/main/features.c (original)
+++ trunk/main/features.c Thu Mar 29 14:54:35 2012
@@ -844,6 +844,7 @@
struct ast_bridge_config bconfig;
struct ast_channel *chan;
struct ast_channel *peer;
+ struct ast_callid *callid; /*<! callid pointer (Only used to bind thread) */
unsigned int return_to_pbx:1;
};
@@ -948,6 +949,12 @@
{
struct ast_bridge_thread_obj *tobj = data;
int res;
+
+ if (tobj->callid) {
+ ast_callid_threadassoc_add(tobj->callid);
+ /* Need to deref and set to null since ast_bridge_thread_obj has no common destructor */
+ tobj->callid = ast_callid_unref(tobj->callid);
+ }
ast_channel_appl_set(tobj->chan, !tobj->return_to_pbx ? "Transferred Call" : "ManagerBridge");
ast_channel_data_set(tobj->chan, ast_channel_name(tobj->peer));
@@ -987,15 +994,23 @@
*
* Create thread and attributes, call bridge_call_thread
*/
-static void bridge_call_thread_launch(void *data)
+static void bridge_call_thread_launch(struct ast_bridge_thread_obj *data)
{
pthread_t thread;
pthread_attr_t attr;
struct sched_param sched;
+ /* This needs to be unreffed once it has been associated with the new thread. */
+ data->callid = ast_read_threadstorage_callid();
+
pthread_attr_init(&attr);
pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
- ast_pthread_create(&thread, &attr, bridge_call_thread, data);
+ if (ast_pthread_create(&thread, &attr, bridge_call_thread, data)) {
+ /* Failed to create thread. Ditch the reference to callid. */
+ ast_callid_unref(data->callid);
+ ast_log(LOG_ERROR, "Failed to create bridge_call_thread.\n");
+ return;
+ }
pthread_attr_destroy(&attr);
memset(&sched, 0, sizeof(sched));
pthread_setschedparam(thread, SCHED_RR, &sched);
@@ -8263,3 +8278,4 @@
return res;
}
+
Modified: trunk/main/logger.c
URL: http://svnview.digium.com/svn/asterisk/trunk/main/logger.c?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/main/logger.c (original)
+++ trunk/main/logger.c Thu Mar 29 14:54:35 2012
@@ -43,6 +43,7 @@
#include "asterisk/cli.h"
#include "asterisk/utils.h"
#include "asterisk/manager.h"
+#include "asterisk/astobj2.h"
#include "asterisk/threadstorage.h"
#include "asterisk/strings.h"
#include "asterisk/pbx.h"
@@ -73,6 +74,15 @@
static unsigned int global_logmask = 0xFFFF;
static int queuelog_init;
static int logger_initialized;
+static volatile int next_unique_callid; /* Used to assign unique call_ids to calls */
+static int display_callids;
+static void unique_callid_cleanup(void *data);
+
+struct ast_callid {
+ int call_identifier; /* Numerical value of the call displayed in the logs */
+};
+
+AST_THREADSTORAGE_CUSTOM(unique_callid, NULL, unique_callid_cleanup);
static enum rotatestrategy {
SEQUENTIAL = 1 << 0, /* Original method - create a new file, in order */
@@ -129,6 +139,7 @@
int level;
int line;
int lwp;
+ struct ast_callid *callid;
AST_DECLARE_STRING_FIELDS(
AST_STRING_FIELD(date);
AST_STRING_FIELD(file);
@@ -138,6 +149,14 @@
);
AST_LIST_ENTRY(logmsg) list;
};
+
+static void logmsg_free(struct logmsg *msg)
+{
+ if (msg->callid) {
+ ast_callid_unref(msg->callid);
+ }
+ ast_free(msg);
+}
static AST_LIST_HEAD_STATIC(logmsgs, logmsg);
static pthread_t logthread = AST_PTHREADT_NULL;
@@ -320,6 +339,8 @@
const char *s;
struct ast_flags config_flags = { 0 };
+ display_callids = 1;
+
if (!(cfg = ast_config_load2(S_OR(altconf, "logger.conf"), "logger", config_flags)) || cfg == CONFIG_STATUS_FILEINVALID) {
return;
}
@@ -373,6 +394,9 @@
hostname[0] = '\0';
} else
hostname[0] = '\0';
+ if ((s = ast_variable_retrieve(cfg, "general", "display_callids"))) {
+ display_callids = ast_true(s);
+ }
if ((s = ast_variable_retrieve(cfg, "general", "dateformat")))
ast_copy_string(dateformat, s, sizeof(dateformat));
else
@@ -999,6 +1023,14 @@
if (!AST_RWLIST_EMPTY(&logchannels)) {
AST_RWLIST_TRAVERSE(&logchannels, chan, list) {
+ /* XXX May need to grow larger later in order to accomodate call counts higher than 999999. */
+ char call_identifier_str[13] = "";
+
+ if (logmsg->callid) {
+ snprintf(call_identifier_str, sizeof(call_identifier_str), "[C-%08x]", logmsg->callid->call_identifier);
+ }
+
+
/* If the channel is disabled, then move on to the next one */
if (chan->disabled) {
continue;
@@ -1022,10 +1054,11 @@
/* 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[%d]: %s:%s %s: %s",
+ snprintf(buf, sizeof(buf), "[%s] %s[%d]%s: %s:%s %s: %s",
logmsg->date,
term_color(tmp1, logmsg->level_name, colors[logmsg->level], 0, sizeof(tmp1)),
logmsg->lwp,
+ call_identifier_str,
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)),
@@ -1042,8 +1075,9 @@
}
/* Print out to the file */
- res = fprintf(chan->fileptr, "[%s] %s[%d] %s: %s",
- logmsg->date, logmsg->level_name, logmsg->lwp, logmsg->file, term_strip(buf, logmsg->message, BUFSIZ));
+ res = fprintf(chan->fileptr, "[%s] %s[%d]%s %s: %s",
+ logmsg->date, logmsg->level_name, logmsg->lwp, call_identifier_str,
+ logmsg->file, term_strip(buf, logmsg->message, BUFSIZ));
if (res <= 0 && !ast_strlen_zero(logmsg->message)) {
fprintf(stderr, "**** Asterisk Logging Error: ***********\n");
if (errno == ENOMEM || errno == ENOSPC)
@@ -1100,7 +1134,7 @@
logger_print_normal(msg);
/* Free the data since we are done */
- ast_free(msg);
+ logmsg_free(msg);
}
/* If we should stop, then stop */
@@ -1203,17 +1237,83 @@
return;
}
+struct ast_callid *ast_create_callid(void)
+{
+ struct ast_callid *call;
+ int using;
+
+ if (!(call = ao2_alloc(sizeof(struct ast_callid), NULL))) {
+ ast_log(LOG_ERROR, "Could not allocate callid struct.\n");
+ return NULL;
+ }
+
+ using = ast_atomic_fetchadd_int(&next_unique_callid, +1);
+
+ call->call_identifier = using;
+ ast_log(LOG_DEBUG, "CALL_ID [C-%08x] created by thread.\n", call->call_identifier);
+ return call;
+}
+
+struct ast_callid *ast_read_threadstorage_callid(void)
+{
+ struct ast_callid **callid;
+ callid = ast_threadstorage_get(&unique_callid, sizeof(struct ast_callid **));
+ if (callid && *callid) {
+ ast_callid_ref(*callid);
+ return *callid;
+ }
+
+ return NULL;
+
+}
+
+int ast_callid_threadassoc_add(struct ast_callid *callid)
+{
+ struct ast_callid **pointing;
+ pointing = ast_threadstorage_get(&unique_callid, sizeof(struct ast_callid **));
+ if (!(pointing)) {
+ ast_log(LOG_ERROR, "Failed to allocate thread storage.\n");
+ return -1;
+ }
+
+ if (!(*pointing)) {
+ /* callid will be unreffed at thread destruction */
+ ast_callid_ref(callid);
+ *pointing = callid;
+ ast_log(LOG_DEBUG, "CALL_ID [C-%08x] bound to thread.\n", callid->call_identifier);
+ } else {
+ ast_log(LOG_WARNING, "Attempted to ast_callid_threadassoc_add on thread already associated with a callid.\n");
+ return 1;
+ }
+
+ return 0;
+}
+
+/*!
+ * \internal
+ * \brief thread storage cleanup function for unique_callid
+ */
+static void unique_callid_cleanup(void *data)
+{
+ struct ast_callid **callid = data;
+
+ if (*callid) {
+ ast_callid_unref(*callid);
+ }
+
+ ast_free(data);
+}
+
/*!
* \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 __attribute__((format(printf, 6, 0))) ast_log_full(int level, const char *file, int line, const char *function, struct 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;
- va_list ap;
char datestring[256];
if (!(buf = ast_str_thread_get(&log_buf, LOG_BUF_INIT_SIZE)))
@@ -1225,9 +1325,7 @@
* so just log to stdout
*/
int result;
- va_start(ap, fmt);
result = ast_str_set_va(&buf, BUFSIZ, fmt, ap); /* XXX BUFSIZ ? */
- va_end(ap);
if (result != AST_DYNSTR_BUILD_FAILED) {
term_filter_escapes(ast_str_buffer(buf));
fputs(ast_str_buffer(buf), stdout);
@@ -1240,9 +1338,7 @@
return;
/* Build string */
- va_start(ap, fmt);
res = ast_str_set_va(&buf, BUFSIZ, fmt, ap);
- va_end(ap);
/* If the build failed, then abort and free this structure */
if (res == AST_DYNSTR_BUILD_FAILED)
@@ -1260,6 +1356,11 @@
logmsg->type = LOGMSG_VERBOSE;
} else {
logmsg->type = LOGMSG_NORMAL;
+ }
+
+ if (display_callids && callid) {
+ logmsg->callid = ast_callid_ref(callid);
+ /* callid will be unreffed at logmsg destruction */
}
/* Create our date/time */
@@ -1283,10 +1384,34 @@
AST_LIST_UNLOCK(&logmsgs);
} else {
logger_print_normal(logmsg);
- ast_free(logmsg);
+ logmsg_free(logmsg);
}
return;
+}
+
+void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...)
+{
+ struct ast_callid *callid;
+ va_list ap;
+
+ callid = ast_read_threadstorage_callid();
+
+ va_start(ap, fmt);
+ ast_log_full(level, file, line, function, callid, fmt, ap);
+ va_end(ap);
+
+ if (callid) {
+ ast_callid_unref(callid);
+ }
+}
+
+void ast_log_callid(int level, const char *file, int line, const char *function, struct ast_callid *callid, const char *fmt, ...)
+{
+ va_list ap;
+ va_start(ap, fmt);
+ ast_log_full(level, file, line, function, callid, fmt, ap);
+ va_end(ap);
}
#ifdef HAVE_BKTR
Modified: trunk/main/pbx.c
URL: http://svnview.digium.com/svn/asterisk/trunk/main/pbx.c?view=diff&rev=360785&r1=360784&r2=360785
==============================================================================
--- trunk/main/pbx.c (original)
+++ trunk/main/pbx.c Thu Mar 29 14:54:35 2012
@@ -5486,6 +5486,11 @@
*/
struct ast_channel *c = data;
+ /* Associate new PBX thread with a call-id */
+ struct ast_callid *callid = ast_create_callid();
+ ast_callid_threadassoc_add(callid);
+ callid = ast_callid_unref(callid);
+
__ast_pbx_run(c, NULL);
decrease_call_count();
More information about the asterisk-commits
mailing list