TELECOM-11605: Add extra logs

modules/tm/async.c

@@ -320,7 +320,10 @@ int t_handle_async(struct sip_msg *msg, struct action* a,
 	}
 
 	if (route_type!=REQUEST_ROUTE) {
-		LM_WARN("async detected in non-request route, switching to sync\n");
+		LM_WARN("async detected in non-request route, switching to sync (extra debug info: Call-Id: %.*s, User-Agent: %.*s)\n",
+				(msg->callid ? msg->callid->body.len : 3), (msg->callid ? msg->callid->body.s : "N/A"),
+				(msg->user_agent ? msg->user_agent->body.len : 3), (msg->user_agent ? msg->user_agent->body.s : "N/A")
+		);
 		goto sync;
 	}
 

receive.c

@@ -287,8 +287,29 @@ int receive_msg(char* buf, unsigned int len, struct receive_info* rcv_info,
 end:
 	reset_global_context();
 
-	__stop_expire_timer( start, execmsgthreshold, "msg processing",
-		msg->buf, msg->len, 0, slow_msgs);
+	if (msg) {
+		const char *fmt = "(extra debug info: Call-Id: %.*s, User-Agent: %.*s)";
+
+		int callid_len = (msg->callid ? msg->callid->body.len : 3);
+		const char *callid_str = (msg->callid ? msg->callid->body.s : "N/A");
+
+		int ua_len = (msg->user_agent ? msg->user_agent->body.len : 3);
+		const char *ua_str = (msg->user_agent ? msg->user_agent->body.s : "N/A");
+
+		int size = strlen(fmt) - 8 + callid_len + ua_len + 1;
+
+		char *buf = pkg_malloc(size);
+		if (buf) {
+			snprintf(buf, size, fmt, callid_len, callid_str, ua_len, ua_str);
+			__stop_expire_timer(start, execmsgthreshold, "msg processing",
+				buf, size, 0, slow_msgs);
+			pkg_free(buf);
+		} else {
+			__stop_expire_timer(start, execmsgthreshold, "msg processing",
+				NULL, 0, 0, slow_msgs);
+		}
+	}
+
 	reset_longest_action_list(execmsgthreshold);
 
 	/* free possible loaded avps -bogdan */

ut.h

@@ -1370,7 +1370,7 @@ static inline void log_expiry(int time_diff,int expire,
 				tcp_timeout_con_get;
 		} else
 			LM_WARN("threshold exceeded : %s took too long - %d us."
-					"Source : %.*s\n",func_info,time_diff,dbg_len,redact_pii(extra_dbg));
+					"Source : %.*s\n",func_info,time_diff,dbg_len,(strncmp(func_info, "msg", 3) == 0 ? extra_dbg : redact_pii(extra_dbg)));
 
 		if (memcmp(func_info,"msg",3) == 0) {
 			for (i=0;i<LONGEST_ACTION_SIZE;i++) {