<p>Kevin Harwell has uploaded this change for <strong>review</strong>.</p><p><a href="https://gerrit.asterisk.org/c/asterisk/+/14887">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;">Logging: Add debug logging categories<br><br>Added debug logging categories that allow a user to output debug information<br>based on a specified category. This lets the user limit, and filter debug<br>output to data relevant to a particular context, or topic. For instance the<br>following categories are now available for debug logging purposes:<br><br> dtls, dtls_packet, ice, rtcp, rtcp_packet, rtp, rtp_packet, stun, stun_packet<br><br>These debug categories can be enable/disable via an Asterisk CLI command.<br><br>While this overrides, and outputs debug data, core system debugging is not<br>affected by this patch. Statements still output at their appropriate debug<br>level. As well backwards compatibility has been maintained with past debug<br>groups that could be enabled using the CLI (e.g. rtpdebug, stundebug, etc.).<br><br>ASTERISK-29054 #close<br><br>Change-Id: I6e6cb247bb1f01dbf34750b2cd98e5b5b41a1849<br>---<br>A doc/CHANGES-staging/logger_category.txt<br>A include/asterisk/logger_category.h<br>M main/cli.c<br>M main/logger.c<br>A main/logger_category.c<br>M main/stun.c<br>M res/res_pjsip_sdp_rtp.c<br>M res/res_rtp_asterisk.c<br>8 files changed, 925 insertions(+), 201 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;">git pull ssh://gerrit.asterisk.org:29418/asterisk refs/changes/87/14887/1</pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/doc/CHANGES-staging/logger_category.txt b/doc/CHANGES-staging/logger_category.txt</span><br><span>new file mode 100644</span><br><span>index 0000000..67cc3ec</span><br><span>--- /dev/null</span><br><span>+++ b/doc/CHANGES-staging/logger_category.txt</span><br><span>@@ -0,0 +1,18 @@</span><br><span style="color: hsl(120, 100%, 40%);">+Subject: Core</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+Added debug logging categories that allow a user to output debug information</span><br><span style="color: hsl(120, 100%, 40%);">+based on a specified category. This lets the user limit, and filter debug</span><br><span style="color: hsl(120, 100%, 40%);">+output to data relevant to a particular context, or topic. For instance the</span><br><span style="color: hsl(120, 100%, 40%);">+following categories are now available for debug logging purposes:</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ dtls, dtls_packet, ice, rtcp, rtcp_packet, rtp, rtp_packet, stun, stun_packet</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+These debug categories can be enable/disable via an Asterisk CLI command:</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ core set debug category <category>[:<sublevel>] [category[:<sublevel] ...]</span><br><span style="color: hsl(120, 100%, 40%);">+ core set debug category off [<category> [<category>] ...]</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+If no sub-level is associated all debug statements for a given category are</span><br><span style="color: hsl(120, 100%, 40%);">+output. If a sub-level is given then only those statements assigned a value</span><br><span style="color: hsl(120, 100%, 40%);">+at or below the associated sub-level are output.</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>diff --git a/include/asterisk/logger_category.h b/include/asterisk/logger_category.h</span><br><span>new file mode 100644</span><br><span>index 0000000..c21c3bf</span><br><span>--- /dev/null</span><br><span>+++ b/include/asterisk/logger_category.h</span><br><span>@@ -0,0 +1,273 @@</span><br><span style="color: hsl(120, 100%, 40%);">+/*</span><br><span style="color: hsl(120, 100%, 40%);">+ * Asterisk -- An open source telephony toolkit.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * Copyright (C) 2020, Sangoma Technologies Corporation</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * Kevin Harwell <kharwell@sangoma.com></span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * See http://www.asterisk.org for more information about</span><br><span style="color: hsl(120, 100%, 40%);">+ * the Asterisk project. Please do not directly contact</span><br><span style="color: hsl(120, 100%, 40%);">+ * any of the maintainers of this project for assistance;</span><br><span style="color: hsl(120, 100%, 40%);">+ * the project provides a web site, mailing lists and IRC</span><br><span style="color: hsl(120, 100%, 40%);">+ * channels for your use.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * This program is free software, distributed under the terms of</span><br><span style="color: hsl(120, 100%, 40%);">+ * the GNU General Public License Version 2. See the LICENSE file</span><br><span style="color: hsl(120, 100%, 40%);">+ * at the top of the source tree.</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#ifndef ASTERISK_LOGGER_CATEGORY_H</span><br><span style="color: hsl(120, 100%, 40%);">+#define ASTERISK_LOGGER_CATEGORY_H</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%);">+ * Logger category is enabled</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_ENABLED -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%);">+ * Logger category is disabled</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_DISABLED 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%);">+ * \brief Load/Initialize system wide logger category functionality</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_logger_category_load(void);</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 Unload system wide logger category functionality</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_logger_category_unload(void);</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 Register a debug level logger category</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param name The name of the category</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param id The unique id of the category</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_debug_category_register(const char *name, uint64_t id);</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 Un-register a debug level logger category</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_debug_category_unregister(const char *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 Set the debug category's sublevel</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * Statements are output at a specified sublevel. Typically any number greater</span><br><span style="color: hsl(120, 100%, 40%);">+ * than or equal to 0. Other acceptable values include AST_LOG_CATEGORY_ENABLED</span><br><span style="color: hsl(120, 100%, 40%);">+ * and AST_LOG_CATEGORY_DISABLED.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param name The name of the category</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel The debug sublevel output number</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_debug_category_set_sublevel(const char *name, int sublevel);</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 Set one or more debug category's sublevel.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * Accepts an array of category names, and optional associated sublevels. Sublevels can</span><br><span style="color: hsl(120, 100%, 40%);">+ * be associated with a name by using a ':' as a separator. For example:</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * <category name>:<category sublevel></span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * The given default sublevel is used if no sublevel is associated with a name.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param names An array of category names</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param size The size of the array (number of elements)</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param default_sublevel The sublevel value to use if one is not associated with a name</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_debug_category_set_sublevels(const char * const *names, size_t size, int default_sublevel);</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 a unique (no duplicates) result to a request for completion for debug categories.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param argv A list of already completed options</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param argc The number of already completed options</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param word The word to complete</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param state The state</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 0 Success, -1 Failure</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+char *ast_debug_category_complete(const char * const *argv, int argc, const char *word, int state);</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 Check if a debug category is enabled, and allowed to output</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \note If more than one id is specified then if even one is allowed "true"</span><br><span style="color: hsl(120, 100%, 40%);">+ * is returned.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel Current set sublevel must be this sublevel or less</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ids One or more unique category ids to check</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \retval 1 if allowed, 0 if not allowed</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+*/</span><br><span style="color: hsl(120, 100%, 40%);">+int ast_debug_category_allow(int sublevel, uint64_t ids);</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 Log for a debug category.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * This will output log data for debug under the following conditions:</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * 1. The specified sublevel is at, or below the current system debug level</span><br><span style="color: hsl(120, 100%, 40%);">+ * 2. At least one of the given category ids is enabled AND</span><br><span style="color: hsl(120, 100%, 40%);">+ * a. The category sublevel is enabled OR the given sublevel is at, or</span><br><span style="color: hsl(120, 100%, 40%);">+ * below a category's specified sublevel.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel The minimum level to output at</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ids One or more unique category ids to output for</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 16.14</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 17.8</span><br><span style="color: hsl(120, 100%, 40%);">+ * \since 18.0</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+void ast_debug_category(int sublevel, uint64_t ids, const char *fmt, ...)</span><br><span style="color: hsl(120, 100%, 40%);">+ __attribute__((format(printf, 3, 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%);">+ * Category name, unique id and helper macros.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * These each really should be located in specific modules or core files, but in</span><br><span style="color: hsl(120, 100%, 40%);">+ * order to ease management, and file inclusions they are located here for now.</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%);">+/* RTP debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_RTP "rtp"</span><br><span style="color: hsl(120, 100%, 40%);">+/* RTP packet debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_RTP_PACKET "rtp_packet"</span><br><span style="color: hsl(120, 100%, 40%);">+/* RTCP debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_RTCP "rtcp"</span><br><span style="color: hsl(120, 100%, 40%);">+/* RTCP packet debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_RTCP_PACKET "rtcp_packet"</span><br><span style="color: hsl(120, 100%, 40%);">+/* DTLS debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_DTLS "dtls"</span><br><span style="color: hsl(120, 100%, 40%);">+/* DTLS packet debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_DTLS_PACKET "dtls_packet"</span><br><span style="color: hsl(120, 100%, 40%);">+/* STUN debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_STUN "stun"</span><br><span style="color: hsl(120, 100%, 40%);">+/* STUN packet debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_STUN_PACKET "stun_packet"</span><br><span style="color: hsl(120, 100%, 40%);">+/* ICE debug logging category name */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_LOG_CATEGORY_ICE "ice"</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_RTP (1 << 0) /* RTP debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_RTP_PACKET (1 << 1) /* RTP packet debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_RTCP (1 << 2) /* RTCP debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_RTCP_PACKET (1 << 3) /* RTCP packet debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_DTLS (1 << 4) /* DTLS debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_DTLS_PACKET (1 << 5) /* DTLS packet debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_STUN (1 << 6) /* STUN debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_STUN_PACKET (1 << 7) /* STUN packet debug logging category id */</span><br><span style="color: hsl(120, 100%, 40%);">+#define AST_DEBUG_CATEGORY_ICE (1 << 8) /* ICE debug logging category id */</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 Log debug level RTP information</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel Debug output sublevel (>= 0)</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param fmt Formatted string to output</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ... Variable arguments for fmt</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_rtp(sublevel, fmt, ...) \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(sublevel, AST_DEBUG_CATEGORY_RTP, fmt, __VA_ARGS__)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/* Allow logging of RTP packets? */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_rtp_packet_allow \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_allow(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_RTP_PACKET)</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 Log debug level RTCP information</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel Debug output sublevel (>= 0)</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param fmt Formatted string to output</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ... Variable arguments for fmt</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_rtcp(sublevel, fmt, ...) \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(sublevel, AST_DEBUG_CATEGORY_RTCP, fmt, __VA_ARGS__)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/* Allow logging of RTCP packets? */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_rtcp_packet_allow \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_allow(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_RTCP_PACKET)</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 Log debug level DTLS information</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel Debug output sublevel (>= 0)</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param fmt Formatted string to output</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ... Variable arguments for fmt</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_dtls(sublevel, fmt, ...) \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(sublevel, AST_DEBUG_CATEGORY_DTLS, fmt, __VA_ARGS__)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/* Allow logging of DTLS packets? */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_dtls_packet_allow \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_allow(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_DTLS_PACKET)</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 Log debug level STUN information</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel Debug output sublevel (>= 0)</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param fmt Formatted string to output</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ... Variable arguments for fmt</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_stun(sublevel, fmt, ...) \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(sublevel, AST_DEBUG_CATEGORY_STUN, fmt, __VA_ARGS__)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+/* Is logging of stun packets allowed? */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_stun_packet_allow \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_allow(AST_LOG_CATEGORY_ENABLED, AST_DEBUG_CATEGORY_STUN_PACKET)</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 Log debug level ICE information</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param sublevel Debug output sublevel (>= 0)</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param fmt Formatted string to output</span><br><span style="color: hsl(120, 100%, 40%);">+ * \param ... Variable arguments for fmt</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+#define ast_debug_ice(sublevel, fmt, ...) \</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(sublevel, AST_DEBUG_CATEGORY_ICE, fmt, __VA_ARGS__)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+#endif /* ASTERISK_LOGGER_CATEGORY_H */</span><br><span>diff --git a/main/cli.c b/main/cli.c</span><br><span>index 3cb42f2..f9793d2 100644</span><br><span>--- a/main/cli.c</span><br><span>+++ b/main/cli.c</span><br><span>@@ -55,6 +55,7 @@</span><br><span> #include "asterisk/app.h"</span><br><span> #include "asterisk/lock.h"</span><br><span> #include "asterisk/threadstorage.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger_category.h"</span><br><span> #include "asterisk/translate.h"</span><br><span> #include "asterisk/bridge.h"</span><br><span> #include "asterisk/stasis_channels.h"</span><br><span>@@ -478,9 +479,11 @@</span><br><span> if (!strcasecmp(a->argv[e->args], "atleast")) {</span><br><span> atleast = 1;</span><br><span> }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> if (a->argc != e->args + atleast + 1 && a->argc != e->args + atleast + 2) {</span><br><span> return CLI_SHOWUSAGE;</span><br><span> }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> if (sscanf(a->argv[e->args + atleast], "%30d", &newlevel) != 1) {</span><br><span> return CLI_SHOWUSAGE;</span><br><span> }</span><br><span>@@ -585,13 +588,16 @@</span><br><span> return NULL;</span><br><span> </span><br><span> case CLI_GENERATE:</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!strcasecmp(argv3, "category")) {</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> if (!strcasecmp(argv3, "atleast")) {</span><br><span> atleast = 1;</span><br><span> }</span><br><span> if (a->pos == 3 || (a->pos == 4 && atleast)) {</span><br><span> const char *pos = a->pos == 3 ? argv3 : S_OR(a->argv[4], "");</span><br><span> int numbermatch = (ast_strlen_zero(pos) || strchr("123456789", pos[0])) ? 0 : 21;</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span> if (a->n < 21 && numbermatch == 0) {</span><br><span> return complete_number(pos, 0, 0x7fffffff, a->n);</span><br><span> } else if (pos[0] == '0') {</span><br><span>@@ -618,7 +624,6 @@</span><br><span> */</span><br><span> </span><br><span> return handle_debug_or_trace(DEBUG_HANDLER, e, cmd, a);</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span> }</span><br><span> </span><br><span> static char *handle_trace(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)</span><br><span>@@ -1533,6 +1538,47 @@</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+static char *handle_debug_category(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ const char *argv4 = a->argv ? S_OR(a->argv[4], "") : "";</span><br><span style="color: hsl(120, 100%, 40%);">+ int offset = strncasecmp(argv4, "off", strlen(argv4)) ? 0 : 1;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ switch (cmd) {</span><br><span style="color: hsl(120, 100%, 40%);">+ case CLI_INIT:</span><br><span style="color: hsl(120, 100%, 40%);">+ e->command = "core set debug category";</span><br><span style="color: hsl(120, 100%, 40%);">+ e->usage =</span><br><span style="color: hsl(120, 100%, 40%);">+ "Usage: core set debug category <category>[:<sublevel>] [category[:<sublevel] ...]\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " core set debug category off [<category> [<category>] ...]\n\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " Allows for enabling and disabling of debug logging categories.\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " When a category is enabled all relevant debug messages are logged\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " for a given category. However, if a sublevel is specified only\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " those categorized messages at or below the coded debug sublevel\n"</span><br><span style="color: hsl(120, 100%, 40%);">+ " are logged.\n";</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%);">+ case CLI_GENERATE:</span><br><span style="color: hsl(120, 100%, 40%);">+ if (a->pos < e->args) {</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%);">+ if (a->pos == 4 && offset) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli_completion_add(ast_strdup("off"));</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%);">+ return ast_debug_category_complete(a->argv + 4,</span><br><span style="color: hsl(120, 100%, 40%);">+ a->pos - e->args, a->word, a->n - 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%);">+ if (a->argc <= e->args) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return CLI_SHOWUSAGE;</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_debug_category_set_sublevels(a->argv + e->args + offset, a->argc - e->args - offset,</span><br><span style="color: hsl(120, 100%, 40%);">+ offset ? AST_LOG_CATEGORY_DISABLED : AST_LOG_CATEGORY_ENABLED);</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 *handle_nodebugchan_deprecated(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)</span><br><span> {</span><br><span> char *res;</span><br><span>@@ -1947,6 +1993,8 @@</span><br><span> </span><br><span> AST_CLI_DEFINE(handle_core_set_debug_channel, "Enable/disable debugging on a channel"),</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ AST_CLI_DEFINE(handle_debug_category, "Enable/disable debugging categories"),</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> AST_CLI_DEFINE(handle_debug, "Set level of debug chattiness"),</span><br><span> AST_CLI_DEFINE(handle_trace, "Set level of trace chattiness"),</span><br><span> AST_CLI_DEFINE(handle_verbose, "Set level of verbose chattiness"),</span><br><span>diff --git a/main/logger.c b/main/logger.c</span><br><span>index d7d1807..067f9a9 100644</span><br><span>--- a/main/logger.c</span><br><span>+++ b/main/logger.c</span><br><span>@@ -52,6 +52,7 @@</span><br><span> #include "asterisk/module.h"</span><br><span> #include "asterisk/paths.h" /* use ast_config_AST_LOG_DIR */</span><br><span> #include "asterisk/logger.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger_category.h"</span><br><span> #include "asterisk/lock.h"</span><br><span> #include "asterisk/channel.h"</span><br><span> #include "asterisk/config.h"</span><br><span>@@ -1868,6 +1869,8 @@</span><br><span> ast_log(LOG_ERROR, "Errors detected in logger.conf. Default console logging is being used.\n");</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_logger_category_load();</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -1875,6 +1878,8 @@</span><br><span> {</span><br><span> struct logchannel *f = NULL;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_logger_category_unload();</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> ast_cli_unregister_multiple(cli_logger, ARRAY_LEN(cli_logger));</span><br><span> </span><br><span> logger_initialized = 0;</span><br><span>diff --git a/main/logger_category.c b/main/logger_category.c</span><br><span>new file mode 100644</span><br><span>index 0000000..3a528ad</span><br><span>--- /dev/null</span><br><span>+++ b/main/logger_category.c</span><br><span>@@ -0,0 +1,311 @@</span><br><span style="color: hsl(120, 100%, 40%);">+/*</span><br><span style="color: hsl(120, 100%, 40%);">+ * Asterisk -- An open source telephony toolkit.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * Copyright (C) 2020, Sangoma Technologies Corporation</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * Kevin Harwell <kharwell@sangoma.com></span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * See http://www.asterisk.org for more information about</span><br><span style="color: hsl(120, 100%, 40%);">+ * the Asterisk project. Please do not directly contact</span><br><span style="color: hsl(120, 100%, 40%);">+ * any of the maintainers of this project for assistance;</span><br><span style="color: hsl(120, 100%, 40%);">+ * the project provides a web site, mailing lists and IRC</span><br><span style="color: hsl(120, 100%, 40%);">+ * channels for your use.</span><br><span style="color: hsl(120, 100%, 40%);">+ *</span><br><span style="color: hsl(120, 100%, 40%);">+ * This program is free software, distributed under the terms of</span><br><span style="color: hsl(120, 100%, 40%);">+ * the GNU General Public License Version 2. See the LICENSE file</span><br><span style="color: hsl(120, 100%, 40%);">+ * at the top of the source tree.</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%);">+#include "asterisk.h"</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/cli.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/conversions.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger_category.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/vector.h"</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+struct category_t {</span><br><span style="color: hsl(120, 100%, 40%);">+ int sublevel;</span><br><span style="color: hsl(120, 100%, 40%);">+ uint64_t id;</span><br><span style="color: hsl(120, 100%, 40%);">+ char name[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%);">+AST_VECTOR(categories_t, struct category_t *);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+struct categories_level_t {</span><br><span style="color: hsl(120, 100%, 40%);">+ int type;</span><br><span style="color: hsl(120, 100%, 40%);">+ int sublevel;</span><br><span style="color: hsl(120, 100%, 40%);">+ uint64_t state;</span><br><span style="color: hsl(120, 100%, 40%);">+ struct categories_t categories;</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 category_register(struct categories_level_t *level, const char *name, uint64_t id)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ int i;</span><br><span style="color: hsl(120, 100%, 40%);">+ struct category_t *category;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ for (i = 0; i < AST_VECTOR_SIZE(&level->categories); ++i) {</span><br><span style="color: hsl(120, 100%, 40%);">+ category = AST_VECTOR_GET(&level->categories, i);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (category->id == id) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "Cannot register logger category '%s' with id '%"PRId64"'"</span><br><span style="color: hsl(120, 100%, 40%);">+ ". Id already used by '%s'.", name, id, category->name);</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%);">+ if (!strcmp(category->name, name)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "Cannot register logger category '%s' with id '%"PRId64"'"</span><br><span style="color: hsl(120, 100%, 40%);">+ ". Name already used for type.", name, id);</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%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ category = ast_calloc(1, sizeof(*category) + strlen(name) + 1);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!category) {</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%);">+ category->id = id;</span><br><span style="color: hsl(120, 100%, 40%);">+ category->sublevel = AST_LOG_CATEGORY_DISABLED;</span><br><span style="color: hsl(120, 100%, 40%);">+ strcpy(category->name, name); /* Safe */</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (AST_VECTOR_APPEND(&level->categories, category)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "Cannot register logger category '%s' with id '%"PRId64"'"</span><br><span style="color: hsl(120, 100%, 40%);">+ ". Unable to append.", name, id);</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%);">+ 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%);">+static int cmp_by_name(const struct category_t *category, const char *name)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return !strcmp(category->name, 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%);">+static int category_unregister(struct categories_level_t *level, const char *name)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return AST_VECTOR_REMOVE_CMP_UNORDERED(&level->categories, name, cmp_by_name, 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%);">+static int casecmp_by_name(const struct category_t *category, const char *name)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return !strcasecmp(category->name, 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%);">+static int category_set_sublevel(struct category_t *category, struct categories_level_t *level,</span><br><span style="color: hsl(120, 100%, 40%);">+ const char *name, int sublevel)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!category) {</span><br><span style="color: hsl(120, 100%, 40%);">+ struct category_t **obj = AST_VECTOR_GET_CMP(&level->categories, name, casecmp_by_name);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!obj) {</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%);">+ category = *obj;</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%);">+ category->sublevel = sublevel;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (category->sublevel == AST_LOG_CATEGORY_DISABLED) {</span><br><span style="color: hsl(120, 100%, 40%);">+ level->state &= ~category->id;</span><br><span style="color: hsl(120, 100%, 40%);">+ } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ level->state |= category->id;</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%);">+ 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%);">+static int category_set_sublevels(struct categories_level_t *level,</span><br><span style="color: hsl(120, 100%, 40%);">+ const char * const *names, size_t size, int default_sublevel)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ int i;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!names || !size) {</span><br><span style="color: hsl(120, 100%, 40%);">+ level->state = default_sublevel;</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_CALLBACK_VOID(&level->categories, category_set_sublevel,</span><br><span style="color: hsl(120, 100%, 40%);">+ level, NULL, default_sublevel);</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%);">+ const char *sublevel;</span><br><span style="color: hsl(120, 100%, 40%);">+ int num = default_sublevel;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ sublevel = strchr(names[i], ':');</span><br><span style="color: hsl(120, 100%, 40%);">+ if (sublevel) {</span><br><span style="color: hsl(120, 100%, 40%);">+ size_t len = ++sublevel - names[i];</span><br><span style="color: hsl(120, 100%, 40%);">+ char name[len];</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (*sublevel && ast_str_to_int(sublevel, &num)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ continue;</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_copy_string(name, names[i], len);</span><br><span style="color: hsl(120, 100%, 40%);">+ category_set_sublevel(NULL, level, name, num);</span><br><span style="color: hsl(120, 100%, 40%);">+ } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ category_set_sublevel(NULL, level, names[i], num);</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%);">+ 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%);">+static char *category_complete(struct categories_level_t *level, const char * const *argv,</span><br><span style="color: hsl(120, 100%, 40%);">+ int argc, const char *word, int state)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ int wordlen = strlen(word);</span><br><span style="color: hsl(120, 100%, 40%);">+ int which = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ int i, j;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (argc == AST_VECTOR_SIZE(&level->categories)) {</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%);">+ for (i = 0; i < AST_VECTOR_SIZE(&level->categories); ++i) {</span><br><span style="color: hsl(120, 100%, 40%);">+ struct category_t *category = AST_VECTOR_GET(&level->categories, i);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!strncasecmp(word, category->name, wordlen) && (++which > state)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Check to see if one is already been included */</span><br><span style="color: hsl(120, 100%, 40%);">+ for (j = 0; j < argc; ++j) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!strncasecmp(category->name, argv[j], strlen(category->name))) {</span><br><span style="color: hsl(120, 100%, 40%);">+ break;</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%);">+ if (j != argc) {</span><br><span style="color: hsl(120, 100%, 40%);">+ continue;</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 (state != -1) {</span><br><span style="color: hsl(120, 100%, 40%);">+ return ast_strdup(category->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%);">+ if (ast_cli_completion_add(ast_strdup(category->name))) {</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%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</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%);">+static int category_allow(int sublevel, const struct categories_level_t *level, uint64_t ids)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Check level, and potentially allow but only if there is a matching state enabled */</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ids & level->state) {</span><br><span style="color: hsl(120, 100%, 40%);">+ int i;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (sublevel == AST_LOG_CATEGORY_ENABLED || sublevel == 0) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* If at least one id is enabled then always allow these sublevels */</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%);">+ for (i = 0; i < AST_VECTOR_SIZE(&level->categories); ++i) {</span><br><span style="color: hsl(120, 100%, 40%);">+ struct category_t *category = AST_VECTOR_GET(&level->categories, i);</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 there is at least one matching category, and that category is enabled</span><br><span style="color: hsl(120, 100%, 40%);">+ * or its sub-level is at or above the given sub-level then allow.</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+ if ((category->id & ids) && category->sublevel != AST_LOG_CATEGORY_DISABLED &&</span><br><span style="color: hsl(120, 100%, 40%);">+ (category->sublevel == AST_LOG_CATEGORY_ENABLED || category->sublevel >= sublevel)) {</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%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</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%);">+static struct categories_level_t debug_categories = {</span><br><span style="color: hsl(120, 100%, 40%);">+ .type = __LOG_DEBUG,</span><br><span style="color: hsl(120, 100%, 40%);">+ .sublevel = 0,</span><br><span style="color: hsl(120, 100%, 40%);">+ .state = 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%);">+int ast_debug_category_register(const char *name, uint64_t id)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return category_register(&debug_categories, name, id);</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%);">+int ast_debug_category_unregister(const char *name)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return category_unregister(&debug_categories, 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%);">+int ast_debug_category_set_sublevel(const char *name, int sublevel)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return category_set_sublevel(NULL, &debug_categories, name, sublevel);</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%);">+int ast_debug_category_set_sublevels(const char * const *names,</span><br><span style="color: hsl(120, 100%, 40%);">+ size_t size, int default_sublevel)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return category_set_sublevels(&debug_categories, names, size, default_sublevel);</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%);">+char *ast_debug_category_complete(const char * const *argv, int argc,</span><br><span style="color: hsl(120, 100%, 40%);">+ const char *word, int state)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return category_complete(&debug_categories, argv, argc, word, state);</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%);">+int ast_debug_category_allow(int sublevel, uint64_t ids)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ return category_allow(sublevel, &debug_categories, ids);</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%);">+void ast_debug_category(int sublevel, uint64_t ids, const char *fmt, ...)</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%);">+ * Log if it meets the normal debug criteria. Otherwise check to see if the</span><br><span style="color: hsl(120, 100%, 40%);">+ * category is enabled, and allowed to log.</span><br><span style="color: hsl(120, 100%, 40%);">+ */</span><br><span style="color: hsl(120, 100%, 40%);">+ if (DEBUG_ATLEAST(sublevel) || ast_debug_category_allow(sublevel, ids)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ va_list ap;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ va_start(ap, fmt);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log_ap(debug_categories.type, _A_, fmt, ap);</span><br><span style="color: hsl(120, 100%, 40%);">+ va_end(ap);</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%);">+int ast_logger_category_load(void)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_RTP, AST_DEBUG_CATEGORY_RTP);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_RTP_PACKET, AST_DEBUG_CATEGORY_RTP_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_RTCP, AST_DEBUG_CATEGORY_RTCP);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_RTCP_PACKET, AST_DEBUG_CATEGORY_RTCP_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_DTLS, AST_DEBUG_CATEGORY_DTLS);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_DTLS_PACKET, AST_DEBUG_CATEGORY_DTLS_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_STUN, AST_DEBUG_CATEGORY_STUN);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_STUN_PACKET, AST_DEBUG_CATEGORY_STUN_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_register(AST_LOG_CATEGORY_ICE, AST_DEBUG_CATEGORY_ICE);</span><br><span style="color: hsl(120, 100%, 40%);">+</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%);">+int ast_logger_category_unload(void)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_ICE);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_STUN_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_STUN);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_DTLS_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_DTLS);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_RTCP_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_RTCP);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_RTP_PACKET);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_unregister(AST_LOG_CATEGORY_RTP);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span>diff --git a/main/stun.c b/main/stun.c</span><br><span>index c103ab8..c64c7f4 100644</span><br><span>--- a/main/stun.c</span><br><span>+++ b/main/stun.c</span><br><span>@@ -32,14 +32,14 @@</span><br><span> </span><br><span> #include "asterisk.h"</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger_category.h"</span><br><span> #include "asterisk/_private.h"</span><br><span> #include "asterisk/stun.h"</span><br><span> #include "asterisk/cli.h"</span><br><span> #include "asterisk/utils.h"</span><br><span> #include "asterisk/channel.h"</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-static int stundebug; /*!< Are we debugging stun? */</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span> /*!</span><br><span> * \brief STUN support code</span><br><span> *</span><br><span>@@ -178,9 +178,10 @@</span><br><span> </span><br><span> static int stun_process_attr(struct stun_state *state, struct stun_attr *attr)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">- if (stundebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_stun_packet_allow) {</span><br><span> ast_verbose("Found STUN Attribute %s (%04x), length %d\n",</span><br><span style="color: hsl(0, 100%, 40%);">- stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));</span><br><span style="color: hsl(120, 100%, 40%);">+ stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span> switch (ntohs(attr->attr)) {</span><br><span> case STUN_USERNAME:</span><br><span> state->username = (const char *) (attr->value);</span><br><span>@@ -189,10 +190,12 @@</span><br><span> state->password = (const char *) (attr->value);</span><br><span> break;</span><br><span> default:</span><br><span style="color: hsl(0, 100%, 40%);">- if (stundebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_stun_packet_allow) {</span><br><span> ast_verbose("Ignoring STUN attribute %s (%04x), length %d\n",</span><br><span style="color: hsl(0, 100%, 40%);">- stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));</span><br><span style="color: hsl(120, 100%, 40%);">+ stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr), ntohs(attr->len));</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span> }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -275,35 +278,35 @@</span><br><span> * while 'data' is advanced accordingly.</span><br><span> */</span><br><span> if (len < sizeof(struct stun_header)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Runt STUN packet (only %d, wanting at least %d)\n", (int) len, (int) sizeof(struct stun_header));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "Runt STUN packet (only %d, wanting at least %d)\n", (int) len, (int) sizeof(struct stun_header));</span><br><span> return -1;</span><br><span> }</span><br><span> len -= sizeof(struct stun_header);</span><br><span> data += sizeof(struct stun_header);</span><br><span> x = ntohs(hdr->msglen); /* len as advertised in the message */</span><br><span style="color: hsl(0, 100%, 40%);">- if (stundebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_stun_packet_allow)</span><br><span> ast_verbose("STUN Packet, msg %s (%04x), length: %d\n", stun_msg2str(ntohs(hdr->msgtype)), (unsigned)ntohs(hdr->msgtype), x);</span><br><span> if (x > len) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Scrambled STUN packet length (got %d, expecting %d)\n", x, (int)len);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "Scrambled STUN packet length (got %d, expecting %d)\n", x, (int)len);</span><br><span> } else</span><br><span> len = x;</span><br><span> memset(&st, 0, sizeof(st));</span><br><span> while (len) {</span><br><span> if (len < sizeof(struct stun_attr)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Runt Attribute (got %d, expecting %d)\n", (int)len, (int) sizeof(struct stun_attr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "Runt Attribute (got %d, expecting %d)\n", (int)len, (int) sizeof(struct stun_attr));</span><br><span> break;</span><br><span> }</span><br><span> attr = (struct stun_attr *)data;</span><br><span> /* compute total attribute length */</span><br><span> x = ntohs(attr->len) + sizeof(struct stun_attr);</span><br><span> if (x > len) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Inconsistent Attribute (length %d exceeds remaining msg len %d)\n", x, (int)len);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "Inconsistent Attribute (length %d exceeds remaining msg len %d)\n", x, (int)len);</span><br><span> break;</span><br><span> }</span><br><span> if (stun_cb)</span><br><span> stun_cb(attr, arg);</span><br><span> if (stun_process_attr(&st, attr)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to handle attribute %s (%04x)\n", stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "Failed to handle attribute %s (%04x)\n", stun_attr2str(ntohs(attr->attr)), (unsigned)ntohs(attr->attr));</span><br><span> break;</span><br><span> }</span><br><span> /* Clear attribute id: in case previous entry was a string,</span><br><span>@@ -337,7 +340,7 @@</span><br><span> attr = (struct stun_attr *)resp->ies;</span><br><span> switch (ntohs(hdr->msgtype)) {</span><br><span> case STUN_BINDREQ:</span><br><span style="color: hsl(0, 100%, 40%);">- if (stundebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_stun_packet_allow)</span><br><span> ast_verbose("STUN Bind Request, username: %s\n",</span><br><span> st.username ? st.username : "<none>");</span><br><span> if (st.username) {</span><br><span>@@ -355,7 +358,7 @@</span><br><span> ret = AST_STUN_ACCEPT;</span><br><span> break;</span><br><span> default:</span><br><span style="color: hsl(0, 100%, 40%);">- if (stundebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_stun_packet_allow)</span><br><span> ast_verbose("Dunno what to do with STUN message %04x (%s)\n", (unsigned)ntohs(hdr->msgtype), stun_msg2str(ntohs(hdr->msgtype)));</span><br><span> }</span><br><span> }</span><br><span>@@ -416,7 +419,7 @@</span><br><span> /* Send STUN message. */</span><br><span> res = stun_send(s, dst, req);</span><br><span> if (res < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "stun_send try %d failed: %s\n", retry, strerror(errno));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "stun_send try %d failed: %s\n", retry, strerror(errno));</span><br><span> break;</span><br><span> }</span><br><span> if (!answer) {</span><br><span>@@ -459,7 +462,7 @@</span><br><span> res = recvfrom(s, rsp_buf, sizeof(rsp_buf) - 1,</span><br><span> 0, (struct sockaddr *) &src, &srclen);</span><br><span> if (res < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "recvfrom try %d failed: %s\n", retry, strerror(errno));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "recvfrom try %d failed: %s\n", retry, strerror(errno));</span><br><span> break;</span><br><span> }</span><br><span> </span><br><span>@@ -500,13 +503,13 @@</span><br><span> return CLI_SHOWUSAGE;</span><br><span> </span><br><span> if (!strncasecmp(a->argv[e->args-1], "on", 2))</span><br><span style="color: hsl(0, 100%, 40%);">- stundebug = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_STUN_PACKET, AST_LOG_CATEGORY_ENABLED);</span><br><span> else if (!strncasecmp(a->argv[e->args-1], "off", 3))</span><br><span style="color: hsl(0, 100%, 40%);">- stundebug = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_STUN_PACKET, AST_LOG_CATEGORY_DISABLED);</span><br><span> else</span><br><span> return CLI_SHOWUSAGE;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "STUN Debugging %s\n", stundebug ? "Enabled" : "Disabled");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "STUN Debugging %s\n", ast_debug_stun_packet_allow ? "Enabled" : "Disabled");</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> </span><br><span>diff --git a/res/res_pjsip_sdp_rtp.c b/res/res_pjsip_sdp_rtp.c</span><br><span>index eacae22..f7234d0 100644</span><br><span>--- a/res/res_pjsip_sdp_rtp.c</span><br><span>+++ b/res/res_pjsip_sdp_rtp.c</span><br><span>@@ -52,6 +52,7 @@</span><br><span> #include "asterisk/dsp.h"</span><br><span> #include "asterisk/linkedlists.h" /* for AST_LIST_NEXT */</span><br><span> #include "asterisk/stream.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger_category.h"</span><br><span> #include "asterisk/format_cache.h"</span><br><span> </span><br><span> #include "asterisk/res_pjsip.h"</span><br><span>@@ -82,15 +83,15 @@</span><br><span> keepalive = ast_rtp_instance_get_keepalive(rtp);</span><br><span> </span><br><span> if (!ast_sockaddr_isnull(&session_media->direct_media_addr)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Not sending RTP keepalive on RTP instance %p since direct media is in use\n", rtp);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP not sending keepalive since direct media is in use\n", rtp);</span><br><span> return keepalive * 1000;</span><br><span> }</span><br><span> </span><br><span> interval = time(NULL) - ast_rtp_instance_get_last_tx(rtp);</span><br><span> send_keepalive = interval >= keepalive;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "It has been %d seconds since RTP was last sent on instance %p. %sending keepalive\n",</span><br><span style="color: hsl(0, 100%, 40%);">- (int) interval, rtp, send_keepalive ? "S" : "Not s");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP it has been %d seconds since RTP was last sent. %sending keepalive\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ rtp, (int) interval, send_keepalive ? "S" : "Not s");</span><br><span> </span><br><span> if (send_keepalive) {</span><br><span> ast_rtp_instance_sendcng(rtp, 0);</span><br><span>@@ -138,8 +139,8 @@</span><br><span> * - disconnect channel unless direct media is in use.</span><br><span> */</span><br><span> if (!ast_sockaddr_isnull(&session_media->direct_media_addr)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Not disconnecting channel '%s' for lack of %s RTP activity in %d seconds "</span><br><span style="color: hsl(0, 100%, 40%);">- "since direct media is in use\n", ast_channel_name(chan),</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP not disconnecting channel '%s' for lack of %s RTP activity in %d seconds "</span><br><span style="color: hsl(120, 100%, 40%);">+ "since direct media is in use\n", rtp, ast_channel_name(chan),</span><br><span> ast_codec_media_type2str(session_media->type), elapsed);</span><br><span> ast_channel_unlock(chan);</span><br><span> ast_channel_unref(chan);</span><br><span>@@ -233,12 +234,12 @@</span><br><span> </span><br><span> if (session->endpoint->media.bind_rtp_to_media_address && !ast_strlen_zero(session->endpoint->media.address)) {</span><br><span> if (ast_sockaddr_parse(&temp_media_address, session->endpoint->media.address, 0)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Endpoint %s: Binding RTP media to %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "Endpoint %s: Binding RTP media to %s\n",</span><br><span> ast_sorcery_object_get_id(session->endpoint),</span><br><span> session->endpoint->media.address);</span><br><span> media_address = &temp_media_address;</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Endpoint %s: RTP media address invalid: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "Endpoint %s: RTP media address invalid: %s\n",</span><br><span> ast_sorcery_object_get_id(session->endpoint),</span><br><span> session->endpoint->media.address);</span><br><span> }</span><br><span>@@ -256,11 +257,11 @@</span><br><span> </span><br><span> pj_sockaddr_print(&trans_state->host, hoststr, sizeof(hoststr), 0);</span><br><span> if (ast_sockaddr_parse(&temp_media_address, hoststr, 0)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Transport %s bound to %s: Using it for RTP media.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "Transport %s bound to %s: Using it for RTP media.\n",</span><br><span> session->endpoint->transport, hoststr);</span><br><span> media_address = &temp_media_address;</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Transport %s bound to %s: Invalid for RTP media.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "Transport %s bound to %s: Invalid for RTP media.\n",</span><br><span> session->endpoint->transport, hoststr);</span><br><span> }</span><br><span> ao2_ref(trans_state, -1);</span><br><span>@@ -783,6 +784,8 @@</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE process attributes\n", session_media->rtp);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> attr = pjmedia_sdp_media_find_attr2(remote_stream, "ice-ufrag", NULL);</span><br><span> if (!attr) {</span><br><span> attr = pjmedia_sdp_attr_find2(remote->attr_count, remote->attr, "ice-ufrag", NULL);</span><br><span>@@ -791,6 +794,7 @@</span><br><span> ast_copy_pj_str(attr_value, (pj_str_t*)&attr->value, sizeof(attr_value));</span><br><span> ice->set_authentication(session_media->rtp, attr_value, NULL);</span><br><span> } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE no, or invalid ice-ufrag\n", session_media->rtp);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>@@ -802,6 +806,7 @@</span><br><span> ast_copy_pj_str(attr_value, (pj_str_t*)&attr->value, sizeof(attr_value));</span><br><span> ice->set_authentication(session_media->rtp, NULL, attr_value);</span><br><span> } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE no, or invalid ice-pwd\n", session_media->rtp);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>diff --git a/res/res_rtp_asterisk.c b/res/res_rtp_asterisk.c</span><br><span>index 1820ab1..530962c 100644</span><br><span>--- a/res/res_rtp_asterisk.c</span><br><span>+++ b/res/res_rtp_asterisk.c</span><br><span>@@ -64,6 +64,7 @@</span><br><span> #endif</span><br><span> </span><br><span> #include "asterisk/options.h"</span><br><span style="color: hsl(120, 100%, 40%);">+#include "asterisk/logger_category.h"</span><br><span> #include "asterisk/stun.h"</span><br><span> #include "asterisk/pbx.h"</span><br><span> #include "asterisk/frame.h"</span><br><span>@@ -110,6 +111,7 @@</span><br><span> #define MAXIMUM_RTP_RECV_BUFFER_SIZE (DEFAULT_RTP_RECV_BUFFER_SIZE + 20) /*!< Maximum RTP receive buffer size */</span><br><span> #define OLD_PACKET_COUNT 1000 /*!< The number of previous packets that are considered old */</span><br><span> #define MISSING_SEQNOS_ADDED_TRIGGER 2 /*!< The number of immediate missing packets that will trigger an immediate NACK */</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> #define SEQNO_CYCLE_OVER 65536 /*!< The number after the maximum allowed sequence number */</span><br><span> </span><br><span> /*! Full INTRA-frame Request / Fast Update Request (From RFC2032) */</span><br><span>@@ -189,8 +191,6 @@</span><br><span> </span><br><span> static int rtpstart = DEFAULT_RTP_START; /*!< First port for RTP sessions (set in rtp.conf) */</span><br><span> static int rtpend = DEFAULT_RTP_END; /*!< Last port for RTP sessions (set in rtp.conf) */</span><br><span style="color: hsl(0, 100%, 40%);">-static int rtpdebug; /*!< Are we debugging? */</span><br><span style="color: hsl(0, 100%, 40%);">-static int rtcpdebug; /*!< Are we debugging RTCP? */</span><br><span> static int rtcpstats; /*!< Are we debugging RTCP? */</span><br><span> static int rtcpinterval = RTCP_DEFAULT_INTERVALMS; /*!< Time between rtcp reports in millisecs */</span><br><span> static struct ast_sockaddr rtpdebugaddr; /*!< Debug packets to/from this host */</span><br><span>@@ -669,6 +669,7 @@</span><br><span> int rtcp = 0;</span><br><span> struct ast_sockaddr remote_address = { {0, } };</span><br><span> int ice;</span><br><span style="color: hsl(120, 100%, 40%);">+ int bytes_sent;</span><br><span> </span><br><span> /* OpenSSL can't tolerate a packet not being sent, so we always state that</span><br><span> * we sent the packet. If it isn't then retransmission will occur.</span><br><span>@@ -685,7 +686,13 @@</span><br><span> return len;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- __rtp_sendto(instance, (char *)buf, len, 0, &remote_address, rtcp, &ice, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+ bytes_sent = __rtp_sendto(instance, (char *)buf, len, 0, &remote_address, rtcp, &ice, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (bytes_sent > 0 && ast_debug_dtls_packet_allow) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug(0, "(%p) DTLS - sent %s packet to %s%s (len %-6.6d)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtcp ? "RTCP" : "RTP", ast_sockaddr_stringify(&remote_address),</span><br><span style="color: hsl(120, 100%, 40%);">+ ice ? " (via ICE)" : "", bytes_sent);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span> </span><br><span> return len;</span><br><span> }</span><br><span>@@ -817,6 +824,8 @@</span><br><span> ast_sockaddr_copy(&remote_candidate->relay_address, &candidate->relay_address);</span><br><span> remote_candidate->type = candidate->type;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE add remote candidate\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> ao2_link(rtp->ice_proposed_remote_candidates, remote_candidate);</span><br><span> ao2_ref(remote_candidate, -1);</span><br><span> }</span><br><span>@@ -862,6 +871,7 @@</span><br><span> ao2_unlock(instance);</span><br><span> ao2_ref(ice, -1);</span><br><span> ao2_lock(instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE stopped\n", instance);</span><br><span> }</span><br><span> }</span><br><span> </span><br><span>@@ -922,13 +932,14 @@</span><br><span> struct ast_rtp *rtp = ast_rtp_instance_get_data(instance);</span><br><span> int res;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Resetting ICE for RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(3, "(%p) ICE resetting\n", instance);</span><br><span> if (!rtp->ice->real_ice->is_nominating && !rtp->ice->real_ice->is_complete) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Nevermind. ICE isn't ready for a reset\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(3, " (%p) ICE nevermind, not ready for a reset\n", instance);</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Recreating ICE session %s (%d) for RTP instance '%p'\n", ast_sockaddr_stringify(&rtp->ice_original_rtp_addr), rtp->ice_port, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(3, "(%p) ICE recreating ICE session %s (%d)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&rtp->ice_original_rtp_addr), rtp->ice_port);</span><br><span> res = ice_create(instance, &rtp->ice_original_rtp_addr, rtp->ice_port, 1);</span><br><span> if (!res) {</span><br><span> /* Use the current expected role for the ICE session */</span><br><span>@@ -1004,7 +1015,7 @@</span><br><span> /* Check for equivalence in the lists */</span><br><span> if (rtp->ice_active_remote_candidates &&</span><br><span> !ice_candidates_compare(rtp->ice_proposed_remote_candidates, rtp->ice_active_remote_candidates)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Proposed == active candidates for RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE proposed equals active candidates\n", instance);</span><br><span> ao2_cleanup(rtp->ice_proposed_remote_candidates);</span><br><span> rtp->ice_proposed_remote_candidates = NULL;</span><br><span> /* If this ICE session is being preserved then go back to the role it currently is */</span><br><span>@@ -1017,9 +1028,11 @@</span><br><span> rtp->ice_active_remote_candidates = rtp->ice_proposed_remote_candidates;</span><br><span> rtp->ice_proposed_remote_candidates = NULL;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE start\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /* Reset the ICE session. Is this going to work? */</span><br><span> if (ice_reset_session(instance)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_NOTICE, "Failed to create replacement ICE session\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_NOTICE, "(%p) ICE failed to create replacement session\n", instance);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>@@ -1054,13 +1067,13 @@</span><br><span> }</span><br><span> </span><br><span> if (candidate->id == AST_RTP_ICE_COMPONENT_RTP && rtp->turn_rtp) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "RTP candidate %s (%p)\n", ast_sockaddr_stringify(&candidate->address), instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE RTP candidate %s\n", instance, ast_sockaddr_stringify(&candidate->address));</span><br><span> /* Release the instance lock to avoid deadlock with PJPROJECT group lock */</span><br><span> ao2_unlock(instance);</span><br><span> pj_turn_sock_set_perm(rtp->turn_rtp, 1, &candidates[cand_cnt].addr, 1);</span><br><span> ao2_lock(instance);</span><br><span> } else if (candidate->id == AST_RTP_ICE_COMPONENT_RTCP && rtp->turn_rtcp) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "RTCP candidate %s (%p)\n", ast_sockaddr_stringify(&candidate->address), instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE RTCP candidate %s\n", instance, ast_sockaddr_stringify(&candidate->address));</span><br><span> /* Release the instance lock to avoid deadlock with PJPROJECT group lock */</span><br><span> ao2_unlock(instance);</span><br><span> pj_turn_sock_set_perm(rtp->turn_rtcp, 1, &candidates[cand_cnt].addr, 1);</span><br><span>@@ -1074,17 +1087,17 @@</span><br><span> ao2_iterator_destroy(&i);</span><br><span> </span><br><span> if (cand_cnt < ao2_container_count(rtp->ice_active_remote_candidates)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Lost %d ICE candidates. Consider increasing PJ_ICE_MAX_CAND in PJSIP (%p)\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ao2_container_count(rtp->ice_active_remote_candidates) - cand_cnt, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_WARNING, "(%p) ICE lost %d candidates. Consider increasing PJ_ICE_MAX_CAND in PJSIP\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ao2_container_count(rtp->ice_active_remote_candidates) - cand_cnt);</span><br><span> }</span><br><span> </span><br><span> if (!has_rtp) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "No RTP candidates; skipping ICE checklist (%p)\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_WARNING, "(%p) ICE no RTP candidates; skipping checklist\n", instance);</span><br><span> }</span><br><span> </span><br><span> /* If we're only dealing with one ICE component, then we don't care about the lack of RTCP candidates */</span><br><span> if (!has_rtcp && rtp->ice_num_components > 1) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "No RTCP candidates; skipping ICE checklist (%p)\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_WARNING, "(%p) ICE no RTCP candidates; skipping checklist\n", instance);</span><br><span> }</span><br><span> </span><br><span> if (rtp->ice && has_rtp && (has_rtcp || rtp->ice_num_components == 1)) {</span><br><span>@@ -1098,7 +1111,7 @@</span><br><span> ao2_unlock(instance);</span><br><span> res = pj_ice_sess_create_check_list(ice->real_ice, &ufrag, &passwd, cand_cnt, &candidates[0]);</span><br><span> if (res == PJ_SUCCESS) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Successfully created ICE checklist (%p)\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE successfully created checklist\n", instance);</span><br><span> ast_test_suite_event_notify("ICECHECKLISTCREATE", "Result: SUCCESS");</span><br><span> pj_ice_sess_start_check(ice->real_ice);</span><br><span> pj_timer_heap_poll(timer_heap, NULL);</span><br><span>@@ -1111,7 +1124,7 @@</span><br><span> ao2_lock(instance);</span><br><span> </span><br><span> pj_strerror(res, reason, sizeof(reason));</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Failed to create ICE session check list: %s (%p)\n", reason, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_WARNING, "(%p) ICE failed to create session check list: %s\n", instance, reason);</span><br><span> }</span><br><span> </span><br><span> ast_test_suite_event_notify("ICECHECKLISTCREATE", "Result: FAILURE");</span><br><span>@@ -1174,11 +1187,8 @@</span><br><span> {</span><br><span> struct ast_rtp *rtp = ast_rtp_instance_get_data(instance);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Set role to %s (%p)\n",</span><br><span style="color: hsl(0, 100%, 40%);">- role == AST_RTP_ICE_ROLE_CONTROLLED ? "CONTROLLED" : "CONTROLLING", instance);</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span> if (!rtp->ice) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Set role failed; no ice instance (%p)\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(3, "(%p) ICE set role failed; no ice instance\n", instance);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>@@ -1186,11 +1196,13 @@</span><br><span> </span><br><span> if (!rtp->ice->real_ice->is_nominating && !rtp->ice->real_ice->is_complete) {</span><br><span> pj_thread_register_check();</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE set role to %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, role == AST_RTP_ICE_ROLE_CONTROLLED ? "CONTROLLED" : "CONTROLLING");</span><br><span> pj_ice_sess_change_role(rtp->ice->real_ice, role == AST_RTP_ICE_ROLE_CONTROLLED ?</span><br><span> PJ_ICE_SESS_ROLE_CONTROLLED : PJ_ICE_SESS_ROLE_CONTROLLING);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Not setting ICE role because state is %s\n", rtp->ice->real_ice->is_nominating ? "nominating" : "complete" );</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE not setting role because state is %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp->ice->real_ice->is_nominating ? "nominating" : "complete");</span><br><span> }</span><br><span> }</span><br><span> </span><br><span>@@ -1261,6 +1273,8 @@</span><br><span> ao2_ref(ice, -1);</span><br><span> ao2_lock(instance);</span><br><span> if (!rtp->ice || status != PJ_SUCCESS) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE unable to add candidate: %s, %d\n", instance, ast_sockaddr_stringify(</span><br><span style="color: hsl(120, 100%, 40%);">+ &candidate->address), candidate->priority);</span><br><span> ao2_ref(candidate, -1);</span><br><span> return;</span><br><span> }</span><br><span>@@ -1268,6 +1282,9 @@</span><br><span> /* By placing the candidate into the ICE session it will have produced the priority, so update the local candidate with it */</span><br><span> candidate->priority = rtp->ice->real_ice->lcand[rtp->ice->real_ice->lcand_cnt - 1].prio;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE add candidate: %s, %d\n", instance, ast_sockaddr_stringify(</span><br><span style="color: hsl(120, 100%, 40%);">+ &candidate->address), candidate->priority);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> ao2_link(rtp->ice_local_candidates, candidate);</span><br><span> ao2_ref(candidate, -1);</span><br><span> }</span><br><span>@@ -1292,8 +1309,8 @@</span><br><span> char buf[100];</span><br><span> </span><br><span> pj_strerror(status, buf, sizeof(buf));</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "PJ ICE Rx error status code: %d '%s'.\n",</span><br><span style="color: hsl(0, 100%, 40%);">- (int)status, buf);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_WARNING, "(%p) ICE PJ Rx error status code: %d '%s'.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, (int)status, buf);</span><br><span> return;</span><br><span> }</span><br><span> if (!rtp->rtp_passthrough) {</span><br><span>@@ -1624,7 +1641,7 @@</span><br><span> turn_cb, &turn_sock_cfg, instance, turn_sock);</span><br><span> ao2_cleanup(ice);</span><br><span> if (status != PJ_SUCCESS) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Could not create a TURN client socket\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_WARNING, "(%p) Could not create a TURN client socket\n", instance);</span><br><span> ao2_lock(instance);</span><br><span> return;</span><br><span> }</span><br><span>@@ -1635,6 +1652,11 @@</span><br><span> pj_strset2(&cred.data.static_cred.data, (char*)password);</span><br><span> </span><br><span> pj_turn_sock_alloc(*turn_sock, pj_cstr(&turn_addr, server), port, NULL, &cred, NULL);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE request TURN %s %s candidate\n", instance,</span><br><span style="color: hsl(120, 100%, 40%);">+ transport == AST_TRANSPORT_UDP ? "UDP" : "TCP",</span><br><span style="color: hsl(120, 100%, 40%);">+ component == AST_RTP_ICE_COMPONENT_RTP ? "RTP" : "RTCP");</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> ao2_lock(instance);</span><br><span> </span><br><span> /*</span><br><span>@@ -1688,6 +1710,9 @@</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE change number of components %u -> %u\n", instance,</span><br><span style="color: hsl(120, 100%, 40%);">+ rtp->ice_num_components, num_components);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> rtp->ice_num_components = num_components;</span><br><span> ice_reset_session(instance);</span><br><span> }</span><br><span>@@ -1782,6 +1807,7 @@</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS RTCP setup\n", instance);</span><br><span> return dtls_details_initialize(&rtp->rtcp->dtls, rtp->ssl_ctx, rtp->dtls.dtls_setup, instance);</span><br><span> }</span><br><span> </span><br><span>@@ -2075,6 +2101,8 @@</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS RTP setup\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> if (!ast_rtp_engine_srtp_is_registered()) {</span><br><span> ast_log(LOG_ERROR, "SRTP support module is not loaded or available. Try loading res_srtp.so.\n");</span><br><span> return -1;</span><br><span>@@ -2197,6 +2225,7 @@</span><br><span> struct ast_rtp *rtp = ast_rtp_instance_get_data(instance);</span><br><span> SSL *ssl = rtp->dtls.ssl;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS stop\n", instance);</span><br><span> ao2_unlock(instance);</span><br><span> dtls_srtp_stop_timeout_timer(instance, rtp, 0);</span><br><span> ao2_lock(instance);</span><br><span>@@ -2469,7 +2498,7 @@</span><br><span> {</span><br><span> struct ast_rtp *rtp = ast_rtp_instance_get_data(instance);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "dtls_perform_handshake (%p) - ssl = %p, setup = %d\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS perform handshake - ssl = %p, setup = %d\n",</span><br><span> rtp, dtls->ssl, dtls->dtls_setup);</span><br><span> </span><br><span> /* If we are not acting as a client connecting to the remote side then</span><br><span>@@ -2509,7 +2538,7 @@</span><br><span> }</span><br><span> dtls->connection = AST_RTP_DTLS_CONNECTION_NEW;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "dtls_perform_setup - connection reset'\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "DTLS perform setup - connection reset\n", 0);</span><br><span> }</span><br><span> #endif</span><br><span> </span><br><span>@@ -2548,7 +2577,8 @@</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "ast_rtp_on_ice_complete (%p) - perform DTLS\n", rtp);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(2, AST_DEBUG_CATEGORY_ICE | AST_DEBUG_CATEGORY_DTLS,</span><br><span style="color: hsl(120, 100%, 40%);">+ "(%p) ICE starting media - perform DTLS - (%p)\n", instance, rtp);</span><br><span> </span><br><span> /*</span><br><span> * Seemingly no reason to call dtls_perform_setup here. Currently we'll do a full</span><br><span>@@ -2585,6 +2615,7 @@</span><br><span> /* PJPROJECT ICE optional callback */</span><br><span> static void ast_rtp_on_valid_pair(pj_ice_sess *ice)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE valid pair, start media\n", ice->user_data);</span><br><span> ast_rtp_ice_start_media(ice, PJ_SUCCESS);</span><br><span> }</span><br><span> #endif</span><br><span>@@ -2592,6 +2623,7 @@</span><br><span> /* PJPROJECT ICE callback */</span><br><span> static void ast_rtp_on_ice_complete(pj_ice_sess *ice, pj_status_t status)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE complete, start media\n", ice->user_data);</span><br><span> ast_rtp_ice_start_media(ice, status);</span><br><span> }</span><br><span> </span><br><span>@@ -2681,7 +2713,7 @@</span><br><span> </span><br><span> static inline int rtp_debug_test_addr(struct ast_sockaddr *addr)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">- if (!rtpdebug) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!ast_debug_rtp_packet_allow) {</span><br><span> return 0;</span><br><span> }</span><br><span> if (!ast_sockaddr_isnull(&rtpdebugaddr)) {</span><br><span>@@ -2697,7 +2729,7 @@</span><br><span> </span><br><span> static inline int rtcp_debug_test_addr(struct ast_sockaddr *addr)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">- if (!rtcpdebug) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!ast_debug_rtcp_packet_allow) {</span><br><span> return 0;</span><br><span> }</span><br><span> if (!ast_sockaddr_isnull(&rtcpdebugaddr)) {</span><br><span>@@ -2719,6 +2751,7 @@</span><br><span> struct dtls_details *dtls = !rtcp ? &rtp->dtls : &rtp->rtcp->dtls;</span><br><span> struct timeval dtls_timeout;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS srtp - handle timeout - rtcp=%d\n", instance, rtcp);</span><br><span> DTLSv1_handle_timeout(dtls->ssl);</span><br><span> </span><br><span> /* If a timeout can't be retrieved then this recurring scheduled item must stop */</span><br><span>@@ -2778,6 +2811,8 @@</span><br><span> ao2_ref(instance, -1);</span><br><span> ast_log(LOG_WARNING, "Scheduling '%s' DTLS retransmission for RTP instance [%p] failed.\n",</span><br><span> !rtcp ? "RTP" : "RTCP", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS srtp - scheduled timeout timer for '%d'\n", instance, timeout);</span><br><span> }</span><br><span> }</span><br><span> }</span><br><span>@@ -2788,6 +2823,7 @@</span><br><span> struct dtls_details *dtls = !rtcp ? &rtp->dtls : &rtp->rtcp->dtls;</span><br><span> </span><br><span> AST_SCHED_DEL_UNREF(rtp->sched, dtls->timeout_timer, ao2_ref(instance, -1));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS srtp - stopped timeout timer'\n", instance);</span><br><span> }</span><br><span> </span><br><span> /* Scheduler callback */</span><br><span>@@ -2798,6 +2834,7 @@</span><br><span> </span><br><span> ao2_lock(instance);</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS srtp - renegotiate'\n", instance);</span><br><span> SSL_renegotiate(rtp->dtls.ssl);</span><br><span> SSL_do_handshake(rtp->dtls.ssl);</span><br><span> </span><br><span>@@ -2822,6 +2859,9 @@</span><br><span> int res = -1;</span><br><span> struct dtls_details *dtls = !rtcp ? &rtp->dtls : &rtp->rtcp->dtls;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS srtp - add local ssrc - rtcp=%d, set_remote_policy=%d'\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtcp, set_remote_policy);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /* Produce key information and set up SRTP */</span><br><span> if (!SSL_export_keying_material(dtls->ssl, material, SRTP_MASTER_LEN * 2, "EXTRACTOR-dtls_srtp", 19, NULL, 0, 0)) {</span><br><span> ast_log(LOG_WARNING, "Unable to extract SRTP keying material from DTLS-SRTP negotiation on RTP instance '%p'\n",</span><br><span>@@ -2899,7 +2939,7 @@</span><br><span> struct dtls_details *dtls = !rtcp ? &rtp->dtls : &rtp->rtcp->dtls;</span><br><span> int index;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Setup DTLS SRTP (%p)'\n", rtp);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS setup SRTP rtp=%p'\n", instance, rtp);</span><br><span> </span><br><span> /* If a fingerprint is present in the SDP make sure that the peer certificate matches it */</span><br><span> if (rtp->dtls_verify & AST_RTP_DTLS_VERIFY_FINGERPRINT) {</span><br><span>@@ -3048,7 +3088,7 @@</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "__rtp_recvfrom (%p) - Got SSL packet '%d'\n", rtp, *in);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS - __rtp_recvfrom rtp=%p - Got SSL packet '%d'\n", instance, rtp, *in);</span><br><span> </span><br><span> /*</span><br><span> * A race condition is prevented between dtls_perform_handshake()</span><br><span>@@ -3090,7 +3130,7 @@</span><br><span> /* Notify that dtls has been established */</span><br><span> res = RTP_DTLS_ESTABLISHED;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "__rtp_recvfrom (%p) - DTLS established'\n", rtp);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS - __rtp_recvfrom rtp=%p - established'\n", instance, rtp);</span><br><span> } else {</span><br><span> /* Since we've sent additional traffic start the timeout timer for retransmission */</span><br><span> dtls_srtp_start_timeout_timer(instance, rtp, rtcp);</span><br><span>@@ -3484,9 +3524,10 @@</span><br><span> </span><br><span> if (getifaddrs(&ifa) < 0) {</span><br><span> /* If we can't get addresses, we can't load ICE candidates */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_ERROR, "Error obtaining list of local addresses: %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- strerror(errno));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "(%p) ICE Error obtaining list of local addresses: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, strerror(errno));</span><br><span> } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE add system candidates\n", instance);</span><br><span> /* Iterate through the list of addresses obtained from the system,</span><br><span> * until we've iterated through all of them, or accepted</span><br><span> * PJ_ICE_MAX_CAND candidates */</span><br><span>@@ -3588,6 +3629,11 @@</span><br><span> struct sockaddr_in answer;</span><br><span> int rsp;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category(3, AST_DEBUG_CATEGORY_ICE | AST_DEBUG_CATEGORY_STUN,</span><br><span style="color: hsl(120, 100%, 40%);">+ "(%p) ICE request STUN %s %s candidate\n", instance,</span><br><span style="color: hsl(120, 100%, 40%);">+ transport == AST_TRANSPORT_UDP ? "UDP" : "TCP",</span><br><span style="color: hsl(120, 100%, 40%);">+ component == AST_RTP_ICE_COMPONENT_RTP ? "RTP" : "RTCP");</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /*</span><br><span> * The instance should not be locked because we can block</span><br><span> * waiting for a STUN respone.</span><br><span>@@ -3699,6 +3745,8 @@</span><br><span> ao2_cleanup(rtp->ice_local_candidates);</span><br><span> rtp->ice_local_candidates = NULL;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE create%s\n", instance, replace ? " and replace" : "");</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> ice = ao2_alloc_options(sizeof(*ice), ice_wrap_dtor, AO2_ALLOC_OPT_LOCK_NOLOCK);</span><br><span> if (!ice) {</span><br><span> ast_rtp_ice_stop(instance);</span><br><span>@@ -3782,7 +3830,7 @@</span><br><span> ast_sockaddr_set_port(&rtp->bind_address, x);</span><br><span> /* Try to bind, this will tell us whether the port is available or not */</span><br><span> if (!ast_bind(rtp->s, &rtp->bind_address)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Allocated port %d for RTP instance '%p'\n", x, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP allocated port %d\n", instance, x);</span><br><span> ast_rtp_instance_set_local_address(instance, &rtp->bind_address);</span><br><span> ast_test_suite_event_notify("RTP_PORT_ALLOCATED", "Port: %d", x);</span><br><span> break;</span><br><span>@@ -3812,9 +3860,10 @@</span><br><span> /* Create an ICE session for ICE negotiation */</span><br><span> if (icesupport) {</span><br><span> rtp->ice_num_components = 2;</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Creating ICE session %s (%d) for RTP instance '%p'\n", ast_sockaddr_stringify(&rtp->bind_address), x, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE creating session %s (%d)\n", instance,</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_sockaddr_stringify(&rtp->bind_address), x);</span><br><span> if (ice_create(instance, &rtp->bind_address, x, 0)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_NOTICE, "Failed to create ICE session\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_NOTICE, "(%p) ICE failed to create session\n", instance);</span><br><span> } else {</span><br><span> rtp->ice_port = x;</span><br><span> ast_sockaddr_copy(&rtp->ice_original_rtp_addr, &rtp->bind_address);</span><br><span>@@ -3891,6 +3940,7 @@</span><br><span> rtp->turn_rtcp = NULL;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_ice(2, "(%p) ICE RTP transport deallocating\n", instance);</span><br><span> /* Destroy any ICE session */</span><br><span> ast_rtp_ice_stop(instance);</span><br><span> </span><br><span>@@ -4218,7 +4268,8 @@</span><br><span> rtp->dtmfmute = ast_tvadd(ast_tvnow(), ast_tv(0, 500000));</span><br><span> </span><br><span> if (duration > 0 && (measured_samples = duration * ast_rtp_get_rate(rtp->f.subclass.format) / 1000) > rtp->send_duration) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Adjusting final end duration from %d to %u\n", rtp->send_duration, measured_samples);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP adjusting final end duration from %d to %u\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp->send_duration, measured_samples);</span><br><span> rtp->send_duration = measured_samples;</span><br><span> }</span><br><span> </span><br><span>@@ -4281,7 +4332,7 @@</span><br><span> </span><br><span> /* We simply set this bit so that the next packet sent will have the marker bit turned on */</span><br><span> ast_set_flag(rtp, FLAG_NEED_MARKER_BIT);</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Setting the marker bit due to a source update\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP setting the marker bit due to a source update\n", instance);</span><br><span> </span><br><span> return;</span><br><span> }</span><br><span>@@ -4299,10 +4350,12 @@</span><br><span> ast_set_flag(rtp, FLAG_NEED_MARKER_BIT);</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Changing ssrc from %u to %u due to a source change\n", rtp->ssrc, ssrc);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP changing ssrc from %u to %u due to a source change\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp->ssrc, ssrc);</span><br><span> </span><br><span> if (srtp) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Changing ssrc for SRTP from %u to %u\n", rtp->ssrc, ssrc);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP changing ssrc for SRTP from %u to %u\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp->ssrc, ssrc);</span><br><span> res_srtp->change_source(srtp, rtp->ssrc, ssrc);</span><br><span> if (rtcp_srtp != srtp) {</span><br><span> res_srtp->change_source(rtcp_srtp, rtp->ssrc, ssrc);</span><br><span>@@ -4639,7 +4692,7 @@</span><br><span> res = ast_rtcp_generate_report(instance, rtcpheader, report, sr);</span><br><span> </span><br><span> if (res == 0 || res == 1) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to generate %s report!\n", sr ? "SR" : "RR");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to generate %s report!\n", instance, sr ? "SR" : "RR");</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -4648,7 +4701,7 @@</span><br><span> res = ast_rtcp_generate_sdes(instance, rtcpheader + packet_len, report);</span><br><span> </span><br><span> if (res == 0 || res == 1) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to generate SDES!\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to generate SDES!\n", instance);</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -4856,7 +4909,8 @@</span><br><span> if (abs((int)rtp->lastts - pred) < MAX_TIMESTAMP_SKEW) {</span><br><span> rtp->lastts = pred;</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Difference is %d, ms is %u\n", abs((int)rtp->lastts - pred), ms);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP audio difference is %d, ms is %u\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, abs((int)rtp->lastts - pred), ms);</span><br><span> mark = 1;</span><br><span> }</span><br><span> }</span><br><span>@@ -4871,7 +4925,8 @@</span><br><span> rtp->lastts = pred;</span><br><span> rtp->lastovidtimestamp += frame->samples;</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Difference is %d, ms is %u (%u), pred/ts/samples %u/%d/%d\n", abs((int)rtp->lastts - pred), ms, ms * 90, rtp->lastts, pred, frame->samples);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP video difference is %d, ms is %u (%u), pred/ts/samples %u/%d/%d\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, abs((int)rtp->lastts - pred), ms, ms * 90, rtp->lastts, pred, frame->samples);</span><br><span> rtp->lastovidtimestamp = rtp->lastts;</span><br><span> }</span><br><span> }</span><br><span>@@ -4885,7 +4940,8 @@</span><br><span> rtp->lastts = pred;</span><br><span> rtp->lastotexttimestamp += frame->samples;</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "Difference is %d, ms is %u, pred/ts/samples %u/%d/%d\n", abs((int)rtp->lastts - pred), ms, rtp->lastts, pred, frame->samples);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(3, "(%p) RTP other difference is %d, ms is %u, pred/ts/samples %u/%d/%d\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, abs((int)rtp->lastts - pred), ms, rtp->lastts, pred, frame->samples);</span><br><span> rtp->lastotexttimestamp = rtp->lastts;</span><br><span> }</span><br><span> }</span><br><span>@@ -5001,20 +5057,20 @@</span><br><span> res = rtp_sendto(instance, (void *)rtpheader, packet_len, 0, &remote_address, &ice);</span><br><span> if (res < 0) {</span><br><span> if (!ast_rtp_instance_get_prop(instance, AST_RTP_PROPERTY_NAT) || (ast_rtp_instance_get_prop(instance, AST_RTP_PROPERTY_NAT) && (ast_test_flag(rtp, FLAG_NAT_ACTIVE) == FLAG_NAT_ACTIVE))) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "RTP Transmission error of packet %d to %s: %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- rtp->seqno,</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP transmission error of packet %d to %s: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp->seqno,</span><br><span> ast_sockaddr_stringify(&remote_address),</span><br><span> strerror(errno));</span><br><span style="color: hsl(0, 100%, 40%);">- } else if (((ast_test_flag(rtp, FLAG_NAT_ACTIVE) == FLAG_NAT_INACTIVE) || rtpdebug) && !ast_test_flag(rtp, FLAG_NAT_INACTIVE_NOWARN)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (((ast_test_flag(rtp, FLAG_NAT_ACTIVE) == FLAG_NAT_INACTIVE) || ast_debug_rtp_packet_allow) && !ast_test_flag(rtp, FLAG_NAT_INACTIVE_NOWARN)) {</span><br><span> /* Only give this error message once if we are not RTP debugging */</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug)</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(0, "RTP NAT: Can't write RTP to private address %s, waiting for other end to send audio...\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&remote_address));</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow)</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug(0, "(%p) RTP NAT: Can't write RTP to private address %s, waiting for other end to send audio...\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&remote_address));</span><br><span> ast_set_flag(rtp, FLAG_NAT_INACTIVE_NOWARN);</span><br><span> }</span><br><span> } else {</span><br><span> if (rtp->rtcp && rtp->rtcp->schedid < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Starting RTCP transmission on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP starting transmission\n", instance);</span><br><span> ao2_ref(instance, +1);</span><br><span> rtp->rtcp->schedid = ast_sched_add(rtp->sched, ast_rtcp_calc_interval(rtp), ast_rtcp_write, instance);</span><br><span> if (rtp->rtcp->schedid < 0) {</span><br><span>@@ -5160,8 +5216,8 @@</span><br><span> ao2_cleanup);</span><br><span> </span><br><span> if (feedback->fmt != AST_RTP_RTCP_FMT_REMB) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Provided an RTCP feedback frame of format %d to write on RTP instance '%p' but only REMB is supported\n",</span><br><span style="color: hsl(0, 100%, 40%);">- feedback->fmt, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP provided feedback frame of format %d to write, but only REMB is supported\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, feedback->fmt);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>@@ -5171,7 +5227,7 @@</span><br><span> </span><br><span> /* If REMB support is not enabled don't send this RTCP packet */</span><br><span> if (!ast_rtp_instance_get_prop(instance, AST_RTP_PROPERTY_REMB)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Provided an RTCP feedback REMB report to write on RTP instance '%p' but REMB support not enabled\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP provided feedback REMB report to write, but REMB support not enabled\n",</span><br><span> instance);</span><br><span> return;</span><br><span> }</span><br><span>@@ -5223,7 +5279,7 @@</span><br><span> </span><br><span> /* If we don't actually know the remote address don't even bother doing anything */</span><br><span> if (ast_sockaddr_isnull(&remote_address)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "No remote address on RTP instance '%p' so dropping frame\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP no remote address on instance, so dropping frame\n", instance);</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -5240,7 +5296,7 @@</span><br><span> </span><br><span> /* If there is no data length we can't very well send the packet */</span><br><span> if (!frame->datalen) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Received frame with no data for RTP instance '%p' so dropping frame\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP received frame with no data for instance, so dropping frame\n", instance);</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -5272,8 +5328,8 @@</span><br><span> format = frame->subclass.format;</span><br><span> if (ast_format_cmp(rtp->lasttxformat, format) == AST_FORMAT_CMP_NOT_EQUAL) {</span><br><span> /* Oh dear, if the format changed we will have to set up a new smoother */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Ooh, format changed from %s to %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_format_get_name(rtp->lasttxformat),</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP ooh, format changed from %s to %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_format_get_name(rtp->lasttxformat),</span><br><span> ast_format_get_name(frame->subclass.format));</span><br><span> ao2_replace(rtp->lasttxformat, format);</span><br><span> if (rtp->smoother) {</span><br><span>@@ -5398,14 +5454,14 @@</span><br><span> ast_rtp_instance_get_remote_address(instance, &remote_address);</span><br><span> </span><br><span> if (((compensate && type == AST_FRAME_DTMF_END) || (type == AST_FRAME_DTMF_BEGIN)) && ast_tvcmp(ast_tvnow(), rtp->dtmfmute) < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Ignore potential DTMF echo from '%s'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&remote_address));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP ignore potential DTMF echo from '%s'\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&remote_address));</span><br><span> rtp->resp = 0;</span><br><span> rtp->dtmfsamples = 0;</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Creating %s DTMF Frame: %d (%c), at %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- type == AST_FRAME_DTMF_END ? "END" : "BEGIN",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP creating %s DTMF Frame: %d (%c), at %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, type == AST_FRAME_DTMF_END ? "END" : "BEGIN",</span><br><span> rtp->resp, rtp->resp,</span><br><span> ast_sockaddr_stringify(&remote_address));</span><br><span> if (rtp->resp == 'X') {</span><br><span>@@ -5450,7 +5506,7 @@</span><br><span> }</span><br><span> </span><br><span> /* Print out debug if turned on */</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow)</span><br><span> ast_debug(0, "- RTP 2833 Event: %08x (len = %d)\n", event, len);</span><br><span> </span><br><span> /* Figure out what digit was pressed */</span><br><span>@@ -5466,7 +5522,7 @@</span><br><span> resp = 'X';</span><br><span> } else {</span><br><span> /* Not a supported event */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Ignoring RTP 2833 Event: %08x. Not a DTMF Digit.\n", event);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP ignoring RTP 2833 Event: %08x. Not a DTMF Digit.\n", instance, event);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>@@ -5504,9 +5560,9 @@</span><br><span> rtp->resp = 0;</span><br><span> rtp->dtmf_duration = rtp->dtmf_timeout = 0;</span><br><span> AST_LIST_INSERT_TAIL(frames, f, frame_list);</span><br><span style="color: hsl(0, 100%, 40%);">- } else if (rtpdebug) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Dropping duplicate or out of order DTMF END frame (seqno: %u, ts %u, digit %c)\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, timestamp, resp);</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (ast_debug_rtp_packet_allow) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP dropping duplicate or out of order DTMF END frame (seqno: %u, ts %u, digit %c)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno, timestamp, resp);</span><br><span> }</span><br><span> } else {</span><br><span> /* Begin/continuation */</span><br><span>@@ -5521,8 +5577,8 @@</span><br><span> * improperly duplicate incoming DTMF, so just drop</span><br><span> * this.</span><br><span> */</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Dropping out of order DTMF frame (seqno %u, ts %u, digit %c)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug(0, "Dropping out of order DTMF frame (seqno %u, ts %u, digit %c)\n",</span><br><span> seqno, timestamp, resp);</span><br><span> }</span><br><span> return;</span><br><span>@@ -5606,7 +5662,7 @@</span><br><span> power = data[2];</span><br><span> event = data[3] & 0x1f;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug)</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow)</span><br><span> ast_debug(0, "Cisco DTMF Digit: %02x (len=%d, seq=%d, flags=%02x, power=%u, history count=%d)\n", event, len, seq, flags, power, (len - 4) / 2);</span><br><span> if (event < 10) {</span><br><span> resp = '0' + event;</span><br><span>@@ -5646,7 +5702,7 @@</span><br><span> /* Convert comfort noise into audio with various codecs. Unfortunately this doesn't</span><br><span> totally help us out becuase we don't have an engine to keep it going and we are not</span><br><span> guaranteed to have it every 20ms or anything */</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow) {</span><br><span> ast_debug(0, "- RTP 3389 Comfort noise event: Format %s (len = %d)\n",</span><br><span> ast_format_get_name(rtp->lastrxformat), len);</span><br><span> }</span><br><span>@@ -5888,7 +5944,8 @@</span><br><span> unsigned int packets_not_found = 0;</span><br><span> </span><br><span> if (!rtp->send_buffer) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Tried to handle NACK request, but we don't have a RTP packet storage!\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP tried to handle NACK request, "</span><br><span style="color: hsl(120, 100%, 40%);">+ "but we don't have a RTP packet storage!\n", instance);</span><br><span> return res;</span><br><span> }</span><br><span> </span><br><span>@@ -5917,7 +5974,8 @@</span><br><span> }</span><br><span> res += rtp_sendto(instance, payload->buf, payload->size, 0, &remote_address, &ice);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Received NACK request for RTP packet with seqno %d, but we don't have it\n", pid);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP received NACK request for RTP packet with seqno %d, "</span><br><span style="color: hsl(120, 100%, 40%);">+ "but we don't have it\n", instance, pid);</span><br><span> packets_not_found++;</span><br><span> }</span><br><span> /*</span><br><span>@@ -5939,7 +5997,8 @@</span><br><span> }</span><br><span> res += rtp_sendto(instance, payload->buf, payload->size, 0, &remote_address, &ice);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Remote end also requested RTP packet with seqno %d, but we don't have it\n", seqno);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP remote end also requested RTP packet with seqno %d, "</span><br><span style="color: hsl(120, 100%, 40%);">+ "but we don't have it\n", instance, seqno);</span><br><span> packets_not_found++;</span><br><span> }</span><br><span> }</span><br><span>@@ -5954,7 +6013,8 @@</span><br><span> */</span><br><span> ast_data_buffer_resize(rtp->send_buffer, MIN(MAXIMUM_RTP_SEND_BUFFER_SIZE,</span><br><span> ast_data_buffer_max(rtp->send_buffer) + packets_not_found));</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Send buffer on RTP instance '%p' is now at maximum of %zu\n", instance, ast_data_buffer_max(rtp->send_buffer));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(2, "(%p) RTCP send buffer on RTP instance is now at maximum of %zu\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_data_buffer_max(rtp->send_buffer));</span><br><span> }</span><br><span> </span><br><span> return res;</span><br><span>@@ -6028,23 +6088,23 @@</span><br><span> </span><br><span> packetwords = len / 4;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Got RTCP report of %d bytes from %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- len, ast_sockaddr_stringify(addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP got report of %d bytes from %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, len, ast_sockaddr_stringify(addr));</span><br><span> </span><br><span> /*</span><br><span> * Validate the RTCP packet according to an adapted and slightly</span><br><span> * modified RFC3550 validation algorithm.</span><br><span> */</span><br><span> if (packetwords < RTCP_HEADER_SSRC_LENGTH) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- RTCP from %s: Frame size (%u words) is too short\n",</span><br><span style="color: hsl(0, 100%, 40%);">- transport_rtp, ast_sockaddr_stringify(addr), packetwords);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP %p -- from %s: Frame size (%u words) is too short\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, transport_rtp, ast_sockaddr_stringify(addr), packetwords);</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> position = 0;</span><br><span> first_word = ntohl(rtcpheader[position]);</span><br><span> if ((first_word & RTCP_VALID_MASK) != RTCP_VALID_VALUE) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- RTCP from %s: Failed first packet validity check\n",</span><br><span style="color: hsl(0, 100%, 40%);">- transport_rtp, ast_sockaddr_stringify(addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP %p -- from %s: Failed first packet validity check\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, transport_rtp, ast_sockaddr_stringify(addr));</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> do {</span><br><span>@@ -6055,8 +6115,8 @@</span><br><span> first_word = ntohl(rtcpheader[position]);</span><br><span> } while ((first_word & RTCP_VERSION_MASK_SHIFTED) == RTCP_VERSION_SHIFTED);</span><br><span> if (position != packetwords) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- RTCP from %s: Failed packet version or length check\n",</span><br><span style="color: hsl(0, 100%, 40%);">- transport_rtp, ast_sockaddr_stringify(addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP %p -- from %s: Failed packet version or length check\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, transport_rtp, ast_sockaddr_stringify(addr));</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> </span><br><span>@@ -6146,8 +6206,8 @@</span><br><span> min_length = length;</span><br><span> break;</span><br><span> default:</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- RTCP from %s: %u(%s) skipping record\n",</span><br><span style="color: hsl(0, 100%, 40%);">- transport_rtp, ast_sockaddr_stringify(addr), pt, rtcp_payload_type2str(pt));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP %p -- from %s: %u(%s) skipping record\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, transport_rtp, ast_sockaddr_stringify(addr), pt, rtcp_payload_type2str(pt));</span><br><span> if (rtcp_debug_test_addr(addr)) {</span><br><span> ast_verbose("\n");</span><br><span> ast_verbose("RTCP from %s: %u(%s) skipping record\n",</span><br><span>@@ -6157,8 +6217,8 @@</span><br><span> continue;</span><br><span> }</span><br><span> if (length < min_length) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- RTCP from %s: %u(%s) length field less than expected minimum. Min:%u Got:%u\n",</span><br><span style="color: hsl(0, 100%, 40%);">- transport_rtp, ast_sockaddr_stringify(addr), pt, rtcp_payload_type2str(pt),</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP %p -- from %s: %u(%s) length field less than expected minimum. Min:%u Got:%u\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, transport_rtp, ast_sockaddr_stringify(addr), pt, rtcp_payload_type2str(pt),</span><br><span> min_length - 1, length - 1);</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span>@@ -6248,8 +6308,8 @@</span><br><span> * for a different stream.</span><br><span> */</span><br><span> position += length;</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- RTCP from %s: Skipping record, received SSRC '%u' != expected '%u'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- rtp, ast_sockaddr_stringify(addr), ssrc, rtp->themssrc);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP %p -- from %s: Skipping record, received SSRC '%u' != expected '%u'\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp, ast_sockaddr_stringify(addr), ssrc, rtp->themssrc);</span><br><span> if (child) {</span><br><span> ao2_unlock(child);</span><br><span> }</span><br><span>@@ -6262,9 +6322,9 @@</span><br><span> /* Send to whoever sent to us */</span><br><span> if (ast_sockaddr_cmp(&rtp->rtcp->them, addr)) {</span><br><span> ast_sockaddr_copy(&rtp->rtcp->them, addr);</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(0, "RTCP NAT: Got RTCP from other end. Now sending to address %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug(0, "(%p) RTCP NAT: Got RTCP from other end. Now sending to address %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(addr));</span><br><span> }</span><br><span> }</span><br><span> }</span><br><span>@@ -6527,12 +6587,12 @@</span><br><span> if (ast_sockaddr_is_ipv4(&addr)) {</span><br><span> ast_sockaddr_to_sin(&addr, &addr_tmp);</span><br><span> } else if (ast_sockaddr_ipv4_mapped(&addr, &addr_v4)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Using IPv6 mapped address %s for STUN\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(2, "(%p) STUN using IPv6 mapped address %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&addr));</span><br><span> ast_sockaddr_to_sin(&addr_v4, &addr_tmp);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Cannot do STUN for non IPv4 address %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(2, "(%p) STUN cannot do for non IPv4 address %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&addr));</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> if ((ast_stun_handle_packet(rtp->rtcp->s, &addr_tmp, read_area, res, NULL, NULL) == AST_STUN_ACCEPT)) {</span><br><span>@@ -6579,7 +6639,7 @@</span><br><span> </span><br><span> /* If the payload coming in is not one of the negotiated ones then send it to the core, this will cause formats to change and the bridge to break */</span><br><span> if (ast_rtp_codecs_find_payload_code(ast_rtp_instance_get_codecs(instance1), bridged_payload) == -1) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Unsupported payload type received \n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p, %p) RTP unsupported payload type received\n", instance, instance1);</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span>@@ -6589,7 +6649,7 @@</span><br><span> * core so they can be filtered accordingly.</span><br><span> */</span><br><span> if (rtp->last_end_timestamp == timestamp) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Feeding packet with duplicate timestamp to core\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p, %p) RTP feeding packet with duplicate timestamp to core\n", instance, instance1);</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span>@@ -6621,7 +6681,7 @@</span><br><span> </span><br><span> /* If bridged peer is in dtmf, feed all packets to core until it finishes to avoid infinite dtmf */</span><br><span> if (bridged->sending_digit) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Feeding packet to core until DTMF finishes\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p, %p) RTP Feeding packet to core until DTMF finishes\n", instance, instance1);</span><br><span> ao2_unlock(instance1);</span><br><span> ao2_lock(instance);</span><br><span> return -1;</span><br><span>@@ -6635,8 +6695,8 @@</span><br><span> if (!bridged->asymmetric_codec</span><br><span> && bridged->lastrxformat != ast_format_none</span><br><span> && ast_format_cmp(payload_type->format, bridged->lastrxformat) == AST_FORMAT_CMP_NOT_EQUAL) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Asymmetric RTP codecs detected (TX: %s, RX: %s) sending frame to core\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_format_get_name(payload_type->format),</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p, %p) RTP asymmetric RTP codecs detected (TX: %s, RX: %s) sending frame to core\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, instance1, ast_format_get_name(payload_type->format),</span><br><span> ast_format_get_name(bridged->lastrxformat));</span><br><span> ao2_unlock(instance1);</span><br><span> ao2_lock(instance);</span><br><span>@@ -6649,7 +6709,8 @@</span><br><span> ast_rtp_instance_get_remote_address(instance1, &remote_address);</span><br><span> </span><br><span> if (ast_sockaddr_isnull(&remote_address)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(5, "Remote address is null, most likely RTP has been stopped\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(5, "(%p, %p) RTP remote address is null, most likely RTP has been stopped\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, instance1);</span><br><span> ao2_unlock(instance1);</span><br><span> ao2_lock(instance);</span><br><span> return 0;</span><br><span>@@ -6686,8 +6747,8 @@</span><br><span> "RTP Transmission error of packet to %s: %s\n",</span><br><span> ast_sockaddr_stringify(&remote_address),</span><br><span> strerror(errno));</span><br><span style="color: hsl(0, 100%, 40%);">- } else if (((ast_test_flag(bridged, FLAG_NAT_ACTIVE) == FLAG_NAT_INACTIVE) || rtpdebug) && !ast_test_flag(bridged, FLAG_NAT_INACTIVE_NOWARN)) {</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug || DEBUG_ATLEAST(1)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (((ast_test_flag(bridged, FLAG_NAT_ACTIVE) == FLAG_NAT_INACTIVE) || ast_debug_rtp_packet_allow) && !ast_test_flag(bridged, FLAG_NAT_INACTIVE_NOWARN)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow || DEBUG_ATLEAST(1)) {</span><br><span> ast_log(LOG_WARNING,</span><br><span> "RTP NAT: Can't write RTP to private "</span><br><span> "address %s, waiting for other end to "</span><br><span>@@ -6965,8 +7026,8 @@</span><br><span> /* The packet is now fully constructed so send it out */</span><br><span> ast_sockaddr_copy(&remote_address, &rtp->rtcp->them);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Sending transport-cc feedback packet of size '%d' on '%s' with packet count of %d (small = %d, large = %d, lost = %d)\n",</span><br><span style="color: hsl(0, 100%, 40%);">- packet_len, ast_rtp_instance_get_channel_id(instance), packet_count, small_delta_count, large_delta_count, lost_count);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(2, "(%p) RTCP sending transport-cc feedback packet of size '%d' on '%s' with packet count of %d (small = %d, large = %d, lost = %d)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, packet_len, ast_rtp_instance_get_channel_id(instance), packet_count, small_delta_count, large_delta_count, lost_count);</span><br><span> </span><br><span> res = rtcp_sendto(instance, (unsigned int *)rtcpheader, packet_len, 0, &remote_address, &ice);</span><br><span> if (res < 0) {</span><br><span>@@ -7026,7 +7087,7 @@</span><br><span> </span><br><span> /* If we have not yet scheduled the periodic sending of feedback for this transport then do so */</span><br><span> if (transport_rtp->transport_wide_cc.schedid < 0 && transport_rtp->rtcp) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Starting RTCP transport-cc feedback transmission on RTP instance '%p'\n", transport);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP starting transport-cc feedback transmission on RTP instance '%p'\n", instance, transport);</span><br><span> ao2_ref(transport, +1);</span><br><span> transport_rtp->transport_wide_cc.schedid = ast_sched_add(rtp->sched, 1000,</span><br><span> rtp_transport_wide_cc_feedback_produce, transport);</span><br><span>@@ -7460,12 +7521,12 @@</span><br><span> if (ast_sockaddr_is_ipv4(&addr)) {</span><br><span> ast_sockaddr_to_sin(&addr, &addr_tmp);</span><br><span> } else if (ast_sockaddr_ipv4_mapped(&addr, &addr_v4)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Using IPv6 mapped address %s for STUN\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "(%p) STUN using IPv6 mapped address %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&addr));</span><br><span> ast_sockaddr_to_sin(&addr_v4, &addr_tmp);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Cannot do STUN for non IPv4 address %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_stun(1, "(%p) STUN cannot do for non IPv4 address %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&addr));</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> if ((ast_stun_handle_packet(rtp->s, &addr_tmp, read_area, res, NULL, NULL) == AST_STUN_ACCEPT) &&</span><br><span>@@ -7611,8 +7672,8 @@</span><br><span> break;</span><br><span> }</span><br><span> /* Not ready to accept the RTP stream candidate */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- Received RTP packet from %s, dropping due to strict RTP protection. Will switch to it in %d packets.\n",</span><br><span style="color: hsl(0, 100%, 40%);">- rtp, ast_sockaddr_stringify(&addr), rtp->rtp_source_learn.packets);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP %p -- Received packet from %s, dropping due to strict RTP protection. Will switch to it in %d packets.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp, ast_sockaddr_stringify(&addr), rtp->rtp_source_learn.packets);</span><br><span> } else {</span><br><span> /*</span><br><span> * This is either an attacking stream or</span><br><span>@@ -7620,8 +7681,8 @@</span><br><span> */</span><br><span> ast_sockaddr_copy(&rtp->rtp_source_learn.proposed_address, &addr);</span><br><span> rtp_learning_seq_init(&rtp->rtp_source_learn, seqno);</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- Received RTP packet from %s, dropping due to strict RTP protection. Qualifying new stream.\n",</span><br><span style="color: hsl(0, 100%, 40%);">- rtp, ast_sockaddr_stringify(&addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP %p -- Received packet from %s, dropping due to strict RTP protection. Qualifying new stream.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp, ast_sockaddr_stringify(&addr));</span><br><span> }</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span>@@ -7639,8 +7700,8 @@</span><br><span> if (!ast_sockaddr_cmp(&rtp->strict_rtp_address, &addr)) {</span><br><span> break;</span><br><span> }</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "%p -- Received RTP packet from %s, dropping due to strict RTP protection.\n",</span><br><span style="color: hsl(0, 100%, 40%);">- rtp, ast_sockaddr_stringify(&addr));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(1, "(%p) RTP %p -- Received packet from %s, dropping due to strict RTP protection.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, rtp, ast_sockaddr_stringify(&addr));</span><br><span> #ifdef TEST_FRAMEWORK</span><br><span> {</span><br><span> static int strict_rtp_test_event = 1;</span><br><span>@@ -7667,9 +7728,9 @@</span><br><span> ast_sockaddr_set_port(&rtp->rtcp->them, ast_sockaddr_port(&addr) + 1);</span><br><span> }</span><br><span> ast_set_flag(rtp, FLAG_NAT_ACTIVE);</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug)</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(0, "RTP NAT: Got audio from other end. Now sending to address %s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- ast_sockaddr_stringify(&remote_address));</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow)</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug(0, "(%p) RTP NAT: Got audio from other end. Now sending to address %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, ast_sockaddr_stringify(&remote_address));</span><br><span> }</span><br><span> }</span><br><span> </span><br><span>@@ -7697,8 +7758,8 @@</span><br><span> };</span><br><span> </span><br><span> if (!mark) {</span><br><span style="color: hsl(0, 100%, 40%);">- if (rtpdebug) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Forcing Marker bit, because SSRC has changed\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ if (ast_debug_rtp_packet_allow) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug(0, "(%p) RTP forcing Marker bit, because SSRC has changed\n", instance);</span><br><span> }</span><br><span> mark = 1;</span><br><span> }</span><br><span>@@ -7750,8 +7811,8 @@</span><br><span> </span><br><span> if (!AST_VECTOR_REMOVE_CMP_ORDERED(&rtp->missing_seqno, seqno, find_by_value,</span><br><span> AST_VECTOR_ELEM_CLEANUP_NOOP)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Packet with sequence number '%d' on RTP instance '%p' is no longer missing\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP Packet with sequence number '%d' on instance is no longer missing\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno);</span><br><span> }</span><br><span> </span><br><span> /* If we don't have the next packet after this we can directly return the frame, as there is no</span><br><span>@@ -7793,8 +7854,8 @@</span><br><span> return AST_LIST_FIRST(&frames);</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Pulled buffered packet with sequence number '%d' to additionally return on RTP instance '%p'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- frame->seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP pulled buffered packet with sequence number '%d' to additionally return\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, frame->seqno);</span><br><span> AST_LIST_INSERT_TAIL(&frames, frame, frame_list);</span><br><span> prev_seqno = rtp->expectedrxseqno;</span><br><span> rtp->expectedrxseqno++;</span><br><span>@@ -7815,7 +7876,7 @@</span><br><span> */</span><br><span> </span><br><span> if (rtp->rtp_source_learn.stream_type == AST_MEDIA_TYPE_VIDEO) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Source on RTP instance '%p' has wild gap or packet loss, sending FIR\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP source has wild gap or packet loss, sending FIR\n",</span><br><span> instance);</span><br><span> rtp_write_rtcp_fir(instance, rtp, &remote_address);</span><br><span> }</span><br><span>@@ -7833,8 +7894,8 @@</span><br><span> if (frame) {</span><br><span> AST_LIST_INSERT_TAIL(&frames, frame, frame_list);</span><br><span> prev_seqno = seqno;</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Inserted just received packet with sequence number '%d' in correct order on RTP instance '%p'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP inserted just received packet with sequence number '%d' in correct order\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno);</span><br><span> }</span><br><span> /* It is possible due to packet retransmission for this packet to also exist in the receive</span><br><span> * buffer so we explicitly remove it in case this occurs, otherwise the receive buffer will</span><br><span>@@ -7858,8 +7919,8 @@</span><br><span> if (frame) {</span><br><span> AST_LIST_INSERT_TAIL(&frames, frame, frame_list);</span><br><span> prev_seqno = rtp->expectedrxseqno;</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Emptying queue and returning packet with sequence number '%d' from RTP instance '%p'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- frame->seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP emptying queue and returning packet with sequence number '%d'\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, frame->seqno);</span><br><span> }</span><br><span> ast_free(payload);</span><br><span> }</span><br><span>@@ -7883,8 +7944,8 @@</span><br><span> rtp->expectedrxseqno = 0;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Adding just received packet with sequence number '%d' to end of dumped queue on RTP instance '%p'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP adding just received packet with sequence number '%d' to end of dumped queue\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno);</span><br><span> }</span><br><span> </span><br><span> /* When we flush increase our chance for next time by growing the receive buffer when possible</span><br><span>@@ -7892,7 +7953,7 @@</span><br><span> */</span><br><span> ast_data_buffer_resize(rtp->recv_buffer, MIN(MAXIMUM_RTP_RECV_BUFFER_SIZE,</span><br><span> ast_data_buffer_max(rtp->recv_buffer) + AST_VECTOR_SIZE(&rtp->missing_seqno)));</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Receive buffer on RTP instance '%p' is now at maximum of %zu\n", instance, ast_data_buffer_max(rtp->recv_buffer));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP receive buffer is now at maximum of %zu\n", instance, ast_data_buffer_max(rtp->recv_buffer));</span><br><span> </span><br><span> /* As there is such a large gap we don't want to flood the order side with missing packets, so we</span><br><span> * give up and start anew.</span><br><span>@@ -7918,13 +7979,13 @@</span><br><span> if ((seqno < rtp->expectedrxseqno && ((rtp->expectedrxseqno - seqno) <= OLD_PACKET_COUNT)) ||</span><br><span> (seqno > rtp->expectedrxseqno && (seqno >= (65535 - OLD_PACKET_COUNT + rtp->expectedrxseqno)))) {</span><br><span> /* If this is a packet from the past then we have received a duplicate packet, so just drop it */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Received an old packet with sequence number '%d' on RTP instance '%p', dropping it\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP received an old packet with sequence number '%d', dropping it\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno);</span><br><span> return &ast_null_frame;</span><br><span> } else if (ast_data_buffer_get(rtp->recv_buffer, seqno)) {</span><br><span> /* If this is a packet we already have buffered then it is a duplicate, so just drop it */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Received a duplicate transmission of packet with sequence number '%d' on RTP instance '%p', dropping it\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP received a duplicate transmission of packet with sequence number '%d', dropping it\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno);</span><br><span> return &ast_null_frame;</span><br><span> } else {</span><br><span> /* This is an out of order packet from the future */</span><br><span>@@ -7933,8 +7994,8 @@</span><br><span> int remove_failed;</span><br><span> unsigned int missing_seqnos_added = 0;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Received an out of order packet with sequence number '%d' while expecting '%d' from the future on RTP instance '%p'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, rtp->expectedrxseqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP received an out of order packet with sequence number '%d' while expecting '%d' from the future\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno, rtp->expectedrxseqno);</span><br><span> </span><br><span> payload = ast_malloc(sizeof(*payload) + res);</span><br><span> if (!payload) {</span><br><span>@@ -7961,8 +8022,8 @@</span><br><span> remove_failed = AST_VECTOR_REMOVE_CMP_ORDERED(&rtp->missing_seqno, seqno, find_by_value,</span><br><span> AST_VECTOR_ELEM_CLEANUP_NOOP);</span><br><span> if (!remove_failed) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Packet with sequence number '%d' on RTP instance '%p' is no longer missing\n",</span><br><span style="color: hsl(0, 100%, 40%);">- seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP packet with sequence number '%d' is no longer missing\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, seqno);</span><br><span> }</span><br><span> </span><br><span> /* The missing sequence number code works by taking the sequence number of the</span><br><span>@@ -8008,8 +8069,8 @@</span><br><span> continue;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Added missing sequence number '%d' to RTP instance '%p'\n",</span><br><span style="color: hsl(0, 100%, 40%);">- missing_seqno, instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtp(2, "(%p) RTP added missing sequence number '%d'\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ instance, missing_seqno);</span><br><span> AST_VECTOR_ADD_SORTED(&rtp->missing_seqno, missing_seqno,</span><br><span> compare_by_value);</span><br><span> missing_seqnos_added++;</span><br><span>@@ -8039,7 +8100,7 @@</span><br><span> */</span><br><span> rtcpheader = ast_malloc(sizeof(*rtcpheader) + data_size);</span><br><span> if (!rtcpheader) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to allocate memory for NACK\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to allocate memory for NACK\n", instance);</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> </span><br><span>@@ -8056,7 +8117,7 @@</span><br><span> res = ast_rtcp_generate_nack(instance, rtcpheader + packet_len);</span><br><span> </span><br><span> if (res == 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to construct NACK, stopping here\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to construct NACK, stopping here\n", instance);</span><br><span> return &ast_null_frame;</span><br><span> }</span><br><span> </span><br><span>@@ -8064,9 +8125,9 @@</span><br><span> </span><br><span> res = rtcp_sendto(instance, rtcpheader, packet_len, 0, &remote_address, &ice);</span><br><span> if (res < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to send NACK request out\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to send NACK request out\n", instance);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(2, "Sending a NACK request on RTP instance '%p' to get missing packets\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(2, "(%p) RTCP sending a NACK request to get missing packets\n", instance);</span><br><span> /* Update RTCP SR/RR statistics */</span><br><span> ast_rtcp_calculate_sr_rr_statistics(instance, rtcp_report, remote_address, ice, sr);</span><br><span> }</span><br><span>@@ -8086,7 +8147,7 @@</span><br><span> struct ast_sockaddr local_addr;</span><br><span> </span><br><span> if (rtp->rtcp && rtp->rtcp->type == value) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Ignoring duplicate RTCP property on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP ignoring duplicate property\n", instance);</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span>@@ -8138,7 +8199,7 @@</span><br><span> AF_INET :</span><br><span> ast_sockaddr_is_ipv6(&rtp->rtcp->us) ?</span><br><span> AF_INET6 : -1)) < 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to create a new socket for RTCP on instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to create a new socket\n", instance);</span><br><span> ast_free(rtp->rtcp->local_addr_str);</span><br><span> ast_free(rtp->rtcp);</span><br><span> rtp->rtcp = NULL;</span><br><span>@@ -8147,7 +8208,7 @@</span><br><span> </span><br><span> /* Try to actually bind to the IP address and port we are going to use for RTCP, if this fails we have to bail out */</span><br><span> if (ast_bind(rtp->rtcp->s, &rtp->rtcp->us)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to setup RTCP on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to setup RTP instance\n", instance);</span><br><span> close(rtp->rtcp->s);</span><br><span> ast_free(rtp->rtcp->local_addr_str);</span><br><span> ast_free(rtp->rtcp);</span><br><span>@@ -8187,7 +8248,7 @@</span><br><span> #endif</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Setup RTCP on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP setup on RTP instance\n", instance);</span><br><span> } else {</span><br><span> if (rtp->rtcp) {</span><br><span> if (rtp->rtcp->schedid > -1) {</span><br><span>@@ -8197,7 +8258,7 @@</span><br><span> ao2_ref(instance, -1);</span><br><span> } else {</span><br><span> /* Unable to cancel scheduler entry */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to tear down RTCP on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to tear down RTCP\n", instance);</span><br><span> ao2_lock(instance);</span><br><span> return;</span><br><span> }</span><br><span>@@ -8209,7 +8270,7 @@</span><br><span> if (!ast_sched_del(rtp->sched, rtp->transport_wide_cc.schedid)) {</span><br><span> ao2_ref(instance, -1);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Failed to tear down RTCP transport-cc feedback on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP failed to tear down transport-cc feedback\n", instance);</span><br><span> ao2_lock(instance);</span><br><span> return;</span><br><span> }</span><br><span>@@ -8289,7 +8350,7 @@</span><br><span> }</span><br><span> </span><br><span> if (rtp->rtcp && !ast_sockaddr_isnull(addr)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(1, "Setting RTCP address on RTP instance '%p'\n", instance);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_rtcp(1, "(%p) RTCP setting address on RTP instance\n", instance);</span><br><span> ast_sockaddr_copy(&rtp->rtcp->them, addr);</span><br><span> </span><br><span> if (rtp->rtcp->type == AST_RTP_INSTANCE_RTCP_STANDARD) {</span><br><span>@@ -8785,7 +8846,7 @@</span><br><span> }</span><br><span> #endif</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- ast_debug(3, "ast_rtp_activate (%p) - setup and perform DTLS'\n", rtp);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_dtls(3, "(%p) DTLS - ast_rtp_activate rtp=%p - setup and perform DTLS'\n", instance, rtp);</span><br><span> </span><br><span> dtls_perform_setup(&rtp->dtls);</span><br><span> dtls_perform_handshake(instance, &rtp->dtls, 0);</span><br><span>@@ -8810,9 +8871,9 @@</span><br><span> return CLI_FAILURE;</span><br><span> }</span><br><span> rtpdebugport = (!ast_strlen_zero(debugport) && debugport[0] != '0');</span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "RTP Debugging Enabled for address: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "RTP Packet Debugging Enabled for address: %s\n",</span><br><span> ast_sockaddr_stringify(&rtpdebugaddr));</span><br><span style="color: hsl(0, 100%, 40%);">- rtpdebug = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_RTP_PACKET, AST_LOG_CATEGORY_ENABLED);</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> </span><br><span>@@ -8827,9 +8888,9 @@</span><br><span> return CLI_FAILURE;</span><br><span> }</span><br><span> rtcpdebugport = (!ast_strlen_zero(debugport) && debugport[0] != '0');</span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "RTCP Debugging Enabled for address: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "RTCP Packet Debugging Enabled for address: %s\n",</span><br><span> ast_sockaddr_stringify(&rtcpdebugaddr));</span><br><span style="color: hsl(0, 100%, 40%);">- rtcpdebug = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_RTCP_PACKET, AST_LOG_CATEGORY_ENABLED);</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> </span><br><span>@@ -8850,13 +8911,13 @@</span><br><span> </span><br><span> if (a->argc == e->args) { /* set on or off */</span><br><span> if (!strncasecmp(a->argv[e->args-1], "on", 2)) {</span><br><span style="color: hsl(0, 100%, 40%);">- rtpdebug = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_RTP_PACKET, AST_LOG_CATEGORY_ENABLED);</span><br><span> memset(&rtpdebugaddr, 0, sizeof(rtpdebugaddr));</span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "RTP Debugging Enabled\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "RTP Packet Debugging Enabled\n");</span><br><span> return CLI_SUCCESS;</span><br><span> } else if (!strncasecmp(a->argv[e->args-1], "off", 3)) {</span><br><span style="color: hsl(0, 100%, 40%);">- rtpdebug = 0;</span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "RTP Debugging Disabled\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_RTP_PACKET, AST_LOG_CATEGORY_DISABLED);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "RTP Packet Debugging Disabled\n");</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> } else if (a->argc == e->args +1) { /* ip */</span><br><span>@@ -8921,13 +8982,13 @@</span><br><span> </span><br><span> if (a->argc == e->args) { /* set on or off */</span><br><span> if (!strncasecmp(a->argv[e->args-1], "on", 2)) {</span><br><span style="color: hsl(0, 100%, 40%);">- rtcpdebug = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_RTCP_PACKET, AST_LOG_CATEGORY_ENABLED);</span><br><span> memset(&rtcpdebugaddr, 0, sizeof(rtcpdebugaddr));</span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "RTCP Debugging Enabled\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "RTCP Packet Debugging Enabled\n");</span><br><span> return CLI_SUCCESS;</span><br><span> } else if (!strncasecmp(a->argv[e->args-1], "off", 3)) {</span><br><span style="color: hsl(0, 100%, 40%);">- rtcpdebug = 0;</span><br><span style="color: hsl(0, 100%, 40%);">- ast_cli(a->fd, "RTCP Debugging Disabled\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_debug_category_set_sublevel(AST_LOG_CATEGORY_RTCP_PACKET, AST_LOG_CATEGORY_DISABLED);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_cli(a->fd, "RTCP Packet Debugging Disabled\n");</span><br><span> return CLI_SUCCESS;</span><br><span> }</span><br><span> } else if (a->argc == e->args +1) { /* ip */</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/c/asterisk/+/14887">change 14887</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/+/14887"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: asterisk </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: I6e6cb247bb1f01dbf34750b2cd98e5b5b41a1849 </div>
<div style="display:none"> Gerrit-Change-Number: 14887 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: Kevin Harwell <kharwell@digium.com> </div>
<div style="display:none"> Gerrit-MessageType: newchange </div>