From 1ea1524950b8bc4e4dfe06865e1e5c47a657b6e4 Mon Sep 17 00:00:00 2001 From: Gal Pressman Date: Sun, 6 Jun 2021 14:48:07 +0300 Subject: verbs: Add generic logging API A debug prints mechanism is useful when debugging application failures. This patch adds a generic API that can be used by all providers and replace provider-specific counterparts. The debug messages are controlled through an environment variable named VERBS_LOG_LEVEL, where the value indicates which prints should be enabled: enum { VERBS_LOG_LEVEL_NONE, VERBS_LOG_ERR, VERBS_LOG_WARN, VERBS_LOG_INFO, VERBS_LOG_DEBUG, }; For example, to enable prints with level warn or higher, VERBS_LOG_LEVEL shall be set to 2. The output shall be written to the file provided in the VERBS_LOG_FILE environment variable. When the library is compiled in debug mode and no file is provided the output shall be written to stderr. For data-path flows, where the overhead of the additional if statement matters, the verbs_*_datapath() macros can be used, which will be compiled out when the library is compiled for release. Signed-off-by: Gal Pressman --- Documentation/libibverbs.md | 18 ++++++++++ buildlib/RDMA_BuildType.cmake | 4 +++ libibverbs/driver.h | 50 +++++++++++++++++++++++++++ libibverbs/init.c | 65 +++++++++++++++++++++++++++++++++++ libibverbs/libibverbs.map.in | 1 + 5 files changed, 138 insertions(+) diff --git a/Documentation/libibverbs.md b/Documentation/libibverbs.md index cbe076e..980f354 100644 --- a/Documentation/libibverbs.md +++ b/Documentation/libibverbs.md @@ -56,3 +56,21 @@ need to increase this limit. This is usually done for ordinary users via the file /etc/security/limits.conf. More configuration may be necessary if you are logging in via OpenSSH and your sshd is configured to use privilege separation. + +# Debugging + +### Enabling debug prints + +Library and providers debug prints can be enabled using the `VERBS_LOG_LEVEL` +environment variable, the output shall be written to the file provided in the +`VERBS_LOG_FILE` environment variable. When the library is compiled in debug +mode and no file is provided the output will be written to stderr. + +Note: some of the debug prints are only available when the library is compiled +in debug mode. + +The following table describes the expected behavior when VERBS_LOG_LEVEL is set: +| | Release | Debug | +|-----------------|---------------------------------|------------------------------------------------| +| Regular prints | Output to VERBS_LOG_FILE if set | Output to VERBS_LOG_FILE, or stderr if not set | +| Datapath prints | Compiled out, no output | Output to VERBS_LOG_FILE, or stderr if not set | diff --git a/buildlib/RDMA_BuildType.cmake b/buildlib/RDMA_BuildType.cmake index 17206f5..7a4f6a4 100644 --- a/buildlib/RDMA_BuildType.cmake +++ b/buildlib/RDMA_BuildType.cmake @@ -39,4 +39,8 @@ function(RDMA_BuildType) CACHE STRING "Default flags for RelWithDebInfo configuration" FORCE) endif() endforeach() + + if (CMAKE_BUILD_TYPE STREQUAL Debug OR CMAKE_BUILD_TYPE STREQUAL RelWithDebInfo) + add_definitions("-DVERBS_DEBUG") + endif() endfunction() diff --git a/libibverbs/driver.h b/libibverbs/driver.h index 926023b..bdb1aa4 100644 --- a/libibverbs/driver.h +++ b/libibverbs/driver.h @@ -49,6 +49,56 @@ struct verbs_device; +enum { + VERBS_LOG_LEVEL_NONE, + VERBS_LOG_ERR, + VERBS_LOG_WARN, + VERBS_LOG_INFO, + VERBS_LOG_DEBUG, +}; + +void __verbs_log(struct verbs_context *ctx, uint32_t level, + const char *fmt, ...); + +#define verbs_log(ctx, level, format, arg...) \ +do { \ + int tmp = errno; \ + __verbs_log(ctx, level, "%s: %s:%d: " format, \ + (ctx)->context.device->name, __func__, __LINE__, ##arg); \ + errno = tmp; \ +} while (0) + +#define verbs_debug(ctx, format, arg...) \ + verbs_log(ctx, VERBS_LOG_DEBUG, format, ##arg) + +#define verbs_info(ctx, format, arg...) \ + verbs_log(ctx, VERBS_LOG_INFO, format, ##arg) + +#define verbs_warn(ctx, format, arg...) \ + verbs_log(ctx, VERBS_LOG_WARN, format, ##arg) + +#define verbs_err(ctx, format, arg...) \ + verbs_log(ctx, VERBS_LOG_ERR, format, ##arg) + +#ifdef VERBS_DEBUG +#define verbs_log_datapath(ctx, level, format, arg...) \ + verbs_log(ctx, level, format, ##arg) +#else +#define verbs_log_datapath(ctx, level, format, arg...) {} +#endif + +#define verbs_debug_datapath(ctx, format, arg...) \ + verbs_log_datapath(ctx, VERBS_LOG_DEBUG, format, ##arg) + +#define verbs_info_datapath(ctx, format, arg...) \ + verbs_log_datapath(ctx, VERBS_LOG_INFO, format, ##arg) + +#define verbs_warn_datapath(ctx, format, arg...) \ + verbs_log_datapath(ctx, VERBS_LOG_WARN, format, ##arg) + +#define verbs_err_datapath(ctx, format, arg...) \ + verbs_log_datapath(ctx, VERBS_LOG_ERR, format, ##arg) + enum verbs_xrcd_mask { VERBS_XRCD_HANDLE = 1 << 0, VERBS_XRCD_RESERVED = 1 << 1 diff --git a/libibverbs/init.c b/libibverbs/init.c index f5340ea..52b166a 100644 --- a/libibverbs/init.c +++ b/libibverbs/init.c @@ -36,6 +36,7 @@ #include #include #include +#include #include #include #include @@ -52,11 +53,30 @@ #include #include +#include "driver.h" #include "ibverbs.h" #include int abi_ver; +static uint32_t verbs_log_level; +static FILE *verbs_log_fp; + +__attribute__((format(printf, 3, 4))) +void __verbs_log(struct verbs_context *ctx, uint32_t level, + const char *fmt, ...) +{ + va_list args; + + if (level <= verbs_log_level) { + int tmp = errno; + va_start(args, fmt); + vfprintf(verbs_log_fp, fmt, args); + va_end(args); + errno = tmp; + } +} + struct ibv_driver { struct list_node entry; const struct verbs_device_ops *ops; @@ -600,6 +620,49 @@ out: return num_devices; } +static void verbs_set_log_level(void) +{ + char *env; + + env = getenv("VERBS_LOG_LEVEL"); + if (env) + verbs_log_level = strtol(env, NULL, 0); +} + +/* + * Fallback in case log file is not provided or can't be opened. + * Release mode: disable debug prints. + * Debug mode: Use stderr instead of a file. + */ +static void verbs_log_file_fallback(void) +{ +#ifdef VERBS_DEBUG + verbs_log_fp = stderr; +#else + verbs_log_level = VERBS_LOG_LEVEL_NONE; +#endif +} + +static void verbs_set_log_file(void) +{ + char *env; + + if (verbs_log_level == VERBS_LOG_LEVEL_NONE) + return; + + env = getenv("VERBS_LOG_FILE"); + if (!env) { + verbs_log_file_fallback(); + return; + } + + verbs_log_fp = fopen(env, "aw+"); + if (!verbs_log_fp) { + verbs_log_file_fallback(); + return; + } +} + int ibverbs_init(void) { char *env_value; @@ -621,6 +684,8 @@ int ibverbs_init(void) return -errno; check_memlock_limit(); + verbs_set_log_level(); + verbs_set_log_file(); return 0; } diff --git a/libibverbs/libibverbs.map.in b/libibverbs/libibverbs.map.in index 7c0fb6a..905f58f 100644 --- a/libibverbs/libibverbs.map.in +++ b/libibverbs/libibverbs.map.in @@ -167,6 +167,7 @@ IBVERBS_PRIVATE_@IBVERBS_PABI_VERSION@ { global: /* These historical symbols are now private to libibverbs */ __ioctl_final_num_attrs; + __verbs_log; _verbs_init_and_alloc_context; execute_ioctl; ibv_cmd_advise_mr; -- 2.27.0