[Asterisk-code-review] Scope Trace: Add some new tracing macros and an ast_str helper (asterisk[certified/16.8])

George Joseph asteriskteam at digium.com
Thu Aug 13 06:26:41 CDT 2020


George Joseph has submitted this change. ( https://gerrit.asterisk.org/c/asterisk/+/14754 )

Change subject: Scope Trace:  Add some new tracing macros and an ast_str helper
......................................................................

Scope Trace:  Add some new tracing macros and an ast_str helper

Created new SCOPE_ functions that don't depend on RAII_VAR.  Besides
generating less code, the use of the explicit SCOPE_EXIT macros
capture the line number where the scope exited.  The RAII_VAR
versions can't do that.

 * SCOPE_ENTER(level, ...): Like SCOPE_TRACE but doesn't use
   RAII_VAR and therefore needs needs one of...

 * SCOPE_EXIT(...): Decrements the trace stack counter and optionally
   prints a message.

 * SCOPE_EXIT_EXPR(__expr, ...): Decrements the trace stack counter,
   optionally prints a message, then executes the expression.
   SCOPE_EXIT_EXPR(break, "My while got broken\n");

 * SCOPE_EXIT_RTN(, ...): Decrements the trace stack counter,
   optionally prints a message, then returns without a value.
   SCOPE_EXIT_RTN("Bye\n");

 * SCOPE_EXIT_RTN_VALUE(__return_value, ...): Decrements the trace
   stack counter, optionally prints a message, then returns the value
   specified.
   SCOPE_EXIT_RTN_VALUE(rc, "Returning with RC: %d\n", rc);

Create an ast_str helper ast_str_tmp() that allocates a temporary
ast_str that can be passed to a function that needs it, then frees
it.  This makes using the above macros easier.  Example:

   SCOPE_ENTER(1, Format Caps 1: %s  Format Caps 2: %s\n",
       ast_str_tmp(32, ast_format_cap_get_names(cap1, &STR_TMP),
       ast_str_tmp(32, ast_format_cap_get_names(cap2, &STR_TMP));

The calls to ast_str_tmp create an ast_str of the specified initial
length which can be referenced as STR_TMP.  It then calls the
expression, which must return a char *, ast_strdupa's it, frees
STR_TMP, then returns the ast_strdupa'd string.  That string is
freed when the function returns.

Change-Id: I44059b20d55a889aa91440d2f8a590865998be51
(cherry picked from commit 43ba72dea099b5448fdeb0fcab44b6186a0ddf75)
---
M include/asterisk/logger.h
M include/asterisk/strings.h
M tests/test_scope_trace.c
M tests/test_strings.c
4 files changed, 232 insertions(+), 24 deletions(-)

Approvals:
  George Joseph: Looks good to me, approved; Approved for Submit



diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h
index 4392e5a..67e4df7 100644
--- a/include/asterisk/logger.h
+++ b/include/asterisk/logger.h
@@ -715,10 +715,107 @@
 	} \
 	int __scopevar ## __LINE__ ## __RETURN __attribute__((unused)) = __scopevar ## __LINE__ ## __ENTER()
 
+/*!
+ * \brief Non RAII_VAR Scope Trace macros
+ * The advantage of these macros is that the EXITs will have the actual
+ * line number where the scope exited.  Much less code is required as well.
+ */
+
+/*!
+ * \brief Scope Enter
+ *
+ * \param level The trace level
+ * \param (optional) A printf style format string
+ * \param (optional) Arguments
+ */
+#define SCOPE_ENTER(level, ...) \
+	int __scope_level = level; \
+	if (TRACE_ATLEAST(level)) { \
+		__ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_INC_AFTER, " " __VA_ARGS__); \
+	} \
+
+/*!
+ * \brief Scope Exit
+ *
+ * \param (optional) A printf style format string
+ * \param (optional) Arguments
+ *
+ * \details
+ * This macro can be used at the exit points of a statement block since it just prints the message.
+ */
+#define SCOPE_EXIT(...) \
+	if (TRACE_ATLEAST(__scope_level)) { \
+		__ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+	} \
+
+/*!
+ * \brief Scope Exit with expression
+ *
+ * \param __expr An expression to execute after printing the message
+ * \param (optional) A printf style format string
+ * \param (optional) Arguments
+ *
+ * \details
+ * Handy for getting out of or continuing loops.
+ *
+ * \example
+ * while(something) {
+ *     SCOPE_ENTER(2, "In a while\n");
+ *     if (something) {
+ *         SCOPE_EXIT_EXPR(break, "Somethiung broke me\n");
+ *     } else {
+ *         SCOPE_EXIT_EXPR(contniue, "Somethiung continued me\n");
+ *     }
+ * }
+ */
+#define SCOPE_EXIT_EXPR(__expr, ...) \
+	if (TRACE_ATLEAST(__scope_level)) { \
+		__ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+	} \
+	__expr
+
+/*!
+ * \brief Scope Exit with return
+ *
+ * \param (optional) A printf style format string
+ * \param (optional) Arguments
+ *
+ * \details
+ * This macro can be used at the exit points of a function when no value
+ * needs to be returned.
+ */
+#define SCOPE_EXIT_RTN(...) \
+	if (TRACE_ATLEAST(__scope_level)) { \
+		__ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+	} \
+	return
+
+/*!
+ * \brief Scope Exit with return value
+ *
+ * \param __return_value The return value
+ * \param (optional) A printf style format string
+ * \param (optional) Arguments
+ *
+ * \details
+ * This macro can be used at the exit points of a function when a value
+ * needs to be returned.
+ */
+#define SCOPE_EXIT_RTN_VALUE(__return_value, ...) \
+	if (TRACE_ATLEAST(__scope_level)) { \
+		__ast_trace(__FILE__, __LINE__, __PRETTY_FUNCTION__, AST_TRACE_INDENT_DEC_BEFORE, " " __VA_ARGS__); \
+	} \
+	return(__return_value)
+
 #else
-#define ast_trace_raw(__level, __indent_type, __fmt, ...)
-#define ast_trace(__level)
-#define SCOPE_TRACE(__level)
+#define ast_trace_raw(__level, __indent_type, ...)
+#define ast_trace(__level, ...)
+#define SCOPE_TRACE(__level, ...)
+#define SCOPE_ENTER(level, ...)
+#define SCOPE_EXIT(...)
+#define SCOPE_EXIT_EXPR(__expr, ...)
+#define SCOPE_EXIT_RTN(...)
+#define SCOPE_EXIT_RTN_VALUE(__return_value, ...)
 #endif
 
 #if defined(__cplusplus) || defined(c_plusplus)
diff --git a/include/asterisk/strings.h b/include/asterisk/strings.h
index c56a139..e9d786c 100644
--- a/include/asterisk/strings.h
+++ b/include/asterisk/strings.h
@@ -1091,6 +1091,59 @@
 )
 
 /*!
+ * \brief Provides a temporary ast_str and returns a copy of its buffer
+ * \since 16.12
+ * \since 17.6
+ * \since 18.0
+ *
+ * \param init_len The initial length of the temporary ast_str needed.
+ * \param __expr An expression that needs the temporary ast_str and returns a char *.
+ *
+ * \returns A copy of __expr's return buffer allocated on the stack.
+ *
+ * \details
+ * There are a few query functions scattered around that need an ast_str in which
+ * to assemble the results but it's not always convenient to create an ast_str
+ * and ensure it's freed just to print a log message.  For example...
+ *
+ * struct ast_str *temp = ast_str_create(128);
+ * ast_log(LOG_INFO, "Format caps: %s\n", ast_format_cap_get_names(caps, &temp));
+ * ast_free(temp);
+ *
+ * That's not bad if you only have to do it once but some of our code that deals
+ * with streams and codecs is pretty complex and good instrumentation is essential.
+ * The aim of this function is to make that easier.
+ *
+ * With this macro, the above code can be simplified as follows...
+ * \example
+ * ast_log(LOG_INFO, "Format caps: %s\n",
+ *     ast_str_tmp(128, ast_format_cap_get_names(caps, &STR_TMP));
+ *
+ * STR_TMP will always be a reference to the temporary ast_str created
+ * by the macro.  Its scope is limited by the macro so you can use it multiple
+ * times without conflict.
+ *
+ * \example
+ * ast_log(LOG_INFO, "Format caps in: %s  Format caps out: %s\n",
+ *     ast_str_tmp(128, ast_format_cap_get_names(caps_in, &STR_TMP),
+ *     ast_str_tmp(128, ast_format_cap_get_names(caps_out, &STR_TMP)
+ *     );
+ *
+ * \warning
+ * The returned string is stack allocated so don't go overboard.
+ *
+ */
+#define ast_str_tmp(init_len, __expr) \
+({ \
+	struct ast_str *STR_TMP = ast_str_create(init_len); \
+	char *ret = ast_strdupa(__expr); \
+	ast_free(STR_TMP); \
+	ret; \
+})
+
+
+
+/*!
  * \brief Check if a string is only digits
  *
  * \retval 1 The string contains only digits
diff --git a/tests/test_scope_trace.c b/tests/test_scope_trace.c
index 6ab480a..56f0875 100644
--- a/tests/test_scope_trace.c
+++ b/tests/test_scope_trace.c
@@ -38,58 +38,77 @@
 #include "asterisk/test.h"
 #include "asterisk/logger.h"
 
-static void test_scope2(void)
+
+static const char *str_appender(struct ast_str**buf, char *a)
 {
-	SCOPE_TRACE(1);
+	ast_str_append(buf, 0, "<append %s>", a);
+	return ast_str_buffer(*buf);
 }
 
-static void test_scope(void)
+static void test_scope_trace(void)
 {
-	SCOPE_TRACE(1, "nested function: %d * %d = %d\n", 6, 7, (6 * 7));
+	SCOPE_ENTER(1, "subfunction\n");
+	SCOPE_EXIT_RTN("got out\n");
+}
 
-	test_scope2();
+static int test_scope_enter_function(void)
+{
+	SCOPE_ENTER(1, "%s %s %s %s %s %s %s\n",
+		ast_str_tmp(12, str_appender(&STR_TMP, "str1")),
+		ast_str_tmp(12, str_appender(&STR_TMP, "str2")),
+		ast_str_tmp(32, str_appender(&STR_TMP, "AAAAAAAAAAAAAAAAAAAAAAAA")),
+		ast_str_tmp(12, str_appender(&STR_TMP, "B")),
+		"ccccccccccccc",
+		ast_str_tmp(12, str_appender(&STR_TMP, "DDDDD")),
+		ast_str_tmp(12, str_appender(&STR_TMP, "ww"))
+		);
 
-	ast_trace(1, "test no variables\n");
+	test_scope_trace();
+
+	SCOPE_EXIT_RTN_VALUE(AST_TEST_PASS, "test no variables\n");
 }
 
 
 AST_TEST_DEFINE(scope_test)
 {
-	SCOPE_TRACE(1, "top %s function\n", "scope_test");
+	SCOPE_ENTER(1, "top %s function\n", "scope_test");
 
 	ast_trace(1, "%s\n", "test outer");
 
 	switch (cmd) {
 	case TEST_INIT:
+	{
+		SCOPE_ENTER(1, "TEST_INIT\n");
 		info->name = "scope_test";
 		info->category = "/main/logging/";
 		info->summary = "Scope Trace Tests";
 		info->description = "Scope Trace Tests";
-		return AST_TEST_NOT_RUN;
+		/* need to exit the case scope */
+		SCOPE_EXIT("TEST_INIT\n");
+		/* need to exit the function */
+		SCOPE_EXIT_RTN_VALUE(AST_TEST_NOT_RUN, "BYE\n");
+	}
 	case TEST_EXECUTE:
-		{
-			SCOPE_TRACE(1, "CASE statement\n");
-			ast_trace(1, "%s\n", "test case");
-		}
-		break;
+	{
+		SCOPE_ENTER(1, "TEST_EXECUTE\n");
+		ast_trace(1, "%s\n", "test execute");
+		SCOPE_EXIT_EXPR(break, "TEST_EXECUTE\n");
+	}
+	default:
+		ast_test_status_update(test, "Shouldn't have gotten here\n");
+		return AST_TEST_FAIL;
 	}
 
 	if (1) {
 		SCOPE_TRACE(1, "IF block\n");
-
-		test_scope();
+		test_scope_enter_function();
 	}
 
 	ast_trace(1);
-
 	ast_trace(1, "test no variables\n");
-
-
-
-
 	ast_trace(1, "%s\n", "test variable");
 
- 	return AST_TEST_PASS;
+	SCOPE_EXIT_RTN_VALUE(AST_TEST_PASS, "Something: %d\n", AST_TEST_PASS);
 }
 
 static int unload_module(void)
diff --git a/tests/test_strings.c b/tests/test_strings.c
index 90b0d36..3d697e5 100644
--- a/tests/test_strings.c
+++ b/tests/test_strings.c
@@ -583,6 +583,43 @@
 	return AST_TEST_PASS;
 }
 
+/*!
+ * \brief Function that needs a temporary ast_str
+ */
+static const char *str_appender(struct ast_str**buf, char *a)
+{
+	ast_str_append(buf, 0, "<%s>", a);
+	return ast_str_buffer(*buf);
+}
+
+AST_TEST_DEFINE(temp_strings)
+{
+	char *return_buffer = ast_malloc(128);
+	switch (cmd) {
+	case TEST_INIT:
+		info->name = "temp_strings";
+		info->category = "/main/strings/";
+		info->summary = "Test ast_str_temp_buffer";
+		info->description = "Test ast_str_temp_buffer";
+		return AST_TEST_NOT_RUN;
+	case TEST_EXECUTE:
+		break;
+	}
+
+	snprintf(return_buffer, 128, "%s %s %s %s %s",
+	ast_str_tmp(12, str_appender(&STR_TMP, "str1")),
+	ast_str_tmp(12, str_appender(&STR_TMP, "str2")),
+	ast_str_tmp(12, str_appender(&STR_TMP, "B")),
+	"ccccccccccccc",
+	ast_str_tmp(12, str_appender(&STR_TMP, "ww"))
+	);
+
+	ast_test_validate(test, ast_strings_match(return_buffer, "=", "<str1> <str2> <B> ccccccccccccc <ww>"));
+
+	ast_free(return_buffer);
+	return AST_TEST_PASS;
+}
+
 static int unload_module(void)
 {
 	AST_TEST_UNREGISTER(str_test);
@@ -592,6 +629,7 @@
 	AST_TEST_UNREGISTER(escape_semicolons_test);
 	AST_TEST_UNREGISTER(escape_test);
 	AST_TEST_UNREGISTER(strings_match);
+	AST_TEST_UNREGISTER(temp_strings);
 	return 0;
 }
 
@@ -604,6 +642,7 @@
 	AST_TEST_REGISTER(escape_semicolons_test);
 	AST_TEST_REGISTER(escape_test);
 	AST_TEST_REGISTER(strings_match);
+	AST_TEST_REGISTER(temp_strings);
 	return AST_MODULE_LOAD_SUCCESS;
 }
 

-- 
To view, visit https://gerrit.asterisk.org/c/asterisk/+/14754
To unsubscribe, or for help writing mail filters, visit https://gerrit.asterisk.org/settings

Gerrit-Project: asterisk
Gerrit-Branch: certified/16.8
Gerrit-Change-Id: I44059b20d55a889aa91440d2f8a590865998be51
Gerrit-Change-Number: 14754
Gerrit-PatchSet: 2
Gerrit-Owner: George Joseph <gjoseph at digium.com>
Gerrit-Reviewer: Friendly Automation
Gerrit-Reviewer: George Joseph <gjoseph at digium.com>
Gerrit-Reviewer: Joshua Colp <jcolp at sangoma.com>
Gerrit-Reviewer: Kevin Harwell <kharwell at digium.com>
Gerrit-MessageType: merged
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-code-review/attachments/20200813/089afc89/attachment-0001.html>


More information about the asterisk-code-review mailing list