From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id ACEC343D8B; Sat, 30 Mar 2024 04:06:25 +0100 (CET) Received: from mails.dpdk.org (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id B3F6342D99; Sat, 30 Mar 2024 04:05:06 +0100 (CET) Received: from mail-pf1-f182.google.com (mail-pf1-f182.google.com [209.85.210.182]) by mails.dpdk.org (Postfix) with ESMTP id BD36641104 for ; Sat, 30 Mar 2024 04:04:53 +0100 (CET) Received: by mail-pf1-f182.google.com with SMTP id d2e1a72fcca58-6ea80de0e97so1682125b3a.2 for ; Fri, 29 Mar 2024 20:04:53 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=networkplumber-org.20230601.gappssmtp.com; s=20230601; t=1711767893; x=1712372693; darn=dpdk.org; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:from:to:cc:subject:date :message-id:reply-to; bh=VkK4F13YG5mZA4a0cEYatTcU1uoLlLFo0sOonnBvIt4=; b=kD2e/eo3Q/eUvVHV5V0EOoMM1MSHDqS8dSWxgzZclbNToPGqeYVO4aDeIhZDAy8lVk dxNr1goKLinzYdT3Ggfn1GAX1SZgXs0Gw/SmMrAyZS/X44KxRY6+8KGc8lH5tEjLbpy4 AIG2HM7mjroS2T3HJZn9GnkSw5cLCapNxoV49WNpCBHc5g0WwMlgIWpfZ7CQoMvJG5ES +nqsJ4+1ktHcly+HYv0/g5w72YOnDYox8WDFR0LPZ+rZTs2XKEsnf1OThtbbDpW7ZnM/ QrmUhNNqrGlYnB2sYrd3JFSwNV39MFtoMFRd5Izc2jlL5a0rsDq0Ge4XDuRsWWeXcqAF By8A== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1711767893; x=1712372693; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=VkK4F13YG5mZA4a0cEYatTcU1uoLlLFo0sOonnBvIt4=; b=wigtSLkSIP/KTeltL0W7cwkuzjB/OzcpruPlHrNFXnlmYsKcqYWDtnpy4O+vCsyraA JAQYnss1J1TAnav8xEGo8F7D0UNiKdJN1xyWODK776wO/uafjHhiEL2NHmgsUjHF8yFU /WkdfAFueB3zVZt99eCPlBs00o9QleQdiiiH6rSbXt9osDSIGNXtD+2D/sPcJxkMhFBo TKSngVWGyNZn4634W2Csk0NruvcYmeG43NoBVmYPgG9sZ7puSxT4/iZq3Ivz/Wg6Ztd9 tSL2cGugwlrO4a25vLbMaMWgU1nuVT+BXcCHcrIjpf/dqbvXYEhU8r1GmjO6kupRa1P2 f00Q== X-Gm-Message-State: AOJu0YyATxNZsNtnUz9Z8mX04gjSOEFSc8zKzxKF4U7tMkVxmHsrjzI7 AiV17aY23hfSN6OPTqAeV1Pwh9yT1giamT3pTl62E0k5833Lk/nl8qTq9KCM15j1BYz1O27pt0A w X-Google-Smtp-Source: AGHT+IEdR+QJMWcyX8xmWzXLItlC8Xvth9faPxomT0H0cIF19R3Eh+7eJwArAmNFIgmxYOcSZUQUIQ== X-Received: by 2002:a05:6a20:3d90:b0:1a3:81d2:29f with SMTP id s16-20020a056a203d9000b001a381d2029fmr4189815pzi.17.1711767892830; Fri, 29 Mar 2024 20:04:52 -0700 (PDT) Received: from hermes.local (204-195-123-203.wavecable.com. [204.195.123.203]) by smtp.gmail.com with ESMTPSA id o3-20020a056a00214300b006e6288ef4besm3655486pfk.54.2024.03.29.20.04.52 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 29 Mar 2024 20:04:52 -0700 (PDT) From: Stephen Hemminger To: dev@dpdk.org Cc: Stephen Hemminger Subject: [PATCH v19 15/15] log: colorize log output Date: Fri, 29 Mar 2024 20:00:58 -0700 Message-ID: <20240330030429.4630-16-stephen@networkplumber.org> X-Mailer: git-send-email 2.43.0 In-Reply-To: <20240330030429.4630-1-stephen@networkplumber.org> References: <20200814173441.23086-1-stephen@networkplumber.org> <20240330030429.4630-1-stephen@networkplumber.org> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org Like dmesg, colorize the log output (unless redirected to file). Timestamp is green, the subsystem is in yellow and the message is red if urgent, boldface if an error, and normal for info and debug messages. Signed-off-by: Stephen Hemminger --- app/test/test_eal_flags.c | 24 +++++ doc/guides/prog_guide/log_lib.rst | 16 ++- lib/eal/common/eal_common_options.c | 11 ++ lib/eal/common/eal_options.h | 6 +- lib/log/log.c | 24 +++-- lib/log/log_color.c | 160 ++++++++++++++++++++++++++++ lib/log/log_internal.h | 5 + lib/log/log_private.h | 8 ++ lib/log/meson.build | 2 +- lib/log/version.map | 1 + 10 files changed, 247 insertions(+), 10 deletions(-) create mode 100644 lib/log/log_color.c diff --git a/app/test/test_eal_flags.c b/app/test/test_eal_flags.c index 08f4866461..c6c05e2e1d 100644 --- a/app/test/test_eal_flags.c +++ b/app/test/test_eal_flags.c @@ -1067,6 +1067,18 @@ test_misc_flags(void) const char * const argv25[] = {prgname, prefix, mp_flag, "--log-timestamp=invalid" }; + /* Try running with --log-color */ + const char * const argv26[] = {prgname, prefix, mp_flag, + "--log-color" }; + + /* Try running with --log-color=never */ + const char * const argv27[] = {prgname, prefix, mp_flag, + "--log-color=never" }; + + /* Try running with --log-color=invalid */ + const char * const argv28[] = {prgname, prefix, mp_flag, + "--log-color=invalid" }; + /* run all tests also applicable to FreeBSD first */ @@ -1187,6 +1199,18 @@ test_misc_flags(void) printf("Error - process did run ok with --log-timestamp=invalid parameter\n"); goto fail; } + if (launch_proc(argv26) != 0) { + printf("Error - process did not run ok with --log-color parameter\n"); + goto fail; + } + if (launch_proc(argv27) != 0) { + printf("Error - process did not run ok with --log-color=none parameter\n"); + goto fail; + } + if (launch_proc(argv28) == 0) { + printf("Error - process did run ok with --log-timestamp=invalid parameter\n"); + goto fail; + } rmdir(hugepath_dir3); diff --git a/doc/guides/prog_guide/log_lib.rst b/doc/guides/prog_guide/log_lib.rst index 476dedb097..f46720fe34 100644 --- a/doc/guides/prog_guide/log_lib.rst +++ b/doc/guides/prog_guide/log_lib.rst @@ -59,6 +59,21 @@ For example:: Within an application, the same result can be got using the ``rte_log_set_level_pattern()`` or ``rte_log_set_level_regex()`` APIs. +Color output +~~~~~~~~~~~~ + +The log library will highlight important messages. +This is controlled by the ``--log-color`` option. +he optional argument ``when`` can be ``auto``, ``never``, or ``always``. +The default setting is ``auto`` which enables color when the output to +``stderr`` is a terminal. +If the ``when`` argument is omitted, it defaults to ``always``. + +For example to turn off all coloring:: + + /path/to/app --log-color=none + + Log timestamp ~~~~~~~~~~~~~ @@ -115,7 +130,6 @@ There are three possible settings for this option: *always* Always try to direct messages to journal socket. - Using Logging APIs to Generate Log Messages ------------------------------------------- diff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c index 9a82118184..70fdf3f5a1 100644 --- a/lib/eal/common/eal_common_options.c +++ b/lib/eal/common/eal_common_options.c @@ -73,6 +73,7 @@ eal_long_options[] = { {OPT_HUGE_UNLINK, 2, NULL, OPT_HUGE_UNLINK_NUM }, {OPT_IOVA_MODE, 1, NULL, OPT_IOVA_MODE_NUM }, {OPT_LCORES, 1, NULL, OPT_LCORES_NUM }, + {OPT_LOG_COLOR, 2, NULL, OPT_LOG_COLOR_NUM }, {OPT_LOG_LEVEL, 1, NULL, OPT_LOG_LEVEL_NUM }, {OPT_LOG_JOURNAL, 2, NULL, OPT_LOG_JOURNAL_NUM }, {OPT_LOG_TIMESTAMP, 2, NULL, OPT_LOG_TIMESTAMP_NUM }, @@ -1620,6 +1621,7 @@ eal_log_level_parse(int argc, char * const argv[]) case OPT_SYSLOG_NUM: case OPT_LOG_JOURNAL_NUM: case OPT_LOG_TIMESTAMP_NUM: + case OPT_LOG_COLOR_NUM: if (eal_parse_common_option(opt, optarg, internal_conf) < 0) return -1; break; @@ -1872,6 +1874,14 @@ eal_parse_common_option(int opt, const char *optarg, } break; + case OPT_LOG_COLOR_NUM: + if (eal_log_color(optarg) < 0) { + EAL_LOG(ERR, "invalid parameters for --" + OPT_LOG_COLOR); + return -1; + } + break; + #ifndef RTE_EXEC_ENV_WINDOWS case OPT_TRACE_NUM: { if (eal_trace_args_save(optarg) < 0) { @@ -2240,6 +2250,7 @@ eal_common_usage(void) " Set specific log level\n" " --"OPT_LOG_LEVEL"=help Show log types and levels\n" " --"OPT_LOG_TIMESTAMP"[=] Timestamp log output\n" + " --"OPT_LOG_COLOR"[=] Colorize log messages\n" #ifndef RTE_EXEC_ENV_WINDOWS " --"OPT_TRACE"=\n" " Enable trace based on regular expression trace name.\n" diff --git a/lib/eal/common/eal_options.h b/lib/eal/common/eal_options.h index c5a1c70288..c0686c2544 100644 --- a/lib/eal/common/eal_options.h +++ b/lib/eal/common/eal_options.h @@ -33,10 +33,12 @@ enum { OPT_HUGE_UNLINK_NUM, #define OPT_LCORES "lcores" OPT_LCORES_NUM, -#define OPT_LOG_LEVEL "log-level" - OPT_LOG_LEVEL_NUM, +#define OPT_LOG_COLOR "log-color" + OPT_LOG_COLOR_NUM, #define OPT_LOG_JOURNAL "log-journal" OPT_LOG_JOURNAL_NUM, +#define OPT_LOG_LEVEL "log-level" + OPT_LOG_LEVEL_NUM, #define OPT_LOG_TIMESTAMP "log-timestamp" OPT_LOG_TIMESTAMP_NUM, #define OPT_TRACE "trace" diff --git a/lib/log/log.c b/lib/log/log.c index d97bde984e..a2254b461b 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -510,10 +510,14 @@ log_print(FILE *f, uint32_t level __rte_unused, const char *format, va_list ap) void eal_log_init(const char *id) { + bool is_terminal; + #ifdef RTE_EXEC_ENV_WINDOWS RTE_SET_USED(id); + + is_terminal = _isatty(_fileno(stderr)); #else - bool is_terminal = isatty(STDERR_FILENO); + is_terminal = isatty(STDERR_FILENO); #ifdef RTE_EXEC_ENV_LINUX if (log_journal_enabled(id)) @@ -523,11 +527,19 @@ eal_log_init(const char *id) if (log_syslog_enabled(is_terminal)) log_syslog_open(id, is_terminal); else -#endif - if (log_timestamp_enabled()) - rte_logs.print_func = log_print_with_timestamp; - else - rte_logs.print_func = log_print; +#endif /* RTE_EXEC_ENV_WINDOWS */ + + if (log_color_enabled(is_terminal)) { + if (log_timestamp_enabled()) + rte_logs.print_func = color_print_with_timestamp; + else + rte_logs.print_func = color_print; + } else { + if (log_timestamp_enabled()) + rte_logs.print_func = log_print_with_timestamp; + else + rte_logs.print_func = log_print; + } #if RTE_LOG_DP_LEVEL >= RTE_LOG_DEBUG RTE_LOG(NOTICE, EAL, diff --git a/lib/log/log_color.c b/lib/log/log_color.c new file mode 100644 index 0000000000..2bed521bc0 --- /dev/null +++ b/lib/log/log_color.c @@ -0,0 +1,160 @@ +/* SPDX-License-Identifier: BSD-3-Clause */ + +#include +#include +#include +#include +#include +#include + +#include +#include + +#ifdef RTE_EXEC_ENV_WINDOWS +#include +#endif + +#include "log_internal.h" +#include "log_private.h" + +enum { + LOG_COLOR_AUTO = 0, /* default */ + LOG_COLOR_NEVER, + LOG_COLOR_ALWAYS, +} log_color_mode; + +enum color { + COLOR_NONE, + COLOR_RED, + COLOR_GREEN, + COLOR_YELLOW, + COLOR_BLUE, + COLOR_MAGENTA, + COLOR_CYAN, + COLOR_WHITE, + COLOR_BOLD, + COLOR_CLEAR, +}; + +/* Standard terminal escape codes for colors and bold */ +static const char * const color_code[] = { + [COLOR_NONE] = "", + [COLOR_RED] = "\033[31m", + [COLOR_GREEN] = "\033[32m", + [COLOR_YELLOW] = "\033[33m", + [COLOR_BLUE] = "\033[34m", + [COLOR_MAGENTA] = "\033[35m", + [COLOR_CYAN] = "\033[36m", + [COLOR_WHITE] = "\033[37m", + [COLOR_BOLD] = "\033[1m", + [COLOR_CLEAR] = "\033[0m", +}; + +__rte_format_printf(3, 4) +static int color_fprintf(FILE *out, enum color color, const char *fmt, ...) +{ + va_list args; + int ret = 0; + + va_start(args, fmt); + ret = fprintf(out, "%s", color_code[color]); + ret += vfprintf(out, fmt, args); + ret += fprintf(out, "%s", color_code[COLOR_CLEAR]); + va_end(args); + + return ret; +} + +static ssize_t +color_log_write(FILE *f, int level, char *msg) +{ + char *cp; + ssize_t ret = 0; + + /* + * use convention that first part of message (up to the ':' character) + * is the subsystem id and should be highlighted. + */ + cp = strchr(msg, ':'); + if (cp) { + /* print first part in yellow */ + ret = color_fprintf(stderr, COLOR_YELLOW, "%.*s", + (int)(cp - msg + 1), msg); + msg = cp + 1; + } + + if (level <= 0 || level >= (int)RTE_LOG_INFO) + ret += fprintf(f, "%s", msg); + else if (level >= (int)RTE_LOG_ERR) + ret += color_fprintf(f, COLOR_BOLD, "%s", msg); + else + ret += color_fprintf(f, COLOR_RED, "%s", msg); + + return ret; +} + +/* + * Controls whether color is enabled: + * modes are: + * always - enable color output regardless + * auto - enable if stderr is a terminal + * never - color output is disabled. + */ +int +eal_log_color(const char *mode) +{ + if (mode == NULL || strcmp(mode, "always") == 0) + log_color_mode = LOG_COLOR_ALWAYS; + else if (strcmp(mode, "never") == 0) + log_color_mode = LOG_COLOR_NEVER; + else if (strcmp(mode, "auto") == 0) + log_color_mode = LOG_COLOR_AUTO; + else + return -1; + + return 0; +} + +bool +log_color_enabled(bool is_terminal) +{ + switch (log_color_mode) { + default: + case LOG_COLOR_NEVER: + return false; + case LOG_COLOR_ALWAYS: + return true; + case LOG_COLOR_AUTO: + return is_terminal; + } +} + +int +color_print(FILE *f, uint32_t level, const char *format, va_list ap) +{ + char *buf = NULL; + int ret; + + /* need to make temporary buffer for color scan */ + ret = vasprintf(&buf, format, ap); + if (ret > 0) { + ret = color_log_write(f, level, buf); + free(buf); + return ret; + } + + /* if vasprintf fails, print without color */ + return log_print(f, level, format, ap); +} + +int +color_print_with_timestamp(FILE *f, uint32_t level, + const char *format, va_list ap) +{ + char tsbuf[128]; + + if (log_timestamp(tsbuf, sizeof(tsbuf)) > 0) + color_fprintf(f, COLOR_GREEN, "[%s] ", tsbuf); + + return color_print(f, level, format, ap); +} diff --git a/lib/log/log_internal.h b/lib/log/log_internal.h index 82fdc21ac2..bba7041ea3 100644 --- a/lib/log/log_internal.h +++ b/lib/log/log_internal.h @@ -50,5 +50,10 @@ void rte_eal_log_cleanup(void); __rte_internal int eal_log_timestamp(const char *fmt); +/* + * Enable or disable color in log messages + */ +__rte_internal +int eal_log_color(const char *mode); #endif /* LOG_INTERNAL_H */ diff --git a/lib/log/log_private.h b/lib/log/log_private.h index 988579fc08..bb93584f29 100644 --- a/lib/log/log_private.h +++ b/lib/log/log_private.h @@ -23,4 +23,12 @@ bool log_journal_enabled(const char *id); __rte_format_printf(3, 0) int journal_print(FILE *f, uint32_t level, const char *format, va_list ap); +bool log_color_enabled(bool is_tty); + +__rte_format_printf(3, 0) +int color_print(FILE *f, uint32_t level, const char *format, va_list ap); + +__rte_format_printf(3, 0) +int color_print_with_timestamp(FILE *f, uint32_t level, const char *format, va_list ap); + #endif /* LOG_PRIVATE_H */ diff --git a/lib/log/meson.build b/lib/log/meson.build index 5b9be7f6f1..3467cb5e9d 100644 --- a/lib/log/meson.build +++ b/lib/log/meson.build @@ -4,6 +4,7 @@ includes += global_inc sources = files( 'log.c', + 'log_color.c', 'log_timestamp.c', ) @@ -17,5 +18,4 @@ else sources += files('log_syslog.c') endif - headers = files('rte_log.h') diff --git a/lib/log/version.map b/lib/log/version.map index 7af97ece43..eb3200dcde 100644 --- a/lib/log/version.map +++ b/lib/log/version.map @@ -25,6 +25,7 @@ DPDK_24 { INTERNAL { global: + eal_log_color; eal_log_init; eal_log_journal; eal_log_level2str; -- 2.43.0