SIP plugin: add logger callback function for processing SIP message t…

…races in a single log callback for Sofia >= 1.13 (#3386)

plugins/janus_sip.c

@@ -1687,7 +1687,7 @@ static void janus_sip_parse_custom_contact_params(json_t *root, char *custom_par
 char sofia_log[3072];
 char call_id[255];
 gboolean skip = FALSE, started = FALSE, append = FALSE;
-static void janus_sip_sofia_logger(void *stream, char const *fmt, va_list ap) {
+static void janus_sip_sofia_logger_siptrace_multi_log_callback(void *stream, char const *fmt, va_list ap) {
 	if(!fmt)
 		return;
 	char line[255];
@@ -1800,6 +1800,92 @@ static void janus_sip_sofia_logger(void *stream, char const *fmt, va_list ap) {
 	}
 }
 
+static void janus_sip_sofia_logger_siptrace_single_log_callback(void *stream, char const *fmt, va_list ap) {
+	/* Since the fmt format string in the current Sofia SIP tport_log_msg function implementation is just "%s\n",
+	 * it's more efficient to directly work with the siptrace buffer. */
+	char *buffer = va_arg(ap, char *);
+
+	/* Check if this is a message we need */
+	if(strstr(buffer, "send ") == buffer) {
+		/* An outgoing message is going to be logged, prepare for that */
+		int length = atoi(&buffer[5]);
+		JANUS_LOG(LOG_HUGE, "Intercepting message (%d bytes)\n", length);
+		/* Skip the stamp line */
+		buffer = strchr(buffer, '\n');
+		if(!buffer) {
+			JANUS_LOG(LOG_WARN, "No newline after the stamp in this message, dropping it...\n");
+			return;
+		}
+		buffer++;
+		/* Skip the separator line */
+		buffer = strchr(buffer, '\n');
+		if(!buffer) {
+			JANUS_LOG(LOG_WARN, "No newline after the separator in this message, dropping it...\n");
+			return;
+		}
+		buffer++;
+		/* If this is an OPTIONS, we don't care: drop it */
+		if(strstr(buffer, "OPTIONS") == buffer)
+			return;
+		/* Search for the Call-ID header and extract its value if it exists */
+		char *from = strstr(buffer, "Call-ID: ");
+		if(from) {
+			char *start = from + 9;
+			if(start) {
+				char *end = strchr(start, '\n');
+				if(end) {
+					size_t count = end - start;
+					count = count >= sizeof(call_id) ? sizeof(call_id) - 1 : count;
+					memcpy(call_id, start, count);
+					call_id[count] = '\0';
+				}
+			}
+		}
+		/* Look for the session this message belongs to */
+		janus_sip_session *session = NULL;
+		janus_mutex_lock(&sessions_mutex);
+		if(strlen(call_id))
+			session = g_hash_table_lookup(callids, call_id);
+		if(!session) {
+			/* Couldn't find any SIP session with that Call-ID, check the request */
+			if(strstr(buffer, "REGISTER") == buffer || strstr(buffer, "SIP/2.0 ") == buffer) {
+				/* FIXME This is a REGISTER or a response code:
+				* check the To header and get the identity from there */
+				char *from = strstr(buffer, "To: ");
+				if(from) {
+					char *start = strstr(from + 4, "<");
+					if(start) {
+						start++;
+						char *end = strstr(from, ">");
+						if(end) {
+							size_t count = end - start;
+							count = count >= sizeof(call_id) ? sizeof(call_id) - 1 : count;
+							memcpy(call_id, start, count);
+							call_id[count] = '\0';
+							session = g_hash_table_lookup(identities, call_id);
+						}
+					}
+				}
+			}
+		}
+		if(session)
+			janus_refcount_increase(&session->ref);
+		janus_mutex_unlock(&sessions_mutex);
+		if(session) {
+			/* Notify event handlers about the content of the whole outgoing SIP message */
+			json_t *info = json_object();
+			json_object_set_new(info, "event", json_string("sip-out"));
+			json_object_set_new(info, "sip", json_string(buffer));
+			gateway->notify_event(&janus_sip_plugin, session->handle, info);
+			janus_refcount_decrease(&session->ref);
+		} else {
+			JANUS_LOG(LOG_WARN, "Couldn't find a session associated to this message, dropping it...\n%s", buffer);
+		}
+	}
+}
+
+static su_logger_f *janus_sip_sofia_logger = janus_sip_sofia_logger_siptrace_multi_log_callback;
+
 /* Helpers to ref/unref sessions with active calls */
 static void janus_sip_ref_active_call(janus_sip_session *session) {
 	if(session == NULL)
@@ -1857,6 +1943,9 @@ int janus_sip_init(janus_callbacks *callback, const char *config_path) {
 			/* Versions of Sofia SIP >= 1.13 apparently don't add a Contact header in
 			 * dialogs, so we'll query it ourselves using nua_get_params (see #2597) */
 			query_contact_header = TRUE;
+			/* In Sofia SIP versions >= 1.13, the su_log_redirect callback function is called only once for the entire SIP message trace.
+			 * In prior versions, the su_log_redirect callback function was called line by line. */
+			janus_sip_sofia_logger = janus_sip_sofia_logger_siptrace_single_log_callback;
 		}
 	}