test(performance): count SQL statements only for the launch journey

Codex review: the M3U import, refresh-cancellation and Xtream benchmarks
also run with IPTVNATOR_PERF_CAPTURE=1, so the statement hook wrapped
every row of their bulk inserts and changed what they measure.

SQL counting now also needs IPTVNATOR_PERF_COUNT_SQL=1, which only the
launch journey sets; a harness test fails if another source sets it.
Startup phases, the window snapshot and the read handler stay on the
capture flag. Without SQL counting no ready-to-show listener is attached,
so a zero is never reported for statements nobody counted.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
4grayandClaude Opus 5.5 committed 2026-09-27 18:51:56 +02:00
1 parent 757166b43a
commit e5b28074e6
15 files changed
+171 -38

No files matched your search

@@ -129,11 +129,14 @@ export async function measureLaunchJourney(
try {
await cp(templateDirectory, dataDirectory, { recursive: true });
// IPTVNATOR_PERF_CAPTURE turns on the main-process counters and
// their read handler; see journey-main-counters.ts.
// their read handler, IPTVNATOR_PERF_COUNT_SQL the SQL statement
// count behind main.sqlStatementsBeforeReadyToShow; only this journey
// sets it. See journey-main-counters.ts.
const env = buildElectronLaunchEnvironment(
dataDirectory,
launchOptions({
IPTVNATOR_PERF_CAPTURE: '1',
IPTVNATOR_PERF_COUNT_SQL: '1',
IPTVNATOR_TRACE_IPC: '1',
})
);
@@ -1,4 +1,6 @@
import assert from 'node:assert/strict';
import { readdirSync, readFileSync } from 'node:fs';
import { join, relative, resolve } from 'node:path';
import test from 'node:test';
import {
@@ -124,3 +126,22 @@ test('rejects snapshots that were not frozen at the moments they claim', () => {
/total-below-frozen: main.startupPhases/
);
});
test('only the launch journey opts into SQL statement counting', () => {
// The import benchmarks also run with IPTVNATOR_PERF_CAPTURE=1; the SQL
// hook wraps every row of a bulk insert, so they must not enable it.
const sourceRoot = resolve(__dirname, '..');
const files = readdirSync(sourceRoot, { recursive: true })
.map(String)
.filter(
(file) => /\.(ts|cjs)$/.test(file) && !/\.spec\.ts$/.test(file)
);
const optedIn = files
.filter((file) =>
readFileSync(join(sourceRoot, file), 'utf8').includes(
'IPTVNATOR_PERF_COUNT_SQL'
)
)
.map((file) => relative(sourceRoot, join(sourceRoot, file)));
assert.deepEqual(optedIn, [join('journeys', 'launch-journey-app.ts')]);
});
+5 -1
View File
@@ -9,6 +9,7 @@ import { rendererAppName, rendererAppPort } from './constants';
import {
isPerformanceCaptureEnabled,
isRendererConsoleTraceEnabled,
isSqlStatementCountEnabled,
isWindowTraceEnabled,
performanceCounters,
trace,
@@ -523,7 +524,10 @@ export default class App {
attachMainWindowPerformanceCounters(
App.mainWindow,
performanceCounters,
isPerformanceCaptureEnabled()
{
capture: isPerformanceCaptureEnabled(),
sqlStatements: isSqlStatementCountEnabled(),
}
);
attachWindowTrace(App.mainWindow);
App.attachWindowStateEvents(App.mainWindow);
@@ -131,3 +131,33 @@ describe('startup phase counting', () => {
]);
});
});
describe('SQL statement count opt-in', () => {
const FLAGS = ['IPTVNATOR_PERF_CAPTURE', 'IPTVNATOR_PERF_COUNT_SQL'];
const original = FLAGS.map((name) => [name, process.env[name]] as const);
afterEach(() => {
for (const [name, value] of original) {
if (value === undefined) {
delete process.env[name];
} else {
process.env[name] = value;
}
}
});
it.each([
[{}, false],
[{ IPTVNATOR_PERF_CAPTURE: '1' }, false],
[{ IPTVNATOR_PERF_COUNT_SQL: '1' }, false],
[{ IPTVNATOR_PERF_CAPTURE: '1', IPTVNATOR_PERF_COUNT_SQL: '1' }, true],
])('needs both flags: %j -> %s', async (env, expected) => {
for (const name of FLAGS) {
delete process.env[name];
}
Object.assign(process.env, env);
const { isSqlStatementCountEnabled } = await import('./debug-trace');
expect(isSqlStatementCountEnabled()).toBe(expected);
});
});
@@ -63,6 +63,18 @@ export function isPerformanceCaptureEnabled(): boolean {
return readFlag('IPTVNATOR_PERF_CAPTURE');
}
/**
* SQL statement counting wraps every statement execution, including each
* row of a bulk insert, so it has its own opt-in on top of the capture flag:
* only the launch journey sets it, and the import benchmarks that also run
* with IPTVNATOR_PERF_CAPTURE=1 keep measuring the unwrapped workload.
*/
export function isSqlStatementCountEnabled(): boolean {
return (
isPerformanceCaptureEnabled() && readFlag('IPTVNATOR_PERF_COUNT_SQL')
);
}
/**
* Process-wide performance counters (see `performance-counters.ts`). Every
* call is a no-op unless `IPTVNATOR_PERF_CAPTURE=1`.
@@ -7,7 +7,8 @@ import { PERFORMANCE_COUNTER } from './performance-counters';
import type { PerformanceCounterRegistry } from './performance-counters';
/**
* With IPTVNATOR_PERF_CAPTURE=1, counts the SQL statements the main process
* With IPTVNATOR_PERF_CAPTURE=1 and IPTVNATOR_PERF_COUNT_SQL=1, counts the
* SQL statements the main process
* executes into `main.sqlStatements`, next to the database worker's
* statements that `DatabaseWorkerClient` adds. The shared connection
* (`initDatabase`, the `sql-main` trace) runs schema creation and migrations
@@ -113,23 +113,46 @@ describe('performance:read-counters handler', () => {
});
describe('main window performance counters', () => {
const BOTH_FLAGS = { capture: true, sqlStatements: true };
it('attaches nothing without the capture flag', () => {
const window = new EventEmitter();
const { registry } = createRegistry();
attachMainWindowPerformanceCounters(window, registry, false);
attachMainWindowPerformanceCounters(window, registry, {
capture: false,
sqlStatements: false,
});
expect(window.listenerCount('ready-to-show')).toBe(0);
expect(registry.read().counters).toEqual({});
});
it('freezes only the startup phases when SQL is not counted', () => {
const window = new EventEmitter();
const { registry } = createRegistry();
registry.increment(PERFORMANCE_COUNTER.STARTUP_PHASES, 2);
attachMainWindowPerformanceCounters(window, registry, {
capture: true,
sqlStatements: false,
});
window.emit('ready-to-show');
expect(window.listenerCount('ready-to-show')).toBe(0);
expect(registry.read().counters).toEqual({
'main.modulesRegisteredBeforeWindow': 2,
'main.startupPhases': 2,
});
});
it('freezes startup phases at creation and SQL at ready-to-show', () => {
const window = new EventEmitter();
const { registry } = createRegistry();
registry.increment(PERFORMANCE_COUNTER.STARTUP_PHASES, 2);
registry.increment(PERFORMANCE_COUNTER.SQL_STATEMENTS, 3);
attachMainWindowPerformanceCounters(window, registry, true);
attachMainWindowPerformanceCounters(window, registry, BOTH_FLAGS);
registry.increment(PERFORMANCE_COUNTER.STARTUP_PHASES);
registry.increment(PERFORMANCE_COUNTER.SQL_STATEMENTS, 4);
window.emit('ready-to-show');
@@ -154,12 +177,12 @@ describe('main window performance counters', () => {
const second = new EventEmitter();
const { registry } = createRegistry();
registry.increment(PERFORMANCE_COUNTER.STARTUP_PHASES, 2);
attachMainWindowPerformanceCounters(first, registry, true);
attachMainWindowPerformanceCounters(first, registry, BOTH_FLAGS);
first.emit('ready-to-show');
registry.increment(PERFORMANCE_COUNTER.STARTUP_PHASES, 5);
registry.increment(PERFORMANCE_COUNTER.SQL_STATEMENTS, 5);
attachMainWindowPerformanceCounters(second, registry, true);
attachMainWindowPerformanceCounters(second, registry, BOTH_FLAGS);
second.emit('ready-to-show');
expect(registry.read().counters).toMatchObject({
@@ -91,23 +91,35 @@ export function registerPerformanceCountersHandler(
return true;
}
export interface MainWindowPerformanceCounterFlags {
/** IPTVNATOR_PERF_CAPTURE=1. */
readonly capture: boolean;
/** IPTVNATOR_PERF_COUNT_SQL=1 as well; SQL is not counted otherwise. */
readonly sqlStatements: boolean;
}
/**
* Freezes the window-relative counters: the startup phases that ran before
* this window existed, and the database statements that ran before its first
* `ready-to-show`. Call right after the window is constructed.
* this window existed and, when SQL is counted, the database statements that
* ran before its first `ready-to-show`. Without SQL counting no listener is
* attached, so a zero is never reported for statements nobody counted. Call
* right after the window is constructed.
*/
export function attachMainWindowPerformanceCounters(
window: { once(event: 'ready-to-show', listener: () => void): unknown },
registry: PerformanceCounterRegistry,
enabled: boolean
flags: MainWindowPerformanceCounterFlags
): void {
if (!enabled) {
if (!flags.capture) {
return;
}
registry.freeze(
PERFORMANCE_COUNTER.STARTUP_PHASES,
PERFORMANCE_COUNTER.MODULES_REGISTERED_BEFORE_WINDOW
);
if (!flags.sqlStatements) {
return;
}
window.once('ready-to-show', () => {
registry.freeze(
PERFORMANCE_COUNTER.SQL_STATEMENTS,
@@ -4,7 +4,9 @@ import type BetterSqlite3 from 'better-sqlite3';
* Counts the SQL statements the database worker executes and reports the
* count to the main process, where `main.sqlStatements` is kept (see
* `services/performance-counters.ts`). Only active with
* `IPTVNATOR_PERF_CAPTURE=1`.
* `IPTVNATOR_PERF_CAPTURE=1` and `IPTVNATOR_PERF_COUNT_SQL=1`, which only the
* launch journey sets: the import benchmarks run with the capture flag alone
* and keep measuring unwrapped statements.
*
* The count travels over the worker's message port, which is ordered with
* the worker's responses, instead of the stdout trace lines Node forwards
@@ -7,11 +7,16 @@ import { DB_WORKER_SQL_STATEMENTS_MESSAGE_TYPE } from './database-worker-sql-sta
/**
* Pins the worker wiring of `database-worker-sql-statement-count.ts`: with
* IPTVNATOR_PERF_CAPTURE=1 the real worker connection reports its statements
* over the parent port, without the flag it reports nothing, and the worker
* flushes the count before any response it posts.
* IPTVNATOR_PERF_CAPTURE=1 and IPTVNATOR_PERF_COUNT_SQL=1 the real worker
* connection reports its statements over the parent port, with the capture
* flag alone (the import benchmarks) or without flags it reports nothing,
* and the worker flushes the count before any response it posts.
*/
const ENV_NAMES = ['IPTVNATOR_PERF_CAPTURE', 'IPTVNATOR_E2E_DATA_DIR'] as const;
const ENV_NAMES = [
'IPTVNATOR_PERF_CAPTURE',
'IPTVNATOR_PERF_COUNT_SQL',
'IPTVNATOR_E2E_DATA_DIR',
] as const;
const EXECUTION_METHODS = ['run', 'get', 'all', 'iterate'] as const;
describe('database worker SQL statement count wiring', () => {
@@ -69,16 +74,14 @@ describe('database worker SQL statement count wiring', () => {
}
async function openConnection(
captureFlag: string | undefined,
flags: Partial<Record<(typeof ENV_NAMES)[number], string>>,
expectedMessages: number
) {
dataDirectory = mkdtempSync(join(tmpdir(), 'iptvnator-sql-count-'));
delete process.env['IPTVNATOR_PERF_CAPTURE'];
delete process.env['IPTVNATOR_PERF_COUNT_SQL'];
Object.assign(process.env, flags);
process.env['IPTVNATOR_E2E_DATA_DIR'] = dataDirectory;
if (captureFlag === undefined) {
delete process.env['IPTVNATOR_PERF_CAPTURE'];
} else {
process.env['IPTVNATOR_PERF_CAPTURE'] = captureFlag;
}
const { messages } = connectPorts();
const connection = await import('./database.worker-connection');
await connection.getWorkerDatabase();
@@ -94,8 +97,11 @@ describe('database worker SQL statement count wiring', () => {
return messages;
}
it('reports the connection setup statements when capture is on', async () => {
const messages = await openConnection('1', 2);
it('reports the connection setup statements when SQL counting is on', async () => {
const messages = await openConnection(
{ IPTVNATOR_PERF_CAPTURE: '1', IPTVNATOR_PERF_COUNT_SQL: '1' },
2
);
// Seven PRAGMAs on open, then `PRAGMA optimize` on close.
expect(messages).toEqual([
@@ -105,14 +111,23 @@ describe('database worker SQL statement count wiring', () => {
expect(JSON.stringify(messages)).not.toMatch(/PRAGMA|journal_mode/i);
});
it('reports nothing and leaves better-sqlite3 alone without the flag', async () => {
const messages = await openConnection(undefined, 0);
it.each([
['without flags', {}],
[
'with the capture flag alone, as the import benchmarks run',
{ IPTVNATOR_PERF_CAPTURE: '1' },
],
])(
'reports nothing and leaves better-sqlite3 alone %s',
async (_label, flags) => {
const messages = await openConnection(flags, 0);
expect(messages).toEqual([]);
for (const [method, original] of originalMethods) {
expect(statementPrototype[method]).toBe(original);
expect(messages).toEqual([]);
for (const [method, original] of originalMethods) {
expect(statementPrototype[method]).toBe(original);
}
}
});
);
it('flushes the count before the worker posts a response', async () => {
const { messages, workerPort } = connectPorts();
@@ -10,7 +10,7 @@ import {
registerNativeModuleSearchPaths,
} from './worker-runtime-paths';
import {
isPerformanceCaptureEnabled,
isSqlStatementCountEnabled,
isSqlTraceEnabled,
trace,
traceSqlStatement,
@@ -64,8 +64,9 @@ const Database = loadBetterSqlite3();
let db: AppDatabase | null = null;
let sqlite: BetterSqlite3.Database | null = null;
// IPTVNATOR_PERF_CAPTURE=1 only: the main process keeps the running total.
const sqlStatementCount = isPerformanceCaptureEnabled()
// IPTVNATOR_PERF_CAPTURE=1 with IPTVNATOR_PERF_COUNT_SQL=1 only: the main
// process keeps the running total.
const sqlStatementCount = isSqlStatementCountEnabled()
? createSqlStatementCountReporter((message) =>
parentPort?.postMessage(message)
)
+2 -1
View File
@@ -6,6 +6,7 @@ import PlaylistOpenEvents from './app/events/playlist-open.events';
import SquirrelEvents from './app/events/squirrel.events';
import {
isPerformanceCaptureEnabled,
isSqlStatementCountEnabled,
isStartupTraceEnabled,
performanceCounters,
traceStartupPhase,
@@ -46,7 +47,7 @@ traceStartupPhase('compile-cache', () => readCompileCacheOutcome());
// Before anything can open the shared database connection.
countMainProcessSqlStatements(
performanceCounters,
isPerformanceCaptureEnabled()
isSqlStatementCountEnabled()
);
// Before the first portal, playlist or update request leaves this process.
+5 -1
View File
@@ -108,7 +108,11 @@ With `IPTVNATOR_PERF_CAPTURE=1`, which the journey sets,
in the main process (`services/performance-counters.ts`) and `main.ts`
registers the `performance:read-counters` IPC handler. Without the flag
nothing is counted, no listener is attached and the handler does not exist;
the preload never exposes the channel. After the renderer probe completes,
the preload never exposes the channel. SQL statements are counted only with
`IPTVNATOR_PERF_COUNT_SQL=1` as well, because the hook wraps every statement
execution: the journey sets both, while the M3U, refresh and Xtream
benchmarks run with the capture flag alone and keep measuring unwrapped
statements. A harness test fails if any other source sets the SQL flag. After the renderer probe completes,
`journey-main-counters.ts` calls the handler through `electronApp.evaluate`
and the gate's tap.
+6 -3
View File
@@ -444,8 +444,8 @@ first, this receipt remains distinct from the later authoritative
exposing the pending request. Disabled profiling performs no receipt clock or
transport work, and `DatabaseWorkerClient.cancel()` remains fire-and-return.
With `IPTVNATOR_PERF_CAPTURE=1`, the worker connection also counts the SQL
statements it executes and posts `performance-sql-statements` messages that
With `IPTVNATOR_PERF_CAPTURE=1` and `IPTVNATOR_PERF_COUNT_SQL=1`, the worker
connection also counts the SQL statements it executes and posts `performance-sql-statements` messages that
carry only a positive count, never SQL text or bound values. Counts are
coalesced per microtask and flushed before every other worker message, so a
response never overtakes the statements that produced it.
@@ -454,7 +454,10 @@ counter and settles nothing. Statements are counted by wrapping the
execution methods of better-sqlite3's `Statement` prototype and the
connection's `exec`, not through the `verbose` callback: a callback makes
better-sqlite3 expand every statement's SQL, which made bulk inserts two to
four times slower. A call that throws is not counted, which matches the SQL
four times slower. Counting still adds a JavaScript call per row of a bulk
insert, so it needs `IPTVNATOR_PERF_COUNT_SQL` on top of the capture flag:
only the launch journey sets it, and the import benchmarks that run with the
capture flag measure unwrapped statements. A call that throws is not counted, which matches the SQL
trace for statements that fail before execution. One `exec` call counts as
one statement, so initialization passes one statement per call; the
historical-upgrade test enforces it. The main process counts its
+1
View File
@@ -31,6 +31,7 @@ IPTVNATOR_TRACE_STARTUP=1 pnpm nx serve electron-backend
- `IPTVNATOR_TRACE_PLAYER=1` traces external-player activity and bounded Embedded MPV runtime-probe stderr
- `IPTVNATOR_TRACE_RENDERER_CONSOLE=1` mirrors renderer console output into the Electron terminal
- `IPTVNATOR_PERF_CAPTURE=1` enables development/test-only, redacted M3U and Xtream preload IPC request/completion markers plus count-only M3U acquire/parse/normalize, Xtream main network/JSON-transform/success-response-ready/cancel-dispatch, and renderer store phase capture; renderer wrappers emit only while the benchmark installs its Symbol hook, benchmark tooling sets the flag explicitly, and production launches must leave it unset. It also keeps count-only main-process counters (startup phases, database worker SQL statements, and their values at main-window creation and `ready-to-show`) and registers the main-only `performance:read-counters` IPC handler, which the preload does not expose; see [performance journeys](../architecture/performance-journeys.md)
- `IPTVNATOR_PERF_COUNT_SQL=1`, together with `IPTVNATOR_PERF_CAPTURE=1`, also counts every SQL statement of the main-process and database-worker connections for `main.sqlStatementsBeforeReadyToShow`; it wraps each statement execution, including every row of a bulk insert, so only the launch journey sets it and the import benchmarks leave it unset
- `IPTVNATOR_PERF_WORKER_PROFILING=1` enables development/test-only, request-scoped worker receive/work/response-post timestamps, thread CPU, event-loop utilization/delay, count-only playlist serialization/SQLite write/read/deserialization plus Xtream category/content/cache-clear/delete/in-source-search phase events, profiling-only worker cancel-receipt acknowledgements, valid-sample-counted isolate peak memory, and the database worker's idle-only one-shot post-GC heap probe; overlapping database requests are explicitly invalidated instead of misattributed, the performance benchmark sets the flag automatically, and production launches must leave it unset
- `IPTVNATOR_DISABLE_COMPILE_CACHE=1` disables the main-process V8 compile cache; `IPTVNATOR_COMPILE_CACHE_DIR=<dir>` relocates it. The startup trace reports the outcome as `compile-cache`