RuhNetConsulting
/
rtpengine
mirror of https://github.com/sipwise/rtpengine
1
1
Fork 0
Code Issues 0 Projects 0 Releases 822 Wiki Activity
Browse Source

TT#97301 support granular log levels 

Change-Id: Ife458bd2449f61113a3e6db1708821570d92dc23
pull/1163/head
Richard Fuchs 5 years ago
parent
44bc0b90c8
commit
30733ec5cd
27 changed files with 425 additions and 317 deletions
Split View
Diff Options
Show Stats Download Patch File Download Diff File
  1. +3
    -1
      README.md
  2. +11
    -11
      daemon/call.c
  3. +27
    -12
      daemon/cli.c
  4. +90
    -91
      daemon/codec.c
  5. +10
    -10
      daemon/control_ng.c
  6. +8
    -8
      daemon/control_tcp.c
  7. +4
    -4
      daemon/control_udp.c
  8. +23
    -24
      daemon/crypto.c
  9. +21
    -21
      daemon/dtls.c
  10. +37
    -37
      daemon/ice.c
  11. +1
    -1
      daemon/log.h
  12. +12
    -0
      daemon/loglevels.h
  13. +21
    -10
      daemon/main.c
  14. +4
    -2
      daemon/redis.c
  15. +13
    -13
      daemon/rtcp.c
  16. +22
    -2
      daemon/rtpengine.pod
  17. +2
    -2
      daemon/t38.c
  18. +48
    -48
      daemon/websocket.c
  19. +3
    -5
      include/crypto.h
  20. +0
    -1
      include/main.h
  21. +12
    -5
      lib/auxlib.c
  22. +3
    -1
      lib/auxlib.h
  23. +2
    -2
      lib/codeclib.c
  24. +8
    -0
      lib/loglib.c
  25. +26
    -6
      lib/loglib.h
  26. +2
    -0
      recording-daemon/loglevels.h
  27. +12
    -0
      t/loglevels.h

+ 3
- 1
README.md View File

@ -194,7 +194,9 @@ Usage
Userspace Daemon
----------------
The options are described in detail in the rtpengine(1) man page.
The options are described in detail in the rtpengine(1) man page. If you're
reading this on Github, you can view the current master's man page
[here](https://github.com/sipwise/rtpengine/blob/master/daemon/rtpengine.pod).
In-kernel Packet Forwarding
---------------------------


+ 11
- 11
daemon/call.c View File

@ -777,7 +777,7 @@ static struct call_media *__get_media(struct call_monologue *ml, GList **it, con
med = g_hash_table_lookup(ml->media_ids, &sp->media_id);
if (med)
return med;
ilog(LOG_ERR, "Received trickle ICE SDP fragment with unknown media ID '"
ilogs(ice, LOG_ERR, "Received trickle ICE SDP fragment with unknown media ID '"
STR_FORMAT "'",
STR_FMT(&sp->media_id));
}
@ -1087,14 +1087,14 @@ int __init_stream(struct packet_stream *ps) {
struct crypto_params_sdes *cps = media->sdes_in.head
? media->sdes_in.head->data : NULL;
crypto_init(&sfd->crypto, cps ? &cps->params : NULL);
ilog(LOG_DEBUG, "[%s] Initialized incoming SRTP with SDES crypto params: %s%s%s",
ilogs(crypto, LOG_DEBUG, "[%s] Initialized incoming SRTP with SDES crypto params: %s%s%s",
endpoint_print_buf(&sfd->socket.local),
FMT_M(crypto_params_sdes_dump(cps, &paramsbuf)));
}
struct crypto_params_sdes *cps = media->sdes_out.head
? media->sdes_out.head->data : NULL;
crypto_init(&ps->crypto, cps ? &cps->params : NULL);
ilog(LOG_DEBUG, "[%i] Initialized outgoing SRTP with SDES crypto params: %s%s%s",
ilogs(crypto, LOG_DEBUG, "[%i] Initialized outgoing SRTP with SDES crypto params: %s%s%s",
ps->component,
FMT_M(crypto_params_sdes_dump(cps, &paramsbuf)));
}
@ -1489,7 +1489,7 @@ static void __generate_crypto(const struct sdp_ng_flags *flags, struct call_medi
if (flags->sdes_no && g_hash_table_lookup(flags->sdes_no,
&crypto_suites[i].name_str))
{
ilog(LOG_DEBUG, "Not offering crypto suite '%s' "
ilogs(crypto, LOG_DEBUG, "Not offering crypto suite '%s' "
"due to 'SDES-no' option",
crypto_suites[i].name);
continue;
@ -1515,14 +1515,14 @@ static void __generate_crypto(const struct sdp_ng_flags *flags, struct call_medi
struct crypto_params_sdes *cps_in = cpq_in->head ? cpq_in->head->data : NULL;
struct crypto_params_sdes *offered_cps = offered_cpq->head ? offered_cpq->head->data : NULL;
if (offered_cps) {
ilog(LOG_DEBUG, "Looking for matching crypto suite to offered %u:%s", offered_cps->tag,
ilogs(crypto, LOG_DEBUG, "Looking for matching crypto suite to offered %u:%s", offered_cps->tag,
offered_cps->params.crypto_suite->name);
// check if we can do SRTP<>SRTP passthrough. the crypto suite that was accepted
// must have been present in what was offered to us
for (GList *l = cpq_in->head; l; l = l->next) {
struct crypto_params_sdes *check_cps = l->data;
if (check_cps->params.crypto_suite == offered_cps->params.crypto_suite) {
ilog(LOG_DEBUG, "Found matching crypto suite %u:%s", check_cps->tag,
ilogs(crypto, LOG_DEBUG, "Found matching crypto suite %u:%s", check_cps->tag,
check_cps->params.crypto_suite->name);
cps_in = check_cps;
break;
@ -1540,7 +1540,7 @@ static void __generate_crypto(const struct sdp_ng_flags *flags, struct call_medi
// SRTP<>SRTP passthrough
cps->params.session_params = cps_in->params.session_params; // XXX verify
crypto_params_copy(&cps->params, &offered_cps->params, 1);
ilog(LOG_DEBUG, "Copied crypto params from %i:%s for SRTP passthrough",
ilogs(crypto, LOG_DEBUG, "Copied crypto params from %i:%s for SRTP passthrough",
cps_in->tag, cps_in->params.crypto_suite->name);
}
else {
@ -1550,14 +1550,14 @@ static void __generate_crypto(const struct sdp_ng_flags *flags, struct call_medi
cps->params.crypto_suite->master_salt_len);
/* mki = mki_len = 0 */
cps->params.session_params = cps_in->params.session_params;
ilog(LOG_DEBUG, "Creating new SRTP crypto params for %i:%s",
ilogs(crypto, LOG_DEBUG, "Creating new SRTP crypto params for %i:%s",
cps->tag, cps->params.crypto_suite->name);
}
// flush out crypto suites we ended up not using - leave only one
#if GLIB_CHECK_VERSION(2,30,0)
if (!g_queue_remove(cpq_in, cps_in))
ilog(LOG_ERR, "BUG: incoming crypto suite not found in queue");
ilogs(crypto, LOG_ERR, "BUG: incoming crypto suite not found in queue");
#else
g_queue_remove(cpq_in, cps_in);
#endif
@ -1595,7 +1595,7 @@ static void __sdes_accept(struct call_media *media, const struct sdp_ng_flags *f
continue;
}
ilog(LOG_DEBUG, "Dropping offered crypto suite '%s' from offer "
ilogs(crypto, LOG_DEBUG, "Dropping offered crypto suite '%s' from offer "
"due to 'SDES-no' option",
offered_cps->params.crypto_suite->name);
@ -1714,7 +1714,7 @@ static void __fingerprint_changed(struct call_media *m) {
if (!m->fingerprint.hash_func || !m->fingerprint.digest_len)
return;
ilog(LOG_INFO, "DTLS fingerprint changed, restarting DTLS");
ilogs(crypto, LOG_INFO, "DTLS fingerprint changed, restarting DTLS");
for (l = m->streams.head; l; l = l->next) {
ps = l->data;


+ 27
- 12
daemon/cli.c View File

@ -244,7 +244,12 @@ static void cli_incoming_params_start(str *instr, struct cli_writer *cw) {
GList *s;
struct intf_config *ifa;
cw->cw_printf(cw, "log-level = %d\ntable = %d\nmax-sessions = %d\ntimeout = %d\nsilent-timeout = %d\n"
for (unsigned int i = 0; i < num_log_levels; i++)
cw->cw_printf(cw, "log-level-%s = %d\n",
log_level_names[i],
g_atomic_int_get(&initial_rtpe_config.common.log_levels[i]));
cw->cw_printf(cw, "table = %d\nmax-sessions = %d\ntimeout = %d\nsilent-timeout = %d\n"
"final-timeout = %d\noffer-timeout = %d\n"
"delete-delay = %d\nredis-expires = %d\ntos = %d\ncontrol-tos = %d\ngraphite-interval = %d\nredis-num-threads = %d\n"
"homer-protocol = %d\nhomer-id = %d\nno-fallback = %d\nport-min = %d\nport-max = %d\nredis = %s:%d/%d\n"
@ -253,7 +258,7 @@ static void cli_incoming_params_start(str *instr, struct cli_writer *cw) {
"max-cpu = %.1f\n"
"max-load = %.2f\n"
"max-bandwidth = %" PRIu64 "\n",
initial_rtpe_config.common.log_level, initial_rtpe_config.kernel_table, initial_rtpe_config.max_sessions,
initial_rtpe_config.kernel_table, initial_rtpe_config.max_sessions,
initial_rtpe_config.timeout, initial_rtpe_config.silent_timeout, initial_rtpe_config.final_timeout,
initial_rtpe_config.offer_timeout, initial_rtpe_config.delete_delay,
initial_rtpe_config.redis_expires_secs, initial_rtpe_config.default_tos, initial_rtpe_config.control_tos,
@ -294,7 +299,12 @@ static void cli_incoming_params_current(str *instr, struct cli_writer *cw) {
GList *c;
struct intf_config *ifa;
cw->cw_printf(cw, "log-level = %d\ntable = %d\nmax-sessions = %d\ntimeout = %d\nsilent-timeout = %d\n"
for (unsigned int i = 0; i < num_log_levels; i++)
cw->cw_printf(cw, "log-level-%s = %d\n",
log_level_names[i],
g_atomic_int_get(&rtpe_config.common.log_levels[i]));
cw->cw_printf(cw, "table = %d\nmax-sessions = %d\ntimeout = %d\nsilent-timeout = %d\n"
"final-timeout = %d\noffer-timeout = %d\n"
"delete-delay = %d\nredis-expires = %d\ntos = %d\ncontrol-tos = %d\ngraphite-interval = %d\nredis-num-threads = %d\n"
"homer-protocol = %d\nhomer-id = %d\nno-fallback = %d\nport-min = %d\nport-max = %d\nredis-db = %d\n"
@ -303,7 +313,7 @@ static void cli_incoming_params_current(str *instr, struct cli_writer *cw) {
"max-cpu = %.1f\n"
"max-load = %.2f\n"
"max-bw = %" PRIu64 "\n",
rtpe_config.common.log_level, rtpe_config.kernel_table, rtpe_config.max_sessions, rtpe_config.timeout,
rtpe_config.kernel_table, rtpe_config.max_sessions, rtpe_config.timeout,
rtpe_config.silent_timeout, rtpe_config.final_timeout, rtpe_config.offer_timeout,
rtpe_config.delete_delay, rtpe_config.redis_expires_secs, rtpe_config.default_tos,
rtpe_config.control_tos, rtpe_config.graphite_interval, rtpe_config.redis_num_threads, rtpe_config.homer_protocol,
@ -367,7 +377,10 @@ static void int_diff_print_sz(long long start_param, void* current_param, size_t
option_string, cw, option)
static void cli_incoming_diff_or_revert(struct cli_writer *cw, char* option) {
int_diff_print(common.log_level, "log-level");
#define ll(system) \
int_diff_print(common.log_levels[log_level_index_ ## system], "log-level-" #system);
#include "loglevels.h"
#undef ll
int_diff_print(max_sessions, "max-sessions");
int_diff_print(cpu_limit, "max-cpu");
int_diff_print(load_limit, "max-load");
@ -1081,7 +1094,7 @@ static void cli_incoming_standby(str *instr, struct cli_writer *cw) {
}
static void cli_incoming(struct streambuf_stream *s) {
ilog(LOG_INFO, "New cli connection from %s", s->addr);
ilogs(control, LOG_INFO, "New cli connection from %s", s->addr);
}
static void cli_streambuf_printf(struct cli_writer *cw, const char *fmt, ...) {
@ -1099,7 +1112,7 @@ static void cli_stream_readable(struct streambuf_stream *s) {
inbuf = streambuf_getline(s->inbuf);
if (!inbuf) {
if (streambuf_bufsize(s->inbuf) > MAXINPUT) {
ilog(LOG_INFO, "Buffer length exceeded in CLI connection from %s", s->addr);
ilogs(control, LOG_INFO, "Buffer length exceeded in CLI connection from %s", s->addr);
streambuf_stream_close(s);
}
return;
@ -1119,7 +1132,7 @@ static void cli_stream_readable(struct streambuf_stream *s) {
}
void cli_handle(str *instr, struct cli_writer *cw) {
ilog(LOG_INFO, "Got CLI command: " STR_FORMAT_M, STR_FMT_M(instr));
ilogs(control, LOG_INFO, "Got CLI command: " STR_FORMAT_M, STR_FMT_M(instr));
cli_handler_do(cli_top_handlers, instr, cw);
}
@ -1143,7 +1156,7 @@ struct cli *cli_new(struct poller *p, endpoint_t *ep) {
NULL,
&c->obj))
{
ilog(LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
ilogs(control, LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
goto fail;
}
if (ipv46_any_convert(ep)) {
@ -1153,7 +1166,7 @@ struct cli *cli_new(struct poller *p, endpoint_t *ep) {
NULL,
&c->obj))
{
ilog(LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
ilogs(control, LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
goto fail;
}
}
@ -1170,7 +1183,8 @@ fail:
}
static void cli_incoming_list_loglevel(str *instr, struct cli_writer *cw) {
cw->cw_printf(cw, "%i\n", get_log_level());
for (unsigned int i = 0; i < num_log_levels; i++)
cw->cw_printf(cw, "%s = %i\n", log_level_names[i], __get_log_level(i));
}
static void cli_incoming_set_loglevel(str *instr, struct cli_writer *cw) {
int nl;
@ -1187,7 +1201,8 @@ static void cli_incoming_set_loglevel(str *instr, struct cli_writer *cw) {
return;
}
g_atomic_int_set(&rtpe_config.common.log_level, nl);
for (unsigned int i = 0; i < num_log_levels; i++)
g_atomic_int_set(&rtpe_config.common.log_levels[i], nl);
cw->cw_printf(cw, "Success setting loglevel to %i\n", nl);
}


+ 90
- 91
daemon/codec.c View File

@ -233,7 +233,7 @@ static struct codec_handler *__handler_new(const struct rtp_payload_type *pt, st
static void __make_passthrough(struct codec_handler *handler) {
__handler_shutdown(handler);
ilog(LOG_DEBUG, "Using passthrough handler for " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Using passthrough handler for " STR_FORMAT,
STR_FMT(&handler->source_pt.encoding_with_params));
if (handler->source_pt.codec_def && handler->source_pt.codec_def->dtmf)
handler->func = handler_func_dtmf;
@ -248,7 +248,7 @@ static void __make_passthrough(struct codec_handler *handler) {
}
static void __make_passthrough_ssrc(struct codec_handler *handler) {
__handler_shutdown(handler);
ilog(LOG_DEBUG, "Using passthrough handler with new SSRC for " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Using passthrough handler with new SSRC for " STR_FORMAT,
STR_FMT(&handler->source_pt.encoding_with_params));
if (handler->source_pt.codec_def && handler->source_pt.codec_def->dtmf)
handler->func = handler_func_dtmf;
@ -280,7 +280,7 @@ static void __make_transcoder(struct codec_handler *handler, struct rtp_payload_
if (handler->func != handler_func_transcode)
goto reset;
ilog(LOG_DEBUG, "Leaving transcode context for " STR_FORMAT " -> " STR_FORMAT " intact",
ilogs(codec, LOG_DEBUG, "Leaving transcode context for " STR_FORMAT " -> " STR_FORMAT " intact",
STR_FMT(&handler->source_pt.encoding_with_params),
STR_FMT(&dest->encoding_with_params));
@ -298,13 +298,13 @@ reset:
// is this DTMF to DTMF?
if (dtmf_payload_type != -1 && handler->source_pt.codec_def->dtmf) {
ilog(LOG_DEBUG, "Created DTMF transcode context for " STR_FORMAT " -> PT %i",
ilogs(codec, LOG_DEBUG, "Created DTMF transcode context for " STR_FORMAT " -> PT %i",
STR_FMT(&handler->source_pt.encoding_with_params),
dtmf_payload_type);
handler->dtmf_scaler = 1;
}
else
ilog(LOG_DEBUG, "Created transcode context for " STR_FORMAT " -> " STR_FORMAT
ilogs(codec, LOG_DEBUG, "Created transcode context for " STR_FORMAT " -> " STR_FORMAT
" with DTMF output %i",
STR_FMT(&handler->source_pt.encoding_with_params),
STR_FMT(&dest->encoding_with_params), dtmf_payload_type);
@ -339,7 +339,7 @@ check_output:;
output_handler = g_hash_table_lookup(output_transcoders,
GINT_TO_POINTER(dest->payload_type));
if (output_handler) {
ilog(LOG_DEBUG, "Using existing encoder context");
ilogs(codec, LOG_DEBUG, "Using existing encoder context");
handler->output_handler = output_handler;
}
else {
@ -361,7 +361,7 @@ struct codec_handler *codec_handler_make_playback(const struct rtp_payload_type
handler->ssrc_handler->first_ts = random();
handler->ssrc_handler->rtp_mark = 1;
ilog(LOG_DEBUG, "Created media playback context for " STR_FORMAT " -> " STR_FORMAT "",
ilogs(codec, LOG_DEBUG, "Created media playback context for " STR_FORMAT " -> " STR_FORMAT "",
STR_FMT(&src_pt->encoding_with_params),
STR_FMT(&dst_pt->encoding_with_params));
@ -404,7 +404,7 @@ static void __dtmf_dsp_shutdown(struct call_media *sink, int payload_type) {
if (handler->dtmf_scaler)
continue;
ilog(LOG_DEBUG, "Shutting down DTMF DSP for '" STR_FORMAT "' -> %i (not needed)",
ilogs(codec, LOG_DEBUG, "Shutting down DTMF DSP for '" STR_FORMAT "' -> %i (not needed)",
STR_FMT(&handler->source_pt.encoding_with_params),
payload_type);
handler->dtmf_payload_type = -1;
@ -485,7 +485,7 @@ static struct rtp_payload_type *__check_dest_codecs(struct call_media *receiver,
if (first_tc_codec)
pref_dest_codec = first_tc_codec;
if (pref_dest_codec)
ilog(LOG_DEBUG, "Default sink codec is " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Default sink codec is " STR_FORMAT,
STR_FMT(&pref_dest_codec->encoding_with_params));
return pref_dest_codec;
@ -563,11 +563,11 @@ static int __dtmf_payload_type(GHashTable *supplemental_sinks, struct rtp_payloa
int dtmf_payload_type = __supp_payload_type(supplemental_sinks, pref_dest_codec, "telephone-event");
if (dtmf_payload_type == -1)
ilog(LOG_INFO, "Not transcoding PCM DTMF tones to telephone-event packets as "
ilogs(codec, LOG_INFO, "Not transcoding PCM DTMF tones to telephone-event packets as "
"no payload type with a matching clock rate for '" STR_FORMAT
"' was found", STR_FMT(&pref_dest_codec->encoding_with_params));
else
ilog(LOG_DEBUG, "Output DTMF payload type is %i", dtmf_payload_type);
ilogs(codec, LOG_DEBUG, "Output DTMF payload type is %i", dtmf_payload_type);
return dtmf_payload_type;
}
@ -624,7 +624,7 @@ static void __single_codec(struct call_media *media, const struct sdp_ng_flags *
l = l->next;
continue;
}
ilog(LOG_DEBUG, "Removing codec '" STR_FORMAT "' due to 'single codec' flag",
ilogs(codec, LOG_DEBUG, "Removing codec '" STR_FORMAT "' due to 'single codec' flag",
STR_FMT(&pt->encoding_with_params));
codec_touched(pt, media);
l = __delete_receiver_codec(media, l);
@ -696,13 +696,13 @@ static void __accept_transcode_codecs(struct call_media *receiver, struct call_m
// the existing entry.
int new_pt = __unused_pt_number(receiver, sink, existing_pt);
if (new_pt < 0) {
ilog(LOG_WARN, "Ran out of RTP payload type numbers while accepting '"
ilogs(codec, LOG_WARN, "Ran out of RTP payload type numbers while accepting '"
STR_FORMAT "' due to '" STR_FORMAT "'",
STR_FMT(&pt->encoding_with_params),
STR_FMT(&existing_pt->encoding_with_params));
continue;
}
ilog(LOG_DEBUG, "Renumbering '" STR_FORMAT "' from PT %i to %i due to '" STR_FORMAT "'",
ilogs(codec, LOG_DEBUG, "Renumbering '" STR_FORMAT "' from PT %i to %i due to '" STR_FORMAT "'",
STR_FMT(&existing_pt->encoding_with_params),
existing_pt->payload_type,
new_pt,
@ -713,7 +713,7 @@ static void __accept_transcode_codecs(struct call_media *receiver, struct call_m
}
//ilog(LOG_DEBUG, "XXXXXXXXXXXXX offered codec %i", pt->for_transcoding);
ilog(LOG_DEBUG, "Accepting offered codec " STR_FORMAT " due to transcoding",
ilogs(codec, LOG_DEBUG, "Accepting offered codec " STR_FORMAT " due to transcoding",
STR_FMT(&pt->encoding_with_params));
MEDIA_SET(receiver, TRANSCODE);
@ -769,7 +769,7 @@ static void __eliminate_rejected_codecs(struct call_media *receiver, struct call
l = l->next;
continue;
}
ilog(LOG_DEBUG, "Eliminating asymmetric outbound codec " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Eliminating asymmetric outbound codec " STR_FORMAT,
STR_FMT(&pt->encoding_with_params));
l = __delete_send_codec(receiver, l);
}
@ -784,7 +784,7 @@ static GHashTable *__payload_type_queue_hash(GQueue *prefs, GQueue *order) {
for (GList *l = prefs->head; l; l = l->next) {
struct rtp_payload_type *pt = l->data;
if (g_hash_table_lookup(ret, GINT_TO_POINTER(pt->payload_type))) {
ilog(LOG_DEBUG, "Removing duplicate RTP payload type %i", pt->payload_type);
ilogs(codec, LOG_DEBUG, "Removing duplicate RTP payload type %i", pt->payload_type);
payload_type_free(pt);
continue;
}
@ -837,7 +837,7 @@ static void __symmetric_codecs(struct call_media *receiver, struct call_media *s
struct rtp_payload_type *send_pt;
if (!out_pt || !(send_pt = g_hash_table_lookup(prefs_send, GINT_TO_POINTER(pt->payload_type)))) {
// we must transcode after all.
ilog(LOG_DEBUG, "RTP payload type %i is not symmetric and must be transcoded",
ilogs(codec, LOG_DEBUG, "RTP payload type %i is not symmetric and must be transcoded",
pt->payload_type);
transcoding = 1;
continue;
@ -857,7 +857,7 @@ static void __symmetric_codecs(struct call_media *receiver, struct call_media *s
continue; // not interesting
// add it to the list
ilog(LOG_DEBUG, "Adding force-accepted RTP payload type %i", prefix_pt->payload_type);
ilogs(codec, LOG_DEBUG, "Adding force-accepted RTP payload type %i", prefix_pt->payload_type);
g_hash_table_steal(prefs_send, ptype);
__rtp_payload_type_add_send(receiver, prefix_pt);
// and our receive leg
@ -870,7 +870,7 @@ static void __symmetric_codecs(struct call_media *receiver, struct call_media *s
}
// add it to the list
ilog(LOG_DEBUG, "Adding symmetric RTP payload type %i", pt->payload_type);
ilogs(codec, LOG_DEBUG, "Adding symmetric RTP payload type %i", pt->payload_type);
g_hash_table_steal(prefs_recv, GINT_TO_POINTER(pt->payload_type));
__rtp_payload_type_add_recv(receiver, out_pt, 1);
// and our send leg
@ -934,7 +934,7 @@ static void __check_dtmf_injector(const struct sdp_ng_flags *flags, struct call_
const str tp_event = STR_CONST_INIT("telephone-event");
src_pt.codec_def = codec_find(&tp_event, MT_AUDIO);
if (!src_pt.codec_def) {
ilog(LOG_ERR, "RTP payload type 'telephone-event' is not defined");
ilogs(codec, LOG_ERR, "RTP payload type 'telephone-event' is not defined");
return;
}
@ -956,14 +956,14 @@ static struct codec_handler *__get_pt_handler(struct call_media *receiver, struc
if (handler) {
// make sure existing handler matches this PT
if (rtp_payload_type_cmp(pt, &handler->source_pt)) {
ilog(LOG_DEBUG, "Resetting codec handler for PT %u", pt->payload_type);
ilogs(codec, LOG_DEBUG, "Resetting codec handler for PT %u", pt->payload_type);
handler = NULL;
g_atomic_pointer_set(&receiver->codec_handler_cache, NULL);
g_hash_table_remove(receiver->codec_handlers, GINT_TO_POINTER(pt->payload_type));
}
}
if (!handler) {
ilog(LOG_DEBUG, "Creating codec handler for " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Creating codec handler for " STR_FORMAT,
STR_FMT(&pt->encoding_with_params));
handler = __handler_new(pt, receiver);
g_hash_table_insert(receiver->codec_handlers,
@ -987,7 +987,7 @@ static struct codec_handler *__get_pt_handler(struct call_media *receiver, struc
static void __check_t38_decoder(struct call_media *t38_media) {
if (t38_media->t38_handler)
return;
ilog(LOG_DEBUG, "Creating T.38 packet handler");
ilogs(codec, LOG_DEBUG, "Creating T.38 packet handler");
t38_media->t38_handler = __handler_new(NULL, t38_media);
t38_media->t38_handler->func = handler_func_t38;
}
@ -1053,12 +1053,12 @@ static void __check_t38_gateway(struct call_media *pcm_media, struct call_media
struct codec_handler *handler = __get_pt_handler(pcm_media, pt);
if (!pt->codec_def) {
// should not happen
ilog(LOG_WARN, "Unsupported codec " STR_FORMAT " for T.38 transcoding",
ilogs(codec, LOG_WARN, "Unsupported codec " STR_FORMAT " for T.38 transcoding",
STR_FMT(&pt->encoding_with_params));
continue;
}
ilog(LOG_DEBUG, "Creating T.38 encoder for " STR_FORMAT, STR_FMT(&pt->encoding_with_params));
ilogs(codec, LOG_DEBUG, "Creating T.38 encoder for " STR_FORMAT, STR_FMT(&pt->encoding_with_params));
__make_transcoder(handler, &pcm_media->t38_gateway->pcm_pt, NULL, -1, 0);
@ -1081,7 +1081,7 @@ static int codec_handler_udptl_update(struct call_media *receiver, struct call_m
return 1;
}
}
ilog(LOG_WARN, "Unsupported non-RTP protocol: " STR_FORMAT "/" STR_FORMAT
ilogs(codec, LOG_WARN, "Unsupported non-RTP protocol: " STR_FORMAT "/" STR_FORMAT
" -> " STR_FORMAT "/" STR_FORMAT,
STR_FMT(&receiver->type), STR_FMT(&receiver->format_str),
STR_FMT(&sink->type), STR_FMT(&sink->format_str));
@ -1097,7 +1097,7 @@ static int codec_handler_non_rtp_update(struct call_media *receiver, struct call
__check_t38_gateway(receiver, sink, sp, flags);
return 1;
}
ilog(LOG_WARN, "Unsupported non-RTP protocol: " STR_FORMAT "/" STR_FORMAT
ilogs(codec, LOG_WARN, "Unsupported non-RTP protocol: " STR_FORMAT "/" STR_FORMAT
" -> " STR_FORMAT "/" STR_FORMAT,
STR_FMT(&receiver->type), STR_FMT(&receiver->format_str),
STR_FMT(&sink->type), STR_FMT(&sink->format_str));
@ -1295,7 +1295,7 @@ void codec_handlers_update(struct call_media *receiver, struct call_media *sink,
// stop transcoding if we've determined that we don't need it
if (MEDIA_ISSET(sink, TRANSCODE) && !sink_transcoding && !(receiver_transcoding & 0x2)) {
ilog(LOG_DEBUG, "Disabling transcoding engine (not needed)");
ilogs(codec, LOG_DEBUG, "Disabling transcoding engine (not needed)");
MEDIA_CLEAR(sink, TRANSCODE);
}
@ -1332,7 +1332,7 @@ void codec_handlers_update(struct call_media *receiver, struct call_media *sink,
struct rtp_payload_type *recv_pt =
g_hash_table_lookup(receiver->codecs_send, &pt->payload_type);
if (!recv_pt && !pt->for_transcoding) {
ilog(LOG_DEBUG, "Eliminating transcoded codec " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Eliminating transcoded codec " STR_FORMAT,
STR_FMT(&pt->encoding_with_params));
codec_touched(pt, receiver);
@ -1355,7 +1355,7 @@ void codec_handlers_update(struct call_media *receiver, struct call_media *sink,
// to do. most likely this is an initial offer without a received answer.
// we default to forwarding without transcoding.
if (!pref_dest_codec) {
ilog(LOG_DEBUG, "No known/supported sink codec for " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "No known/supported sink codec for " STR_FORMAT,
STR_FMT(&pt->encoding_with_params));
__make_passthrough_gsl(handler, &passthrough_handlers);
goto next;
@ -1412,7 +1412,7 @@ void codec_handlers_update(struct call_media *receiver, struct call_media *sink,
if (dest_pt->ptime && pt->ptime
&& dest_pt->ptime != pt->ptime)
{
ilog(LOG_DEBUG, "Mismatched ptime between source and sink (%i <> %i), "
ilogs(codec, LOG_DEBUG, "Mismatched ptime between source and sink (%i <> %i), "
"enabling transcoding",
dest_pt->ptime, pt->ptime);
goto transcode;
@ -1434,7 +1434,7 @@ void codec_handlers_update(struct call_media *receiver, struct call_media *sink,
goto transcode;
// XXX check format parameters as well
ilog(LOG_DEBUG, "Sink supports codec " STR_FORMAT, STR_FMT(&pt->encoding_with_params));
ilogs(codec, LOG_DEBUG, "Sink supports codec " STR_FORMAT, STR_FMT(&pt->encoding_with_params));
__make_passthrough_gsl(handler, &passthrough_handlers);
if (pt->codec_def && pt->codec_def->dtmf)
__dtmf_dsp_shutdown(sink, pt->payload_type);
@ -1443,7 +1443,7 @@ void codec_handlers_update(struct call_media *receiver, struct call_media *sink,
unsupported:
// the sink does not support this codec -> transcode
ilog(LOG_DEBUG, "Sink does not support codec " STR_FORMAT, STR_FMT(&pt->encoding_with_params));
ilogs(codec, LOG_DEBUG, "Sink does not support codec " STR_FORMAT, STR_FMT(&pt->encoding_with_params));
dest_pt = pref_dest_codec;
if (pt->codec_def->supplemental)
transcode_supplemental = 1;
@ -1471,7 +1471,7 @@ next:
// the list, as we must expect to potentially receive media in that codec, which we
// then could not transcode.
if (MEDIA_ISSET(receiver, TRANSCODE)) {
ilog(LOG_INFO, "Enabling transcoding engine");
ilogs(codec, LOG_INFO, "Enabling transcoding engine");
for (GList *l = receiver->codecs_prefs_recv.head; l; ) {
struct rtp_payload_type *pt = l->data;
@ -1482,7 +1482,7 @@ next:
continue;
}
ilog(LOG_DEBUG, "Stripping unsupported codec " STR_FORMAT " due to active transcoding",
ilogs(codec, LOG_DEBUG, "Stripping unsupported codec " STR_FORMAT " due to active transcoding",
STR_FMT(&pt->encoding));
codec_touched(pt, receiver);
l = __delete_receiver_codec(receiver, l);
@ -1700,7 +1700,7 @@ static int __handler_func_sequencer(struct media_packet *mp, struct transcode_pa
if (packet->dup_func)
packet->dup_func(ch, packet, mp);
else
ilog(LOG_DEBUG, "Ignoring duplicate RTP packet");
ilogs(transcoding, LOG_DEBUG, "Ignoring duplicate RTP packet");
__transcode_packet_free(packet);
atomic64_inc(&ssrc_in->duplicates);
goto out;
@ -1724,7 +1724,7 @@ static int __handler_func_sequencer(struct media_packet *mp, struct transcode_pa
packet = packet_sequencer_force_next_packet(&ssrc_in_p->sequencer);
if (!packet)
break;
ilog(LOG_DEBUG, "Timestamp difference too large (%llu ms) after lost packet, "
ilogs(transcoding, LOG_DEBUG, "Timestamp difference too large (%llu ms) after lost packet, "
"forcing next packet", ts_diff_us / 1000);
}
else
@ -1740,7 +1740,7 @@ static int __handler_func_sequencer(struct media_packet *mp, struct transcode_pa
atomic64_set(&ssrc_in->packets_lost, ssrc_in_p->sequencer.lost_count);
atomic64_set(&ssrc_in->last_seq, ssrc_in_p->sequencer.ext_seq);
ilog(LOG_DEBUG, "Processing RTP packet: seq %u, TS %lu",
ilogs(transcoding, LOG_DEBUG, "Processing RTP packet: seq %u, TS %lu",
packet->p.seq, packet->ts);
if (seq_ret == 1) {
@ -1754,7 +1754,7 @@ static int __handler_func_sequencer(struct media_packet *mp, struct transcode_pa
func_ret = packet->func(ch, packet, mp);
if (func_ret < 0)
ilog(LOG_WARN | LOG_FLAG_LIMIT, "Decoder error while processing RTP packet");
ilogs(transcoding, LOG_WARN | LOG_FLAG_LIMIT, "Decoder error while processing RTP packet");
next:
if (func_ret != 1)
__transcode_packet_free(packet);
@ -1829,7 +1829,7 @@ static void __output_rtp(struct media_packet *mp, struct codec_ssrc_handler *ch,
ch->output_skew = ch->output_skew * 15 / 16 + ts_diff_us / 16;
if (ch->output_skew > 40000 && ts_diff_us > 10000) { // arbitrary value, 40 ms, 10 ms shift
ilog(LOG_DEBUG, "Steady clock skew of %lu.%01lu ms detected, shifting send timer back by 10 ms",
ilogs(transcoding, LOG_DEBUG, "Steady clock skew of %lu.%01lu ms detected, shifting send timer back by 10 ms",
ch->output_skew / 1000,
(ch->output_skew % 1000) / 100);
timeval_add_usec(&p->ttq_entry.when, -10000);
@ -1837,7 +1837,7 @@ static void __output_rtp(struct media_packet *mp, struct codec_ssrc_handler *ch,
ch->first_send_ts += ch->encoder_format.clockrate / 100;
}
ilog(LOG_DEBUG, "Scheduling to send RTP packet (seq %u TS %lu) in %llu.%01llu ms (at %lu.%06lu)",
ilogs(transcoding, LOG_DEBUG, "Scheduling to send RTP packet (seq %u TS %lu) in %llu.%01llu ms (at %lu.%06lu)",
ntohs(rh->seq_num),
ts,
ts_diff_us / 1000,
@ -1857,11 +1857,11 @@ static struct codec_ssrc_handler *__output_ssrc_handler(struct codec_ssrc_handle
}
// our encoder is in a different codec handler
ilog(LOG_DEBUG, "Switching context from decoder to encoder");
ilogs(transcoding, LOG_DEBUG, "Switching context from decoder to encoder");
handler = handler->output_handler;
struct codec_ssrc_handler *new_ch = get_ssrc(mp->ssrc_in->parent->h.ssrc, handler->ssrc_hash);
if (G_UNLIKELY(!new_ch)) {
ilog(LOG_ERR, "Switched from input to output codec context, but no codec handler present");
ilogs(transcoding, LOG_ERR, "Switched from input to output codec context, but no codec handler present");
obj_get(&ch->h);
return ch;
}
@ -1901,7 +1901,7 @@ static void packet_dtmf_fwd(struct codec_ssrc_handler *ch, struct transcode_pack
// adjust to output RTP TS
unsigned long packet_ts = ts + output_ch->first_ts;
ilog(LOG_DEBUG, "Scaling DTMF packet timestamp and duration: TS %lu -> %lu "
ilogs(transcoding, LOG_DEBUG, "Scaling DTMF packet timestamp and duration: TS %lu -> %lu "
"(%u -> %u)",
packet->ts, packet_ts,
ch->handler->source_pt.clock_rate, ch->handler->dest_pt.clock_rate);
@ -1966,7 +1966,7 @@ static int __handler_func_supplemental(struct codec_handler *h, struct media_pac
// create new packet and insert it into sequencer queue
ilog(LOG_DEBUG, "Received %s RTP packet: SSRC %" PRIx32 ", PT %u, seq %u, TS %u, len %i",
ilogs(transcoding, LOG_DEBUG, "Received %s RTP packet: SSRC %" PRIx32 ", PT %u, seq %u, TS %u, len %i",
h->source_pt.codec_def->rtpname,
ntohl(mp->rtp->ssrc), mp->rtp->m_pt, ntohs(mp->rtp->seq_num),
ntohl(mp->rtp->timestamp), mp->payload.len);
@ -1986,7 +1986,7 @@ static int __handler_func_supplemental(struct codec_handler *h, struct media_pac
continue;
if (sequencer_h->source_pt.codec_def && sequencer_h->source_pt.codec_def->supplemental)
continue;
ilog(LOG_DEBUG, "Primary RTP payload type for handling %s is %i",
ilogs(transcoding, LOG_DEBUG, "Primary RTP payload type for handling %s is %i",
h->source_pt.codec_def->rtpname,
prim_pt);
break;
@ -2177,7 +2177,7 @@ static void __dtmf_dsp_callback(void *ptr, int code, int level, int delay) {
void codec_add_dtmf_event(struct codec_ssrc_handler *ch, int code, int level, uint64_t ts) {
struct dtmf_event *ev = g_slice_alloc(sizeof(*ev));
*ev = (struct dtmf_event) { .code = code, .volume = level, .ts = ts };
ilog(LOG_DEBUG, "DTMF event state change: code %i, volume %i, TS %lu",
ilogs(transcoding, LOG_DEBUG, "DTMF event state change: code %i, volume %i, TS %lu",
ev->code, ev->volume, (unsigned long) ts);
g_queue_push_tail(&ch->dtmf_events, ev);
}
@ -2194,13 +2194,13 @@ uint64_t codec_encoder_pts(struct codec_ssrc_handler *ch) {
}
void codec_decoder_skip_pts(struct codec_ssrc_handler *ch, uint64_t pts) {
ilog(LOG_DEBUG, "Skipping next %" PRIu64 " samples", pts);
ilogs(transcoding, LOG_DEBUG, "Skipping next %" PRIu64 " samples", pts);
ch->skip_pts += pts;
}
uint64_t codec_decoder_unskip_pts(struct codec_ssrc_handler *ch) {
uint64_t prev = ch->skip_pts;
ilog(LOG_DEBUG, "Un-skipping next %" PRIu64 " samples", prev);
ilogs(transcoding, LOG_DEBUG, "Un-skipping next %" PRIu64 " samples", prev);
ch->skip_pts = 0;
return prev;
}
@ -2268,13 +2268,13 @@ static void __dtx_send_later(struct timerthread_queue *ttq, void *p) {
__ssrc_lock_both(mp);
if (packet) {
ilog(LOG_DEBUG, "Decoding DTX-buffered RTP packet (TS %lu) now", packet->ts);
ilogs(transcoding, LOG_DEBUG, "Decoding DTX-buffered RTP packet (TS %lu) now", packet->ts);
ret = decoder_input_data(ch->decoder, packet->payload, packet->ts,
ch->handler->packet_decoded, ch, &dtxe->mp);
mp->ssrc_out->parent->seq_diff--;
if (ret)
ilog(LOG_WARN | LOG_FLAG_LIMIT, "Decoder error while processing buffered RTP packet");
ilogs(transcoding, LOG_WARN | LOG_FLAG_LIMIT, "Decoder error while processing buffered RTP packet");
}
else {
unsigned long dtxe_ts = dtxe->ts;
@ -2288,7 +2288,7 @@ static void __dtx_send_later(struct timerthread_queue *ttq, void *p) {
&& ssrc_ptr == dtxe->ssrc_ptr
&& (rtpe_config.max_dtx <= 0 || diff < rtpe_config.max_dtx))
{
ilog(LOG_DEBUG, "RTP media for TS %lu+ missing, triggering DTX",
ilogs(transcoding, LOG_DEBUG, "RTP media for TS %lu+ missing, triggering DTX",
dtxe_ts);
dtxb_ts += dtxb->tspp;
@ -2299,7 +2299,7 @@ static void __dtx_send_later(struct timerthread_queue *ttq, void *p) {
ret = decoder_lost_packet(ch->decoder, dtxe_ts,
ch->handler->packet_decoded, ch, &dtxe->mp);
if (ret)
ilog(LOG_WARN | LOG_FLAG_LIMIT, "Decoder error handling DTX/lost packet");
ilogs(transcoding, LOG_WARN | LOG_FLAG_LIMIT, "Decoder error handling DTX/lost packet");
__dtx_add_callback(dtxb, &dtxe->ttq_entry.when, dtxb->ptime * 1000, mp, dtxe_ts, 0, ssrc_ptr);
}
@ -2316,11 +2316,11 @@ static void __dtx_send_later(struct timerthread_queue *ttq, void *p) {
media_socket_dequeue(mp, NULL); // just free
else {
if (ps->handler && media_packet_encrypt(ps->handler->out->rtp_crypt, sink, mp))
ilog(LOG_ERR | LOG_FLAG_LIMIT, "Error encrypting buffered RTP media");
ilogs(transcoding, LOG_ERR | LOG_FLAG_LIMIT, "Error encrypting buffered RTP media");
mutex_lock(&sink->out_lock);
if (media_socket_dequeue(mp, sink))
ilog(LOG_ERR | LOG_FLAG_LIMIT, "Error sending buffered media to RTP sink");
ilogs(transcoding, LOG_ERR | LOG_FLAG_LIMIT, "Error sending buffered media to RTP sink");
mutex_unlock(&sink->out_lock);
}
}
@ -2343,7 +2343,6 @@ static void __dtx_shutdown(struct dtx_buffer *dtxb) {
}
static void __dtx_free(void *p) {
struct dtx_buffer *dtxb = p;
ilog(LOG_DEBUG, "__dtx_free");
__dtx_shutdown(dtxb);
mutex_destroy(&dtxb->lock);
}
@ -2445,7 +2444,7 @@ static void __silence_detect(struct codec_ssrc_handler *ch, AVFrame *frame) {
__silence_detect_int16_t(ch, frame, rtpe_config.silence_detect_int >> 16);
break;
default:
ilog(LOG_WARN | LOG_FLAG_LIMIT, "Unsupported sample format %i for silence detection",
ilogs(transcoding, LOG_WARN | LOG_FLAG_LIMIT, "Unsupported sample format %i for silence detection",
frame->format);
}
}
@ -2486,13 +2485,13 @@ static struct ssrc_entry *__ssrc_handler_transcode_new(void *p) {
struct codec_handler *h = p;
if (h->dtmf_scaler)
ilog(LOG_DEBUG, "Creating SSRC DTMF transcoder from %s/%u/%i to "
ilogs(codec, LOG_DEBUG, "Creating SSRC DTMF transcoder from %s/%u/%i to "
"PT %i",
h->source_pt.codec_def->rtpname, h->source_pt.clock_rate,
h->source_pt.channels,
h->dtmf_payload_type);
else
ilog(LOG_DEBUG, "Creating SSRC transcoder from %s/%u/%i to "
ilogs(codec, LOG_DEBUG, "Creating SSRC transcoder from %s/%u/%i to "
"%s/%u/%i",
h->source_pt.codec_def->rtpname, h->source_pt.clock_rate,
h->source_pt.channels,
@ -2521,11 +2520,11 @@ static struct ssrc_entry *__ssrc_handler_transcode_new(void *p) {
goto err;
if (h->pcm_dtmf_detect) {
ilog(LOG_DEBUG, "Inserting DTMF DSP for output payload type %i", h->dtmf_payload_type);
ilogs(codec, LOG_DEBUG, "Inserting DTMF DSP for output payload type %i", h->dtmf_payload_type);
ch->dtmf_format = (format_t) { .clockrate = 8000, .channels = 1, .format = AV_SAMPLE_FMT_S16 };
ch->dtmf_dsp = dtmf_rx_init(NULL, NULL, NULL);
if (!ch->dtmf_dsp)
ilog(LOG_ERR, "Failed to allocate DTMF RX context");
ilogs(codec, LOG_ERR, "Failed to allocate DTMF RX context");
else
dtmf_rx_set_realtime_callback(ch->dtmf_dsp, __dtmf_dsp_callback, ch);
}
@ -2544,7 +2543,7 @@ static struct ssrc_entry *__ssrc_handler_transcode_new(void *p) {
__dtx_setup(ch);
ilog(LOG_DEBUG, "Encoder created with clockrate %i, %i channels, using sample format %i "
ilogs(codec, LOG_DEBUG, "Encoder created with clockrate %i, %i channels, using sample format %i "
"(ptime %i for %i samples per frame and %i samples (%i bytes) per packet, bitrate %i)",
ch->encoder_format.clockrate, ch->encoder_format.channels, ch->encoder_format.format,
ch->ptime, ch->encoder->samples_per_frame, ch->encoder->samples_per_packet,
@ -2590,7 +2589,7 @@ static int packet_encoded_rtp(encoder_t *enc, void *u1, void *u2) {
struct media_packet *mp = u2;
//unsigned int seq_off = (mp->iter_out > mp->iter_in) ? 1 : 0;
ilog(LOG_DEBUG, "RTP media successfully encoded: TS %llu, len %i",
ilogs(transcoding, LOG_DEBUG, "RTP media successfully encoded: TS %llu, len %i",
(unsigned long long) enc->avpkt.pts, enc->avpkt.size);
// run this through our packetizer
@ -2609,7 +2608,7 @@ static int packet_encoded_rtp(encoder_t *enc, void *u1, void *u2) {
str_init_len(&inout, payload, payload_len);
// and request a packet
if (in_pkt)
ilog(LOG_DEBUG, "Adding %i bytes to packetizer", in_pkt->size);
ilogs(transcoding, LOG_DEBUG, "Adding %i bytes to packetizer", in_pkt->size);
int ret = ch->handler->dest_pt.codec_def->packetizer(in_pkt,
ch->sample_buffer, &inout, enc);
@ -2619,7 +2618,7 @@ static int packet_encoded_rtp(encoder_t *enc, void *u1, void *u2) {
break;
}
ilog(LOG_DEBUG, "Received packet of %i bytes from packetizer", inout.len);
ilogs(transcoding, LOG_DEBUG, "Received packet of %i bytes from packetizer", inout.len);
// check special payloads
@ -2681,11 +2680,11 @@ static void __dtmf_detect(struct codec_ssrc_handler *ch, AVFrame *frame) {
AVFrame *dsp_frame = resample_frame(&ch->dtmf_resampler, frame, &ch->dtmf_format);
if (!dsp_frame) {
ilog(LOG_ERR | LOG_FLAG_LIMIT, "Failed to resample audio for DTMF DSP");
ilogs(transcoding, LOG_ERR | LOG_FLAG_LIMIT, "Failed to resample audio for DTMF DSP");
return;
}
ilog(LOG_DEBUG, "DTMF detect, TS %lu -> %lu, %u -> %u samples",
ilogs(transcoding, LOG_DEBUG, "DTMF detect, TS %lu -> %lu, %u -> %u samples",
(unsigned long) frame->pts,
(unsigned long) dsp_frame->pts,
frame->nb_samples,
@ -2694,7 +2693,7 @@ static void __dtmf_detect(struct codec_ssrc_handler *ch, AVFrame *frame) {
if (dsp_frame->pts > ch->dtmf_ts)
dtmf_rx_fillin(ch->dtmf_dsp, dsp_frame->pts - ch->dtmf_ts);
else if (dsp_frame->pts < ch->dtmf_ts)
ilog(LOG_ERR | LOG_FLAG_LIMIT, "DTMF TS seems to run backwards (%lu < %lu)",
ilogs(transcoding, LOG_ERR | LOG_FLAG_LIMIT, "DTMF TS seems to run backwards (%lu < %lu)",
(unsigned long) dsp_frame->pts,
(unsigned long) ch->dtmf_ts);
@ -2703,7 +2702,7 @@ static void __dtmf_detect(struct codec_ssrc_handler *ch, AVFrame *frame) {
while (num_samples > 0) {
int ret = dtmf_rx(ch->dtmf_dsp, samples, num_samples);
if (ret < 0 || ret >= num_samples) {
ilog(LOG_ERR | LOG_FLAG_LIMIT, "DTMF DSP returned error %i", ret);
ilogs(transcoding, LOG_ERR | LOG_FLAG_LIMIT, "DTMF DSP returned error %i", ret);
break;
}
samples += num_samples - ret;
@ -2720,7 +2719,7 @@ static int packet_decoded_common(decoder_t *decoder, AVFrame *frame, void *u1, v
struct codec_ssrc_handler *ch = u1;
struct media_packet *mp = u2;
ilog(LOG_DEBUG, "RTP media successfully decoded: TS %llu, samples %u",
ilogs(transcoding, LOG_DEBUG, "RTP media successfully decoded: TS %llu, samples %u",
(unsigned long long) frame->pts, frame->nb_samples);
// switch from input codec context to output context if necessary
@ -2747,12 +2746,12 @@ static int packet_decoded_common(decoder_t *decoder, AVFrame *frame, void *u1, v
ch->skip_pts -= frame->nb_samples;
else
ch->skip_pts = 0;
ilog(LOG_DEBUG, "Discarding %i samples", frame->nb_samples);
ilogs(transcoding, LOG_DEBUG, "Discarding %i samples", frame->nb_samples);
goto discard;
}
if (G_UNLIKELY(!ch->encoder)) {
ilog(LOG_INFO | LOG_FLAG_LIMIT,
ilogs(transcoding, LOG_INFO | LOG_FLAG_LIMIT,
"Discarding decoded %i PCM samples due to lack of output encoder",
frame->nb_samples);
goto discard;
@ -2790,7 +2789,7 @@ static int packet_decode(struct codec_ssrc_handler *ch, struct transcode_packet
ch->last_ts = packet->ts;
if (ch->dtx_buffer && mp->sfd && mp->ssrc_in && mp->ssrc_out) {
ilog(LOG_DEBUG, "Adding packet to DTX buffer");
ilogs(transcoding, LOG_DEBUG, "Adding packet to DTX buffer");
struct dtx_buffer *dtxb = ch->dtx_buffer;
unsigned long ts = packet->ts;
@ -2816,7 +2815,7 @@ static int packet_decode(struct codec_ssrc_handler *ch, struct transcode_packet
ret = 1;
}
else {
ilog(LOG_DEBUG, "Decoding RTP packet now");
ilogs(transcoding, LOG_DEBUG, "Decoding RTP packet now");
ret = decoder_input_data(ch->decoder, packet->payload, packet->ts, ch->handler->packet_decoded,
ch, mp);
ret = ret ? -1 : 0;
@ -2855,7 +2854,7 @@ static int handler_func_transcode(struct codec_handler *h, struct media_packet *
// create new packet and insert it into sequencer queue
ilog(LOG_DEBUG, "Received RTP packet: SSRC %" PRIx32 ", PT %u, seq %u, TS %u, len %i",
ilogs(transcoding, LOG_DEBUG, "Received RTP packet: SSRC %" PRIx32 ", PT %u, seq %u, TS %u, len %i",
ntohl(mp->rtp->ssrc), mp->rtp->m_pt, ntohs(mp->rtp->seq_num),
ntohl(mp->rtp->timestamp), mp->payload.len);
@ -2949,7 +2948,7 @@ static struct rtp_payload_type *codec_add_payload_type(const str *codec, struct
{
struct rtp_payload_type *pt = codec_make_payload_type_sup(codec, media);
if (!pt) {
ilog(LOG_WARN, "Codec '" STR_FORMAT "' requested for transcoding is not supported",
ilogs(codec, LOG_WARN, "Codec '" STR_FORMAT "' requested for transcoding is not supported",
STR_FMT(codec));
return NULL;
}
@ -2958,7 +2957,7 @@ static struct rtp_payload_type *codec_add_payload_type(const str *codec, struct
pt->payload_type = __unused_pt_number(media, other_media, pt);
if (pt->payload_type < 0) {
ilog(LOG_WARN, "Ran out of RTP payload type numbers while adding codec '"
ilogs(codec, LOG_WARN, "Ran out of RTP payload type numbers while adding codec '"
STR_FORMAT "' for transcoding",
STR_FMT(&pt->encoding_with_params));
payload_type_free(pt);
@ -3112,7 +3111,7 @@ static int __revert_codec_strip(GHashTable *stripped, GHashTable *masked, const
GQueue *q = g_hash_table_lookup(stripped, codec);
if (q) {
ilog(LOG_DEBUG, "Restoring codec '" STR_FORMAT "' from stripped codecs (%u payload types)",
ilogs(codec, LOG_DEBUG, "Restoring codec '" STR_FORMAT "' from stripped codecs (%u payload types)",
STR_FMT(codec), q->length);
while (q->length) {
struct rtp_payload_type *pt = g_queue_pop_head(q);
@ -3124,7 +3123,7 @@ static int __revert_codec_strip(GHashTable *stripped, GHashTable *masked, const
q = g_hash_table_lookup(masked, codec);
if (q) {
ilog(LOG_DEBUG, "Restoring codec '" STR_FORMAT "' from masked codecs (%u payload types)",
ilogs(codec, LOG_DEBUG, "Restoring codec '" STR_FORMAT "' from masked codecs (%u payload types)",
STR_FMT(codec), q->length);
while (q->length) {
struct rtp_payload_type *pt = g_queue_pop_head(q);
@ -3242,7 +3241,7 @@ void codec_tracker_finish(struct call_media *media) {
if (!sct->all_touched && !g_hash_table_lookup(sct->touched, GUINT_TO_POINTER(clockrate)))
continue;
ilog(LOG_DEBUG, "Adding supplemental codec " STR_FORMAT " for clock rate %u", STR_FMT(supp_codec), clockrate);
ilogs(codec, LOG_DEBUG, "Adding supplemental codec " STR_FORMAT " for clock rate %u", STR_FMT(supp_codec), clockrate);
char *pt_s = g_strdup_printf(STR_FORMAT "/%u", STR_FMT(supp_codec), clockrate);
str pt_str;
@ -3272,7 +3271,7 @@ void codec_tracker_finish(struct call_media *media) {
GList *link = j->data;
struct rtp_payload_type *pt = link->data;
ilog(LOG_DEBUG, "Eliminating supplemental codec " STR_FORMAT " with stray clock rate %u",
ilogs(codec, LOG_DEBUG, "Eliminating supplemental codec " STR_FORMAT " with stray clock rate %u",
STR_FMT(&pt->encoding), clockrate);
__delete_receiver_codec(media, link);
@ -3376,7 +3375,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
// codec stripping
if (__codec_ht_except(strip_all, flags->codec_strip, flags->codec_except, pt)) {
ilog(LOG_DEBUG, "Stripping codec '" STR_FORMAT "'",
ilogs(codec, LOG_DEBUG, "Stripping codec '" STR_FORMAT "'",
STR_FMT(&pt->encoding_with_params));
#ifdef WITH_TRANSCODING
codec_touched(pt, media);
@ -3392,7 +3391,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
// codec masking
if (__codec_ht_except(mask_all, flags->codec_mask, flags->codec_except, pt)) {
ilog(LOG_DEBUG, "Masking codec '" STR_FORMAT "'",
ilogs(codec, LOG_DEBUG, "Masking codec '" STR_FORMAT "'",
STR_FMT(&pt->encoding_with_params));
#ifdef WITH_TRANSCODING
codec_touched(pt, media);
@ -3409,7 +3408,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
__rtp_payload_type_add_send(other_media, pt);
}
else if (__codec_ht_except(consume_all, flags->codec_consume, flags->codec_except, pt)) {
ilog(LOG_DEBUG, "Consuming codec '" STR_FORMAT "'",
ilogs(codec, LOG_DEBUG, "Consuming codec '" STR_FORMAT "'",
STR_FMT(&pt->encoding_with_params));
#ifdef WITH_TRANSCODING
codec_touched(pt, media);
@ -3422,7 +3421,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
__rtp_payload_type_add_send(other_media, pt);
}
else if (__codec_ht_except(accept_all, flags->codec_accept, NULL, pt)) {
ilog(LOG_DEBUG, "Accepting codec '" STR_FORMAT "'",
ilogs(codec, LOG_DEBUG, "Accepting codec '" STR_FORMAT "'",
STR_FMT(&pt->encoding_with_params));
#ifdef WITH_TRANSCODING
codec_touched(pt, media);
@ -3449,7 +3448,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
l = l->next;
continue;
}
ilog(LOG_DEBUG, "Eliminating asymmetric inbound codec " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Eliminating asymmetric inbound codec " STR_FORMAT,
STR_FMT(&pt->encoding_with_params));
l = __delete_receiver_codec(other_media, l);
}
@ -3472,7 +3471,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
continue;
// also check if maybe the codec was never stripped
if (g_hash_table_lookup(media->codec_names_recv, codec)) {
ilog(LOG_DEBUG, "Codec '" STR_FORMAT "' requested for transcoding is already present",
ilogs(codec, LOG_DEBUG, "Codec '" STR_FORMAT "' requested for transcoding is already present",
STR_FMT(codec));
continue;
}
@ -3484,7 +3483,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
pt->for_transcoding = 1;
codec_touched(pt, media);
ilog(LOG_DEBUG, "Codec '" STR_FORMAT "' added for transcoding with payload type %u",
ilogs(codec, LOG_DEBUG, "Codec '" STR_FORMAT "' added for transcoding with payload type %u",
STR_FMT(&pt->encoding_with_params), pt->payload_type);
__rtp_payload_type_add_recv(media, pt, 1);
}
@ -3517,7 +3516,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
assert(pt != NULL);
__rtp_payload_type_add_recv(media, pt, 1);
ilog(LOG_DEBUG, "Using default codecs PCMU and PCMA for T.38 gateway");
ilogs(codec, LOG_DEBUG, "Using default codecs PCMU and PCMA for T.38 gateway");
}
}
else if (flags->opmode == OP_OFFER) {
@ -3532,7 +3531,7 @@ void codec_rtp_payload_types(struct call_media *media, struct call_media *other_
l = l->next;
continue;
}
ilog(LOG_DEBUG, "Eliminating unsupported codec " STR_FORMAT,
ilogs(codec, LOG_DEBUG, "Eliminating unsupported codec " STR_FORMAT,
STR_FMT(&pt->encoding_with_params));
codec_touched(pt, media);
l = __delete_receiver_codec(media, l);


+ 10
- 10
daemon/control_ng.c View File

@ -121,7 +121,7 @@ struct control_ng_stats* get_control_ng_stats(const sockaddr_t *addr) {
if (!cur) {
cur = g_slice_alloc0(sizeof(struct control_ng_stats));
cur->proxy = *addr;
ilog(LOG_DEBUG,"Adding a proxy for control ng stats:%s", sockaddr_print_buf(addr));
ilogs(control, LOG_DEBUG,"Adding a proxy for control ng stats:%s", sockaddr_print_buf(addr));
for (int i = 0; i < NGC_COUNT; i++) {
struct ng_command_stats *c = &cur->cmd[i];
@ -149,7 +149,7 @@ int control_ng_process(str *buf, const endpoint_t *sin, char *addr,
str_chr_str(&data, buf, ' ');
if (!data.s || data.s == buf->s) {
ilog(LOG_WARNING, "Received invalid data on NG port (no cookie) from %s: " STR_FORMAT_M,
ilogs(control, LOG_WARNING, "Received invalid data on NG port (no cookie) from %s: " STR_FORMAT_M,
addr, STR_FMT_M(buf));
return funcret;
}
@ -171,7 +171,7 @@ int control_ng_process(str *buf, const endpoint_t *sin, char *addr,
to_send = cookie_cache_lookup(&ng_cookie_cache, &cookie);
if (to_send) {
ilog(LOG_INFO, "Detected command from %s as a duplicate", addr);
ilogs(control, LOG_INFO, "Detected command from %s as a duplicate", addr);
resp = NULL;
goto send_only;
}
@ -189,15 +189,15 @@ int control_ng_process(str *buf, const endpoint_t *sin, char *addr,
bencode_dictionary_get_str(dict, "call-id", &callid);
log_info_str(&callid);
ilog(LOG_INFO, "Received command '"STR_FORMAT"' from %s", STR_FMT(&cmd), addr);
ilogs(control, LOG_INFO, "Received command '"STR_FORMAT"' from %s", STR_FMT(&cmd), addr);
if (get_log_level() >= LOG_DEBUG) {
if (get_log_level(control) >= LOG_DEBUG) {
log_str = g_string_sized_new(256);
g_string_append_printf(log_str, "Dump for '"STR_FORMAT"' from %s: %s", STR_FMT(&cmd), addr,
rtpe_config.common.log_mark_prefix);
pretty_print(dict, log_str);
g_string_append(log_str, rtpe_config.common.log_mark_suffix);
ilog(LOG_DEBUG, "%.*s", (int) log_str->len, log_str->str);
ilogs(control, LOG_DEBUG, "%.*s", (int) log_str->len, log_str->str);
g_string_free(log_str, TRUE);
}
@ -325,7 +325,7 @@ int control_ng_process(str *buf, const endpoint_t *sin, char *addr,
err_send:
if (errstr < magic_load_limit_strings[0] || errstr > magic_load_limit_strings[__LOAD_LIMIT_MAX-1]) {
ilog(LOG_WARNING, "Protocol error in packet from %s: %s [" STR_FORMAT_M "]",
ilogs(control, LOG_WARNING, "Protocol error in packet from %s: %s [" STR_FORMAT_M "]",
addr, errstr, STR_FMT_M(&data));
bencode_dictionary_add_string(resp, "result", "error");
bencode_dictionary_add_string(resp, "error-reason", errstr);
@ -342,9 +342,9 @@ send_resp:
to_send = &reply;
if (cmd.s) {
ilog(LOG_INFO, "Replying to '"STR_FORMAT"' from %s (elapsed time %llu.%06llu sec)", STR_FMT(&cmd), addr, (unsigned long long)cmd_process_time.tv_sec, (unsigned long long)cmd_process_time.tv_usec);
ilogs(control, LOG_INFO, "Replying to '"STR_FORMAT"' from %s (elapsed time %llu.%06llu sec)", STR_FMT(&cmd), addr, (unsigned long long)cmd_process_time.tv_sec, (unsigned long long)cmd_process_time.tv_usec);
if (get_log_level() >= LOG_DEBUG) {
if (get_log_level(control) >= LOG_DEBUG) {
dict = bencode_decode_expect_str(&bencbuf, to_send, BENCODE_DICTIONARY);
if (dict) {
log_str = g_string_sized_new(256);
@ -353,7 +353,7 @@ send_resp:
rtpe_config.common.log_mark_prefix);
pretty_print(dict, log_str);
g_string_append(log_str, rtpe_config.common.log_mark_suffix);
ilog(LOG_DEBUG, "%.*s", (int) log_str->len, log_str->str);
ilogs(control, LOG_DEBUG, "%.*s", (int) log_str->len, log_str->str);
g_string_free(log_str, TRUE);
}
}


+ 8
- 8
daemon/control_tcp.c View File

@ -39,7 +39,7 @@ struct control_tcp {
//static void control_stream_closed(int fd, void *p, uintptr_t u) {
static void control_stream_closed(struct streambuf_stream *s) {
ilog(LOG_INFO, "Control connection from %s closed", s->addr);
ilogs(control, LOG_INFO, "Control connection from %s closed", s->addr);
}
@ -74,11 +74,11 @@ static int control_stream_parse(struct streambuf_stream *s, char *line) {
ret = pcre_exec(c->parse_re, c->parse_ree, line, strlen(line), 0, 0, ovec, G_N_ELEMENTS(ovec));
if (ret <= 0) {
ilog(LOG_WARNING, "Unable to parse command line from %s: %s", s->addr, line);
ilogs(control, LOG_WARNING, "Unable to parse command line from %s: %s", s->addr, line);
return -1;
}
ilog(LOG_INFO, "Got valid command from %s: %s", s->addr, line);
ilogs(control, LOG_INFO, "Got valid command from %s: %s", s->addr, line);
pcre_get_substring_list(line, ovec, ret, (const char ***) &out);
@ -127,7 +127,7 @@ static void control_stream_readable(struct streambuf_stream *s) {
int ret;
while ((line = streambuf_getline(s->inbuf))) {
ilog(LOG_DEBUG, "Got control line from %s: %s", s->addr, line);
ilogs(control, LOG_DEBUG, "Got control line from %s: %s", s->addr, line);
ret = control_stream_parse(s, line);
free(line);
if (ret == 1) {
@ -139,7 +139,7 @@ static void control_stream_readable(struct streambuf_stream *s) {
}
if (streambuf_bufsize(s->inbuf) > 1024) {
ilog(LOG_WARNING, "Buffer length exceeded in control connection from %s", s->addr);
ilogs(control, LOG_WARNING, "Buffer length exceeded in control connection from %s", s->addr);
goto close;
}
@ -150,7 +150,7 @@ close:
}
static void control_incoming(struct streambuf_stream *s) {
ilog(LOG_INFO, "New TCP control connection from %s", s->addr);
ilogs(control, LOG_INFO, "New TCP control connection from %s", s->addr);
}
@ -178,7 +178,7 @@ struct control_tcp *control_tcp_new(struct poller *p, endpoint_t *ep) {
control_stream_timer,
&c->obj))
{
ilog(LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
ilogs(control, LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
goto fail;
}
if (ipv46_any_convert(ep)) {
@ -188,7 +188,7 @@ struct control_tcp *control_tcp_new(struct poller *p, endpoint_t *ep) {
control_stream_timer,
&c->obj))
{
ilog(LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
ilogs(control, LOG_ERR, "Failed to open TCP control port: %s", strerror(errno));
goto fail;
}
}


+ 4
- 4
daemon/control_udp.c View File

@ -35,11 +35,11 @@ static void control_udp_incoming(struct obj *obj, str *buf, const endpoint_t *si
if (ret <= 0) {
ret = pcre_exec(u->fallback_re, NULL, buf->s, buf->len, 0, 0, ovec, G_N_ELEMENTS(ovec));
if (ret <= 0) {
ilog(LOG_WARNING, "Unable to parse command line from udp:%s: %.*s", addr, STR_FMT(buf));
ilogs(control, LOG_WARNING, "Unable to parse command line from udp:%s: %.*s", addr, STR_FMT(buf));
return;
}
ilog(LOG_WARNING, "Failed to properly parse UDP command line '%.*s' from %s, using fallback RE", STR_FMT(buf), addr);
ilogs(control, LOG_WARNING, "Failed to properly parse UDP command line '%.*s' from %s, using fallback RE", STR_FMT(buf), addr);
pcre_get_substring_list(buf->s, ovec, ret, (const char ***) &out);
@ -67,14 +67,14 @@ static void control_udp_incoming(struct obj *obj, str *buf, const endpoint_t *si
return;
}
ilog(LOG_INFO, "Got valid command from udp:%s: %.*s", addr, STR_FMT(buf));
ilogs(control, LOG_INFO, "Got valid command from udp:%s: %.*s", addr, STR_FMT(buf));
pcre_get_substring_list(buf->s, ovec, ret, (const char ***) &out);
str_init(&cookie, (void *) out[RE_UDP_COOKIE]);
reply = cookie_cache_lookup(&u->cookie_cache, &cookie);
if (reply) {
ilog(LOG_INFO, "Detected command from udp:%s as a duplicate", addr);
ilogs(control, LOG_INFO, "Detected command from udp:%s as a duplicate", addr);
socket_sendto(ul, reply->s, reply->len, sin);
free(reply);
goto out;


+ 23
- 24
daemon/crypto.c View File

@ -424,26 +424,25 @@ int crypto_gen_session_key(struct crypto_context *c, str *out, unsigned char lab
prf_n(out, c->params.master_key, c->params.crypto_suite->lib_cipher_ptr, x);
if (rtpe_config.debug_srtp)
ilog(LOG_DEBUG, "Generated session key: master key "
"%02x%02x%02x%02x..., "
"master salt "
"%02x%02x%02x%02x..., "
"label %02x, length %i, result "
"%02x%02x%02x%02x...",
c->params.master_key[0],
c->params.master_key[1],
c->params.master_key[2],
c->params.master_key[3],
c->params.master_salt[0],
c->params.master_salt[1],
c->params.master_salt[2],
c->params.master_salt[3],
label, out->len,
(unsigned char) out->s[0],
(unsigned char) out->s[1],
(unsigned char) out->s[2],
(unsigned char) out->s[3]);
ilogs(internals, LOG_DEBUG, "Generated session key: master key "
"%02x%02x%02x%02x..., "
"master salt "
"%02x%02x%02x%02x..., "
"label %02x, length %i, result "
"%02x%02x%02x%02x...",
c->params.master_key[0],
c->params.master_key[1],
c->params.master_key[2],
c->params.master_key[3],
c->params.master_salt[0],
c->params.master_salt[1],
c->params.master_salt[2],
c->params.master_salt[3],
label, out->len,
(unsigned char) out->s[0],
(unsigned char) out->s[1],
(unsigned char) out->s[2],
(unsigned char) out->s[3]);
return 0;
}
@ -708,7 +707,7 @@ static void dump_key(struct crypto_context *c, int log_level) {
k = g_base64_encode(c->params.master_key, c->params.crypto_suite->master_key_len);
s = g_base64_encode(c->params.master_salt, c->params.crypto_suite->master_salt_len);
ilog(log_level, "--- %s key %s%s%s salt %s%s%s", c->params.crypto_suite->name, FMT_M(k), FMT_M(s));
ilogs(srtp, log_level, "--- %s key %s%s%s salt %s%s%s", c->params.crypto_suite->name, FMT_M(k), FMT_M(s));
g_free(k);
g_free(s);
@ -720,12 +719,12 @@ void crypto_dump_keys(struct crypto_context *in, struct crypto_context *out) {
if (rtpe_config.log_keys)
log_level = LOG_ERROR;
if (get_log_level() < log_level)
if (get_log_level(core) < log_level)
return;
ilog(log_level, "SRTP keys, incoming:");
ilogs(srtp, log_level, "SRTP keys, incoming:");
dump_key(in, log_level);
ilog(log_level, "SRTP keys, outgoing:");
ilogs(srtp, log_level, "SRTP keys, outgoing:");
dump_key(out, log_level);
}


+ 21
- 21
daemon/dtls.c View File

@ -32,7 +32,7 @@
#if DTLS_DEBUG
#define __DBG(x...) ilog(LOG_DEBUG, x)
#else
#define __DBG(x...) ((void)0)
#define __DBG(x...) ilogs(internals, LOG_DEBUG, x)
#endif
@ -140,7 +140,7 @@ static void buf_dump_free(char *buf, size_t len) {
else
llen = len;
ilog(LOG_DEBUG, "--- %.*s", llen, p);
ilogs(srtp, LOG_DEBUG, "--- %.*s", llen, p);
if (!f)
break;
@ -156,7 +156,7 @@ static void dump_cert(struct dtls_cert *cert) {
char *buf;
size_t len;
if (get_log_level() < LOG_DEBUG)
if (get_log_level(core) < LOG_DEBUG)
return;
/* cert */
@ -164,7 +164,7 @@ static void dump_cert(struct dtls_cert *cert) {
PEM_write_X509(fp, cert->x509);
fclose(fp);
ilog(LOG_DEBUG, "Dump of DTLS certificate:");
ilogs(srtp, LOG_DEBUG, "Dump of DTLS certificate:");
buf_dump_free(buf, len);
/* key */
@ -172,7 +172,7 @@ static void dump_cert(struct dtls_cert *cert) {
PEM_write_PrivateKey(fp, cert->pkey, NULL, NULL, 0, 0, NULL);
fclose(fp);
ilog(LOG_DEBUG, "Dump of DTLS private key:");
ilogs(srtp, LOG_DEBUG, "Dump of DTLS private key:");
buf_dump_free(buf, len);
}
@ -185,7 +185,7 @@ static int cert_init(void) {
X509_NAME *name;
struct dtls_cert *new_cert;
ilog(LOG_INFO, "Generating new DTLS certificate");
ilogs(crypto, LOG_INFO, "Generating new DTLS certificate");
/* objects */
@ -292,7 +292,7 @@ static int cert_init(void) {
return 0;
err:
ilog(LOG_ERROR, "Failed to generate DTLS certificate");
ilogs(crypto, LOG_ERROR, "Failed to generate DTLS certificate");
if (pkey)
EVP_PKEY_free(pkey);
@ -452,7 +452,7 @@ int dtls_verify_cert(struct packet_stream *ps) {
dtls_hash(media->fingerprint.hash_func, ps->dtls_cert, fp);
if (memcmp(media->fingerprint.digest, fp, media->fingerprint.hash_func->num_bytes)) {
ilog(LOG_WARNING, "DTLS: Peer certificate rejected - fingerprint mismatch");
ilogs(crypto, LOG_WARNING, "DTLS: Peer certificate rejected - fingerprint mismatch");
__DBG("fingerprint expected: %02x%02x%02x%02x%02x%02x%02x%02x received: %02x%02x%02x%02x%02x%02x%02x%02x",
media->fingerprint.digest[0], media->fingerprint.digest[1],
media->fingerprint.digest[2], media->fingerprint.digest[3],
@ -464,7 +464,7 @@ int dtls_verify_cert(struct packet_stream *ps) {
}
PS_SET(ps, FINGERPRINT_VERIFIED);
ilog(LOG_INFO, "DTLS: Peer certificate accepted");
ilogs(crypto, LOG_INFO, "DTLS: Peer certificate accepted");
return 0;
}
@ -487,7 +487,7 @@ static int try_connect(struct dtls_connection *d) {
ret = 0;
switch (code) {
case SSL_ERROR_NONE:
ilog(LOG_DEBUG, "DTLS handshake successful");
ilogs(crypto, LOG_DEBUG, "DTLS handshake successful");
d->connected = 1;
ret = 1;
break;
@ -498,7 +498,7 @@ static int try_connect(struct dtls_connection *d) {
default:
ret = ERR_peek_last_error();
ilog(LOG_ERROR, "DTLS error: %i (%s)", code, ERR_reason_error_string(ret));
ilogs(crypto, LOG_ERROR, "DTLS error: %i (%s)", code, ERR_reason_error_string(ret));
ret = -1;
break;
}
@ -519,7 +519,7 @@ int dtls_connection_init(struct dtls_connection *d, struct packet_stream *ps, in
d->ptr = ps;
ilog(LOG_DEBUG, "Creating %s DTLS connection context", active ? "active" : "passive");
ilogs(crypto, LOG_DEBUG, "Creating %s DTLS connection context", active ? "active" : "passive");
#if OPENSSL_VERSION_NUMBER >= 0x10002000L
d->ssl_ctx = SSL_CTX_new(active ? DTLS_client_method() : DTLS_server_method());
@ -591,7 +591,7 @@ error:
if (d->ssl_ctx)
SSL_CTX_free(d->ssl_ctx);
ZERO(*d);
ilog(LOG_ERROR, "Failed to init DTLS connection: %s", ERR_reason_error_string(err));
ilogs(crypto, LOG_ERROR, "Failed to init DTLS connection: %s", ERR_reason_error_string(err));
return -1;
}
@ -641,7 +641,7 @@ found:
i += cs->master_salt_len;
memcpy(server.master_salt, &keys[i], cs->master_salt_len);
ilog(LOG_INFO, "DTLS-SRTP successfully negotiated");
ilogs(crypto, LOG_INFO, "DTLS-SRTP successfully negotiated");
if (d->active) {
/* we're the client */
@ -671,9 +671,9 @@ found:
error:
if (!spp)
ilog(LOG_ERROR, "Failed to set up SRTP after DTLS negotiation: %s", err);
ilogs(crypto, LOG_ERROR, "Failed to set up SRTP after DTLS negotiation: %s", err);
else
ilog(LOG_ERROR, "Failed to set up SRTP after DTLS negotiation: %s (profile \"%s\")",
ilogs(crypto, LOG_ERROR, "Failed to set up SRTP after DTLS negotiation: %s (profile \"%s\")",
err, spp->name);
return -1;
}
@ -704,7 +704,7 @@ int dtls(struct stream_fd *sfd, const str *s, const endpoint_t *fsin) {
return -1;
if (s) {
ilog(LOG_DEBUG, "Processing incoming DTLS packet");
ilogs(srtp, LOG_DEBUG, "Processing incoming DTLS packet");
BIO_write(d->r_bio, s->s, s->len);
/* we understand this as preference of DTLS over SDES */
MEDIA_CLEAR(ps->media, SDES);
@ -712,7 +712,7 @@ int dtls(struct stream_fd *sfd, const str *s, const endpoint_t *fsin) {
ret = try_connect(d);
if (ret == -1) {
ilog(LOG_ERROR, "DTLS error on local port %u", sfd->socket.local.port);
ilogs(srtp, LOG_ERROR, "DTLS error on local port %u", sfd->socket.local.port);
/* fatal error */
dtls_connection_cleanup(d);
return 0;
@ -744,7 +744,7 @@ int dtls(struct stream_fd *sfd, const str *s, const endpoint_t *fsin) {
break;
if (ret > sizeof(buf)) {
ilog(LOG_ERROR, "BIO buffer overflow");
ilogs(srtp, LOG_ERROR, "BIO buffer overflow");
(void) BIO_reset(d->w_bio);
break;
}
@ -763,7 +763,7 @@ int dtls(struct stream_fd *sfd, const str *s, const endpoint_t *fsin) {
if (!fsin)
fsin = &ps->endpoint;
ilog(LOG_DEBUG, "Sending DTLS packet");
ilogs(srtp, LOG_DEBUG, "Sending DTLS packet");
socket_sendto(&sfd->socket, buf, ret, fsin);
}
@ -813,7 +813,7 @@ void dtls_shutdown(struct packet_stream *ps) {
void dtls_connection_cleanup(struct dtls_connection *c) {
if (c->ssl_ctx || c->ssl)
ilog(LOG_DEBUG, "Resetting DTLS connection context");
ilogs(crypto, LOG_DEBUG, "Resetting DTLS connection context");
if (c->ssl_ctx)
SSL_CTX_free(c->ssl_ctx);


+ 37
- 37
daemon/ice.c View File

@ -21,9 +21,9 @@
#endif
#if ICE_DEBUG
#define __DBG(x...) ilog(LOG_DEBUG, x)
#define __DBG(x...) ilogs(ice, LOG_DEBUG, x)
#else
#define __DBG(x...) ((void)0)
#define __DBG(x...) ilogs(internals, LOG_DEBUG, x)
#endif
@ -135,7 +135,7 @@ static void __all_pairs_list(struct ice_agent *ag) {
static void __tree_coll_callback(void *oo, void *nn) {
struct ice_candidate_pair *o = oo, *n = nn;
ilog(LOG_WARN | LOG_FLAG_LIMIT, "Priority collision between candidate pairs " PAIR_FORMAT " and "
ilogs(ice, LOG_WARN | LOG_FLAG_LIMIT, "Priority collision between candidate pairs " PAIR_FORMAT " and "
PAIR_FORMAT " - ICE will likely fail",
PAIR_FMT(o), PAIR_FMT(n));
}
@ -164,7 +164,7 @@ static struct ice_candidate_pair *__pair_candidate(struct stream_fd *sfd, struct
g_hash_table_insert(ag->pair_hash, pair, pair);
g_tree_insert_coll(ag->all_pairs, pair, pair, __tree_coll_callback);
ilog(LOG_DEBUG, "Created candidate pair "PAIR_FORMAT" between %s and %s%s%s, type %s", PAIR_FMT(pair),
ilogs(ice, LOG_DEBUG, "Created candidate pair "PAIR_FORMAT" between %s and %s%s%s, type %s", PAIR_FMT(pair),
sockaddr_print_buf(&sfd->socket.local.address),
FMT_M(endpoint_print_buf(&cand->endpoint)),
ice_candidate_type_str(cand->type));
@ -295,7 +295,7 @@ static void __ice_reset(struct ice_agent *ag) {
/* if the other side did a restart */
static void __ice_restart(struct ice_agent *ag) {
ilog(LOG_DEBUG, "ICE restart, resetting ICE agent");
ilogs(ice, LOG_DEBUG, "ICE restart, resetting ICE agent");
ag->ufrag[0] = STR_NULL;
ag->pwd[0] = STR_NULL;
@ -361,7 +361,7 @@ void ice_update(struct ice_agent *ag, struct stream_params *sp) {
comps = 0;
for (l = candidates->head; l; l = l->next) {
if (ag->remote_candidates.length >= MAX_ICE_CANDIDATES) {
ilog(LOG_WARNING, "Maxmimum number of ICE candidates exceeded");
ilogs(ice, LOG_WARNING, "Maxmimum number of ICE candidates exceeded");
break;
}
@ -384,7 +384,7 @@ void ice_update(struct ice_agent *ag, struct stream_params *sp) {
/* if this is peer reflexive, we've learned it through STUN.
* otherwise it's simply one we've seen before. */
if (dup->type == ICT_PRFLX) {
ilog(LOG_DEBUG, "Replacing previously learned prflx ICE candidate with "
ilogs(ice, LOG_DEBUG, "Replacing previously learned prflx ICE candidate with "
STR_FORMAT_M ":%lu", STR_FMT_M(&cand->foundation),
cand->component_id);
}
@ -392,7 +392,7 @@ void ice_update(struct ice_agent *ag, struct stream_params *sp) {
/* if the new one has higher priority then the old one, then we
* update it, otherwise we just drop it */
if (cand->priority <= dup->priority) {
ilog(LOG_DEBUG, "Dropping new ICE candidate " STR_FORMAT_M
ilogs(ice, LOG_DEBUG, "Dropping new ICE candidate " STR_FORMAT_M
" in favour of "
STR_FORMAT_M ":%lu",
STR_FMT_M(&cand->foundation),
@ -400,7 +400,7 @@ void ice_update(struct ice_agent *ag, struct stream_params *sp) {
continue;
}
ilog(LOG_DEBUG, "Replacing known ICE candidate " STR_FORMAT_M " with higher "
ilogs(ice, LOG_DEBUG, "Replacing known ICE candidate " STR_FORMAT_M " with higher "
"priority "
STR_FORMAT_M ":%lu",
STR_FMT_M(&dup->foundation),
@ -412,7 +412,7 @@ void ice_update(struct ice_agent *ag, struct stream_params *sp) {
recalc += __copy_cand(call, dup, cand);
}
else {
ilog(LOG_DEBUG, "Learning new ICE candidate " STR_FORMAT_M ":%lu",
ilogs(ice, LOG_DEBUG, "Learning new ICE candidate " STR_FORMAT_M ":%lu",
STR_FMT_M(&cand->foundation), cand->component_id);
dup = g_slice_alloc(sizeof(*dup));
__copy_cand(call, dup, cand);
@ -477,7 +477,7 @@ void ice_shutdown(struct ice_agent **agp) {
struct ice_agent *ag;
if (!agp) {
ilog(LOG_ERR, "ice agp is NULL");
ilogs(ice, LOG_ERR, "ice agp is NULL");
return ;
}
@ -492,7 +492,7 @@ void ice_shutdown(struct ice_agent **agp) {
}
static void __ice_agent_free_components(struct ice_agent *ag) {
if (!ag) {
ilog(LOG_ERR, "ice ag is NULL");
ilogs(ice, LOG_ERR, "ice ag is NULL");
return;
}
@ -513,7 +513,7 @@ static void __ice_agent_free(void *p) {
struct ice_agent *ag = p;
if (!ag) {
ilog(LOG_ERR, "ice ag is NULL");
ilogs(ice, LOG_ERR, "ice ag is NULL");
return;
}
@ -569,7 +569,7 @@ void ice_free(void) {
static void __fail_pair(struct ice_candidate_pair *pair) {
ilog(LOG_DEBUG, "Setting ICE candidate pair "PAIR_FORMAT" as failed", PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "Setting ICE candidate pair "PAIR_FORMAT" as failed", PAIR_FMT(pair));
PAIR_SET(pair, FAILED);
PAIR_CLEAR(pair, IN_PROGRESS);
}
@ -618,7 +618,7 @@ static void __do_ice_check(struct ice_candidate_pair *pair) {
mutex_unlock(&ag->lock);
ilog(LOG_DEBUG, "Sending %sICE/STUN request for candidate pair "PAIR_FORMAT" from %s to %s%s%s",
ilogs(ice, LOG_DEBUG, "Sending %sICE/STUN request for candidate pair "PAIR_FORMAT" from %s to %s%s%s",
PAIR_ISSET(pair, TO_USE) ? "nominating " : "",
PAIR_FMT(pair), sockaddr_print_buf(&pair->local_intf->spec->local_address.addr),
FMT_M(endpoint_print_buf(&pair->remote_candidate->endpoint)));
@ -656,7 +656,7 @@ static void __nominate_pairs(struct ice_agent *ag) {
GList *l;
struct ice_candidate_pair *pair;
ilog(LOG_DEBUG, "Start nominating ICE pairs");
ilogs(ice, LOG_DEBUG, "Start nominating ICE pairs");
AGENT_SET(ag, NOMINATING);
ZERO(ag->start_nominating);
@ -665,7 +665,7 @@ static void __nominate_pairs(struct ice_agent *ag) {
for (l = complete.head; l; l = l->next) {
pair = l->data;
ilog(LOG_DEBUG, "Nominating ICE pair "PAIR_FORMAT, PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "Nominating ICE pair "PAIR_FORMAT, PAIR_FMT(pair));
PAIR_CLEAR(pair, IN_PROGRESS);
PAIR_SET2(pair, NOMINATED, TO_USE);
pair->retransmits = 0;
@ -686,7 +686,7 @@ static void __do_ice_checks(struct ice_agent *ag) {
int have_more = 0;
if (!ag) {
ilog(LOG_ERR, "ice ag is NULL");
ilogs(ice, LOG_ERR, "ice ag is NULL");
return;
}
@ -797,7 +797,7 @@ check:
}
static void __agent_shutdown(struct ice_agent *ag) {
ilog(LOG_DEBUG, "Shutting down ICE agent (nothing to do)");
ilogs(ice, LOG_DEBUG, "Shutting down ICE agent (nothing to do)");
__agent_deschedule(ag);
}
@ -886,7 +886,7 @@ out:
static void __trigger_check(struct ice_candidate_pair *pair) {
struct ice_agent *ag = pair->agent;
ilog(LOG_DEBUG, "Triggering check for "PAIR_FORMAT, PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "Triggering check for "PAIR_FORMAT, PAIR_FMT(pair));
mutex_lock(&ag->lock);
pair->retransmits = 0;
@ -906,7 +906,7 @@ static void __recalc_pair_prios(struct ice_agent *ag) {
GList *l;
GQueue nominated, valid, succ, all;
ilog(LOG_DEBUG, "Recalculating all ICE pair priorities");
ilogs(ice, LOG_DEBUG, "Recalculating all ICE pair priorities");
g_tree_remove_all(&nominated, ag->nominated_pairs);
g_tree_remove_all(&succ, ag->succeeded_pairs);
@ -936,7 +936,7 @@ static void __role_change(struct ice_agent *ag, int new_controlling) {
else
return;
ilog(LOG_DEBUG, "ICE role change, now %s", new_controlling ? "controlling" : "controlled");
ilogs(ice, LOG_DEBUG, "ICE role change, now %s", new_controlling ? "controlling" : "controlled");
/* recalc priorities and resort list */
@ -999,7 +999,7 @@ static int __check_valid(struct ice_agent *ag) {
int is_complete = 1;
if (!ag) {
ilog(LOG_ERR, "ice ag is NULL");
ilogs(ice, LOG_ERR, "ice ag is NULL");
return 0;
}
@ -1011,18 +1011,18 @@ static int __check_valid(struct ice_agent *ag) {
is_complete = 0;
__get_complete_succeeded_pairs(&all_compos, ag);
if (!all_compos.length) {
ilog(LOG_DEBUG, "ICE not completed yet and no usable candidates");
ilogs(ice, LOG_DEBUG, "ICE not completed yet and no usable candidates");
return 0;
}
}
pair = all_compos.head->data;
if (is_complete) {
ilog(LOG_DEBUG, "ICE completed, using pair " PAIR_FORMAT, PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "ICE completed, using pair " PAIR_FORMAT, PAIR_FMT(pair));
AGENT_SET(ag, COMPLETED);
}
else {
ilog(LOG_DEBUG, "ICE not completed yet, but can use pair " PAIR_FORMAT, PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "ICE not completed yet, but can use pair " PAIR_FORMAT, PAIR_FMT(pair));
AGENT_SET(ag, USABLE);
}
@ -1032,7 +1032,7 @@ static int __check_valid(struct ice_agent *ag) {
mutex_lock(&ps->out_lock);
if (memcmp(&ps->endpoint, &pair->remote_candidate->endpoint, sizeof(ps->endpoint))) {
ilog(LOG_INFO, "ICE negotiated: peer for component %u is %s%s%s", ps->component,
ilogs(ice, LOG_INFO, "ICE negotiated: peer for component %u is %s%s%s", ps->component,
FMT_M(endpoint_print_buf(&pair->remote_candidate->endpoint)));
ps->endpoint = pair->remote_candidate->endpoint;
}
@ -1044,7 +1044,7 @@ static int __check_valid(struct ice_agent *ag) {
continue;
ps->selected_sfd = sfd;
if (ps->component == 1)
ilog(LOG_INFO, "ICE negotiated: local interface %s",
ilogs(ice, LOG_INFO, "ICE negotiated: local interface %s",
sockaddr_print_buf(&pair->local_intf->spec->local_address.addr));
break;
}
@ -1127,7 +1127,7 @@ int ice_request(struct stream_fd *sfd, const endpoint_t *src,
ret = 0;
if (attrs->use && !PAIR_SET(pair, NOMINATED)) {
ilog(LOG_DEBUG, "ICE pair "PAIR_FORMAT" has been nominated by peer", PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "ICE pair "PAIR_FORMAT" has been nominated by peer", PAIR_FMT(pair));
mutex_lock(&ag->lock);
@ -1149,7 +1149,7 @@ int ice_request(struct stream_fd *sfd, const endpoint_t *src,
err_unlock:
mutex_unlock(&ag->lock);
ilog(LOG_NOTICE | LOG_FLAG_LIMIT, "%s (from %s%s%s on interface %s)", err, FMT_M(endpoint_print_buf(src)),
ilogs(ice, LOG_NOTICE | LOG_FLAG_LIMIT, "%s (from %s%s%s on interface %s)", err, FMT_M(endpoint_print_buf(src)),
endpoint_print_buf(&sfd->socket.local));
return 0;
}
@ -1162,11 +1162,11 @@ static int __check_succeeded_complete(struct ice_agent *ag) {
__get_complete_succeeded_pairs(&complete, ag);
if (complete.length) {
struct ice_candidate_pair *pair = complete.head->data;
ilog(LOG_DEBUG, "Best succeeded ICE pair with all components is "PAIR_FORMAT, PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "Best succeeded ICE pair with all components is "PAIR_FORMAT, PAIR_FMT(pair));
ret = 1;
}
else {
ilog(LOG_DEBUG, "No succeeded ICE pairs with all components yet");
ilogs(ice, LOG_DEBUG, "No succeeded ICE pairs with all components yet");
ret = 0;
}
g_queue_clear(&complete);
@ -1208,7 +1208,7 @@ int ice_response(struct stream_fd *sfd, const endpoint_t *src,
ifa = pair->local_intf;
ilog(LOG_DEBUG, "Received ICE/STUN response code %u for candidate pair "PAIR_FORMAT" from %s%s%s to %s",
ilogs(ice, LOG_DEBUG, "Received ICE/STUN response code %u for candidate pair "PAIR_FORMAT" from %s%s%s to %s",
attrs->error_code, PAIR_FMT(pair),
FMT_M(endpoint_print_buf(&pair->remote_candidate->endpoint)),
sockaddr_print_buf(&ifa->spec->local_address.addr));
@ -1242,7 +1242,7 @@ int ice_response(struct stream_fd *sfd, const endpoint_t *src,
/* check if we're in the final (controlling) phase */
if (pair->was_nominated && PAIR_CLEAR(pair, TO_USE)) {
ilog(LOG_DEBUG, "Setting nominated ICE candidate pair "PAIR_FORMAT" as valid", PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "Setting nominated ICE candidate pair "PAIR_FORMAT" as valid", PAIR_FMT(pair));
PAIR_SET(pair, VALID);
g_tree_insert_coll(ag->valid_pairs, pair, pair, __tree_coll_callback);
ret = __check_valid(ag);
@ -1252,7 +1252,7 @@ int ice_response(struct stream_fd *sfd, const endpoint_t *src,
if (PAIR_SET(pair, SUCCEEDED))
goto out_unlock;
ilog(LOG_DEBUG, "Setting ICE candidate pair "PAIR_FORMAT" as succeeded", PAIR_FMT(pair));
ilogs(ice, LOG_DEBUG, "Setting ICE candidate pair "PAIR_FORMAT" as succeeded", PAIR_FMT(pair));
g_tree_insert_coll(ag->succeeded_pairs, pair, pair, __tree_coll_callback);
if (!ag->start_nominating.tv_sec) {
@ -1279,7 +1279,7 @@ int ice_response(struct stream_fd *sfd, const endpoint_t *src,
if (!PAIR_CLEAR(opair, FROZEN))
continue;
ilog(LOG_DEBUG, "Unfreezing related ICE pair "PAIR_FORMAT, PAIR_FMT(opair));
ilogs(ice, LOG_DEBUG, "Unfreezing related ICE pair "PAIR_FORMAT, PAIR_FMT(opair));
}
/* if this was previously nominated by the peer, it's now valid */
@ -1299,7 +1299,7 @@ err_unlock:
mutex_unlock(&ag->lock);
err:
if (err)
ilog(LOG_NOTICE | LOG_FLAG_LIMIT, "%s (from %s%s%s on interface %s)",
ilogs(ice, LOG_NOTICE | LOG_FLAG_LIMIT, "%s (from %s%s%s on interface %s)",
err, FMT_M(endpoint_print_buf(src)), endpoint_print_buf(&sfd->socket.local));
if (pair && attrs->error_code)


+ 1
- 1
daemon/log.h View File

@ -52,7 +52,7 @@ void __ilog(int prio, const char *fmt, ...) __attribute__ ((format (printf, 2, 3
#ifdef __DEBUG
#define __C_DBG(x...) ilog(LOG_DEBUG, x)
#else
#define __C_DBG(x...) ((void)0)
#define __C_DBG(x...) ilogs(internals, LOG_DEBUG, x)
#endif


+ 12
- 0
daemon/loglevels.h View File

@ -0,0 +1,12 @@
ll(core)
ll(spandsp)
ll(ffmpeg)
ll(transcoding)
ll(codec)
ll(rtcp)
ll(ice)
ll(crypto)
ll(srtp)
ll(internals)
ll(http)
ll(control)

+ 21
- 10
daemon/main.c View File

@ -80,6 +80,11 @@ struct rtpengine_config rtpe_config = {
.dtls_rsa_key_size = 2048,
.dtls_signature = 256,
.max_dtx = 30,
.common = {
.log_levels = {
[log_level_index_internals] = -1,
},
},
};
static void sighandler(gpointer x) {
@ -107,17 +112,19 @@ static void sighandler(gpointer x) {
if (ret == SIGINT || ret == SIGTERM)
rtpe_shutdown = 1;
else if (ret == SIGUSR1) {
if (get_log_level() > 0) {
g_atomic_int_add(&rtpe_config.common.log_level, -1);
ilog(get_log_level(), "Set log level to %d\n",
get_log_level());
for (unsigned int i = 0; i < num_log_levels; i++) {
g_atomic_int_add(&rtpe_config.common.log_levels[i], -1);
ilogsn(i, __get_log_level(i), "Decreased '%s' log level to %d\n",
log_level_names[i],
__get_log_level(i));
}
}
else if (ret == SIGUSR2) {
if (get_log_level() < 7) {
g_atomic_int_add(&rtpe_config.common.log_level, 1);
ilog(get_log_level(), "Set log level to %d\n",
get_log_level());
for (unsigned int i = 0; i < num_log_levels; i++) {
g_atomic_int_add(&rtpe_config.common.log_levels[i], 1);
ilogsn(i, __get_log_level(i), "Increased '%s' log level to %d\n",
log_level_names[i],
__get_log_level(i));
}
}
else
@ -382,6 +389,7 @@ static void options(int *argc, char ***argv) {
AUTO_CLEANUP_GBUF(dtls_sig);
double silence_detect = 0;
AUTO_CLEANUP_GVBUF(cn_payload);
int debug_srtp;
GOptionEntry e[] = {
{ "table", 't', 0, G_OPTION_ARG_INT, &rtpe_config.kernel_table, "Kernel table to use", "INT" },
@ -455,7 +463,7 @@ static void options(int *argc, char ***argv) {
{ "endpoint-learning",0,0,G_OPTION_ARG_STRING, &endpoint_learning, "RTP endpoint learning algorithm", "delayed|immediate|off|heuristic" },
{ "jitter-buffer",0, 0, G_OPTION_ARG_INT, &rtpe_config.jb_length, "Size of jitter buffer", "INT" },
{ "jb-clock-drift",0,0, G_OPTION_ARG_NONE, &rtpe_config.jb_clock_drift,"Compensate for source clock drift",NULL },
{ "debug-srtp",0,0, G_OPTION_ARG_NONE, &rtpe_config.debug_srtp,"Log raw encryption details for SRTP", NULL },
{ "debug-srtp",0,0, G_OPTION_ARG_NONE, &debug_srtp, "Log raw encryption details for SRTP", NULL },
{ "dtls-rsa-key-size",0, 0, G_OPTION_ARG_INT,&rtpe_config.dtls_rsa_key_size,"Size of RSA key for DTLS", "INT" },
{ "dtls-ciphers",0, 0, G_OPTION_ARG_STRING, &rtpe_config.dtls_ciphers,"List of ciphers for DTLS", "STRING" },
{ "dtls-signature",0, 0,G_OPTION_ARG_STRING, &dtls_sig, "Signature algorithm for DTLS", "SHA-256|SHA-1" },
@ -628,6 +636,9 @@ static void options(int *argc, char ***argv) {
die("Invalid --log-format option");
}
if (debug_srtp)
rtpe_config.common.log_levels[log_level_index_srtp] = LOG_DEBUG;
if (dtmf_udp_ep) {
if (endpoint_parse_any_getaddrinfo_full(&rtpe_config.dtmf_udp_ep, dtmf_udp_ep))
die("Invalid IP or port '%s' (--dtmf-log-dest)", dtmf_udp_ep);
@ -768,7 +779,7 @@ void fill_initial_rtpe_cfg(struct rtpengine_config* ini_rtpe_cfg) {
ini_rtpe_cfg->redis_connect_timeout = rtpe_config.redis_connect_timeout;
ini_rtpe_cfg->redis_delete_async = rtpe_config.redis_delete_async;
ini_rtpe_cfg->redis_delete_async_interval = rtpe_config.redis_delete_async_interval;
ini_rtpe_cfg->common.log_level = rtpe_config.common.log_level;
memcpy(&ini_rtpe_cfg->common.log_levels, &rtpe_config.common.log_levels, sizeof(ini_rtpe_cfg->common.log_levels));
ini_rtpe_cfg->graphite_ep = rtpe_config.graphite_ep;
ini_rtpe_cfg->tcp_listen_ep = rtpe_config.tcp_listen_ep;


+ 4
- 2
daemon/redis.c View File

@ -1907,7 +1907,8 @@ int redis_restore(struct redis *r) {
if (!r)
return 0;
rtpe_config.common.log_level |= LOG_FLAG_RESTORE;
for (unsigned int i = 0; i < num_log_levels; i++)
rtpe_config.common.log_levels[i] |= LOG_FLAG_RESTORE;
rlog(LOG_DEBUG, "Restoring calls from Redis...");
@ -1954,7 +1955,8 @@ int redis_restore(struct redis *r) {
freeReplyObject(calls);
err:
rtpe_config.common.log_level &= ~LOG_FLAG_RESTORE;
for (unsigned int i = 0; i < num_log_levels; i++)
rtpe_config.common.log_levels[i] &= ~LOG_FLAG_RESTORE;
return ret;
}


+ 13
- 13
daemon/rtcp.c View File

@ -632,7 +632,7 @@ static int rtcp_xr(struct rtcp_chain_element *el, struct rtcp_process_ctx *log_c
if (!hf)
goto next;
if (rb->bt < G_N_ELEMENTS(min_xr_packet_sizes) && len < min_xr_packet_sizes[rb->bt]) {
ilog(LOG_WARN, "Short RTCP XR block (type %u, %u < %i)", rb->bt, len,
ilogs(rtcp, LOG_WARN, "Short RTCP XR block (type %u, %u < %i)", rb->bt, len,
min_xr_packet_sizes[rb->bt]);
goto next;
}
@ -682,7 +682,7 @@ int rtcp_parse(GQueue *q, struct media_packet *mp) {
break;
if (hdr->version != 2) {
ilog(LOG_DEBUG, "Unknown RTCP version %u", hdr->version);
ilogs(rtcp, LOG_DEBUG, "Unknown RTCP version %u", hdr->version);
goto error;
}
@ -690,7 +690,7 @@ int rtcp_parse(GQueue *q, struct media_packet *mp) {
if (hdr->pt < G_N_ELEMENTS(min_packet_sizes))
min_packet_size = min_packet_sizes[hdr->pt];
if (len < min_packet_size) {
ilog(LOG_WARN, "Invalid RTCP packet type %u (short: %u < %i)",
ilogs(rtcp, LOG_WARN, "Invalid RTCP packet type %u (short: %u < %i)",
hdr->pt, len, min_packet_size);
goto error;
}
@ -698,19 +698,19 @@ int rtcp_parse(GQueue *q, struct media_packet *mp) {
el = rtcp_new_element(hdr, len);
if (hdr->pt >= G_N_ELEMENTS(handler_funcs)) {
ilog(LOG_INFO, "Ignoring unknown RTCP packet type %u", hdr->pt);
ilogs(rtcp, LOG_INFO, "Ignoring unknown RTCP packet type %u", hdr->pt);
goto next;
}
func = handler_funcs[hdr->pt];
if (!func) {
ilog(LOG_INFO, "Ignoring unknown RTCP packet type %u", hdr->pt);
ilogs(rtcp, LOG_INFO, "Ignoring unknown RTCP packet type %u", hdr->pt);
goto next;
}
ilog(LOG_DEBUG, "Calling handler for RTCP packet type %u", hdr->pt);
ilogs(rtcp, LOG_DEBUG, "Calling handler for RTCP packet type %u", hdr->pt);
ret = func(el, log_ctx);
if (ret) {
ilog(LOG_WARN, "Failed to handle or parse RTCP packet type %u", hdr->pt);
ilogs(rtcp, LOG_WARN, "Failed to handle or parse RTCP packet type %u", hdr->pt);
rtcp_ce_free(el);
goto error;
}
@ -794,7 +794,7 @@ INLINE int check_session_keys(struct crypto_context *c) {
return 0;
error:
ilog(LOG_ERROR | LOG_FLAG_LIMIT, "%s", err);
ilogs(rtcp, LOG_ERROR | LOG_FLAG_LIMIT, "%s", err);
return -1;
}
@ -839,7 +839,7 @@ done:
*out = rtcp;
return 0;
error:
ilog(LOG_DEBUG | LOG_FLAG_LIMIT, "Error parsing RTCP header: %s", err);
ilogs(rtcp, LOG_DEBUG | LOG_FLAG_LIMIT, "Error parsing RTCP header: %s", err);
return -1;
}
@ -951,7 +951,7 @@ int rtcp_savp2avp(str *s, struct crypto_context *c, struct ssrc_ctx *ssrc_ctx) {
return 0;
error:
ilog(LOG_WARNING | LOG_FLAG_LIMIT, "Discarded invalid SRTCP packet: %s", err);
ilogs(rtcp, LOG_WARNING | LOG_FLAG_LIMIT, "Discarded invalid SRTCP packet: %s", err);
return -1;
}
@ -1284,7 +1284,7 @@ static void transcode_common(struct rtcp_process_ctx *ctx, struct rtcp_packet *c
return;
// forward SSRC mapping
common->ssrc = htonl(ctx->mp->ssrc_in->ssrc_map_out);
ilog(LOG_DEBUG, "Substituting RTCP header SSRC from %s%x%s to %x",
ilogs(rtcp, LOG_DEBUG, "Substituting RTCP header SSRC from %s%x%s to %x",
FMT_M(ctx->scratch_common_ssrc), ctx->mp->ssrc_in->ssrc_map_out);
}
static void transcode_rr(struct rtcp_process_ctx *ctx, struct report_block *rr) {
@ -1315,7 +1315,7 @@ static void transcode_rr(struct rtcp_process_ctx *ctx, struct report_block *rr)
unsigned int dupes = atomic64_get(&input_ctx->duplicates);
unsigned int tot_lost = lost - dupes; // can be negative/rollover
ilog(LOG_DEBUG, "Substituting RTCP RR SSRC from %s%x%s to %x: %u packets, %u lost, %u duplicates",
ilogs(rtcp, LOG_DEBUG, "Substituting RTCP RR SSRC from %s%x%s to %x: %u packets, %u lost, %u duplicates",
FMT_M(ctx->scratch.rr.ssrc), map_ctx->ssrc_map_out,
packets, lost, dupes);
@ -1563,7 +1563,7 @@ void rtcp_send_report(struct call_media *media, struct ssrc_ctx *ssrc_out) {
GQueue rrs = G_QUEUE_INIT;
rtcp_receiver_reports(&rrs, call->ssrc_hash, ps->media->monologue);
ilog(LOG_DEBUG, "Generating and sending RTCP SR for %x and up to %i source(s)",
ilogs(rtcp, LOG_DEBUG, "Generating and sending RTCP SR for %x and up to %i source(s)",
ssrc_out->parent->h.ssrc, rrs.length);
struct ssrc_sender_report ssr;


+ 22
- 2
daemon/rtpengine.pod View File

@ -192,8 +192,11 @@ Default to 30000 and 40000 respectively.
=item B<-L>, B<--log-level=>I<INT>
Takes an integer as argument and controls the highest log level which
will be sent to syslog.
Takes an integer as argument and controls the highest log level which will be
sent to syslog. This is merely the default log level used for logging
subsystems (see below) that don't explicitly have a separate log level
configured.
The log levels correspond to the ones found in the L<syslog(3)> man page.
The default value is B<6>, equivalent to LOG_INFO.
The highest possible value is B<7> (LOG_DEBUG) which will log everything.
@ -201,6 +204,23 @@ The highest possible value is B<7> (LOG_DEBUG) which will log everything.
During runtime, the log level can be decreased by sending the signal
SIGURS1 to the daemon and can be increased with the signal SIGUSR2.
=item B<--log-level->I<subsystem>B<=>I<INT>
Configures a log level for one of the logging subsystems. A logging subsystem
which doesn't have a log level configured explicitly takes its default value
from the B<log-level> setting described above, with the exceptino of the
B<internals> subsystem which by default has all logging disabled.
The full list of logging subsystems can be viewed by pulling up the B<--help>
online help. Some (if not all) subsystems are: B<core>, B<spandsp> (messages
generated by SpanDSP itself), B<ffmpeg> (messages generated by ffmpeg libraries
themselves), B<transcoding> (messages related to RTP/media transcoding),
B<codec> (messages related to codec negotiation), B<rtcp>, B<ice>, B<crypto>
(messages related to crypto/SRTP/SDES/DTLS negotiation), B<srtp> (messages
related to RTP/SRTP en/decryption), B<internals> (disabled by default), B<http>
(includes WebSocket), B<control> (messages related to control protocols,
including SDP exchanges).
=item B<--log-facilty=>B<daemon>|B<local0>|...|B<local7>|...
The syslog facilty to use when sending log messages to the syslog daemon.


+ 2
- 2
daemon/t38.c View File

@ -84,7 +84,7 @@ static void spandsp_logging_func(SPAN_LOG_ARGS) {
level = LOG_WARN;
else
level = LOG_DEBUG;
ilog(level, "SpanDSP: %s", text);
ilogs(spandsp, level, "SpanDSP: %s", text);
}
@ -414,7 +414,7 @@ int t38_gateway_pair(struct call_media *t38_media, struct call_media *pcm_media,
logging_state_t *ls = t38_gateway_get_logging_state(tg->gw);
my_span_set_log(ls, spandsp_logging_func);
span_log_set_level(ls, span_log_level_map(get_log_level()));
span_log_set_level(ls, span_log_level_map(get_log_level(spandsp)));
packet_sequencer_init(&tg->sequencer, (GDestroyNotify) __udptl_packet_free);
tg->sequencer.seq = 0;


+ 48
- 48
daemon/websocket.c View File

@ -156,7 +156,7 @@ void websocket_write_next(struct websocket_conn *wc) {
static const char *websocket_echo_process(struct websocket_message *wm) {
ilog(LOG_DEBUG, "Returning %lu bytes websocket echo from %s", (unsigned long) wm->body->len,
ilogs(http, LOG_DEBUG, "Returning %lu bytes websocket echo from %s", (unsigned long) wm->body->len,
endpoint_print_buf(&wm->wc->endpoint));
websocket_write_binary(wm->wc, wm->body->str, wm->body->len, 1);
return NULL;
@ -164,7 +164,7 @@ static const char *websocket_echo_process(struct websocket_message *wm) {
static void websocket_message_push(struct websocket_conn *wc, websocket_message_func_t func) {
ilog(LOG_DEBUG, "Adding HTTP/WS message to processing queue");
ilogs(http, LOG_DEBUG, "Adding HTTP/WS message to processing queue");
mutex_lock(&wc->lock);
@ -203,7 +203,7 @@ static void websocket_process(void *p, void *up) {
mutex_unlock(&wc->lock);
if (err)
ilog(LOG_ERR, "Error while processing HTTP/WS message: %s", err);
ilogs(http, LOG_ERR, "Error while processing HTTP/WS message: %s", err);
}
@ -223,14 +223,14 @@ static int websocket_dequeue(struct websocket_conn *wc) {
size_t to_send = wo->str->len - wo->str_done - LWS_SEND_BUFFER_POST_PADDING;
if (to_send) {
if (to_send > 500)
ilog(LOG_DEBUG, "Writing %lu bytes to LWS", (unsigned long) to_send);
ilogs(http, LOG_DEBUG, "Writing %lu bytes to LWS", (unsigned long) to_send);
else
ilog(LOG_DEBUG, "Writing back to LWS: '%.*s'",
ilogs(http, LOG_DEBUG, "Writing back to LWS: '%.*s'",
(int) to_send, wo->str->str + wo->str_done);
size_t ret = lws_write(wc->wsi, (unsigned char *) wo->str->str + wo->str_done,
to_send, wo->protocol);
if (ret != to_send)
ilog(LOG_ERR, "Invalid LWS write: %lu != %lu",
ilogs(http, LOG_ERR, "Invalid LWS write: %lu != %lu",
(unsigned long) ret,
(unsigned long) to_send);
wo->str_done += ret;
@ -283,7 +283,7 @@ int websocket_http_response(struct websocket_conn *wc, int status, const char *c
const char *err = websocket_do_http_response(wc, status, content_type, content_length);
if (!err)
return 0;
ilog(LOG_ERR, "Failed to write HTTP response headers: %s", err);
ilogs(http, LOG_ERR, "Failed to write HTTP response headers: %s", err);
return -1;
}
const char *websocket_http_complete(struct websocket_conn *wc, int status, const char *content_type,
@ -298,7 +298,7 @@ const char *websocket_http_complete(struct websocket_conn *wc, int status, const
static const char *websocket_http_ping(struct websocket_message *wm) {
ilog(LOG_DEBUG, "Respoding to GET /ping");
ilogs(http, LOG_DEBUG, "Respoding to GET /ping");
return websocket_http_complete(wm->wc, 200, "text/plain", 5, "pong\n");
}
@ -310,7 +310,7 @@ static void __g_hash_table_destroy(GHashTable **s) {
g_hash_table_destroy(*s);
}
static const char *websocket_http_metrics(struct websocket_message *wm) {
ilog(LOG_DEBUG, "Respoding to GET /metrics");
ilogs(http, LOG_DEBUG, "Respoding to GET /metrics");
AUTO_CLEANUP_INIT(GQueue *metrics, statistics_free_metrics, statistics_gather_metrics());
AUTO_CLEANUP_INIT(GString *outp, __g_string_free, g_string_new(""));
@ -361,7 +361,7 @@ static const char *websocket_http_cli(struct websocket_message *wm) {
assert(strncmp(wm->uri, "/cli/", 5) == 0);
char *uri = wm->uri+5;
ilog(LOG_DEBUG, "Respoding to GET /cli/%s", uri);
ilogs(http, LOG_DEBUG, "Respoding to GET /cli/%s", uri);
str uri_cmd;
str_init(&uri_cmd, uri);
@ -379,7 +379,7 @@ static const char *websocket_http_cli(struct websocket_message *wm) {
static const char *websocket_cli_process(struct websocket_message *wm) {
ilog(LOG_DEBUG, "Processing websocket CLI req '%s'", wm->body->str);
ilogs(http, LOG_DEBUG, "Processing websocket CLI req '%s'", wm->body->str);
str uri_cmd;
str_init_len(&uri_cmd, wm->body->str, wm->body->len);
@ -405,7 +405,7 @@ static void websocket_ng_send_ws(str *cookie, str *body, const endpoint_t *sin,
static void websocket_ng_send_http(str *cookie, str *body, const endpoint_t *sin, void *p1) {
struct websocket_conn *wc = p1;
if (websocket_http_response(wc, 200, "application/x-rtpengine-ng", cookie->len + 1 + body->len))
ilog(LOG_WARN, "Failed to write HTTP headers");
ilogs(http, LOG_WARN, "Failed to write HTTP headers");
websocket_queue_raw(wc, cookie->s, cookie->len);
websocket_queue_raw(wc, " ", 1);
websocket_queue_raw(wc, body->s, body->len);
@ -415,7 +415,7 @@ static const char *websocket_ng_process(struct websocket_message *wm) {
char addr[64];
endpoint_print(&wm->wc->endpoint, addr, sizeof(addr));
ilog(LOG_DEBUG, "Processing websocket NG req from %s", addr);
ilogs(http, LOG_DEBUG, "Processing websocket NG req from %s", addr);
str cmd;
str_init_len(&cmd, wm->body->str, wm->body->len);
@ -429,7 +429,7 @@ static const char *websocket_http_ng(struct websocket_message *wm) {
endpoint_print(&wm->wc->endpoint, addr, sizeof(addr));
ilog(LOG_DEBUG, "Respoding to POST /ng from %s", addr);
ilogs(http, LOG_DEBUG, "Respoding to POST /ng from %s", addr);
str cmd;
str_init_len(&cmd, wm->body->str, wm->body->len);
@ -449,7 +449,7 @@ static int websocket_http_get(struct websocket_conn *wc) {
const char *uri = wm->uri;
websocket_message_func_t handler = NULL;
ilog(LOG_DEBUG, "HTTP GET from %s: '%s'", endpoint_print_buf(&wc->endpoint), wm->uri);
ilogs(http, LOG_INFO, "HTTP GET from %s: '%s'", endpoint_print_buf(&wc->endpoint), wm->uri);
wm->method = M_GET;
if (!strcmp(uri, "/ping"))
@ -460,7 +460,7 @@ static int websocket_http_get(struct websocket_conn *wc) {
handler = websocket_http_metrics;
if (!handler) {
ilog(LOG_WARN, "Unhandled HTTP GET URI: '%s'", uri);
ilogs(http, LOG_WARN, "Unhandled HTTP GET URI: '%s'", uri);
websocket_http_complete(wm->wc, 404, "text/plain", 10, "not found\n");
return 0;
}
@ -473,33 +473,33 @@ static int websocket_http_get(struct websocket_conn *wc) {
static int websocket_http_post(struct websocket_conn *wc) {
struct websocket_message *wm = wc->wm;
ilog(LOG_DEBUG, "HTTP POST from %s: '%s'", endpoint_print_buf(&wc->endpoint), wm->uri);
ilogs(http, LOG_INFO, "HTTP POST from %s: '%s'", endpoint_print_buf(&wc->endpoint), wm->uri);
wm->method = M_POST;
char ct[64];
if (lws_hdr_total_length(wc->wsi, WSI_TOKEN_HTTP_CONTENT_TYPE) >= sizeof(ct)) {
ilog(LOG_WARN, "Too long content-type header, rejecting HTTP POST");
ilogs(http, LOG_WARN, "Too long content-type header, rejecting HTTP POST");
return -1;
}
if (lws_hdr_copy(wc->wsi, ct, sizeof(ct)-1, WSI_TOKEN_HTTP_CONTENT_TYPE) <= 0) {
ilog(LOG_WARN, "Failed to get Content-type header, rejecting HTTP POST");
ilogs(http, LOG_WARN, "Failed to get Content-type header, rejecting HTTP POST");
return -1;
}
if (lws_hdr_total_length(wc->wsi, WSI_TOKEN_HTTP_CONTENT_LENGTH) <= 0) {
ilog(LOG_WARN, "Failed to get Content-length header, rejecting HTTP POST");
ilogs(http, LOG_WARN, "Failed to get Content-length header, rejecting HTTP POST");
return -1;
}
ilog(LOG_DEBUG, "POST content-type: %s", ct);
ilogs(http, LOG_DEBUG, "POST content-type: %s", ct);
if (!strcasecmp(ct, "application/json"))
wm->content_type = CT_JSON;
else if (!strcasecmp(ct, "application/x-rtpengine-ng"))
wm->content_type = CT_NG;
else
ilog(LOG_WARN, "Unsupported content-type '%s'", ct);
ilogs(http, LOG_WARN, "Unsupported content-type '%s'", ct);
return 0;
}
@ -511,23 +511,23 @@ static int websocket_http_body(struct websocket_conn *wc, const char *body, size
websocket_message_func_t handler = NULL;
if (wm->method != M_POST) {
ilog(LOG_WARN, "Rejecting HTTP body on unsupported method");
ilogs(http, LOG_WARN, "Rejecting HTTP body on unsupported method");
return -1;
}
if (len) {
ilog(LOG_DEBUG, "HTTP body: %lu bytes", (unsigned long) len);
ilogs(http, LOG_DEBUG, "HTTP body: %lu bytes", (unsigned long) len);
g_string_append_len(wm->body, body, len);
return 0;
}
ilog(LOG_DEBUG, "HTTP body complete: '%.*s'", (int) wm->body->len, wm->body->str);
ilogs(http, LOG_DEBUG, "HTTP body complete: '%.*s'", (int) wm->body->len, wm->body->str);
if (!strcmp(uri, "/ng") && wm->method == M_POST && wm->content_type == CT_NG)
handler = websocket_http_ng;
if (!handler) {
ilog(LOG_WARN, "Unhandled HTTP POST URI: '%s'", wm->uri);
ilogs(http, LOG_WARN, "Unhandled HTTP POST URI: '%s'", wm->uri);
websocket_http_complete(wm->wc, 404, "text/plain", 10, "not found\n");
return 0;
}
@ -594,7 +594,7 @@ static void websocket_conn_init(struct lws *wsi, void *p) {
int fd = lws_get_socket_fd(wsi);
#endif
if (getpeername(fd, (struct sockaddr *) &sa, &sl))
ilog(LOG_ERR, "Failed to get remote address of HTTP/WS connection (fd %i): %s",
ilogs(http, LOG_ERR, "Failed to get remote address of HTTP/WS connection (fd %i): %s",
fd, strerror(errno));
else
endpoint_parse_sockaddr_storage(&wc->endpoint, &sa);
@ -604,7 +604,7 @@ static void websocket_conn_init(struct lws *wsi, void *p) {
static int websocket_do_http(struct lws *wsi, struct websocket_conn *wc, const char *uri) {
ilog(LOG_DEBUG, "HTTP request start: %s", uri);
ilogs(http, LOG_DEBUG, "HTTP request start: %s", uri);
websocket_conn_init(wsi, wc);
wc->wm->uri = strdup(uri);
@ -614,7 +614,7 @@ static int websocket_do_http(struct lws *wsi, struct websocket_conn *wc, const c
if (lws_hdr_total_length(wsi, WSI_TOKEN_POST_URI))
return websocket_http_post(wc);
ilog(LOG_INFO, "Ignoring HTTP request to %s with unsupported method", uri);
ilogs(http, LOG_INFO, "Ignoring HTTP request to %s with unsupported method", uri);
return 0;
}
@ -622,7 +622,7 @@ static int websocket_do_http(struct lws *wsi, struct websocket_conn *wc, const c
static int websocket_http(struct lws *wsi, enum lws_callback_reasons reason, void *user, void *in,
size_t len)
{
ilog(LOG_DEBUG, "http-only callback %i %p %p", reason, wsi, user);
ilogs(http, LOG_DEBUG, "http-only callback %i %p %p", reason, wsi, user);
gettimeofday(&rtpe_now, NULL);
@ -646,10 +646,10 @@ static int websocket_http(struct lws *wsi, enum lws_callback_reasons reason, voi
case LWS_CALLBACK_GET_THREAD_ID:
return (long int) pthread_self();
case LWS_CALLBACK_WSI_CREATE:
ilog(LOG_DEBUG, "WS client created %p", wsi);
ilogs(http, LOG_DEBUG, "WS client created %p", wsi);
break;
case LWS_CALLBACK_SERVER_NEW_CLIENT_INSTANTIATED:
ilog(LOG_DEBUG, "New WS client %p", wsi);
ilogs(http, LOG_DEBUG, "New WS client %p", wsi);
break;
case LWS_CALLBACK_HTTP:
return websocket_do_http(wsi, user, in);
@ -660,21 +660,21 @@ static int websocket_http(struct lws *wsi, enum lws_callback_reasons reason, voi
case LWS_CALLBACK_HTTP_BODY_COMPLETION:
return websocket_http_body(user, NULL, 0);
case LWS_CALLBACK_CLOSED_HTTP:
ilog(LOG_DEBUG, "HTTP connection closed %p", wsi);
ilogs(http, LOG_DEBUG, "HTTP connection closed %p", wsi);
websocket_conn_cleanup(user);
break;
case LWS_CALLBACK_WSI_DESTROY:
ilog(LOG_DEBUG, "WS client destroyed %p", wsi);
ilogs(http, LOG_DEBUG, "WS client destroyed %p", wsi);
break;
case LWS_CALLBACK_ESTABLISHED:
case LWS_CALLBACK_RECEIVE:
case LWS_CALLBACK_CLOSED:
ilog(LOG_WARN, "Invalid HTTP callback %i", reason);
ilogs(http, LOG_WARN, "Invalid HTTP callback %i", reason);
return -1;
case LWS_CALLBACK_HTTP_WRITEABLE:
return websocket_dequeue(user);
default:
ilog(LOG_DEBUG, "Unhandled HTTP callback %i", reason);
ilogs(http, LOG_DEBUG, "Unhandled HTTP callback %i", reason);
break;
}
@ -687,7 +687,7 @@ static int websocket_protocol(struct lws *wsi, enum lws_callback_reasons reason,
{
struct websocket_conn *wc = user;
ilog(LOG_DEBUG, "Websocket protocol '%s' callback %i %p %p", name, reason, wsi, wc);
ilogs(http, LOG_DEBUG, "Websocket protocol '%s' callback %i %p %p", name, reason, wsi, wc);
gettimeofday(&rtpe_now, NULL);
@ -709,7 +709,7 @@ static int websocket_protocol(struct lws *wsi, enum lws_callback_reasons reason,
case LWS_CALLBACK_GET_THREAD_ID:
return (long int) pthread_self();
case LWS_CALLBACK_ESTABLISHED:
ilog(LOG_DEBUG, "Websocket protocol '%s' established", name);
ilogs(http, LOG_DEBUG, "Websocket protocol '%s' established", name);
websocket_conn_init(wsi, wc);
int get_len = lws_hdr_total_length(wsi, WSI_TOKEN_GET_URI);
if (get_len > 0) {
@ -723,12 +723,12 @@ static int websocket_protocol(struct lws *wsi, enum lws_callback_reasons reason,
}
break;
case LWS_CALLBACK_CLOSED:
ilog(LOG_DEBUG, "Websocket protocol '%s' closed", name);
ilogs(http, LOG_DEBUG, "Websocket protocol '%s' closed", name);
websocket_conn_cleanup(wc);
ilog(LOG_DEBUG, "Websocket protocol '%s' ready for cleanup", name);
ilogs(http, LOG_DEBUG, "Websocket protocol '%s' ready for cleanup", name);
break;
case LWS_CALLBACK_RECEIVE:;
ilog(LOG_DEBUG, "Websocket protocol '%s' data received for '%s': '%.*s'",
ilogs(http, LOG_DEBUG, "Websocket protocol '%s' data received for '%s': '%.*s'",
name, wc->uri, (int) len, (const char *) in);
wc->wm->method = M_WEBSOCKET;
g_string_append_len(wc->wm->body, in, len);
@ -737,7 +737,7 @@ static int websocket_protocol(struct lws *wsi, enum lws_callback_reasons reason,
case LWS_CALLBACK_SERVER_WRITEABLE:
return websocket_dequeue(user);
default:
ilog(LOG_DEBUG, "Unhandled websocket protocol '%s' callback %i", name, reason);
ilogs(http, LOG_DEBUG, "Unhandled websocket protocol '%s' callback %i", name, reason);
break;
}
@ -798,7 +798,7 @@ static void websocket_log(int level, const char *line) {
level = LOG_INFO;
else
level = LOG_DEBUG;
ilog(level, "libwebsockets: %s", line);
ilogs(http, level, "libwebsockets: %s", line);
}
@ -843,7 +843,7 @@ int websocket_init(void) {
for (char **ifp = rtpe_config.http_ifs; ifp && *ifp; ifp++) {
char *ifa = *ifp;
ilog(LOG_DEBUG, "Starting HTTP/WS '%s'", ifa);
ilogs(http, LOG_DEBUG, "Starting HTTP/WS '%s'", ifa);
endpoint_t ep;
err = "Failed to parse address/port";
if (endpoint_parse_any_getaddrinfo(&ep, ifa))
@ -869,7 +869,7 @@ int websocket_init(void) {
goto err;
char *ifa = *ifp;
ilog(LOG_DEBUG, "Starting HTTPS/WSS '%s'", ifa);
ilogs(http, LOG_DEBUG, "Starting HTTPS/WSS '%s'", ifa);
endpoint_t ep;
err = "Failed to parse address/port";
if (endpoint_parse_any_getaddrinfo(&ep, ifa))
@ -896,17 +896,17 @@ int websocket_init(void) {
int num_threads = rtpe_config.http_threads ? : rtpe_config.num_threads;
websocket_threads = g_thread_pool_new(websocket_process, NULL, num_threads, FALSE, NULL);
ilog(LOG_DEBUG, "Websocket init complete with %i threads", num_threads);
ilogs(http, LOG_DEBUG, "Websocket init complete with %i threads", num_threads);
return 0;
err:
ilog(LOG_ERROR, "Failed to start websocket listener: %s", err);
ilogs(http, LOG_ERROR, "Failed to start websocket listener: %s", err);
websocket_cleanup();
return -1;
}
static void websocket_loop(void *p) {
ilog(LOG_INFO, "Websocket listener thread running");
ilogs(http, LOG_INFO, "Websocket listener thread running");
while (!rtpe_shutdown)
lws_service(websocket_context, 100);


+ 3
- 5
include/crypto.h View File

@ -211,7 +211,7 @@ INLINE void crypto_params_sdes_queue_clear(GQueue *q) {
INLINE void crypto_debug_init(int flag) {
if (!rtpe_config.debug_srtp)
if (rtpe_config.common.log_levels[log_level_index_srtp] < LOG_NOTICE)
return;
if (crypto_debug_string)
g_string_free(crypto_debug_string, TRUE);
@ -222,7 +222,7 @@ INLINE void crypto_debug_init(int flag) {
}
void __crypto_debug_printf(const char *fmt, ...) __attribute__((format(printf,1,2)));
#define crypto_debug_printf(f, ...) \
if (rtpe_config.debug_srtp && crypto_debug_string) \
if (crypto_debug_string) \
__crypto_debug_printf(f, ##__VA_ARGS__)
INLINE void crypto_debug_dump_raw(const char *b, int len) {
for (int i = 0; i < len; i++)
@ -232,11 +232,9 @@ INLINE void crypto_debug_dump(const str *s) {
crypto_debug_dump_raw(s->s, s->len);
}
INLINE void crypto_debug_finish(void) {
if (!rtpe_config.debug_srtp)
return;
if (!crypto_debug_string)
return;
ilog(LOG_NOTICE, "Crypto debug: %.*s", (int) crypto_debug_string->len, crypto_debug_string->str);
ilogs(srtp, LOG_NOTICE, "Crypto debug: %.*s", (int) crypto_debug_string->len, crypto_debug_string->str);
g_string_free(crypto_debug_string, TRUE);
crypto_debug_string = NULL;
}


+ 0
- 1
include/main.h View File

@ -97,7 +97,6 @@ struct rtpengine_config {
enum endpoint_learning endpoint_learning;
int jb_length;
int jb_clock_drift;
int debug_srtp;
int dtls_rsa_key_size;
char *dtls_ciphers;
int dtls_signature;


+ 12
- 5
lib/auxlib.c View File

@ -134,19 +134,23 @@ void config_load(int *argc, char ***argv, GOptionEntry *app_entries, const char
// defaults
#ifndef __DEBUG
rtpe_common_config_ptr->log_level = LOG_INFO;
rtpe_common_config_ptr->default_log_level = LOG_INFO;
#else
rtpe_common_config_ptr->log_level = LOG_DEBUG;
rtpe_common_config_ptr->default_log_level = LOG_DEBUG;
#endif
AUTO_CLEANUP(GKeyFile *kf, free_gkeyfile) = g_key_file_new();
#define ll(system) \
{ "log-level-" #system, 0, 0, G_OPTION_ARG_INT, &rtpe_common_config_ptr->log_levels[log_level_index_ ## system],"Log level for '" #system "'","INT" },
GOptionEntry shared_options[] = {
{ "version", 'v', 0, G_OPTION_ARG_NONE, &version, "Print build time and exit", NULL },
{ "config-file", 0, 0, G_OPTION_ARG_STRING, &rtpe_common_config_ptr->config_file, "Load config from this file", "FILE" },
{ "config-section", 0, 0, G_OPTION_ARG_STRING, &rtpe_common_config_ptr->config_section,"Config file section to use", "STRING" },
{ "log-facility", 0, 0, G_OPTION_ARG_STRING, &rtpe_common_config_ptr->log_facility, "Syslog facility to use for logging", "daemon|local0|...|local7"},
{ "log-level", 'L', 0, G_OPTION_ARG_INT, (void *)&rtpe_common_config_ptr->log_level,"Mask log priorities above this level","INT" },
{ "log-level", 'L', 0, G_OPTION_ARG_INT, &rtpe_common_config_ptr->default_log_level,"Default log level", "INT" },
#include "loglevels.h"
{ "log-stderr", 'E', 0, G_OPTION_ARG_NONE, &rtpe_common_config_ptr->log_stderr, "Log on stderr instead of syslog", NULL },
{ "split-logs", 0, 0, G_OPTION_ARG_NONE, &rtpe_common_config_ptr->split_logs, "Split multi-line log messages", NULL },
{ "no-log-timestamps", 0, 0, G_OPTION_ARG_NONE, &rtpe_common_config_ptr->no_log_timestamps,"Drop timestamps from log lines to stderr",NULL },
@ -157,6 +161,7 @@ void config_load(int *argc, char ***argv, GOptionEntry *app_entries, const char
{ "thread-stack", 0,0, G_OPTION_ARG_INT, &rtpe_common_config_ptr->thread_stack, "Thread stack size in kB", "INT" },
{ NULL, }
};
#undef ll
// prepend shared CLI options
@ -320,8 +325,10 @@ out:
}
}
if ((rtpe_common_config_ptr->log_level < LOG_EMERG) || (rtpe_common_config_ptr->log_level > LOG_DEBUG))
die("Invalid log level (--log_level)");
for (unsigned int i = 0; i < num_log_levels; i++) {
if (!rtpe_common_config_ptr->log_levels[i])
rtpe_common_config_ptr->log_levels[i] = rtpe_common_config_ptr->default_log_level;
}
if (rtpe_common_config_ptr->log_stderr) {
write_log = log_to_stderr;


+ 3
- 1
lib/auxlib.h View File

@ -10,13 +10,15 @@
#define THREAD_BUF_SIZE 64
#define NUM_THREAD_BUFS 8
#define MAX_LOG_LEVELS 32
struct rtpengine_common_config {
char *config_file;
char *config_section;
char *log_facility;
volatile int log_level;
int default_log_level;
int log_levels[MAX_LOG_LEVELS];
int log_stderr;
int split_logs;
int no_log_timestamps;


+ 2
- 2
lib/codeclib.c View File

@ -761,7 +761,7 @@ int decoder_lost_packet(decoder_t *dec, unsigned long ts,
static void avlog_ilog(void *ptr, int loglevel, const char *fmt, va_list ap) {
char *msg;
if (vasprintf(&msg, fmt, ap) <= 0)
ilog(LOG_ERR | LOG_FLAG_LIMIT, "av_log message dropped");
ilogs(ffmpeg, LOG_ERR | LOG_FLAG_LIMIT, "av_log message dropped");
else {
#ifdef AV_LOG_PANIC
// translate AV_LOG_ constants to LOG_ levels
@ -784,7 +784,7 @@ static void avlog_ilog(void *ptr, int loglevel, const char *fmt, va_list ap) {
else
loglevel = LOG_DEBUG;
#endif
ilog(loglevel | LOG_FLAG_LIMIT, "av_log: %s", msg);
ilogs(ffmpeg, loglevel | LOG_FLAG_LIMIT, "av_log: %s", msg);
free(msg);
}
}


+ 8
- 0
lib/loglib.c View File

@ -31,6 +31,14 @@ write_log_t *write_log = (write_log_t *) log_both;
#define ll(system) #system,
const char * const log_level_names[] = {
#include "loglevels.h"
NULL
};
static const _fac_code_t _facilitynames[] =
{
{ "auth", LOG_AUTH },


+ 26
- 6
lib/loglib.h View File

@ -29,26 +29,46 @@ void __vpilog(int prio, const char *prefix, const char *fmt, va_list);
void __ilog_np(int prio, const char *format, ...) __attribute__ ((format (printf, 2, 3)));
#define ll(system) log_level_index_ ## system,
enum __loglevels {
#include "loglevels.h"
ll(LAST)
};
#undef ll
#define num_log_levels log_level_index_LAST
extern const char * const log_level_names[];
#ifndef __DEBUG
#define ilog(prio, fmt, ...) \
#define ilogsn(system, prio, fmt, ...) \
do { \
int __loglevel = get_log_level(); \
int __loglevel = __get_log_level(system); \
if (LOG_LEVEL_MASK((prio)) > LOG_LEVEL_MASK(__loglevel)) \
break; \
if ((__loglevel & LOG_FLAG_RESTORE) && !((prio) & LOG_FLAG_RESTORE)) \
break; \
__ilog(prio, fmt, ##__VA_ARGS__); \
__ilog(prio, "[%s] " fmt, log_level_names[system], ##__VA_ARGS__); \
} while (0)
#else
#define ilog(prio, fmt, ...) __ilog(prio, fmt, ##__VA_ARGS__)
#define ilogsn(prio, system, fmt, ...) __ilog(prio, "[%s] " fmt, log_level_names[system], ##__VA_ARGS__)
#endif
INLINE int get_log_level(void) {
#define ilog(prio, fmt, ...) ilogs(core, prio, fmt, ##__VA_ARGS__)
#define ilogs(system, prio, fmt, ...) ilogsn(log_level_index_ ## system, prio, fmt, ##__VA_ARGS__)
INLINE int __get_log_level(unsigned int idx) {
if (!rtpe_common_config_ptr)
return 8;
return g_atomic_int_get(&rtpe_common_config_ptr->log_level);
if (idx >= MAX_LOG_LEVELS)
return 8;
return g_atomic_int_get(&rtpe_common_config_ptr->log_levels[idx]);
}
#define get_log_level(system) __get_log_level(log_level_index_ ## system)


+ 2
- 0
recording-daemon/loglevels.h View File

@ -0,0 +1,2 @@
ll(core)
ll(ffmpeg)

+ 12
- 0
t/loglevels.h View File

@ -0,0 +1,12 @@
ll(core)
ll(spandsp)
ll(ffmpeg)
ll(transcoding)
ll(codec)
ll(rtcp)
ll(ice)
ll(crypto)
ll(srtp)
ll(internals)
ll(http)
ll(control)

Write Preview
Loading…
Cancel
Save