<p>N A has uploaded this change for <strong>review</strong>.</p><p><a href="https://gerrit.asterisk.org/c/asterisk/+/19492">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;">res_pjsip_logger: Add method-based logging option.<br><br>Expands the pjsip logger to support the ability to filter<br>by SIP message method. This can make certain types of SIP debugging<br>easier by only logging messages of particular method(s).<br><br>ASTERISK-30146 #close<br><br>Co-authored-by: Sean Bright <sean@seanbright.com><br>Change-Id: I9c8cbb6fc8686ef21190eb42e08bc9a9b147707f<br>---<br>A doc/CHANGES-staging/res_pjsip_logger_method.txt<br>M res/res_pjsip_logger.c<br>2 files changed, 180 insertions(+), 8 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;">git pull ssh://gerrit.asterisk.org:29418/asterisk refs/changes/92/19492/1</pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/doc/CHANGES-staging/res_pjsip_logger_method.txt b/doc/CHANGES-staging/res_pjsip_logger_method.txt</span><br><span>new file mode 100644</span><br><span>index 0000000..a1f774e</span><br><span>--- /dev/null</span><br><span>+++ b/doc/CHANGES-staging/res_pjsip_logger_method.txt</span><br><span>@@ -0,0 +1,7 @@</span><br><span style="color: hsl(120, 100%, 40%);">+Subject: res_pjsip_logger</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+SIP messages can now be filtered by SIP request method</span><br><span style="color: hsl(120, 100%, 40%);">+(INVITE, CANCEL, ACK, BYE, REGISTER, OPTION,</span><br><span style="color: hsl(120, 100%, 40%);">+SUBSCRIBE, NOTIFY, PUBLISH, INFO, and MESSAGE),</span><br><span style="color: hsl(120, 100%, 40%);">+allowing for more granular debugging to be done</span><br><span style="color: hsl(120, 100%, 40%);">+in the CLI. This applies to requests but not responses.</span><br><span>diff --git a/res/res_pjsip_logger.c b/res/res_pjsip_logger.c</span><br><span>index 957020f..456bb22 100644</span><br><span>--- a/res/res_pjsip_logger.c</span><br><span>+++ b/res/res_pjsip_logger.c</span><br><span>@@ -30,6 +30,7 @@</span><br><span> #include <pjsip.h></span><br><span> </span><br><span> #include "asterisk/res_pjsip.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/vector.h"</span><br><span> #include "asterisk/module.h"</span><br><span> #include "asterisk/logger.h"</span><br><span> #include "asterisk/cli.h"</span><br><span>@@ -99,6 +100,12 @@</span><br><span> uint16_t checksum; /*! \brief Packet checksum, left uncalculated for our purposes */</span><br><span> };</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+struct method_logging_info {</span><br><span style="color: hsl(120, 100%, 40%);">+ pj_str_t pj_name; /*! \brief A PJSIP string for the method */</span><br><span style="color: hsl(120, 100%, 40%);">+ pjsip_method method; /*! \brief The PJSIP method structure used for comparisons */</span><br><span style="color: hsl(120, 100%, 40%);">+ char name[]; /*! \brief The method name */</span><br><span style="color: hsl(120, 100%, 40%);">+};</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /*! \brief PJSIP Logging Session */</span><br><span> struct pjsip_logger_session {</span><br><span> /*! \brief Explicit addresses or ranges being logged */</span><br><span>@@ -115,6 +122,8 @@</span><br><span> unsigned int log_to_verbose:1;</span><br><span> /*! \brief Whether to log to pcap or not */</span><br><span> unsigned int log_to_pcap:1;</span><br><span style="color: hsl(120, 100%, 40%);">+ /*! \brief Vector of SIP methods to log */</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR(, struct method_logging_info *) log_methods;</span><br><span> };</span><br><span> </span><br><span> /*! \brief The default logger session */</span><br><span>@@ -130,6 +139,9 @@</span><br><span> }</span><br><span> </span><br><span> ast_free_ha(session->matches);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_RESET(&session->log_methods, ast_free);</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_FREE(&session->log_methods);</span><br><span> }</span><br><span> </span><br><span> /*! \brief Allocator for logger session */</span><br><span>@@ -145,11 +157,35 @@</span><br><span> </span><br><span> session->log_to_verbose = 1;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_INIT(&session->log_methods, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> return session;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-/*! \brief See if we pass debug IP filter */</span><br><span style="color: hsl(0, 100%, 40%);">-static inline int pjsip_log_test_addr(const struct pjsip_logger_session *session, const char *address, int port)</span><br><span style="color: hsl(120, 100%, 40%);">+/*! \note Must be called with the pjsip_logger_session lock held */</span><br><span style="color: hsl(120, 100%, 40%);">+static int apply_method_filter(const struct pjsip_logger_session *session, const pjsip_method *method)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ size_t size = AST_VECTOR_SIZE(&session->log_methods);</span><br><span style="color: hsl(120, 100%, 40%);">+ size_t i;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (size == 0) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Nothing in the vector means everything matches */</span><br><span style="color: hsl(120, 100%, 40%);">+ return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ for (i = 0; i < size; ++i) {</span><br><span style="color: hsl(120, 100%, 40%);">+ struct method_logging_info *candidate = AST_VECTOR_GET(&session->log_methods, i);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (pjsip_method_cmp(&candidate->method, method) == 0) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Nothing matched */</span><br><span style="color: hsl(120, 100%, 40%);">+ return 1;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/*! \brief See if we pass debug filter */</span><br><span style="color: hsl(120, 100%, 40%);">+static inline int pjsip_log_test_filter(const struct pjsip_logger_session *session, const char *address, int port, const pjsip_method *method)</span><br><span> {</span><br><span> struct ast_sockaddr test_addr;</span><br><span> </span><br><span>@@ -161,9 +197,15 @@</span><br><span> return 1;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ if (apply_method_filter(session, method)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* The method filter didn't match anything, so reject. */</span><br><span style="color: hsl(120, 100%, 40%);">+ return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /* A null address was passed in or no explicit matches. Just reject it. */</span><br><span> if (ast_strlen_zero(address) || !session->matches) {</span><br><span style="color: hsl(0, 100%, 40%);">- return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ /* If we matched on method and host is empty, accept, otherwise reject. */</span><br><span style="color: hsl(120, 100%, 40%);">+ return AST_VECTOR_SIZE(&session->log_methods) > 0;</span><br><span> }</span><br><span> </span><br><span> ast_sockaddr_parse(&test_addr, address, PARSE_PORT_IGNORE);</span><br><span>@@ -270,7 +312,7 @@</span><br><span> char buffer[AST_SOCKADDR_BUFLEN];</span><br><span> </span><br><span> ao2_rdlock(default_logger);</span><br><span style="color: hsl(0, 100%, 40%);">- if (!pjsip_log_test_addr(default_logger, tdata->tp_info.dst_name, tdata->tp_info.dst_port)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!pjsip_log_test_filter(default_logger, tdata->tp_info.dst_name, tdata->tp_info.dst_port, &tdata->msg->line.req.method)) {</span><br><span> ao2_unlock(default_logger);</span><br><span> return PJ_SUCCESS;</span><br><span> }</span><br><span>@@ -302,7 +344,7 @@</span><br><span> }</span><br><span> </span><br><span> ao2_rdlock(default_logger);</span><br><span style="color: hsl(0, 100%, 40%);">- if (!pjsip_log_test_addr(default_logger, rdata->pkt_info.src_name, rdata->pkt_info.src_port)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!pjsip_log_test_filter(default_logger, rdata->pkt_info.src_name, rdata->pkt_info.src_port, &rdata->msg_info.msg->line.req.method)) {</span><br><span> ao2_unlock(default_logger);</span><br><span> return PJ_FALSE;</span><br><span> }</span><br><span>@@ -393,6 +435,93 @@</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+static struct method_logging_info *method_logging_info_alloc(const char *method)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ size_t method_bytes = strlen(method);</span><br><span style="color: hsl(120, 100%, 40%);">+ struct method_logging_info *info;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ info = ast_calloc(1, sizeof(struct method_logging_info) + method_bytes + 1);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!info) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ memcpy(info->name, method, method_bytes + 1);</span><br><span style="color: hsl(120, 100%, 40%);">+ pj_strset(&info->pj_name, info->name, method_bytes);</span><br><span style="color: hsl(120, 100%, 40%);">+ pjsip_method_init_np(&info->method, &info->pj_name);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ return info;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+static int method_logging_info_cmp(const struct method_logging_info *element,</span><br><span style="color: hsl(120, 100%, 40%);">+ const struct method_logging_info *candidate)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return pjsip_method_cmp(&element->method, &candidate->method) == 0</span><br><span style="color: hsl(120, 100%, 40%);">+ ? CMP_MATCH | CMP_STOP</span><br><span style="color: hsl(120, 100%, 40%);">+ : 0;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+static int method_logging_info_sort_cmp(const void *a, const void *b)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ const struct method_logging_info *const *m_a = a;</span><br><span style="color: hsl(120, 100%, 40%);">+ const struct method_logging_info *const *m_b = b;</span><br><span style="color: hsl(120, 100%, 40%);">+ return strcasecmp((*m_a)->name, (*m_b)->name);</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/*! \brief Add the current or an additional method to match for filtering */</span><br><span style="color: hsl(120, 100%, 40%);">+static char *pjsip_enable_logger_method(int fd, const char *arg, int add_method)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ struct ast_str *str;</span><br><span style="color: hsl(120, 100%, 40%);">+ struct method_logging_info *method;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ method = method_logging_info_alloc(arg);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!method) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return CLI_FAILURE;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ao2_wrlock(default_logger);</span><br><span style="color: hsl(120, 100%, 40%);">+ default_logger->enabled = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!add_method) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Remove what already exists */</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_RESET(&default_logger->log_methods, ast_free);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Already in the list? */</span><br><span style="color: hsl(120, 100%, 40%);">+ if (AST_VECTOR_CALLBACK(&default_logger->log_methods, method_logging_info_cmp, NULL, method) != NULL) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(fd, "Method '%s' is already enabled\n", method->name);</span><br><span style="color: hsl(120, 100%, 40%);">+ ao2_unlock(default_logger);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(method);</span><br><span style="color: hsl(120, 100%, 40%);">+ return CLI_SUCCESS;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (AST_VECTOR_APPEND(&default_logger->log_methods, method)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "Cannot register logger method '%s'. Unable to append.\n", method->name);</span><br><span style="color: hsl(120, 100%, 40%);">+ ao2_unlock(default_logger);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(method);</span><br><span style="color: hsl(120, 100%, 40%);">+ return CLI_SUCCESS;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_SORT(&default_logger->log_methods, method_logging_info_sort_cmp);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ str = ast_str_create(256);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (str) {</span><br><span style="color: hsl(120, 100%, 40%);">+ size_t i;</span><br><span style="color: hsl(120, 100%, 40%);">+ for (i = 0; i < AST_VECTOR_SIZE(&default_logger->log_methods); i++) {</span><br><span style="color: hsl(120, 100%, 40%);">+ method = AST_VECTOR_GET(&default_logger->log_methods, i);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_str_append(&str, 0, "%s%.*s",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_str_strlen(str) ? ", " : "",</span><br><span style="color: hsl(120, 100%, 40%);">+ (int) method->pj_name.slen, method->pj_name.ptr);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(fd, "PJSIP Logging Enabled for SIP Methods: %s\n", ast_str_buffer(str));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(str);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ao2_unlock(default_logger);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ return CLI_SUCCESS;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> static char *pjsip_disable_logger(int fd)</span><br><span> {</span><br><span> ao2_wrlock(default_logger);</span><br><span>@@ -404,6 +533,8 @@</span><br><span> default_logger->log_to_verbose = 1;</span><br><span> default_logger->log_to_pcap = 0;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_RESET(&default_logger->log_methods, ast_free);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /* Stop logging to the PCAP file if active */</span><br><span> if (default_logger->pcap_file) {</span><br><span> fclose(default_logger->pcap_file);</span><br><span>@@ -469,18 +600,32 @@</span><br><span> </span><br><span> static char *pjsip_set_logger(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+ static const char * const method_choices[] = {</span><br><span style="color: hsl(120, 100%, 40%);">+ "INVITE", "CANCEL", "ACK",</span><br><span style="color: hsl(120, 100%, 40%);">+ "BYE", "REGISTER", "OPTION",</span><br><span style="color: hsl(120, 100%, 40%);">+ "SUBSCRIBE", "NOTIFY", "PUBLISH",</span><br><span style="color: hsl(120, 100%, 40%);">+ "INFO", "MESSAGE",</span><br><span style="color: hsl(120, 100%, 40%);">+ NULL</span><br><span style="color: hsl(120, 100%, 40%);">+ };</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> const char *what;</span><br><span> </span><br><span> if (cmd == CLI_INIT) {</span><br><span style="color: hsl(0, 100%, 40%);">- e->command = "pjsip set logger {on|off|host|add|verbose|pcap}";</span><br><span style="color: hsl(120, 100%, 40%);">+ e->command = "pjsip set logger {on|off|host|add|method|methodadd|verbose|pcap}";</span><br><span> e->usage =</span><br><span style="color: hsl(0, 100%, 40%);">- "Usage: pjsip set logger {on|off|host <name/subnet>|add <name/subnet>|verbose <on/off>|pcap <filename>}\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ "Usage: pjsip set logger {on|off|host <name/subnet>|add <name/subnet>|method <method>|methodadd <method>|verbose <on/off>|pcap <filename>}\n"</span><br><span> " Enables or disabling logging of SIP packets\n"</span><br><span> " read on ports bound to PJSIP transports either\n"</span><br><span> " globally or enables logging for an individual\n"</span><br><span style="color: hsl(0, 100%, 40%);">- " host.\n";</span><br><span style="color: hsl(120, 100%, 40%);">+ " host or particular SIP method(s).\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " Messages can be filtered by SIP request methods\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " INVITE, CANCEL, ACK, BYE, REGISTER, OPTION\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " SUBSCRIBE, NOTIFY, PUBLISH, INFO, and MESSAGE\n";</span><br><span> return NULL;</span><br><span> } else if (cmd == CLI_GENERATE) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (a->argc && !strncasecmp(a->argv[e->args - 1], "method", 6)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return ast_cli_complete(a->word, method_choices, a->n);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span> return NULL;</span><br><span> }</span><br><span> </span><br><span>@@ -497,6 +642,10 @@</span><br><span> return pjsip_enable_logger_host(a->fd, a->argv[e->args], 0);</span><br><span> } else if (!strcasecmp(what, "add")) {</span><br><span> return pjsip_enable_logger_host(a->fd, a->argv[e->args], 1);</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (!strcasecmp(what, "method")) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return pjsip_enable_logger_method(a->fd, a->argv[e->args], 0);</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (!strcasecmp(what, "methodadd")) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return pjsip_enable_logger_method(a->fd, a->argv[e->args], 1);</span><br><span> } else if (!strcasecmp(what, "verbose")) {</span><br><span> return pjsip_set_logger_verbose(a->fd, a->argv[e->args]);</span><br><span> } else if (!strcasecmp(what, "pcap")) {</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/c/asterisk/+/19492">change 19492</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.asterisk.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.asterisk.org/c/asterisk/+/19492"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: asterisk </div>
<div style="display:none"> Gerrit-Branch: 20 </div>
<div style="display:none"> Gerrit-Change-Id: I9c8cbb6fc8686ef21190eb42e08bc9a9b147707f </div>
<div style="display:none"> Gerrit-Change-Number: 19492 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: N A <asterisk@phreaknet.org> </div>
<div style="display:none"> Gerrit-MessageType: newchange </div>