logger.h: Add SCOPE_CALL and SCOPE_CALL_WITH_RESULT

If you're tracing a large function that may call another function
multiple times in different circumstances, it can be difficult to
see from the trace output exactly which location that function
was called from.  There's no good way to automatically determine
the calling location.  SCOPE_CALL and SCOPE_CALL_WITH_RESULT
simply print out a trace line before and after the call.

The difference between SCOPE_CALL and SCOPE_CALL_WITH_RESULT is
that SCOPE_CALL ignores the function's return value (if any) where
SCOPE_CALL_WITH_RESULT allows you to specify the type of the
function's return value so it can be assigned to a variable.
SCOPE_CALL_WITH_INT_RESULT is just a wrapper for SCOPE_CALL_WITH_RESULT
and the "int" return type.

diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h
index f01e11766c22aa056fc8c713636f09caf754a46c..0c4faea844bbbfb23ba346a5ebe07e60f79277fd 100644 (file)
--- a/include/asterisk/logger.h
+++ b/include/asterisk/logger.h
@@ -831,6 +831,76 @@ unsigned long _ast_trace_dec_indent(void);
                __ast_trace(_TRACE_PREFIX_, AST_TRACE_INDENT_PROVIDED, indent, " " __VA_ARGS__); \
        } \
 
+/*!
+ * \def SCOPE_CALL
+ * \brief Wrap a function call in "--> Calling:" and "<-- Return from:" trace messages
+ *
+ * \param level The trace level (usually -1 to use the same level as the calling function)
+ * \param __funcname The name of the function to call (return value, if any, is ignored)
+ * \param ... Arguments to pass to the function
+ *
+ * Simple Example:
+ * The following code called from inside the app_voicemail.c leave_voicemail function...
+\code
+       SCOPE_CALL(-1, store_file, dir, vmu->mailbox, vmu->context, msgnum);
+\endcode
+ * would produce...
+\verbatim
+1     app_voicemail_odbc.c:7161 leave_voicemail: --> Calling store_file
+1     --> app_voicemail_odbc.c:4483 store_file: dir: /var/spool/asterisk/voicemail/default/1179/INBOX user: 1179 context: default msgnum: 8
+2         app_voicemail_odbc.c:4502 store_file: Formats: wav49|gsm|wav Using format: 'WAV'
+2         app_voicemail_odbc.c:4510 store_file: Base path: '/var/spool/asterisk/voicemail/default/1179/INBOX/msg0008'
+2         app_voicemail_odbc.c:4513 store_file: Basename: 'msg0008'
+1     <-- app_voicemail_odbc.c:4597 store_file: Success
+1     app_voicemail_odbc.c:7161 leave_voicemail: <-- Return from store_file
+\endverbatim
+ */
+#define SCOPE_CALL(level, __funcname, ...) \
+({ \
+       ast_trace(level, "--> Calling %s\n", #__funcname); \
+       __funcname(__VA_ARGS__); \
+       ast_trace(level, "<-- Return from %s\n", #__funcname); \
+})
+
+/*!
+ * \def SCOPE_CALL_WITH_RESULT
+ * \brief Wrap a function call returning a value in "--> Calling:" and "<-- Return from:" trece messages
+ *
+ * \param level The trace level (usually -1 to use the same level as the calling function)
+ * \param __type The return type of the function
+ * \param __funcname The name of the function to call
+ * \param ... Arguments to pass to the function
+ *
+ * Simple Example:
+ * The following code called from inside the app_voicemail.c leave_voicemail function...
+\code
+       int res = 0;
+       res = SCOPE_CALL_WITH_RESULT(-1, int, store_file, dir, vmu->mailbox, vmu->context, msgnum);
+\endcode
+ * would produce...
+\verbatim
+1     app_voicemail_odbc.c:7161 leave_voicemail: --> Calling store_file
+1     --> app_voicemail_odbc.c:4483 store_file: dir: /var/spool/asterisk/voicemail/default/1179/INBOX user: 1179 context: default msgnum: 8
+2         app_voicemail_odbc.c:4502 store_file: Formats: wav49|gsm|wav Using format: 'WAV'
+2         app_voicemail_odbc.c:4510 store_file: Base path: '/var/spool/asterisk/voicemail/default/1179/INBOX/msg0008'
+2         app_voicemail_odbc.c:4513 store_file: Basename: 'msg0008'
+1     <-- app_voicemail_odbc.c:4597 store_file: Success
+1     app_voicemail_odbc.c:7161 leave_voicemail: <-- Return from store_file
+\endverbatim
+ * ...and the return value of the store_file function would be assigned to the variable res.
+ */
+#define SCOPE_CALL_WITH_RESULT(level, __type, __funcname, ...) \
+({ \
+       __type __var; \
+       ast_trace(level, "--> Calling %s\n", #__funcname); \
+       __var = __funcname(__VA_ARGS__); \
+       ast_trace(level, "<-- Return from %s\n", #__funcname) \
+       __var; \
+})
+
+#define SCOPE_CALL_WITH_INT_RESULT(level, __funcname, ...) \
+       SCOPE_CALL_WITH_RESULT(level, int, __funcname, __VA_ARGS__)
+
 /*!
  * \brief Scope Exit
  *
@@ -938,6 +1008,12 @@ unsigned long _ast_trace_dec_indent(void);
        int __scope_level = level; \
        ast_debug(level, " " __VA_ARGS__)
 
+#define SCOPE_CALL(level, __funcname, ...) \
+       __funcname(__VA_ARGS__)
+
+#define SCOPE_CALL_WITH_RESULT(level, __var, __funcname, ...) \
+       __var = __funcname(__VA_ARGS__)
+
 #define SCOPE_EXIT(...) \
        ast_debug(__scope_level, " " __VA_ARGS__)