TT#45617 add new options to support log markers for sensitive data

Change-Id: I2ffa4da4be3a05f043e7991612bbb37d8102d91a

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, &paramsbuf));
+					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",
+		ilog(LOG_DEBUG, "[%i] Initialized outgoing SRTP with SDES crypto params: %s%s%s",
 				ps->component,
-				crypto_params_sdes_dump(cps, &paramsbuf));
+				FMT_M(crypto_params_sdes_dump(cps, &paramsbuf)));
 	}
 
 	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;
 	}

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);
 	}

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);

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);
 			}

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);

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);

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;
 }

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;
 	}

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));
 

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;

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;
 }
 

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);

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))

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,

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)
 {

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, }

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;
 };

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 }

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);

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;
 	}

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);
 }
 

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);

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';

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);
 

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];