Skip to content

Honor a configurable format depth in RabbitMQ's log formatters#16992

Open
lukebakken wants to merge 8 commits into
rabbitmq:mainfrom
amazon-mq:feature/logger-formatter-honor-format-depth
Open

Honor a configurable format depth in RabbitMQ's log formatters#16992
lukebakken wants to merge 8 commits into
rabbitmq:mainfrom
amazon-mq:feature/logger-formatter-honor-format-depth

Conversation

@lukebakken

Copy link
Copy Markdown
Collaborator

Why

Follow-up to #14349 and the work that shipped in #14523 / #14555.

Those changes shrink the queue process state via format_state/1 before it is logged, which stops the largest offender (the backing-queue state) from being dumped on a crash. They do not, however, cap the depth of everything else a crash report prints: the Last message, the exit Reason, and the full crasher: SASL report from proc_lib. A crash in a process with a large mailbox or large arguments (for example a gen_batch_server such as ra_log_wal, as @the-mikedavis noted in the discussion) can still produce a multi-hundred-KB to multi-MB log entry containing message bodies, and in the worst case OOM the node.

OTP's own logger_formatter already solves this with its depth config value, which rewrites ~p/~w to ~P/~W so deep sub-terms are truncated to .... RabbitMQ ships its own formatters (rabbit_logger_text_fmt and rabbit_logger_json_fmt), which did not honor any depth, so the deprecated kernel.error_logger_format_depth setting mentioned in #14349 was not reflected in RabbitMQ's formatted output.

What

Make RabbitMQ's formatters honor a format depth, exposed as a per-output formatter setting:

log.file.formatter.depth = 20
log.console.formatter.depth = 20
log.exchange.formatter.depth = 20
log.syslog.formatter.depth = 20

Behavior:

  • The depth is applied the same way OTP's logger_formatter does: ~p/~w control sequences are rewritten to ~P/~W with the depth appended, truncating deeper sub-terms to .... This covers both {Format, Args} messages and reports formatted through an arity-2 report_cb (which is how proc_lib crash reports are logged), so the crash report itself is truncated, not just the server state.
  • When unset (the default), the value is unlimited, and RabbitMQ falls back to the deprecated error_logger_format_depth kernel variable via error_logger:get_format_depth/0, exactly as OTP's logger_formatter:get_depth/1 does. This keeps the deprecated setting working for anyone relying on it today, with no behavior change for users who set neither.
  • An explicit depth is floored at 5, matching OTP's logger_formatter semantics.

This is complementary to #14523 / #14555, not a replacement: format_state/1 removes the bulk of the state, and this bounds whatever remains across all crash-report fields.

Testing

  • deps/rabbitmq_prelaunch: new CT suites rabbit_logger_fmt_helpers_SUITE (text/report paths), rabbit_logger_json_fmt_SUITE (JSON path, asserting output remains valid JSON), and rabbit_prelaunch_early_logging_SUITE (config resolution and the error_logger_format_depth fallback). All green.
  • deps/rabbit: config_schema_SUITE covers the new mappings; green.
  • make dialyze and make xref pass on deps/rabbitmq_prelaunch; make dialyze passes on deps/rabbit.

Related

@mergify

mergify Bot commented Jul 21, 2026

Copy link
Copy Markdown

Tick the box to add this pull request to the merge queue (same as @mergifyio queue).

  • Queue this pull request

`rabbit_logger_fmt_helpers:format_msg/3` renders `{Format, Args}`
messages with a bare `io_lib:format/2`, which ignores any configured
format depth. As a result crash reports with large process states or
mailboxes are logged in full, unlike OTP's `logger_formatter` which
honors a `depth` parameter.

Add a Common Test suite that pins the intended behavior: a `{Format,
Args}` message formatted with `depth => 3` must truncate deep sub-terms
to `...`, while `depth => unlimited` must render the full term. The
truncation case fails against the current implementation.
`format_msg1/3` renders `{Format, Args}` messages with a bare
`io_lib:format/2`, ignoring any configured format depth. Crash reports
carrying large process states or mailboxes are therefore logged in
full, which can drive a large peak memory footprint.

Read `depth` from the formatter config (defaulting to `unlimited`, the
previous behavior) and apply it the same way OTP's `logger_formatter`
does: rewrite the ~p/~w control sequences to ~P/~W with the depth
appended so deep sub-terms are truncated to `...`.

This turns the truncation test added previously green while leaving the
`unlimited` path byte-for-byte unchanged.
The arity-2 `report_cb' clause in `format_report/3' invokes the
callback with an empty `Extra' map, so report callbacks never receive
the configured format depth. `proc_lib:report_cb/2' therefore falls
back to its `unlimited' default and logs crash reports in full,
including large mailboxes and process states.

Pass the depth-limiting keys (`depth', `chars_limit', `single_line')
through to the callback, the same way OTP's `logger_formatter' does.
Report callbacks can now truncate their output as intended.

Add tests covering an arity-2 report callback that honors the `depth'
from its `Extra' argument: truncated at a finite depth, full when
`unlimited'.
Derive a `depth' value in the generic formatter config from the
`log.*.formatter.depth' cuttlefish variable. When the key is unset or
`unlimited', fall back to the deprecated `error_logger_format_depth'
kernel variable, matching OTP's `logger_formatter:get_depth/1' (which
also floors an explicit depth at 5). This lets the existing kernel
setting finally take effect through RabbitMQ's own formatters.

Export `translate_generic_conf/2' for testing alongside the other
internal-testing helpers, and add a suite covering the explicit,
`unlimited', and unset cases.

The schema mapping that exposes `log.*.formatter.depth' in
`rabbitmq.conf' is added separately.
Expose the formatter depth in `rabbitmq.conf` as
`log.{console,file,exchange,syslog}.formatter.depth', mirroring the
existing `formatter.single_line' mappings. The value accepts a positive
integer or `unlimited' (the default), and is routed into the translated
formatter config where `translate_generic_conf/2' resolves it.

Without this mapping cuttlefish rejects the key with `unknown_variable'.

Add a config-schema snippet asserting the schema accepts the key. The
harness strips the `rabbit.log' subtree before comparison, so the
snippet cannot check the resulting value; a comment records this and
points to `rabbit_prelaunch_early_logging_SUITE', which covers the
resolved depth value.
The JSON formatter renders the `msg' field through the shared
`format_msg/3', so it already honors the configured format depth,
including crash reports (logged as `{report, _}' messages). Lock this
in with a test suite covering the `{Format, Args}' path, the
`unlimited' case, and the report-callback path, each also asserting the
produced line is still valid JSON.

No formatter change is needed; the behavior comes from the earlier
`format_msg/3' depth support.
`translate_generic_conf/2` returns a map carrying a `depth` key, which
the plaintext and JSON formatter translators merge into their results.
The `formatter_plaintext_conf()` and `formatter_json_conf()` types do not
declare `depth`, so dialyzer infers a return that violates the
`translate_*_formatter_conf` contracts and reports "has no local return".

Add `depth := unlimited | pos_integer()` to both types, matching the
field already present on `formatter_generic_conf()`.
@lukebakken
lukebakken force-pushed the feature/logger-formatter-honor-format-depth branch from 2a72712 to 05af8b8 Compare July 23, 2026 15:31
The `log.*.formatter.depth` mappings accept any integer, so a
misconfiguration such as `depth = 0` or a negative value passes schema
validation and is then silently clamped to 5. This is inconsistent with
the sibling `log.error_logger_format_depth` mapping, which rejects
non-positive values.

Add a `formatter_depth` validator that accepts `unlimited` or a positive
integer, and apply it to all four formatter depth mappings (console,
exchange, syslog, file). Document in `translate_generic_conf/2` that an
explicit depth is floored at 5, matching OTP's
`logger_formatter:get_depth/1`, so the clamp is no longer undocumented.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants