From 3cc60ac279722d89ea5214fab0d376f440535f90 Mon Sep 17 00:00:00 2001 From: Stefan Becker Date: Sat, 19 Jun 2010 23:38:52 +0300 Subject: [PATCH] debug: refactor message debugging New function sipe_utils_message_debug() handles all message debugging needs. This not only removes code duplication but also ensures that all messages use the same format in the log. That will make life easier for a debug analyzer script, an idea I've had in my head for some time now. The message format will probably have to be refined in conjunction with the development of such an analyzer. fix_newlines() removed. --- src/api/sipe-core.h | 1 - src/core/http-conn.c | 23 ++++++++++------------- src/core/sip-transport.c | 26 ++++++++++++++------------ src/core/sipe-incoming.c | 6 ------ src/core/sipe-utils.c | 29 ++++++++++++++++++++++++++--- src/core/sipe-utils.h | 14 ++++++++++---- src/core/sipe-xml-tests.c | 4 ++++ src/core/sipe.c | 6 ------ src/purple/purple-transport.c | 9 --------- 9 files changed, 64 insertions(+), 54 deletions(-) diff --git a/src/api/sipe-core.h b/src/api/sipe-core.h index 3905a49e..4a0b5894 100644 --- a/src/api/sipe-core.h +++ b/src/api/sipe-core.h @@ -150,7 +150,6 @@ void sipe_core_destroy(void); /** Utility functions exported by the core to backends ***********************/ gboolean sipe_strequal(const gchar *left, const gchar *right); -char *fix_newlines(const char *st); GSList * sipe_utils_nameval_add(GSList *list, const gchar *name, const gchar *value); diff --git a/src/core/http-conn.c b/src/core/http-conn.c index 0ae157b0..4876a46a 100644 --- a/src/core/http-conn.c +++ b/src/core/http-conn.c @@ -366,6 +366,7 @@ http_conn_send0(HttpConn *http_conn, } g_string_append_printf(outstr, "\r\n%s", http_conn->body ? http_conn->body : ""); + sipe_utils_message_debug("HTTP", outstr->str, NULL, TRUE); sipe_backend_transport_message(http_conn->conn, outstr->str); g_string_free(outstr, TRUE); } @@ -572,18 +573,11 @@ static void http_conn_input(struct sipe_transport_connection *conn) while ((cur = strstr(conn->buffer, "\r\n\r\n")) != NULL) { struct sipmsg *msg; guint remainder; + cur += 2; cur[0] = '\0'; - - if (sipe_backend_debug_enabled()) { - time_t currtime = time(NULL); - char *tmp = fix_newlines(conn->buffer); - SIPE_DEBUG_INFO("received - %s******\n%s\n******", ctime(&currtime), tmp); - g_free(tmp); - } - msg = sipmsg_parse_header(conn->buffer); - cur[0] = '\r'; + cur += 2; remainder = conn->buffer_used - (cur - conn->buffer); if (msg && remainder >= (guint) msg->bodylen) { @@ -592,17 +586,20 @@ static void http_conn_input(struct sipe_transport_connection *conn) dummy[msg->bodylen] = '\0'; msg->body = dummy; cur += msg->bodylen; + sipe_utils_message_debug("HTTP", + conn->buffer, + msg->body, + FALSE); sipe_utils_shrink_buffer(conn, cur); } else { if (msg){ SIPE_DEBUG_INFO("process_input: body too short (%d < %d, strlen %d) - ignoring message", remainder, msg->bodylen, (int)strlen(conn->buffer)); sipmsg_free(msg); } - return; - } - if (msg->body) { - SIPE_DEBUG_INFO("body:\n%s", msg->body); + /* restore header for next try */ + cur[-2] = '\r'; + return; } /* important to set before callback call */ diff --git a/src/core/sip-transport.c b/src/core/sip-transport.c index 5aa51ad2..4df6e20d 100644 --- a/src/core/sip-transport.c +++ b/src/core/sip-transport.c @@ -462,6 +462,7 @@ void sip_transport_response(struct sipe_core_private *sipe_private, tmp = g_slist_next(tmp); } g_string_append_printf(outstr, "\r\n%s", body ? body : ""); + sipe_utils_message_debug("SIP", outstr->str, NULL, TRUE); sipe_backend_transport_message(sipe_private->transport->connection, outstr->str); g_string_free(outstr, TRUE); } @@ -692,6 +693,7 @@ struct transaction *sip_transport_request(struct sipe_core_private *sipe_private } g_free(callid); + sipe_utils_message_debug("SIP", buf, NULL, TRUE); sipe_backend_transport_message(transport->connection, buf); g_free(buf); @@ -1340,6 +1342,7 @@ static void process_input_message(struct sipe_core_private *sipe_private, g_free(auth); resend = sipmsg_to_string(trans->msg); /* resend request */ + sipe_utils_message_debug("SIP", resend, NULL, TRUE); sipe_backend_transport_message(sipe_private->transport->connection, resend); g_free(resend); } else { @@ -1394,6 +1397,7 @@ static void process_input_message(struct sipe_core_private *sipe_private, g_free(auth); resend = sipmsg_to_string(trans->msg); /* resend request */ + sipe_utils_message_debug("SIP", resend, NULL, TRUE); sipe_backend_transport_message(sipe_private->transport->connection, resend); g_free(resend); } @@ -1442,17 +1446,11 @@ static void sip_transport_input(struct sipe_transport_connection *conn) ((cur = strstr(conn->buffer, "\r\n\r\n")) != NULL)) { struct sipmsg *msg; guint remainder; + cur += 2; cur[0] = '\0'; - - if (sipe_backend_debug_enabled()) { - time_t currtime = time(NULL); - gchar *tmp = fix_newlines(conn->buffer); - SIPE_DEBUG_INFO("received - %s######\n%s\n#######", ctime(&currtime), tmp); - g_free(tmp); - } msg = sipmsg_parse_header(conn->buffer); - cur[0] = '\r'; + cur += 2; remainder = conn->buffer_used - (cur - conn->buffer); if (msg && remainder >= (guint) msg->bodylen) { @@ -1461,19 +1459,22 @@ static void sip_transport_input(struct sipe_transport_connection *conn) dummy[msg->bodylen] = '\0'; msg->body = dummy; cur += msg->bodylen; + sipe_utils_message_debug("SIP", + conn->buffer, + msg->body, + FALSE); sipe_utils_shrink_buffer(conn, cur); } else { if (msg){ SIPE_DEBUG_INFO("process_input: body too short (%d < %d, strlen %d) - ignoring message", remainder, msg->bodylen, (int)strlen(conn->buffer)); sipmsg_free(msg); } + + /* restore header for next try */ + cur[-2] = '\r'; return; } - /*if (msg->body) { - SIPE_DEBUG_INFO("body:\n%s", msg->body); - }*/ - // Verify the signature before processing it if (transport->registrar.gssapi_context) { struct sipmsg_breakdown msgbd; @@ -1679,6 +1680,7 @@ void sipe_core_transport_sip_keepalive(struct sipe_core_public *sipe_public) { SIPE_DEBUG_INFO("sending keep alive %d", sipe_public->keepalive_timeout); + sipe_utils_message_debug("SIP", "", NULL, TRUE); sipe_backend_transport_message(SIPE_CORE_PRIVATE->transport->connection, "\r\n\r\n"); } diff --git a/src/core/sipe-incoming.c b/src/core/sipe-incoming.c index 18c9630d..3bffa20d 100644 --- a/src/core/sipe-incoming.c +++ b/src/core/sipe-incoming.c @@ -285,12 +285,6 @@ void process_incoming_invite(struct sipe_core_private *sipe_private, struct sip_session *session; const gchar *ms_text_format; - if (msg->body && sipe_backend_debug_enabled()) { - char *tmp = fix_newlines(msg->body); - SIPE_DEBUG_INFO("process_incoming_invite: body:\n%s!", tmp); - g_free(tmp); - } - #ifdef HAVE_VV if (g_str_has_prefix(content_type, "multipart/alternative")) { sipe_mime_parts_foreach(content_type, msg->body, sipe_invite_mime_cb, msg); diff --git a/src/core/sipe-utils.c b/src/core/sipe-utils.c index ffde24ab..9a53ffc6 100644 --- a/src/core/sipe-utils.c +++ b/src/core/sipe-utils.c @@ -240,10 +240,33 @@ replace(const char *st, return res; } -char * -fix_newlines(const char *st) +void sipe_utils_message_debug(const gchar *type, + const gchar *header, + const gchar *body, + gboolean sending) { - return replace(st, "\r\n", "\n"); + if (sipe_backend_debug_enabled()) { + GString *str = g_string_new(""); + time_t currtime = time(NULL); + const char *time_str = ctime(&currtime); /* ends in "\n" */ + const char *marker = sending ? + ">>>>>>>>>>" : + "<<<<<<<<<<"; + gchar *tmp; + + g_string_append_printf(str, "MESSAGE START %s %s - %s", marker, type, time_str); + g_string_append(str, tmp = replace(header, "\r\n", "\n")); + g_free(tmp); + g_string_append(str, "\n"); + if (body) { + g_string_append(str, tmp = replace(body, "\r\n", "\n")); + g_free(tmp); + g_string_append(str, "\n"); + } + g_string_append_printf(str, "MESSAGE END %s %s - %s", marker, type, time_str); + SIPE_DEBUG_INFO_NOFORMAT(str->str); + g_string_free(str, TRUE); + } } gboolean diff --git a/src/core/sipe-utils.h b/src/core/sipe-utils.h index 2c6f4468..c89a1bd8 100644 --- a/src/core/sipe-utils.h +++ b/src/core/sipe-utils.h @@ -224,11 +224,17 @@ replace(const char *st, const char *replace); /** - * Replaces \r\n to \n - * Returns newly allocated string. Must be g_free()'d + * Message debugging + * + * @param type message type description (SIP or HTTP). + * @param header message header + * @param body message body or NULL + * @param sending TRUE if outgoing message */ -char * -fix_newlines(const char *st); +void sipe_utils_message_debug(const gchar *type, + const gchar *header, + const gchar *body, + gboolean sending); /** * Tests two strings for equality. diff --git a/src/core/sipe-xml-tests.c b/src/core/sipe-xml-tests.c index a83ed6e1..05637194 100644 --- a/src/core/sipe-xml-tests.c +++ b/src/core/sipe-xml-tests.c @@ -50,6 +50,10 @@ void sipe_backend_debug(sipe_debug_level level, printf("DEBUG %d: %s", level, msg); g_free(msg); } +gboolean sipe_backend_debug_enabled(void) +{ + return TRUE; +} void sipe_digest_sha1(SIPE_UNUSED_PARAMETER const guchar *data, SIPE_UNUSED_PARAMETER gsize length, diff --git a/src/core/sipe.c b/src/core/sipe.c index e050b1cc..32c7fc34 100644 --- a/src/core/sipe.c +++ b/src/core/sipe.c @@ -4687,12 +4687,6 @@ void process_incoming_notify(struct sipe_core_private *sipe_private, const gchar *event = sipmsg_find_header(msg, "Event"); const gchar *subscription_state = sipmsg_find_header(msg, "subscription-state"); - if (sipe_backend_debug_enabled()) { - char *tmp = fix_newlines(msg->body); - SIPE_DEBUG_INFO("process_incoming_notify: Event: %s\n\n%s", - event ? event : "", tmp); - g_free(tmp); - } SIPE_DEBUG_INFO("process_incoming_notify: subscription_state: %s", subscription_state ? subscription_state : ""); /* implicit subscriptions */ diff --git a/src/purple/purple-transport.c b/src/purple/purple-transport.c index a3cbb2b4..d78a4758 100644 --- a/src/purple/purple-transport.c +++ b/src/purple/purple-transport.c @@ -345,15 +345,6 @@ void sipe_backend_transport_message(struct sipe_transport_connection *conn, { struct sipe_transport_purple *transport = PURPLE_TRANSPORT; - if (sipe_backend_debug_enabled()) { - time_t currtime = time(NULL); - char *tmp = fix_newlines(buffer); - - SIPE_DEBUG_INFO("sending - %s######\n%s######", - ctime(&currtime), tmp ); - g_free(tmp); - } - /* add packet to circular buffer */ purple_circ_buffer_append(transport->transmit_buffer, buffer, strlen(buffer)); -- 2.11.4.GIT