diff --git a/daemon/call.c b/daemon/call.c index e3f3b9ade..28635a47c 100644 --- a/daemon/call.c +++ b/daemon/call.c @@ -261,8 +261,8 @@ void xmlrpc_kill_calls(void *p) { tag3 = xh->strings.head->next->next->next->data; } - ilog(LOG_INFO, "Forking child to close call with tag "STR_FORMAT" via XMLRPC call to %s", - STR_FMT(tag), url); + ilog(LOG_INFO, "Forking child to close call with tag " STR_FORMAT_M " via XMLRPC call to %s", + STR_FMT_M(tag), url); pid = fork(); if (pid) { @@ -296,7 +296,7 @@ retry: if (!rtpe_config.common.log_stderr) { openlog("rtpengine/child", LOG_PID | LOG_NDELAY, LOG_DAEMON); } - ilog(LOG_INFO, "Initiating XMLRPC call for tag "STR_FORMAT"", STR_FMT(tag)); + ilog(LOG_INFO, "Initiating XMLRPC call for tag " STR_FORMAT_M "", STR_FMT_M(tag)); alarm(5); @@ -953,7 +953,8 @@ static void __fill_stream(struct packet_stream *ps, const struct endpoint *epp, dtls_shutdown(ps); } - ilog(LOG_DEBUG, "set FILLED flag for stream %s:%d", sockaddr_print_buf(&ps->endpoint.address), ps->endpoint.port); + ilog(LOG_DEBUG, "set FILLED flag for stream %s%s:%d%s", + FMT_M(sockaddr_print_buf(&ps->endpoint.address), ps->endpoint.port)); PS_SET(ps, FILLED); /* XXX reset/repair ICE */ } @@ -1004,16 +1005,16 @@ static 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", + ilog(LOG_DEBUG, "[%s] Initialized incoming SRTP with SDES crypto params: %s%s%s", endpoint_print_buf(&sfd->socket.local), - crypto_params_sdes_dump(cps, ¶msbuf)); + FMT_M(crypto_params_sdes_dump(cps, ¶msbuf))); } 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", + ilog(LOG_DEBUG, "[%i] Initialized outgoing SRTP with SDES crypto params: %s%s%s", ps->component, - crypto_params_sdes_dump(cps, ¶msbuf)); + FMT_M(crypto_params_sdes_dump(cps, ¶msbuf))); } if (MEDIA_ISSET(media, DTLS) && !PS_ISSET(ps, FALLBACK_RTCP)) { @@ -2128,17 +2129,19 @@ void call_destroy(struct call *c) { for (l = c->monologues.head; l; l = l->next) { ml = l->data; - ilog(LOG_INFO, "--- Tag '"STR_FORMAT"'%s"STR_FORMAT"%s, created " - "%u:%02u ago for branch '"STR_FORMAT"', in dialogue with '"STR_FORMAT"'", - STR_FMT(&ml->tag), + ilog(LOG_INFO, "--- Tag '" STR_FORMAT_M "'%s"STR_FORMAT"%s, created " + "%u:%02u ago for branch '" STR_FORMAT_M "', in dialogue with '" STR_FORMAT_M "'", + STR_FMT_M(&ml->tag), ml->label.s ? " (label '" : "", STR_FMT(ml->label.s ? &ml->label : &STR_EMPTY), ml->label.s ? "')" : "", (unsigned int) (rtpe_now.tv_sec - ml->created) / 60, (unsigned int) (rtpe_now.tv_sec - ml->created) % 60, - STR_FMT(&ml->viabranch), + STR_FMT_M(&ml->viabranch), + ml->active_dialogue ? rtpe_common_config_ptr->log_mark_prefix : "", ml->active_dialogue ? ml->active_dialogue->tag.len : 6, - ml->active_dialogue ? ml->active_dialogue->tag.s : "(none)"); + ml->active_dialogue ? ml->active_dialogue->tag.s : "(none)", + ml->active_dialogue ? rtpe_common_config_ptr->log_mark_suffix : ""); for (k = ml->medias.head; k; k = k->next) { md = k->data; @@ -2164,13 +2167,13 @@ void call_destroy(struct call *c) { char *addr = sockaddr_print_buf(&ps->endpoint.address); char *local_addr = ps->selected_sfd ? sockaddr_print_buf(&ps->selected_sfd->socket.local.address) : "0.0.0.0"; - ilog(LOG_INFO, "--------- Port %15s:%-5u <> %15s:%-5u%s, SSRC %" PRIx32 ", " + ilog(LOG_INFO, "--------- Port %15s:%-5u <> %s%15s:%-5u%s%s, SSRC %s%" PRIx32 "%s, " ""UINT64F" p, "UINT64F" b, "UINT64F" e, "UINT64F" ts", local_addr, (unsigned int) (ps->selected_sfd ? ps->selected_sfd->socket.local.port : 0), - addr, ps->endpoint.port, + FMT_M(addr, ps->endpoint.port), (!PS_ISSET(ps, RTP) && PS_ISSET(ps, RTCP)) ? " (RTCP)" : "", - ps->ssrc_in ? ps->ssrc_in->parent->h.ssrc : 0, + FMT_M(ps->ssrc_in ? ps->ssrc_in->parent->h.ssrc : 0), atomic64_get(&ps->stats.packets), atomic64_get(&ps->stats.bytes), atomic64_get(&ps->stats.errors), @@ -2195,7 +2198,7 @@ void call_destroy(struct call *c) { if (!se->stats_blocks.length || !se->lowest_mos || !se->highest_mos) continue; - ilog(LOG_INFO, "--- SSRC %" PRIx32 "", se->h.ssrc); + ilog(LOG_INFO, "--- SSRC %s%" PRIx32 "%s", FMT_M(se->h.ssrc)); ilog(LOG_INFO, "------ Average MOS %" PRIu64 ".%" PRIu64 ", " "lowest MOS %" PRIu64 ".%" PRIu64 " (at %u:%02u), " "highest MOS %" PRIu64 ".%" PRIu64 " (at %u:%02u)", @@ -2535,22 +2538,22 @@ static int monologue_destroy(struct call_monologue *ml) { __monologue_destroy(ml); if (!g_hash_table_size(c->tags)) { - ilog(LOG_INFO, "Call branch '"STR_FORMAT"' (%s"STR_FORMAT"%svia-branch '"STR_FORMAT"') " + ilog(LOG_INFO, "Call branch '" STR_FORMAT_M "' (%s" STR_FORMAT "%svia-branch '" STR_FORMAT_M "') " "deleted, no more branches remaining", - STR_FMT(&ml->tag), + STR_FMT_M(&ml->tag), ml->label.s ? "label '" : "", STR_FMT(ml->label.s ? &ml->label : &STR_EMPTY), ml->label.s ? "', " : "", - STR_FMT0(&ml->viabranch)); + STR_FMT0_M(&ml->viabranch)); return 1; /* destroy call */ } - ilog(LOG_INFO, "Call branch '"STR_FORMAT"' (%s"STR_FORMAT"%svia-branch '"STR_FORMAT"') deleted", - STR_FMT(&ml->tag), + ilog(LOG_INFO, "Call branch '" STR_FORMAT_M "' (%s" STR_FORMAT "%svia-branch '" STR_FORMAT_M "') deleted", + STR_FMT_M(&ml->tag), ml->label.s ? "label '" : "", STR_FMT(ml->label.s ? &ml->label : &STR_EMPTY), ml->label.s ? "', " : "", - STR_FMT0(&ml->viabranch)); + STR_FMT0_M(&ml->viabranch)); return 0; } @@ -2759,16 +2762,16 @@ do_delete: media_player_stop(ml->player); if (delete_delay > 0) { - ilog(LOG_INFO, "Scheduling deletion of call branch '"STR_FORMAT"' " - "(via-branch '"STR_FORMAT"') in %d seconds", - STR_FMT(&ml->tag), STR_FMT0(branch), delete_delay); + ilog(LOG_INFO, "Scheduling deletion of call branch '" STR_FORMAT_M "' " + "(via-branch '" STR_FORMAT_M "') in %d seconds", + STR_FMT_M(&ml->tag), STR_FMT0_M(branch), delete_delay); ml->deleted = rtpe_now.tv_sec + delete_delay; if (!c->ml_deleted || c->ml_deleted > ml->deleted) c->ml_deleted = ml->deleted; } else { - ilog(LOG_INFO, "Deleting call branch '"STR_FORMAT"' (via-branch '"STR_FORMAT"')", - STR_FMT(&ml->tag), STR_FMT0(branch)); + ilog(LOG_INFO, "Deleting call branch '" STR_FORMAT_M "' (via-branch '" STR_FORMAT_M "')", + STR_FMT_M(&ml->tag), STR_FMT0_M(branch)); if (monologue_destroy(ml)) goto del_all; } diff --git a/daemon/call_interfaces.c b/daemon/call_interfaces.c index 0e1d8c3c1..1323f6d72 100644 --- a/daemon/call_interfaces.c +++ b/daemon/call_interfaces.c @@ -169,8 +169,8 @@ static str *call_update_lookup_udp(char **out, enum call_opmode opmode, const ch c = call_get_opmode(&callid, opmode); if (!c) { - ilog(LOG_WARNING, "["STR_FORMAT"] Got UDP LOOKUP for unknown call-id", - STR_FMT(&callid)); + ilog(LOG_WARNING, "[" STR_FORMAT_M "] Got UDP LOOKUP for unknown call-id", + STR_FMT_M(&callid)); return str_sprintf("%s 0 0.0.0.0\n", out[RE_UDP_COOKIE]); } @@ -215,8 +215,8 @@ ml_fail: goto unlock_fail; addr_fail: - ilog(LOG_ERR, "Failed to parse a media stream: %s/%s:%s", - out[RE_UDP_UL_ADDR4], out[RE_UDP_UL_ADDR6], out[RE_UDP_UL_PORT]); + ilog(LOG_ERR, "Failed to parse a media stream: %s%s/%s:%s%s", + FMT_M(out[RE_UDP_UL_ADDR4], out[RE_UDP_UL_ADDR6], out[RE_UDP_UL_PORT])); goto unlock_fail; unlock_fail: @@ -275,7 +275,7 @@ static int streams_parse_func(char **a, void **ret, void *p) { return 0; fail: - ilog(LOG_WARNING, "Failed to parse a media stream: %s:%s", a[0], a[1]); + ilog(LOG_WARNING, "Failed to parse a media stream: %s%s:%s%s", FMT_M(a[0], a[1])); g_slice_free1(sizeof(*sp), sp); return -1; } @@ -316,7 +316,7 @@ static str *call_request_lookup_tcp(char **out, enum call_opmode opmode) { infohash = g_hash_table_new_full(g_str_hash, g_str_equal, free, free); c = call_get_opmode(&callid, opmode); if (!c) { - ilog(LOG_WARNING, "["STR_FORMAT"] Got LOOKUP for unknown call-id", STR_FMT(&callid)); + ilog(LOG_WARNING, "[" STR_FORMAT_M "] Got LOOKUP for unknown call-id", STR_FMT_M(&callid)); goto out; } @@ -396,7 +396,7 @@ str *call_query_udp(char **out) { c = call_get_opmode(&callid, OP_OTHER); if (!c) { - ilog(LOG_INFO, "["STR_FORMAT"] Call-ID to query not found", STR_FMT(&callid)); + ilog(LOG_INFO, "[" STR_FORMAT_M "] Call-ID to query not found", STR_FMT_M(&callid)); goto err; } @@ -1519,8 +1519,8 @@ static const char *media_block_match(struct call **call, struct call_monologue * struct packet_stream *ps = media->streams.head->data; if (!sockaddr_eq(&addr, &ps->advertised_endpoint.address)) continue; - ilog(LOG_DEBUG, "Matched address %s to tag '" STR_FORMAT "'", - sockaddr_print_buf(&addr), STR_FMT(&(*monologue)->tag)); + ilog(LOG_DEBUG, "Matched address %s%s%s to tag '" STR_FORMAT_M "'", + FMT_M(sockaddr_print_buf(&addr)), STR_FMT_M(&(*monologue)->tag)); goto found; } } @@ -1549,8 +1549,8 @@ const char *call_start_forwarding_ng(bencode_item_t *input, bencode_item_t *outp goto out; if (monologue) { - ilog(LOG_INFO, "Start forwarding for single party (tag '" STR_FORMAT ")", - STR_FMT(&monologue->tag)); + ilog(LOG_INFO, "Start forwarding for single party (tag '" STR_FORMAT_M "')", + STR_FMT_M(&monologue->tag)); monologue->rec_forwarding = 1; } else { @@ -1580,8 +1580,8 @@ const char *call_stop_forwarding_ng(bencode_item_t *input, bencode_item_t *outpu goto out; if (monologue) { - ilog(LOG_INFO, "Stop forwarding for single party (tag '" STR_FORMAT ")", - STR_FMT(&monologue->tag)); + ilog(LOG_INFO, "Stop forwarding for single party (tag '" STR_FORMAT_M "')", + STR_FMT_M(&monologue->tag)); monologue->rec_forwarding = 0; } else { @@ -1618,8 +1618,8 @@ const char *call_block_dtmf_ng(bencode_item_t *input, bencode_item_t *output) { goto out; if (monologue) { - ilog(LOG_INFO, "Blocking directional DTMF (tag '" STR_FORMAT ")", - STR_FMT(&monologue->tag)); + ilog(LOG_INFO, "Blocking directional DTMF (tag '" STR_FORMAT_M "')", + STR_FMT_M(&monologue->tag)); monologue->block_dtmf = 1; } else { @@ -1648,8 +1648,8 @@ const char *call_unblock_dtmf_ng(bencode_item_t *input, bencode_item_t *output) goto out; if (monologue) { - ilog(LOG_INFO, "Unblocking directional DTMF (tag '" STR_FORMAT ")", - STR_FMT(&monologue->tag)); + ilog(LOG_INFO, "Unblocking directional DTMF (tag '" STR_FORMAT_M "')", + STR_FMT_M(&monologue->tag)); monologue->block_dtmf = 0; } else { @@ -1684,8 +1684,8 @@ const char *call_block_media_ng(bencode_item_t *input, bencode_item_t *output) { goto out; if (monologue) { - ilog(LOG_INFO, "Blocking directional media (tag '" STR_FORMAT ")", - STR_FMT(&monologue->tag)); + ilog(LOG_INFO, "Blocking directional media (tag '" STR_FORMAT_M "')", + STR_FMT_M(&monologue->tag)); monologue->block_media = 1; __monologue_unkernelize(monologue); } @@ -1716,8 +1716,8 @@ const char *call_unblock_media_ng(bencode_item_t *input, bencode_item_t *output) goto out; if (monologue) { - ilog(LOG_INFO, "Unblocking directional media (tag '" STR_FORMAT ")", - STR_FMT(&monologue->tag)); + ilog(LOG_INFO, "Unblocking directional media (tag '" STR_FORMAT_M "')", + STR_FMT_M(&monologue->tag)); monologue->block_media = 0; __monologue_unkernelize(monologue); } diff --git a/daemon/cli.c b/daemon/cli.c index 62f23ef13..d232592fa 100644 --- a/daemon/cli.c +++ b/daemon/cli.c @@ -1146,7 +1146,7 @@ static void cli_stream_readable(struct streambuf_stream *s) { return; } - ilog(LOG_INFO, "Got CLI command:%s",inbuf); + ilog(LOG_INFO, "Got CLI command: %s%s%s", FMT_M(inbuf)); str_init(&instr, inbuf); cli_handler_do(cli_top_handlers, &instr, s->outbuf); diff --git a/daemon/control_ng.c b/daemon/control_ng.c index 8d2ecd6a0..27a317ed7 100644 --- a/daemon/control_ng.c +++ b/daemon/control_ng.c @@ -14,6 +14,7 @@ #include "call_interfaces.h" #include "socket.h" #include "log_funcs.h" +#include "main.h" mutex_t rtpe_cngs_lock; @@ -129,7 +130,8 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin 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, addr, STR_FMT(buf)); + ilog(LOG_WARNING, "Received invalid data on NG port (no cookie) from %s: " STR_FORMAT_M, + addr, STR_FMT_M(buf)); return; } @@ -172,8 +174,10 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin if (get_log_level() >= LOG_DEBUG) { log_str = g_string_sized_new(256); - g_string_append_printf(log_str, "Dump for '"STR_FORMAT"' from %s: ", STR_FMT(&cmd), addr); + 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); g_string_free(log_str, TRUE); } @@ -287,7 +291,8 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin 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"]", addr, errstr, STR_FMT(&data)); + ilog(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); g_atomic_int_inc(&cur->errors); @@ -309,9 +314,11 @@ send_resp: dict = bencode_decode_expect_str(&bencbuf, to_send, BENCODE_DICTIONARY); if (dict) { log_str = g_string_sized_new(256); - g_string_append_printf(log_str, "Response dump for '"STR_FORMAT"' to %s: ", - STR_FMT(&cmd), addr); + g_string_append_printf(log_str, "Response dump for '"STR_FORMAT"' to %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); g_string_free(log_str, TRUE); } diff --git a/daemon/crypto.c b/daemon/crypto.c index a4c4f0246..7b3e39611 100644 --- a/daemon/crypto.c +++ b/daemon/crypto.c @@ -709,7 +709,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 salt %s", c->params.crypto_suite->name, k, s); + ilog(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); diff --git a/daemon/ice.c b/daemon/ice.c index 350119145..dba833324 100644 --- a/daemon/ice.c +++ b/daemon/ice.c @@ -29,10 +29,10 @@ -#define PAIR_FORMAT STR_FORMAT":"STR_FORMAT":%lu" +#define PAIR_FORMAT STR_FORMAT_M ":" STR_FORMAT_M ":%lu" #define PAIR_FMT(p) \ - STR_FMT(&(p)->local_intf->ice_foundation), \ - STR_FMT(&(p)->remote_candidate->foundation), \ + STR_FMT_M(&(p)->local_intf->ice_foundation), \ + STR_FMT_M(&(p)->remote_candidate->foundation), \ (p)->remote_candidate->component_id @@ -157,9 +157,9 @@ static struct ice_candidate_pair *__pair_candidate(struct stream_fd *sfd, struct g_hash_table_insert(ag->pair_hash, pair, pair); g_tree_insert(ag->all_pairs, pair, pair); - ilog(LOG_DEBUG, "Created candidate pair "PAIR_FORMAT" between %s and %s, type %s", PAIR_FMT(pair), + ilog(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), - endpoint_print_buf(&cand->endpoint), + FMT_M(endpoint_print_buf(&cand->endpoint)), ice_candidate_type_str(cand->type)); return pair; @@ -377,25 +377,26 @@ void ice_update(struct ice_agent *ag, struct stream_params *sp) { * otherwise it's simply one we've seen before. */ if (dup->type == ICT_PRFLX) { ilog(LOG_DEBUG, "Replacing previously learned prflx ICE candidate with " - STR_FORMAT":%lu", STR_FMT(&cand->foundation), + STR_FORMAT_M ":%lu", STR_FMT_M(&cand->foundation), cand->component_id); } else { /* 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" in favour of " - STR_FORMAT":%lu", - STR_FMT(&cand->foundation), - STR_FMT(&dup->foundation), cand->component_id); + ilog(LOG_DEBUG, "Dropping new ICE candidate " STR_FORMAT_M + " in favour of " + STR_FORMAT_M ":%lu", + STR_FMT_M(&cand->foundation), + STR_FMT_M(&dup->foundation), cand->component_id); continue; } - ilog(LOG_DEBUG, "Replacing known ICE candidate "STR_FORMAT" with higher " + ilog(LOG_DEBUG, "Replacing known ICE candidate " STR_FORMAT_M " with higher " "priority " - STR_FORMAT":%lu", - STR_FMT(&dup->foundation), - STR_FMT(&cand->foundation), cand->component_id); + STR_FORMAT_M ":%lu", + STR_FMT_M(&dup->foundation), + STR_FMT_M(&cand->foundation), cand->component_id); } /* priority and foundation may change */ @@ -403,8 +404,8 @@ 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":%lu", - STR_FMT(&cand->foundation), cand->component_id); + ilog(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); g_hash_table_insert(ag->candidate_hash, dup, dup); @@ -602,10 +603,10 @@ 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", + ilog(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), - endpoint_print_buf(&pair->remote_candidate->endpoint)); + FMT_M(endpoint_print_buf(&pair->remote_candidate->endpoint))); stun_binding_request(&pair->remote_candidate->endpoint, transact, &ag->pwd[0], ag->ufrag, AGENT_ISSET(ag, CONTROLLING), tie_breaker, @@ -997,8 +998,8 @@ 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", ps->component, - endpoint_print_buf(&pair->remote_candidate->endpoint)); + ilog(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; } mutex_unlock(&ps->out_lock); @@ -1110,7 +1111,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 on interface %s)", err, endpoint_print_buf(src), + ilog(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; } @@ -1169,9 +1170,9 @@ 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 to %s", + ilog(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), - endpoint_print_buf(&pair->remote_candidate->endpoint), + FMT_M(endpoint_print_buf(&pair->remote_candidate->endpoint)), sockaddr_print_buf(&ifa->spec->local_address.addr)); /* verify endpoints */ @@ -1261,8 +1262,8 @@ err_unlock: mutex_unlock(&ag->lock); err: if (err) - ilog(LOG_NOTICE | LOG_FLAG_LIMIT, "%s (from %s on interface %s)", - err, endpoint_print_buf(src), endpoint_print_buf(&sfd->socket.local)); + ilog(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) __fail_pair(pair); diff --git a/daemon/iptables.c b/daemon/iptables.c index 802a3efc9..340098ca5 100644 --- a/daemon/iptables.c +++ b/daemon/iptables.c @@ -276,8 +276,8 @@ static int __iptables_add_rule(const socket_t *local_sock, const str *comment) { }; if (err) - ilog(LOG_ERROR, "Error adding iptables rule (for '" STR_FORMAT "'): %s (%s)", - STR_FMT(comment), err, strerror(errno)); + ilog(LOG_ERROR, "Error adding iptables rule (for '" STR_FORMAT_M "'): %s (%s)", + STR_FMT_M(comment), err, strerror(errno)); return 0; } diff --git a/daemon/log.c b/daemon/log.c index 8ab647ce0..56f48ffbe 100644 --- a/daemon/log.c +++ b/daemon/log.c @@ -39,26 +39,27 @@ static void ilog_prefix_default(char *prefix, size_t prefix_len) { prefix[0] = 0; break; case LOG_INFO_CALL: - snprintf(prefix, prefix_len, "["STR_FORMAT"]: ", - STR_FMT(&log_info.u.call->callid)); + snprintf(prefix, prefix_len, "[" STR_FORMAT_M "]: ", + STR_FMT_M(&log_info.u.call->callid)); break; case LOG_INFO_STREAM_FD: if (log_info.u.stream_fd->call) - snprintf(prefix, prefix_len, "["STR_FORMAT" port %5u]: ", - STR_FMT(&log_info.u.stream_fd->call->callid), + snprintf(prefix, prefix_len, "[" STR_FORMAT_M " port %5u]: ", + STR_FMT_M(&log_info.u.stream_fd->call->callid), log_info.u.stream_fd->socket.local.port); break; case LOG_INFO_STR: - snprintf(prefix, prefix_len, "["STR_FORMAT"]: ", - STR_FMT(log_info.u.str)); + snprintf(prefix, prefix_len, "[" STR_FORMAT_M "]: ", + STR_FMT_M(log_info.u.str)); break; case LOG_INFO_C_STRING: - snprintf(prefix, prefix_len, "[%s]: ", log_info.u.cstr); + snprintf(prefix, prefix_len, "[%s%s%s]: ", + FMT_M(log_info.u.cstr)); break; case LOG_INFO_ICE_AGENT: - snprintf(prefix, prefix_len, "["STR_FORMAT"/"STR_FORMAT"/%u]: ", - STR_FMT(&log_info.u.ice_agent->call->callid), - STR_FMT(&log_info.u.ice_agent->media->monologue->tag), + snprintf(prefix, prefix_len, "[" STR_FORMAT_M "/" STR_FORMAT_M "/%u]: ", + STR_FMT_M(&log_info.u.ice_agent->call->callid), + STR_FMT_M(&log_info.u.ice_agent->media->monologue->tag), log_info.u.ice_agent->media->index); break; } diff --git a/daemon/media_player.c b/daemon/media_player.c index 7f7789966..853c145cf 100644 --- a/daemon/media_player.c +++ b/daemon/media_player.c @@ -175,9 +175,9 @@ static int send_timer_send(struct send_timer *st, struct codec_packet *cp) { goto out; struct rtp_header *rh = (void *) cp->s.s; - ilog(LOG_DEBUG, "Forward to sink endpoint: %s:%d (RTP seq %u TS %u)", - sockaddr_print_buf(&st->sink->endpoint.address), - st->sink->endpoint.port, + ilog(LOG_DEBUG, "Forward to sink endpoint: %s%s:%d%s (RTP seq %u TS %u)", + FMT_M(sockaddr_print_buf(&st->sink->endpoint.address), + st->sink->endpoint.port), ntohs(rh->seq_num), ntohl(rh->timestamp)); diff --git a/daemon/media_socket.c b/daemon/media_socket.c index f74ac24e4..2484e7f26 100644 --- a/daemon/media_socket.c +++ b/daemon/media_socket.c @@ -349,14 +349,14 @@ static int has_free_ports_loc(struct local_intf *loc, unsigned int num_ports) { } if (num_ports > g_atomic_int_get(&loc->spec->port_pool.free_ports)) { - ilog(LOG_ERR, "Didn't found %d ports available for %.*s/%s", - num_ports, loc->logical->name.len, loc->logical->name.s, + ilog(LOG_ERR, "Didn't find %d ports available for " STR_FORMAT "/%s", + num_ports, STR_FMT(&loc->logical->name), sockaddr_print_buf(&loc->spec->local_address.addr)); return 0; } - __C_DBG("Found %d ports available for %.*s/%s from total of %d free ports", - num_ports, loc->logical->name.len, loc->logical->name.s, + __C_DBG("Found %d ports available for " STR_FORMAT "/%s from total of %d free ports", + num_ports, STR_FMT(&loc->logical->name), sockaddr_print_buf(&loc->spec->local_address.addr), loc->spec->port_pool.free_ports); @@ -1037,7 +1037,8 @@ void kernelize(struct packet_stream *stream) { if (stream->media->monologue->block_media || call->block_media) goto no_kernel; - ilog(LOG_INFO, "Kernelizing media stream: %s:%d", sockaddr_print_buf(&stream->endpoint.address), stream->endpoint.port); + ilog(LOG_INFO, "Kernelizing media stream: %s%s%s:%s%d%s", + FMT_M(sockaddr_print_buf(&stream->endpoint.address)), FMT_M(stream->endpoint.port)); sink = packet_stream_sink(stream); if (!sink) { @@ -1529,7 +1530,8 @@ static int media_packet_address_check(struct packet_handler_ctx *phc) int tmp = memcmp(&endpoint, &phc->mp.stream->endpoint, sizeof(endpoint)); if (tmp && PS_ISSET(phc->mp.stream, MEDIA_HANDOVER)) { /* out_lock remains locked */ - ilog(LOG_INFO, "Peer address changed to %s", endpoint_print_buf(&phc->mp.fsin)); + ilog(LOG_INFO, "Peer address changed to %s%s%s", + FMT_M(endpoint_print_buf(&phc->mp.fsin))); phc->unkernelize = 1; phc->update = 1; phc->mp.stream->endpoint = phc->mp.fsin; @@ -1539,10 +1541,11 @@ static int media_packet_address_check(struct packet_handler_ctx *phc) mutex_unlock(&phc->mp.stream->out_lock); if (tmp && PS_ISSET(phc->mp.stream, STRICT_SOURCE)) { - ilog(LOG_INFO, "Drop due to strict-source attribute; got %s:%d, expected %s:%d", - sockaddr_print_buf(&endpoint.address), endpoint.port, - sockaddr_print_buf(&phc->mp.stream->endpoint.address), - phc->mp.stream->endpoint.port); + ilog(LOG_INFO, "Drop due to strict-source attribute; got %s%s%s:%s%d%s, " + "expected %s%s%s:%s%d%s", + FMT_M(sockaddr_print_buf(&endpoint.address)), FMT_M(endpoint.port), + FMT_M(sockaddr_print_buf(&phc->mp.stream->endpoint.address)), + FMT_M(phc->mp.stream->endpoint.port)); atomic64_inc(&phc->mp.stream->stats.errors); ret = -1; goto out; @@ -1560,7 +1563,7 @@ static int media_packet_address_check(struct packet_handler_ctx *phc) phc->kernelize = 1; phc->update = 1; - ilog(LOG_INFO, "Confirmed peer address as %s", endpoint_print_buf(&phc->mp.fsin)); + ilog(LOG_INFO, "Confirmed peer address as %s%s%s", FMT_M(endpoint_print_buf(&phc->mp.fsin))); PS_SET(phc->mp.stream, CONFIRMED); @@ -1727,7 +1730,7 @@ static int stream_packet(struct packet_handler_ctx *phc) { if (G_UNLIKELY(!phc->sink || !phc->sink->selected_sfd || !phc->out_srtp || !phc->out_srtp->selected_sfd || !phc->in_srtp->selected_sfd)) { - ilog(LOG_WARNING, "RTP packet from %s discarded", endpoint_print_buf(&phc->mp.fsin)); + ilog(LOG_WARNING, "RTP packet from %s%s%s discarded", FMT_M(endpoint_print_buf(&phc->mp.fsin))); atomic64_inc(&phc->mp.stream->stats.errors); atomic64_inc(&rtpe_statsps.errors); goto out; diff --git a/daemon/recording.c b/daemon/recording.c index 30ac94405..4623475ee 100644 --- a/daemon/recording.c +++ b/daemon/recording.c @@ -376,13 +376,13 @@ static char *meta_setup_file(struct recording *recording) { // coverity[check_return : FALSE] chmod(meta_filepath, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH); if (mfp == NULL) { - ilog(LOG_ERROR, "Could not open metadata file: %s", meta_filepath); + ilog(LOG_ERROR, "Could not open metadata file: %s%s%s", FMT_M(meta_filepath)); free(meta_filepath); recording->meta_filepath = NULL; return NULL; } recording->u.pcap.meta_fp = mfp; - ilog(LOG_DEBUG, "Wrote metadata file to temporary path: %s", meta_filepath); + ilog(LOG_DEBUG, "Wrote metadata file to temporary path: %s%s%s", FMT_M(meta_filepath)); return meta_filepath; } diff --git a/daemon/redis.c b/daemon/redis.c index 0f1c184c5..99ab39e7a 100644 --- a/daemon/redis.c +++ b/daemon/redis.c @@ -321,7 +321,7 @@ void on_redis_notification(redisAsyncContext *actx, void *reply, void *privdata) goto err; for (int j = 0; j < rr->elements; j++) { - rlog(LOG_DEBUG, "Redis-Notify: %u) %s\n", j, rr->element[j]->str); + rlog(LOG_DEBUG, "Redis-Notify: %u) %s%s%s\n", j, FMT_M(rr->element[j]->str)); } if (rr->elements != 4) @@ -813,7 +813,7 @@ static int json_get_hash(struct redis_hash *out, char* tmp = strdup(*members); if (g_hash_table_insert_check(out->ht, tmp, val) != TRUE) { - ilog(LOG_WARNING,"Key %s already exists", tmp); + rlog(LOG_WARNING,"Key %s already exists", tmp); goto err3; } @@ -1664,7 +1664,8 @@ err1: freeReplyObject(rr_jsonStr); log_info_clear(); if (err) { - rlog(LOG_WARNING, "Failed to restore call ID '" STR_FORMAT "' from Redis: %s", STR_FMT(callid), + rlog(LOG_WARNING, "Failed to restore call ID '" STR_FORMAT_M "' from Redis: %s", + STR_FMT_M(callid), err); if (c) call_destroy(c); @@ -1690,7 +1691,7 @@ static void restore_thread(void *call_p, void *ctx_p) { str callid; str_init_len(&callid, call->str, call->len); - rlog(LOG_DEBUG, "Processing call ID '%.*s' from Redis", REDIS_FMT(call)); + rlog(LOG_DEBUG, "Processing call ID '%s%.*s%s' from Redis", FMT_M(REDIS_FMT(call))); mutex_lock(&ctx->r_m); r = g_queue_pop_head(&ctx->r_q); diff --git a/daemon/rtcp.c b/daemon/rtcp.c index 71c412ddb..dc3342804 100644 --- a/daemon/rtcp.c +++ b/daemon/rtcp.c @@ -1240,8 +1240,8 @@ 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 %x to %x", - ctx->scratch_common_ssrc, ctx->mp->ssrc_in->ssrc_map_out); + ilog(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) { if (!ctx->mp->ssrc_in) @@ -1271,8 +1271,8 @@ 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 %x to %x: %u packets, %u lost, %u duplicates", - ctx->scratch.rr.ssrc, map_ctx->ssrc_map_out, + ilog(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); if (G_UNLIKELY(tot_lost > 0xffffff)) diff --git a/daemon/ssrc.c b/daemon/ssrc.c index ea8e845f0..10fa185cf 100644 --- a/daemon/ssrc.c +++ b/daemon/ssrc.c @@ -137,8 +137,9 @@ restart: while (G_UNLIKELY(ht->q.length > 20)) { // arbitrary limit g_queue_sort(&ht->q, ssrc_time_cmp, NULL); struct ssrc_entry *old_ent = g_queue_pop_head(&ht->q); - ilog(LOG_DEBUG, "SSRC hash table exceeded size limit (trying to add %x) - deleting SSRC %x", - ssrc, old_ent->ssrc); + ilog(LOG_DEBUG, "SSRC hash table exceeded size limit (trying to add %s%x%s) - " + "deleting SSRC %s%x%s", + FMT_M(ssrc), FMT_M(old_ent->ssrc)); g_atomic_pointer_set(&ht->cache, NULL); g_hash_table_remove(ht->ht, &old_ent->ssrc); // does obj_put obj_put(old_ent); // for the queue entry @@ -272,7 +273,7 @@ found:; mutex_unlock(&e->h.lock); rtt -= (long long) delay * 1000000LL / 65536LL; - ilog(LOG_DEBUG, "Calculated round-trip time for %x is %lli us", ssrc, rtt); + ilog(LOG_DEBUG, "Calculated round-trip time for %s%x%s is %lli us", FMT_M(ssrc), rtt); if (rtt <= 0 || rtt > 10000000) { ilog(LOG_DEBUG, "Invalid RTT - discarding"); @@ -298,8 +299,8 @@ void ssrc_sender_report(struct call_media *m, const struct ssrc_sender_report *s seri->report = *sr; - ilog(LOG_DEBUG, "SR from %x: RTP TS %u PC %u OC %u NTP TS %u/%u=%f", - sr->ssrc, sr->timestamp, sr->packet_count, sr->octet_count, + ilog(LOG_DEBUG, "SR from %s%x%s: RTP TS %u PC %u OC %u NTP TS %u/%u=%f", + FMT_M(sr->ssrc), sr->timestamp, sr->packet_count, sr->octet_count, sr->ntp_msw, sr->ntp_lsw, seri->time_item.ntp_ts); mutex_unlock(&e->lock); @@ -310,8 +311,8 @@ void ssrc_receiver_report(struct call_media *m, const struct ssrc_receiver_repor { struct call *c = m->call; - ilog(LOG_DEBUG, "RR from %x about %x: FL %u TL %u HSR %u J %u LSR %u DLSR %u", - rr->from, rr->ssrc, rr->fraction_lost, rr->packets_lost, + ilog(LOG_DEBUG, "RR from %s%x%s about %s%x%s: FL %u TL %u HSR %u J %u LSR %u DLSR %u", + FMT_M(rr->from), FMT_M(rr->ssrc), rr->fraction_lost, rr->packets_lost, rr->high_seq_received, rr->jitter, rr->lsr, rr->dlsr); int pt; @@ -335,7 +336,7 @@ void ssrc_receiver_report(struct call_media *m, const struct ssrc_receiver_repor goto out_nl_put; } unsigned int jitter = rpt->clock_rate ? (rr->jitter * 1000 / rpt->clock_rate) : rr->jitter; - ilog(LOG_DEBUG, "Calculated jitter for %x is %u ms", rr->ssrc, jitter); + ilog(LOG_DEBUG, "Calculated jitter for %s%x%s is %u ms", FMT_M(rr->ssrc), jitter); ilog(LOG_DEBUG, "Adding opposide side RTT of %u us", other_e->last_rtt); @@ -348,7 +349,7 @@ void ssrc_receiver_report(struct call_media *m, const struct ssrc_receiver_repor }; mos_calc(ssb); - ilog(LOG_DEBUG, "Calculated MOS from RR for %x is %.1f", rr->from, (double) ssb->mos / 10.0); + ilog(LOG_DEBUG, "Calculated MOS from RR for %s%x%s is %.1f", FMT_M(rr->from), (double) ssb->mos / 10.0); // got a new stats block, add it to reporting ssrc mutex_lock(&other_e->h.lock); @@ -397,8 +398,8 @@ void ssrc_receiver_rr_time(struct call_media *m, const struct ssrc_xr_rr_time *r if (!srti) return; - ilog(LOG_DEBUG, "XR RR TIME from %x: NTP TS %u/%u=%f", - rr->ssrc, + ilog(LOG_DEBUG, "XR RR TIME from %s%x%s: NTP TS %u/%u=%f", + FMT_M(rr->ssrc), rr->ntp_msw, rr->ntp_lsw, srti->time_item.ntp_ts); mutex_unlock(&e->lock); @@ -408,8 +409,8 @@ void ssrc_receiver_rr_time(struct call_media *m, const struct ssrc_xr_rr_time *r void ssrc_receiver_dlrr(struct call_media *m, const struct ssrc_xr_dlrr *dlrr, const struct timeval *tv) { - ilog(LOG_DEBUG, "XR DLRR from %x about %x: LRR %u DLRR %u", - dlrr->from, dlrr->ssrc, + ilog(LOG_DEBUG, "XR DLRR from %s%x%s about %s%x%s: LRR %u DLRR %u", + FMT_M(dlrr->from), FMT_M(dlrr->ssrc), dlrr->lrr, dlrr->dlrr); __calc_rtt(m->call, dlrr->ssrc, dlrr->lrr, dlrr->dlrr, @@ -419,10 +420,10 @@ void ssrc_receiver_dlrr(struct call_media *m, const struct ssrc_xr_dlrr *dlrr, void ssrc_voip_metrics(struct call_media *m, const struct ssrc_xr_voip_metrics *vm, const struct timeval *tv) { - ilog(LOG_DEBUG, "XR VM from %x about %x: LR %u DR %u BD %u GD %u BDu %u GDu %u RTD %u " + ilog(LOG_DEBUG, "XR VM from %s%x%s about %s%x%s: LR %u DR %u BD %u GD %u BDu %u GDu %u RTD %u " "ESD %u SL %u NL %u RERL %u GMin %u R %u eR %u MOSL %u MOSC %u RX %u " "JBn %u JBm %u JBam %u", - vm->from, vm->ssrc, + FMT_M(vm->from), FMT_M(vm->ssrc), vm->loss_rate, vm->discard_rate, vm->burst_den, vm->gap_den, vm->burst_dur, vm->gap_dur, vm->rnd_trip_delay, vm->end_sys_delay, vm->signal_lvl, vm->noise_lvl, vm->rerl, vm->gmin, vm->r_factor, diff --git a/daemon/stun.c b/daemon/stun.c index fe962bcfd..babe183ac 100644 --- a/daemon/stun.c +++ b/daemon/stun.c @@ -512,8 +512,8 @@ INLINE int u_int16_t_arr_len(u_int16_t *arr) { -#define SLF " from %s" -#define SLP endpoint_print_buf(sin) +#define SLF " from %s%s%s" +#define SLP FMT_M(endpoint_print_buf(sin)) static int __stun_request(struct stream_fd *sfd, const endpoint_t *sin, struct header *req, struct stun_attrs *attrs) { diff --git a/lib/auxlib.c b/lib/auxlib.c index d72e2fb79..030656451 100644 --- a/lib/auxlib.c +++ b/lib/auxlib.c @@ -105,6 +105,8 @@ void config_load(int *argc, char ***argv, GOptionEntry *app_entries, const char #else rtpe_common_config_ptr->log_level = LOG_DEBUG; #endif + rtpe_common_config_ptr->log_mark_prefix = ""; + rtpe_common_config_ptr->log_mark_suffix = ""; GOptionEntry shared_options[] = { { "version", 'v', 0, G_OPTION_ARG_NONE, &version, "Print build time and exit", NULL }, @@ -114,6 +116,8 @@ void config_load(int *argc, char ***argv, GOptionEntry *app_entries, const char { "log-level", 'L', 0, G_OPTION_ARG_INT, (void *)&rtpe_common_config_ptr->log_level,"Mask log priorities above this level","INT" }, { "log-stderr", 'E', 0, G_OPTION_ARG_NONE, &rtpe_common_config_ptr->log_stderr, "Log on stderr instead of syslog", 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 }, + { "log-mark-prefix", 0, 0, G_OPTION_ARG_STRING, &rtpe_common_config_ptr->log_mark_prefix,"Prefix for sensitive log info", NULL }, + { "log-mark-suffix", 0, 0, G_OPTION_ARG_STRING, &rtpe_common_config_ptr->log_mark_suffix,"Suffix for sensitive log info", NULL }, { "pidfile", 'p', 0, G_OPTION_ARG_FILENAME, &rtpe_common_config_ptr->pidfile, "Write PID to file", "FILE" }, { "foreground", 'f', 0, G_OPTION_ARG_NONE, &rtpe_common_config_ptr->foreground, "Don't fork to background", NULL }, { NULL, } diff --git a/lib/auxlib.h b/lib/auxlib.h index b0d44988c..5877a5e33 100644 --- a/lib/auxlib.h +++ b/lib/auxlib.h @@ -19,6 +19,8 @@ struct rtpengine_common_config { volatile int log_level; int log_stderr; int no_log_timestamps; + char *log_mark_prefix; + char *log_mark_suffix; char *pidfile; int foreground; }; diff --git a/lib/str.h b/lib/str.h index 1d48f4841..80172f73d 100644 --- a/lib/str.h +++ b/lib/str.h @@ -21,9 +21,16 @@ typedef struct _str str; #define STR_FORMAT "%.*s" +#define STR_FORMAT_M "%s%.*s%s" #define STR_FMT(str) (str)->len, (str)->s +#define STR_FMT_M(str) FMT_M(STR_FMT(str)) #define STR_FMT0(str) ((str) ? (str)->len : 6), ((str) ? (str)->s : "(NULL)") +#define STR_FMT0_M(str) FMT_M(STR_FMT0(str)) #define G_STR_FMT(gstr) (int) (gstr)->len, (gstr)->str // for glib GString + +#define FMT_M(x...) rtpe_common_config_ptr->log_mark_prefix, x, \ + rtpe_common_config_ptr->log_mark_suffix + #define STR_NULL ((str) { NULL, 0 }) #define STR_EMPTY ((str) { "", 0 }) #define STR_CONST_INIT(str) { str, sizeof(str)-1 } diff --git a/recording-daemon/db.c b/recording-daemon/db.c index 47c57a7e6..f665d0ce8 100644 --- a/recording-daemon/db.c +++ b/recording-daemon/db.c @@ -383,7 +383,7 @@ void db_close_stream(output_t *op) { strcat(filename, op->file_format); FILE *f = fopen(filename, "rb"); if (!f) { - ilog(LOG_ERR, "Failed to open file: %s", filename); + ilog(LOG_ERR, "Failed to open file: %s%s%s", FMT_M(filename)); if ((output_storage & OUTPUT_STORAGE_FILE)) goto file; free(filename); diff --git a/recording-daemon/decoder.c b/recording-daemon/decoder.c index b206e05ba..429ffbad0 100644 --- a/recording-daemon/decoder.c +++ b/recording-daemon/decoder.c @@ -35,7 +35,7 @@ decode_t *decoder_new(const char *payload_str, output_t *outp) { str_init_len(&name, (char *) payload_str, slash - payload_str); int clockrate = atoi(slash + 1); if (clockrate <= 0) { - ilog(LOG_ERR, "Invalid clock rate %i (parsed from '%.20s'/'%.20s'", + ilog(LOG_ERR, "Invalid clock rate %i (parsed from '%.20s'/'%.20s')", clockrate, slash + 1, payload_str); return NULL; } diff --git a/recording-daemon/inotify.c b/recording-daemon/inotify.c index 36af9017f..e6a54401f 100644 --- a/recording-daemon/inotify.c +++ b/recording-daemon/inotify.c @@ -20,13 +20,13 @@ static handler_t inotify_handler = { static void inotify_close_write(struct inotify_event *inev) { - dbg("inotify close_write(%s)", inev->name); + dbg("inotify close_write(%s%s%s)", FMT_M(inev->name)); metafile_change(inev->name); } static void inotify_delete(struct inotify_event *inev) { - dbg("inotify delete(%s)", inev->name); + dbg("inotify delete(%s%s%s)", FMT_M(inev->name)); metafile_delete(inev->name); } diff --git a/recording-daemon/log.c b/recording-daemon/log.c index 2a14a3494..e4fd2889f 100644 --- a/recording-daemon/log.c +++ b/recording-daemon/log.c @@ -16,11 +16,11 @@ void __ilog(int prio, const char *fmt, ...) { char *endp = prefix + sizeof(prefix); if (log_info_call) - pp += snprintf(pp, endp - pp, "[C %s] ", log_info_call); + pp += snprintf(pp, endp - pp, "[C %s%s%s] ", FMT_M(log_info_call)); if (log_info_stream) - pp += snprintf(pp, endp - pp, "[S %s] ", log_info_stream); + pp += snprintf(pp, endp - pp, "[S %s%s%s] ", FMT_M(log_info_stream)); if (log_info_ssrc) - pp += snprintf(pp, endp - pp, "[0x%lx] ", log_info_ssrc); + pp += snprintf(pp, endp - pp, "[%s0x%lx%s] ", FMT_M(log_info_ssrc)); va_start(ap, fmt); __vpilog(prio, prefix, fmt, ap); diff --git a/recording-daemon/metafile.c b/recording-daemon/metafile.c index 451add550..9b98885ff 100644 --- a/recording-daemon/metafile.c +++ b/recording-daemon/metafile.c @@ -25,7 +25,7 @@ static GHashTable *metafiles; static void meta_free(void *ptr) { metafile_t *mf = ptr; - dbg("freeing metafile info for %s", mf->name); + dbg("freeing metafile info for %s%s%s", FMT_M(mf->name)); output_close(mf->mix_out); mix_destroy(mf->mix); g_string_chunk_free(mf->gsc); @@ -57,7 +57,7 @@ static void meta_destroy(metafile_t *mf) { } //close forward socket if (mf->forward_fd >= 0) { - dbg("call [%s] forwarded %d packets. %d failed sends.", mf->call_id, + dbg("call [%s%s%s] forwarded %d packets. %d failed sends.", FMT_M(mf->call_id), (int )g_atomic_int_get(&mf->forward_count), (int )g_atomic_int_get(&mf->forward_failed)); close(mf->forward_fd); @@ -81,7 +81,7 @@ static void meta_stream_interface(metafile_t *mf, unsigned long snum, char *cont } pthread_mutex_unlock(&mf->mix_lock); } - dbg("stream %lu interface %s", snum, content); + dbg("stream %lu interface %s%s%s", snum, FMT_M(content)); stream_open(mf, snum, content); } @@ -164,7 +164,7 @@ static metafile_t *metafile_get(char *name) { if (mf) goto out; - dbg("allocating metafile info for %s", name); + dbg("allocating metafile info for %s%s%s", FMT_M(name)); mf = g_slice_alloc0(sizeof(*mf)); mf->gsc = g_string_chunk_new(0); mf->name = g_string_chunk_insert(mf->gsc, name); @@ -202,11 +202,11 @@ void metafile_change(char *name) { // open file and seek to last known position int fd = open(fnbuf, O_RDONLY); if (fd == -1) { - ilog(LOG_ERR, "Failed to open %s: %s", fnbuf, strerror(errno)); + ilog(LOG_ERR, "Failed to open %s%s%s: %s", FMT_M(fnbuf), strerror(errno)); goto out; } if (lseek(fd, mf->pos, SEEK_SET) == (off_t) -1) { - ilog(LOG_ERR, "Failed to seek to end of file %s: %s", fnbuf, strerror(errno)); + ilog(LOG_ERR, "Failed to seek to end of file %s%s%s: %s", FMT_M(fnbuf), strerror(errno)); close(fd); goto out; } @@ -235,11 +235,11 @@ void metafile_change(char *name) { // section header char *nl = memchr(head, '\n', endp - head); if (!nl || nl == head) { - ilog(LOG_WARN, "Missing section header in %s", name); + ilog(LOG_WARN, "Missing section header in %s%s%s", FMT_M(name)); break; } if (memchr(head, '\0', nl - head)) { - ilog(LOG_WARN, "NUL character in section header in %s", name); + ilog(LOG_WARN, "NUL character in section header in %s%s%s", FMT_M(name)); break; } *(nl++) = '\0'; @@ -250,18 +250,18 @@ void metafile_change(char *name) { // content length nl = memchr(head, ':', endp - head); if (!nl || nl == head) { - ilog(LOG_WARN, "Content length for section %s missing in %s", section, name); + ilog(LOG_WARN, "Content length for section %s missing in %s%s%s", section, FMT_M(name)); break; } *(nl++) = '\0'; if (*(nl++) != '\n') { - ilog(LOG_WARN, "Unterminated content length for section %s in %s", section, name); + ilog(LOG_WARN, "Unterminated content length for section %s in %s%s%s", section, FMT_M(name)); break; } char *errp; unsigned long slen = strtoul(head, &errp, 10); if (*errp != '\0') { - ilog(LOG_WARN, "Invalid content length for section %s in %s", section, name); + ilog(LOG_WARN, "Invalid content length for section %s in %s%s%s", section, FMT_M(name)); break; } dbg("content length %lu", slen); @@ -269,19 +269,19 @@ void metafile_change(char *name) { // content if (endp - head < slen) { - ilog(LOG_WARN, "Content truncated in section %s in %s", section, name); + ilog(LOG_WARN, "Content truncated in section %s in %s%s%s", section, FMT_M(name)); break; } char *content = head; if (memchr(content, '\0', slen)) { - ilog(LOG_WARN, "NUL character in content in section %s in %s", section, name); + ilog(LOG_WARN, "NUL character in content in section %s in %s%s%s", section, FMT_M(name)); break; } // double newline separator head += slen; if (*head != '\n' || *(head + 1) != '\n') { - ilog(LOG_WARN, "Separator missing after section %s in %s", section, name); + ilog(LOG_WARN, "Separator missing after section %s in %s%s%s", section, FMT_M(name)); break; } *head = '\0'; diff --git a/recording-daemon/output.c b/recording-daemon/output.c index 4a597d74b..d2640b855 100644 --- a/recording-daemon/output.c +++ b/recording-daemon/output.c @@ -23,10 +23,10 @@ static void output_shutdown(output_t *output); static int output_got_packet(encoder_t *enc, void *u1, void *u2) { output_t *output = u1; - dbg("{%s} output avpkt size is %i", output->file_name, (int) enc->avpkt.size); - dbg("{%s} output pkt pts/dts is %li/%li", output->file_name, (long) enc->avpkt.pts, + dbg("{%s%s%s} output avpkt size is %i", FMT_M(output->file_name), (int) enc->avpkt.size); + dbg("{%s%s%s} output pkt pts/dts is %li/%li", FMT_M(output->file_name), (long) enc->avpkt.pts, (long) enc->avpkt.dts); - dbg("{%s} output dts %li", output->file_name, (long) output->encoder->mux_dts); + dbg("{%s%s%s} output dts %li", FMT_M(output->file_name), (long) output->encoder->mux_dts); av_write_frame(output->fmtctx, &enc->avpkt); diff --git a/recording-daemon/packet.c b/recording-daemon/packet.c index 4729229ee..d423eb81d 100644 --- a/recording-daemon/packet.c +++ b/recording-daemon/packet.c @@ -174,7 +174,7 @@ out: pthread_mutex_lock(&ret->lock); pthread_mutex_unlock(&mf->lock); - dbg("Init for SSRC %lx of stream #%lu", ret->ssrc, stream->id); + dbg("Init for SSRC %s%lx%s of stream #%lu", FMT_M(ret->ssrc), stream->id); if (mf->recording_on && !ret->output && output_single) { char buf[256];