mirror of
https://github.com/Azure/cosmos-explorer.git
synced 2026-09-19 09:02:41 +01:00
Address review: do not trade false-unhealthy for false-healthy
The previous revision removed the missing-phase signatures, but three of those changes could report a load as healthy without establishing that it finished, and one could prevent a slow initialization from recovering. Preserve late initialization recovery. configurePortal() raced the iframe handshake against a 30s reject while leaving the message listener active, so a late init message would build an Explorer that the rejected caller never received — turning a slow load into an unrecoverable one. The timeout is now a watchdog that traces the stuck handshake and lets the caller keep waiting, so recovery behaves as it did before. Initialization work inside the message handler is wrapped so a throw reports and still yields a shell, instead of leaving the promise pending forever. Do not accept an earlier render as proof the loaded tree is ready. Phase auto-start let a render of the databases-only tree complete DatabaseTreeRendered with a zero-duration measurement, before collections had loaded. The producer ordering is fixed instead: Explorer publishes a ready revision once the load has produced the data the tree should show, and ResourceTree completes the phase only for a render carrying that revision, acknowledging each revision once. Stale callbacks from a superseded load, accounts with no databases and unchanged trees are covered by tests. A completion for a phase that was never opened is now refused and reported as phase_complete_unstarted rather than backdated, and the early-completion buffer no longer accepts deferred phases, which must be opened by their producer. Do not turn unfinished background loads into successes. A timeout in a hidden tab emitted healthy=true even with no phases completed. The emitted outcome again reflects what actually happened; documentHidden continues to be reported so alerting can apply a background policy without the load being relabelled. Related: IcM 865096261
This commit is contained in:
@@ -447,8 +447,12 @@ export default class Explorer {
|
|||||||
startKey,
|
startKey,
|
||||||
);
|
);
|
||||||
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
||||||
// Start DatabaseTreeRendered — React render cycle will complete it in ResourceTree
|
// Start DatabaseTreeRendered before publishing the revision that triggers the render,
|
||||||
|
// so the phase is always open by the time ResourceTree acknowledges it. Bumping the
|
||||||
|
// revision is what tells the tree "this is the data the current load is expected to
|
||||||
|
// show"; the phase is completed only for a render carrying that revision.
|
||||||
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
useDatabases.setState({ treeReadyRevision: useDatabases.getState().treeReadyRevision + 1 });
|
||||||
} catch (error) {
|
} catch (error) {
|
||||||
TelemetryProcessor.traceFailure(
|
TelemetryProcessor.traceFailure(
|
||||||
Action.LoadCollections,
|
Action.LoadCollections,
|
||||||
|
|||||||
@@ -13,6 +13,11 @@ interface DatabasesState {
|
|||||||
resourceTokenCollection: ViewModels.CollectionBase;
|
resourceTokenCollection: ViewModels.CollectionBase;
|
||||||
sampleDataResourceTokenCollection: ViewModels.CollectionBase;
|
sampleDataResourceTokenCollection: ViewModels.CollectionBase;
|
||||||
databasesFetchedSuccessfully: boolean; // Track if last database fetch was successful
|
databasesFetchedSuccessfully: boolean; // Track if last database fetch was successful
|
||||||
|
// Incremented once a load has produced the data the resource tree is expected to show.
|
||||||
|
// The DatabaseTreeRendered phase is only completed for a render that carries the current
|
||||||
|
// revision, so an earlier render (databases fetched, collections still loading) cannot be
|
||||||
|
// mistaken for the loaded tree. 0 means no load has reached that point yet.
|
||||||
|
treeReadyRevision: number;
|
||||||
searchText: string;
|
searchText: string;
|
||||||
sortOrder: DatabaseSortOrder;
|
sortOrder: DatabaseSortOrder;
|
||||||
pinnedDatabaseIds: Set<string>;
|
pinnedDatabaseIds: Set<string>;
|
||||||
@@ -52,6 +57,7 @@ export const useDatabases: UseStore<DatabasesState> = create((set, get) => ({
|
|||||||
resourceTokenCollection: undefined,
|
resourceTokenCollection: undefined,
|
||||||
sampleDataResourceTokenCollection: undefined,
|
sampleDataResourceTokenCollection: undefined,
|
||||||
databasesFetchedSuccessfully: false,
|
databasesFetchedSuccessfully: false,
|
||||||
|
treeReadyRevision: 0,
|
||||||
searchText: "",
|
searchText: "",
|
||||||
sortOrder: loadSortOrder(),
|
sortOrder: loadSortOrder(),
|
||||||
pinnedDatabaseIds: loadPinnedDatabases(),
|
pinnedDatabaseIds: loadPinnedDatabases(),
|
||||||
|
|||||||
@@ -3,21 +3,16 @@
|
|||||||
*
|
*
|
||||||
* Regression tests for IcM 865096261 — DataExplorerHealthV2 "High Unhealthy Percentage".
|
* Regression tests for IcM 865096261 — DataExplorerHealthV2 "High Unhealthy Percentage".
|
||||||
*
|
*
|
||||||
* Before the fix, ScenarioMonitor.completePhase() silently no-oped when the phase had not
|
* DatabaseTreeRendered used to be completed by any tree render. Because the phase is only
|
||||||
* been started yet. The production call ordering in Explorer.tsx / ResourceTree.tsx always
|
* opened after collections finish (Explorer.tsx) and databaseTreeNodes is memoised
|
||||||
* hits that case:
|
* (ResourceTree.tsx), every completion arrived before the phase existed and was dropped:
|
||||||
|
* missing in 1624 of 1627 DatabaseLoad timeouts over three days.
|
||||||
*
|
*
|
||||||
* - DatabaseTreeRendered is started at Explorer.tsx:451, but the effect that completes it
|
* The fix is on the producer side — a ready revision published once the load has produced the
|
||||||
* (useMetricPhases.ts:55-59) last fires on the databaseTreeNodes change that happens
|
* data the tree is expected to show, acknowledged by the render that carries it. These tests
|
||||||
* *before* line 451. databaseTreeNodes is useMemo'd (ResourceTree.tsx:54), so the effect
|
* pin the monitor half of that contract: completions for phases that were never opened are
|
||||||
* never re-fires and the phase stayed open until the 10 s timeout.
|
* refused rather than backdated, so a render observed too early cannot stand in for the
|
||||||
* - Interactive is completed by a one-shot effect (deps [scenario, enabled]) that can run
|
* loaded tree.
|
||||||
* 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 { updateUserContext } from "../UserContext";
|
||||||
@@ -42,20 +37,19 @@ jest.mock("../ConfigContext", () => ({
|
|||||||
Platform: { Portal: "Portal", Hosted: "Hosted", Emulator: "Emulator", Fabric: "Fabric" },
|
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 lastEmit = () => (reportMetric as jest.Mock).mock.calls.at(-1)[0];
|
||||||
|
|
||||||
const ALL_DATABASE_LOAD_PHASES = [
|
/** Producer sequence up to the point where the tree is ready to be acknowledged. */
|
||||||
ApplicationMetricPhase.DatabasesFetched,
|
const loadUpToTreeReady = () => {
|
||||||
ApplicationMetricPhase.CollectionsLoaded,
|
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
||||||
ApplicationMetricPhase.DatabaseTreeRendered,
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
|
||||||
CommonMetricPhase.Interactive,
|
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
||||||
];
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
||||||
|
// Explorer publishes the ready revision immediately after opening the phase.
|
||||||
|
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
};
|
||||||
|
|
||||||
describe("DatabaseLoad phase ordering (IcM 865096261)", () => {
|
describe("DatabaseLoad phase accounting (IcM 865096261)", () => {
|
||||||
beforeEach(() => {
|
beforeEach(() => {
|
||||||
jest.clearAllMocks();
|
jest.clearAllMocks();
|
||||||
jest.useFakeTimers({ legacyFakeTimers: true });
|
jest.useFakeTimers({ legacyFakeTimers: true });
|
||||||
@@ -68,55 +62,77 @@ describe("DatabaseLoad phase ordering (IcM 865096261)", () => {
|
|||||||
jest.useRealTimers();
|
jest.useRealTimers();
|
||||||
});
|
});
|
||||||
|
|
||||||
it("completes healthy under the production call ordering", () => {
|
it("completes healthy once the render carrying the ready revision is acknowledged", () => {
|
||||||
// Explorer.tsx:577 — refreshExplorer starts the scenario
|
loadUpToTreeReady();
|
||||||
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
// ResourceTree commits the revision-bearing render and acknowledges it.
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
// 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);
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
|
||||||
|
|
||||||
jest.advanceTimersByTime(10_000);
|
jest.advanceTimersByTime(10_000);
|
||||||
|
|
||||||
const emitted = lastEmit();
|
const emitted = lastEmit();
|
||||||
expect(emitted.scenario).toBe("DatabaseLoad");
|
|
||||||
expect(emitted.timedOut).toBe(false);
|
expect(emitted.timedOut).toBe(false);
|
||||||
expect(emitted.healthy).toBe(true);
|
expect(emitted.healthy).toBe(true);
|
||||||
expect(emitted.completedPhases).toEqual(expect.arrayContaining(ALL_DATABASE_LOAD_PHASES));
|
expect(emitted.completedPhases).toEqual(
|
||||||
|
expect.arrayContaining([
|
||||||
|
ApplicationMetricPhase.DatabasesFetched,
|
||||||
|
ApplicationMetricPhase.CollectionsLoaded,
|
||||||
|
ApplicationMetricPhase.DatabaseTreeRendered,
|
||||||
|
CommonMetricPhase.Interactive,
|
||||||
|
]),
|
||||||
|
);
|
||||||
});
|
});
|
||||||
|
|
||||||
it("honours a completion that arrives before the scenario is started", () => {
|
it("refuses a tree completion that arrives before the phase is opened", () => {
|
||||||
// ResourceTree mounts and its one-shot effects run before Explorer.tsx:577.
|
|
||||||
treeRenderEffectFires();
|
|
||||||
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
|
|
||||||
|
|
||||||
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
||||||
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
|
||||||
|
|
||||||
|
// A render of the databases-only tree, while collections are still loading. This must not
|
||||||
|
// be accepted as the loaded tree, and must not be backdated once the phase opens.
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
|
||||||
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
||||||
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.CollectionsLoaded);
|
||||||
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
scenarioMonitor.startPhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
|
||||||
|
|
||||||
|
jest.advanceTimersByTime(10_000);
|
||||||
|
|
||||||
|
const emitted = lastEmit();
|
||||||
|
expect(emitted.timedOut).toBe(true);
|
||||||
|
expect(emitted.healthy).toBe(false);
|
||||||
|
expect(emitted.completedPhases).not.toContain(ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
});
|
||||||
|
|
||||||
|
it("does not buffer a deferred phase reported before the scenario exists", () => {
|
||||||
|
// A stale callback from a superseded load, before this load has started.
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
|
||||||
|
loadUpToTreeReady();
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
|
||||||
|
|
||||||
|
jest.advanceTimersByTime(10_000);
|
||||||
|
|
||||||
|
const emitted = lastEmit();
|
||||||
|
expect(emitted.timedOut).toBe(true);
|
||||||
|
expect(emitted.healthy).toBe(false);
|
||||||
|
expect(emitted.completedPhases).not.toContain(ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
});
|
||||||
|
|
||||||
|
it("still honours a non-deferred completion reported before the scenario exists", () => {
|
||||||
|
// useInteractive is a one-shot effect started with the scenario, so a mount that beats
|
||||||
|
// refreshExplorer is a real observation and must not be lost.
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, CommonMetricPhase.Interactive);
|
||||||
|
|
||||||
|
loadUpToTreeReady();
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
|
||||||
jest.advanceTimersByTime(10_000);
|
jest.advanceTimersByTime(10_000);
|
||||||
|
|
||||||
const emitted = lastEmit();
|
const emitted = lastEmit();
|
||||||
expect(emitted.timedOut).toBe(false);
|
expect(emitted.timedOut).toBe(false);
|
||||||
expect(emitted.healthy).toBe(true);
|
expect(emitted.healthy).toBe(true);
|
||||||
expect(emitted.completedPhases).toEqual(expect.arrayContaining(ALL_DATABASE_LOAD_PHASES));
|
expect(emitted.completedPhases).toContain(CommonMetricPhase.Interactive);
|
||||||
});
|
});
|
||||||
|
|
||||||
it("still reports unhealthy when a phase genuinely never completes", () => {
|
it("still reports unhealthy when a phase genuinely never completes", () => {
|
||||||
@@ -133,20 +149,34 @@ describe("DatabaseLoad phase ordering (IcM 865096261)", () => {
|
|||||||
expect(emitted.completedPhases).not.toContain(ApplicationMetricPhase.CollectionsLoaded);
|
expect(emitted.completedPhases).not.toContain(ApplicationMetricPhase.CollectionsLoaded);
|
||||||
});
|
});
|
||||||
|
|
||||||
it("does not count a timeout against health while the tab is backgrounded", () => {
|
it("reports an unfinished background load as unhealthy, with the visibility context", () => {
|
||||||
|
// Timer throttling may justify excluding this from alerting, but the load did not finish,
|
||||||
|
// so the emitted outcome must stay unhealthy and carry documentHidden for that decision.
|
||||||
const hidden = jest.spyOn(document, "hidden", "get").mockReturnValue(true);
|
const hidden = jest.spyOn(document, "hidden", "get").mockReturnValue(true);
|
||||||
try {
|
try {
|
||||||
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
||||||
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabasesFetched);
|
|
||||||
|
|
||||||
jest.advanceTimersByTime(10_000);
|
jest.advanceTimersByTime(10_000);
|
||||||
|
|
||||||
const emitted = lastEmit();
|
const emitted = lastEmit();
|
||||||
expect(emitted.timedOut).toBe(true);
|
expect(emitted.timedOut).toBe(true);
|
||||||
expect(emitted.documentHidden).toBe(true);
|
expect(emitted.documentHidden).toBe(true);
|
||||||
expect(emitted.healthy).toBe(true);
|
expect(emitted.healthy).toBe(false);
|
||||||
|
expect(emitted.completedPhases).toHaveLength(0);
|
||||||
} finally {
|
} finally {
|
||||||
hidden.mockRestore();
|
hidden.mockRestore();
|
||||||
}
|
}
|
||||||
});
|
});
|
||||||
|
|
||||||
|
it("excuses a timeout that followed an expected failure", () => {
|
||||||
|
scenarioMonitor.start(MetricScenario.DatabaseLoad);
|
||||||
|
scenarioMonitor.markExpectedFailure();
|
||||||
|
|
||||||
|
jest.advanceTimersByTime(10_000);
|
||||||
|
|
||||||
|
const emitted = lastEmit();
|
||||||
|
expect(emitted.timedOut).toBe(true);
|
||||||
|
expect(emitted.hasExpectedFailure).toBe(true);
|
||||||
|
expect(emitted.healthy).toBe(true);
|
||||||
|
});
|
||||||
});
|
});
|
||||||
|
|||||||
@@ -130,11 +130,11 @@ class ScenarioMonitor {
|
|||||||
hasExpectedFailure: ctx.hasExpectedFailure,
|
hasExpectedFailure: ctx.hasExpectedFailure,
|
||||||
});
|
});
|
||||||
|
|
||||||
// Expected failures (auth, firewall, ...) are not our outage. Neither is a timeout in
|
// Expected failures (auth, firewall, ...) are not our outage. A backgrounded tab is not
|
||||||
// a backgrounded tab: browsers throttle timers and suspend rAF there, so phase
|
// excused here: timer throttling changes whether the timeout should raise an alert, but
|
||||||
// completion is unreliable and the elapsed time is not the user's experience.
|
// it does not establish that the load completed. documentHidden is reported with the
|
||||||
// documentHidden is still reported so these can be sliced out in telemetry.
|
// event so alerting can apply that policy without the load being relabelled as healthy.
|
||||||
const healthy = ctx.hasExpectedFailure || document.hidden;
|
const healthy = ctx.hasExpectedFailure;
|
||||||
this.emit(ctx, healthy, true);
|
this.emit(ctx, healthy, true);
|
||||||
}, config.timeoutMs);
|
}, config.timeoutMs);
|
||||||
this.contexts.set(scenario, ctx);
|
this.contexts.set(scenario, ctx);
|
||||||
@@ -199,11 +199,14 @@ class ScenarioMonitor {
|
|||||||
completePhase(scenario: MetricScenario, phase: MetricPhase) {
|
completePhase(scenario: MetricScenario, phase: MetricPhase) {
|
||||||
const ctx = this.contexts.get(scenario);
|
const ctx = this.contexts.get(scenario);
|
||||||
|
|
||||||
// The scenario has not been started yet. Remember the completion and replay it in
|
// The scenario has not been started yet. Buffer the completion and replay it in start(),
|
||||||
// start(); otherwise a one-shot React effect that fired early is lost forever.
|
// otherwise a one-shot React effect that fired early is lost forever. Only phases that
|
||||||
|
// start with the scenario are buffered: a deferred phase must be opened explicitly by its
|
||||||
|
// producer, so accepting one early would record a completion for work that had not begun.
|
||||||
if (!ctx) {
|
if (!ctx) {
|
||||||
const config = scenarioConfigs[scenario];
|
const config = scenarioConfigs[scenario];
|
||||||
if (config?.requiredPhases.includes(phase)) {
|
const isDeferred = config?.deferredPhases?.includes(phase) ?? false;
|
||||||
|
if (config?.requiredPhases.includes(phase) && !isDeferred) {
|
||||||
const pending = this.earlyCompletions.get(scenario) ?? new Set<MetricPhase>();
|
const pending = this.earlyCompletions.get(scenario) ?? new Set<MetricPhase>();
|
||||||
pending.add(phase);
|
pending.add(phase);
|
||||||
this.earlyCompletions.set(scenario, pending);
|
this.earlyCompletions.set(scenario, pending);
|
||||||
@@ -216,16 +219,18 @@ class ScenarioMonitor {
|
|||||||
return;
|
return;
|
||||||
}
|
}
|
||||||
|
|
||||||
// The phase is required but has not been started yet (deferred phases are started
|
// Completion for a phase that was never started. The producer ordering is wrong, and we
|
||||||
// explicitly, and the caller may run before that happens). Self-start it now so the
|
// cannot tell what the completion actually observed, so the phase is left open rather than
|
||||||
// completion is honoured instead of silently dropped.
|
// backdated. Reported so the ordering bug is visible instead of silently skewing the metric.
|
||||||
let phaseCtx = ctx.phases.get(phase);
|
const phaseCtx = ctx.phases.get(phase);
|
||||||
if (!phaseCtx) {
|
if (!phaseCtx) {
|
||||||
const lateStartMarkName = `scenario_${scenario}_${phase}_start`;
|
this.devLog(`phase_complete_unstarted: ${scenario}.${phase} — ignored, phase was never started`);
|
||||||
performance.mark(lateStartMarkName);
|
traceMark(Action.MetricsScenario, {
|
||||||
phaseCtx = { startMarkName: lateStartMarkName };
|
event: "phase_complete_unstarted",
|
||||||
ctx.phases.set(phase, phaseCtx);
|
scenario,
|
||||||
this.devLog(`phase_autostart: ${scenario}.${phase} — completed before startPhase()`);
|
phase,
|
||||||
|
});
|
||||||
|
return;
|
||||||
}
|
}
|
||||||
|
|
||||||
const endMarkName = `scenario_${scenario}_${phase}_end`;
|
const endMarkName = `scenario_${scenario}_${phase}_end`;
|
||||||
|
|||||||
@@ -1,4 +1,5 @@
|
|||||||
import React from "react";
|
import React from "react";
|
||||||
|
import { useDatabases } from "../Explorer/useDatabases";
|
||||||
import MetricScenario from "./MetricEvents";
|
import MetricScenario from "./MetricEvents";
|
||||||
import { ApplicationMetricPhase, CommonMetricPhase } from "./ScenarioConfig";
|
import { ApplicationMetricPhase, CommonMetricPhase } from "./ScenarioConfig";
|
||||||
import { scenarioMonitor } from "./ScenarioMonitor";
|
import { scenarioMonitor } from "./ScenarioMonitor";
|
||||||
@@ -41,22 +42,32 @@ export function useInteractive(scenario: MetricScenario, enabled = true) {
|
|||||||
|
|
||||||
/**
|
/**
|
||||||
* Hook to manage DatabaseLoad scenario phase completions.
|
* Hook to manage DatabaseLoad scenario phase completions.
|
||||||
* Tracks tree rendering and completes Interactive phase.
|
|
||||||
* Only attempts to complete DatabaseTreeRendered if the database fetch was successful.
|
|
||||||
* Note: Scenario must be started before databases are fetched (in refreshExplorer).
|
|
||||||
*
|
*
|
||||||
* No one-shot guard is needed — completePhase is idempotent (ScenarioMonitor returns
|
* DatabaseTreeRendered is completed only for a render that carries the ready revision
|
||||||
* early if the phase hasn't been started yet, is already completed, or is already
|
* published by the current load (Explorer.refreshAndExpandNewDatabases). An earlier render —
|
||||||
* emitted). This lets the effect safely re-fire on every databaseTreeNodes change
|
* databases fetched but collections still loading — carries a stale revision and is ignored,
|
||||||
* until the phase has actually been started via startPhase() in Explorer.tsx.
|
* so it cannot be mistaken for the loaded tree. Each revision is acknowledged at most once,
|
||||||
|
* which also discards stale callbacks from a superseded load.
|
||||||
|
*
|
||||||
|
* An account with no databases still publishes a revision and renders an empty tree, so it
|
||||||
|
* completes normally rather than stalling.
|
||||||
*/
|
*/
|
||||||
export function useDatabaseLoadScenario(databaseTreeNodes: unknown[], fetchSucceeded: boolean) {
|
export function useDatabaseLoadScenario(databaseTreeNodes: unknown[], fetchSucceeded: boolean) {
|
||||||
// Track DatabaseTreeRendered phase (only if fetch succeeded)
|
const treeReadyRevision = useDatabases((state) => state.treeReadyRevision);
|
||||||
|
const acknowledgedRevision = React.useRef(0);
|
||||||
|
|
||||||
|
// Track DatabaseTreeRendered phase. Runs after commit, so the tree carrying this revision
|
||||||
|
// is on screen by the time the phase is completed.
|
||||||
React.useEffect(() => {
|
React.useEffect(() => {
|
||||||
if (fetchSucceeded) {
|
if (!fetchSucceeded || treeReadyRevision === 0) {
|
||||||
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
return;
|
||||||
}
|
}
|
||||||
}, [databaseTreeNodes, fetchSucceeded]);
|
if (acknowledgedRevision.current >= treeReadyRevision) {
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
acknowledgedRevision.current = treeReadyRevision;
|
||||||
|
scenarioMonitor.completePhase(MetricScenario.DatabaseLoad, ApplicationMetricPhase.DatabaseTreeRendered);
|
||||||
|
}, [databaseTreeNodes, fetchSucceeded, treeReadyRevision]);
|
||||||
|
|
||||||
// Track Interactive phase
|
// Track Interactive phase
|
||||||
useInteractive(MetricScenario.DatabaseLoad);
|
useInteractive(MetricScenario.DatabaseLoad);
|
||||||
|
|||||||
@@ -710,11 +710,12 @@ export async function fetchAndUpdateKeys(subscriptionId: string, resourceGroup:
|
|||||||
}
|
}
|
||||||
|
|
||||||
// The portal configures Data Explorer with a single iframe message. If a dependency on the
|
// 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
|
// portal side never resolves, that message is never posted and the promise below stays
|
||||||
// promise below stays pending forever, leaving the user on <LoadingExplorer /> with no
|
// pending, leaving the user on <LoadingExplorer /> while the ApplicationLoad health scenario
|
||||||
// diagnostic while the ApplicationLoad health scenario times out mute (IcM 865096261).
|
// times out with no diagnostic (IcM 865096261). The watchdog below reports that, but
|
||||||
// Deliberately well above the 10s scenario budget so only genuinely stuck handshakes fail.
|
// deliberately does not reject: a late init message must still be able to complete setup.
|
||||||
const PORTAL_INIT_MESSAGE_TIMEOUT_MS = 30000;
|
// Well above the 10s scenario budget so only genuinely stuck handshakes are reported.
|
||||||
|
const PORTAL_INIT_MESSAGE_WATCHDOG_MS = 30000;
|
||||||
|
|
||||||
async function configurePortal(): Promise<Explorer> {
|
async function configurePortal(): Promise<Explorer> {
|
||||||
const configureStartKey = traceStart(Action.ConfigurePortal, {
|
const configureStartKey = traceStart(Action.ConfigurePortal, {
|
||||||
@@ -725,7 +726,7 @@ async function configurePortal(): Promise<Explorer> {
|
|||||||
});
|
});
|
||||||
|
|
||||||
let explorer: Explorer;
|
let explorer: Explorer;
|
||||||
let initMessageTimeoutId: number;
|
let initMessageReceived = false;
|
||||||
|
|
||||||
const explorerReady = new Promise<Explorer>((resolve) => {
|
const explorerReady = new Promise<Explorer>((resolve) => {
|
||||||
// In development mode, try to load the iframe message from session storage.
|
// In development mode, try to load the iframe message from session storage.
|
||||||
@@ -767,76 +768,90 @@ async function configurePortal(): Promise<Explorer> {
|
|||||||
const inputs = message?.inputs;
|
const inputs = message?.inputs;
|
||||||
const openAction = message?.openAction;
|
const openAction = message?.openAction;
|
||||||
if (inputs) {
|
if (inputs) {
|
||||||
updateContextsFromPortalMessage(inputs);
|
initMessageReceived = true;
|
||||||
|
try {
|
||||||
|
updateContextsFromPortalMessage(inputs);
|
||||||
|
|
||||||
const { databaseAccount: account, subscriptionId, resourceGroup } = userContext;
|
const { databaseAccount: account, subscriptionId, resourceGroup } = userContext;
|
||||||
|
|
||||||
if (userContext.apiType === "SQL") {
|
if (userContext.apiType === "SQL") {
|
||||||
checkAndUpdateSelectedRegionalEndpoint();
|
checkAndUpdateSelectedRegionalEndpoint();
|
||||||
}
|
|
||||||
|
|
||||||
let dataPlaneRbacEnabled;
|
|
||||||
if (isDataplaneRbacSupported(userContext.apiType)) {
|
|
||||||
if (LocalStorageUtility.hasItem(StorageKey.DataPlaneRbacEnabled)) {
|
|
||||||
const isDataPlaneRbacSetting = LocalStorageUtility.getEntryString(StorageKey.DataPlaneRbacEnabled);
|
|
||||||
Logger.logInfo(
|
|
||||||
`Local storage RBAC setting for ${userContext.apiType} account ${account.name} is ${isDataPlaneRbacSetting}`,
|
|
||||||
"Explorer/configurePortal",
|
|
||||||
);
|
|
||||||
|
|
||||||
if (isDataPlaneRbacSetting === Constants.RBACOptions.setAutomaticRBACOption) {
|
|
||||||
dataPlaneRbacEnabled = account.properties.disableLocalAuth;
|
|
||||||
} else {
|
|
||||||
dataPlaneRbacEnabled = isDataPlaneRbacSetting === Constants.RBACOptions.setTrueRBACOption;
|
|
||||||
}
|
|
||||||
} else {
|
|
||||||
Logger.logInfo(
|
|
||||||
`Local storage does not exist for ${userContext.apiType} account ${account.name} with disable local auth set to ${account.properties.disableLocalAuth} is ${dataPlaneRbacEnabled}`,
|
|
||||||
"Explorer/configurePortal",
|
|
||||||
);
|
|
||||||
dataPlaneRbacEnabled = account.properties.disableLocalAuth;
|
|
||||||
}
|
}
|
||||||
Logger.logInfo(
|
|
||||||
`Data Plane RBAC value for ${userContext.apiType} account ${account.name} with disable local auth set to ${account.properties.disableLocalAuth} is ${dataPlaneRbacEnabled}`,
|
|
||||||
"Explorer/configurePortal",
|
|
||||||
);
|
|
||||||
|
|
||||||
if (!dataPlaneRbacEnabled) {
|
let dataPlaneRbacEnabled;
|
||||||
|
if (isDataplaneRbacSupported(userContext.apiType)) {
|
||||||
|
if (LocalStorageUtility.hasItem(StorageKey.DataPlaneRbacEnabled)) {
|
||||||
|
const isDataPlaneRbacSetting = LocalStorageUtility.getEntryString(StorageKey.DataPlaneRbacEnabled);
|
||||||
|
Logger.logInfo(
|
||||||
|
`Local storage RBAC setting for ${userContext.apiType} account ${account.name} is ${isDataPlaneRbacSetting}`,
|
||||||
|
"Explorer/configurePortal",
|
||||||
|
);
|
||||||
|
|
||||||
|
if (isDataPlaneRbacSetting === Constants.RBACOptions.setAutomaticRBACOption) {
|
||||||
|
dataPlaneRbacEnabled = account.properties.disableLocalAuth;
|
||||||
|
} else {
|
||||||
|
dataPlaneRbacEnabled = isDataPlaneRbacSetting === Constants.RBACOptions.setTrueRBACOption;
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
Logger.logInfo(
|
||||||
|
`Local storage does not exist for ${userContext.apiType} account ${account.name} with disable local auth set to ${account.properties.disableLocalAuth} is ${dataPlaneRbacEnabled}`,
|
||||||
|
"Explorer/configurePortal",
|
||||||
|
);
|
||||||
|
dataPlaneRbacEnabled = account.properties.disableLocalAuth;
|
||||||
|
}
|
||||||
|
Logger.logInfo(
|
||||||
|
`Data Plane RBAC value for ${userContext.apiType} account ${account.name} with disable local auth set to ${account.properties.disableLocalAuth} is ${dataPlaneRbacEnabled}`,
|
||||||
|
"Explorer/configurePortal",
|
||||||
|
);
|
||||||
|
|
||||||
|
if (!dataPlaneRbacEnabled) {
|
||||||
|
Logger.logInfo(
|
||||||
|
`Calling fetch keys for ${userContext.apiType} account ${account.name}`,
|
||||||
|
"Explorer/configurePortal",
|
||||||
|
);
|
||||||
|
await fetchAndUpdateKeys(subscriptionId, resourceGroup, account.name);
|
||||||
|
} else {
|
||||||
|
Logger.logInfo(
|
||||||
|
`Trying to silently acquire MSAL token for ${userContext.apiType} account ${account.name}`,
|
||||||
|
"Explorer/configurePortal",
|
||||||
|
);
|
||||||
|
try {
|
||||||
|
const aadToken = await acquireMsalTokenForAccount(userContext.databaseAccount, true);
|
||||||
|
updateUserContext({ aadToken: aadToken });
|
||||||
|
useDataPlaneRbac.setState({ aadTokenUpdated: true });
|
||||||
|
} catch (authError) {
|
||||||
|
Logger.logWarning(
|
||||||
|
`Failed to silently acquire authorization token from MSAL: ${authError} for ${userContext.apiType} account ${account}`,
|
||||||
|
"Explorer/configurePortal",
|
||||||
|
);
|
||||||
|
logConsoleError("Failed to silently acquire authorization token: " + authError);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
updateUserContext({ dataPlaneRbacEnabled });
|
||||||
|
useDataPlaneRbac.setState({ dataPlaneRbacEnabled: dataPlaneRbacEnabled });
|
||||||
|
} else if (userContext.apiType !== "Postgres" && userContext.apiType !== "VCoreMongo") {
|
||||||
Logger.logInfo(
|
Logger.logInfo(
|
||||||
`Calling fetch keys for ${userContext.apiType} account ${account.name}`,
|
`Calling fetch keys for ${userContext.apiType} account ${account.name}`,
|
||||||
"Explorer/configurePortal",
|
"Explorer/configurePortal",
|
||||||
);
|
);
|
||||||
await fetchAndUpdateKeys(subscriptionId, resourceGroup, account.name);
|
await fetchAndUpdateKeys(subscriptionId, resourceGroup, account.name);
|
||||||
} else {
|
|
||||||
Logger.logInfo(
|
|
||||||
`Trying to silently acquire MSAL token for ${userContext.apiType} account ${account.name}`,
|
|
||||||
"Explorer/configurePortal",
|
|
||||||
);
|
|
||||||
try {
|
|
||||||
const aadToken = await acquireMsalTokenForAccount(userContext.databaseAccount, true);
|
|
||||||
updateUserContext({ aadToken: aadToken });
|
|
||||||
useDataPlaneRbac.setState({ aadTokenUpdated: true });
|
|
||||||
} catch (authError) {
|
|
||||||
Logger.logWarning(
|
|
||||||
`Failed to silently acquire authorization token from MSAL: ${authError} for ${userContext.apiType} account ${account}`,
|
|
||||||
"Explorer/configurePortal",
|
|
||||||
);
|
|
||||||
logConsoleError("Failed to silently acquire authorization token: " + authError);
|
|
||||||
}
|
|
||||||
}
|
}
|
||||||
|
|
||||||
updateUserContext({ dataPlaneRbacEnabled });
|
explorer = new Explorer();
|
||||||
useDataPlaneRbac.setState({ dataPlaneRbacEnabled: dataPlaneRbacEnabled });
|
traceSuccess(Action.ConfigurePortal, {}, configureStartKey);
|
||||||
} else if (userContext.apiType !== "Postgres" && userContext.apiType !== "VCoreMongo") {
|
} catch (error) {
|
||||||
Logger.logInfo(
|
// A valid init message arrived but setup threw. Leaving the promise pending would
|
||||||
`Calling fetch keys for ${userContext.apiType} account ${account.name}`,
|
// strand the user on <LoadingExplorer /> with nothing reported, so the shell is
|
||||||
"Explorer/configurePortal",
|
// still created below: steps depending on the failed work surface their own errors.
|
||||||
);
|
const errorMessage = error instanceof Error ? error.message : String(error);
|
||||||
await fetchAndUpdateKeys(subscriptionId, resourceGroup, account.name);
|
traceFailure(Action.ConfigurePortal, { error: errorMessage }, configureStartKey);
|
||||||
|
logConsoleError(`Data Explorer initialization failed: ${errorMessage}`);
|
||||||
}
|
}
|
||||||
|
|
||||||
explorer = new Explorer();
|
if (!explorer) {
|
||||||
traceSuccess(Action.ConfigurePortal, {}, configureStartKey);
|
explorer = new Explorer();
|
||||||
|
}
|
||||||
resolve(explorer);
|
resolve(explorer);
|
||||||
|
|
||||||
if (openAction) {
|
if (openAction) {
|
||||||
@@ -863,20 +878,27 @@ async function configurePortal(): Promise<Explorer> {
|
|||||||
sendReadyMessage();
|
sendReadyMessage();
|
||||||
});
|
});
|
||||||
|
|
||||||
const initMessageTimeout = new Promise<never>((_resolve, reject) => {
|
// Report a handshake that has not produced an init message, without cancelling it. Rejecting
|
||||||
initMessageTimeoutId = window.setTimeout(() => {
|
// here would abandon the caller while the listener stays live, so a late message would build
|
||||||
const error = new Error(
|
// an Explorer that setExplorer() never receives — the load would be unrecoverable rather
|
||||||
`Portal did not send the Data Explorer init message within ${PORTAL_INIT_MESSAGE_TIMEOUT_MS}ms`,
|
// than merely slow.
|
||||||
);
|
const watchdogId = window.setTimeout(() => {
|
||||||
traceFailure(Action.ConfigurePortal, { error: error.message }, configureStartKey);
|
if (initMessageReceived) {
|
||||||
reject(error);
|
return;
|
||||||
}, PORTAL_INIT_MESSAGE_TIMEOUT_MS);
|
}
|
||||||
});
|
traceFailure(
|
||||||
|
Action.ConfigurePortal,
|
||||||
|
{
|
||||||
|
error: `Portal has not sent the Data Explorer init message after ${PORTAL_INIT_MESSAGE_WATCHDOG_MS}ms; still waiting`,
|
||||||
|
},
|
||||||
|
configureStartKey,
|
||||||
|
);
|
||||||
|
}, PORTAL_INIT_MESSAGE_WATCHDOG_MS);
|
||||||
|
|
||||||
try {
|
try {
|
||||||
return await Promise.race([explorerReady, initMessageTimeout]);
|
return await explorerReady;
|
||||||
} finally {
|
} finally {
|
||||||
window.clearTimeout(initMessageTimeoutId);
|
window.clearTimeout(watchdogId);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user