From 1fd2177b94c68e4ff397185ac575854035aae5e7 Mon Sep 17 00:00:00 2001 From: Luke Cotter <4013877+lukecotter@users.noreply.github.com> Date: Wed, 2 Sep 2026 15:38:05 +0100 Subject: [PATCH 1/7] feat(log-viewer): publish the stretch of log the timeline is showing The inspector's Timeline summary could only ever read the whole log, so zooming in left the figures answering a question the user had moved on from. The chart now records the stretch of log it shows, and everything else reads it. One publish per frame, coalesced, so the figures follow a gesture instead of landing after it. - `core/log/rangeScope.ts` holds the window, with the chart as its only writer: it owns the viewport, so it also decides when one is wide enough to be the whole log. - State rather than an event, so a section built after the last viewport change still opens on the window the user is looking at. - `windowFor` reads a viewport as a window or as the whole log. A full zoom-out sets zoom to width over span, and reading the width back out of that division lands an ULP either side, so the whole-log test carries a nanosecond of slack. A viewport of no width is no window: before layout the bounds collapse, and a window of nothing would read as a stretch of log where nothing ran. --- .../src/core/log/__tests__/rangeScope.test.ts | 110 +++++++++++++++++ log-viewer/src/core/log/rangeScope.ts | 116 ++++++++++++++++++ .../timeline/components/TimelineFlameChart.ts | 29 ++++- 3 files changed, 254 insertions(+), 1 deletion(-) create mode 100644 log-viewer/src/core/log/__tests__/rangeScope.test.ts create mode 100644 log-viewer/src/core/log/rangeScope.ts diff --git a/log-viewer/src/core/log/__tests__/rangeScope.test.ts b/log-viewer/src/core/log/__tests__/rangeScope.test.ts new file mode 100644 index 000000000..390e64eca --- /dev/null +++ b/log-viewer/src/core/log/__tests__/rangeScope.test.ts @@ -0,0 +1,110 @@ +/* + * Copyright (c) 2026 Certinia Inc. All rights reserved. + */ +import { + currentRange, + onRangeChange, + setRange, + windowFor, + type TimeWindow, +} from '../rangeScope.js'; + +describe('rangeScope', () => { + afterEach(() => { + setRange(null); + }); + + it('reads as the whole log until a window is set', () => { + expect(currentRange()).toBeNull(); + }); + + it('holds the window it was given', () => { + setRange({ start: 100, end: 500 }); + + expect(currentRange()).toEqual({ start: 100, end: 500 }); + }); + + it('returns to the whole log', () => { + setRange({ start: 100, end: 500 }); + setRange(null); + + expect(currentRange()).toBeNull(); + }); + + it('tells every reader when the window changes', () => { + const seen: Array = []; + const other: Array = []; + onRangeChange((window) => seen.push(window)); + onRangeChange((window) => other.push(window)); + + setRange({ start: 1, end: 2 }); + + expect(seen).toEqual([{ start: 1, end: 2 }]); + expect(other).toEqual([{ start: 1, end: 2 }]); + }); + + // A viewport that settles back where it started must rebuild nothing. + it('says nothing when the window has not moved', () => { + const seen: Array = []; + setRange({ start: 1, end: 2 }); + onRangeChange((window) => seen.push(window)); + + setRange({ start: 1, end: 2 }); + + expect(seen).toEqual([]); + }); + + it('says nothing when the whole log is set twice', () => { + const seen: Array = []; + onRangeChange((window) => seen.push(window)); + + setRange(null); + + expect(seen).toEqual([]); + }); + + it('stops telling a released reader', () => { + const seen: Array = []; + const release = onRangeChange((window) => seen.push(window)); + + release(); + setRange({ start: 1, end: 2 }); + + expect(seen).toEqual([]); + }); +}); + +describe('windowFor', () => { + const LOG_START = 6_329_577; + const LOG_END = LOG_START + 24_600_000_000; + + it('names the stretch a zoomed viewport shows', () => { + expect(windowFor(1_000, 2_000, LOG_START, LOG_END)).toEqual({ start: 1_000, end: 2_000 }); + }); + + it('reads a viewport of the whole log as no window', () => { + expect(windowFor(0, LOG_END, LOG_START, LOG_END)).toBeNull(); + }); + + // A full zoom-out sets zoom to width over span, and reading the width back + // out of that division lands an ULP short for about one width in twenty. + it('reads a full zoom-out as no window even when the division falls short', () => { + const span = LOG_END; + const width = 1_713; + const zoom = width / span; + const timeEnd = width / zoom; + + expect(timeEnd).toBeLessThan(span); + expect(windowFor(0, timeEnd, LOG_START, LOG_END)).toBeNull(); + }); + + it('reads a viewport of no width as no window', () => { + expect(windowFor(1_000, 1_000, LOG_START, LOG_END)).toBeNull(); + expect(windowFor(2_000, 1_000, LOG_START, LOG_END)).toBeNull(); + }); + + it('reads a viewport with no numbers in it as no window', () => { + expect(windowFor(Number.NaN, Number.NaN, LOG_START, LOG_END)).toBeNull(); + expect(windowFor(0, Number.POSITIVE_INFINITY, LOG_START, LOG_END)).toBeNull(); + }); +}); diff --git a/log-viewer/src/core/log/rangeScope.ts b/log-viewer/src/core/log/rangeScope.ts new file mode 100644 index 000000000..6993fd3c8 --- /dev/null +++ b/log-viewer/src/core/log/rangeScope.ts @@ -0,0 +1,116 @@ +/* + * Copyright (c) 2026 Certinia Inc. All rights reserved. + */ +import type { ReactiveController, ReactiveControllerHost } from 'lit'; + +/** A stretch of the log, in the nanosecond timestamps the parser reports. */ +export interface TimeWindow { + start: number; + end: number; +} + +/** + * The stretch of the log the Timeline is showing, or null for the whole log. + * + * The Timeline is the only writer: it owns the viewport, so it also decides when + * a viewport is wide enough to count as the whole log. Everything else reads. + */ +let range: TimeWindow | null = null; + +const listeners = new Set<(window: TimeWindow | null) => void>(); + +/** The window on screen, or null for the whole log. */ +export function currentRange(): TimeWindow | null { + return range; +} + +/** + * Records the window on screen and tells every reader. Pass null for the whole + * log. An unchanged window tells nobody, so a viewport that settles back where + * it started rebuilds nothing. + */ +export function setRange(window: TimeWindow | null): void { + if (sameWindow(window, range)) { + return; + } + range = window; + for (const listener of listeners) { + listener(range); + } +} + +/** Slack on the whole-log test. A full zoom-out sets zoom to width over span, + * so reading the width back out of that division lands an ULP either side of + * the span, and an exact test would leave a window on at full zoom-out. */ +const WHOLE_LOG_SLACK_NS = 1; + +/** + * The window a viewport showing `timeStart` to `timeEnd` scopes to, or null + * where it shows the whole log and so scopes to nothing. + * + * Null for a viewport of no width too: before layout, or in a collapsed + * container, the bounds collapse, and a window of nothing would read as a + * stretch of log where nothing ran. + */ +export function windowFor( + timeStart: number, + timeEnd: number, + logStart: number, + logEnd: number, +): TimeWindow | null { + if (!Number.isFinite(timeStart) || !Number.isFinite(timeEnd) || timeEnd <= timeStart) { + return null; + } + const showsWholeLog = + timeStart <= logStart + WHOLE_LOG_SLACK_NS && timeEnd >= logEnd - WHOLE_LOG_SLACK_NS; + return showsWholeLog ? null : { start: timeStart, end: timeEnd }; +} + +/** True when both name the same stretch, the whole log included. */ +export function sameWindow(a: TimeWindow | null, b: TimeWindow | null): boolean { + return a?.start === b?.start && a?.end === b?.end; +} + +/** Subscribes to the window, and returns the release. */ +export function onRangeChange(callback: (window: TimeWindow | null) => void): () => void { + listeners.add(callback); + return () => { + listeners.delete(callback); + }; +} + +/** + * Follows the window on screen for a component that reads it. + * + * Reads the window afresh on connect, which is why the window is state rather + * than an event: a section built after the last viewport change still opens on + * the window the user is looking at. + */ +export class RangeScopeController implements ReactiveController { + private _window = currentRange(); + private _release: (() => void) | null = null; + private readonly _host: ReactiveControllerHost; + + constructor(host: ReactiveControllerHost) { + this._host = host; + host.addController(this); + } + + hostConnected(): void { + this._window = currentRange(); + this._release = onRangeChange((window) => { + this._window = window; + this._host.requestUpdate(); + }); + } + + hostDisconnected(): void { + this._release?.(); + this._release = null; + } + + /** The window on screen, or null for the whole log. */ + get window(): TimeWindow | null { + return this._window; + } +} diff --git a/log-viewer/src/features/timeline/components/TimelineFlameChart.ts b/log-viewer/src/features/timeline/components/TimelineFlameChart.ts index 6b5db0b98..06a88bde7 100644 --- a/log-viewer/src/features/timeline/components/TimelineFlameChart.ts +++ b/log-viewer/src/features/timeline/components/TimelineFlameChart.ts @@ -13,10 +13,13 @@ import { css, html, LitElement, type PropertyValues, unsafeCSS } from 'lit'; import { customElement, property, query, state } from 'lit/decorators.js'; import type { ApexLog } from 'apex-log-parser'; +import { setRange, windowFor } from '../../../core/log/rangeScope.js'; +import { debounce } from '../../../core/utility/Util.js'; import { themeObserver } from '../../../core/theme/ThemeObserver.js'; import { ApexLogTimeline } from '../optimised/ApexLogTimeline.js'; import { parseColorToHex } from '../optimised/rendering/ColorUtils.js'; -import type { EditorColors, TimelineOptions } from '../types/flamechart.types.js'; +import { calculateViewportBounds } from '../optimised/ViewportUtils.js'; +import type { EditorColors, TimelineOptions, ViewportState } from '../types/flamechart.types.js'; import { TimelineError } from '../types/flamechart.types.js'; import { tokenStyles } from '../../../styles/tokens.styles.js'; @@ -208,6 +211,10 @@ export class TimelineFlameChart extends LitElement { ...this.options, themeName: this.themeName, editorColors: this.extractEditorColors(), + onViewportChange: (viewport: ViewportState) => { + this.options.onViewportChange?.(viewport); + this._publishRange(viewport, this.initEpoch); + }, }; const epoch = this.initEpoch; @@ -292,12 +299,32 @@ export class TimelineFlameChart extends LitElement { // CLEANUP // ============================================================================ + /** + * Records the stretch of log on screen, for the inspector's sections. The + * chart owns the viewport, so it also decides when one is wide enough to be + * the whole log. + * + * Coalesced to one publish per frame: a drag reports a viewport per input + * event, and a frame can only show one of them. + */ + private readonly _publishRange = debounce((viewport: ViewportState, epoch: number) => { + // A frame queued before the chart was torn down must not put the window back. + if (epoch !== this.initEpoch) { + return; + } + const { timeStart, timeEnd } = calculateViewportBounds(viewport); + const logStart = this.apexLog?.timestamp ?? 0; + setRange(windowFor(timeStart, timeEnd, logStart, this.apexLog?.exitStamp ?? logStart)); + }); + /** * Clean up renderer and observers. */ private cleanup(): void { // Supersede any in-flight `initializeTimeline`. this.initEpoch++; + // No chart, no window: the sections read the whole log again. + setRange(null); // Destroy renderer if (this.apexLogTimeline) { From e581de4f13f41f62e9d5ae379d19dfe2fd9af477 Mon Sep 17 00:00:00 2001 From: Luke Cotter <4013877+lukecotter@users.noreply.github.com> Date: Wed, 2 Sep 2026 15:38:44 +0100 Subject: [PATCH 2/7] fix(log-viewer): report the viewport a seek or a reveal moves to Clicking a governor usage chart, or revealing a frame from the call tree, moved the chart but told nothing: both reached past the chart to its viewport manager and then asked for a repaint, which reports nowhere. So the inspector's summary kept reading the window the chart had left. `FlameChart.focusOn` focuses and then reports, and both callers use it. The repaint they asked for goes with them, since reporting a change already renders. Every other way the viewport moves already reported itself: the interaction handler, `ViewportAnimator`, the minimap lens, `resetZoom`, area zoom, and focus on a frame or a marker. --- .../timeline/optimised/ApexLogTimeline.ts | 6 +- .../features/timeline/optimised/FlameChart.ts | 21 ++++++ .../__tests__/FlameChartFocusOn.test.ts | 65 +++++++++++++++++++ 3 files changed, 88 insertions(+), 4 deletions(-) create mode 100644 log-viewer/src/features/timeline/optimised/__tests__/FlameChartFocusOn.test.ts diff --git a/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts b/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts index 2545dbe59..0201040e9 100644 --- a/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts +++ b/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts @@ -326,8 +326,7 @@ export class ApexLogTimeline { // The frame only gives the depth to centre on; the window is the log's, and // padding 0 keeps the width asked for. const { start, width } = seekWindow(timestamp, this.apexLog?.duration.total ?? 0); - this.flamechart.getViewportManager()?.focusOnEvent(start, width, result?.depth ?? 0, 0); - this.flamechart.requestRender(); + this.flamechart.focusOn(start, width, result?.depth ?? 0, 0); } private _reveal(result: { event: LogEvent; depth: number } | null): void { @@ -337,8 +336,7 @@ export class ApexLogTimeline { this.flamechart.selectByEventNode(this.toEventNode(result)); const { timestamp, duration } = result.event; - this.flamechart.getViewportManager()?.focusOnEvent(timestamp, duration.total, result.depth); - this.flamechart.requestRender(); + this.flamechart.focusOn(timestamp, duration.total, result.depth); } private toEventNode(result: { event: LogEvent; depth: number }): EventNode { diff --git a/log-viewer/src/features/timeline/optimised/FlameChart.ts b/log-viewer/src/features/timeline/optimised/FlameChart.ts index 5a36fd6be..4aa93d7aa 100644 --- a/log-viewer/src/features/timeline/optimised/FlameChart.ts +++ b/log-viewer/src/features/timeline/optimised/FlameChart.ts @@ -2159,6 +2159,27 @@ export class FlameChart { this.selectionOrchestrator?.centerOnSelectedFrame(); } + /** + * Zoom and pan to fit `duration` from `timestamp`, at `depth`. + * + * The way in for a caller outside the chart: moving the viewport through + * {@link getViewportManager} instead changes it without reporting it, and the + * inspector reads the stretch of log the chart says it is showing. + * + * @param timestamp - Start of the stretch to fit, in nanoseconds + * @param duration - Length of that stretch, in nanoseconds + * @param depth - Call-tree depth to centre on + * @param padding - Share of the width to leave either side; 0 fits exactly + */ + public focusOn(timestamp: number, duration: number, depth: number, padding?: number): void { + if (!this.viewport) { + return; + } + + this.viewport.focusOnEvent(timestamp, duration, depth, padding); + this.notifyViewportChange(); + } + /** * Reset viewport to show entire timeline. * Cancels any active animations. diff --git a/log-viewer/src/features/timeline/optimised/__tests__/FlameChartFocusOn.test.ts b/log-viewer/src/features/timeline/optimised/__tests__/FlameChartFocusOn.test.ts new file mode 100644 index 000000000..b33498e22 --- /dev/null +++ b/log-viewer/src/features/timeline/optimised/__tests__/FlameChartFocusOn.test.ts @@ -0,0 +1,65 @@ +/** + * @jest-environment jsdom + */ + +/* + * Copyright (c) 2026 Certinia Inc. All rights reserved. + */ + +/** + * Moving the viewport must report the stretch of log it lands on. The inspector + * reads that report, so a caller that pans or zooms without one leaves the + * summary showing a window that is no longer on screen. + */ + +import { describe, expect, it, jest } from '@jest/globals'; +import { FlameChart } from '../FlameChart.js'; + +/** A chart with only the viewport `focusOn` needs. `state` is left unset, so + * the render it asks for is a no-op. */ +function stubbedChart(): { + chart: FlameChart; + focusOnEvent: jest.Mock; + onViewportChange: jest.Mock; +} { + const chart = new FlameChart(); + const focusOnEvent = jest.fn(); + const onViewportChange = jest.fn(); + const viewportState = { zoom: 2, offsetX: 40, offsetY: 0, displayWidth: 400, displayHeight: 300 }; + + const internals = chart as unknown as Record; + internals['viewport'] = { focusOnEvent, getState: () => viewportState }; + internals['callbacks'] = { onViewportChange }; + + return { chart, focusOnEvent, onViewportChange }; +} + +describe('FlameChart focusOn', () => { + it('reports the viewport it moved to', () => { + const { chart, focusOnEvent, onViewportChange } = stubbedChart(); + + chart.focusOn(1_000, 500, 3, 0); + + expect(focusOnEvent).toHaveBeenCalledWith(1_000, 500, 3, 0); + expect(onViewportChange).toHaveBeenCalledWith( + expect.objectContaining({ zoom: 2, offsetX: 40 }), + ); + }); + + it('leaves the padding to the viewport when none is asked for', () => { + const { chart, focusOnEvent } = stubbedChart(); + + chart.focusOn(1_000, 500, 3); + + expect(focusOnEvent).toHaveBeenCalledWith(1_000, 500, 3, undefined); + }); + + it('does nothing before the chart has a viewport', () => { + const { chart, onViewportChange } = stubbedChart(); + (chart as unknown as Record)['viewport'] = null; + + chart.focusOn(1_000, 500, 3); + + expect(onViewportChange).not.toHaveBeenCalled(); + }); +}); From 0c713562e6ac4ae403c85742c97f865fe5034033 Mon Sep 17 00:00:00 2001 From: Luke Cotter <4013877+lukecotter@users.noreply.github.com> Date: Wed, 2 Sep 2026 15:38:54 +0100 Subject: [PATCH 3/7] refactor(log-viewer): let nothing outside the chart move its viewport `getViewportManager` handed out the live viewport, so any caller could move it without reporting where it landed. That is what the seek and the reveal did, and nothing stopped the next caller doing it again. Its one remaining caller only read the bounds, so it is now `getViewportBounds`. The viewport is private with no public way out, and `focusOn` is the only way in. --- .../timeline/__tests__/chart-select-dim.test.ts | 2 +- .../timeline/optimised/ApexLogTimeline.ts | 2 +- .../features/timeline/optimised/FlameChart.ts | 17 +++++++++++------ 3 files changed, 13 insertions(+), 8 deletions(-) diff --git a/log-viewer/src/features/timeline/__tests__/chart-select-dim.test.ts b/log-viewer/src/features/timeline/__tests__/chart-select-dim.test.ts index e90dd19b8..a0752cb77 100644 --- a/log-viewer/src/features/timeline/__tests__/chart-select-dim.test.ts +++ b/log-viewer/src/features/timeline/__tests__/chart-select-dim.test.ts @@ -34,7 +34,7 @@ function timelineWithSpy(): { handleSelect.call(timeline, null); return true; }, - getViewportManager: () => null, + getViewportBounds: () => null, }; internals['pickEmphasis'] = (eventIndex: number) => calls.push(eventIndex); internals['clearEmphasis'] = () => calls.push('clear'); diff --git a/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts b/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts index 0201040e9..9012cf41b 100644 --- a/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts +++ b/log-viewer/src/features/timeline/optimised/ApexLogTimeline.ts @@ -254,7 +254,7 @@ export class ApexLogTimeline { // run: the select inside it clears the mark, as any chart select does. this.pickEmphasis(eventIndex); - const bounds = this.flamechart.getViewportManager()?.getBounds(); + const bounds = this.flamechart.getViewportBounds(); if ( bounds && isFrameOffscreen(bounds, result.event.timestamp, result.event.duration.total, result.depth) diff --git a/log-viewer/src/features/timeline/optimised/FlameChart.ts b/log-viewer/src/features/timeline/optimised/FlameChart.ts index 4aa93d7aa..f66ffc55e 100644 --- a/log-viewer/src/features/timeline/optimised/FlameChart.ts +++ b/log-viewer/src/features/timeline/optimised/FlameChart.ts @@ -25,6 +25,7 @@ import type { TimelineOptions, TimelineState, TreeNode, + ViewportBounds, ViewportState, } from '../types/flamechart.types.js'; import { TIMELINE_CONSTANTS, TimelineError, TimelineErrorCode } from '../types/flamechart.types.js'; @@ -673,10 +674,14 @@ export class FlameChart { } /** - * Get viewport manager instance. + * The stretch of log and the depths on screen, or null before the chart has a + * viewport. + * + * A read, not the viewport itself: moving the viewport has to report where it + * landed, and only the chart can do that (see {@link focusOn}). */ - public getViewportManager(): TimelineViewport | null { - return this.viewport; + public getViewportBounds(): ViewportBounds | null { + return this.viewport?.getBounds() ?? null; } /** @@ -2162,9 +2167,9 @@ export class FlameChart { /** * Zoom and pan to fit `duration` from `timestamp`, at `depth`. * - * The way in for a caller outside the chart: moving the viewport through - * {@link getViewportManager} instead changes it without reporting it, and the - * inspector reads the stretch of log the chart says it is showing. + * The only way a caller outside the chart moves the viewport, so that every + * move is reported: the inspector reads the stretch of log the chart says it + * is showing. * * @param timestamp - Start of the stretch to fit, in nanoseconds * @param duration - Length of that stretch, in nanoseconds From df31e54d1fb326020ce9d404f3dcd3f4cbcf1d6f Mon Sep 17 00:00:00 2001 From: Luke Cotter <4013877+lukecotter@users.noreply.github.com> Date: Wed, 2 Sep 2026 15:39:08 +0100 Subject: [PATCH 4/7] perf(log-viewer): read the log once so any window answers at once The window moves with the gesture, so a walk per window would put a walk of the log in every frame of a drag. On a 100MB log, 431k calls, that measured 27ms for a narrow window and 175ms for a wide one, per section, per frame. The log is read once instead, into an index any stretch of it can be read from. Measured on the same log: 117ms to build, once; 0ms for a window whatever its width; 6ms for sixty windows, a whole drag. Cross-checked against a walk of every event on five windows, self time and counts exact. - Self time by category and by namespace is bucketed by time and kept as a running total, so a window's whole buckets are one subtraction each. Only the part bucket at each edge is read event by event, about a hundred events on the largest logs. Self time sits in the gaps between an event's children, and those gaps never overlap another event's anywhere in the tree, so the buckets add up. - Statement counts need no buckets: running totals by start and by end give the statements a window reaches any part of, exactly. Only the events carrying a counter are held. - One build serves every reader and nothing abandons it. A build tied to one window would restart every frame and never finish. --- .../core/log/__tests__/windowStats.test.ts | 304 ++++++++++ log-viewer/src/core/log/windowStats.ts | 560 ++++++++++++++++++ scripts/measure/measure.ts | 37 ++ 3 files changed, 901 insertions(+) create mode 100644 log-viewer/src/core/log/__tests__/windowStats.test.ts create mode 100644 log-viewer/src/core/log/windowStats.ts diff --git a/log-viewer/src/core/log/__tests__/windowStats.test.ts b/log-viewer/src/core/log/__tests__/windowStats.test.ts new file mode 100644 index 000000000..bc21287f2 --- /dev/null +++ b/log-viewer/src/core/log/__tests__/windowStats.test.ts @@ -0,0 +1,304 @@ +/* + * Copyright (c) 2026 Certinia Inc. All rights reserved. + */ +import { describe, expect, it } from '@jest/globals'; +import type { ApexLog, LogEvent } from 'apex-log-parser'; + +import type { FrameBudgetOptions } from '../../utility/FrameBudget.js'; +import { windowIndexFor, type WindowStats } from '../windowStats.js'; +import type { TimeWindow } from '../rangeScope.js'; + +const options: FrameBudgetOptions = { yieldSlice: () => Promise.resolve() }; + +interface Count { + self: number; + total: number; +} + +/** The parser gives every event all five counters, zero included. */ +interface Built { + category: string; + namespace: string; + timestamp: number; + exitStamp: number | null; + soqlCount: Count; + soqlRowCount: Count; + dmlCount: Count; + dmlRowCount: Count; + soslCount: Count; + children: Built[]; +} + +const count = (self: number): Count => ({ self, total: self }); + +interface Spec { + category?: string; + namespace?: string; + soql?: number; + dml?: number; + children?: Built[]; + /** An unclosed frame, as a truncated log leaves its last frames. */ + unclosed?: boolean; +} + +function ev(timestamp: number, exitStamp: number, spec: Spec = {}): Built { + return { + category: spec.category ?? 'Apex', + namespace: spec.namespace ?? 'default', + timestamp, + exitStamp: spec.unclosed ? null : exitStamp, + soqlCount: count(spec.soql ?? 0), + soqlRowCount: count(0), + dmlCount: count(spec.dml ?? 0), + dmlRowCount: count(0), + soslCount: count(0), + children: spec.children ?? [], + }; +} + +/** The log's own span, which sets where the index puts its bucket edges. */ +function spanOf(children: readonly Built[]): { timestamp: number; exitStamp: number } { + let last = 0; + const reach = (event: Built): void => { + last = Math.max(last, event.exitStamp ?? event.timestamp); + event.children.forEach(reach); + }; + children.forEach(reach); + return { timestamp: children[0]?.timestamp ?? 0, exitStamp: last }; +} + +const logOf = (children: Built[]) => ({ children, ...spanOf(children) }) as unknown as ApexLog; + +/** The stats a fresh index gives for `window`. */ +async function statsFor(log: ApexLog, window: TimeWindow): Promise { + const index = await windowIndexFor(log, options); + return index.statsFor(window); +} + +/** + * A log whose roots count their own time reads, so a test can prove that + * answering a window reads a handful of siblings rather than the log. + */ +function countingLog(children: Built[]): { + log: ApexLog; + visited: () => number; + reset: () => void; +} { + let reads = 0; + const watched = children.map( + (child) => + new Proxy(child, { + get(target, key, receiver) { + if (key === 'timestamp' || key === 'exitStamp') { + reads++; + } + return Reflect.get(target, key, receiver) as unknown; + }, + }) as unknown as LogEvent, + ); + return { + log: { children: watched, ...spanOf(children) } as unknown as ApexLog, + visited: () => reads, + reset: () => { + reads = 0; + }, + }; +} + +describe('windowStats', () => { + it('answers category, namespace and counts from one index', async () => { + const log = logOf([ + ev(0, 100, { category: 'DML', namespace: 'pkg', dml: 2 }), + ev(100, 300, { category: 'SOQL', soql: 3 }), + ]); + + const stats = await statsFor(log, { start: 0, end: 300 }); + + expect(stats.selfByCategory.get('DML')).toBeCloseTo(100, 3); + expect(stats.selfByCategory.get('SOQL')).toBeCloseTo(200, 3); + expect(stats.selfByNamespace.get('pkg')).toBeCloseTo(100, 3); + expect(stats.selfByNamespace.get('default')).toBeCloseTo(200, 3); + expect(stats.counts).toEqual({ + soqlCount: 3, + soqlRowCount: 0, + dmlCount: 2, + dmlRowCount: 0, + soslCount: 0, + }); + }); + + it('counts only the self time inside the window', async () => { + const log = logOf([ev(0, 1_000, { category: 'Apex' })]); + + const stats = await statsFor(log, { start: 200, end: 500 }); + + expect(stats.selfByCategory.get('Apex')).toBeCloseTo(300, 3); + }); + + // Any part of a statement inside the window counts it: one the window cuts + // across still ran in it. + it('counts a statement that began before the window', async () => { + const log = logOf([ev(0, 1_000, { soql: 5 })]); + + const stats = await statsFor(log, { start: 500, end: 900 }); + + expect(stats.counts.soqlCount).toBe(5); + }); + + it('counts a statement that runs past the end of the window', async () => { + const log = logOf([ev(0, 100), ev(800, 2_000, { soql: 2 })]); + + const stats = await statsFor(log, { start: 0, end: 1_000 }); + + expect(stats.counts.soqlCount).toBe(2); + }); + + it('still counts nothing for a statement the window never reaches', async () => { + const log = logOf([ev(0, 100, { soql: 5 }), ev(500, 600)]); + + const stats = await statsFor(log, { start: 500, end: 600 }); + + expect(stats.counts.soqlCount).toBe(0); + }); + + // Counts come from the events' own times, not from the buckets, so a window + // that stops a nanosecond short leaves the statement out. + it('counts a statement by its own times, not the bucket it sits in', async () => { + const log = logOf([ev(0, 1_000_000), ev(500_000, 500_100, { soql: 1 })]); + + const before = await statsFor(log, { start: 0, end: 499_999 }); + const index = await windowIndexFor(log, options); + const upTo = index.statsFor({ start: 0, end: 500_000 }); + + expect(before.counts.soqlCount).toBe(0); + expect(upTo.counts.soqlCount).toBe(1); + }); + + it('reads a parent by its own gaps, not its span', async () => { + // Apex spans 0-100 with a SOQL child filling 10-90. + const log = logOf([ + ev(0, 100, { category: 'Apex', children: [ev(10, 90, { category: 'SOQL' })] }), + ]); + + const stats = await statsFor(log, { start: 0, end: 50 }); + + expect(stats.selfByCategory.get('Apex')).toBeCloseTo(10, 3); + expect(stats.selfByCategory.get('SOQL')).toBeCloseTo(40, 3); + }); + + it('finds nothing in a window the log does not reach', async () => { + const log = logOf([ev(0, 100)]); + + const stats = await statsFor(log, { start: 500, end: 600 }); + + expect(stats.selfByCategory.size).toBe(0); + expect(stats.counts.soqlCount).toBe(0); + }); + + it('holds an unclosed frame rather than dropping it', async () => { + const log = logOf([ + ev(0, 0, { unclosed: true, children: [ev(400, 500, { category: 'SOQL', soql: 1 })] }), + ]); + + const stats = await statsFor(log, { start: 300, end: 600 }); + + expect(stats.selfByCategory.get('SOQL')).toBeCloseTo(100, 3); + expect(stats.counts.soqlCount).toBe(1); + }); +}); + +describe('windowStats own time', () => { + it('adds up the gaps between several children', async () => { + // Gaps of 0-10, 20-40 and 50-100 belong to the parent. + const log = logOf([ + ev(0, 100, { + category: 'Apex', + children: [ev(10, 20, { category: 'SOQL' }), ev(40, 50, { category: 'SOQL' })], + }), + ]); + + const stats = await statsFor(log, { start: 0, end: 100 }); + + expect(stats.selfByCategory.get('Apex')).toBeCloseTo(80, 3); + expect(stats.selfByCategory.get('SOQL')).toBeCloseTo(20, 3); + }); + + it('reads a gap that opens before the window and reaches into it', async () => { + // The parent's own time runs 90-200, and the window opens at 150. + const log = logOf([ + ev(0, 200, { category: 'Apex', children: [ev(10, 90, { category: 'SOQL' })] }), + ]); + + const stats = await statsFor(log, { start: 150, end: 200 }); + + expect(stats.selfByCategory.get('Apex')).toBeCloseTo(50, 3); + expect(stats.selfByCategory.has('SOQL')).toBe(false); + }); + + it('holds none of a parent whose child fills the window', async () => { + const log = logOf([ + ev(0, 100, { category: 'Apex', children: [ev(10, 90, { category: 'SOQL' })] }), + ]); + + const stats = await statsFor(log, { start: 20, end: 80 }); + + expect(stats.selfByCategory.get('Apex')).toBeUndefined(); + expect(stats.selfByCategory.get('SOQL')).toBeCloseTo(60, 3); + }); + + // A child running past its parent's exit must not lend it negative time. + it('never gives a frame less than nothing', async () => { + const log = logOf([ + ev(0, 50, { category: 'Apex', children: [ev(10, 90, { category: 'SOQL' })] }), + ]); + + const stats = await statsFor(log, { start: 0, end: 100 }); + + expect(stats.selfByCategory.get('Apex')).toBeCloseTo(10, 3); + }); +}); + +// The point of the index: the viewport moves per frame, so a window must be +// answered without reading the log again. +describe('windowStats index', () => { + const roots = () => Array.from({ length: 4_096 }, (_, i) => ev(i * 100, i * 100 + 100)); + + it('answers a window from the buckets, reading only its edges', async () => { + const { log, visited, reset } = countingLog(roots()); + const index = await windowIndexFor(log, options); + reset(); + + const stats = index.statsFor({ start: 100_000, end: 200_000 }); + + expect(stats.selfByCategory.get('Apex')).toBeCloseTo(100_000, 0); + // The two part buckets at the edges, not 4,096 siblings. + expect(visited()).toBeLessThan(100); + }); + + it('answers a window it has already worked out without reading again', async () => { + const { log, visited, reset } = countingLog(roots()); + const index = await windowIndexFor(log, options); + const window = { start: 100_000, end: 200_000 }; + index.statsFor(window); + reset(); + + index.statsFor(window); + + expect(visited()).toBe(0); + }); + + it('builds one index per log, however many readers ask', async () => { + const { log, visited } = countingLog(roots()); + + const [first, second] = await Promise.all([ + windowIndexFor(log, options), + windowIndexFor(log, options), + ]); + const reads = visited(); + const third = await windowIndexFor(log, options); + + expect(second).toBe(first); + expect(third).toBe(first); + expect(visited()).toBe(reads); + }); +}); diff --git a/log-viewer/src/core/log/windowStats.ts b/log-viewer/src/core/log/windowStats.ts new file mode 100644 index 000000000..3face2ebd --- /dev/null +++ b/log-viewer/src/core/log/windowStats.ts @@ -0,0 +1,560 @@ +/* + * Copyright (c) 2026 Certinia Inc. All rights reserved. + */ +import type { ApexLog, LogEvent } from 'apex-log-parser'; +import type { ReactiveControllerHost } from 'lit'; + +import { DEFAULT_NAMESPACE } from '../utility/CallerNamespace.js'; +import { CHECK_EVERY, frameBudget, type FrameBudgetOptions } from '../utility/FrameBudget.js'; +import { RangeScopeController, sameWindow, type TimeWindow } from './rangeScope.js'; + +/** The statement counters an event carries for itself. */ +export interface WindowCounts { + soqlCount: number; + soqlRowCount: number; + dmlCount: number; + dmlRowCount: number; + soslCount: number; +} + +/** Everything the inspector's sections read for one stretch of the log. */ +export interface WindowStats { + /** Keyed by the parser's own category, which is empty where it has none. */ + selfByCategory: Map; + selfByNamespace: Map; + counts: WindowCounts; +} + +/** Only the yield matters here: the build is never abandoned, so it accepts no + * signal. */ +type BuildOptions = Pick; + +const COUNTERS: ReadonlyArray = [ + 'soqlCount', + 'soqlRowCount', + 'dmlCount', + 'dmlRowCount', + 'soslCount', +]; + +/** Buckets across the log's span. A window's whole buckets are read from a + * running total, so its width costs nothing; only the part bucket at each edge + * is read event by event, and 4,096 buckets leave about a hundred events in + * one on the largest logs. */ +const BUCKETS = 4_096; + +/** + * The events carrying one counter: when they started and when they ended, each + * ascending with its running total. + * + * Only the events carrying the counter are held, so the five runs together are + * about as long as the statements in the log rather than five times its events. + */ +interface CounterRun { + startedAt: Float64Array; + /** One longer than `startedAt`: the total before each entry, then all of it. */ + startedTotal: Float64Array; + endedAt: Float64Array; + endedTotal: Float64Array; +} + +type CounterRuns = Readonly>; + +/** One counter's events as the walk finds them, in three parallel columns. */ +interface Gathered { + starts: number[]; + ends: number[]; + values: number[]; +} + +/** + * The log read once, so any stretch of it can be read at once afterwards. + * + * Self time is bucketed by time and kept as a running total, so a window's + * whole buckets are one subtraction each however wide the window is. Statement + * counts come from running totals by start and by end, so a count is exact with + * no walk at all. + */ +export class WindowIndex { + /** Every section asks for the same window, so one answer serves them all. */ + private _held: { window: TimeWindow; stats: WindowStats } | null = null; + + private readonly _roots: readonly LogEvent[]; + private readonly _start: number; + private readonly _width: number; + private readonly _selfByCategory: ReadonlyMap; + private readonly _selfByNamespace: ReadonlyMap; + private readonly _runs: CounterRuns; + + private constructor( + roots: readonly LogEvent[], + start: number, + width: number, + selfByCategory: ReadonlyMap, + selfByNamespace: ReadonlyMap, + runs: CounterRuns, + ) { + this._roots = roots; + this._start = start; + this._width = width; + this._selfByCategory = selfByCategory; + this._selfByNamespace = selfByNamespace; + this._runs = runs; + } + + /** Reads every event once, yielding between slices so the chart keeps its + * frames (see {@link FrameBudgetOptions}). */ + static async build(log: ApexLog, options: BuildOptions): Promise { + const tick = frameBudget(options); + const start = log.timestamp; + const logEnd = log.exitStamp ?? start; + // A log with no span still needs one bucket for its events to land in. + const width = logEnd > start ? (logEnd - start) / BUCKETS : 1; + const selfByCategory = new Map(); + const selfByNamespace = new Map(); + const gathered: Readonly> = { + soqlCount: gatherer(), + soqlRowCount: gatherer(), + dmlCount: gatherer(), + dmlRowCount: gatherer(), + soslCount: gatherer(), + }; + + // Reassigned per event, so the gap visitor below is allocated once for the + // whole walk rather than once per event. + let intoCategory = bucketsFor(selfByCategory, ''); + let intoNamespace = bucketsFor(selfByNamespace, ''); + const bucket = (from: number, to: number): void => { + spread(intoCategory, intoNamespace, from, to, start, width); + }; + + const stack = [...log.children]; + for (let walked = 0; stack.length; walked++) { + if (walked % CHECK_EVERY === 0) { + await tick(); + } + const event = stack.pop()!; // non-empty: the loop condition just checked + intoCategory = bucketsFor(selfByCategory, event.category); + intoNamespace = bucketsFor(selfByNamespace, event.namespace || DEFAULT_NAMESPACE); + const children = event.children; + eachSelfGap(event, 0, children.length, bucket); + + const from = event.timestamp; + const to = endOf(event); + gather(gathered.soqlCount, from, to, event.soqlCount.self); + gather(gathered.soqlRowCount, from, to, event.soqlRowCount.self); + gather(gathered.dmlCount, from, to, event.dmlCount.self); + gather(gathered.dmlRowCount, from, to, event.dmlRowCount.self); + gather(gathered.soslCount, from, to, event.soslCount.self); + + for (let i = 0; i < children.length; i++) { + stack.push(children[i]!); + } + } + + for (const buckets of selfByCategory.values()) { + cumulate(buckets); + } + for (const buckets of selfByNamespace.values()) { + cumulate(buckets); + } + // The sorts scale with the statements in the log, so they yield too. + await tick(); + const runs: CounterRuns = { + soqlCount: runOf(gathered.soqlCount), + soqlRowCount: runOf(gathered.soqlRowCount), + dmlCount: runOf(gathered.dmlCount), + dmlRowCount: runOf(gathered.dmlRowCount), + soslCount: runOf(gathered.soslCount), + }; + return new WindowIndex(log.children, start, width, selfByCategory, selfByNamespace, runs); + } + + /** Self time by category and by namespace, and the statements run, for the + * stretch of log `window` covers. */ + statsFor(window: TimeWindow): WindowStats { + if (this._held && sameWindow(this._held.window, window)) { + return this._held.stats; + } + const stats: WindowStats = { + selfByCategory: new Map(), + selfByNamespace: new Map(), + counts: this._countsFor(window), + }; + const firstWhole = Math.max(0, Math.ceil((window.start - this._start) / this._width)); + const lastWhole = Math.min( + BUCKETS - 1, + Math.floor((window.end - this._start) / this._width) - 1, + ); + if (lastWhole >= firstWhole) { + addBuckets(stats.selfByCategory, this._selfByCategory, firstWhole, lastWhole); + addBuckets(stats.selfByNamespace, this._selfByNamespace, firstWhole, lastWhole); + const opens = this._start + firstWhole * this._width; + const closes = this._start + (lastWhole + 1) * this._width; + addSelfTime(this._roots, { start: window.start, end: opens }, stats); + addSelfTime(this._roots, { start: closes, end: window.end }, stats); + } else { + // Too narrow to hold a whole bucket, so all of it is an edge. + addSelfTime(this._roots, window, stats); + } + this._held = { window, stats }; + return stats; + } + + /** + * The statements the whole log reports one by one. + * + * A counter reading zero here has no windowed value at all: the log names no + * statement for it, so a whole-log figure from the cumulative block cannot be + * cut into windows. + */ + get logCounts(): WindowCounts { + const total = (counter: keyof WindowCounts): number => { + const run = this._runs[counter]; + return run.startedTotal[run.startedTotal.length - 1]!; + }; + return { + soqlCount: total('soqlCount'), + soqlRowCount: total('soqlRowCount'), + dmlCount: total('dmlCount'), + dmlRowCount: total('dmlRowCount'), + soslCount: total('soslCount'), + }; + } + + /** + * The statements `window` reaches any part of. + * + * Everything that had started by the end of the window, less everything that + * had finished before it opened. A statement the window cuts across is left + * in, since it did run in the window. + */ + private _countsFor(window: TimeWindow): WindowCounts { + const counts: WindowCounts = { + soqlCount: 0, + soqlRowCount: 0, + dmlCount: 0, + dmlRowCount: 0, + soslCount: 0, + }; + for (const counter of COUNTERS) { + const run = this._runs[counter]; + const started = firstIndexWhere(run.startedAt.length, (i) => run.startedAt[i]! > window.end); + const ended = firstIndexWhere(run.endedAt.length, (i) => run.endedAt[i]! >= window.start); + counts[counter] = run.startedTotal[started]! - run.endedTotal[ended]!; + } + return counts; + } +} + +const indexes = new WeakMap(); +const building = new WeakMap>(); + +/** + * The index for `log`, read once and then shared. + * + * One build answers every reader, and nothing abandons it: the window moves with + * the gesture, so a build tied to one window would restart per frame and never + * finish. + */ +export function windowIndexFor(log: ApexLog, options: BuildOptions = {}): Promise { + const held = indexes.get(log); + if (held) { + return Promise.resolve(held); + } + let inFlight = building.get(log); + if (!inFlight) { + inFlight = WindowIndex.build(log, options) + .then((index) => { + indexes.set(log, index); + return index; + }) + // A build that threw must not stay cached, or every later reader inherits + // the same failure. + .finally(() => building.delete(log)); + building.set(log, inFlight); + } + return inFlight; +} + +function gather(into: Gathered, start: number, end: number, value: number): void { + if (value === 0) { + return; + } + into.starts.push(start); + into.ends.push(end); + into.values.push(value); +} + +const gatherer = (): Gathered => ({ starts: [], ends: [], values: [] }); + +/** One counter's gathered events as two ascending runs with running totals. */ +function runOf(gathered: Gathered): CounterRun { + const [startedAt, startedTotal] = runningTotal(gathered.starts, gathered.values); + const [endedAt, endedTotal] = runningTotal(gathered.ends, gathered.values); + return { startedAt, startedTotal, endedAt, endedTotal }; +} + +/** `times` in ascending order, with the total of the `values` before each one. */ +function runningTotal(times: number[], values: number[]): [Float64Array, Float64Array] { + const order = times.map((_, index) => index).sort((a, b) => times[a]! - times[b]!); + const at = new Float64Array(order.length); + const total = new Float64Array(order.length + 1); + for (let i = 0; i < order.length; i++) { + at[i] = times[order[i]!]!; + total[i + 1] = total[i]! + values[order[i]!]!; + } + return [at, total]; +} + +function bucketsFor(series: Map, key: string): Float64Array { + let buckets = series.get(key); + if (!buckets) { + // One longer than the buckets, so the total after the last one has a slot. + buckets = new Float64Array(BUCKETS + 1); + series.set(key, buckets); + } + return buckets; +} + +/** + * Calls `visit` for each stretch of `event`'s own time between the children + * `from` up to `to`. + * + * An event's own time sits in the gaps between its children, and those gaps + * never overlap another event's, anywhere in the tree. So bucketing every gap + * fills each bucket with exactly the self time inside it, and clipping the gaps + * of one run gives exactly the self time a window holds. Only the gaps around + * the run can reach a window: every earlier child ends before it opens, so the + * gaps among them do too. + */ +function eachSelfGap( + event: LogEvent, + from: number, + to: number, + visit: (start: number, end: number) => void, +): void { + const children = event.children; + const end = event.exitStamp ?? event.timestamp; + // The gap reaching the run opens where the child before it ended. + let cursor = from > 0 ? Math.max(event.timestamp, endOf(children[from - 1]!)) : event.timestamp; + for (let i = from; i < to; i++) { + const child = children[i]!; + if (child.timestamp > cursor) { + visit(cursor, child.timestamp); + } + cursor = Math.max(cursor, child.exitStamp ?? child.timestamp); + } + if (end > cursor) { + visit(cursor, end); + } +} + +/** Adds [from, to) to both series, split where it crosses a bucket edge. */ +function spread( + category: Float64Array, + namespace: Float64Array, + from: number, + to: number, + start: number, + width: number, +): void { + const last = bucketOf(to, start, width); + for (let bucket = bucketOf(from, start, width); bucket <= last; bucket++) { + const opens = start + bucket * width; + const held = Math.min(to, opens + width) - Math.max(from, opens); + if (held > 0) { + category[bucket]! += held; + namespace[bucket]! += held; + } + } +} + +function bucketOf(at: number, start: number, width: number): number { + return Math.min(BUCKETS - 1, Math.max(0, Math.floor((at - start) / width))); +} + +/** Turns bucket totals into running totals, so `buckets[b]` becomes everything + * before bucket `b` and a run of buckets is one subtraction. */ +function cumulate(buckets: Float64Array): void { + let running = 0; + for (let bucket = 0; bucket <= BUCKETS; bucket++) { + const held = buckets[bucket]!; + buckets[bucket] = running; + running += held; + } +} + +function addBuckets( + into: Map, + series: ReadonlyMap, + firstWhole: number, + lastWhole: number, +): void { + for (const [key, buckets] of series) { + const held = buckets[lastWhole + 1]! - buckets[firstWhole]!; + if (held > 0) { + add(into, key, held); + } + } +} + +/** + * Adds the own time inside `window` to `stats`, event by event. + * + * Only the part bucket at a window's edge is read this way, so this walks a few + * events. + */ +function addSelfTime(roots: readonly LogEvent[], window: TimeWindow, stats: WindowStats): void { + if (window.end <= window.start) { + return; + } + const stack: LogEvent[] = []; + pushReached(stack, roots, window); + while (stack.length) { + const event = stack.pop()!; // non-empty: the loop condition just checked + const children = event.children; + const { from, to } = reachedRun(children, window); + let self = 0; + eachSelfGap(event, from, to, (start, end) => { + self += overlapOf(start, end, window); + }); + if (self > 0) { + // The parser's own category, named for display by the reader: `core/` + // holds no display strings. + add(stats.selfByCategory, event.category, self); + add(stats.selfByNamespace, event.namespace || DEFAULT_NAMESPACE, self); + } + for (let i = from; i < to; i++) { + stack.push(children[i]!); + } + } +} + +function pushReached(stack: LogEvent[], children: readonly LogEvent[], window: TimeWindow): void { + const { from, to } = reachedRun(children, window); + for (let i = from; i < to; i++) { + stack.push(children[i]!); + } +} + +/** + * The run of `children` that `window` reaches, as [from, to). + * + * Siblings run one after another and never overlap, so both their starts and + * their ends ascend and the run is contiguous: two binary searches find it, + * where testing every child would read the whole log. An unclosed frame reads as + * reaching forever, so a truncated log's last frames are walked, not dropped. + */ +function reachedRun( + children: readonly LogEvent[], + window: TimeWindow, +): { from: number; to: number } { + return { + from: firstIndexWhere(children.length, (i) => endOf(children[i]!) >= window.start), + to: firstIndexWhere(children.length, (i) => children[i]!.timestamp > window.end), + }; +} + +/** The leftmost index below `length` where `holds` becomes true, or `length` if + * it never does. `holds` must be false then true across the run. */ +function firstIndexWhere(length: number, holds: (index: number) => boolean): number { + let low = 0; + let high = length; + while (low < high) { + const mid = (low + high) >>> 1; + if (holds(mid)) { + high = mid; + } else { + low = mid + 1; + } + } + return low; +} + +function endOf(event: LogEvent): number { + return event.exitStamp ?? Number.POSITIVE_INFINITY; +} + +/** The length of [start, end) that falls inside `window`. */ +function overlapOf(start: number, end: number, window: TimeWindow): number { + return Math.max(0, Math.min(end, window.end) - Math.max(start, window.start)); +} + +function add(totals: Map, key: string, value: number): void { + totals.set(key, (totals.get(key) ?? 0) + value); +} + +/** + * The stats for the window on screen. + * + * Follows the window through a {@link RangeScopeController}, and derives the + * stats from the log's index rather than holding a copy: the index is built on + * the first window and shared, so every window after it is answered inside the + * frame that asked. + */ +export class WindowStatsController { + private readonly _range: RangeScopeController; + private readonly _host: ReactiveControllerHost; + private readonly _log: () => ApexLog | null; + private _awaiting: ApexLog | null = null; + + constructor(host: ReactiveControllerHost, log: () => ApexLog | null) { + this._host = host; + this._log = log; + this._range = new RangeScopeController(host); + } + + /** The window on screen, or null for the whole log. */ + get window(): TimeWindow | null { + return this._range.window; + } + + /** The window's stats, or null while they are still being added up. Always + * null where {@link window} is. */ + get stats(): WindowStats | null { + const window = this._range.window; + const log = this._log(); + if (!window || !log) { + return null; + } + const index = indexes.get(log); + if (index) { + return index.statsFor(window); + } + this._readLog(log); + return null; + } + + /** The window's statement counts beside the whole log's, or null where the + * whole log is the scope. */ + get counts(): { counts: WindowCounts; logCounts: WindowCounts } | null { + const window = this._range.window; + const log = this._log(); + const index = window && log ? indexes.get(log) : undefined; + return index && window + ? { counts: index.statsFor(window).counts, logCounts: index.logCounts } + : null; + } + + /** True while a window is on screen and its stats are not ready yet. */ + get pending(): boolean { + return this._range.window !== null && this.stats === null; + } + + private _readLog(log: ApexLog): void { + if (this._awaiting === log) { + return; + } + this._awaiting = log; + void windowIndexFor(log) + .then(() => { + if (this._awaiting === log) { + this._host.requestUpdate(); + } + }) + // A build only fails on a log the parser cannot walk. The section keeps + // its "adding up" note rather than retrying it every render. + .catch(() => {}); + } +} diff --git a/scripts/measure/measure.ts b/scripts/measure/measure.ts index f15e32033..7a498ce4b 100644 --- a/scripts/measure/measure.ts +++ b/scripts/measure/measure.ts @@ -24,6 +24,7 @@ import { type ScopedRow, } from '../../log-viewer/src/components/scopedCallTree.js'; import { LogStore, setCurrentLog } from '../../log-viewer/src/core/log/LogStore.js'; +import { windowIndexFor } from '../../log-viewer/src/core/log/windowStats.js'; import { toAggregatedCallTree, toBottomUpTree, @@ -134,3 +135,39 @@ console.log(''); const gridPaths = new LogStore(log).keyPathIds(); await time('grid toAggregatedCallTree', () => toAggregatedCallTree(log.children, gridPaths)); await time('grid toBottomUpTree', () => toBottomUpTree(log.children, gridPaths)); + +// The inspector's range scope: a viewport move must not read the whole log. +console.log(''); +const logStart = log.timestamp; +const logSpan = (log.exitStamp ?? logStart) - logStart; +const at = (from: number, share: number) => ({ + start: logStart + logSpan * from, + end: logStart + logSpan * (from + share), +}); + +// One read of the log, then every window is answered from it. The heap column +// is what the index costs. +const index = await time('windowIndex build', () => windowIndexFor(log, { yieldSlice })); + +for (const [label, share] of [ + ['narrow (8%)', 0.08], + ['half (50%)', 0.5], + ['wide (90%)', 0.9], + ['whole log', 1], +] as const) { + const window = at(share === 1 ? 0 : 0.05, share); + const stats = await time(`windowIndex statsFor ${label}`, () => index.statsFor(window)); + const total = [...stats.selfByCategory.values()].reduce((sum, held) => sum + held, 0); + console.log( + ` ${stats.selfByCategory.size} categories, ${stats.selfByNamespace.size} namespaces, ${Math.round(total / 1_000_000)}ms self, ${stats.counts.soqlCount} SOQL`, + ); +} + +// A drag: a window per frame, none of them the same. This is the number that +// decides whether the figures can follow the gesture. +const frames = 60; +await time(`windowIndex statsFor x${frames} (a drag)`, () => { + for (let frame = 0; frame < frames; frame++) { + index.statsFor(at(frame / (frames * 4), 0.25)); + } +}); From c06d6b23df5847c0c6cd6d6f3ada05fb06b45f65 Mon Sep 17 00:00:00 2001 From: Luke Cotter <4013877+lukecotter@users.noreply.github.com> Date: Wed, 2 Sep 2026 15:39:27 +0100 Subject: [PATCH 5/7] feat(log-viewer): read time by category and namespace for the timeline's window Over a whole log these two bars answer a question the log level already answers. Over a window they invert: on one 100MB log, System goes from 11% of the log to 61% of a window, Automation from 7.7% to 35%, and one package from 2.5% to 15.4%. That is the reading a user zooms in to get. Both read the window from the index. A selection still wins over it: a picked frame is answered as itself, wherever the timeline is looking. While the window answers, the whole-log walk waits, since its result would be thrown away. The shared event fixture now lays its tree out in time, so a windowed test reads real figures rather than passing because a window scores everything zero. --- log-viewer/src/components/CategoryTimeBar.ts | 32 +++++++++--- log-viewer/src/components/NamespaceTimeBar.ts | 39 ++++++++++++--- .../__tests__/NamespaceTimeBar.test.ts | 44 ++++++++++++++++ .../__tests__/fixtures/logEvents.ts | 50 +++++++++++++++++-- log-viewer/src/components/categoryTime.ts | 19 ++++--- log-viewer/src/components/namespaceTime.ts | 5 ++ 6 files changed, 165 insertions(+), 24 deletions(-) diff --git a/log-viewer/src/components/CategoryTimeBar.ts b/log-viewer/src/components/CategoryTimeBar.ts index bcb76758f..c417d4bde 100644 --- a/log-viewer/src/components/CategoryTimeBar.ts +++ b/log-viewer/src/components/CategoryTimeBar.ts @@ -6,21 +6,25 @@ import { LitElement, html } from 'lit'; import { customElement, property } from 'lit/decorators.js'; import { logContext } from '../core/log/logContext.js'; +import { WindowStatsController } from '../core/log/windowStats.js'; import type { LogStore } from '../core/log/LogStore.js'; import { globalStyles } from '../styles/global.styles.js'; import { inspectorSectionStyles } from '../styles/inspectorSection.styles.js'; -import { CategoryPaletteController, categorySelfTimes } from './categoryTime.js'; +import { CategoryPaletteController, categorySelfTimes, toCategoryTimes } from './categoryTime.js'; import './StackedTimeBar.js'; /** - * The whole log's self time split by category, as one stacked bar in the flame - * chart's own palette — the Inspector's answer to Chrome DevTools' Summary - * donut. Self time, so every nanosecond lands in exactly one segment and the bar - * always totals the log. + * Self time split by category, as one stacked bar in the flame chart's own + * palette. Self time, so every nanosecond lands in exactly one segment and the + * bar always totals its scope. + * + * The scope is the window the Timeline is showing, or the whole log when it + * shows all of it. */ @customElement('category-time-bar') export class CategoryTimeBar extends LitElement { private readonly _palette = new CategoryPaletteController(this); + private readonly _window = new WindowStatsController(this, () => this.logStore?.log ?? null); /** The log on screen, from the app root. */ @consume({ context: logContext, subscribe: true }) @@ -30,10 +34,24 @@ export class CategoryTimeBar extends LitElement { static styles = [globalStyles, inspectorSectionStyles]; render() { + if (this._window.pending) { + return html`

Adding up the self time…

`; + } const apexLog = this.logStore?.log; - const slices = apexLog ? categorySelfTimes(apexLog) : []; + const windowed = this._window.stats; + const slices = windowed + ? toCategoryTimes(windowed.selfByCategory) + : apexLog + ? categorySelfTimes(apexLog) + : []; if (!slices.length) { - return html`

No categorised time was recorded in this log.

`; + return html`

+ ${ + this._window.window + ? 'No categorised time was recorded in this range.' + : 'No categorised time was recorded in this log.' + } +

`; } return html` string) | null = null; + private readonly _window = new WindowStatsController(this, () => this.logStore?.log ?? null); static styles = [globalStyles, inspectorSectionStyles]; render() { - const slices = this._slices; + let slices = this._slices; + if (this._windowScoped()) { + const windowed = this._window.stats; + slices = windowed ? toNamespaceTimes(windowed.selfByNamespace) : null; + } if (!slices) { return html`

Adding up the self time…

`; } - const color = this._color; - if (!slices.length || !color) { + // The palette is the log's, so it stands whatever the scope is: the window + // answers without the scope walk that used to resolve it. + const log = this.logStore?.log; + if (!slices.length || !log) { return html`

No time was recorded here.

`; } + const color = logNamespacePalette(log); const segments = segmentsWithTail(slices, (slice) => ({ label: slice.namespace, value: slice.selfTime, @@ -109,6 +117,11 @@ export class NamespaceTimeBar extends LitElement { } protected updated(changed: PropertyValues): void { + // The window answers on its own, so a whole-log walk now would be thrown + // away. It waits until the window clears or a selection takes over. + if (this._windowScoped()) { + return; + } // Resolving a scope maps every instance index, so only a changed selection — // or a scope we have yet to resolve — earns the walk. if (changed.has('eventIndex') || changed.has('instances') || this._scopeKey === UNRESOLVED) { @@ -130,7 +143,6 @@ export class NamespaceTimeBar extends LitElement { this._slices = []; return; } - this._color = logNamespacePalette(scope.log); // A scope walked before answers now, so a re-selection shows no placeholder. this._slices = cachedNamespaceSelfTimes(scope.key) ?? null; if (this._slices) { @@ -151,6 +163,17 @@ export class NamespaceTimeBar extends LitElement { } } + /** True where the section answers for a picked frame or aggregate. */ + private _selected(): boolean { + return this.eventIndex >= 0 || !!this.instances?.length; + } + + /** True where the window is the scope. A selection wins over it: a picked + * frame is answered as itself, wherever the timeline is looking. */ + private _windowScoped(): boolean { + return !this._selected() && this._window.window !== null; + } + private _scope(): Scope | null { const store = this.logStore; if (!store) { diff --git a/log-viewer/src/components/__tests__/NamespaceTimeBar.test.ts b/log-viewer/src/components/__tests__/NamespaceTimeBar.test.ts index ca4cde2af..3a358d99d 100644 --- a/log-viewer/src/components/__tests__/NamespaceTimeBar.test.ts +++ b/log-viewer/src/components/__tests__/NamespaceTimeBar.test.ts @@ -9,6 +9,7 @@ import type { ApexLog } from 'apex-log-parser'; let apexLog: ApexLog | null = null; import type { LogStore } from '../../core/log/LogStore.js'; +import { setRange } from '../../core/log/rangeScope.js'; import type { NamespaceTimeBar } from '../NamespaceTimeBar.js'; import { DEFAULT_MAX_SEGMENTS } from '../StackedTimeBar.js'; import '../NamespaceTimeBar.js'; @@ -49,6 +50,7 @@ describe('namespace-time-bar', () => { document.body.replaceChildren(); resetEvents(); apexLog = null; + setRange(null); }); it('splits the whole log by namespace, largest first', async () => { @@ -124,3 +126,45 @@ describe('namespace-time-bar', () => { expect(element.shadowRoot?.querySelector('.note')?.textContent).toContain('No time'); }); }); + +describe('namespace-time-bar with a timeline window', () => { + beforeEach(() => { + document.body.replaceChildren(); + resetEvents(); + apexLog = null; + setRange(null); + }); + + afterEach(() => { + setRange(null); + }); + + // A picked frame is answered as itself, wherever the timeline is looking: the + // window here holds a nanosecond, so its own figures could not be these. + it('answers for the picked frame, not the window', async () => { + logOf([ev('default', 100, [ev('pkg', 500)])], ['pkg']); + setRange({ start: 0, end: 1 }); + + // Children register first, so the outer `default` frame is index 1. + const element = await mount({ eventIndex: 1 }); + + expect(segments(element).map((segment) => segment.label)).toEqual(['pkg', 'default']); + expect(segments(element).map((segment) => segment.value)).toEqual([500, 100]); + }); + + // The bar took its palette from the whole-log walk, which a window skips, so + // mounting into a window left it with no colours and an empty note. + it('answers for a window it mounts into', async () => { + logOf([ev('default', 100, [ev('pkg', 500)])], ['pkg']); + // `default` owns 0 to 100, `pkg` 100 to 600. + setRange({ start: 0, end: 350 }); + + const element = await mount(); + const bars = segments(element); + + expect(bars.map((segment) => segment.label)).toEqual(['pkg', 'default']); + expect(bars[0]?.value).toBeCloseTo(250, 3); + expect(bars[1]?.value).toBeCloseTo(100, 3); + expect(bars[0]?.color).toBe(logNamespacePalette(apexLog!)('pkg')); + }); +}); diff --git a/log-viewer/src/components/__tests__/fixtures/logEvents.ts b/log-viewer/src/components/__tests__/fixtures/logEvents.ts index ff153548e..2a8a961e7 100644 --- a/log-viewer/src/components/__tests__/fixtures/logEvents.ts +++ b/log-viewer/src/components/__tests__/fixtures/logEvents.ts @@ -3,15 +3,31 @@ */ import type { ApexLog, LogEvent } from 'apex-log-parser'; -/** Only the fields the namespace walk reads. */ +interface Count { + self: number; + total: number; +} + +/** Only the fields the namespace walk and the window index read. */ export interface FakeEvent { eventIndex: number; namespace: string; + category: string; duration: { total: number; self: number }; + /** Laid out by {@link log}, which is what puts the tree in time. */ + timestamp: number; + exitStamp: number; + soqlCount: Count; + soqlRowCount: Count; + dmlCount: Count; + dmlRowCount: Count; + soslCount: Count; children: FakeEvent[]; parent?: FakeEvent; } +const count = (): Count => ({ self: 0, total: 0 }); + const registry: FakeEvent[] = []; /** @@ -22,10 +38,18 @@ export function ev(namespace: string, self: number, children: FakeEvent[] = []): const event: FakeEvent = { eventIndex: registry.length, namespace, + category: 'Apex', duration: { total: self + children.reduce((sum, child) => sum + child.duration.total, 0), self, }, + timestamp: 0, + exitStamp: 0, + soqlCount: count(), + soqlRowCount: count(), + dmlCount: count(), + dmlRowCount: count(), + soslCount: count(), children, }; for (const child of children) { @@ -46,5 +70,25 @@ export function eventByIndex(index: number): FakeEvent | null { export const roots = (events: FakeEvent[]) => events as unknown as LogEvent[]; -export const log = (children: FakeEvent[], namespaces: string[] = []) => - ({ children, namespaces }) as unknown as ApexLog; +/** + * Lays `event` out from `start` and returns where it ends: its own time first, + * then its children back to back. A windowed read needs real timestamps, and + * this keeps each event's own time exactly its `duration.self`. + */ +function layOut(event: FakeEvent, start: number): number { + event.timestamp = start; + let cursor = start + event.duration.self; + for (const child of event.children) { + cursor = layOut(child, cursor); + } + event.exitStamp = cursor; + return cursor; +} + +export const log = (children: FakeEvent[], namespaces: string[] = []) => { + let cursor = 0; + for (const child of children) { + cursor = layOut(child, cursor); + } + return { children, namespaces, timestamp: 0, exitStamp: cursor } as unknown as ApexLog; +}; diff --git a/log-viewer/src/components/categoryTime.ts b/log-viewer/src/components/categoryTime.ts index 4b3442df6..9ff9f29f6 100644 --- a/log-viewer/src/components/categoryTime.ts +++ b/log-viewer/src/components/categoryTime.ts @@ -61,20 +61,27 @@ export function categorySelfTimes(root: ApexLog): CategoryTime[] { while (stack.length) { const event = stack.pop()!; // non-empty: the loop condition just checked - const category = categoryName(event.category); - totals.set(category, (totals.get(category) ?? 0) + event.duration.self); + totals.set(event.category, (totals.get(event.category) ?? 0) + event.duration.self); for (const child of event.children) { stack.push(child); } } - const slices = [...totals] - .filter(([, selfTime]) => selfTime > 0) - .map(([category, selfTime]) => ({ category, selfTime })) - .sort((a, b) => b.selfTime - a.selfTime); + const slices = toCategoryTimes(totals); selfTimesCache.set(root, slices); return slices; } +/** + * Self time per raw category, named and ranked for display: empty buckets go, + * an uncategorised event lands in {@link OTHER_CATEGORY}, largest first. + */ +export function toCategoryTimes(totals: ReadonlyMap): CategoryTime[] { + return [...totals] + .filter(([, selfTime]) => selfTime > 0) + .map(([category, selfTime]) => ({ category: categoryName(category), selfTime })) + .sort((a, b) => b.selfTime - a.selfTime); +} + /** * The flame chart's own colour for each category, resolved the way * `TimelineView` resolves it: the active theme (custom themes registered diff --git a/log-viewer/src/components/namespaceTime.ts b/log-viewer/src/components/namespaceTime.ts index 9efee3acf..4b5831f54 100644 --- a/log-viewer/src/components/namespaceTime.ts +++ b/log-viewer/src/components/namespaceTime.ts @@ -38,6 +38,11 @@ async function namespaceSelfTimes( stack.push(child); } } + return toNamespaceTimes(totals); +} + +/** Self time per namespace, ranked for display: empty buckets go, largest first. */ +export function toNamespaceTimes(totals: ReadonlyMap): NamespaceTime[] { return [...totals] .filter(([, selfTime]) => selfTime > 0) .map(([namespace, selfTime]) => ({ namespace, selfTime })) From 024f79a3da01efef3893d083a7f08b667520a2f0 Mon Sep 17 00:00:00 2001 From: Luke Cotter <4013877+lukecotter@users.noreply.github.com> Date: Wed, 2 Sep 2026 15:40:00 +0100 Subject: [PATCH 6/7] feat(log-viewer): count a window's statements from its own events The Overview renders first, so whole-log governor figures above windowed ones is the confusion to avoid. The statements a window ran now come from the events themselves. Not from the cumulative snapshots, which are far too sparse to window: one 100MB log carries two readings across 27 seconds, so a delta reads zero for windows where statements provably ran. - Every whole-log row stays, in whole-log order, showing 0 where the window ran none. Rows that appear and vanish under a drag are worse than a zero. - CPU time and heap keep their whole-log figure and say so: the log reports them only in total, and a user who narrowed the view still needs to know the transaction breached. - A counter the log never reported statement by statement also keeps its whole-log figure. Its total came from the cumulative block, which no window can cut, and reading 0 would say no statements ran. - The window is a Timeline idea, so the Overview on every other tab reads the whole log. The tab panels all stay mounted, so it has to be told. --- log-viewer/src/components/LogOverview.ts | 25 +++++- .../__tests__/logOverviewMetrics.test.ts | 77 +++++++++++++++++++ log-viewer/src/components/detailSections.ts | 2 +- .../src/components/logOverviewMetrics.ts | 46 ++++++++--- .../database/components/GovernorSummary.ts | 9 ++- 5 files changed, 143 insertions(+), 16 deletions(-) diff --git a/log-viewer/src/components/LogOverview.ts b/log-viewer/src/components/LogOverview.ts index e76cc0087..f409956d6 100644 --- a/log-viewer/src/components/LogOverview.ts +++ b/log-viewer/src/components/LogOverview.ts @@ -6,6 +6,7 @@ import { LitElement, css, html } from 'lit'; import { customElement, property } from 'lit/decorators.js'; import { logContext } from '../core/log/logContext.js'; +import { WindowStatsController } from '../core/log/windowStats.js'; import type { LogStore } from '../core/log/LogStore.js'; import { apexLimitTimeSeries } from '../features/timeline/optimised/apex-limit-series.js'; import { globalStyles } from '../styles/global.styles.js'; @@ -19,9 +20,14 @@ import { import '../features/database/components/GovernorSummary.js'; /** - * The inspector's whole-log section, shown while nothing is selected: the - * governor metrics nearest a limit, read from the metric strip's series so the - * figures always match the timeline and the trend charts. + * The inspector's unselected section: the governor metrics nearest a limit, + * read from the metric strip's series so the figures always match the timeline + * and the trend charts. + * + * On the Timeline tab, while the chart shows part of the log, the statements are + * counted for that window instead, from the events themselves. CPU time and heap + * have no windowed value and stay whole-log. Every other tab passes `wholeLog`, + * since a window is a Timeline idea. * * Log size and duration are deliberately absent — `LogMeta` heads the app with * both. @@ -33,6 +39,13 @@ export class LogOverview extends LitElement { @property({ attribute: false }) logStore: LogStore | null = null; + /** True keeps the whole-log figures whatever the Timeline is showing. The + * window is a Timeline idea, and every other tab scopes by its own row. */ + @property({ type: Boolean }) + wholeLog = false; + + private readonly _window = new WindowStatsController(this, () => this.logStore?.log ?? null); + static styles = [ globalStyles, css` @@ -54,7 +67,11 @@ export class LogOverview extends LitElement { render() { const apexLog = this.logStore?.log; - const gauges = apexLog ? seriesGauges(apexLimitTimeSeries(apexLog)) : []; + if (!this.wholeLog && this._window.pending) { + return html`

Adding up the governor usage…

`; + } + const window = this.wholeLog ? null : this._window.counts; + const gauges = apexLog ? seriesGauges(apexLimitTimeSeries(apexLog), window ?? undefined) : []; if (!apexLog || !gauges.length) { return html`

${NO_CUMULATIVE_LIMITS_TEXT}

`; } diff --git a/log-viewer/src/components/__tests__/logOverviewMetrics.test.ts b/log-viewer/src/components/__tests__/logOverviewMetrics.test.ts index c288370ff..da74e74b2 100644 --- a/log-viewer/src/components/__tests__/logOverviewMetrics.test.ts +++ b/log-viewer/src/components/__tests__/logOverviewMetrics.test.ts @@ -3,6 +3,7 @@ */ import { describe, expect, it } from '@jest/globals'; +import type { WindowCounts } from '../../core/log/windowStats.js'; import { GOVERNOR_METRICS, limitTotals, seriesGauges } from '../logOverviewMetrics.js'; import { emptyLimits, seriesEvent, timeSeries } from './limitsTestUtils.js'; @@ -110,3 +111,79 @@ describe('seriesGauges', () => { expect(seriesGauges(timeSeries([]))).toEqual([]); }); }); + +describe('seriesGauges for a window', () => { + const none = { + soqlCount: 0, + soqlRowCount: 0, + dmlCount: 0, + dmlRowCount: 0, + soslCount: 0, + }; + + /** The log reports these statements one by one, so they are windowable. */ + const reported = { ...none, soqlCount: 9, dmlCount: 4 }; + const windowOf = (counts: WindowCounts, logCounts: WindowCounts = reported) => ({ + counts, + logCounts, + }); + + const series = () => + timeSeries([ + seriesEvent(1_000, { + cpuTime: { used: 15_163, limit: 10_000 }, + soqlQueries: { used: 9, limit: 100 }, + dmlStatements: { used: 4, limit: 150 }, + heapSize: { used: 219_591, limit: 6_000_000 }, + }), + ]); + + // Rows must not appear, vanish or reorder as the viewport moves. + it('shows the same metrics in the same order as the whole log', () => { + const whole = seriesGauges(series()).map((gauge) => gauge.label); + + expect(seriesGauges(series(), windowOf(none)).map((gauge) => gauge.label)).toEqual(whole); + }); + + it('reads a metric the window did not use as zero, not as missing', () => { + const gauges = seriesGauges(series(), windowOf(none)); + + expect(gauges.find((gauge) => gauge.label === 'SOQL')).toMatchObject({ + used: 0, + found: 0, + limit: 100, + }); + }); + + it('reads what the window ran', () => { + const gauges = seriesGauges(series(), windowOf({ ...none, soqlCount: 6, dmlCount: 2 })); + + expect(gauges.find((gauge) => gauge.label === 'SOQL')).toMatchObject({ used: 6, limit: 100 }); + expect(gauges.find((gauge) => gauge.label === 'DML')).toMatchObject({ used: 2, limit: 150 }); + }); + + // Both are cumulative readings the log reports only in total. + it('keeps CPU time and heap whole-log, and says so', () => { + const gauges = seriesGauges(series(), windowOf(none)); + + expect(gauges.find((gauge) => gauge.label === 'CPU Time')).toMatchObject({ + used: 15_163, + limit: 10_000, + wholeLog: true, + }); + expect(gauges.find((gauge) => gauge.label === 'Heap Size')).toMatchObject({ wholeLog: true }); + expect(gauges.find((gauge) => gauge.label === 'SOQL')?.wholeLog).toBeUndefined(); + }); + + // The whole-log figure then came from the cumulative block, which no window + // can cut. Reading 0 would say no statements ran. + it('keeps a counter the log never reported one by one whole-log', () => { + const gauges = seriesGauges(series(), windowOf(none, none)); + + expect(gauges.find((gauge) => gauge.label === 'SOQL')).toMatchObject({ + used: 9, + limit: 100, + wholeLog: true, + }); + }); +}); diff --git a/log-viewer/src/components/detailSections.ts b/log-viewer/src/components/detailSections.ts index 12bbddf61..e4fe07c48 100644 --- a/log-viewer/src/components/detailSections.ts +++ b/log-viewer/src/components/detailSections.ts @@ -59,7 +59,7 @@ export async function buildDetailSections( id: 'overview', title: 'Overview', fit: 'content', - content: html``, + content: html``, }, ]; if (source === 'calltree') { diff --git a/log-viewer/src/components/logOverviewMetrics.ts b/log-viewer/src/components/logOverviewMetrics.ts index e5c5c1126..e9d9d1d42 100644 --- a/log-viewer/src/components/logOverviewMetrics.ts +++ b/log-viewer/src/components/logOverviewMetrics.ts @@ -3,6 +3,7 @@ */ import type { Limits } from 'apex-log-parser'; +import type { WindowCounts } from '../core/log/windowStats.js'; import { formatByteSize } from '../core/utility/Util.js'; import type { GaugeMetric } from '../features/database/components/GovernorSummary.js'; import type { HeatStripTimeSeries } from '../features/timeline/types/flamechart.types.js'; @@ -124,17 +125,42 @@ export function rankedLimitMetrics(series: HeatStripTimeSeries, max: number): Ra .slice(0, max); } +/** The governor metric each windowable statement counter consumes. A metric + * absent here has no windowed value, so it keeps its whole-log figure. */ +const COUNTER_FOR: ReadonlyMap = new Map([ + ['soqlQueries', 'soqlCount'], + ['queryRows', 'soqlRowCount'], + ['dmlStatements', 'dmlCount'], + ['dmlRows', 'dmlRowCount'], + ['soslQueries', 'soslCount'], +]); + /** - * The whole-log gauges closest to a limit, capped at {@link MAX_GAUGES}. - * Without cumulative snapshots the totals are estimates, and the caller shows + * The gauges closest to a limit, capped at {@link MAX_GAUGES}. Without + * cumulative snapshots the totals are estimates, and the caller shows * {@link ESTIMATED_LIMITS_TEXT} alongside them. + * + * Given a `window`, the same metrics in the same order are re-read for it, so no + * row appears, vanishes or moves as the viewport does. A windowable metric then + * shows what the window ran, 0 included; the rest keep their whole-log figure + * and say so, since CPU time and heap are cumulative readings the log reports + * only in total and a user who narrowed the view still needs to know the + * transaction breached. */ -export function seriesGauges(series: HeatStripTimeSeries): GaugeMetric[] { - return rankedLimitMetrics(series, MAX_GAUGES).map(({ key, label, used, limit }) => ({ - label, - found: used, - used, - limit, - ...(key === 'heapSize' ? { format: formatByteSize } : {}), - })); +export function seriesGauges( + series: HeatStripTimeSeries, + window?: { counts: WindowCounts; logCounts: WindowCounts }, +): GaugeMetric[] { + return rankedLimitMetrics(series, MAX_GAUGES).map(({ key, label, used, limit }) => { + const format = key === 'heapSize' ? { format: formatByteSize } : {}; + const counter = window ? COUNTER_FOR.get(key) : undefined; + // A counter the log never reported statement by statement has no windowed + // value: its whole-log figure came from the cumulative block, which no + // window can cut. Reading 0 there would say no statements ran. + if (window && counter && window.logCounts[counter] > 0) { + const held = window.counts[counter]; + return { label, found: held, used: held, limit, ...format }; + } + return { label, found: used, used, limit, ...(window ? { wholeLog: true } : {}), ...format }; + }); } diff --git a/log-viewer/src/features/database/components/GovernorSummary.ts b/log-viewer/src/features/database/components/GovernorSummary.ts index d262784fa..51b061b31 100644 --- a/log-viewer/src/features/database/components/GovernorSummary.ts +++ b/log-viewer/src/features/database/components/GovernorSummary.ts @@ -23,6 +23,9 @@ export interface GaugeMetric { * gauge. */ format?: (value: number) => string; + /** Set where the figure is the transaction's while its neighbours are a + * window's, so no gauge lies about the scope it reports. */ + wholeLog?: boolean; } /** Consumption percentage where a gauge or trend turns from safe to warn. */ @@ -95,10 +98,12 @@ export class GovernorSummary extends LitElement { } .gauge__limit, + .gauge__scope, .gauge__na { color: var(--lana-fg-muted); } + .gauge__scope, .gauge__na { font-size: var(--lana-text-xs); font-style: italic; @@ -165,7 +170,9 @@ export class GovernorSummary extends LitElement { > ${metric.label} ${format(metric.used)} / ${format(metric.limit)}${format(metric.used)} + / ${format(metric.limit)} + ${metric.wholeLog ? html`whole log` : ''}
Date: Wed, 2 Sep 2026 15:40:14 +0100 Subject: [PATCH 7/7] feat(log-viewer): name the window and mark what still reads the whole log Windowed figures with nothing saying so read as wrong figures. The scope toggle's log side now names the window's own bounds, and with no selection those bounds stand on their own above the sections. - The bounds carry enough decimals to keep their two ends apart: a seek window is 2% of the log, where two figures to the same place would say nothing. - The governor trend charts keep the whole series and shade the window on it. Readings are sparse, so a chart clipped to a short window would draw nothing. - The whole-log call tree says it is whole-log rather than contradicting the sections above it in silence. Pruning it to the window is its own problem: a wide window already costs the cheap aggregation 117ms of index build, and a tree needs more. Closes #875 --- CHANGELOG.md | 2 + log-viewer/src/components/GovernorTrends.ts | 16 +++++ log-viewer/src/components/LogInspector.ts | 70 ++++++++++++++++++++- log-viewer/src/components/detailSections.ts | 11 +++- 4 files changed, 95 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6c80d6525..7bfdf72cb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,6 +21,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Every row is a link: click it to reveal the frame, row or statement behind it in the tab you're on. Hover works both ways without moving the view — hover a row to pick out what it names in the tab you're on, or hover there to mark the rows that name it, and what you click stays picked out until `Escape`. Click a point on a governor usage chart to move the Timeline to that instant and zoom in on it. Right-click for copy actions. - **Findings** list the statements behind them, most repeated first with how often each ran, and report one query built per record and run a row at a time. The severities head the list and filter it, any number at once, a finding the log times shows how long it took and what that is of the log, and selecting an Analysis row narrows the list to the findings that name that method or anything it called. - **Detail | Summary** switches between what you picked and the tab's summary of the whole log, keeping the selection to come back to. + - **A timeline range** narrows the Timeline summary to the stretch of log the chart shows, and returns to the whole log when you zoom out. CPU and heap stay whole-log, since the log only reports them in total. ([#875]) - Dock it left, right or bottom, drag to resize any section — double-click a divider to restore the defaults — and collapse the sections you don't need; the layout is remembered. `Escape` clears the selection and returns the whole-log view. ([#63]) - 🗄️ **Database Analysis**: governor-limit visibility and SOSL usage. ([#162]) - 📏 **Governor-limit overview**: SOQL, SOSL, DML and query/DML rows shown as `used / limit`, colored as they approach the limit. @@ -578,6 +579,7 @@ Skipped due to adopting odd numbering for pre releases and even number for relea [#373]: https://github.com/certinia/debug-log-analyzer/issues/373 [#298]: https://github.com/certinia/debug-log-analyzer/issues/298 [#162]: https://github.com/certinia/debug-log-analyzer/issues/162 +[#875]: https://github.com/certinia/debug-log-analyzer/issues/875 [#113]: https://github.com/certinia/debug-log-analyzer/issues/113 [#63]: https://github.com/certinia/debug-log-analyzer/issues/63 [#32]: https://github.com/certinia/debug-log-analyzer/issues/32 diff --git a/log-viewer/src/components/GovernorTrends.ts b/log-viewer/src/components/GovernorTrends.ts index 53bdd72ea..9623a992b 100644 --- a/log-viewer/src/components/GovernorTrends.ts +++ b/log-viewer/src/components/GovernorTrends.ts @@ -7,6 +7,7 @@ import { customElement, property, state } from 'lit/decorators.js'; import { eventBus } from '../core/events/EventBus.js'; import { logContext } from '../core/log/logContext.js'; +import { RangeScopeController } from '../core/log/rangeScope.js'; import type { LogStore } from '../core/log/LogStore.js'; import { formatDuration } from '../core/utility/Util.js'; import { @@ -99,6 +100,8 @@ export class GovernorTrends extends LitElement { @property({ attribute: false }) logStore: LogStore | null = null; + private readonly _range = new RangeScopeController(this); + static styles = [ globalStyles, inspectorSectionStyles, @@ -207,6 +210,11 @@ export class GovernorTrends extends LitElement { stroke-width: 1; vector-effect: non-scaling-stroke; } + + .trend__window { + fill: currentColor; + opacity: 0.12; + } `, ]; @@ -230,6 +238,9 @@ export class GovernorTrends extends LitElement { const { line, area, guideY, x } = trendGeometry(series, logTotal); const cursor = this._cursorFor(series); const cursorX = cursor ? x(cursor.t).toFixed(2) : null; + // The whole log stays on screen and the window is marked on it: readings are + // sparse, so a chart clipped to a short window would draw nothing. + const window = this._range.window; return html`
@@ -258,6 +269,11 @@ export class GovernorTrends extends LitElement { aria-hidden="true" > ${svg` + ${ + window + ? svg`` + : '' + } diff --git a/log-viewer/src/components/LogInspector.ts b/log-viewer/src/components/LogInspector.ts index 9ae779631..cbf4716f3 100644 --- a/log-viewer/src/components/LogInspector.ts +++ b/log-viewer/src/components/LogInspector.ts @@ -1,6 +1,7 @@ /* * Copyright (c) 2026 Certinia Inc. All rights reserved. */ +import { consume } from '@lit/context'; import { LitElement, css, html, type PropertyValues } from 'lit'; import { customElement, property, state } from 'lit/decorators.js'; @@ -11,6 +12,9 @@ import { type SelectionView, eventBus, } from '../core/events/EventBus.js'; +import { logContext } from '../core/log/logContext.js'; +import type { LogStore } from '../core/log/LogStore.js'; +import { RangeScopeController, type TimeWindow } from '../core/log/rangeScope.js'; import type { InspectorLocateEvent, InspectorRevealEvent } from './inspectorReveal.js'; import { debounce } from '../core/utility/Util.js'; import { getSettings, updateSetting } from '../features/settings/Settings.js'; @@ -31,6 +35,20 @@ const SCOPE_OPTIONS: readonly ViewModeOption[] = [ { value: 'log', label: 'Summary' }, ]; +/** + * The window the summary is reading, as elapsed times, so it reads against the + * timeline's own axis. The times say the scope on their own, so nothing labels + * them further. + */ +function windowLabel(window: TimeWindow, logStart: number): string { + // Enough decimals to keep the two ends apart: a seek window is 2% of the log + // and a deep zoom a few milliseconds, where "0.30s to 0.30s" says nothing. + const width = Math.max(window.end - window.start, 1) / 1_000_000_000; + const decimals = Math.min(6, Math.max(2, 2 - Math.floor(Math.log10(width)))); + const seconds = (at: number) => ((at - logStart) / 1_000_000_000).toFixed(decimals); + return `${seconds(window.start)}s to ${seconds(window.end)}s`; +} + /** * The app-wide inspector. Lives at the app root (sibling of the tab strip, * via a forwarded `main` slot) so it crosscuts every tab. It follows the active @@ -134,12 +152,37 @@ export class LogInspector extends LitElement { // the row without the table noticing. this._clearLocate(); void this._rebuild(); + return; + } + // A window appearing or going changes which sections are shown; a viewport + // moving inside one does not, because each section reads the window itself. + if ((this._range.window !== null) !== this._builtWithWindow) { + this._scheduleRebuild(); } } + /** The log on screen, so a window's times read as elapsed. */ + @consume({ context: logContext, subscribe: true }) + @property({ attribute: false }) + logStore: LogStore | null = null; + + private readonly _range = new RangeScopeController(this); + + /** Whether the last build had a window. Only its appearing or going changes + * what the sections are, so a moving viewport rebuilds nothing. */ + private _builtWithWindow = false; + static styles = [ globalStyles, css` + .scope-window { + font-family: var(--lana-font-mono); + font-variant-numeric: tabular-nums; + font-size: var(--lana-text-meta); + color: var(--lana-fg-muted); + white-space: nowrap; + } + :host { display: flex; flex: 1 1 auto; @@ -184,23 +227,42 @@ export class LogInspector extends LitElement { `; } - /** Only with a selection to switch away from: one live choice is noise. */ + /** + * Only with a selection to switch away from: one live choice is noise. With no + * selection the window still has to be named, so the times stand alone. + */ private _scopeSwitch() { const source = this._activeSource; + const label = this._windowLabel(); if (!source || !this._selections.has(source)) { - return ''; + return label ? html`${label}` : ''; } + // The summary reads the window when there is one, so its own label says so. + const options = label + ? SCOPE_OPTIONS.map((option) => (option.value === 'log' ? { ...option, label } : option)) + : SCOPE_OPTIONS; return html`) => this._setScope(e.detail.value as InspectorScope)} >`; } + /** The window's times, or null where the summary reads the whole log. Only the + * Timeline scopes to a window, so only its own tab names one. */ + private _windowLabel(): string | null { + const window = this._range.window; + const log = this.logStore?.log; + if (!window || !log || this._activeSource !== 'timeline') { + return null; + } + return windowLabel(window, log.timestamp); + } + private get _activeSource(): DetailSource | undefined { return TAB_TO_SOURCE[this.activeTab]; } @@ -342,6 +404,7 @@ export class LogInspector extends LitElement { private async _rebuild(): Promise { const epoch = ++this._rebuildEpoch; + this._builtWithWindow = this._range.window !== null; const source = this._activeSource; const sections = source ? await buildDetailSections( @@ -349,6 +412,7 @@ export class LogInspector extends LitElement { this._scopedSelection(source), this._active.get(source) ?? null, this._sourceViews.get(source), + this._range.window, ) : []; // Drop a slow build that a newer selection already superseded. diff --git a/log-viewer/src/components/detailSections.ts b/log-viewer/src/components/detailSections.ts index e4fe07c48..b8946a1e0 100644 --- a/log-viewer/src/components/detailSections.ts +++ b/log-viewer/src/components/detailSections.ts @@ -4,6 +4,7 @@ import { html, type TemplateResult } from 'lit'; import type { DetailSelection, DetailSource, SelectionView } from '../core/events/EventBus.js'; +import type { TimeWindow } from '../core/log/rangeScope.js'; import { buildDatabaseSections } from '../features/database/components/databaseSections.js'; import type { PaneSection } from './PaneView.js'; @@ -40,6 +41,10 @@ import './NamespaceTimeBar.js'; * ambient scope only applies when `selection` is `null`, so it belongs inside * the `!selection` branch — never above it. * + * `window` is the stretch of log the Timeline is showing, or null for all of it. + * Only the whole-log call tree reads it, to say that it alone is not narrowed; + * every other section follows the window itself. + * * `active` is what the user walked to inside the selection's own call stack: * one frame, or the calls a row counts where the view's rows merge occurrences. * Details and the call tree follow it; the call stack stays anchored to @@ -50,6 +55,7 @@ export async function buildDetailSections( selection: DetailSelection | null, active: DetailSelection | null = null, sourceView?: SelectionView, + window: TimeWindow | null = null, ): Promise { // Nothing selected: the whole log is the scope. `DetailDock`'s own empty // state still covers the moment before a tab id resolves. @@ -128,6 +134,9 @@ export async function buildDetailSections( ); } if (source === 'timeline') { + // The four sections below read the window themselves; this one does not, + // so it says so rather than contradicting them in silence. + const scoped = window !== null; // The Timeline's whole-log analogue: where the time went (by category and // by frame) and how governor consumption built up across the log. sections.push( @@ -148,7 +157,7 @@ export async function buildDetailSections( // The same id as the selection's tree, deliberately: collapse state is // keyed by section id, so the pane treats them as one "Call tree". id: 'calltree', - title: 'Call tree', + title: scoped ? 'Call tree · whole log' : 'Call tree', weight: 4, // The Timeline draws the whole log top down, so the tree answers with // where its time went. Time Order would open on two collapsed roots.