From ae2b2f64eac66d658306b8711baeb7dd9e9e05ea Mon Sep 17 00:00:00 2001 From: Pawel Wodkowski Date: Mon, 10 Sep 2018 16:08:25 +0200 Subject: [PATCH] log: add a way to turn on and off stack unwinding in logs As a side effect, if SPDK_LOG_DISABLED is used in spdk_log() as log level then no message will be printed. Change-Id: I2d57b60a5a310a9ef2a1187a81088d0acf828742 Signed-off-by: Pawel Wodkowski Reviewed-on: https://review.gerrithub.io/425105 Chandler-Test-Pool: SPDK Automated Test System Reviewed-by: Darek Stojaczyk Reviewed-by: Jim Harris Reviewed-by: Ben Walker Tested-by: SPDK CI Jenkins --- CONFIG | 4 ++-- configure | 19 ++++++------------- include/spdk/log.h | 28 ++++++++++++++++++++++++++-- include/spdk_internal/log.h | 1 + lib/event/app.c | 2 ++ lib/log/log.c | 4 +++- lib/log/log_flags.c | 12 ++++++++++++ mk/spdk.common.mk | 1 - test/common/autotest_common.sh | 2 +- 9 files changed, 53 insertions(+), 20 deletions(-) diff --git a/CONFIG b/CONFIG index d9f1e45e4d..087be7a7b5 100644 --- a/CONFIG +++ b/CONFIG @@ -37,8 +37,8 @@ CONFIG_PREFIX?=/usr/local # Build with debug logging. Turn off for performance testing and normal usage CONFIG_DEBUG?=n -# Show backtrace when logging message at level <= lvl (ERROR, WARN, NOTICE, DEBUG) -#CONFIG_LOG_BACKTRACE?=lvl +# Build with support of backtrace printing in log messages. Requires libunwind. +#CONFIG_LOG_BACKTRACE?=n # Treat warnings as errors (fail the build on any warning). CONFIG_WERROR?=n diff --git a/configure b/configure index 2a46b6cc33..674fa5fbb2 100755 --- a/configure +++ b/configure @@ -16,8 +16,7 @@ function usage() echo " --prefix=path Configure installation prefix (default: /usr/local)" echo "" echo " --enable-debug Configure for debug builds" - echo " --enable-log-bt=lvl Show backtrace using libunwind when logging message at level <= lvl." - echo " Valid values are: ERROR, WARN, NOTICE, DEBUG." + echo " --enable-log-bt Enable support of backtrace printing in SPDK logs (requires libunwind)." echo " --enable-werror Treat compiler warnings as errors" echo " --enable-asan Enable address sanitizer" echo " --enable-ubsan Enable undefined behavior sanitizer" @@ -91,8 +90,11 @@ for i in "$@"; do --disable-debug) CONFIG_DEBUG=n ;; - --enable-log-bt=*) - CONFIG_LOG_BACKTRACE=${i#*=} + --enable-log-bt) + CONFIG_LOG_BACKTRACE=y + ;; + --disable-log-bt) + CONFIG_LOG_BACKTRACE=n ;; --enable-asan) CONFIG_ASAN=y @@ -244,15 +246,6 @@ for i in "$@"; do esac done -case "$CONFIG_LOG_BACKTRACE" in - ""|ERROR|WARN|NOTICE|DEBUG) - ;; - *) - echo "Invalid '--enable-log-bt=$CONFIG_LOG_BACKTRACE' option. Valid levels are ERROR, WARN, NOTICE or DEBUG" - exit 1 - ;; -esac - if [ -z "$CONFIG_ENV" ]; then if [ -z "$CONFIG_DPDK_DIR" ]; then rootdir=$(readlink -f $(dirname $0)) diff --git a/include/spdk/log.h b/include/spdk/log.h index e098dfd18c..b6f0dd62c4 100644 --- a/include/spdk/log.h +++ b/include/spdk/log.h @@ -58,6 +58,8 @@ void spdk_log_open(void); void spdk_log_close(void); enum spdk_log_level { + /** All messages will be suppressed. */ + SPDK_LOG_DISABLED = -1, SPDK_LOG_ERROR, SPDK_LOG_WARN, SPDK_LOG_NOTICE, @@ -80,10 +82,31 @@ void spdk_log_set_level(enum spdk_log_level level); */ enum spdk_log_level spdk_log_get_level(void); +/** + * Set the log level threshold to include stack trace in log messages. + * Messages with a higher level than this will not contain stack trace. You + * can use \c SPDK_LOG_DISABLED to completely disable stack trace printing + * even if it is supported. + * + * \note This function has no effect if SPDK is built without stack trace + * printing support. + * + * \param level Log level threshold for stacktrace. + */ +void spdk_log_set_backtrace_level(enum spdk_log_level level); + +/** + * Get the current log level threshold for showing stack trace in log message. + * + * \return the current log level threshold for stack trace. + */ +enum spdk_log_level spdk_log_get_backtrace_level(void); + /** * Set the current log level threshold for printing to stderr. * Messages with a level less than or equal to this level - * are also printed to stderr. + * are also printed to stderr. You can use \c SPDK_LOG_DISABLED to completely + * suppress log printing. * * \param level Log level threshold for printing to stderr. */ @@ -104,7 +127,8 @@ enum spdk_log_level spdk_log_get_print_level(void); spdk_log(SPDK_LOG_ERROR, __FILE__, __LINE__, __func__, __VA_ARGS__) /** - * Write messages to the log file. + * Write messages to the log file. If \c level is set to \c SPDK_LOG_DISABLED, + * this log message won't be written. * * \param level Log level threshold. * \param file Name of the current source file. diff --git a/include/spdk_internal/log.h b/include/spdk_internal/log.h index a38e1fcc77..c91116bb03 100644 --- a/include/spdk_internal/log.h +++ b/include/spdk_internal/log.h @@ -44,6 +44,7 @@ extern enum spdk_log_level g_spdk_log_level; extern enum spdk_log_level g_spdk_log_print_level; +extern enum spdk_log_level g_spdk_log_backtrace_level; struct spdk_trace_flag { TAILQ_ENTRY(spdk_trace_flag) tailq; diff --git a/lib/event/app.c b/lib/event/app.c index 8e3910bc7f..012e2920b0 100644 --- a/lib/event/app.c +++ b/lib/event/app.c @@ -46,6 +46,7 @@ #define SPDK_APP_DEFAULT_LOG_LEVEL SPDK_LOG_NOTICE #define SPDK_APP_DEFAULT_LOG_PRINT_LEVEL SPDK_LOG_INFO +#define SPDK_APP_DEFAULT_BACKTRACE_LOG_LEVEL SPDK_LOG_ERROR #define SPDK_APP_DPDK_DEFAULT_MEM_SIZE -1 #define SPDK_APP_DPDK_DEFAULT_MASTER_CORE -1 @@ -591,6 +592,7 @@ spdk_app_start(struct spdk_app_opts *opts, spdk_event_fn start_fn, } spdk_log_set_level(SPDK_APP_DEFAULT_LOG_LEVEL); + spdk_log_set_backtrace_level(SPDK_APP_DEFAULT_BACKTRACE_LOG_LEVEL); if (spdk_app_setup_env(opts) < 0) { goto app_start_setup_conf_err; diff --git a/lib/log/log.c b/lib/log/log.c index fb270e2c94..9f4546ce7e 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -74,7 +74,7 @@ spdk_log_unwind_stack(FILE *fp, enum spdk_log_level level) char f_name[64]; int frame; - if (level > SPDK_LOG_BACKTRACE_LVL) { + if (level > g_spdk_log_backtrace_level) { return; } @@ -122,6 +122,8 @@ spdk_log(enum spdk_log_level level, const char *file, const int line, const char case SPDK_LOG_DEBUG: severity = LOG_INFO; break; + case SPDK_LOG_DISABLED: + return; } va_start(ap, format); diff --git a/lib/log/log_flags.c b/lib/log/log_flags.c index 1b5c409468..6b5697f5c5 100644 --- a/lib/log/log_flags.c +++ b/lib/log/log_flags.c @@ -39,6 +39,7 @@ static TAILQ_HEAD(, spdk_trace_flag) g_trace_flags = TAILQ_HEAD_INITIALIZER(g_tr enum spdk_log_level g_spdk_log_level = SPDK_LOG_NOTICE; enum spdk_log_level g_spdk_log_print_level = SPDK_LOG_NOTICE; +enum spdk_log_level g_spdk_log_backtrace_level = SPDK_LOG_DISABLED; SPDK_LOG_REGISTER_COMPONENT("log", SPDK_LOG_LOG) @@ -66,6 +67,17 @@ spdk_log_get_print_level(void) { return g_spdk_log_print_level; } +void +spdk_log_set_backtrace_level(enum spdk_log_level level) +{ + g_spdk_log_backtrace_level = level; +} + +enum spdk_log_level +spdk_log_get_backtrace_level(void) { + return g_spdk_log_backtrace_level; +} + static struct spdk_trace_flag * get_trace_flag(const char *name) { diff --git a/mk/spdk.common.mk b/mk/spdk.common.mk index ac0e71358d..d30a4d8e1d 100644 --- a/mk/spdk.common.mk +++ b/mk/spdk.common.mk @@ -191,7 +191,6 @@ SYS_LIBS += -luuid SYS_LIBS += -lcrypto ifneq ($(CONFIG_LOG_BACKTRACE),) SYS_LIBS += -lunwind -COMMON_CFLAGS += -DSPDK_LOG_BACKTRACE_LVL=SPDK_LOG_$(CONFIG_LOG_BACKTRACE) endif MAKEFLAGS += --no-print-directory diff --git a/test/common/autotest_common.sh b/test/common/autotest_common.sh index badfb88600..754abf8e71 100644 --- a/test/common/autotest_common.sh +++ b/test/common/autotest_common.sh @@ -80,7 +80,7 @@ config_params='--enable-debug --enable-werror' if echo -e "#include \nint main(int argc, char *argv[]) {return 0;}\n" | \ gcc -o /dev/null -lunwind -x c - 2>/dev/null; then - config_params+=' --enable-log-bt=ERROR' + config_params+=' --enable-log-bt' fi # RAID is marked experimental and not built by default currently, since it does not