fix(mesh): PreStart resolve race logs honestly — quiet on heal, loud on permanent absence
PreStart's eager resolve of IMeshCommandDialer/IMeshPskProvider loses a
millisecond-wide race against the Akka builder's remaining starters on
essentially every admin boot (live gates: 1A 2/3 boots, 1B 4/4 boots) and
self-heals at the memoized Dialer/PskProvider properties' first use. Before
this change that produced two FALSE Errors per healthy boot, which made a
soak error-grep on a healthy rig impossible.
Resolve() now takes a `firstUse` flag and logs at Debug on BOTH call sites
(PreStart and the memoized properties' retry) — from inside Resolve a lost
race and a genuinely broken factory are indistinguishable, so severity is
decided by the CONSUMER of a still-null result after the retry, not by
Resolve itself:
- Dialer: DispatchOverGrpc's existing per-dispatch Error ("no command
dialer is wired") is unchanged and is now the ONLY loud signal for that
dependency.
- PskProvider: PublishKnownClusters gained a new Error carrying the old
PreStart guard's diagnostic content (gate never published, cached keys
never dropped, rotated key needs restart), guarded to fire ONCE per
actor incarnation via `_pskProviderAbsenceReported` — that handler runs
on the contact-refresh timer for the actor's whole life, so an
unguarded Error there would repeat every ContactRefreshSeconds forever.
Design choice for the "factory never supplied" case (Dps/ClusterClient test
constructions that pass no factories at all): kept silent at BOTH call
sites for both dependencies, same as before. For the dialer this was
already true (DispatchOverGrpc's check doesn't care why the dialer is
null). For the PSK provider the new once-guarded Error is gated on
`_pskProviderFactory is not null` specifically so the many existing
ClusterClient/Dps facts in CentralCommunicationActorTests that never wire a
PSK provider (using the bare Spawn helper) keep passing unmodified — a
never-supplied factory is a deliberate wiring/test choice, not a resolve
failure, and Resolve() already stayed silent about it for the same reason.
Two new tests pin the net behavior: a healthy boot (factories that throw
once then succeed) produces zero Warning/Error end-to-end through PreStart,
the first contact load and the first dispatch; a permanently-broken PSK
provider logs the absence exactly once across two contact loads, not once
per refresh.
Claude-Session: https://claude.ai/code/session_014WNM4vjoVksyyBraTXSZE1
This commit is contained in:
Joseph Doherty
+114
-2
@@ -820,13 +820,125 @@ public class CentralCommunicationActorTests : ControlPlaneActorTestBase
|
||||
dialer: null,
|
||||
pskProvider: null));
|
||||
|
||||
// Filtered on the DISPATCH message's exact phrase: PreStart logs its own error about the same
|
||||
// mis-wiring, and a looser filter races it into a second match.
|
||||
// A never-supplied factory (dialer: null here) is silent at PreStart and on every retry —
|
||||
// see Resolve's remarks — so this dispatch-time Error is the ONLY log line the mis-wiring
|
||||
// produces. That is what makes the plain "no command dialer is wired" phrase safe to match
|
||||
// without a second source racing it, unlike before this actor stopped double-reporting the
|
||||
// same absence at two severities.
|
||||
EventFilter.Error(contains: "no command dialer is wired").ExpectOne(
|
||||
TimeSpan.FromSeconds(5),
|
||||
() => actor.Tell(new MeshCommand(DeploymentsTopic, NewDispatch())));
|
||||
}
|
||||
|
||||
// ------------------------------------------------------------------ PreStart resolve-race logging
|
||||
//
|
||||
// PreStart's eager resolve of IMeshCommandDialer/IMeshPskProvider loses a millisecond-wide race
|
||||
// against the Akka builder's remaining starters on essentially every admin boot (live gates: 1A
|
||||
// 2/3 boots, 1B 4/4 boots) and self-heals at the memoized properties' first use. The two facts
|
||||
// below are the headline pin: a healthy boot must produce ZERO Warning/Error from this actor, and
|
||||
// a GENUINELY broken factory must still be reported loudly, exactly once.
|
||||
|
||||
[Fact]
|
||||
public void A_healthy_boot_produces_no_warning_or_error_even_though_PreStart_loses_the_resolve_race()
|
||||
{
|
||||
// Models the ordinary boot: both factories throw on their FIRST invocation (PreStart, which
|
||||
// loses the race) and succeed on every subsequent one (the memoized properties' first-use
|
||||
// retry, long after every starter has finished). This must be silent — no Warning, no Error
|
||||
// — from PreStart all the way through the first contact load and the first dispatch, or a
|
||||
// soak error-grep on a healthy rig is impossible.
|
||||
var factory = NewInMemoryDbFactory();
|
||||
SeedGrpcCluster(factory, "C1", ("host-a:4053", "host-a", 4056, true, false));
|
||||
var dialer = new RecordingDialer();
|
||||
var psk = new RecordingPskProvider();
|
||||
var dialerCalls = 0;
|
||||
var pskCalls = 0;
|
||||
|
||||
IMeshCommandDialer? DialerFactory()
|
||||
{
|
||||
dialerCalls++;
|
||||
return dialerCalls == 1 ? throw new InvalidOperationException("starter-ordering race") : dialer;
|
||||
}
|
||||
|
||||
IMeshPskProvider? PskFactory()
|
||||
{
|
||||
pskCalls++;
|
||||
return pskCalls == 1 ? throw new InvalidOperationException("starter-ordering race") : psk;
|
||||
}
|
||||
|
||||
IActorRef? actor = null;
|
||||
EventFilter.Warning().And.Error().Expect(0, TimeSpan.FromSeconds(5), () =>
|
||||
{
|
||||
actor = Sys.ActorOf(CentralCommunicationActor.Props(
|
||||
factory,
|
||||
GrpcMode(),
|
||||
new RecordingClientFactory(() => CreateTestProbe()),
|
||||
() => null,
|
||||
DialerFactory,
|
||||
PskFactory));
|
||||
|
||||
// First use of the PSK provider: the contact-refresh timer's initial (TimeSpan.Zero)
|
||||
// tick, observed via the gate publish.
|
||||
AwaitCondition(() => psk.KnownClusterPublications.Count >= 1, TimeSpan.FromSeconds(5));
|
||||
|
||||
// First use of the dialer: an ordinary dispatch, retried until the contact load (which
|
||||
// races this on the same timer tick) has adopted the gRPC target set.
|
||||
AwaitCondition(() =>
|
||||
{
|
||||
actor!.Tell(new MeshCommand(DeploymentsTopic, NewDispatch()));
|
||||
return dialer.Calls.Count >= 1;
|
||||
}, TimeSpan.FromSeconds(5));
|
||||
});
|
||||
|
||||
// Both retries actually happened — this fact is not vacuously true because the factories
|
||||
// never got a second chance to run.
|
||||
dialerCalls.ShouldBeGreaterThanOrEqualTo(2);
|
||||
pskCalls.ShouldBeGreaterThanOrEqualTo(2);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void A_permanently_unresolvable_pskProvider_is_reported_once_per_incarnation_not_once_per_refresh()
|
||||
{
|
||||
// The counterpart pin: a factory that NEVER succeeds is the genuinely permanent absence and
|
||||
// must still be loud — but PublishKnownClusters runs on the contact-refresh timer for the
|
||||
// actor's whole life, so an unguarded Error would repeat every ContactRefreshSeconds forever.
|
||||
// Guarded exactly like _warnedPortlessNodes: once per incarnation, not once per refresh.
|
||||
var factory = NewInMemoryDbFactory();
|
||||
SeedGrpcCluster(factory, "C1", ("host-a:4053", "host-a", 4056, true, false));
|
||||
var dialer = new RecordingDialer();
|
||||
|
||||
IActorRef actor = null!;
|
||||
EventFilter.Error(contains: "will NEVER be published").ExpectOne(TimeSpan.FromSeconds(5), () =>
|
||||
{
|
||||
actor = Sys.ActorOf(CentralCommunicationActor.Props(
|
||||
factory,
|
||||
GrpcMode(),
|
||||
new RecordingClientFactory(() => CreateTestProbe()),
|
||||
() => null,
|
||||
() => dialer,
|
||||
pskProvider: () => throw new InvalidOperationException("permanently broken")));
|
||||
|
||||
// Proof the FIRST contact load actually completed (the gRPC target set is adopted
|
||||
// before the gate publish this Error guards — see HandleContactsLoaded), rather than
|
||||
// relying on timing alone.
|
||||
AwaitCondition(() =>
|
||||
{
|
||||
actor.Tell(new MeshCommand(DeploymentsTopic, NewDispatch()));
|
||||
return dialer.Calls.Count >= 1;
|
||||
}, TimeSpan.FromSeconds(5));
|
||||
});
|
||||
|
||||
// A SECOND contact load must NOT repeat it.
|
||||
EventFilter.Error(contains: "will NEVER be published").Expect(0, TimeSpan.FromSeconds(5), () =>
|
||||
{
|
||||
actor.Tell(new CentralCommunicationActor.RefreshContacts());
|
||||
AwaitCondition(() =>
|
||||
{
|
||||
actor.Tell(new MeshCommand(DeploymentsTopic, NewDispatch()));
|
||||
return dialer.Calls.Count >= 2;
|
||||
}, TimeSpan.FromSeconds(5));
|
||||
});
|
||||
}
|
||||
|
||||
private static void SetGrpcPort(
|
||||
IDbContextFactory<OtOpcUaConfigDbContext> factory, string nodeId, int? grpcPort)
|
||||
{
|
||||
|
||||
Reference in New Issue
Block a user