mirror of
https://github.com/4gray/iptvnator.git
synced 2026-10-11 11:06:16 -08:00
test(performance): anchor J4's SQL count to the journey sentinels
renderer.sqlStatementsPerSearch was the difference of test-side samples taken before the first key and after the end sentinel had been read, so database work in either gap could be counted. The main process now reads main.sqlStatements when the start and end sentinels arrive, and the counter is their difference; sqlStatementsAfterSettled starts at the end sentinel. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
4grayandClaude Opus 5.5 committed
1 parent
7675c01756
commit
c3c153dbd1
4 files changed
+124
-12
No files matched your search
@@ -22,6 +22,7 @@ import {
|
||||
armSearchJourneyProbe,
|
||||
createSearchJourneyProbeOptions,
|
||||
readSearchJourneyPreStartMutations,
|
||||
type SearchJourneyProbeOptions,
|
||||
SEARCH_JOURNEY_INPUT_SELECTOR,
|
||||
SEARCH_JOURNEY_ROUTE_PATH,
|
||||
waitForSearchJourneyProbe,
|
||||
@@ -218,6 +219,69 @@ async function traceQueryCalls(
|
||||
);
|
||||
}
|
||||
|
||||
const SENTINEL_SQL_KEY = '__iptvnatorJourneySearchSentinelSql';
|
||||
|
||||
/**
|
||||
* Reads `main.sqlStatements` in the main process when the start and the end
|
||||
* sentinel arrive, so the SQL counter covers exactly the IPC capture's
|
||||
* window: database work just before the first key or after the settle is
|
||||
* not counted. The gate's `invokeHandler` runs the counters handler
|
||||
* synchronously, so the value is the total at the sentinel's arrival even
|
||||
* though it is stored when the promise settles.
|
||||
*/
|
||||
async function stampSqlAtSentinels(
|
||||
electronApp: ElectronApplication,
|
||||
probeOptions: SearchJourneyProbeOptions
|
||||
): Promise<void> {
|
||||
await electronApp.evaluate(
|
||||
({ ipcMain }, input) => {
|
||||
const target = globalThis as unknown as Record<string, unknown>;
|
||||
const gate = target[input.gateKey] as {
|
||||
invokeHandler: (channel: string) => Promise<unknown>;
|
||||
};
|
||||
const state: Record<'end' | 'start', number | null> = {
|
||||
end: null,
|
||||
start: null,
|
||||
};
|
||||
target[input.key] = state;
|
||||
ipcMain.on(input.channel, (_event, payload: unknown) => {
|
||||
const record = payload as Record<string, unknown> | null;
|
||||
if (
|
||||
record?.['method'] !== input.sentinelMethod ||
|
||||
record['phase'] !== 'start'
|
||||
) {
|
||||
return;
|
||||
}
|
||||
const args = JSON.stringify(record['args'] ?? null);
|
||||
const which = args.includes(input.startId)
|
||||
? 'start'
|
||||
: args.includes(input.endId)
|
||||
? 'end'
|
||||
: null;
|
||||
if (which === null || state[which] !== null) return;
|
||||
void gate
|
||||
.invokeHandler(input.countersChannel)
|
||||
.then((snapshot) => {
|
||||
const value = (
|
||||
snapshot as { counters?: Record<string, number> }
|
||||
)?.counters?.[input.sqlCounter];
|
||||
state[which] = typeof value === 'number' ? value : null;
|
||||
});
|
||||
});
|
||||
},
|
||||
{
|
||||
channel: JOURNEY_RENDERER_API_TRACE_CHANNEL,
|
||||
countersChannel: JOURNEY_PERFORMANCE_COUNTERS_CHANNEL,
|
||||
endId: probeOptions.endSentinelId,
|
||||
gateKey: JOURNEY_RENDERER_GATE_KEY,
|
||||
key: SENTINEL_SQL_KEY,
|
||||
sentinelMethod: probeOptions.sentinelMethod,
|
||||
sqlCounter: JOURNEY_MAIN_COUNTER.SQL_STATEMENTS,
|
||||
startId: probeOptions.startSentinelId,
|
||||
}
|
||||
);
|
||||
}
|
||||
|
||||
async function readQueryTrace(
|
||||
electronApp: ElectronApplication
|
||||
): Promise<SearchJourneyQueryTraceEntry[]> {
|
||||
@@ -296,6 +360,7 @@ export async function measureSearchJourney(
|
||||
});
|
||||
await blockJourneyExternalArtwork(electronApp);
|
||||
await traceQueryCalls(electronApp);
|
||||
await stampSqlAtSentinels(electronApp, probeOptions);
|
||||
await openGlobalSearch(mainWindow, timeoutMs);
|
||||
await installJourneyMainIpcCapture(electronApp, {
|
||||
channel: JOURNEY_RENDERER_API_TRACE_CHANNEL,
|
||||
@@ -354,6 +419,15 @@ export async function measureSearchJourney(
|
||||
pid: session.launch.pid,
|
||||
query,
|
||||
queryTrace: await readQueryTrace(electronApp),
|
||||
sqlAtSentinels: await electronApp.evaluate(
|
||||
(_electron, key) =>
|
||||
JSON.parse(
|
||||
JSON.stringify(
|
||||
(globalThis as unknown as Record<string, unknown>)[key]
|
||||
)
|
||||
) as SearchJourneyMeasurement['sqlAtSentinels'],
|
||||
SENTINEL_SQL_KEY
|
||||
),
|
||||
renderer,
|
||||
samples,
|
||||
settle,
|
||||
|
||||
@@ -96,6 +96,7 @@ function measurement(
|
||||
keyDelayMs: 100,
|
||||
pid: 4242,
|
||||
query: QUERY,
|
||||
sqlAtSentinels: { end: 121, start: 119 },
|
||||
queryTrace: [
|
||||
{
|
||||
epochMs: 11_150,
|
||||
@@ -211,6 +212,7 @@ test('a query per keystroke shows up per key, not only in the total', () => {
|
||||
sqlStatements: 100,
|
||||
waitedMs: 1_000,
|
||||
},
|
||||
sqlAtSentinels: { end: 110, start: 100 },
|
||||
ipc: {
|
||||
...measurement().ipc,
|
||||
callsBeforeSentinel: 5,
|
||||
@@ -312,9 +314,7 @@ test('rejects work that moved between the quiet snapshot and the first key', ()
|
||||
toSearchIterationRecord(
|
||||
1,
|
||||
false,
|
||||
measurement({
|
||||
samples: [sample(0, 0, 120), ...base.samples.slice(1)],
|
||||
})
|
||||
measurement({ sqlAtSentinels: { end: 122, start: 120 } })
|
||||
),
|
||||
/activity-before-first-key-sql/
|
||||
);
|
||||
@@ -422,3 +422,30 @@ test('rejects typing slower than the accepted cadence', () => {
|
||||
[100, 100, 100, 100, 100]
|
||||
);
|
||||
});
|
||||
|
||||
test('counts SQL between the sentinels only', () => {
|
||||
// Background statements after the end sentinel reach the final sample
|
||||
// but not the counter; they show up after the settle instead.
|
||||
const record = toSearchIterationRecord(
|
||||
1,
|
||||
false,
|
||||
measurement({
|
||||
afterSettled: sample(1, 1, 126),
|
||||
samples: [...measurement().samples.slice(0, 6), sample(1, 1, 125)],
|
||||
})
|
||||
);
|
||||
assert.equal(record.counters[SEARCH_JOURNEY_COUNTER.SQL_STATEMENTS], 2);
|
||||
assert.deepEqual(record.evidence['sqlStatementsAfterSettled'], {
|
||||
count: 5,
|
||||
windowMs: 500,
|
||||
});
|
||||
assert.throws(
|
||||
() =>
|
||||
toSearchIterationRecord(
|
||||
1,
|
||||
false,
|
||||
measurement({ sqlAtSentinels: { end: null, start: 119 } })
|
||||
),
|
||||
/sql-at-sentinels-missing/
|
||||
);
|
||||
});
|
||||
@@ -83,6 +83,14 @@ export interface SearchJourneyMeasurement {
|
||||
readonly afterSettled: SearchJourneyActivitySample;
|
||||
readonly afterSettledWindowMs: number;
|
||||
readonly settle: SearchJourneySettle;
|
||||
/**
|
||||
* `main.sqlStatements` read in the main process when the start and the
|
||||
* end sentinel arrived; null when it was not read.
|
||||
*/
|
||||
readonly sqlAtSentinels: {
|
||||
readonly end: number | null;
|
||||
readonly start: number | null;
|
||||
};
|
||||
/** Every traced query event of the process, in arrival order. */
|
||||
readonly queryTrace: readonly SearchJourneyQueryTraceEntry[];
|
||||
}
|
||||
@@ -175,15 +183,20 @@ export function toSearchIterationRecord(
|
||||
) {
|
||||
throw new Error('search-journey-record-clock-order');
|
||||
}
|
||||
const { end: sqlAtEnd, start: sqlAtStart } = measurement.sqlAtSentinels;
|
||||
if (sqlAtStart === null || sqlAtEnd === null || sqlAtEnd < sqlAtStart) {
|
||||
throw new Error('search-journey-record-sql-at-sentinels-missing');
|
||||
}
|
||||
// Activity between the quiet snapshot and the first key could finish
|
||||
// after it and be counted as the search's. The probe and the capture
|
||||
// keep counting until the first keydown, so they must still match it.
|
||||
// after it and be counted as the search's. The probe, the capture and
|
||||
// the SQL total read at the start sentinel all reflect the first
|
||||
// keydown, so they must still match the snapshot.
|
||||
const moved = [
|
||||
renderer.preStart.domMutations !== settle.preStartDomMutations
|
||||
? 'dom'
|
||||
: null,
|
||||
ipc.callsBeforeStart !== settle.preStartIpcCalls ? 'ipc' : null,
|
||||
samples[0].sqlStatements !== settle.sqlStatements ? 'sql' : null,
|
||||
sqlAtStart !== settle.sqlStatements ? 'sql' : null,
|
||||
].filter((kind): kind is string => kind !== null);
|
||||
if (moved.length > 0) {
|
||||
throw new Error(
|
||||
@@ -256,8 +269,7 @@ export function toSearchIterationRecord(
|
||||
renderer.counters.recentInputLayoutShiftScore
|
||||
),
|
||||
[SEARCH_JOURNEY_COUNTER.LONG_TASKS]: renderer.counters.longTasks,
|
||||
[SEARCH_JOURNEY_COUNTER.SQL_STATEMENTS]:
|
||||
finalSample.sqlStatements - samples[0].sqlStatements,
|
||||
[SEARCH_JOURNEY_COUNTER.SQL_STATEMENTS]: sqlAtEnd - sqlAtStart,
|
||||
}),
|
||||
evidence: Object.freeze({
|
||||
capabilities: renderer.capabilities,
|
||||
@@ -298,10 +310,9 @@ export function toSearchIterationRecord(
|
||||
query: measurement.query,
|
||||
results: Object.freeze({ cardCount: renderer.settle.cardCount }),
|
||||
settle,
|
||||
sqlAtSentinels: measurement.sqlAtSentinels,
|
||||
sqlStatementsAfterSettled: Object.freeze({
|
||||
count:
|
||||
measurement.afterSettled.sqlStatements -
|
||||
finalSample.sqlStatements,
|
||||
count: measurement.afterSettled.sqlStatements - sqlAtEnd,
|
||||
windowMs: measurement.afterSettledWindowMs,
|
||||
}),
|
||||
}),
|
||||
|
||||
@@ -881,7 +881,7 @@ the traced `dbGlobalSearch` calls with their terms and result lengths.
|
||||
| Counter | Source |
|
||||
| ---------------------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
|
||||
| `renderer.ipcCallsPerSearch` | Bridge `start` trace events between the start and end sentinels, as `renderer.ipcCallsToFirstPage` in J2. `evidence.ipcCallsByMethod` names them. |
|
||||
| `renderer.sqlStatementsPerSearch` | `main.sqlStatements` (main thread and database worker, see [Main-process counters](#main-process-counters)) read right before the first key and again after the probe settled. The worker reports its count before the response it belongs to, so the statements of a query are counted before its results reach the renderer. Statements in the 500 ms after that read are kept as `evidence.sqlStatementsAfterSettled`, so background work that would have leaked into the count is visible. |
|
||||
| `renderer.sqlStatementsPerSearch` | `main.sqlStatements` (main thread and database worker, see [Main-process counters](#main-process-counters)) read in the main process when the start sentinel and the end sentinel arrive (a listener on the trace channel calls the counters handler through the gate, which reads the registry synchronously), so the count covers exactly the IPC capture's window and never work just before the first key or after the settle. The worker reports its count before the response it belongs to, so the statements of a query are counted before its results reach the renderer. The two values are `evidence.sqlAtSentinels`; statements from the end sentinel until 500 ms after the test read the summary are kept as `evidence.sqlStatementsAfterSettled`. |
|
||||
| `renderer.ipcSerialDepthToResults` | `computeJourneyIpcSerialDepth` over the capture's timeline between the sentinels (see [Serial IPC depth](#serial-ipc-depth)); `evidence.ipcSerialDepth.chain` and `evidence.ipcTimeline` show the calls. |
|
||||
| `renderer.domMutationsToResults` | `MutationRecord`s from the first keydown until the quiet window was confirmed (by definition none arrive inside it). |
|
||||
| `renderer.cdTicksToResults` | `ApplicationRef` ticks from the first keydown (read in the capture-phase listener, before the app handles the key) until the confirmation (see [Change-detection ticks](#change-detection-ticks)). |
|
||||
|
||||
Reference in new issue
Block a user