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 D3220459C0; Tue, 17 Sep 2024 22:43:19 +0200 (CEST) Received: from mails.dpdk.org (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 13BC442D99; Tue, 17 Sep 2024 22:42:11 +0200 (CEST) Received: from mail-pl1-f170.google.com (mail-pl1-f170.google.com [209.85.214.170]) by mails.dpdk.org (Postfix) with ESMTP id B2B91427E6 for ; Tue, 17 Sep 2024 22:41:59 +0200 (CEST) Received: by mail-pl1-f170.google.com with SMTP id d9443c01a7336-2053f6b8201so57853525ad.2 for ; Tue, 17 Sep 2024 13:41:59 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=networkplumber-org.20230601.gappssmtp.com; s=20230601; t=1726605719; x=1727210519; 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=dkIAdJ2ANL7rxi4cTAehNnYlX39/D08ioEa1auKxQlM=; b=WV76f2wZnLS7Uuonre+NEd50x0hQFH39XIbAFdfmp4yMM8DEaxrBif8OLC5llil1AQ VndoPT1KOsts3Hz5ArQTdBHO5/b+VQsuJI/WblPenHn48vnPm72uWHPbU0nhKTz3kuCv UU5EDxy9x/pciwHi5PfsHDOs1NO2QgxE396Umbxfl87zrLIFED/kksX2P4WSYMc1MhNZ bKfIAUQTfSO7bwMBcMA4Zwrp5QkP87xVgsDqvvxeQ7K+ADi34Joh0I8rqoKjDxeUgJf6 JPgllUlXZZu8ZisvZJjHamamO4uSwdmvbFqMQ1OpPXDtBJDlK4CCdJe5VuaBQRRg/IuZ 6B5A== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1726605719; x=1727210519; 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=dkIAdJ2ANL7rxi4cTAehNnYlX39/D08ioEa1auKxQlM=; b=cXp/CENYzzHYZhTf7hqvJfFBZ6aUg/IA4K663yyqK9kcej+hIbXnUQAC1Tmrd9NQ8h nm4HWM3Zyqlf7pODoQm0YF8r9PBl54EnGrxzoMIvRfIu3GdvZe37jHmZAErLDoscwLuR 8EDootKsZO7vnLbUYa/mU/gYHteERXQLtxJQZn3YOd49gCMzG4+68F79WbVdx40RFKip Zw2Kt6+rZnXNIXzp3Ql3IrtAiooQXvw5m67fu/0ioSqTKjgQAnn9Dds81gJoXmDB5Ptd 2KJluTCZd9YMRmrzfxLqbm/y1CBvt8Q+d195dzSJgzbRvls9hrNsOiIaUgRNV/AypXuB KJGQ== X-Gm-Message-State: AOJu0Yz0zSbjM2hAOU6gI/zTNIGXo8cuVSuZqrqhWDhHyH0P0xi6tclH gwTuDKrAJpfeNnlRKW9YK2OUESe9d46hwVYunn/gfMx23kWRO2axK2ik4VYQZPbhAngUILNsaXQ s X-Google-Smtp-Source: AGHT+IEubEHsOfFWUrKjNnO7bCTNR692+AmJZL0+a429kWRP1u/unbQgNrwXNeBrP/2OkpNx+EmGwA== X-Received: by 2002:a17:902:ccc7:b0:206:adf0:4f15 with SMTP id d9443c01a7336-2076e3086c4mr356802005ad.8.1726605718817; Tue, 17 Sep 2024 13:41:58 -0700 (PDT) Received: from hermes.local (204-195-96-226.wavecable.com. [204.195.96.226]) by smtp.gmail.com with ESMTPSA id d9443c01a7336-20794731afasm53830425ad.272.2024.09.17.13.41.58 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 17 Sep 2024 13:41:58 -0700 (PDT) From: Stephen Hemminger To: dev@dpdk.org Cc: Stephen Hemminger , =?UTF-8?q?Morten=20Br=C3=B8rup?= Subject: [PATCH v22 14/15] log: colorize log output Date: Tue, 17 Sep 2024 13:35:56 -0700 Message-ID: <20240917203828.414701-15-stephen@networkplumber.org> X-Mailer: git-send-email 2.45.2 In-Reply-To: <20240917203828.414701-1-stephen@networkplumber.org> References: <20200814173441.23086-1-stephen@networkplumber.org> <20240917203828.414701-1-stephen@networkplumber.org> MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 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 Acked-by: Morten Brørup --- app/test/test_eal_flags.c | 24 +++++ doc/guides/prog_guide/log_lib.rst | 15 +++ lib/eal/common/eal_common_options.c | 11 +++ lib/eal/common/eal_options.h | 6 +- lib/log/log.c | 25 +++-- lib/log/log_color.c | 148 ++++++++++++++++++++++++++++ lib/log/log_internal.h | 5 + lib/log/log_private.h | 8 ++ lib/log/meson.build | 1 + lib/log/version.map | 1 + 10 files changed, 236 insertions(+), 8 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 06295030b2..6ee56ec97a 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..647c3fc28a 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 ~~~~~~~~~~~~~ diff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c index 59b9cdf5ff..db9a18188a 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) { @@ -2239,6 +2249,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 180011ae67..adccf2762b 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -503,10 +503,14 @@ rte_log(uint32_t level, uint32_t logtype, const char *format, ...) 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()) { @@ -518,11 +522,20 @@ eal_log_init(const char *id) log_syslog_open(id, is_terminal); goto notice; } -#endif - if (log_timestamp_enabled()) - rte_logs.print_func = log_print_with_timestamp; - else - rte_logs.print_func = vfprintf; + +#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 = vfprintf; + } notice: #if RTE_LOG_DP_LEVEL >= RTE_LOG_DEBUG diff --git a/lib/log/log_color.c b/lib/log/log_color.c new file mode 100644 index 0000000000..db11306e55 --- /dev/null +++ b/lib/log/log_color.c @@ -0,0 +1,148 @@ +/* SPDX-License-Identifier: BSD-3-Clause */ + +#include +#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; +} + +/* + * 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, const char *format, va_list ap) +{ + const int level = rte_log_cur_msg_loglevel(); + char *cp, *msg; + char buf[LINE_MAX]; + int ret = 0; + + vsnprintf(buf, LINE_MAX, format, ap); + msg = buf; + + /* + * 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(f, 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; +} + +int +color_print_with_timestamp(FILE *f, 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, 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 cb7bb32f2c..382ad0e892 100644 --- a/lib/log/log_private.h +++ b/lib/log/log_private.h @@ -22,4 +22,12 @@ void log_syslog_open(const char *id, bool is_terminal); bool log_journal_enabled(void); void log_journal_open(const char *id); +bool log_color_enabled(bool is_tty); + +__rte_format_printf(2, 0) +int color_print(FILE *f, const char *format, va_list ap); + +__rte_format_printf(2, 0) +int color_print_with_timestamp(FILE *f, const char *format, va_list ap); + #endif /* LOG_PRIVATE_H */ diff --git a/lib/log/meson.build b/lib/log/meson.build index 873c17238e..8fa5a5a47c 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', ) diff --git a/lib/log/version.map b/lib/log/version.map index b00657b98d..2611d3a22a 100644 --- a/lib/log/version.map +++ b/lib/log/version.map @@ -25,6 +25,7 @@ DPDK_25 { INTERNAL { global: + eal_log_color; eal_log_init; eal_log_journal; eal_log_level2str; -- 2.45.2