Fix Data Explorer health scenarios reporting false unhealthy loads

ScenarioMonitor.completePhase() silently no-oped when the phase had not been
started yet, and the production call ordering always hits that case:

- DatabaseTreeRendered is started in Explorer.tsx after the last databaseTreeNodes
  change, but the effect that completes it only re-fires on such a change and
  databaseTreeNodes is memoised, so the phase never closed.
- Interactive is completed by a one-shot effect whose deps are stable, so it is
  lost entirely when ResourceTree mounts before refreshExplorer starts the
  scenario.

Over three days DatabaseTreeRendered was missing in 1624 of 1627 DatabaseLoad
timeouts (99.8%) and Interactive in 588, driving DataExplorerHealthV2 to report
loads as unhealthy that had in fact completed.

completePhase now self-starts a required phase that is completed before
startPhase, and completions reported before the scenario exists are buffered and
replayed on start(). A timeout while the tab is backgrounded no longer counts
against health either: browsers throttle timers and suspend rAF there, so phase
completion is unreliable and the elapsed time is not the user's experience.
documentHidden is still reported so those can be sliced out in telemetry.

Separately, configurePortal() resolved only from the iframe message handler with
no timeout. When the portal never posts the init message the promise stayed
pending forever, leaving the user on LoadingExplorer with no diagnostic while
ApplicationLoad timed out mute. It now rejects after 30s with a ConfigurePortal
failure trace, and the caller handles the rejection instead of leaving it
unhandled.

Related: IcM 865096261

src/Metrics/ScenarioMonitor.phaseOrdering.test.ts

@@ -0,0 +1,152 @@
+/**
+ * @jest-environment jsdom
+ *
+ * Regression tests for IcM 865096261 — DataExplorerHealthV2 "High Unhealthy Percentage".
+ *
+ * Before the fix, ScenarioMonitor.completePhase() silently no-oped when the phase had not
+ * been started yet. The production call ordering in Explorer.tsx / ResourceTree.tsx always
+ * hits that case:
+ *
+ *   - DatabaseTreeRendered is started at Explorer.tsx:451, but the effect that completes it
+ *     (useMetricPhases.ts:55-59) last fires on the databaseTreeNodes change that happens
+ *     *before* line 451. databaseTreeNodes is useMemo'd (ResourceTree.tsx:54), so the effect
+ *     never re-fires and the phase stayed open until the 10 s timeout.
+ *   - Interactive is completed by a one-shot effect (deps [scenario, enabled]) that can run
+ *     before Explorer.tsx:577 starts the scenario at all.
+ *
+ * Telemetry over 3 days: DatabaseTreeRendered missing in 1624 of 1627 DatabaseLoad timeouts
+ * (99.8%), Interactive missing in 588.
+ *
+ * Line references are against 1f04f0ae.
+ */
+
+import { updateUserContext } from "../UserContext";
+import MetricScenario, { reportMetric } from "./MetricEvents";
+import { ApplicationMetricPhase, CommonMetricPhase } from "./ScenarioConfig";
+import { scenarioMonitor } from "./ScenarioMonitor";
+
+jest.mock("./MetricEvents", () => ({
+  __esModule: true,
+  default: {
+    ApplicationLoad: "ApplicationLoad",
+    DatabaseLoad: "DatabaseLoad",
+  },
+  reportMetric: jest.fn().mockResolvedValue({ ok: true }),
+}));
+
+jest.mock("../ConfigContext", () => ({
+  configContext: {
+    platform: "Portal",
+    PORTAL_BACKEND_ENDPOINT: "https://test.portal.azure.com",
+  },
+  Platform: { Portal: "Portal", Hosted: "Hosted", Emulator: "Emulator", Fabric: "Fabric" },
+}));
+
+/** Stands in for the useDatabaseLoadScenario effect firing on a databaseTreeNodes change. */
+const treeRenderEffectFires = () =>
+  scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
+
+const lastEmit = () => (reportMetric as jest.Mock).mock.calls.at(-1)[0];
+
+const ALL_DATABASE_LOAD_PHASES = [
+  ApplicationMetricPhase.DatabasesFetched,
+  ApplicationMetricPhase.CollectionsLoaded,
+  ApplicationMetricPhase.DatabaseTreeRendered,
+  CommonMetricPhase.Interactive,
+];
+
+describe("DatabaseLoad phase ordering (IcM 865096261)", () => {
+  beforeEach(() => {
+    jest.clearAllMocks();
+    jest.useFakeTimers({ legacyFakeTimers: true });
+    updateUserContext({ apiType: "SQL" });
+    scenarioMonitor.reset();
+  });
+
+  afterEach(() => {
+    scenarioMonitor.reset();
+    jest.useRealTimers();
+  });
+
+  it("completes healthy under the production call ordering", () => {
+    // Explorer.tsx:577 — refreshExplorer starts the scenario
+    scenarioMonitor.start(MetricScenario.DatabaseLoad);
+
+    // Explorer.tsx:336 — databases fetched
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
+
+    // ResourceTree re-renders (databases arrived) -> effect fires before the phase exists.
+    treeRenderEffectFires();
+
+    // Explorer.tsx:430 — _loadCollections begins
+    scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
+
+    // Last databaseTreeNodes change; the memoised value never changes again after this.
+    treeRenderEffectFires();
+
+    // Explorer.tsx:449 / :451 — synchronous, immediately after `await Promise.all(...)`
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
+    scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
+
+    // useInteractive rAF / 1 s fallback
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
+
+    jest.advanceTimersByTime(10_000);
+
+    const emitted = lastEmit();
+    expect(emitted.scenario).toBe("DatabaseLoad");
+    expect(emitted.timedOut).toBe(false);
+    expect(emitted.healthy).toBe(true);
+    expect(emitted.completedPhases).toEqual(expect.arrayContaining(ALL_DATABASE_LOAD_PHASES));
+  });
+
+  it("honours a completion that arrives before the scenario is started", () => {
+    // ResourceTree mounts and its one-shot effects run before Explorer.tsx:577.
+    treeRenderEffectFires();
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
+
+    scenarioMonitor.start(MetricScenario.DatabaseLoad);
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
+    scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
+    scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
+
+    jest.advanceTimersByTime(10_000);
+
+    const emitted = lastEmit();
+    expect(emitted.timedOut).toBe(false);
+    expect(emitted.healthy).toBe(true);
+    expect(emitted.completedPhases).toEqual(expect.arrayContaining(ALL_DATABASE_LOAD_PHASES));
+  });
+
+  it("still reports unhealthy when a phase genuinely never completes", () => {
+    scenarioMonitor.start(MetricScenario.DatabaseLoad);
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
+    scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
+    // CollectionsLoaded and DatabaseTreeRendered never arrive — a real stall.
+
+    jest.advanceTimersByTime(10_000);
+
+    const emitted = lastEmit();
+    expect(emitted.timedOut).toBe(true);
+    expect(emitted.healthy).toBe(false);
+    expect(emitted.completedPhases).not.toContain(ApplicationMetricPhase.CollectionsLoaded);
+  });
+
+  it("does not count a timeout against health while the tab is backgrounded", () => {
+    const hidden = jest.spyOn(document, "hidden", "get").mockReturnValue(true);
+    try {
+      scenarioMonitor.start(MetricScenario.DatabaseLoad);
+      scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
+
+      jest.advanceTimersByTime(10_000);
+
+      const emitted = lastEmit();
+      expect(emitted.timedOut).toBe(true);
+      expect(emitted.documentHidden).toBe(true);
+      expect(emitted.healthy).toBe(true);
+    } finally {
+      hidden.mockRestore();
+    }
+  });
+});

src/Metrics/ScenarioMonitor.ts

@@ -27,6 +27,9 @@ interface InternalScenarioContext {
 
 class ScenarioMonitor {
   private contexts = new Map<MetricScenario, InternalScenarioContext>();
+  // Completions reported before start() created a context. Replayed on start() so that a
+  // React effect firing ahead of the scenario is not silently dropped.
+  private earlyCompletions = new Map<MetricScenario, Set<MetricPhase>>();
   private vitals: WebVitals = {};
   private vitalsInitialized = false;
 
@@ -127,11 +130,21 @@ class ScenarioMonitor {
         hasExpectedFailure: ctx.hasExpectedFailure,
       });
 
-      // If an expected failure occurred (auth, firewall, etc.), emit healthy instead of unhealthy
-      const healthy = ctx.hasExpectedFailure;
+      // Expected failures (auth, firewall, ...) are not our outage. Neither is a timeout in
+      // a backgrounded tab: browsers throttle timers and suspend rAF there, so phase
+      // completion is unreliable and the elapsed time is not the user's experience.
+      // documentHidden is still reported so these can be sliced out in telemetry.
+      const healthy = ctx.hasExpectedFailure || document.hidden;
       this.emit(ctx, healthy, true);
     }, config.timeoutMs);
     this.contexts.set(scenario, ctx);
+
+    // Replay completions that were reported before this scenario existed.
+    const early = this.earlyCompletions.get(scenario);
+    if (early) {
+      this.earlyCompletions.delete(scenario);
+      early.forEach((phase) => this.completePhase(scenario, phase));
+    }
   }
 
   startPhase(scenario: MetricScenario, phase: MetricPhase) {
@@ -185,11 +198,36 @@ class ScenarioMonitor {
 
   completePhase(scenario: MetricScenario, phase: MetricPhase) {
     const ctx = this.contexts.get(scenario);
-    const phaseCtx = ctx?.phases.get(phase);
-    if (!ctx || ctx.emitted || ctx.completed.has(phase) || !ctx.config.requiredPhases.includes(phase) || !phaseCtx) {
+
+    // The scenario has not been started yet. Remember the completion and replay it in
+    // start(); otherwise a one-shot React effect that fired early is lost forever.
+    if (!ctx) {
+      const config = scenarioConfigs[scenario];
+      if (config?.requiredPhases.includes(phase)) {
+        const pending = this.earlyCompletions.get(scenario) ?? new Set<MetricPhase>();
+        pending.add(phase);
+        this.earlyCompletions.set(scenario, pending);
+        this.devLog(`phase_complete_early: ${scenario}.${phase} — buffered until scenario start`);
+      }
       return;
     }
 
+    if (ctx.emitted || ctx.completed.has(phase) || !ctx.config.requiredPhases.includes(phase)) {
+      return;
+    }
+
+    // The phase is required but has not been started yet (deferred phases are started
+    // explicitly, and the caller may run before that happens). Self-start it now so the
+    // completion is honoured instead of silently dropped.
+    let phaseCtx = ctx.phases.get(phase);
+    if (!phaseCtx) {
+      const lateStartMarkName = `scenario_${scenario}_${phase}_start`;
+      performance.mark(lateStartMarkName);
+      phaseCtx = { startMarkName: lateStartMarkName };
+      ctx.phases.set(phase, phaseCtx);
+      this.devLog(`phase_autostart: ${scenario}.${phase} — completed before startPhase()`);
+    }
+
     const endMarkName = `scenario_${scenario}_${phase}_end`;
     performance.mark(endMarkName);
     phaseCtx.endMarkName = endMarkName;
@@ -446,6 +484,7 @@ class ScenarioMonitor {
       }
     });
     this.contexts.clear();
+    this.earlyCompletions.clear();
   }
 }
 

src/hooks/useKnockoutExplorer.ts

@@ -108,7 +108,14 @@ export function useKnockoutExplorer(platform: Platform): Explorer {
         scenarioMonitor.completePhase(MetricScenario.ApplicationLoad, ApplicationMetricPhase.ExplorerInitialized);
       }
     };
-    effect();
+    effect().catch((error) => {
+      // configurePortal now rejects instead of hanging forever, so this is reachable.
+      // Without a handler it would surface only as an unhandled rejection.
+      Logger.logError(
+        error instanceof Error ? error.message : String(error),
+        "useKnockoutExplorer/configure",
+      );
+    });
   }, [platform]);
 
   useEffect(() => {
@@ -705,6 +712,13 @@ export async function fetchAndUpdateKeys(subscriptionId: string, resourceGroup:
   }
 }
 
+// The portal configures Data Explorer with a single iframe message. If a dependency on the
+// portal side never resolves, that message is never posted — and without this timeout the
+// promise below stays pending forever, leaving the user on <LoadingExplorer /> with no
+// diagnostic while the ApplicationLoad health scenario times out mute (IcM 865096261).
+// Deliberately well above the 10s scenario budget so only genuinely stuck handshakes fail.
+const PORTAL_INIT_MESSAGE_TIMEOUT_MS = 30000;
+
 async function configurePortal(): Promise<Explorer> {
   const configureStartKey = traceStart(Action.ConfigurePortal, {
     dataExplorerArea: "ResourceTree",
@@ -714,7 +728,9 @@ async function configurePortal(): Promise<Explorer> {
   });
 
   let explorer: Explorer;
-  return new Promise((resolve) => {
+  let initMessageTimeoutId: number;
+
+  const explorerReady = new Promise<Explorer>((resolve) => {
     // In development mode, try to load the iframe message from session storage.
     // This allows webpack hot reload to function properly in the portal
     if (process.env.NODE_ENV === "development" && !window.location.search.includes("disablePortalInitCache")) {
@@ -849,6 +865,22 @@ async function configurePortal(): Promise<Explorer> {
 
     sendReadyMessage();
   });
+
+  const initMessageTimeout = new Promise<never>((_resolve, reject) => {
+    initMessageTimeoutId = window.setTimeout(() => {
+      const error = new Error(
+        `Portal did not send the Data Explorer init message within ${PORTAL_INIT_MESSAGE_TIMEOUT_MS}ms`,
+      );
+      traceFailure(Action.ConfigurePortal, { error: error.message }, configureStartKey);
+      reject(error);
+    }, PORTAL_INIT_MESSAGE_TIMEOUT_MS);
+  });
+
+  try {
+    return await Promise.race([explorerReady, initMessageTimeout]);
+  } finally {
+    window.clearTimeout(initMessageTimeoutId);
+  }
 }
 
 function shouldForwardMessage(message: PortalMessage, messageOrigin: string) {