2008-12-27 11:07:15 +00:00
|
|
|
/* Debugging/Logging support code */
|
|
|
|
/* (C) 2008 by Harald Welte <laforge@gnumonks.org>
|
2008-12-27 12:03:07 +00:00
|
|
|
* (C) 2008 by Holger Hans Peter Freyther <zecke@selfish.org>
|
2008-12-27 11:07:15 +00:00
|
|
|
* All Rights Reserved
|
|
|
|
*
|
|
|
|
* This program is free software; you can redistribute it and/or modify
|
|
|
|
* it under the terms of the GNU General Public License as published by
|
|
|
|
* the Free Software Foundation; either version 2 of the License, or
|
|
|
|
* (at your option) any later version.
|
|
|
|
*
|
|
|
|
* This program is distributed in the hope that it will be useful,
|
|
|
|
* but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
|
|
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
|
|
|
* GNU General Public License for more details.
|
|
|
|
*
|
|
|
|
* You should have received a copy of the GNU General Public License along
|
|
|
|
* with this program; if not, write to the Free Software Foundation, Inc.,
|
|
|
|
* 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
|
|
|
|
*
|
|
|
|
*/
|
|
|
|
|
|
|
|
#include <stdarg.h>
|
2008-12-27 12:03:07 +00:00
|
|
|
#include <stdlib.h>
|
2008-12-27 11:07:15 +00:00
|
|
|
#include <stdio.h>
|
|
|
|
#include <string.h>
|
2008-12-27 12:03:07 +00:00
|
|
|
#include <strings.h>
|
2008-12-27 11:07:15 +00:00
|
|
|
#include <time.h>
|
|
|
|
|
|
|
|
#include <openbsc/debug.h>
|
2009-12-22 21:32:51 +00:00
|
|
|
#include <openbsc/talloc.h>
|
|
|
|
#include <openbsc/gsm_data.h>
|
|
|
|
#include <openbsc/gsm_subscriber.h>
|
2008-12-27 11:07:15 +00:00
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
/* default categories */
|
|
|
|
static struct debug_category default_categories[Debug_LastEntry] = {
|
2009-12-24 12:48:33 +00:00
|
|
|
[DRLL] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DCC] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DNM] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DRR] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DRSL] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMM] = { .enabled = 1, .loglevel = LOGL_INFO },
|
|
|
|
[DMNCC] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DSMS] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DPAG] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMEAS] = { .enabled = 0, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMI] = { .enabled = 0, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMIB] = { .enabled = 0, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMUX] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DINP] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DSCCP] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMSC] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DMGCP] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DHO] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DDB] = { .enabled = 1, .loglevel = LOGL_NOTICE },
|
|
|
|
[DREF] = { .enabled = 0, .loglevel = LOGL_NOTICE },
|
2009-12-22 21:32:51 +00:00
|
|
|
};
|
2008-12-27 11:07:15 +00:00
|
|
|
|
2008-12-27 12:03:07 +00:00
|
|
|
struct debug_info {
|
|
|
|
const char *name;
|
|
|
|
const char *color;
|
|
|
|
const char *description;
|
|
|
|
int number;
|
2009-12-22 21:32:51 +00:00
|
|
|
int position;
|
|
|
|
};
|
|
|
|
|
|
|
|
struct debug_context {
|
|
|
|
struct gsm_lchan *lchan;
|
|
|
|
struct gsm_subscriber *subscr;
|
|
|
|
struct gsm_bts *bts;
|
2008-12-27 12:03:07 +00:00
|
|
|
};
|
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
static struct debug_context debug_context;
|
|
|
|
static void *tall_dbg_ctx = NULL;
|
|
|
|
static LLIST_HEAD(target_list);
|
|
|
|
|
2008-12-27 12:03:07 +00:00
|
|
|
#define DEBUG_CATEGORY(NUMBER, NAME, COLOR, DESCRIPTION) \
|
|
|
|
{ .name = NAME, .color = COLOR, .description = DESCRIPTION, .number = NUMBER },
|
|
|
|
|
|
|
|
static const struct debug_info debug_info[] = {
|
2008-12-27 12:46:48 +00:00
|
|
|
DEBUG_CATEGORY(DRLL, "DRLL", "\033[1;31m", "")
|
|
|
|
DEBUG_CATEGORY(DCC, "DCC", "\033[1;32m", "")
|
2009-06-02 02:35:12 +00:00
|
|
|
DEBUG_CATEGORY(DMM, "DMM", "\033[1;33m", "")
|
2008-12-27 12:46:48 +00:00
|
|
|
DEBUG_CATEGORY(DRR, "DRR", "\033[1;34m", "")
|
2009-05-23 06:43:35 +00:00
|
|
|
DEBUG_CATEGORY(DRSL, "DRSL", "\033[1;35m", "")
|
2008-12-27 12:46:48 +00:00
|
|
|
DEBUG_CATEGORY(DNM, "DNM", "\033[1;36m", "")
|
2008-12-28 21:38:25 +00:00
|
|
|
DEBUG_CATEGORY(DSMS, "DSMS", "\033[1;37m", "")
|
2008-12-29 04:06:41 +00:00
|
|
|
DEBUG_CATEGORY(DPAG, "DPAG", "\033[1;38m", "")
|
2009-05-23 06:42:38 +00:00
|
|
|
DEBUG_CATEGORY(DMNCC, "DMNCC","\033[1;39m", "")
|
2009-05-01 14:59:07 +00:00
|
|
|
DEBUG_CATEGORY(DINP, "DINP", "", "")
|
2009-02-06 12:02:53 +00:00
|
|
|
DEBUG_CATEGORY(DMI, "DMI", "", "")
|
|
|
|
DEBUG_CATEGORY(DMIB, "DMIB", "", "")
|
2009-02-23 00:04:04 +00:00
|
|
|
DEBUG_CATEGORY(DMUX, "DMUX", "", "")
|
2009-06-27 00:53:10 +00:00
|
|
|
DEBUG_CATEGORY(DMEAS, "DMEAS", "", "")
|
2009-08-01 14:54:45 +00:00
|
|
|
DEBUG_CATEGORY(DSCCP, "DSCCP", "", "")
|
2009-08-18 10:54:50 +00:00
|
|
|
DEBUG_CATEGORY(DMSC, "DMSC", "", "")
|
2009-11-20 12:05:48 +00:00
|
|
|
DEBUG_CATEGORY(DMGCP, "DMGCP", "", "")
|
2009-12-16 23:31:10 +00:00
|
|
|
DEBUG_CATEGORY(DHO, "DHO", "", "")
|
2009-12-24 10:39:14 +00:00
|
|
|
DEBUG_CATEGORY(DDB, "DDB", "", "")
|
2009-12-24 10:46:44 +00:00
|
|
|
DEBUG_CATEGORY(DDB, "DREF", "", "")
|
2008-12-27 12:03:07 +00:00
|
|
|
};
|
|
|
|
|
|
|
|
/*
|
|
|
|
* Parse the category mask.
|
2009-12-22 21:32:51 +00:00
|
|
|
* The format can be this: category1:category2:category3
|
|
|
|
* or category1,2:category2,3:...
|
2008-12-27 12:03:07 +00:00
|
|
|
*/
|
2009-12-22 21:32:51 +00:00
|
|
|
void debug_parse_category_mask(struct debug_target* target, const char *_mask)
|
2008-12-27 12:03:07 +00:00
|
|
|
{
|
|
|
|
int i = 0;
|
|
|
|
char *mask = strdup(_mask);
|
|
|
|
char *category_token = NULL;
|
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
/* Disable everything to enable it afterwards */
|
|
|
|
for (i = 0; i < ARRAY_SIZE(target->categories); ++i)
|
|
|
|
target->categories[i].enabled = 0;
|
|
|
|
|
2008-12-27 12:03:07 +00:00
|
|
|
category_token = strtok(mask, ":");
|
|
|
|
do {
|
|
|
|
for (i = 0; i < ARRAY_SIZE(debug_info); ++i) {
|
2009-12-22 21:32:51 +00:00
|
|
|
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;
|
|
|
|
}
|
2008-12-27 12:03:07 +00:00
|
|
|
}
|
2009-01-04 21:05:01 +00:00
|
|
|
} while ((category_token = strtok(NULL, ":")));
|
2008-12-27 12:03:07 +00:00
|
|
|
|
|
|
|
free(mask);
|
|
|
|
}
|
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
static const char* color(int subsys)
|
2008-12-27 12:46:48 +00:00
|
|
|
{
|
|
|
|
int i = 0;
|
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
for (i = 0; i < ARRAY_SIZE(debug_info); ++i) {
|
2008-12-27 12:46:48 +00:00
|
|
|
if (debug_info[i].number == subsys)
|
|
|
|
return debug_info[i].color;
|
|
|
|
}
|
|
|
|
|
|
|
|
return "";
|
|
|
|
}
|
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
static void _output(struct debug_target *target, unsigned int subsys, char *file, int line,
|
|
|
|
int cont, const char *format, va_list ap)
|
2008-12-27 11:07:15 +00:00
|
|
|
{
|
2009-12-22 21:32:51 +00:00
|
|
|
char col[30];
|
|
|
|
char sub[30];
|
|
|
|
char tim[30];
|
|
|
|
char buf[4096];
|
|
|
|
char final[4096];
|
2008-12-27 11:07:15 +00:00
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
/* prepare the data */
|
|
|
|
col[0] = '\0';
|
|
|
|
sub[0] = '\0';
|
|
|
|
tim[0] = '\0';
|
|
|
|
buf[0] = '\0';
|
2008-12-27 11:07:15 +00:00
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
/* are we using color */
|
2009-12-24 10:11:54 +00:00
|
|
|
if (target->use_color) {
|
2009-12-22 21:32:51 +00:00
|
|
|
snprintf(col, sizeof(col), "%s", color(subsys));
|
2009-12-24 10:11:54 +00:00
|
|
|
col[sizeof(col)-1] = '\0';
|
|
|
|
}
|
2009-12-22 21:32:51 +00:00
|
|
|
vsnprintf(buf, sizeof(buf), format, ap);
|
2009-12-24 10:11:54 +00:00
|
|
|
buf[sizeof(buf)-1] = '\0';
|
2009-02-06 12:38:29 +00:00
|
|
|
|
|
|
|
if (!cont) {
|
2009-12-22 21:32:51 +00:00
|
|
|
if (target->print_timestamp) {
|
2009-06-09 20:21:57 +00:00
|
|
|
char *timestr;
|
|
|
|
time_t tm;
|
|
|
|
tm = time(NULL);
|
|
|
|
timestr = ctime(&tm);
|
|
|
|
timestr[strlen(timestr)-1] = '\0';
|
2009-12-22 21:32:51 +00:00
|
|
|
snprintf(tim, sizeof(tim), "%s ", timestr);
|
2009-12-24 10:11:54 +00:00
|
|
|
tim[sizeof(tim)-1] = '\0';
|
2009-06-09 20:21:57 +00:00
|
|
|
}
|
2009-12-22 21:32:51 +00:00
|
|
|
snprintf(sub, sizeof(sub), "<%4.4x> %s:%d ", subsys, file, line);
|
2009-12-24 10:11:54 +00:00
|
|
|
sub[sizeof(sub)-1] = '\0';
|
2009-02-06 12:38:29 +00:00
|
|
|
}
|
2008-12-27 11:07:15 +00:00
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
snprintf(final, sizeof(final), "%s%s%s%s\033[0;m", col, tim, sub, buf);
|
2009-12-24 10:11:54 +00:00
|
|
|
final[sizeof(final)-1] = '\0';
|
2009-12-22 21:32:51 +00:00
|
|
|
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;
|
|
|
|
}
|
|
|
|
|
2009-12-24 10:12:11 +00:00
|
|
|
if (output) {
|
|
|
|
/* FIXME: copying the va_list is an ugly workaround against a bug
|
|
|
|
* hidden somewhere in _output. If we do not copy here, the first
|
|
|
|
* call to _output() will corrupt the va_list contents, and any
|
|
|
|
* further _output() calls with the same va_list will segfault */
|
|
|
|
va_list bp;
|
|
|
|
va_copy(bp, ap);
|
|
|
|
_output(tar, subsys, file, line, cont, format, bp);
|
2009-12-24 10:14:03 +00:00
|
|
|
va_end(bp);
|
2009-12-24 10:12:11 +00:00
|
|
|
}
|
2009-12-22 21:32:51 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
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);
|
2008-12-27 11:07:15 +00:00
|
|
|
va_end(ap);
|
2009-12-22 21:32:51 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
void debugp2(unsigned int subsys, unsigned int level, char *file, int line, int cont, const char *format, ...)
|
|
|
|
{
|
|
|
|
va_list ap;
|
2008-12-27 11:07:15 +00:00
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
va_start(ap, format);
|
|
|
|
_debugp(subsys, level, file, line, cont, format, ap);
|
|
|
|
va_end(ap);
|
2008-12-27 11:07:15 +00:00
|
|
|
}
|
|
|
|
|
2009-02-28 13:08:01 +00:00
|
|
|
static char hexd_buff[4096];
|
|
|
|
|
2009-08-20 11:16:26 +00:00
|
|
|
char *hexdump(const unsigned char *buf, int len)
|
2009-01-04 21:05:01 +00:00
|
|
|
{
|
|
|
|
int i;
|
2009-02-28 13:08:01 +00:00
|
|
|
char *cur = hexd_buff;
|
|
|
|
|
|
|
|
hexd_buff[0] = 0;
|
2009-01-04 21:05:01 +00:00
|
|
|
for (i = 0; i < len; i++) {
|
2009-02-28 13:08:01 +00:00
|
|
|
int len_remain = sizeof(hexd_buff) - (cur - hexd_buff);
|
|
|
|
int rc = snprintf(cur, len_remain, "%02x ", buf[i]);
|
|
|
|
if (rc <= 0)
|
|
|
|
break;
|
|
|
|
cur += rc;
|
2009-01-04 21:05:01 +00:00
|
|
|
}
|
2009-02-28 13:08:01 +00:00
|
|
|
hexd_buff[sizeof(hexd_buff)-1] = 0;
|
|
|
|
return hexd_buff;
|
2009-01-04 21:05:01 +00:00
|
|
|
}
|
|
|
|
|
2009-12-22 21:32:51 +00:00
|
|
|
|
|
|
|
|
|
|
|
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");
|
|
|
|
}
|