diff --git a/CHANGES b/CHANGES
index d42be61deff72ff0b96943f56e5e5dbbb1eacd12..75a7e87aed17f67d6c429b84e6dd700e4c6c2414 100644
--- a/CHANGES
+++ b/CHANGES
@@ -23,6 +23,10 @@ Core
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
-------------------
diff --git a/apps/app_mixmonitor.c b/apps/app_mixmonitor.c
index a89b6cc5dd4121c169b915e3c4f8730325caeb8b..c1f5ada72b660bc7e48baa4d713043383769f4eb 100644
--- a/apps/app_mixmonitor.c
+++ b/apps/app_mixmonitor.c
@@ -240,6 +240,7 @@ static const char * const mixmonitor_spy_type = "MixMonitor";
struct mixmonitor {
struct ast_audiohook audiohook;
+ struct ast_callid *callid;
char *filename;
char *filename_read;
char *filename_write;
@@ -395,6 +396,10 @@ static void mixmonitor_free(struct mixmonitor *mixmonitor)
ast_free(mixmonitor->name);
ast_free(mixmonitor->post_process);
}
+
+ if (mixmonitor->callid) {
+ ast_callid_unref(mixmonitor->callid);
+ }
ast_free(mixmonitor);
}
}
@@ -440,6 +445,11 @@ static void *mixmonitor_thread(void *obj)
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;
@@ -674,6 +684,9 @@ static void launch_monitor_thread(struct ast_channel *chan, const char *filename
return;
}
+ /* reference be released at mixmonitor destruction */
+ mixmonitor->callid = ast_read_threadstorage_callid();
+
ast_pthread_create_detached_background(&thread, NULL, mixmonitor_thread, mixmonitor);
}
diff --git a/configs/logger.conf.sample b/configs/logger.conf.sample
index 3f4850788b53153f832e59319f9bcbe43edf92b6..1fdac703015cf35194807d4775af89380cbc26a6 100644
--- a/configs/logger.conf.sample
+++ b/configs/logger.conf.sample
@@ -19,6 +19,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
;
diff --git a/include/asterisk/bridging.h b/include/asterisk/bridging.h
index 3c117b7cd2d12744b0eb42ad5df6c500accafb44..831f340c882e719b6e54a8ae0f1dd5c854e96790 100644
--- a/include/asterisk/bridging.h
+++ b/include/asterisk/bridging.h
@@ -165,6 +165,8 @@ struct ast_bridge_channel {
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 @@ struct ast_bridge {
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
*
diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h
index c7f260c491b4cf114448db5df51d0ed442c58248..a495449635ebd35f7fffd4856df3c459aeabdf56 100644
--- a/include/asterisk/logger.h
+++ b/include/asterisk/logger.h
@@ -60,6 +60,24 @@ extern "C" {
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);
/*! \brief Reload logger without rotating log files */
@@ -215,6 +233,56 @@ int ast_logger_register_level(const char *name);
*/
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
* \param level The log level to send the message to
diff --git a/main/dial.c b/main/dial.c
index d65cb8a65a1d2167ac57ad32c00109858dafe053..251eab9ba85c397bc0835f03cb3bc40ca4d2cb97 100644
--- a/main/dial.c
+++ b/main/dial.c
@@ -50,6 +50,7 @@ struct ast_dial {
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 enum ast_dial_result monitor_dial(struct ast_dial *dial, struct ast_chann
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 @@ enum ast_dial_result ast_dial_run(struct ast_dial *dial, struct ast_channel *cha
/* 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 @@ int ast_dial_destroy(struct ast_dial *dial)
/* 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);
diff --git a/main/features.c b/main/features.c
index 71be7d3f7d7ca9bb9e5369a9bdec90eecb6c56db..d23bda4a19e670c734dff074587d7b4397e2abb8 100644
--- a/main/features.c
+++ b/main/features.c
@@ -844,6 +844,7 @@ struct ast_bridge_thread_obj
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;
};
@@ -949,6 +950,12 @@ static void *bridge_call_thread(void *data)
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));
ast_channel_appl_set(tobj->peer, !tobj->return_to_pbx ? "Transferred Call" : "ManagerBridge");
@@ -987,15 +994,23 @@ static void *bridge_call_thread(void *data)
*
* 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 @@ int ast_features_init(void)
return res;
}
+
diff --git a/main/logger.c b/main/logger.c
index 37f13cea6e15c9c198d27abd6ab94a7ba95dcf90..5891e87097fb84894dacc1a47955cd30d73bafe7 100644
--- a/main/logger.c
+++ b/main/logger.c
@@ -43,6 +43,7 @@ ASTERISK_FILE_VERSION(__FILE__, "$Revision$")
#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 int filesize_reload_needed;
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 @@ struct logmsg {
int level;
int line;
int lwp;
+ struct ast_callid *callid;
AST_DECLARE_STRING_FIELDS(
AST_STRING_FIELD(date);
AST_STRING_FIELD(file);
@@ -139,6 +150,14 @@ struct logmsg {
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;
static ast_cond_t logcond;
@@ -320,6 +339,8 @@ static void init_logger_chain(int locked, const char *altconf)
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 @@ static void init_logger_chain(int locked, const char *altconf)
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 @@ static void logger_print_normal(struct logmsg *logmsg)
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 @@ static void logger_print_normal(struct logmsg *logmsg)
/* 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 @@ static void logger_print_normal(struct logmsg *logmsg)
}
/* 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 @@ static void *logger_thread(void *data)
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 @@ void close_logger(void)
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 @@ void ast_log(int level, const char *file, int line, const char *function, const
* 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 @@ void ast_log(int level, const char *file, int line, const char *function, const
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)
@@ -1262,6 +1358,11 @@ void ast_log(int level, const char *file, int line, const char *function, const
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 */
ast_localtime(&now, &tm, NULL);
ast_strftime(datestring, sizeof(datestring), dateformat, &tm);
@@ -1283,12 +1384,36 @@ void ast_log(int level, const char *file, int line, const char *function, const
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
struct ast_bt *ast_bt_create(void)
diff --git a/main/pbx.c b/main/pbx.c
index 17d941fa22d97fb75be11ae223a2f1d17380525f..cdeccaf9d19a82ce4803c068073cd8bf4d105a52 100644
--- a/main/pbx.c
+++ b/main/pbx.c
@@ -5486,6 +5486,11 @@ static void *pbx_thread(void *data)
*/
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();