Skip to content

MIM-2681 Collect errors from all reachable MIM nodes - #4701

Merged
telezynski merged 11 commits into
masterfrom
collect-errors-from-all-nodes
May 7, 2026
Merged

telezynski merged 11 commits into
masterfrom
collect-errors-from-all-nodes

Conversation

@telezynski

@telezynski telezynski commented Apr 15, 2026 •

Copy link
Copy Markdown
Member

Summary

Replaces the per-MIM-node ETS-based error log collection with a runner-side sink that receives error events pushed from MIM nodes via Erlang messaging. Fixes the central correctness issue with the previous design: when a MIM node restarted, the ETS table holding its
collected errors went with it.

Why

The previous attempt at MIM-2681 (now absorbed by this branch) injected log_error_collector on each reachable MIM node and pulled errors via RPC at every CT section boundary. The collector kept a per-node ETS table; if the node restarted mid-suite, all collected errors
for that suite were lost. This branch moves the source of truth to the test runner.

Architecture

Three modules, push-mode:

  • cth_error_report_sink (new, on the test runner) — a gen_server owning one ETS table keyed by a global monotonic sequence. Receives {log_entry, Node, Level, Msg, Meta} messages from injected handlers on all MIM nodes.
  • log_error_collector (rewritten) — a stateless OTP logger handler injected on each MIM node. On each error event, calls erlang:send/3 with [noconnect, nosuspend] to the runner-side sink — never blocks the logger, never auto-connects.
  • cth_error_report (rewired) — the CT hook now starts/stops the sink in init/2/terminate/1 and reads from the sink at each section boundary instead of doing per-node RPC fan-out.

Restart contract: re-injection is the responsibility of the utility that brought the node back. distributed_helper:start_node/2 now calls cth_error_report_sink:inject/1 after the node is up. The sink does not subscribe to nodeup itself — log collection should not
be in the business of distribution-layer concerns.

Public API

  • cth_error_report:expect/1,2 and max_unexpected_errors_logged/1 — unchanged.
  • New: cth_error_report_sink exports start_link/0, stop/0, mark/0, get_after/1, clear/0, watch_nodes/2, inject/1, unwatch/0.

Empirical validation

A full test run collected 217 errors from non-mim1 nodes across 7 suites — primarily mod_global_distrib_SUITE (126 from reg1@localhost / mongooseim2@localhost) and service_domain_db_SUITE (81). The new errors_survive_handler_restart_on_mim2 test
case demonstrates the correctness claim end-to-end.

Limitations

Errors logged on a MIM node during the brief boot window between restart and re-injection of the handler are lost. If a node is restarted by a path that does not go through distributed_helper:start_node/2 (e.g. an external script), error collection on that node will not
resume until something calls cth_error_report_sink:inject/1 explicitly. Documented in doc/developers-guide/Error-log-tracking.md.

Files

File Change
big_tests/src/cth_error_report.erl Hook rewired to drive the sink
big_tests/src/cth_error_report_sink.erl New — runner-side sink gen_server
big_tests/tests/log_error_collector.erl Rewritten as a stateless push-mode handler
big_tests/tests/cth_error_report_SUITE.erl New multi_node group + restart-resilience test
test/common/distributed_helper.erl start_node/2 re-injects the handler post-start
doc/developers-guide/Error-log-tracking.md Multi-node section reflects the new design

@mongoose-im

This comment was marked as outdated.

@codecov

codecov Bot commented Apr 15, 2026 •

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 85.85%. Comparing base (6aeee3a) to head (c19f7a7).

Additional details and impacted files
@@            Coverage Diff             @@
##           master    #4701      +/-   ##
==========================================
+ Coverage   85.80%   85.85%   +0.05%     
==========================================
  Files         550      550              
  Lines       33225    33225              
==========================================
+ Hits        28508    28526      +18     
+ Misses       4717     4699      -18     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@telezynski
telezynski marked this pull request as ready for review April 16, 2026 09:45

@chrzaszcz chrzaszcz left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Looks good in general. I added some comments.

Comment thread big_tests/src/cth_error_report.erl Outdated
Comment thread big_tests/tests/cth_error_report_SUITE.erl Outdated
Comment thread big_tests/src/cth_error_report.erl Outdated
Comment thread doc/developers-guide/Error-log-tracking.md Outdated
@telezynski
telezynski force-pushed the collect-errors-from-all-nodes branch from e9f9696 to 3664242 Compare May 4, 2026 14:37
@telezynski

telezynski commented May 4, 2026 •

Copy link
Copy Markdown
Member Author

The implementation was rewritten in new paradigm - errors after collection on nodes are immediately sent to central collector running on test node.
Forced pushed changes, old implementation commit is lost as it is superceded by new implementation.

@chrzaszcz chrzaszcz left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Looks good. I added some minor comments. I also have some notes that are not issues to fix - but rather my general impressions and intuitive thoughts.

Personally, I would lean towards a solution where we only target the nodes listed in require_rpc_nodes(...) in each test suite. Regarding node restarts, I'd add node collector restart to the MIM restart utilities, so that whenever we call them, we are sure logs are collected again. This way the custom connection and node monitoring logic could be avoided, because maybe a log collection layer shouldn't try to take over node connectivity management? but these are my observations.

Comment thread big_tests/src/cth_error_report_sink.erl Outdated
Comment thread big_tests/src/cth_error_report_sink.erl Outdated
Comment thread big_tests/src/cth_error_report_sink.erl Outdated
Comment thread big_tests/src/cth_error_report_sink.erl Outdated
Comment thread big_tests/src/cth_error_report_sink.erl Outdated
@telezynski

Copy link
Copy Markdown
Member Author

Regarding node restarts, I'd add node collector restart to the MIM restart utilities, so that whenever we call them, we are sure logs are collected again. This way the custom connection and node monitoring logic could be avoided, because maybe a log collection layer shouldn't try to take over node connectivity management?

Good suggestion, implemented.

@chrzaszcz chrzaszcz left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Looks good 👌 - I just shared some cosmetic remarks - not mandatory to address.

Comment thread big_tests/src/cth_error_report.erl Outdated
Comment on lines +259 to +260
-spec node_specs() ->
[{atom(), distributed_helper:rpc_spec()}].

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Minor: could nicely fit in one line.

Comment on lines +15 to +16
-import(distributed_helper, [rpc/4, mim/0, mim2/0,
require_rpc_nodes/1]).

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

One line maybe?

Andrzej Telezynski added 11 commits May 7, 2026 09:16
Introduces a gen_server on the test runner that owns one ETS
table keyed by a global monotonic sequence and receives error
log entries pushed from MIM nodes via Erlang messaging.

Subscribes to net_kernel:monitor_nodes(true) and re-injects the
log_error_collector handler on nodeup, so entries already
collected on the runner survive MIM-node restarts -- only the
brief boot window between restart and re-injection loses
entries.

Public API:
  start_link/0, stop/0
  mark/0, get_after/1, clear/0      -- read model
  watch_nodes/2, unwatch/0           -- node management

Injection runs in transient processes so the gen_server stays
responsive; ct:pal surfaces injection failures (wrong cookie,
missing test.config) that would otherwise be silent.
Replaces the per-MIM-node ETS-keeping handler with a stateless
forwarder. log/2 sends {log_entry, node(), Level, Msg, Meta}
to the runner-side cth_error_report_sink using
[noconnect, nosuspend], so a slow or disconnected runner
neither blocks the logging caller (no process suspension on
a congested distribution buffer) nor triggers a synchronous
TCP handshake from inside logger:log.

Drops the multi-instance plumbing, the ETS owner process, and
all get_errors_*/clear/timestamp APIs -- the runner now owns
all state. The handler is idempotent against
logger:add_handler.

The previous design lost the MIM-node ETS on restart; with
state moved to the runner this is no longer possible.
Replaces per-node RPC fan-out with a single sink call per
section boundary. State carries one integer mark instead of
a per-node nodes/marks pair.

Sink lifecycle is tied to the hook (start/stop in init/2 and
terminate/1); per-suite watch/unwatch happens in
pre_init_per_suite / post_end_per_suite. The five RPC
fan-out helpers (start_collectors, try_start_collector,
stop_collectors, get_marks, collect_from_nodes) collapse
into one node_specs/0 helper that resolves the configured
node specs.

Module-level @doc updated to describe the new architecture.
Public API (expect/1, expect/2, max_unexpected_errors_logged/1)
is unchanged.
Adds a multi_node test group that triggers errors on mim2 and
verifies cross-node collection picks them up:

  errors_from_mim2_collected
  errors_from_multiple_nodes
  expect_pattern_covers_all_nodes

Plus errors_survive_handler_restart_on_mim2, which proves the
sinks central claim: entries collected before a handler restart
on mim2 remain in the runner-side sink, and entries logged
after re-injection are also picked up. Only the brief gap with
no handler attached loses entries.

The multi_node group skips automatically if mim2 is
unavailable.
Adds a Multi-node collection section describing the sink and
stateless handler design, including the [noconnect, nosuspend]
trade-off (best-effort silent drops over blocking the logger).

The previous design would have lost the entire suite history
on a MIM-node restart; under push-mode, only entries logged
during the brief boot window between restart and re-injection
are lost. The doc reflects this narrower limitation.
The sink no longer subscribes to net_kernel:monitor_nodes/1 and
no longer manages distribution-level concerns (cookie, connect_node)
when injecting the log_error_collector handler. Re-injection after
a node restart is the restart callers responsibility:
distributed_helper:start_node/2 now calls cth_error_report_sink:inject/1
after the node is back up, which is the documented contract.

This drops ~30 lines from the sink (the nodeup/nodedown handlers
and the cookie/connect_node setup in inject_async) and lets the
log-collection layer focus on collection rather than transparently
managing distribution.

Trade-off: an unplanned BEAM crash leaves the node without a
handler until the next planned start_node call (or an explicit
inject/1 by the test). For big_tests this is acceptable since
node restarts go through start_node/2.
The previous spawn-and-return pattern made inject/1 and
watch_nodes/2 return before the handler was actually attached.
A test that triggered an error on a just-restarted node
immediately after start_node/2 returned could lose that
error -- the spawned injector was still in flight.

Test setup is sequential and the cost of injecting 5 nodes
sequentially is negligible (a few hundred ms at most). Drop
the spawn and run injection inside the gen_server call so
inject/1 returning is a real guarantee that the handler is
attached or the failure has been logged. Same change for
removal during unwatch/0.

inject_async/remove_async renamed to do_inject/do_remove to
reflect the new contract.
The sink and the hook each defined an entry/0 type. The sinks
was a less-precise duplicate of the hooks log_entry/0 (Node,
Level, Msg, Meta tuple), and the hooks was a different shape
entirely (the per-section {section, Unexpected, Expected}
triple) -- two entry/0 types in two modules with very different
meanings, easy to confuse.

Make the sink the canonical owner of the storage shape: define
log_entry/0 there in terms of log_error_collector:level/0,
msg/0, and meta/0 (the producer module already exports these),
and export it. The hook now aliases to cth_error_report_sink:
log_entry/0 instead of redefining it.

The hooks remaining tuple type for per-section grouping is
renamed from entry/0 to report_entry/0 -- which is what it
actually is.

No behavioural change.
Replaces the EDoc-style %%% @doc / %% @doc comments in the three
new modules with OTP 27 -moduledoc and -doc attributes, matching
the convention now used throughout src/ (mod_caps, mongoose_websocket,
service_bosh, etc.). The new attributes integrate with shell_docs,
ex_doc, and language servers; the prior comments did not.

Also unifies doc style: previously some entries used the imperative
form (Declare, Stop, (Re-)inject, Add) and others used third person
(Returns, Drops). Standardised on third person throughout, matching
OTP standard library convention.

No behavioural change.
Replaces the lists:foldl that built #{Node => Spec} with a map
comprehension (OTP 26+ syntax). The do_inject side effect is moved
to a preceding lists:foreach so the comprehension stays a pure
value-producing expression, which is the idiom map comprehensions
were added to support.

No behavioural change.
@telezynski
telezynski force-pushed the collect-errors-from-all-nodes branch from 95a7ea4 to c19f7a7 Compare May 7, 2026 07:16
@telezynski
telezynski merged commit 038a26e into master May 7, 2026
4 checks passed
@telezynski
telezynski deleted the collect-errors-from-all-nodes branch May 7, 2026 09:57
@kamilwaz kamilwaz added this to the 6.7.0 milestone May 11, 2026
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.

4 participants