Skip to content

fix(#841): the ExecuteScript pre-flight refuses in silence — restore the operator's trace - #2991

Merged
github-actions[bot] merged 2 commits into
mainfrom
fix/841-preflight-refusal-trace
Sep 1, 2026
Merged

github-actions[bot] merged 2 commits into
mainfrom
fix/841-preflight-refusal-trace

Conversation

@rbuergi

@rbuergi rbuergi commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

What was broken

#841's contract has two halves, for two different people: the caller is told why a run was
refused, and the operator gets a Warning+ trace saying a run was asked for and never happened.
That is why CodeNodeType.HandleExecuteScript keeps ONE refusal sink (RefuseDispatch) that does
both in one place.

#2918's pre-flight moved two of that handler's three verdicts — no readable node and not a
runnable Code node
— into MeshOperations, where they are decidable from a single bounded read.
It carried the caller's half over and left the log line behind. So from that change onward the two
commonest refusals reproduced #841's reported picture exactly: a structured error for the
caller, and nothing at Warning or above in the pod.

Measured, not inferred — MeshWeaver.AI.Test.ExecuteScriptDispatchDiagnosticsTest.Dispatch_NonExecutableNode_SurfacesRefusalToCaller
red on Plugins main (run 33523800964, job 99911922886). The refusal itself works; the captured
Warning+ set contained three unrelated lines and not one from the refusal.

The fix

PreflightError writes the Warning before it serialises the envelope. It is the single funnel every
pre-flight refusal passes through, so a verdict added later to DescribeUnrunnableTarget cannot be
silent by omission — the same reason the hub keeps one sink instead of logging at each return.

ExecuteScript refused for Acme/Reports/Monthly (NotExecutable): Not executable:
'Acme/Reports/Monthly' has CodeConfiguration.IsExecutable = false. Set it to true on the
Code node to make it runnable. No Activity node was created.

The level is the hub-side sink's, for the hub-side sink's reason: an operation the caller asked for
and was denied is a Warning. Nothing the caller receives changed.

Why the regression merged green

ExecuteScriptPreflightTest's existing cases pin ELAPSED TIME and errorType. Neither can see a
missing log line. The new theory closes that: it asserts on the mesh's own ILoggerFactory — an
ILoggerProvider registered through MeshBuilder.ConfigureServices, so it measures what a
deployment's log sink receives, not test output — and it covers both pre-flight branches,
because they are two returns and a trace on one says nothing about the other.

Verification

  • dotnet build src/MeshWeaver.Mesh.Operations -c Release -warnaserror → 0 Error(s) 0 Warning(s);
    same for test/Memex.Portal.Shared.Test, src/MeshWeaver.Documentation,
    test/MeshWeaver.Documentation.Test.
  • Whole Memex.Portal.Shared.Test: Passed: 525, Failed: 0 (both new cases present in the trx).
  • Whole MeshWeaver.Documentation.Test (the ratchet guards + link integrity, for the What's New
    page): Passed: 166, Failed: 0.
  • Inverted once, seen red, restored. With the LogWarning removed both new cases fail on
    "Expected collection not to be empty because a refused dispatch must leave a Warning+ trace…"
    while the two elapsed-time cases stay green — so the new assertion measures the log line and only
    the log line.
  • Cross-repo: the whole MeshWeaver.AI.Test project (Plugins) built against this worktree
    (-p:MeshWeaverRoot=…) goes Failed: 2, Passed: 1663 → Failed: 0, Passed: 1665.
    (The second of those two was a stale content pin, fixed separately in Plugins.)

Filed, not patched here

#2990 — the boot-time content-type sweep builds a throwaway probe hub with
AsTransientNodeProbe(startDataSources: false); for an Activity-shaped NodeType that starts an
ActivityControlPlane watcher, ReduceLocalStream answers with a causeless
InvalidOperationException("Failed to create stream"), and because that is neither a
HubDisposingException nor a routing NotFound the watcher classifies routine probe teardown as a
transient fault — an ERROR line plus a re-establish timer, at every portal boot. Surfaced in this
test's captured-log dump; it is a design question about the probe, not a line to patch inside an
unrelated change.

Relates to #841, #2918.

…the operator's trace

#841 has two halves, and they are for two different people: the CALLER is told why a
run was refused, and the OPERATOR gets a Warning+ trace saying a run was asked for and
never happened. That is why `CodeNodeType.HandleExecuteScript` keeps ONE refusal sink
(`RefuseDispatch`) that does both things in one place, and why every test in the
engine's dispatch-diagnostics suite asserts the trace as well as the verdict.

#2918's pre-flight moved two of those three verdicts — "no readable node" and "not a
runnable Code node" — off the owning hub and into `MeshOperations`, where they are
decidable from one bounded read. It carried the caller's half over and left the log
line behind. From that change onward the two COMMONEST refusals reproduced #841's
reported picture exactly: the caller gets a structured error, and the pod emits
nothing at Warning or above. Measured on Plugins' `MeshWeaver.AI.Test`:
`Dispatch_NonExecutableNode_SurfacesRefusalToCaller` red with

    Captured: [Warning HostedHubsCollection: Rejecting hosted hub creation … |
               Warning HostedHubsCollection: … | Error KernelContainer: … ]

— three unrelated lines and not one from the refusal itself.

`PreflightError` now writes the Warning before it serialises the envelope. It is the
one funnel every pre-flight refusal passes through, so a verdict added later to
`DescribeUnrunnableTarget` cannot be silent by omission — the same reason the hub keeps
one sink rather than logging at each `return`. The level is the hub-side sink's, for
the hub-side sink's reason: an operation the caller asked for and was denied is a
Warning. Nothing the caller receives changed.

`ExecuteScriptPreflightTest` gains the missing measurement. Its existing cases pin
ELAPSED TIME and the errorType — neither can see a missing log line, which is how the
regression merged green. The new theory asserts on the mesh's own `ILoggerFactory`
(an `ILoggerProvider` registered through `MeshBuilder.ConfigureServices`, so it
measures what a deployment's sink receives) and covers BOTH pre-flight branches,
because they are two `return`s and a trace on one says nothing about the other.

Proven able to fail: with the `LogWarning` removed, both cases red on
"Expected collection not to be empty …" and the other two stay green; restored, the
whole project passes 525/525.

Found while reading the captured log, filed rather than patched here: #2990 — the
boot-time content-type sweep's throwaway probe hub starts an ActivityControlPlane
watcher, `ReduceLocalStream` answers with a causeless
`InvalidOperationException("Failed to create stream")`, and because that is neither a
`HubDisposingException` nor a routing NotFound the watcher classifies routine probe
teardown as a transient fault: an ERROR line and a re-establish timer, at every boot.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Copilot AI lite review requested due to automatic review settings September 1, 2026 16:09
@github-actions
github-actions Bot enabled auto-merge September 1, 2026 16:09

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Pull request overview

Restores operator-visible diagnostics for ExecuteScript pre-flight refusals by emitting a Warning log entry from the shared preflight refusal funnel, and pins the behavior with an integration test plus a What’s New entry.

Changes:

  • Add a LogWarning in MeshOperations.PreflightError(...) so NodeNotFound / NotExecutable refusals leave an operator-visible trace.
  • Extend ExecuteScriptPreflightTest to capture mesh logs via an ILoggerProvider and assert the Warning+ refusal trace is present for both preflight branches.
  • Add a What’s New page documenting the restored operator trace for refused runs.

Reviewed changes

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

File Description
test/Memex.Portal.Shared.Test/ExecuteScriptPreflightTest.cs Adds a log-capturing provider and assertions ensuring preflight refusals are visible to operators (Warning+), not only to callers.
src/MeshWeaver.Mesh.Operations/MeshOperations.cs Logs a Warning when ExecuteScript refuses during preflight (before dispatch), restoring operator observability.
src/MeshWeaver.Documentation/Data/WhatsNew/2026-09-01-a-refused-script-run-is-visible-to-operators-again.md Documents the fix and the expected operator-visible log line.

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

Comment thread test/Memex.Portal.Shared.Test/ExecuteScriptPreflightTest.cs
Copilot review: the summary claimed 'every record the mesh emits' while IsEnabled
gates at Debug. Corrected rather than widened — the assertion is about Warning+, the
factory's own filter rules apply before the provider is reached anyway, and Trace
chatter would only bury the failure dump the assertion prints.

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

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results (shard 0)

216 tests   216 ✅  2m 44s ⏱️
  1 suites    0 💤
  1 files      0 ❌

Results for commit 7fe4c55.

@github-actions

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results (shard 3)

586 tests   586 ✅  47s ⏱️
  2 suites    0 💤
  2 files      0 ❌

Results for commit 7fe4c55.

@github-actions

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results (shard 5)

    3 files      3 suites   1m 11s ⏱️
1 196 tests 1 004 ✅ 192 💤 0 ❌
1 197 runs  1 005 ✅ 192 💤 0 ❌

Results for commit 7fe4c55.

@github-actions

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results (shard 1)

419 tests   419 ✅  1m 22s ⏱️
  1 suites    0 💤
  1 files      0 ❌

Results for commit 7fe4c55.

@github-actions

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results (shard 2)

529 tests   527 ✅  1m 29s ⏱️
  4 suites    2 💤
  4 files      0 ❌

Results for commit 7fe4c55.

@github-actions

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results (shard 4)

1 668 tests   1 668 ✅  1m 47s ⏱️
    3 suites      0 💤
    3 files        0 ❌

Results for commit 7fe4c55.

@github-actions

github-actions Bot commented Sep 1, 2026

Copy link
Copy Markdown
Contributor

Test Results

   14 files     14 suites   9m 22s ⏱️
4 614 tests 4 420 ✅ 194 💤 0 ❌
4 615 runs  4 421 ✅ 194 💤 0 ❌

Results for commit 7fe4c55.

@github-actions
github-actions Bot merged commit 667c42c into main Sep 1, 2026
26 checks passed
@rbuergi
rbuergi deleted the fix/841-preflight-refusal-trace branch September 13, 2026 10:34
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.

2 participants