-
Notifications
You must be signed in to change notification settings - Fork 2.5k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Use different callback functions to get SIP log messages for Sofia-SIP 1.12 and Sofia-SIP 1.13. #3063
Use different callback functions to get SIP log messages for Sofia-SIP 1.12 and Sofia-SIP 1.13. #3063
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -867,6 +867,7 @@ static char *sips_certs_dir = NULL; | |
static int sip_timer_t1x64 = JANUS_DEFAULT_SIP_TIMER_T1X64; | ||
|
||
static gboolean query_contact_header = FALSE; | ||
static gboolean message_log_single_callback = FALSE; | ||
|
||
static GThread *handler_thread; | ||
static void *janus_sip_handler(void *data); | ||
|
@@ -1771,6 +1772,127 @@ static void janus_sip_sofia_logger(void *stream, char const *fmt, va_list ap) { | |
} | ||
} | ||
|
||
/* Sofia SIP logger function: when the Event Handlers mechanism is enabled, | ||
* we use this to intercept SIP messages sent by the stack (received | ||
* messages are more easily recoverable in janus_sip_sofia_callback) */ | ||
static void janus_sip_sofia_logger_single(void *stream, char const *fmt, va_list ap) { | ||
if(!fmt) | ||
return; | ||
char line[255]; | ||
char message[16000]; | ||
char sofia_log_buf[16000]; | ||
char call_id_hdr[255]; | ||
sofia_log_buf[0] = '\0'; | ||
call_id_hdr[0] = '\0'; | ||
#pragma GCC diagnostic push | ||
#pragma GCC diagnostic ignored "-Wformat-nonliteral" | ||
#ifndef __clang__ | ||
#pragma GCC diagnostic push | ||
#pragma GCC diagnostic ignored "-Wsuggest-attribute=format" | ||
#endif | ||
g_vsnprintf(line, sizeof(message), fmt, ap); | ||
#ifndef __clang__ | ||
#pragma GCC diagnostic pop | ||
#endif | ||
#pragma GCC diagnostic pop | ||
gchar **parts = g_strsplit(message, "\n", -1); | ||
if (parts) { | ||
int index = 0; | ||
char *line = NULL, *cr = NULL; | ||
while((line = parts[index]) != NULL) { | ||
cr = strchr(line, '\r'); | ||
if(cr != NULL) | ||
*cr = '\0'; | ||
if(*line == '\0') { | ||
if(cr != NULL) | ||
*cr = '\r'; | ||
index++; | ||
continue; | ||
} | ||
|
||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Empty line is unneeded here. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I will remove it |
||
/* First line of the log indicates if we send or receive a message. */ | ||
/* We are only interested in the sent ones */ | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. "send or receive" should be "sent or received I guess?
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Will fix both. |
||
if(index==0) { | ||
if(strstr(line, "send ") == line) { | ||
int length = atoi(line+5); | ||
JANUS_LOG(LOG_HUGE, "Intercepting message (%d bytes)\n", length); | ||
index++; | ||
continue; | ||
} | ||
g_strfreev(parts); | ||
return ; | ||
} | ||
|
||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Unneeded empty line. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I will remove it |
||
if(strlen(line) == 1) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. @lminiero pedantic warning that's not exactly equivalent (note that in #3059 we only changed calls doing greater than or less than comparisons since the results were guaranteed not to change) although AFACT it should be safe to change this like you say:
|
||
/* Append a carriage and return */ | ||
janus_strlcat(sofia_log_buf, "\r\n", sizeof(sofia_log_buf)); | ||
} else if(strstr(line, "-") == line ) { | ||
index++; | ||
continue; | ||
} else if(strstr(line, "OPTIONS") == line) { | ||
index++; | ||
continue; | ||
} else { | ||
/* Is this a Call-ID header? Keep note of it */ | ||
if(strstr(line, "Call-ID") == line) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Per code style, since the action is simple there's no need for curly brackets. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This part already exists in the janus_sip_sofia_logger callback function (the one for line-by-line logs). I can fix it in both functions if you want. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Ouch, I ended up reviewing my own ugly code 🤭 |
||
g_snprintf(call_id_hdr, sizeof(call_id_hdr), "%s", line+9); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Why is this 9? Are you assuming There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This also existed in janus_sip_sofia_logger. I suppose it's safe to assume that "Call-ID: " will always be sent with this format, as it is Sofia-SIP library the one that generates those messages and we only process the messages sent from Sofia SIP stack. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Makes sense! |
||
} | ||
/* Append the line to our buffer, skipping the indent */ | ||
janus_strlcat(sofia_log_buf, line, sizeof(sofia_log_buf)); | ||
janus_strlcat(sofia_log_buf, "\r\n", sizeof(sofia_log_buf)); | ||
} | ||
if(cr != NULL) | ||
*cr = '\r'; | ||
index++; | ||
} | ||
g_strfreev(parts); | ||
} else { | ||
return; | ||
} | ||
|
||
/* Look for the session this message belongs to */ | ||
janus_sip_session *session = NULL; | ||
janus_mutex_lock(&sessions_mutex); | ||
if(strlen(call_id_hdr)) | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This should be changed to
otherwise I'm not sure if the compiler optimizations discussed in #3059 will kick in. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. From a cursory check of a few compilers (e.g., https://godbolt.org/z/enodKdhMc) So you can use whichever you find more readable. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Thanks for checking! |
||
session = g_hash_table_lookup(callids, call_id_hdr); | ||
if(!session) { | ||
/* Couldn't find any SIP session with that Call-ID, check the request */ | ||
if(strstr(sofia_log_buf, "REGISTER") == sofia_log_buf || strstr(sofia_log_buf, "SIP/2.0 ") == sofia_log) { | ||
/* FIXME This is a REGISTER or a response code: | ||
* check the To header and get the identity from there */ | ||
char *from = strstr(sofia_log_buf, "To: "); | ||
if(from) { | ||
from = from+4; | ||
char *start = strstr(from, "<"); | ||
if(start) { | ||
start++; | ||
char *end = strstr(from, ">"); | ||
if(end) { | ||
*end = '\0'; | ||
g_snprintf(call_id_hdr, sizeof(call_id_hdr), "%s", start); | ||
*end = '>'; | ||
session = g_hash_table_lookup(identities, call_id_hdr); | ||
} | ||
} | ||
} | ||
} | ||
} | ||
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(sofia_log_buf)); | ||
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", sofia_log_buf); | ||
} | ||
return; | ||
} | ||
|
||
/* Helpers to ref/unref sessions with active calls */ | ||
static void janus_sip_ref_active_call(janus_sip_session *session) { | ||
if(session == NULL) | ||
|
@@ -1828,6 +1950,10 @@ 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 >= 1.13 versions the full SIP message is received in the | ||
* su_log_redirect callback function. In prior versions the callback function | ||
* was called line by line. */ | ||
message_log_single_callback = TRUE; | ||
} | ||
} | ||
|
||
|
@@ -1997,7 +2123,11 @@ int janus_sip_init(janus_callbacks *callback, const char *config_path) { | |
JANUS_LOG(LOG_WARN, "sofia-sip logs are going to be redirected and they will not be shown in the process output\n"); | ||
/* Enable the transport logging, as we want to have access to the SIP messages */ | ||
setenv("TPORT_LOG", "1", 1); | ||
su_log_redirect(NULL, janus_sip_sofia_logger, NULL); | ||
if(message_log_single_callback) { | ||
su_log_redirect(NULL, janus_sip_sofia_logger_single, NULL); | ||
} else { | ||
su_log_redirect(NULL, janus_sip_sofia_logger, NULL); | ||
} | ||
} | ||
|
||
sessions = g_hash_table_new_full(NULL, NULL, NULL, (GDestroyNotify)janus_sip_session_destroy); | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
These buffers are way too large.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I set those values to match the maximum buffer that Sofia SIP defines in https://github.com/freeswitch/sofia-sip/blob/master/libsofia-sip-ua/tport/tport_logging.c#L843
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think it's still too large of a buffer, especially to create any time the function is called. The SIP SDPs in Janus are never very large, so I'd put a cap on it. PR #3060 for instance set it to 3072 because in their experience the buffer never went beyond that.