Import the new logging architecture
This is the new logging architecture, including
* support for multiuple logging targets like stderr and vty
* log levels in addition to categories/subsystems
* filtering based on imsi, i.e. only see events for one subscriber
* dynamically change log level for each category for each vty
diff --git a/openbsc/src/abis_rsl.c b/openbsc/src/abis_rsl.c
index 787a803..d669ba0 100644
--- a/openbsc/src/abis_rsl.c
+++ b/openbsc/src/abis_rsl.c
@@ -237,6 +237,8 @@
}
lchan = &ts->lchan[lch_idx];
+ debug_set_context(BSC_CTX_LCHAN, lchan);
+ debug_set_context(BSC_CTX_SUBSCR, lchan->subscr);
return lchan;
}
diff --git a/openbsc/src/bs11_config.c b/openbsc/src/bs11_config.c
index 2a80a49..b2470a9 100644
--- a/openbsc/src/bs11_config.c
+++ b/openbsc/src/bs11_config.c
@@ -71,6 +71,8 @@
static const u_int8_t too_fast[] = { 0x12, 0x80, 0x00, 0x00, 0x02, 0x02 };
+static struct debug_target *stderr_target;
+
/* dummy function to keep gsm_data.c happy */
struct counter *counter_alloc(const char *name)
{
@@ -759,7 +761,7 @@
serial_port = optarg;
break;
case 'b':
- debug_parse_category_mask(optarg);
+ debug_parse_category_mask(stderr_target, optarg);
break;
case 's':
fname_software = optarg;
@@ -812,6 +814,10 @@
struct gsm_network *gsmnet;
int rc;
+ debug_init();
+ stderr_target = debug_target_create_stderr();
+ debug_add_target(stderr_target);
+ debug_set_all_filter(stderr_target, 1);
handle_options(argc, argv);
gsmnet = gsm_network_init(1, 1, NULL);
diff --git a/openbsc/src/bsc_hack.c b/openbsc/src/bsc_hack.c
index a9a5d37..0d20d43 100644
--- a/openbsc/src/bsc_hack.c
+++ b/openbsc/src/bsc_hack.c
@@ -38,6 +38,7 @@
#include <openbsc/signal.h>
/* MCC and MNC for the Location Area Identifier */
+static struct debug_target *stderr_target;
struct gsm_network *bsc_gsmnet = 0;
static const char *database_name = "hlr.sqlite3";
static const char *config_file = "openbsc.cfg";
@@ -105,10 +106,10 @@
print_help();
exit(0);
case 's':
- debug_use_color(0);
+ debug_set_use_color(stderr_target, 0);
break;
case 'd':
- debug_parse_category_mask(optarg);
+ debug_parse_category_mask(stderr_target, optarg);
break;
case 'l':
database_name = strdup(optarg);
@@ -120,7 +121,7 @@
create_pcap_file(optarg);
break;
case 'T':
- debug_timestamp(1);
+ debug_set_print_timestamp(stderr_target, 1);
break;
case 'P':
ipacc_rtp_direct = 0;
@@ -158,11 +159,17 @@
{
int rc;
+ debug_init();
tall_bsc_ctx = talloc_named_const(NULL, 1, "openbsc");
talloc_ctx_init();
on_dso_load_token();
on_dso_load_rrlp();
on_dso_load_ho_dec();
+ stderr_target = debug_target_create_stderr();
+ debug_add_target(stderr_target);
+
+ /* enable filters */
+ debug_set_all_filter(stderr_target, 1);
/* parse options */
handle_options(argc, argv);
@@ -193,6 +200,7 @@
while (1) {
bsc_upqueue(bsc_gsmnet);
+ debug_reset_context();
bsc_select_main(0);
}
}
diff --git a/openbsc/src/bsc_mgcp.c b/openbsc/src/bsc_mgcp.c
index 6d5e6b1..fff6d60 100644
--- a/openbsc/src/bsc_mgcp.c
+++ b/openbsc/src/bsc_mgcp.c
@@ -1084,8 +1084,15 @@
struct gsm_network dummy_network;
struct sockaddr_in addr;
int on = 1, i, rc;
+ struct debug_target *stderr_target;
tall_bsc_ctx = talloc_named_const(NULL, 1, "mgcp-callagent");
+
+ debug_init();
+ stderr_target = debug_target_create_stderr();
+ debug_add_target(stderr_target);
+ debug_set_all_filter(stderr_target, 1);
+
handle_options(argc, argv);
telnet_init(&dummy_network, 4243);
diff --git a/openbsc/src/debug.c b/openbsc/src/debug.c
index 6e99d41..d3d58f3 100644
--- a/openbsc/src/debug.c
+++ b/openbsc/src/debug.c
@@ -27,21 +27,53 @@
#include <time.h>
#include <openbsc/debug.h>
+#include <openbsc/talloc.h>
+#include <openbsc/gsm_data.h>
+#include <openbsc/gsm_subscriber.h>
-unsigned int debug_mask = 0xffffffff & ~(DMI|DMIB|DMEAS);
+/* default categories */
+static struct debug_category default_categories[Debug_LastEntry] = {
+ [DRLL] = { .enabled = 1, .loglevel = 0},
+ [DCC] = { .enabled = 1, .loglevel = 0},
+ [DMM] = { .enabled = 1, .loglevel = 0},
+ [DRR] = { .enabled = 1, .loglevel = 0},
+ [DRSL] = { .enabled = 1, .loglevel = 0},
+ [DMM] = { .enabled = 1, .loglevel = 0},
+ [DMNCC] = { .enabled = 1, .loglevel = 0},
+ [DSMS] = { .enabled = 1, .loglevel = 0},
+ [DPAG] = { .enabled = 1, .loglevel = 0},
+ [DMEAS] = { .enabled = 0, .loglevel = 0},
+ [DMI] = { .enabled = 0, .loglevel = 0},
+ [DMIB] = { .enabled = 0, .loglevel = 0},
+ [DMUX] = { .enabled = 1, .loglevel = 0},
+ [DINP] = { .enabled = 1, .loglevel = 0},
+ [DSCCP] = { .enabled = 1, .loglevel = 0},
+ [DMSC] = { .enabled = 1, .loglevel = 0},
+ [DMGCP] = { .enabled = 1, .loglevel = 0},
+ [DHO] = { .enabled = 1, .loglevel = 0},
+};
struct debug_info {
const char *name;
const char *color;
const char *description;
int number;
+ int position;
};
+struct debug_context {
+ struct gsm_lchan *lchan;
+ struct gsm_subscriber *subscr;
+ struct gsm_bts *bts;
+};
+
+static struct debug_context debug_context;
+static void *tall_dbg_ctx = NULL;
+static LLIST_HEAD(target_list);
+
#define DEBUG_CATEGORY(NUMBER, NAME, COLOR, DESCRIPTION) \
{ .name = NAME, .color = COLOR, .description = DESCRIPTION, .number = NUMBER },
-#define ARRAY_SIZE(array) (sizeof(array)/sizeof(array[0]))
-
static const struct debug_info debug_info[] = {
DEBUG_CATEGORY(DRLL, "DRLL", "\033[1;31m", "")
DEBUG_CATEGORY(DCC, "DCC", "\033[1;32m", "")
@@ -63,50 +95,51 @@
DEBUG_CATEGORY(DHO, "DHO", "", "")
};
-static int use_color = 1;
-
-void debug_use_color(int color)
-{
- use_color = color;
-}
-
-static int print_timestamp = 0;
-
-void debug_timestamp(int enable)
-{
- print_timestamp = enable;
-}
-
-
/*
* Parse the category mask.
- * category1:category2:category3
+ * The format can be this: category1:category2:category3
+ * or category1,2:category2,3:...
*/
-void debug_parse_category_mask(const char *_mask)
+void debug_parse_category_mask(struct debug_target* target, const char *_mask)
{
- unsigned int new_mask = 0;
int i = 0;
char *mask = strdup(_mask);
char *category_token = NULL;
+ /* Disable everything to enable it afterwards */
+ for (i = 0; i < ARRAY_SIZE(target->categories); ++i)
+ target->categories[i].enabled = 0;
+
category_token = strtok(mask, ":");
do {
for (i = 0; i < ARRAY_SIZE(debug_info); ++i) {
- if (strcasecmp(debug_info[i].name, category_token) == 0)
- new_mask |= debug_info[i].number;
+ char* colon = strstr(category_token, ",");
+ int length = strlen(category_token);
+
+ if (colon)
+ length = colon - category_token;
+
+ if (strncasecmp(debug_info[i].name, category_token, length) == 0) {
+ int number = debug_info[i].number;
+ int level = 0;
+
+ if (colon)
+ level = atoi(colon+1);
+
+ target->categories[number].enabled = 1;
+ target->categories[number].loglevel = level;
+ }
}
} while ((category_token = strtok(NULL, ":")));
-
free(mask);
- debug_mask = new_mask;
}
-const char* color(int subsys)
+static const char* color(int subsys)
{
int i = 0;
- for (i = 0; use_color && i < ARRAY_SIZE(debug_info); ++i) {
+ for (i = 0; i < ARRAY_SIZE(debug_info); ++i) {
if (debug_info[i].number == subsys)
return debug_info[i].color;
}
@@ -114,35 +147,97 @@
return "";
}
-void debugp(unsigned int subsys, char *file, int line, int cont, const char *format, ...)
+static void _output(struct debug_target *target, unsigned int subsys, char *file, int line,
+ int cont, const char *format, va_list ap)
{
- va_list ap;
- FILE *outfd = stderr;
+ char col[30];
+ char sub[30];
+ char tim[30];
+ char buf[4096];
+ char final[4096];
- if (!(debug_mask & subsys))
- return;
+ /* prepare the data */
+ col[0] = '\0';
+ sub[0] = '\0';
+ tim[0] = '\0';
+ buf[0] = '\0';
- va_start(ap, format);
-
- fprintf(outfd, "%s", color(subsys));
+ /* are we using color */
+ if (target->use_color)
+ snprintf(col, sizeof(col), "%s", color(subsys));
+ vsnprintf(buf, sizeof(buf), format, ap);
if (!cont) {
- if (print_timestamp) {
+ if (target->print_timestamp) {
char *timestr;
time_t tm;
tm = time(NULL);
timestr = ctime(&tm);
timestr[strlen(timestr)-1] = '\0';
- fprintf(outfd, "%s ", timestr);
+ snprintf(tim, sizeof(tim), "%s ", timestr);
}
- fprintf(outfd, "<%4.4x> %s:%d ", subsys, file, line);
+ snprintf(sub, sizeof(sub), "<%4.4x> %s:%d ", subsys, file, line);
}
- vfprintf(outfd, format, ap);
- fprintf(outfd, "\033[0;m");
+ snprintf(final, sizeof(final), "%s%s%s%s\033[0;m", col, tim, sub, buf);
+ target->output(target, final);
+}
+
+
+static void _debugp(unsigned int subsys, int level, char *file, int line,
+ int cont, const char *format, va_list ap)
+{
+ struct debug_target *tar;
+
+ llist_for_each_entry(tar, &target_list, entry) {
+ struct debug_category *category;
+ int output = 0;
+
+ category = &tar->categories[subsys];
+ /* subsystem is not supposed to be debugged */
+ if (!category->enabled)
+ continue;
+
+ /* Check the global log level */
+ if (tar->loglevel != 0 && level < tar->loglevel)
+ continue;
+
+ /* Check the category log level */
+ if (category->loglevel != 0 && level < category->loglevel)
+ continue;
+
+ /*
+ * Apply filters here... if that becomes messy we will need to put
+ * filters in a list and each filter will say stop, continue, output
+ */
+ if ((tar->filter_map & DEBUG_FILTER_ALL) != 0) {
+ output = 1;
+ } else if ((tar->filter_map & DEBUG_FILTER_IMSI) != 0
+ && debug_context.subscr && strcmp(debug_context.subscr->imsi, tar->imsi_filter) == 0) {
+ output = 1;
+ }
+
+ if (output)
+ _output(tar, subsys, file, line, cont, format, ap);
+ }
+}
+
+void debugp(unsigned int subsys, char *file, int line, int cont, const char *format, ...)
+{
+ va_list ap;
+
+ va_start(ap, format);
+ _debugp(subsys, LOGL_DEBUG, file, line, cont, format, ap);
va_end(ap);
+}
- fflush(outfd);
+void debugp2(unsigned int subsys, unsigned int level, char *file, int line, int cont, const char *format, ...)
+{
+ va_list ap;
+
+ va_start(ap, format);
+ _debugp(subsys, level, file, line, cont, format, ap);
+ va_end(ap);
}
static char hexd_buff[4096];
@@ -164,3 +259,122 @@
return hexd_buff;
}
+
+
+void debug_add_target(struct debug_target *target)
+{
+ llist_add_tail(&target->entry, &target_list);
+}
+
+void debug_del_target(struct debug_target *target)
+{
+ llist_del(&target->entry);
+}
+
+void debug_reset_context(void)
+{
+ memset(&debug_context, 0, sizeof(debug_context));
+}
+
+/* currently we are not reffing these */
+void debug_set_context(int ctx, void *value)
+{
+ switch (ctx) {
+ case BSC_CTX_LCHAN:
+ debug_context.lchan = (struct gsm_lchan *) value;
+ break;
+ case BSC_CTX_SUBSCR:
+ debug_context.subscr = (struct gsm_subscriber *) value;
+ break;
+ case BSC_CTX_BTS:
+ debug_context.bts = (struct gsm_bts *) value;
+ break;
+ case BSC_CTX_SCCP:
+ break;
+ default:
+ break;
+ }
+}
+
+void debug_set_imsi_filter(struct debug_target *target, const char *imsi)
+{
+ if (imsi) {
+ target->filter_map |= DEBUG_FILTER_IMSI;
+ target->imsi_filter = talloc_strdup(target, imsi);
+ } else if (target->imsi_filter) {
+ target->filter_map &= ~DEBUG_FILTER_IMSI;
+ talloc_free(target->imsi_filter);
+ target->imsi_filter = NULL;
+ }
+}
+
+void debug_set_all_filter(struct debug_target *target, int all)
+{
+ if (all)
+ target->filter_map |= DEBUG_FILTER_ALL;
+ else
+ target->filter_map &= ~DEBUG_FILTER_ALL;
+}
+
+void debug_set_use_color(struct debug_target *target, int use_color)
+{
+ target->use_color = use_color;
+}
+
+void debug_set_print_timestamp(struct debug_target *target, int print_timestamp)
+{
+ target->print_timestamp = print_timestamp;
+}
+
+void debug_set_log_level(struct debug_target *target, int log_level)
+{
+ target->loglevel = log_level;
+}
+
+void debug_set_category_filter(struct debug_target *target, int category, int enable, int level)
+{
+ if (category >= Debug_LastEntry)
+ return;
+ target->categories[category].enabled = !!enable;
+ target->categories[category].loglevel = level;
+}
+
+static void _stderr_output(struct debug_target *target, const char *log)
+{
+ fprintf(target->tgt_stdout.out, "%s", log);
+ fflush(target->tgt_stdout.out);
+}
+
+struct debug_target *debug_target_create(void)
+{
+ struct debug_target *target;
+
+ target = talloc_zero(tall_dbg_ctx, struct debug_target);
+ if (!target)
+ return NULL;
+
+ INIT_LLIST_HEAD(&target->entry);
+ memcpy(target->categories, default_categories, sizeof(default_categories));
+ target->use_color = 1;
+ target->print_timestamp = 0;
+ target->loglevel = 0;
+ return target;
+}
+
+struct debug_target *debug_target_create_stderr(void)
+{
+ struct debug_target *target;
+
+ target = debug_target_create();
+ if (!target)
+ return NULL;
+
+ target->tgt_stdout.out = stderr;
+ target->output = _stderr_output;
+ return target;
+}
+
+void debug_init(void)
+{
+ tall_dbg_ctx = talloc_named_const(NULL, 1, "debug");
+}
diff --git a/openbsc/src/e1_input.c b/openbsc/src/e1_input.c
index 083d8f8..0a0cc8d 100644
--- a/openbsc/src/e1_input.c
+++ b/openbsc/src/e1_input.c
@@ -435,6 +435,8 @@
"tei %d, sapi %d\n", tei, sapi);
return -EINVAL;
}
+
+ debug_set_context(BSC_CTX_BTS, link->trx->bts);
switch (link->type) {
case E1INP_SIGN_OML:
msg->trx = link->trx;
diff --git a/openbsc/src/ipaccess-config.c b/openbsc/src/ipaccess-config.c
index c50a465..005c93d 100644
--- a/openbsc/src/ipaccess-config.c
+++ b/openbsc/src/ipaccess-config.c
@@ -289,6 +289,12 @@
struct gsm_bts *bts;
struct sockaddr_in sin;
int rc, option_index = 0, stream_id = 0xff;
+ struct debug_target *stderr_target;
+
+ debug_init();
+ stderr_target = debug_target_create_stderr();
+ debug_add_target(stderr_target);
+ debug_set_all_filter(stderr_target, 1);
printf("ipaccess-config (C) 2009 by Harald Welte\n");
printf("This is FREE SOFTWARE with ABSOLUTELY NO WARRANTY\n\n");
diff --git a/openbsc/src/telnet_interface.c b/openbsc/src/telnet_interface.c
index bc91ca3..ebddaf5 100644
--- a/openbsc/src/telnet_interface.c
+++ b/openbsc/src/telnet_interface.c
@@ -120,6 +120,12 @@
close(fd->fd);
bsc_unregister_fd(fd);
+
+ if (conn->dbg) {
+ debug_del_target(conn->dbg);
+ talloc_free(conn->dbg);
+ }
+
llist_del(&conn->entry);
talloc_free(conn);
return 0;
diff --git a/openbsc/src/vty_interface.c b/openbsc/src/vty_interface.c
index 62eee7a..9645af2 100644
--- a/openbsc/src/vty_interface.c
+++ b/openbsc/src/vty_interface.c
@@ -37,6 +37,7 @@
#include <openbsc/meas_rep.h>
#include <openbsc/db.h>
#include <openbsc/talloc.h>
+#include <openbsc/telnet_interface.h>
static struct gsm_network *gsmnet;
@@ -845,6 +846,170 @@
return CMD_SUCCESS;
}
+static void _vty_output(struct debug_target *tgt, const char *line)
+{
+ struct vty *vty = tgt->tgt_vty.vty;
+ vty_out(vty, "%s", line);
+ /* This is an ugly hack, but there is no easy way... */
+ if (strchr(line, '\n'))
+ vty_out(vty, "\r");
+}
+
+struct debug_target *debug_target_create_vty(struct vty *vty)
+{
+ struct debug_target *target;
+
+ target = debug_target_create();
+ if (!target)
+ return NULL;
+
+ target->tgt_vty.vty = vty;
+ target->output = _vty_output;
+ return target;
+}
+
+DEFUN(enable_logging,
+ enable_logging_cmd,
+ "logging enable",
+ "Enables logging to this vty\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (conn->dbg) {
+ vty_out(vty, "Logging already enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ conn->dbg = debug_target_create_vty(vty);
+ if (!conn->dbg)
+ return CMD_WARNING;
+
+ debug_add_target(conn->dbg);
+ return CMD_SUCCESS;
+}
+
+DEFUN(logging_fltr_imsi,
+ logging_fltr_imsi_cmd,
+ "logging filter imsi IMSI",
+ "Print all messages related to a IMSI\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_set_imsi_filter(conn->dbg, argv[0]);
+ return CMD_SUCCESS;
+}
+
+DEFUN(logging_fltr_all,
+ logging_fltr_all_cmd,
+ "logging filter all <0-1>",
+ "Print all messages to the console\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_set_all_filter(conn->dbg, atoi(argv[0]));
+ return CMD_SUCCESS;
+}
+
+DEFUN(logging_use_clr,
+ logging_use_clr_cmd,
+ "logging use color <0-1>",
+ "Use color for printing messages\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_set_use_color(conn->dbg, atoi(argv[0]));
+ return CMD_SUCCESS;
+}
+
+DEFUN(logging_prnt_timestamp,
+ logging_prnt_timestamp_cmd,
+ "logging print timestamp <0-1>",
+ "Print the timestamp of each message\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_set_print_timestamp(conn->dbg, atoi(argv[0]));
+ return CMD_SUCCESS;
+}
+
+DEFUN(logging_set_category_mask,
+ logging_set_category_mask_cmd,
+ "logging set debug mask MASK",
+ "Decide which categories to output.\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_parse_category_mask(conn->dbg, argv[0]);
+ return CMD_SUCCESS;
+}
+
+DEFUN(logging_set_log_level,
+ logging_set_log_level_cmd,
+ "logging set log level <0-8>",
+ "Set the global log level. The value 0 implies no filtering.\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_set_log_level(conn->dbg, atoi(argv[0]));
+ return CMD_SUCCESS;
+}
+
+DEFUN(diable_logging,
+ disable_logging_cmd,
+ "logging disable",
+ "Disables logging to this vty\n")
+{
+ struct telnet_connection *conn;
+
+ conn = (struct telnet_connection *) vty->priv;
+ if (!conn->dbg) {
+ vty_out(vty, "Logging was not enabled.%s", VTY_NEWLINE);
+ return CMD_WARNING;
+ }
+
+ debug_del_target(conn->dbg);
+ talloc_free(conn->dbg);
+ conn->dbg = NULL;
+ return CMD_SUCCESS;
+}
+
DEFUN(show_stats,
show_stats_cmd,
"show statistics",
@@ -1581,6 +1746,14 @@
install_element(VIEW_NODE, &show_paging_cmd);
install_element(VIEW_NODE, &show_stats_cmd);
+ install_element(VIEW_NODE, &enable_logging_cmd);
+ install_element(VIEW_NODE, &disable_logging_cmd);
+ install_element(VIEW_NODE, &logging_fltr_imsi_cmd);
+ install_element(VIEW_NODE, &logging_fltr_all_cmd);
+ install_element(VIEW_NODE, &logging_use_clr_cmd);
+ install_element(VIEW_NODE, &logging_prnt_timestamp_cmd);
+ install_element(VIEW_NODE, &logging_set_category_mask_cmd);
+
install_element(CONFIG_NODE, &cfg_net_cmd);
install_node(&net_node, config_write_net);
install_default(GSMNET_NODE);