diff --git a/CHANGELOG.md b/CHANGELOG.md index c33ff47..92e1beb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,22 @@ the merge PR. ## Unreleased +- **LOG_* output is colorized by default, using Zephyr's palette** (#57) — + `CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR=y` (mirroring upstream's + `CONFIG_LOG_BACKEND_SHOW_COLOR`) prints errors in bold red and warnings in + bold yellow, spanning the level indicator through the end of the message with + the timestamp left uncolored. INF and DBG are uncolored unless + `CONFIG_ZSYS_LOG_INFO_COLOR_GREEN` / `CONFIG_ZSYS_LOG_DBG_COLOR_BLUE` are set, + as upstream. Set the parent symbol to `n` for plain output. + + Governs `LOG_*` (zsys) output only. `ESP_LOG*` traffic from ESP-IDF internals + keeps ESP-IDF's own non-bold palette under `CONFIG_LOG_COLORS`, so a console + carrying both will not look uniform. +- **New: `zsys_log_format_msg_color()`** (#57) — per-backend color control, + mirroring Zephyr's `LOG_OUTPUT_FLAG_COLORS`. `zsys_log_format_msg()` is + unchanged and still never emits color, so existing custom backends writing to + a file, socket or RTT channel need no action. + ## 0.1.0 — 2026-07-01 First tagged release. The 2026-06 hardening series is complete; the API diff --git a/components/zsys/Kconfig b/components/zsys/Kconfig index 8ce1739..1963378 100644 --- a/components/zsys/Kconfig +++ b/components/zsys/Kconfig @@ -31,6 +31,34 @@ menu "Boreas System Services (zsys)" Maximum length of the pre-formatted text field in each log message. Messages longer than this are truncated. + config ZSYS_LOG_BACKEND_SHOW_COLOR + bool "Colors in the backend" + default y + depends on ZSYS_LOG_MODULE + help + When enabled the backend prints errors in red and warnings in + yellow, mirroring Zephyr's CONFIG_LOG_BACKEND_SHOW_COLOR. As + upstream, the color spans the level indicator through the end + of the message, and INF/DBG are uncolored unless the options + below are set. + + Governs LOG_* (zsys) output only. ESP_LOG* traffic from + ESP-IDF internals keeps ESP-IDF's own coloring, controlled by + CONFIG_LOG_COLORS. + + config ZSYS_LOG_INFO_COLOR_GREEN + bool "Use green color for info level logs" + depends on ZSYS_LOG_BACKEND_SHOW_COLOR + help + Mirrors Zephyr's CONFIG_LOG_INFO_COLOR_GREEN. Off by default + upstream; enable for ESP-IDF-style output, where INF is green. + + config ZSYS_LOG_DBG_COLOR_BLUE + bool "Use blue color for debug level logs" + depends on ZSYS_LOG_BACKEND_SHOW_COLOR + help + Mirrors Zephyr's CONFIG_LOG_DBG_COLOR_BLUE. Off by default. + config ZSYS_LOG_MAX_BACKENDS int "Maximum number of log backends" default 4 diff --git a/components/zsys/README.md b/components/zsys/README.md index cd33d9d..de12cc7 100644 --- a/components/zsys/README.md +++ b/components/zsys/README.md @@ -78,6 +78,17 @@ static void my_put(const struct log_backend *b, const struct log_msg *msg) { zsys_log_format_msg(msg, buf, sizeof(buf)); uart_write(buf); } +``` + +`zsys_log_format_msg()` never emits color, so its output is safe for a file, +socket or RTT transport. A backend writing to a terminal calls +`zsys_log_format_msg_color(msg, buf, sizeof(buf), true)` instead -- the +per-backend switch Zephyr spells `LOG_OUTPUT_FLAG_COLORS`. Backends that format +the `log_msg` fields themselves can reach for `zsys_log_level_color()` and +`ZSYS_LOG_COLOR_RESET` directly. `CONFIG_ZSYS_LOG_COLOR=n` is a global off +switch over all three. + +```c static const struct log_backend_api my_api = { .put = my_put }; LOG_BACKEND_DEFINE(my_backend, &my_api, NULL); @@ -155,6 +166,9 @@ Requires `CONFIG_ZSYS_RETRY=y` (default). | `CONFIG_ZSYS_LOG_MODE_DEFERRED` | n | Deferred output via ring buffer + thread | | `CONFIG_ZSYS_LOG_BUFFER_COUNT` | 32 | Deferred queue depth | | `CONFIG_ZSYS_LOG_MSG_MAX_LEN` | 80 | Max text per message | +| `CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR` | y | Color ERR red / WRN yellow (Zephyr palette) | +| `CONFIG_ZSYS_LOG_INFO_COLOR_GREEN` | n | Also color INF green | +| `CONFIG_ZSYS_LOG_DBG_COLOR_BLUE` | n | Also color DBG blue | | `CONFIG_ZSYS_LOG_MAX_BACKENDS` | 4 | Max registered backends | | `CONFIG_ZSYS_LOG_THREAD_STACK_SIZE` | 2048 | Deferred output thread stack | | `CONFIG_ZSYS_LOG_THREAD_PRIORITY` | 2 | Deferred output thread priority | diff --git a/components/zsys/include/boreas/zsys/log_backend.h b/components/zsys/include/boreas/zsys/log_backend.h index 9ed134a..c22d100 100644 --- a/components/zsys/include/boreas/zsys/log_backend.h +++ b/components/zsys/include/boreas/zsys/log_backend.h @@ -131,9 +131,52 @@ void zsys_log_backend_register(const struct log_backend *backend); * -------------------------------------------------------------------------- */ /** - * Format a log message into a human-readable string. + * @brief ANSI reset sequence, or "" when color is disabled. + * + * Closes a sequence opened with zsys_log_level_color(). + */ +#if defined(CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR) +#define ZSYS_LOG_COLOR_RESET "\x1B[0m" +#else +#define ZSYS_LOG_COLOR_RESET "" +#endif + +/** + * @brief ANSI color escape for a log level. + * + * Follows Zephyr: bold red ERR, bold yellow WRN, and nothing else, unless + * CONFIG_ZSYS_LOG_INFO_COLOR_GREEN / CONFIG_ZSYS_LOG_DBG_COLOR_BLUE are set. + * Returns "" for every level when CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR is off. + * + * For backends that format the log_msg fields themselves; backends using + * zsys_log_format_msg_color() get color applied for them. + * + * @note Governs LOG_* (zsys) output only. ESP_LOG* traffic from ESP-IDF + * internals is colored by ESP-IDF under CONFIG_LOG_COLORS, which uses + * a different, non-bold palette. A console carrying both will not look + * uniform; that is deliberate, since matching ESP-IDF here would mean + * diverging from Zephyr for the API Boreas actually implements. + * + * @note A level with no color still pairs with ZSYS_LOG_COLOR_RESET, so an + * uncolored line carries a bare reset. Upstream does the same -- + * color_print() falls back to LOG_COLOR_CODE_DEFAULT whenever + * colors[level] is NULL, on the prefix and the postfix both -- and it + * clears color left set by another writer on the same UART. + * + * @param level LOG_LEVEL_* value + * @return Escape sequence, never NULL. Close it with ZSYS_LOG_COLOR_RESET. + */ +const char *zsys_log_level_color(int level); + +/** + * @brief Format a log message into a human-readable string. + * * Output: [12.345] module: message text * + * Never emits color, whatever the color options are set to, so the result is + * safe for a file, network or RTT transport. Terminal-bound backends that want + * color call zsys_log_format_msg_color() instead. + * * @param msg Log message to format * @param buf Output buffer * @param buf_size Size of output buffer @@ -142,6 +185,30 @@ void zsys_log_backend_register(const struct log_backend *backend); */ int zsys_log_format_msg(const struct log_msg *msg, char *buf, size_t buf_size); +/** + * @brief Format a log message, optionally colorizing the level token. + * + * As zsys_log_format_msg(), but the caller decides whether the level token is + * wrapped in ANSI escapes -- the per-backend control Zephyr spells + * LOG_OUTPUT_FLAG_COLORS on a struct log_output. Color is applied only when + * @p color is true AND CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR is enabled, so the + * Kconfig remains a global off switch. + * + * Deferred mode hands every backend the same struct log_msg, so this is where + * a terminal backend and a file backend part ways. + * + * @note As upstream, the color spans the level indicator through the end of + * the message; the leading timestamp stays uncolored. + * + * @param msg Log message to format + * @param buf Output buffer + * @param buf_size Size of output buffer + * @param color Wrap the level token in ANSI escapes + * @return Number of characters written (excluding null terminator), or + * negative on error. May be >= buf_size if truncated. + */ +int zsys_log_format_msg_color(const struct log_msg *msg, char *buf, size_t buf_size, bool color); + #ifdef __cplusplus } #endif diff --git a/components/zsys/src/log.c b/components/zsys/src/log.c index 6ee3dfa..1b65455 100644 --- a/components/zsys/src/log.c +++ b/components/zsys/src/log.c @@ -82,6 +82,42 @@ static const char *level_to_str(int level) } } +/* Upstream's codes and names, verbatim from zephyr/subsys/logging/log_output.c. + * Deliberately NOT ESP-IDF's LOG_COLOR_* (esp_log_color.h): those are non-bold + * and gated on CONFIG_LOG_COLORS, which governs ESP_LOG* only. */ +#define LOG_COLOR_CODE_DEFAULT "\x1B[0m" +#define LOG_COLOR_CODE_RED "\x1B[1;31m" +#define LOG_COLOR_CODE_GREEN "\x1B[1;32m" +#define LOG_COLOR_CODE_YELLOW "\x1B[1;33m" +#define LOG_COLOR_CODE_BLUE "\x1B[1;34m" + +const char *zsys_log_level_color(int level) +{ +#if defined(CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR) + /* Mirrors upstream's colors[]: ERR and WRN only, unless the INF/DBG + * options are set. */ + static const char *const colors[] = { + "", /* NONE */ + LOG_COLOR_CODE_RED, /* ERR */ + LOG_COLOR_CODE_YELLOW, /* WRN */ +#if defined(CONFIG_ZSYS_LOG_INFO_COLOR_GREEN) + LOG_COLOR_CODE_GREEN, /* INF */ +#else + "", /* INF */ +#endif +#if defined(CONFIG_ZSYS_LOG_DBG_COLOR_BLUE) + LOG_COLOR_CODE_BLUE, /* DBG */ +#else + "", /* DBG */ +#endif + }; + return (level >= 0 && level <= LOG_LEVEL_DBG) ? colors[level] : ""; +#else + (void)level; + return ""; +#endif +} + void zsys_log_list_modules(void) { ESP_LOGI(TAG, "Registered log modules (%d):", module_count); @@ -385,12 +421,22 @@ uint32_t zsys_log_get_dropped_count(void) * Default message formatter * ------------------------------------------------------------------------- */ -int zsys_log_format_msg(const struct log_msg *msg, char *buf, size_t buf_size) +int zsys_log_format_msg_color(const struct log_msg *msg, char *buf, size_t buf_size, bool color) { uint32_t ms = (uint32_t)msg->timestamp_ms; - return snprintf(buf, buf_size, "[%lu.%03lu] <%s> %s: %s", (unsigned long)(ms / 1000), - (unsigned long)(ms % 1000), level_to_str(msg->level), msg->module, - msg->text); + + /* Upstream spans the color from the level indicator through the end of + * the message, leaving the timestamp uncolored -- color_prefix() runs + * after timestamp_print() and color_postfix() after the body. */ + return snprintf(buf, buf_size, "[%lu.%03lu] %s<%s> %s: %s%s", (unsigned long)(ms / 1000), + (unsigned long)(ms % 1000), color ? zsys_log_level_color(msg->level) : "", + level_to_str(msg->level), msg->module, msg->text, + color ? ZSYS_LOG_COLOR_RESET : ""); +} + +int zsys_log_format_msg(const struct log_msg *msg, char *buf, size_t buf_size) +{ + return zsys_log_format_msg_color(msg, buf, buf_size, false); } void zsys_log_hexdump(uint8_t level, const char *module, const void *data, size_t len, @@ -486,12 +532,29 @@ void zsys_log_hexdump(uint8_t level, const char *module, const void *data, size_ (void)label; } -int zsys_log_format_msg(const struct log_msg *msg, char *buf, size_t buf_size) +int zsys_log_format_msg_color(const struct log_msg *msg, char *buf, size_t buf_size, bool color) { (void)msg; - (void)buf; - (void)buf_size; + (void)color; + + /* Returning 0 claims "wrote an empty string", so leave one behind -- + * a caller that prints buf on a non-negative return must not read + * uninitialized memory. */ + if (buf_size > 0) { + buf[0] = '\0'; + } return 0; } +int zsys_log_format_msg(const struct log_msg *msg, char *buf, size_t buf_size) +{ + return zsys_log_format_msg_color(msg, buf, buf_size, false); +} + +const char *zsys_log_level_color(int level) +{ + (void)level; + return ""; +} + #endif diff --git a/components/zsys/src/log_backend_esp.c b/components/zsys/src/log_backend_esp.c index f2e1782..3c20778 100644 --- a/components/zsys/src/log_backend_esp.c +++ b/components/zsys/src/log_backend_esp.c @@ -17,6 +17,7 @@ #include #include "esp_log.h" +#include "zsys/log.h" #if defined(CONFIG_ZSYS_LOG_MODULE) @@ -32,15 +33,18 @@ static void esp_backend_put(const struct log_backend *backend, const struct log_ #if defined(CONFIG_ZSYS_LOG_MODE_DEFERRED) /* Structured format with the original log-time timestamp */ char buf[CONFIG_ZSYS_LOG_MSG_MAX_LEN + 64]; - zsys_log_format_msg(msg, buf, sizeof(buf)); + /* Console backend: a terminal, so opt in to color. */ + zsys_log_format_msg_color(msg, buf, sizeof(buf), true); printf("%s\n", buf); #else static const char level_char[] = {'?', 'E', 'W', 'I', 'D'}; - uint8_t lvl = (msg->level <= 4) ? msg->level : 0; + uint8_t lvl = (msg->level <= LOG_LEVEL_DBG) ? msg->level : 0; - /* Match standard ESP-IDF format: LETTER (timestamp_ms) tag: text */ - printf("%c (%lu) %s: %s\n", level_char[lvl], (unsigned long)esp_log_timestamp(), - msg->module, msg->text); + /* Match standard ESP-IDF format: LETTER (timestamp_ms) tag: text. + * The level leads here, so upstream's "level indicator through end of + * message" span covers the whole line. */ + printf("%s%c (%lu) %s: %s%s\n", zsys_log_level_color(lvl), level_char[lvl], + (unsigned long)esp_log_timestamp(), msg->module, msg->text, ZSYS_LOG_COLOR_RESET); #endif } diff --git a/examples/log_demo/README.md b/examples/log_demo/README.md index 16d617d..e3f917b 100644 --- a/examples/log_demo/README.md +++ b/examples/log_demo/README.md @@ -72,6 +72,8 @@ I (575) log_demo: === Demo complete === static void my_put(const struct log_backend *b, const struct log_msg *msg) { char buf[128]; + /* Colorless -- safe for a file, socket or RTT channel. A terminal backend + calls zsys_log_format_msg_color(msg, buf, sizeof(buf), true) instead. */ zsys_log_format_msg(msg, buf, sizeof(buf)); my_transport_write(buf); /* UART, RTT, network, file, etc. */ } @@ -91,6 +93,9 @@ The backend is picked up automatically at `zsys_log_init()` time — on ESP targ | `CONFIG_ZSYS_LOG_MODE_DEFERRED` | n | Enable deferred mode (ring buffer + output thread) | | `CONFIG_ZSYS_LOG_BUFFER_COUNT` | 32 | Message queue depth (deferred mode) | | `CONFIG_ZSYS_LOG_MSG_MAX_LEN` | 80 | Max text length per message | +| `CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR` | y | Color ERR red / WRN yellow (Zephyr palette) | +| `CONFIG_ZSYS_LOG_INFO_COLOR_GREEN` | n | Also color INF green | +| `CONFIG_ZSYS_LOG_DBG_COLOR_BLUE` | n | Also color DBG blue | | `CONFIG_ZSYS_LOG_MAX_BACKENDS` | 4 | Maximum number of backends | When `CONFIG_ZSYS_LOG_MODULE` is disabled, `LOG_*` macros fall back to `ESP_LOG*` with zero overhead. diff --git a/test/main/test_log.c b/test/main/test_log.c index 88b8a93..a43d3c2 100644 --- a/test/main/test_log.c +++ b/test/main/test_log.c @@ -9,6 +9,7 @@ #include "zsys/log.h" #include "zsys/log_backend.h" +#include #include /* ----------------------------------------------------------------------- @@ -181,6 +182,73 @@ static void test_log_format_msg(void) TEST_ASSERT_NOT_NULL(strstr(buf, "hello world")); } +static void test_log_level_color(void) +{ + static const char *const names[] = {"NONE", "ERR", "WRN", "INF", "DBG"}; + struct log_msg msg = { + .timestamp_ms = 1, + .level = LOG_LEVEL_ERR, + .module = "mymod", + .thread = "main", + .text = "boom", + }; + char buf[128]; + char plain[128]; + char expect[64]; + + /* The plain formatter is the pre-0.1.0 contract and must stay colorless + * whatever the color options are set to -- backends writing to a file, + * socket or RTT channel depend on it. */ + TEST_ASSERT_GREATER_THAN(0, zsys_log_format_msg(&msg, buf, sizeof(buf))); + TEST_ASSERT_NULL(strchr(buf, '\033')); + TEST_ASSERT_NOT_NULL(strstr(buf, "")); + + /* ...and is exactly what the color variant produces with color=false */ + TEST_ASSERT_GREATER_THAN(0, zsys_log_format_msg_color(&msg, plain, sizeof(plain), false)); + TEST_ASSERT_EQUAL_STRING(buf, plain); + + /* With color=true every level's token is wrapped in whatever escape this + * build defines. Asserted against the accessor rather than a literal, so + * it holds under every color configuration. */ + for (int lvl = LOG_LEVEL_NONE; lvl <= LOG_LEVEL_DBG; lvl++) { + msg.level = (uint8_t)lvl; + TEST_ASSERT_GREATER_THAN(0, + zsys_log_format_msg_color(&msg, buf, sizeof(buf), true)); + snprintf(expect, sizeof(expect), "%s<%s> mymod: boom%s", zsys_log_level_color(lvl), + names[lvl], ZSYS_LOG_COLOR_RESET); + TEST_ASSERT_NOT_NULL(strstr(buf, expect)); + + /* Upstream leaves the timestamp outside the color */ + TEST_ASSERT_EQUAL('[', buf[0]); + } + +#if defined(CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR) + /* Pin upstream's palette: bold codes, ERR and WRN only by default */ + TEST_ASSERT_EQUAL_STRING("\x1B[1;31m", zsys_log_level_color(LOG_LEVEL_ERR)); + TEST_ASSERT_EQUAL_STRING("\x1B[1;33m", zsys_log_level_color(LOG_LEVEL_WRN)); + TEST_ASSERT_EQUAL_STRING("\x1B[0m", ZSYS_LOG_COLOR_RESET); + +#if defined(CONFIG_ZSYS_LOG_INFO_COLOR_GREEN) + TEST_ASSERT_EQUAL_STRING("\x1B[1;32m", zsys_log_level_color(LOG_LEVEL_INF)); +#else + TEST_ASSERT_EQUAL_STRING("", zsys_log_level_color(LOG_LEVEL_INF)); +#endif +#if defined(CONFIG_ZSYS_LOG_DBG_COLOR_BLUE) + TEST_ASSERT_EQUAL_STRING("\x1B[1;34m", zsys_log_level_color(LOG_LEVEL_DBG)); +#else + TEST_ASSERT_EQUAL_STRING("", zsys_log_level_color(LOG_LEVEL_DBG)); +#endif + +#else + TEST_ASSERT_EQUAL_STRING("", zsys_log_level_color(LOG_LEVEL_ERR)); + TEST_ASSERT_EQUAL_STRING("", ZSYS_LOG_COLOR_RESET); +#endif + + /* Out-of-range levels must not index off the table */ + TEST_ASSERT_EQUAL_STRING("", zsys_log_level_color(-1)); + TEST_ASSERT_EQUAL_STRING("", zsys_log_level_color(99)); +} + static void test_log_thread_name(void) { capture_reset(); @@ -292,6 +360,7 @@ void test_log_group(void) RUN_TEST(test_log_runtime_level_filter); RUN_TEST(test_log_all_levels); RUN_TEST(test_log_format_msg); + RUN_TEST(test_log_level_color); RUN_TEST(test_log_thread_name); RUN_TEST(test_log_message_truncation); RUN_TEST(test_log_backend_count);