From ab37492bfae9e809b2e2eaa73f1d7e47bd2fdeb3 Mon Sep 17 00:00:00 2001 From: Yurii Cherniavskyi Date: Fri, 31 May 2024 12:33:49 +0300 Subject: [PATCH 1/4] Add logger callback function for processing SIP message traces in a single log callback for Sofia >= 1.13 --- src/plugins/janus_sip.c | 94 ++++++++++++++++++++++++++++++++++++++++- 1 file changed, 93 insertions(+), 1 deletion(-) diff --git a/src/plugins/janus_sip.c b/src/plugins/janus_sip.c index ddc1740aff..e06e296c96 100644 --- a/src/plugins/janus_sip.c +++ b/src/plugins/janus_sip.c @@ -1688,7 +1688,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]; @@ -1801,6 +1801,95 @@ 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(buffer[0] == 's' && buffer[1] == 'e' && buffer[2] == 'n' && buffer[3] == 'd' && buffer[4] == ' ') { + /* 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) @@ -1858,6 +1947,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; } } From 5c3faefc4bdf351c691164c3497f85b267ac0684 Mon Sep 17 00:00:00 2001 From: Yurii Cherniavskyi Date: Mon, 24 Jun 2024 18:40:59 +0300 Subject: [PATCH 2/4] Safely check that buffer begins with the string "send " --- src/plugins/janus_sip.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/plugins/janus_sip.c b/src/plugins/janus_sip.c index e06e296c96..12f0512875 100644 --- a/src/plugins/janus_sip.c +++ b/src/plugins/janus_sip.c @@ -1807,7 +1807,7 @@ static void janus_sip_sofia_logger_siptrace_single_log_callback(void *stream, ch char *buffer = va_arg(ap, char *); /* Check if this is a message we need */ - if(buffer[0] == 's' && buffer[1] == 'e' && buffer[2] == 'n' && buffer[3] == 'd' && buffer[4] == ' ') { + 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); From 2dc0e051459a2d8e7e7debff848484ee190356c1 Mon Sep 17 00:00:00 2001 From: Yurii Cherniavskyi Date: Mon, 24 Jun 2024 18:46:59 +0300 Subject: [PATCH 3/4] Get rid of excess brackets --- src/plugins/janus_sip.c | 22 ++++++++++------------ 1 file changed, 10 insertions(+), 12 deletions(-) diff --git a/src/plugins/janus_sip.c b/src/plugins/janus_sip.c index 12f0512875..8a119ce1f9 100644 --- a/src/plugins/janus_sip.c +++ b/src/plugins/janus_sip.c @@ -1829,18 +1829,16 @@ static void janus_sip_sofia_logger_siptrace_single_log_callback(void *stream, ch 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'; - } + 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'; } } } From 9db264ab9131d81b7752cc0b617cd27721a65c7e Mon Sep 17 00:00:00 2001 From: Yurii Cherniavskyi Date: Mon, 24 Jun 2024 18:47:53 +0300 Subject: [PATCH 4/4] Get rid of excess empty line --- src/plugins/janus_sip.c | 1 - 1 file changed, 1 deletion(-) diff --git a/src/plugins/janus_sip.c b/src/plugins/janus_sip.c index 8a119ce1f9..e0391c55cf 100644 --- a/src/plugins/janus_sip.c +++ b/src/plugins/janus_sip.c @@ -1863,7 +1863,6 @@ static void janus_sip_sofia_logger_siptrace_single_log_callback(void *stream, ch 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); } }