Logging: Add debug logging categories

Added debug logging categories that allow a user to output debug
information based on a specified category. This lets the user limit,
and filter debug output to data relevant to a particular context,
or topic. For instance the following categories are now available for
debug logging purposes:

  dtls, dtls_packet, ice, rtcp, rtcp_packet, rtp, rtp_packet,
  stun, stun_packet

These debug categories can be enable/disable via an Asterisk CLI command.

While this overrides, and outputs debug data, core system debugging is
not affected by this patch. Statements still output at their appropriate
debug level. As well backwards compatibility has been maintained with
past debug groups that could be enabled using the CLI (e.g. rtpdebug,
stundebug, etc.).

ASTERISK-29054 #close

Change-Id: I6e6cb247bb1f01dbf34750b2cd98e5b5b41a1849
(cherry picked from commit 56028426de)
This commit is contained in:
Kevin Harwell 2020-08-28 16:32:37 -05:00
parent a6faa53af0
commit 6255e7976c
11 changed files with 1035 additions and 200 deletions

View File

@ -0,0 +1,18 @@
Subject: Core
Added debug logging categories that allow a user to output debug information
based on a specified category. This lets the user limit, and filter debug
output to data relevant to a particular context, or topic. For instance the
following categories are now available for debug logging purposes:
dtls, dtls_packet, ice, rtcp, rtcp_packet, rtp, rtp_packet, stun, stun_packet
These debug categories can be enable/disable via an Asterisk CLI command:
core set debug category <category>[:<sublevel>] [category[:<sublevel] ...]
core set debug category off [<category> [<category>] ...]
If no sub-level is associated all debug statements for a given category are
output. If a sub-level is given then only those statements assigned a value
at or below the associated sub-level are output.

View File

@ -0,0 +1,178 @@
/*
* Asterisk -- An open source telephony toolkit.
*
* Copyright (C) 2020, Sangoma Technologies Corporation
*
* Kevin Harwell <kharwell@sangoma.com>
*
* See http://www.asterisk.org for more information about
* the Asterisk project. Please do not directly contact
* any of the maintainers of this project for assistance;
* the project provides a web site, mailing lists and IRC
* channels for your use.
*
* This program is free software, distributed under the terms of
* the GNU General Public License Version 2. See the LICENSE file
* at the top of the source tree.
*/
#ifndef ASTERISK_LOGGER_CATEGORY_H
#define ASTERISK_LOGGER_CATEGORY_H
#include "asterisk/logger.h"
/*!
* Logger category is enabled
*/
#define AST_LOG_CATEGORY_ENABLED -1
/*!
* Logger category is disabled
*/
#define AST_LOG_CATEGORY_DISABLED 0
/*!
* \brief Load/Initialize system wide logger category functionality
*
* \retval 0 Success, -1 Failure
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
int ast_logger_category_load(void);
/*!
* \brief Unload system wide logger category functionality
*
* \retval 0 Success, -1 Failure
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
int ast_logger_category_unload(void);
/*!
* \brief Register a debug level logger category
*
* \param name The name of the category
* \param id The unique id of the category
*
* \retval 0 if failed to register/retrieve an id. Otherwise it returns the id
* for the registered category.
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
uintmax_t ast_debug_category_register(const char *name);
/*!
* \brief Un-register a debug level logger category
*
* \retval 0 Success, -1 Failure
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
int ast_debug_category_unregister(const char *name);
/*!
* \brief Set the debug category's sublevel
*
* Statements are output at a specified sublevel. Typically any number greater
* than or equal to 0. Other acceptable values include AST_LOG_CATEGORY_ENABLED
* and AST_LOG_CATEGORY_DISABLED.
*
* \param name The name of the category
* \param sublevel The debug sublevel output number
*
* \retval 0 Success, -1 Failure
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
int ast_debug_category_set_sublevel(const char *name, int sublevel);
/*!
* \brief Set one or more debug category's sublevel.
*
* Accepts an array of category names, and optional associated sublevels. Sublevels can
* be associated with a name by using a ':' as a separator. For example:
*
* <category name>:<category sublevel>
*
* The given default sublevel is used if no sublevel is associated with a name.
*
* \param names An array of category names
* \param size The size of the array (number of elements)
* \param default_sublevel The sublevel value to use if one is not associated with a name
*
* \retval 0 Success, -1 Failure
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
int ast_debug_category_set_sublevels(const char * const *names, size_t size, int default_sublevel);
/*!
* \brief Add a unique (no duplicates) result to a request for completion for debug categories.
*
* \param argv A list of already completed options
* \param argc The number of already completed options
* \param word The word to complete
* \param state The state
*
* \retval 0 Success, -1 Failure
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
char *ast_debug_category_complete(const char * const *argv, int argc, const char *word, int state);
/*!
* \brief Check if a debug category is enabled, and allowed to output
*
* \note If more than one id is specified then if even one is allowed "true"
* is returned.
*
* \param sublevel Current set sublevel must be this sublevel or less
* \param ids One or more unique category ids to check
*
* \retval 1 if allowed, 0 if not allowed
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
int ast_debug_category_is_allowed(int sublevel, uintmax_t ids);
/*!
* \brief Log for a debug category.
*
* This will output log data for debug under the following conditions:
*
* 1. The specified sublevel is at, or below the current system debug level
* 2. At least one of the given category ids is enabled AND
* a. The category sublevel is enabled OR the given sublevel is at, or
* below a category's specified sublevel.
*
* \param sublevel The minimum level to output at
* \param ids One or more unique category ids to output for
*
* \since 16.14
* \since 17.8
* \since 18.0
*/
#define ast_debug_category(sublevel, ids, ...) \
do { \
if (DEBUG_ATLEAST(sublevel) || ast_debug_category_is_allowed(sublevel, ids)) { \
ast_log(AST_LOG_DEBUG, __VA_ARGS__); \
} \
} while (0)
#endif /* ASTERISK_LOGGER_CATEGORY_H */

View File

@ -77,6 +77,7 @@ extern "C" {
#include "asterisk/res_srtp.h"
#include "asterisk/stasis.h"
#include "asterisk/vector.h"
#include "asterisk/logger_category.h"
/*! Maximum number of payload types RTP can support. */
#define AST_RTP_MAX_PT 128
@ -2819,6 +2820,84 @@ int ast_rtp_get_rate(const struct ast_format *format);
*/
struct stasis_topic *ast_rtp_topic(void);
/* RTP debug logging category name */
#define AST_LOG_CATEGORY_RTP "rtp"
/* RTP packet debug logging category name */
#define AST_LOG_CATEGORY_RTP_PACKET "rtp_packet"
/* RTCP debug logging category name */
#define AST_LOG_CATEGORY_RTCP "rtcp"
/* RTCP packet debug logging category name */
#define AST_LOG_CATEGORY_RTCP_PACKET "rtcp_packet"
/* DTLS debug logging category name */
#define AST_LOG_CATEGORY_DTLS "dtls"
/* DTLS packet debug logging category name */
#define AST_LOG_CATEGORY_DTLS_PACKET "dtls_packet"
/* ICE debug logging category name */
#define AST_LOG_CATEGORY_ICE "ice"
uintmax_t ast_debug_category_rtp_id(void);
uintmax_t ast_debug_category_rtp_packet_id(void);
uintmax_t ast_debug_category_rtcp_id(void);
uintmax_t ast_debug_category_rtcp_packet_id(void);
uintmax_t ast_debug_category_dtls_id(void);
uintmax_t ast_debug_category_dtls_packet_id(void);
uintmax_t ast_debug_category_ice_id(void);
#define AST_DEBUG_CATEGORY_RTP ast_debug_category_rtp_id() /* RTP debug logging category id */
#define AST_DEBUG_CATEGORY_RTP_PACKET ast_debug_category_rtp_packet_id() /* RTP packet debug logging category id */
#define AST_DEBUG_CATEGORY_RTCP ast_debug_category_rtcp_id() /* RTCP debug logging category id */
#define AST_DEBUG_CATEGORY_RTCP_PACKET ast_debug_category_rtcp_packet_id() /* RTCP packet debug logging category id */
#define AST_DEBUG_CATEGORY_DTLS ast_debug_category_dtls_id() /* DTLS debug logging category id */
#define AST_DEBUG_CATEGORY_DTLS_PACKET ast_debug_category_dtls_packet_id() /* DTLS packet debug logging category id */
#define AST_DEBUG_CATEGORY_ICE ast_debug_category_ice_id() /* ICE debug logging category id */
/*!
* \brief Log debug level RTP information
*
* \param sublevel Debug output sublevel (>= 0)
* \param ... String format and any associated arguments
*/
#define ast_debug_rtp(sublevel, ...) \
ast_debug_category(sublevel, AST_DEBUG_CATEGORY_RTP, __VA_ARGS__)
/* Allow logging of RTP packets? */
#define ast_debug_rtp_packet_is_allowed \
ast_debug_category_is_allowed(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_RTP_PACKET)
/*!
* \brief Log debug level RTCP information
*
* \param sublevel Debug output sublevel (>= 0)
* \param ... String format and any associated arguments
*/
#define ast_debug_rtcp(sublevel, ...) \
ast_debug_category(sublevel, AST_DEBUG_CATEGORY_RTCP, __VA_ARGS__)
/* Allow logging of RTCP packets? */
#define ast_debug_rtcp_packet_is_allowed \
ast_debug_category_is_allowed(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_RTCP_PACKET)
/*!
* \brief Log debug level DTLS information
*
* \param sublevel Debug output sublevel (>= 0)
* \param ... String format and any associated arguments
*/
#define ast_debug_dtls(sublevel, ...) \
ast_debug_category(sublevel, AST_DEBUG_CATEGORY_DTLS, __VA_ARGS__)
/* Allow logging of DTLS packets? */
#define ast_debug_dtls_packet_is_allowed \
ast_debug_category_is_allowed(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_DTLS_PACKET)
/*!
* \brief Log debug level ICE information
*
* \param sublevel Debug output sublevel (>= 0)
* \param ... String format and any associated arguments
*/
#define ast_debug_ice(sublevel, ...) \
ast_debug_category(sublevel, AST_DEBUG_CATEGORY_ICE, __VA_ARGS__)
/* @} */
#if defined(__cplusplus) || defined(c_plusplus)

View File

@ -27,11 +27,36 @@
#define _ASTERISK_STUN_H
#include "asterisk/network.h"
#include "asterisk/logger_category.h"
#if defined(__cplusplus) || defined(c_plusplus)
extern "C" {
#endif
/* STUN debug logging category name */
#define AST_LOG_CATEGORY_STUN "stun"
/* STUN packet debug logging category name */
#define AST_LOG_CATEGORY_STUN_PACKET "stun_packet"
uintmax_t ast_debug_category_stun_id(void);
uintmax_t ast_debug_category_stun_packet_id(void);
#define AST_DEBUG_CATEGORY_STUN ast_debug_category_stun_id() /* STUN debug logging category id */
#define AST_DEBUG_CATEGORY_STUN_PACKET ast_debug_category_stun_packet_id() /* STUN packet debug logging category id */
/*!
* \brief Log debug level STUN information
*
* \param sublevel Debug output sublevel (>= 0)
* \param ... String format and any associated arguments
*/
#define ast_debug_stun(sublevel, ...) \
ast_debug_category(sublevel, AST_DEBUG_CATEGORY_STUN, __VA_ARGS__)
/* Is logging of stun packets allowed? */
#define ast_debug_stun_packet_is_allowed \
ast_debug_category_is_allowed(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_STUN_PACKET)
static const int STANDARD_STUN_PORT = 3478;
enum ast_stun_result {

View File

@ -55,6 +55,7 @@
#include "asterisk/app.h"
#include "asterisk/lock.h"
#include "asterisk/threadstorage.h"
#include "asterisk/logger_category.h"
#include "asterisk/translate.h"
#include "asterisk/bridge.h"
#include "asterisk/stasis_channels.h"
@ -478,9 +479,11 @@ static char *handle_debug_or_trace(int handler, struct ast_cli_entry *e, int cmd
if (!strcasecmp(a->argv[e->args], "atleast")) {
atleast = 1;
}
if (a->argc != e->args + atleast + 1 && a->argc != e->args + atleast + 2) {
return CLI_SHOWUSAGE;
}
if (sscanf(a->argv[e->args + atleast], "%30d", &newlevel) != 1) {
return CLI_SHOWUSAGE;
}
@ -585,6 +588,10 @@ static char *handle_debug(struct ast_cli_entry *e, int cmd, struct ast_cli_args
return NULL;
case CLI_GENERATE:
if (!strcasecmp(argv3, "category")) {
return NULL;
}
if (!strcasecmp(argv3, "atleast")) {
atleast = 1;
}
@ -618,7 +625,6 @@ static char *handle_debug(struct ast_cli_entry *e, int cmd, struct ast_cli_args
*/
return handle_debug_or_trace(DEBUG_HANDLER, e, cmd, a);
}
static char *handle_trace(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
@ -1533,6 +1539,47 @@ static char *handle_core_set_debug_channel(struct ast_cli_entry *e, int cmd, str
return CLI_SUCCESS;
}
static char *handle_debug_category(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
{
const char *argv4 = a->argv ? S_OR(a->argv[4], "") : "";
int offset = strncasecmp(argv4, "off", strlen(argv4)) ? 0 : 1;
switch (cmd) {
case CLI_INIT:
e->command = "core set debug category";
e->usage =
"Usage: core set debug category <category>[:<sublevel>] [category[:<sublevel] ...]\n"
" core set debug category off [<category> [<category>] ...]\n\n"
" Allows enabling and disabling debug logging categories.\n"
" When a category is enabled all relevant debug messages are logged\n"
" for a given category. However, if a sublevel is specified only\n"
" those categorized messages at or below the coded debug sublevel\n"
" are logged.\n";
return NULL;
case CLI_GENERATE:
if (a->pos < e->args) {
return NULL;
}
if (a->pos == 4 && offset) {
ast_cli_completion_add(ast_strdup("off"));
}
return ast_debug_category_complete(a->argv + 4,
a->pos - e->args, a->word, a->n - 1);
}
if (a->argc <= e->args) {
return CLI_SHOWUSAGE;
}
ast_debug_category_set_sublevels(a->argv + e->args + offset, a->argc - e->args - offset,
offset ? AST_LOG_CATEGORY_DISABLED : AST_LOG_CATEGORY_ENABLED);
return CLI_SUCCESS;
}
static char *handle_nodebugchan_deprecated(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
{
char *res;
@ -1947,6 +1994,8 @@ static struct ast_cli_entry cli_cli[] = {
AST_CLI_DEFINE(handle_core_set_debug_channel, "Enable/disable debugging on a channel"),
AST_CLI_DEFINE(handle_debug_category, "Enable/disable debugging categories"),
AST_CLI_DEFINE(handle_debug, "Set level of debug chattiness"),
AST_CLI_DEFINE(handle_trace, "Set level of trace chattiness"),
AST_CLI_DEFINE(handle_verbose, "Set level of verbose chattiness"),

View File

@ -52,6 +52,7 @@
#include "asterisk/module.h"
#include "asterisk/paths.h" /* use ast_config_AST_LOG_DIR */
#include "asterisk/logger.h"
#include "asterisk/logger_category.h"
#include "asterisk/lock.h"
#include "asterisk/channel.h"
#include "asterisk/config.h"
@ -1868,6 +1869,8 @@ int init_logger(void)
ast_log(LOG_ERROR, "Errors detected in logger.conf. Default console logging is being used.\n");
}
ast_logger_category_load();
return 0;
}
@ -1875,6 +1878,8 @@ void close_logger(void)
{
struct logchannel *f = NULL;
ast_logger_category_unload();
ast_cli_unregister_multiple(cli_logger, ARRAY_LEN(cli_logger));
logger_initialized = 0;

324
main/logger_category.c Normal file
View File

@ -0,0 +1,324 @@
/*
* Asterisk -- An open source telephony toolkit.
*
* Copyright (C) 2020, Sangoma Technologies Corporation
*
* Kevin Harwell <kharwell@sangoma.com>
*
* See http://www.asterisk.org for more information about
* the Asterisk project. Please do not directly contact
* any of the maintainers of this project for assistance;
* the project provides a web site, mailing lists and IRC
* channels for your use.
*
* This program is free software, distributed under the terms of
* the GNU General Public License Version 2. See the LICENSE file
* at the top of the source tree.
*/
#include "asterisk.h"
#include "asterisk/cli.h"
#include "asterisk/conversions.h"
#include "asterisk/logger_category.h"
#include "asterisk/vector.h"
struct category_t {
int sublevel;
uintmax_t id;
char name[0];
};
AST_VECTOR_RW(categories_t, struct category_t *);
struct categories_level_t {
int type;
int sublevel;
uintmax_t id_pool;
uintmax_t state;
struct categories_t categories;
};
/*! \brief Retrieve the next available id.
*
* Ids must be a power of 2. This allows for fast lookup, and "or'ing" of ids
* in order to permit multiple categories in a log statement.
*/
static uintmax_t get_next_id(struct categories_level_t *level)
{
if (level->id_pool == 0) {
level->id_pool = 1;
} else if (level->id_pool >= (UINTMAX_MAX / 2)) {
/* No more ids left*/
return 0;
} else {
level->id_pool <<= 1;
}
return level->id_pool;
}
static int cmp_by_name(const struct category_t *category, const char *name)
{
return !strcmp(category->name, name);
}
static uintmax_t category_register(struct categories_level_t *level, const char *name)
{
int i;
struct category_t *category;
AST_VECTOR_RW_WRLOCK(&level->categories);
i = AST_VECTOR_GET_INDEX(&level->categories, name, cmp_by_name);
if (i >= 0) {
AST_VECTOR_RW_UNLOCK(&level->categories);
ast_log(LOG_ERROR, "Cannot register logger category '%s'. "
"Name already used for type.\n", name);
return 0;
}
category = ast_calloc(1, sizeof(*category) + strlen(name) + 1);
if (!category) {
AST_VECTOR_RW_UNLOCK(&level->categories);
return 0;
}
category->id = get_next_id(level);
category->sublevel = AST_LOG_CATEGORY_DISABLED;
strcpy(category->name, name); /* Safe */
if (AST_VECTOR_APPEND(&level->categories, category)) {
AST_VECTOR_RW_UNLOCK(&level->categories);
ast_log(LOG_ERROR, "Cannot register logger category '%s'. "
"Unable to append.\n", name);
return 0;
}
AST_VECTOR_RW_UNLOCK(&level->categories);
return category->id;
}
static int category_unregister(struct categories_level_t *level, const char *name)
{
int res;
AST_VECTOR_RW_WRLOCK(&level->categories);
res = AST_VECTOR_REMOVE_CMP_UNORDERED(&level->categories, name, cmp_by_name, ast_free);
AST_VECTOR_RW_UNLOCK(&level->categories);
return res;
}
static int casecmp_by_name(const struct category_t *category, const char *name)
{
return !strcasecmp(category->name, name);
}
static int category_set_sublevel(struct category_t *category, struct categories_level_t *level,
const char *name, int sublevel)
{
int locked = 0;
if (!category) {
struct category_t **obj;
if (!name) {
return -1;
}
locked = !AST_VECTOR_RW_WRLOCK(&level->categories);
if (!locked) {
return -1;
}
obj = AST_VECTOR_GET_CMP(&level->categories, name, casecmp_by_name);
if (!obj) {
AST_VECTOR_RW_UNLOCK(&level->categories);
return -1;
}
category = *obj;
}
category->sublevel = sublevel;
if (category->sublevel == AST_LOG_CATEGORY_DISABLED) {
level->state &= ~category->id;
} else {
level->state |= category->id;
}
if (locked) {
AST_VECTOR_RW_UNLOCK(&level->categories);
}
return 0;
}
static int category_set_sublevels(struct categories_level_t *level,
const char * const *names, size_t size, int default_sublevel)
{
int i;
if (!names || !size) {
level->state = default_sublevel;
AST_VECTOR_RW_WRLOCK(&level->categories);
AST_VECTOR_CALLBACK_VOID(&level->categories, category_set_sublevel,
level, NULL, default_sublevel);
AST_VECTOR_RW_UNLOCK(&level->categories);
return 0;
}
for (i = 0; i < size; ++i) {
const char *sublevel;
int num = default_sublevel;
sublevel = strchr(names[i], ':');
if (sublevel) {
size_t len = ++sublevel - names[i];
char name[len];
if (*sublevel && ast_str_to_int(sublevel, &num)) {
continue;
}
ast_copy_string(name, names[i], len);
category_set_sublevel(NULL, level, name, num);
} else {
category_set_sublevel(NULL, level, names[i], num);
}
}
return 0;
}
static char *category_complete(struct categories_level_t *level, const char * const *argv,
int argc, const char *word, int state)
{
int wordlen = strlen(word);
int which = 0;
int i, j;
AST_VECTOR_RW_RDLOCK(&level->categories);
if (argc == AST_VECTOR_SIZE(&level->categories)) {
AST_VECTOR_RW_UNLOCK(&level->categories);
return NULL;
}
for (i = 0; i < AST_VECTOR_SIZE(&level->categories); ++i) {
struct category_t *category = AST_VECTOR_GET(&level->categories, i);
if (!strncasecmp(word, category->name, wordlen) && (++which > state)) {
/* Check to see if one is already been included */
for (j = 0; j < argc; ++j) {
if (!strncasecmp(category->name, argv[j], strlen(category->name))) {
break;
}
}
if (j != argc) {
continue;
}
if (state != -1) {
AST_VECTOR_RW_UNLOCK(&level->categories);
return ast_strdup(category->name);
}
if (ast_cli_completion_add(ast_strdup(category->name))) {
AST_VECTOR_RW_UNLOCK(&level->categories);
return NULL;
}
}
}
AST_VECTOR_RW_UNLOCK(&level->categories);
return NULL;
}
static int category_is_allowed(int sublevel, struct categories_level_t *level, uintmax_t ids)
{
/* Check level, and potentially allow but only if there is a matching state enabled */
if (ids & level->state) {
int i;
if (sublevel == AST_LOG_CATEGORY_ENABLED || sublevel == 0) {
/* If at least one id is enabled then always allow these sublevels */
return 1;
}
AST_VECTOR_RW_RDLOCK(&level->categories);
for (i = 0; i < AST_VECTOR_SIZE(&level->categories); ++i) {
struct category_t *category = AST_VECTOR_GET(&level->categories, i);
/*
* If there is at least one matching category, and that category is enabled
* or its sub-level is at or above the given sub-level then allow.
*/
if ((category->id & ids) && category->sublevel != AST_LOG_CATEGORY_DISABLED &&
(category->sublevel == AST_LOG_CATEGORY_ENABLED || category->sublevel >= sublevel)) {
AST_VECTOR_RW_UNLOCK(&level->categories);
return 1;
}
}
AST_VECTOR_RW_UNLOCK(&level->categories);
}
return 0;
}
static struct categories_level_t debug_categories = {
.type = __LOG_DEBUG,
.sublevel = 0,
.id_pool = 0,
.state = 0,
};
uintmax_t ast_debug_category_register(const char *name)
{
return category_register(&debug_categories, name);
}
int ast_debug_category_unregister(const char *name)
{
return category_unregister(&debug_categories, name);
}
int ast_debug_category_set_sublevel(const char *name, int sublevel)
{
return category_set_sublevel(NULL, &debug_categories, name, sublevel);
}
int ast_debug_category_set_sublevels(const char * const *names,
size_t size, int default_sublevel)
{
return category_set_sublevels(&debug_categories, names, size, default_sublevel);
}
char *ast_debug_category_complete(const char * const *argv, int argc,
const char *word, int state)
{
return category_complete(&debug_categories, argv, argc, word, state);
}
int ast_debug_category_is_allowed(int sublevel, uintmax_t ids)
{
return category_is_allowed(sublevel, &debug_categories, ids);
}
int ast_logger_category_unload(void)
{
AST_VECTOR_RW_FREE(&debug_categories.categories);
return 0;
}
int ast_logger_category_load(void)
{
if (AST_VECTOR_RW_INIT(&debug_categories.categories, 10)) {
return -1;
}
return 0;
}

View File

@ -3533,6 +3533,55 @@ struct stasis_topic *ast_rtp_topic(void)
return rtp_topic;
}
static uintmax_t debug_category_rtp_id;
uintmax_t ast_debug_category_rtp_id(void)
{
return debug_category_rtp_id;
}
static uintmax_t debug_category_rtp_packet_id;
uintmax_t ast_debug_category_rtp_packet_id(void)
{
return debug_category_rtp_packet_id;
}
static uintmax_t debug_category_rtcp_id;
uintmax_t ast_debug_category_rtcp_id(void)
{
return debug_category_rtcp_id;
}
static uintmax_t debug_category_rtcp_packet_id;
uintmax_t ast_debug_category_rtcp_packet_id(void)
{
return debug_category_rtcp_packet_id;
}
static uintmax_t debug_category_dtls_id;
uintmax_t ast_debug_category_dtls_id(void)
{
return debug_category_dtls_id;
}
static uintmax_t debug_category_dtls_packet_id;
uintmax_t ast_debug_category_dtls_packet_id(void)
{
return debug_category_dtls_packet_id;
}
static uintmax_t debug_category_ice_id;
uintmax_t ast_debug_category_ice_id(void)
{
return debug_category_ice_id;
}
static void rtp_engine_shutdown(void)
{
int x;
@ -3557,6 +3606,17 @@ static void rtp_engine_shutdown(void)
}
mime_types_len = 0;
ast_rwlock_unlock(&mime_types_lock);
ast_debug_category_unregister(AST_LOG_CATEGORY_ICE);
ast_debug_category_unregister(AST_LOG_CATEGORY_DTLS_PACKET);
ast_debug_category_unregister(AST_LOG_CATEGORY_DTLS);
ast_debug_category_unregister(AST_LOG_CATEGORY_RTCP_PACKET);
ast_debug_category_unregister(AST_LOG_CATEGORY_RTCP);
ast_debug_category_unregister(AST_LOG_CATEGORY_RTP_PACKET);
ast_debug_category_unregister(AST_LOG_CATEGORY_RTP);
}
int ast_rtp_engine_init(void)
@ -3684,6 +3744,14 @@ int ast_rtp_engine_init(void)
add_static_payload(127, ast_format_slin96, 0);
/* payload types above 127 are not valid */
debug_category_rtp_id = ast_debug_category_register(AST_LOG_CATEGORY_RTP);
debug_category_rtp_packet_id = ast_debug_category_register(AST_LOG_CATEGORY_RTP_PACKET);
debug_category_rtcp_id = ast_debug_category_register(AST_LOG_CATEGORY_RTCP);
debug_category_rtcp_packet_id = ast_debug_category_register(AST_LOG_CATEGORY_RTCP_PACKET);
debug_category_dtls_id = ast_debug_category_register(AST_LOG_CATEGORY_DTLS);
debug_category_dtls_packet_id = ast_debug_category_register(AST_LOG_CATEGORY_DTLS_PACKET);
debug_category_ice_id = ast_debug_category_register(AST_LOG_CATEGORY_ICE);
return 0;
}

View File

@ -32,14 +32,14 @@
#include "asterisk.h"
#include "asterisk/logger.h"
#include "asterisk/logger_category.h"
#include "asterisk/_private.h"
#include "asterisk/stun.h"
#include "asterisk/cli.h"
#include "asterisk/utils.h"
#include "asterisk/channel.h"
static int stundebug; /*!< Are we debugging stun? */
/*!
* \brief STUN support code
*
@ -178,9 +178,10 @@ struct stun_state {
static int stun_process_attr(struct stun_state *state, struct stun_attr *attr)
{
if (stundebug)
if (ast_debug_stun_packet_is_allowed) {
ast_verbose("Found STUN Attribute %s (%04x), length %d\n",
stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));
stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));
}
switch (ntohs(attr->attr)) {
case STUN_USERNAME:
state->username = (const char *) (attr->value);
@ -189,10 +190,12 @@ static int stun_process_attr(struct stun_state *state, struct stun_attr *attr)
state->password = (const char *) (attr->value);
break;
default:
if (stundebug)
if (ast_debug_stun_packet_is_allowed) {
ast_verbose("Ignoring STUN attribute %s (%04x), length %d\n",
stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));
stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));
}
}
return 0;
}
@ -275,35 +278,35 @@ int ast_stun_handle_packet(int s, struct sockaddr_in *src, unsigned char *data,
* while 'data' is advanced accordingly.
*/
if (len < sizeof(struct stun_header)) {
ast_debug(1, "Runt STUN packet (only %d, wanting at least %d)\n", (int) len, (int) sizeof(struct stun_header));
ast_debug_stun(1, "Runt STUN packet (only %d, wanting at least %d)\n", (int) len, (int) sizeof(struct stun_header));
return -1;
}
len -= sizeof(struct stun_header);
data += sizeof(struct stun_header);
x = ntohs(hdr->msglen); /* len as advertised in the message */
if (stundebug)
if (ast_debug_stun_packet_is_allowed)
ast_verbose("STUN Packet, msg %s (%04x), length: %d\n", stun_msg2str(ntohs(hdr->msgtype)), (unsigned)ntohs(hdr->msgtype), x);
if (x > len) {
ast_debug(1, "Scrambled STUN packet length (got %d, expecting %d)\n", x, (int)len);
ast_debug_stun(1, "Scrambled STUN packet length (got %d, expecting %d)\n", x, (int)len);
} else
len = x;
memset(&st, 0, sizeof(st));
while (len) {
if (len < sizeof(struct stun_attr)) {
ast_debug(1, "Runt Attribute (got %d, expecting %d)\n", (int)len, (int) sizeof(struct stun_attr));
ast_debug_stun(1, "Runt Attribute (got %d, expecting %d)\n", (int)len, (int) sizeof(struct stun_attr));
break;
}
attr = (struct stun_attr *)data;
/* compute total attribute length */
x = ntohs(attr->len) + sizeof(struct stun_attr);
if (x > len) {
ast_debug(1, "Inconsistent Attribute (length %d exceeds remaining msg len %d)\n", x, (int)len);
ast_debug_stun(1, "Inconsistent Attribute (length %d exceeds remaining msg len %d)\n", x, (int)len);
break;
}
if (stun_cb)
stun_cb(attr, arg);
if (stun_process_attr(&st, attr)) {
ast_debug(1, "Failed to handle attribute %s (%04x)\n", stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr));
ast_debug_stun(1, "Failed to handle attribute %s (%04x)\n", stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr));
break;
}
/* Clear attribute id: in case previous entry was a string,
@ -337,7 +340,7 @@ int ast_stun_handle_packet(int s, struct sockaddr_in *src, unsigned char *data,
attr = (struct stun_attr *)resp->ies;
switch (ntohs(hdr->msgtype)) {
case STUN_BINDREQ:
if (stundebug)
if (ast_debug_stun_packet_is_allowed)
ast_verbose("STUN Bind Request, username: %s\n",
st.username ? st.username : "<none>");
if (st.username) {
@ -355,7 +358,7 @@ int ast_stun_handle_packet(int s, struct sockaddr_in *src, unsigned char *data,
ret = AST_STUN_ACCEPT;
break;
default:
if (stundebug)
if (ast_debug_stun_packet_is_allowed)
ast_verbose("Dunno what to do with STUN message %04x (%s)\n", (unsigned)ntohs(hdr->msgtype), stun_msg2str(ntohs(hdr->msgtype)));
}
}
@ -416,7 +419,7 @@ int ast_stun_request(int s, struct sockaddr_in *dst,
/* Send STUN message. */
res = stun_send(s, dst, req);
if (res < 0) {
ast_debug(1, "stun_send try %d failed: %s\n", retry, strerror(errno));
ast_debug_stun(1, "stun_send try %d failed: %s\n", retry, strerror(errno));
break;
}
if (!answer) {
@ -459,7 +462,7 @@ try_again:
res = recvfrom(s, rsp_buf, sizeof(rsp_buf) - 1,
0, (struct sockaddr *) &src, &srclen);
if (res < 0) {
ast_debug(1, "recvfrom try %d failed: %s\n", retry, strerror(errno));
ast_debug_stun(1, "recvfrom try %d failed: %s\n", retry, strerror(errno));
break;
}
@ -500,13 +503,13 @@ static char *handle_cli_stun_set_debug(struct ast_cli_entry *e, int cmd, struct
return CLI_SHOWUSAGE;
if (!strncasecmp(a->argv[e->args-1], "on", 2))
stundebug = 1;
ast_debug_category_set_sublevel(AST_LOG_CATEGORY_STUN_PACKET, AST_LOG_CATEGORY_ENABLED);
else if (!strncasecmp(a->argv[e->args-1], "off", 3))
stundebug = 0;
ast_debug_category_set_sublevel(AST_LOG_CATEGORY_STUN_PACKET, AST_LOG_CATEGORY_DISABLED);
else
return CLI_SHOWUSAGE;
ast_cli(a->fd, "STUN Debugging %s\n", stundebug ? "Enabled" : "Disabled");
ast_cli(a->fd, "STUN Debugging %s\n", ast_debug_stun_packet_is_allowed ? "Enabled" : "Disabled");
return CLI_SUCCESS;
}
@ -514,9 +517,26 @@ static struct ast_cli_entry cli_stun[] = {
AST_CLI_DEFINE(handle_cli_stun_set_debug, "Enable/Disable STUN debugging"),
};
static uintmax_t debug_category_stun_id;
uintmax_t ast_debug_category_stun_id(void)
{
return debug_category_stun_id;
}
static uintmax_t debug_category_stun_packet_id;
uintmax_t ast_debug_category_stun_packet_id(void)
{
return debug_category_stun_packet_id;
}
static void stun_shutdown(void)
{
ast_cli_unregister_multiple(cli_stun, sizeof(cli_stun) / sizeof(struct ast_cli_entry));
ast_debug_category_unregister(AST_LOG_CATEGORY_STUN_PACKET);
ast_debug_category_unregister(AST_LOG_CATEGORY_STUN);
}
/*! \brief Initialize the STUN system in Asterisk */
@ -524,4 +544,7 @@ void ast_stun_init(void)
{
ast_cli_register_multiple(cli_stun, sizeof(cli_stun) / sizeof(struct ast_cli_entry));
ast_register_cleanup(stun_shutdown);
debug_category_stun_id = ast_debug_category_register(AST_LOG_CATEGORY_STUN);
debug_category_stun_packet_id = ast_debug_category_register(AST_LOG_CATEGORY_STUN_PACKET);
}

View File

@ -52,6 +52,7 @@
#include "asterisk/dsp.h"
#include "asterisk/linkedlists.h" /* for AST_LIST_NEXT */
#include "asterisk/stream.h"
#include "asterisk/logger_category.h"
#include "asterisk/format_cache.h"
#include "asterisk/res_pjsip.h"
@ -82,15 +83,15 @@ static int send_keepalive(const void *data)
keepalive = ast_rtp_instance_get_keepalive(rtp);
if (!ast_sockaddr_isnull(&session_media->direct_media_addr)) {
ast_debug(3, "Not sending RTP keepalive on RTP instance %p since direct media is in use\n", rtp);
ast_debug_rtp(3, "(%p) RTP not sending keepalive since direct media is in use\n", rtp);
return keepalive * 1000;
}
interval = time(NULL) - ast_rtp_instance_get_last_tx(rtp);
send_keepalive = interval >= keepalive;
ast_debug(3, "It has been %d seconds since RTP was last sent on instance %p. %sending keepalive\n",
(int) interval, rtp, send_keepalive ? "S" : "Not s");
ast_debug_rtp(3, "(%p) RTP it has been %d seconds since RTP was last sent. %sending keepalive\n",
rtp, (int) interval, send_keepalive ? "S" : "Not s");
if (send_keepalive) {
ast_rtp_instance_sendcng(rtp, 0);
@ -138,8 +139,8 @@ static int rtp_check_timeout(const void *data)
* - disconnect channel unless direct media is in use.
*/
if (!ast_sockaddr_isnull(&session_media->direct_media_addr)) {
ast_debug(3, "Not disconnecting channel '%s' for lack of %s RTP activity in %d seconds "
"since direct media is in use\n", ast_channel_name(chan),
ast_debug_rtp(3, "(%p) RTP not disconnecting channel '%s' for lack of %s RTP activity in %d seconds "
"since direct media is in use\n", rtp, ast_channel_name(chan),
ast_codec_media_type2str(session_media->type), elapsed);
ast_channel_unlock(chan);
ast_channel_unref(chan);
@ -233,12 +234,12 @@ static int create_rtp(struct ast_sip_session *session, struct ast_sip_session_me
if (session->endpoint->media.bind_rtp_to_media_address && !ast_strlen_zero(session->endpoint->media.address)) {
if (ast_sockaddr_parse(&temp_media_address, session->endpoint->media.address, 0)) {
ast_debug(1, "Endpoint %s: Binding RTP media to %s\n",
ast_debug_rtp(1, "Endpoint %s: Binding RTP media to %s\n",
ast_sorcery_object_get_id(session->endpoint),
session->endpoint->media.address);
media_address = &temp_media_address;
} else {
ast_debug(1, "Endpoint %s: RTP media address invalid: %s\n",
ast_debug_rtp(1, "Endpoint %s: RTP media address invalid: %s\n",
ast_sorcery_object_get_id(session->endpoint),
session->endpoint->media.address);
}
@ -256,11 +257,11 @@ static int create_rtp(struct ast_sip_session *session, struct ast_sip_session_me
pj_sockaddr_print(&trans_state->host, hoststr, sizeof(hoststr), 0);
if (ast_sockaddr_parse(&temp_media_address, hoststr, 0)) {
ast_debug(1, "Transport %s bound to %s: Using it for RTP media.\n",
ast_debug_rtp(1, "Transport %s bound to %s: Using it for RTP media.\n",
session->endpoint->transport, hoststr);
media_address = &temp_media_address;
} else {
ast_debug(1, "Transport %s bound to %s: Invalid for RTP media.\n",
ast_debug_rtp(1, "Transport %s bound to %s: Invalid for RTP media.\n",
session->endpoint->transport, hoststr);
}
ao2_ref(trans_state, -1);
@ -786,6 +787,8 @@ static void process_ice_attributes(struct ast_sip_session *session, struct ast_s
return;
}
ast_debug_ice(2, "(%p) ICE process attributes\n", session_media->rtp);
attr = pjmedia_sdp_media_find_attr2(remote_stream, "ice-ufrag", NULL);
if (!attr) {
attr = pjmedia_sdp_attr_find2(remote->attr_count, remote->attr, "ice-ufrag", NULL);
@ -794,6 +797,7 @@ static void process_ice_attributes(struct ast_sip_session *session, struct ast_s
ast_copy_pj_str(attr_value, (pj_str_t*)&attr->value, sizeof(attr_value));
ice->set_authentication(session_media->rtp, attr_value, NULL);
} else {
ast_debug_ice(2, "(%p) ICE no, or invalid ice-ufrag\n", session_media->rtp);
return;
}
@ -805,6 +809,7 @@ static void process_ice_attributes(struct ast_sip_session *session, struct ast_s
ast_copy_pj_str(attr_value, (pj_str_t*)&attr->value, sizeof(attr_value));
ice->set_authentication(session_media->rtp, NULL, attr_value);
} else {
ast_debug_ice(2, "(%p) ICE no, or invalid ice-pwd\n", session_media->rtp);
return;
}

File diff suppressed because it is too large Load Diff