Skip to content

feat(zsys): colorize the log level indicator - #57

Open
swoisz wants to merge 4 commits into
mainfrom
feature/zsys-log-color
Open

feat(zsys): colorize the log level indicator#57
swoisz wants to merge 4 commits into
mainfrom
feature/zsys-log-color

Conversation

@swoisz

@swoisz swoisz commented Aug 18, 2026

Copy link
Copy Markdown
Collaborator

Closes #34.

CONFIG_ZSYS_LOG_COLOR (default y) wraps the level token in ANSI codes -- red ERR, yellow WRN, green INF, uncolored DBG -- in both the sync (E (123) mod: text) and deferred ([12.345] <INF> mod: text) formats. Independent of ESP-IDF's CONFIG_LOG_COLORS, which only governs ESP_LOG* output, so the two can be set separately.

Deviation from the issue

The issue asked for zsys_log_format_msg() to grow a color flag mirroring upstream's LOG_OUTPUT_FLAG_COLORS. That changes a public signature documented in log_backend.h for out-of-tree backends, right after v0.1.0 went public. Backends instead get zsys_log_level_color(level) and ZSYS_LOG_COLOR_RESET -- the same "backend decides" capability with no API break. Worth adding the flag when a second in-tree backend actually needs plain text.

The ESP_LOG intercept from the original issue is split out to #56; it has an unresolved double-formatting question that shouldn't hold up this change.

Notes

  • Escapes are spelled out rather than reusing IDF's LOG_COLOR_*, because those are gated on CONFIG_LOG_COLORS -- reusing them would silently couple the two options. Sequences are identical to what ESP-IDF emits.
  • Worst-case deferred prefix grows 11 bytes (48 total); the backend's CONFIG_ZSYS_LOG_MSG_MAX_LEN + 64 buffer still covers it.
  • zsys_log_level_color() range-checks, so an out-of-range level can't index off the table.

Test

  • linux host: 225/225 pass with CONFIG_ZSYS_LOG_COLOR=y and again with =n
  • esp32s3: builds clean
  • clang-format 21.1.8: clean
  • New test_log_level_color asserts the exact escapes and that <ERR> survives intact between them; the =n branch asserts no \033 reaches the buffer.

🤖 Generated with Claude Code

CONFIG_ZSYS_LOG_COLOR (default y) wraps the level token in ANSI codes --
red ERR, yellow WRN, green INF, uncolored DBG -- in both the sync ("E")
and deferred ("<ERR>") formats. Independent of ESP-IDF's
CONFIG_LOG_COLORS, which only governs ESP_LOG* output.

Backends get zsys_log_level_color() + ZSYS_LOG_COLOR_RESET rather than
zsys_log_format_msg() growing a flag parameter, so the existing public
formatter signature is unchanged.

Part of #34.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@swoisz

swoisz commented Aug 18, 2026

Copy link
Copy Markdown
Collaborator Author

Validated on hardware (ESP32-S3, /dev/cu.usbserial-210, IDF v5.4), both log modes, CONFIG_ZSYS_LOG_COLOR=y.

Sync (CONFIG_ZSYS_LOG_MODE_DEFERRED=n) — 255 Tests 0 Failures:

^[[0;32mI^[[0m (4631) test_log: sync test message 42
^[[0;33mW^[[0m (4640) test_log: should pass
^[[0;31mE^[[0m (4640) test_log: should also pass
D^[[0m (4662) test_log: debug msg

Deferred (CONFIG_ZSYS_LOG_MODE_DEFERRED=y) — 255 Tests 0 Failures:

[4.385] ^[[0;32m<INF>^[[0m test_log: sync test message 42
[4.395] ^[[0;33m<WRN>^[[0m test_log: should pass
[4.396] ^[[0;31m<ERR>^[[0m test_log: should also pass
[4.419] <DBG>^[[0m test_log: debug msg

This covers the two things the host suite structurally cannot reach: esp_backend_put's sync printf (on linux the zsys_log_backend_esp_anchor reference is inside #if !defined(CONFIG_IDF_TARGET_LINUX), so that archive member never gets pulled and the console backend never registers), and the deferred queue -> thread -> backend path, which is default-n everywhere in CI.

One cosmetic note: DBG emits a bare \033[0m with no preceding color, since its entry in the table is "". Same thing ESP-IDF itself does (LOG_COLOR_D is "" followed by LOG_RESET_COLOR), 4 bytes per DBG line, and it usefully clears any color left set by an earlier writer. Left as-is for IDF parity.

Review found the first cut silently changed the contract of a public API
documented at v0.1.0: zsys_log_format_msg() is the formatter the READMEs
tell custom backends to use for "UART, RTT, network, file", and it began
emitting ANSI escapes into all of them with no opt-out.

Split it instead. zsys_log_format_msg() is unchanged and never colors;
zsys_log_format_msg_color(msg, buf, size, bool color) is the per-backend
switch, mirroring Zephyr's LOG_OUTPUT_FLAG_COLORS on struct log_output.
CONFIG_ZSYS_LOG_COLOR stays a global off switch over both. The console
backend opts in; a file or socket backend gets what it always got.

Also from review:

- Document the three divergences from Zephyr's log_output.c on the
  declaration: ESP-IDF's non-bold codes vs upstream's bold, INF colored
  by default where upstream gates it behind CONFIG_LOG_INFO_COLOR_GREEN,
  and level-token-only wrapping vs upstream's whole-line span.
- Document why an uncolored level still emits a bare reset -- both
  ESP-IDF and Zephyr do the same, and it clears color left set by
  another writer on the same UART.
- Assert the color/formatter coupling against the accessor rather than a
  literal, so the test body is exercised under both settings of
  CONFIG_ZSYS_LOG_COLOR instead of only the default; cover every level
  and pin that the plain formatter stays colorless.
- Kconfig table in components/zsys/README.md and examples/log_demo,
  custom-backend snippets in both, CHANGELOG entry.
- LOG_LEVEL_DBG instead of a bare 4 in the sync backend bounds check.

Part of #34.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@swoisz
swoisz marked this pull request as draft August 18, 2026 19:25
@swoisz

swoisz commented Aug 18, 2026

Copy link
Copy Markdown
Collaborator Author

Converted to draft pending one HW re-check (see bottom).

Review round: /boreas-review + two-axis /code-review

Applied

The material one — spec axis. The first cut silently changed a public contract. zsys_log_format_msg() is the formatter both components/zsys/README.md and examples/log_demo/README.md tell custom backends to use for "UART, RTT, network, file, etc.", and it started emitting ANSI escapes into all of them with no opt-out. Avoiding the signature break traded a compile error for a silent semantic break, which is the worse failure.

Split instead: zsys_log_format_msg() unchanged and colorless, new zsys_log_format_msg_color(msg, buf, size, bool color) carrying the per-backend switch (Zephyr's LOG_OUTPUT_FLAG_COLORS on struct log_output). CONFIG_ZSYS_LOG_COLOR stays a global off switch over both. Console backend opts in; a file or socket backend gets what it always got.

Zephyr divergences documented on the declaration, verified against subsys/logging/log_output.c: upstream uses bold \x1B[1;31m vs ESP-IDF's \033[0;31m; upstream gates INF green behind CONFIG_LOG_INFO_COLOR_GREEN and DBG blue behind CONFIG_LOG_DBG_COLOR_BLUE where Boreas colors INF by default; upstream spans the whole line (color_prefix() at :651 through postfix_print() at :709) where Boreas wraps only the level token.

Test made config-agnostic. test/sdkconfig.defaults doesn't set the symbol, so CI only ever built the default y side and the #else branch was dead. The coupling is now asserted against zsys_log_level_color() rather than a literal, so the body runs under both settings; covers every level and pins that the plain formatter stays colorless.

Docs: Kconfig tables in both READMEs, both custom-backend snippets, CHANGELOG entry. Nit: LOG_LEVEL_DBG for the bare 4.

Declined, with reasons

  • "Guard the reset so uncolored levels don't emit a bare \033[0m." Both references do exactly this — ESP-IDF emits LOG_COLOR_D ("") then LOG_RESET_COLOR; Zephyr's color_print() falls back to LOG_COLOR_CODE_DEFAULT whenever colors[level] is NULL, on the prefix and the postfix. It also clears color left set by another writer. Documented in an @note so it doesn't get re-raised.
  • "Collapse level_to_str() / colors[] / level_char[] into one table" (Repeated Switches). Real smell, but log levels are fixed by Zephyr at five and have never changed; the "3 edits to add a level" cost is hypothetical, and collapsing across the two TUs means exporting more API than it removes.
  • "The level >= 0 half of the bounds check is dead." Not dead — the function is public and takes int; the test exercises -1 and 99.
  • "Unify with components/zshell/src/shell_print.c's \033[31m palette." Correctly spotted as a third in-tree palette, but sharing four string literals isn't worth a zshell->zsys coupling. Noted, not acted on.

Not done — needs a decision

CI still only builds CONFIG_ZSYS_LOG_COLOR=y. A =n job in build-and-test is ~8 lines but doubles that job's wall time across both IDF versions. Ran locally instead (225/225 both ways). Say if you want the CI job.

Verification

  • linux host, =y and =n: 225 Tests 0 Failures each
  • esp32s3 default config: builds clean, IRAM guard passes 27/27
  • esp32s3 with CONFIG_ZSYS_LOG_MODE_DEFERRED=y: builds clean
  • clang-format 21.1.8 clean

Pending: the earlier on-HW capture validated the deferred path when it called zsys_log_format_msg(); that call is now zsys_log_format_msg_color(..., true). The board dropped off the bus before I could reflash, so that one path is compile-verified and host-verified but not re-confirmed on silicon. Draft until it is.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Adds optional ANSI/VT100 color support for zsys log level indicators, controlled by a new CONFIG_ZSYS_LOG_COLOR Kconfig option, while preserving the existing “always colorless” formatter contract for non-terminal backends.

Changes:

  • Introduces CONFIG_ZSYS_LOG_COLOR plus a level→escape accessor (zsys_log_level_color) and reset token (ZSYS_LOG_COLOR_RESET).
  • Adds zsys_log_format_msg_color(..., bool color) and keeps zsys_log_format_msg() permanently colorless (backend-controlled coloring).
  • Updates the ESP console backend and adds unit tests + documentation/changelog updates.

Reviewed changes

Copilot reviewed 8 out of 8 changed files in this pull request and generated 1 comment.

Show a summary per file
File Description
test/main/test_log.c Adds unit coverage for colored vs. plain formatting and the level→escape accessor behavior.
examples/log_demo/README.md Documents that zsys_log_format_msg() is colorless and terminals should use the color-aware formatter.
components/zsys/src/log.c Implements color escape selection and the new optional-color formatter variant.
components/zsys/src/log_backend_esp.c Enables color for the console backend in both deferred and sync output formats.
components/zsys/README.md Documents per-backend color behavior and the new APIs/symbols.
components/zsys/Kconfig Adds CONFIG_ZSYS_LOG_COLOR configuration option and help text.
components/zsys/include/boreas/zsys/log_backend.h Exposes ZSYS_LOG_COLOR_RESET, zsys_log_level_color(), and zsys_log_format_msg_color().
CHANGELOG.md Notes the new default coloring behavior and new formatter API.

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread components/zsys/src/log.c
Comment on lines +517 to +521
(void)msg;
(void)buf;
(void)buf_size;
(void)color;
return 0;

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch, and it applied to the pre-existing zsys_log_format_msg() stub too, so both are fixed in 263512ezsys_log_format_msg() now delegates to the color variant in the =n block as well, matching the enabled build.

Not theoretical, either: a CONFIG_ZSYS_LOG_MODULE=n linux build compiles both symbols into libzsys.a (nm shows _zsys_log_format_msg and _zsys_log_format_msg_color), so the stubs are reachable public API rather than dead code.

	/* 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;

Separately, that config exposed something unrelated to this PR: the test binary builds with CONFIG_ZSYS_LOG_MODULE=n but then hangs at runtime — the suite assumes the log module is present. Filing that on its own.

With CONFIG_ZSYS_LOG_MODULE=n both formatter stubs returned 0 -- which
claims "wrote an empty string" -- while leaving buf untouched, so a
caller that printed buf on a non-negative return read uninitialized
memory. Terminate it. zsys_log_format_msg() now delegates to the color
variant in this block too, matching the enabled build.

Not theoretical: a =n build compiles both symbols into libzsys.a.

Reported by Copilot on #57.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@swoisz

swoisz commented Aug 18, 2026

Copy link
Copy Markdown
Collaborator Author

On-HW re-validation complete (ESP32-S3, IDF v5.4) at 263512e — this re-confirms the paths that changed after the review round, in particular the deferred backend now calling zsys_log_format_msg_color(..., true) instead of zsys_log_format_msg().

Deferred (CONFIG_ZSYS_LOG_MODE_DEFERRED=y) — 255 Tests 0 Failures:

[4.391] ^[[0;32m<INF>^[[0m test_log: sync test message 42
[4.401] ^[[0;33m<WRN>^[[0m test_log: should pass
[4.402] ^[[0;31m<ERR>^[[0m test_log: should also pass
[4.425] <DBG>^[[0m test_log: debug msg

Sync (default) — 255 Tests 0 Failures:

^[[0;32mI^[[0m (4625) test_log: sync test message 42
^[[0;33mW^[[0m (4634) test_log: should pass
^[[0;31mE^[[0m (4634) test_log: should also pass
D^[[0m (4656) test_log: debug msg

Byte-for-byte the same output as the pre-refactor capture, so routing the console backend through the opt-in variant changed nothing on the wire. IRAM guard passes 27/27 on the same ELF.

Full verification state:

Check Result
linux host, ZSYS_LOG_COLOR=y 225/225
linux host, ZSYS_LOG_COLOR=n 225/225
linux, ZSYS_LOG_MODULE=n builds clean (runtime hang is pre-existing, #58)
esp32s3 sync, on HW 255/255, colors correct
esp32s3 deferred, on HW 255/255, colors correct
IRAM symbol guard 27/27
clang-format 21.1.8 clean

Marking ready for review.

@swoisz
swoisz marked this pull request as ready for review August 18, 2026 20:11
The first cut reproduced ESP-IDF's palette, which is what #34 asked for.
Reversed on review of the on-target capture: Boreas implements Zephyr's
logging API, so LOG_* output should look like Zephyr's. ESP_LOG* traffic
from ESP-IDF internals is left alone and keeps ESP-IDF's coloring.

Verified against zephyr/subsys/logging/{log_output.c,Kconfig.formatting}:

- Bold codes (LOG_COLOR_CODE_* copied verbatim, "\x1B[1;31m") rather than
  ESP-IDF's non-bold "\033[0;31m".
- ERR red and WRN yellow only. INF and DBG are uncolored unless the new
  ZSYS_LOG_INFO_COLOR_GREEN / ZSYS_LOG_DBG_COLOR_BLUE are set, mirroring
  upstream's sub-options, which are likewise off by default.
- Color spans the level indicator through the end of the message, leaving
  the timestamp uncolored: upstream calls color_prefix() after
  timestamp_print() and color_postfix() after the body. The sync format
  leads with the level, so there the span covers the whole line.
- CONFIG_ZSYS_LOG_COLOR renamed CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR after
  upstream's CONFIG_LOG_BACKEND_SHOW_COLOR. Never released, so no
  migration note; help text is upstream's wording.

The mixed console this produces is deliberate and documented on the
declaration: a UART carrying both LOG_* and ESP_LOG* will show two
palettes, and matching ESP-IDF would mean diverging from Zephyr for the
API Boreas actually implements.

Part of #34.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@swoisz
swoisz marked this pull request as draft August 18, 2026 20:30
@swoisz

swoisz commented Aug 18, 2026

Copy link
Copy Markdown
Collaborator Author

On-HW confirmation of the Zephyr palette (ESP32-S3, IDF v5.4) at b8c108c. Both modes, 255 Tests 0 Failures each.

Deferred — note the timestamp sits outside the color, matching upstream's color_prefix()-after-timestamp_print() ordering:

[4.385] <INF> test_log: sync test message 42^[[0m
[4.395] ^[[1;33m<WRN> test_log: should pass^[[0m
[4.395] ^[[1;31m<ERR> test_log: should also pass^[[0m
[4.418] <DBG> test_log: debug msg^[[0m

Sync — the level leads this format, so the span covers the whole line:

I (4627) test_log: sync test message 42^[[0m
^[[1;33mW (4636) test_log: should pass^[[0m
^[[1;31mE (4636) test_log: should also pass^[[0m
D (4658) test_log: debug msg^[[0m

Bold 1;33 / 1;31, ERR and WRN only, INF and DBG uncolored — upstream's defaults. IRAM guard 27/27 on the same ELF.

Full verification state:

Check Result
linux host, defaults 225/225
linux host, INFO_COLOR_GREEN=y + DBG_COLOR_BLUE=y 225/225
linux host, BACKEND_SHOW_COLOR=n 225/225
linux, ZSYS_LOG_MODULE=n builds clean (runtime hang is pre-existing, #58)
esp32s3 sync, on HW 255/255, palette correct
esp32s3 deferred, on HW 255/255, palette correct
IRAM symbol guard 27/27
clang-format 21.1.8 clean

Two Zephyr deltas deliberately left alone

Both predate this branch, both are format rather than color, and both would break downstream log parsers — worth deciding separately given the consumers pinned to v0.1.0:

  • Upstream's severity tokens are lowercase (severity[] in log_output.c is "err", "wrn", "inf", "dbg"); Boreas emits <INF>.
  • Upstream's timestamp is [00:00:12.345,000]; Boreas emits [12.345].

Marking ready for review.

@swoisz
swoisz marked this pull request as ready for review August 18, 2026 21:26
@swoisz
swoisz requested a lite review from Copilot August 19, 2026 02:09

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 8 out of 8 changed files in this pull request and generated no new comments.

Suppressed comments (3)

components/zsys/README.md:89

  • The README references CONFIG_ZSYS_LOG_COLOR=n as the global off switch, but this PR introduces CONFIG_ZSYS_LOG_BACKEND_SHOW_COLOR (and the other related symbols). As written, the docs point users to a non-existent/unused config option.
`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.

components/zsys/include/boreas/zsys/log_backend.h:164

  • This note claims upstream falls back to LOG_COLOR_CODE_DEFAULT on both prefix and postfix when a level has no color, but the current implementation returns "" for INF/DBG when those options are off (see components/zsys/src/log.c), so callers won’t emit a default/reset prefix. Either adjust the docs to match the actual behavior or change zsys_log_level_color() to return a reset/default code for uncolored levels when color is enabled.
 * @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.

CHANGELOG.md:12

  • Changelog says the color span leaves “the timestamp” uncolored, but in synchronous mode the ESP backend prefixes the color before the level char and resets at the end, which also colors the (%lu) timestamp. Consider clarifying that “timestamp left uncolored” applies to the deferred [sec.ms] prefix only, or adjust the sync backend if the intent is to keep its timestamp uncolored too.
  `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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

zsys/log: ANSI color output

2 participants