Repository navigation
MIM-2681 Collect errors from all reachable MIM nodes - #4701
Conversation
This comment was marked as outdated.
This comment was marked as outdated.
Codecov Report✅ All modified and coverable lines are covered by tests. 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. 🚀 New features to boost your workflow:
|
chrzaszcz
left a comment
There was a problem hiding this comment.
Looks good in general. I added some comments.
e9f9696 to
3664242
Compare
|
The implementation was rewritten in new paradigm - errors after collection on nodes are immediately sent to central collector running on test node. |
chrzaszcz
left a comment
There was a problem hiding this comment.
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.
Good suggestion, implemented. |
chrzaszcz
left a comment
There was a problem hiding this comment.
Looks good 👌 - I just shared some cosmetic remarks - not mandatory to address.
| -spec node_specs() -> | ||
| [{atom(), distributed_helper:rpc_spec()}]. |
There was a problem hiding this comment.
Minor: could nicely fit in one line.
| -import(distributed_helper, [rpc/4, mim/0, mim2/0, | ||
| require_rpc_nodes/1]). |
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.
95a7ea4 to
c19f7a7
Compare
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_collectoron 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 errorsfor 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 OTPloggerhandler injected on each MIM node. On each error event, callserlang:send/3with[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 ininit/2/terminate/1and 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/2now callscth_error_report_sink:inject/1after the node is up. The sink does not subscribe tonodeupitself — log collection should notbe in the business of distribution-layer concerns.
Public API
cth_error_report:expect/1,2andmax_unexpected_errors_logged/1— unchanged.cth_error_report_sinkexportsstart_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 fromreg1@localhost/mongooseim2@localhost) andservice_domain_db_SUITE(81). The newerrors_survive_handler_restart_on_mim2testcase 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 notresume until something calls
cth_error_report_sink:inject/1explicitly. Documented indoc/developers-guide/Error-log-tracking.md.Files
big_tests/src/cth_error_report.erlbig_tests/src/cth_error_report_sink.erlbig_tests/tests/log_error_collector.erlbig_tests/tests/cth_error_report_SUITE.erlmulti_nodegroup + restart-resilience testtest/common/distributed_helper.erlstart_node/2re-injects the handler post-startdoc/developers-guide/Error-log-tracking.md