Skip to content

EaGraphAuth.LoadAsync renders every failure as 'this user never connected' — a swallowed 10s timeout tells a connected user to re-consent, and there is no token cache so the timeout is the expected outcome #3433

Closed

Description

@rbuergi

The defect

memex/Memex.Portal.Shared/Authentication/EaGraphAuth.cs, LoadAsync:

// line ~198, INSIDE the try
    .Take(1).Timeout(TimeSpan.FromSeconds(10)).FirstAsync()
...
// line ~212
catch (Exception ex)
{
    ...
    return (null, null);
}

(null, null) is the same value this method returns when a user genuinely has no stored
credential. So every failure mode — the 10-second timeout on its own node read, a transport fault, a
deserialization problem — is rendered to the caller as "this user has never connected their
mailbox."
GetAccessTokenAsync then answers null, and the Executive Assistant shows the
re-consent link.

There is a second one at line ~223: a bare catch { return null; }.

A user who IS connected is told to connect again. Pressing that link re-consents something that was
never revoked, so it "works", which is why this has survived: the failure looks like a successful
recovery from a state that never existed.

Why the timeout fires — the second half

There is no token cache at all. Every EA tool call:

  1. reads the credential node,
  2. redeems the refresh token,
  3. on rotation — i.e. essentially always — writes that same node.

A single agent round issuing ~20 parallel SearchMail calls therefore puts ~20 writes and ~20 reads
on ONE single-threaded node hub. The 10-second read timeout is not a remote possibility under that
load; it is the expected outcome. In the 2026-09-06 incident the credential write at 12:29:49.375
was one of them, 372 ms after the round went silent.

So the two halves compound: contention makes the read time out, and the swallow turns the timeout
into a lie about the user's connection state.

What was excluded (so nobody re-derives it)

Not excluded: Entra answering non-2xx. One named query distinguishes it —
{app="memex-portal"} |= "EaGraphAuth" over 12:29:40–12:33:00Z. The Hosting/LogEntry window on
that mesh held nothing matching, so it could not be retrieved at the time. 🚨 Note when running it
that Loki's since= is NOT a start bound here (it has been measured capped at ~1 h and returning a
false zero) — use explicit start/end plus an oldest-line control.

The fix has two parts, and the second needs review

  1. Distinguish absent from failed. A modelled result — not (null, null) for both. "I could not
    determine your connection state" must not render as "you are not connected"; a fail-closed
    fallback that forges a correct-looking answer is the actual bug. The bare catch { return null; }
    at ~223 goes the same way.
  2. Cache the delegated access token. This is the part that deserves its own review rather than a
    rushed commit: it is a per-user cache of delegated access tokens held on a singleton, which is
    security-relevant. It must be an instance field on a mesh-scoped singleton, never static, and
    the concurrency bound goes through IIoPool — never a SemaphoreSlim, and never a bare
    ConcurrentDictionary<key, IObservable<T>> (a ReplaySubject latches OnError and replays one
    transient fault forever, A transient fault poisons a promise-cache entry for the life of the process — one blip and a partition can never be provisioned again #1369).

🚨 Do NOT "fix" this by widening the 10-second timeout. The read is contending with writes the same
round generates; a larger bound moves the failure, it does not remove it.

Regression test

The existing FakeEaGraphAuth harness is what a test would use: count acquisitions, fire N
concurrent calls, assert 1. Reverted, it gives N. For part 1 the test is that an INDUCED read
failure produces a state distinguishable from "not connected" — falsify it by reverting and
confirming the two collapse to the same value.

Provenance

Found while investigating MeshWeaver.Plugins#1398 (EA round faults at a token refresh). That issue
stays open in the Plugins repo for the half that is still unexplained — what re-drove the round, and
why the thread node never left Executing. The visible stall guards (StreamStallGuardChatClient,
ThreadExecution.cs:3098) ABORT and ask a human, so it was something else.

Investigation comment:
https://github.com/Systemorph/MeshWeaver.Plugins/issues/1398#issuecomment-5560355098
Doc page: Mail/ExecutiveAssistantCredentialReads.md (MeshWeaver.Plugins#1407)

One duplicate-effect finding worth keeping

A re-executed round cannot send a second mail under the default: Email:AgentSend=DraftOnly
keeps SendMail/ReplyToMail out of CreateTools() entirely, so the model never receives them. On
an explicit =Send deployment it could — there is no idempotency key. It can leave a second
draft
: DraftMail is a plain POST /me/messages with no dedupe, and a re-executed round starts
with an empty tool-call list, so the GetDraft/UpdateDraft amend path (#1049) cannot see the
first one. The 2026-09-06 round was read-only, so nothing was duplicated; a drafting round would
have been.

Activity

  1. rbuergi commented on Sep 6, 2026

    @rbuergi
    ContributorAuthor

    Two corrections to the filing, both in the direction of claiming less — plus one addition.

    1. The Loki caveat: your general rule is right, and I have no measurement to put beside it

    I did not run a Loki query for this. Please keep the rule as you wrote it (explicit start/end plus an oldest-line control; since= is capped in practice at about an hour and has returned a false zero for a window it silently never reached) — it is not competing with a measurement of mine, because there isn't one.

    🚨 And one nearby zero must not be promoted into evidence. What I actually ran was a mesh query against the Hosting/LogEntry mirror:

    namespace:Hosting scope:descendants nodeType:LogEntry EaGraphAuth   →   count: 0
    

    That is not evidence the log line is absent. That mirror is populated by the Hosting module's ingest-logs script over a bounded window rather than by a live tail, so the zero carries no denominator and says nothing about which window it covered. (An earlier unanchored attempt was refused outright by the planner — "no partition could be determined" — so it is not even a consistent series.) If my earlier comment on Plugins#1398 read as "I looked and it wasn't there", that was my wording; the honest statement is "not looked at yet". {app="memex-portal"} |= "EaGraphAuth", 2026-09-06 12:29:40Z–12:33:00Z is still the query that settles which of the two branches fired, and it is still unrun.

    2. The second catch { return null; } — you were right, and it is worse than you said in one way and narrower in another

    That is Safe(…), at the bottom of the file, with exactly one caller: the JsonElement arm of the node?.Content switch inside LoadAsync. So it is reached only when the node exists and its content arrived untyped.

    Same class, confirmed. A deserialization failure becomes null, the caller folds it into cred, and GetAccessTokenAsync reads cred?.RefreshTokenEncrypted as empty ⇒ the re-consent link. I checked the call sites rather than assuming: nowhere in this file — GetAccessTokenAsync, IsConnectedAsync, StoreAsync — does anything distinguish "no credential" from "unreadable credential". So null is not a modelled answer there. Your assertion stands.

    Worse in one way. Unlike LoadAsync's catch, Safe's is bare — catch { return null; }, no exception variable, no log. If it ever fires there is no Warning, no metric, nothing to grep. Per occurrence it is the least diagnosable of the three.

    Narrower in another, and this is the correction that matters for triage. It is deterministic: the same stored bytes with the same JsonSerializerOptions fail identically every time. It therefore cannot produce the 2026-09-06 signature — worked → failed for ~5 minutes → worked again with no user action. It would present as permanently not-connected for one user. So it is a real defect of the same class, but it is excluded as the cause of the incident this issue was filed from, and fixing it alone would change nothing about that incident.

    3. Addition: there is a third instance in the same expression, and it is not a catch

    var cred = node?.Content switch
    {
        EaCredential e => e,
        JsonElement je => Safe(je, hub.JsonSerializerOptions),
        _              => null          // ← third instance
    };

    A content shape that is neither — the as-written JsonObject DOM, or a same-named type from another collectible assembly — silently yields cred = null and the same re-consent link. A fix that repairs both catches and leaves this arm still tells a connected user they never connected.

    It also has a root cause rather than needing a guard: the switch hand-rolls a shape test, which is the pattern the house rule exists against. node.ContentAs<EaCredential>(hub.JsonSerializerOptions) (or the shape-tolerant NodeElement.Of(node)) removes the arm instead of papering over it, and folds #2 into the same call.

    Summary for whoever picks this up — three sites, one method, and only the first is transient:

    # Site Fires when Evidence left Explains 2026-09-06?
    1 catch (Exception ex) { … return (null, null); } any read fault, the 10 s .Timeout included a Warning naming the user yes
    2 Safe(…) → catch { return null; } content is JsonElement and does not deserialize none no — deterministic
    3 _ => null in the content switch content is neither shape none no — deterministic

    None of this changes the fix's shape or the reason it is unassigned: the token-cache half is a per-user cache of delegated access tokens on a singleton and wants its own review.

    The committed reading is Mail/ExecutiveAssistantCredentialReads.md in Systemorph/MeshWeaver.Plugins (PR #1407), now carrying all three sites and both corrections above, and naming this issue as the core half.

    🤖 Filed from Claude Code.

  2. rbuergi commented on Sep 6, 2026

    @rbuergi
    ContributorAuthor

    No async! 100% reactive! see async skill

  3. rbuergi commented on Sep 6, 2026

    @rbuergi
    ContributorAuthor

    🚨 Correcting this issue's root cause — the maintainer is right, and I had it backwards

    I filed this as "a blanket catch + no token cache, so contention makes the 10 s read time out." That
    ordering is wrong. The root cause is async/await/Task<T> in hub-reachable code. Contention
    is not needed to explain the failure at all.

    The actual chain

    EaGraphAuth is async end to end:

     70:  public  async Task<bool>    ExchangeAndStoreAsync(...)
     91:  public  async Task<string?> GetAccessTokenAsync(...)
    115:  public  async Task<bool>    IsConnectedAsync(...)   => (await LoadAsync(...))
    118:  private async Task<string?> PostTokenAsync(...)
    147:  private async Task          StoreAsync(...)
    177:  private Task<(MeshNode?, EaCredential?)> LoadAsync(...)
    180:  private async Task<(MeshNode?, EaCredential?)> LoadAsync(...)
    197:      node = await ws.GetMeshNodeStream(PathFor(userObjectId))   // ← awaiting a mesh stream
    198:                 .Take(1).Timeout(TimeSpan.FromSeconds(10)).FirstAsync()
    

    Line 197 awaits a mesh node stream. Called from a hub turn, that continuation runs on the wrong
    scheduler and parks the single-threaded action block — so the response to the very read being
    awaited can never be processed.
    The .Timeout(10s) then fires, and the blanket catch at ~212
    converts the timeout into (null, null), which is the same value as "this user never connected".

    So the correct ordering is:

    1. async/await in hub-reachable code → deadlock. The read cannot complete.
    2. The 10 s .Timeout fires — a consequence, not an independent contention effect.
    3. The blanket catch returns (null, null).
    4. The user, who IS connected, is shown the re-consent link.

    The async is the ROOT. The swallow is what makes it invisible. My "~20 parallel calls contend on
    one single-threaded node hub" framing was a plausible-sounding second mechanism that is not required
    to produce the observed failure
    — and stating it first pointed the fix at a token cache when the
    fix is to stop being async.

    Why this class is the trap: TWO callers, incompatible threading contracts

    caller context async Task there is
    EaConsentController (memex/Memex.Portal.Shared/Authentication/) HTTP/OAuth boundary — a minimal-API/controller handler sanctioned
    ExecutiveAssistantPlugin (MeshWeaver.Plugins, src/MeshWeaver.Mail.MicrosoftGraph/) — agent TOOLS inside an agent round, on a hub forbidden, and deadlocks

    The class's own doc comment at line 24 says it "sits at the OAuth/HTTP boundary (called from the
    consent controller and the async EA tool)" — the second half of that sentence is the bug, written
    down as if it were a design note.

    The fix

    IEaGraphAuth's hub-facing surface returns IObservable<T>, not Task<T>; the mesh read composes
    with .Select/.SelectMany/.Timeout and .Subscribe(onNext, onError), never await. Every
    async/blocking/IO edge (the Entra token POST) goes through IIoPool — pool.Invoke /
    InvokeBlocking / InvokeStream, resolved from the mesh-scoped IoPoolRegistry. The HTTP
    controller can keep its Task shape at its own boundary; what it must not do is force the hub-facing
    path to be Task-shaped.

    The failure-vs-absent distinction still has to be fixed — it is what made this survive undiagnosed —
    but it is now the SECOND fix, not the first. And per the investigation on Plugins#1398 there are
    three sites that collapse to the re-consent link, not two:

    1. catch (Exception ex) { … return (null, null); } (~212)
    2. Safe(…)'s bare catch { return null; } (~223) — no exception variable, no log at all;
      deterministic, so it cannot produce the observed transient and is excluded as the incident cause
    3. the _ => null arm of the same node?.Content switch — not a catch; a hand-rolled shape test
      that node.ContentAs<EaCredential>(hub.JsonSerializerOptions) removes outright

    A fix touching only the two catches leaves (3) live.

    🚨 The guard gap — why "again"

    No guard catches this shape.

    • ObservableToTaskBridgeGuard — ProductionRoots = ["src","tools","samples","clients","memex"], so
      the ROOT is covered, but it detects .ToTask() bridges.
    • ProductionBlockingBridgeSites / BlockingBridgeSites — .Result / .Wait().
    • HubDisposalJoinRatchetGuard — ScannedRoots = ["src","test","tools"], a different subject.

    Nothing bans an async Task<T> method that awaits a mesh stream in hub-reachable code. The
    AGENTS.md rule is absolute and stated three ways, but it is enforced only against the specific
    bridging idioms, not against the plain shape. That is why this landed without a red, and it is why
    the maintainer's word was "again".

    Closing that gap is part of this issue. The hard part is honest and should be stated rather than
    designed around: "hub-reachable" is not a syntactic property, and a guard that simply banned
    async under memex/ would red the consent controller, which is legitimate. Candidate
    discriminators worth evaluating — none free:

    • a method that awaits GetMeshNodeStream / IMeshService / any workspace read, in ANY root, is
      hub-reachable by construction — this is narrow, syntactic, and would have caught line 197
    • a type registered as a hub service or resolved from hub.ServiceProvider
    • a type implementing a contract consumed by an IAgentPlugin tool

    🚨 Whatever is chosen must have no skip-trapdoor, must not test its own inputs, and must be
    falsified by watching it RED on a reintroduced line 197 — a guard nobody has watched fail is not a
    guard.

    What stays true from the original filing

    The measured evidence, the exclusions (#1369 latch impossible with no cache; client_secret means
    no single-use refresh token; credential present at 12:35), and the duplicate-effect finding (a
    re-executed round cannot send a second mail under DraftOnly, but CAN leave a second draft — that
    half belongs to Plugins#1398 and survives this fix). The Loki query named earlier remains unrun —
    it was never executed, and the Hosting/LogEntry mesh zero must not be quoted as evidence for it.

  4. rbuergi commented on Sep 6, 2026

    @rbuergi
    ContributorAuthor

    Core half is up: #3446

    The correction in this thread is confirmed by measurement, not just by reading. The async is the root, and I reproduced the mechanism against a real monolith mesh rather than arguing it:

    MessageService.DrainOne subscribes to one turn at a time and does not dequeue the next until the current one terminates — the drain is re-scheduled from that turn's terminal callback and nowhere else. So a caller that cannot finish until a cross-hub read finishes holds the very queue that read's reply must travel through.

    EaCredentialReadTest.AwaitingTheCredentialReadInsideAHubTurn_NeverCompletes seeds a credential node, reads it from such a turn, and asserts a TimeoutException on a node that is demonstrably present. Its sibling issues the same read, same turn, same node, by subscribing instead — and gets Connected. That pairing is what makes it a statement about await rather than about the mesh being slow.

    One thing worth adding to the record: the hub's own handler surface was already immune. SyncDelivery and AsyncDelivery both return IObservable<IMessageDelivery>, so an async handler does not compile. What IEaGraphAuth's Task<T> did was reopen the door from the other side — a Task<T> has exactly one consumption idiom, so the agent-tool caller had no choice.

    All three sites, as you catalogued them

    Fixed, and site 3 by removal rather than by handling: node.ContentAs<EaCredential>(hub.JsonSerializerOptions, logger) deletes the hand-rolled switch, so there is no arm left to have. That folds site 2 (Safe's bare catch) into the same call. The answer is modelled — EaConnection.{NotConnected, Connected, Undetermined}, and Undetermined always carries a diagnostic, because an undetermined state with nothing to say is indistinguishable from the swallow it replaces.

    Your triage table held up: only site 1 is transient, and it is the one the 2026-09-06 signature needs.

    Falsified both ways, both directions reported

    • The guard, with the defective line replanted: Passed: 3 / Failed: 2, naming each planted file. Probes removed: 5/5.
    • The absent-vs-failed collapse, with src/ reverted to the pre-fix classification and the tests unchanged: Passed: 5 / Failed: 1 — "Expected Undetermined … but found NotConnected". Restored: 6/6.

    On the two open evidence questions

    • 🚨 The live-mesh caller sweep FAILED and I am not reporting it as clean. search_chunks answered "searched": false on both deployments reachable from here (memex and systemorph) — content indexing is inactive on both, so nothing was searched. What limits the risk instead: the core PR removes nothing from src/ and nothing from IEaGraphAuth.
    • The Loki query is still unrun. {app="memex-portal"} |= "EaGraphAuth", 2026-09-06 12:29:40–12:33:00Z. It distinguishes "Entra refused" from "the read never completed" for that specific incident. The fix does not depend on it — both branches are now modelled and both are logged — but it is the one thing that would name which branch fired, and it stays open.

    Why this issue stays open

    The core PR adds the reactive surface and removes nothing: ExchangeAndStoreAsync / GetAccessTokenAsync / IsConnectedAsync remain as default-implemented forwarders. That is deliberate and the ordering is inverted from the usual deleting-half-last, because the dependency runs the wrong way — MeshWeaver.Plugins compiles -warnaserror against a core checkout at a pinned ref, so a core PR deleting them cannot land before the Plugins PR that stops calling them, and that Plugins PR cannot compile before the reactive surface exists. No [Obsolete], for the same reason: it would red the dependent's main the moment core merged. The deprecation lives in test/TaskShapedMeshSeams.allow, where a shrink-only ratchet is what actually removes them.

    So: #3446 → the MeshWeaver.Plugins migration (ExecutiveAssistantPlugin, GraphEmailSender) → a small core PR deleting the forwarders. The deadlock is only actually gone at the call sites after the second of those.

    Design committed as Doc/Architecture/ExecutiveAssistantCredentialReads, plus a Category: Fix What's New entry.

    🤖 Filed from Claude Code.

  5. rbuergi commented on Sep 6, 2026

    @rbuergi
    ContributorAuthor

    Closed by hand: neither repo's merge queue fires Closes links, and #1416 carried a
    Pairs-with: line rather than a closing keyword, so nothing was going to close this automatically.

    Both halves are on their default branches

    half PR merge commit verified
    core — the seam becomes IObservable, and a failed read is a third state #3446 6cddde50f78ce0edb57bbf353e842253ee5755c3 ancestor of origin/main (merge-base --is-ancestor)
    Plugins — the EA tools tell the three states apart Systemorph/MeshWeaver.Plugins#1416 1e73a048bfc96565809f9242b7f4c84a3e6d2259 ancestor of origin/main (merge-base --is-ancestor)

    Why this is complete, including the clause in the title

    The title names two things — the swallowed failure and "there is no token cache so the timeout
    is the expected outcome"
    . The second was retracted in this thread by the filer
    (comment):

    The root cause is async/await/Task<T> in hub-reachable code. Contention is not needed to
    explain the failure at all. […] My "~20 parallel calls contend on one single-threaded node hub"
    framing was a plausible-sounding second mechanism that is not required to produce the observed
    failure — and stating it first pointed the fix at a token cache when the fix is to stop being
    async
    .

    So the two fixes this issue actually asks for are the two that shipped:

    1. Stop being async. EaGraphAuth's entry points are now cold IObservable<T>
      (GetAccessToken, GetConnection, ExchangeAndStore, Store, Load), the Entra token POST
      goes through IIoPool, and nothing awaits the mesh read from a hub turn. Confirmed by reading
      the file at the current pin: there is deliberately no per-user token cache, per the comment
      above.
    2. Stop reporting a fault as an answer. EaGraphAccess models three states, and
      Undetermined no longer renders as the consent link. All three swallow sites named in this
      thread are gone — the blanket catch, the bare catch in Safe(...), and the _ => null arm
      of the content switch (removed at the root by using the house accessor rather than a hand-rolled
      shape test).

    The Plugins half proves the distinction where a user sees it: ExecutiveAssistantConnectionStateTests
    asserts that an undetermined read is never rendered as "connect your mailbox", that a genuine
    NotConnected still offers the consent link, and that every mailbox tool separates the two —
    falsified by collapsing the states, which is the arm that must go red.

    What is deliberately NOT closed by this

    Architecture page: Doc/Architecture/ExecutiveAssistantCredentialReads, landed with #3446.

    🤖 Filed from Claude Code.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions