diff --git a/backlog/tasks/task-74 - Startup-warmups-configurable-warmup-vs-defer-with-low-power-mode.md b/backlog/tasks/task-74 - Startup-warmups-configurable-warmup-vs-defer-with-low-power-mode.md index 0f22df7..88a9443 100644 --- a/backlog/tasks/task-74 - Startup-warmups-configurable-warmup-vs-defer-with-low-power-mode.md +++ b/backlog/tasks/task-74 - Startup-warmups-configurable-warmup-vs-defer-with-low-power-mode.md @@ -15,9 +15,12 @@ references: - src/main/runtime/startup-warmups.ts - src/main/runtime/startup-warmups-main-deps.ts - src/main/runtime/composers/mpv-runtime-composer.ts + - src/core/services/startup.ts - src/main.ts - src/config/config.test.ts - src/main/runtime/startup-warmups.test.ts + - src/main/runtime/startup-warmups-main-deps.test.ts + - src/core/services/app-ready.test.ts priority: medium --- @@ -48,4 +51,18 @@ Validation: - `bun run test:config:src` - `bun run test:core:src` - `tsc --noEmit` + +Follow-up updates: +- Startup now triggers warmups earlier in app-ready flow (right after config validation/log-level setup) instead of waiting for initial args/overlay actions. Goal: tokenization warmup is already done or mostly done by first visible-subs toggle. +- Tokenization warmup scheduling consolidated as `subtitle-tokenization` stage; when enabled by toggles, it runs Yomitan extension first, then MeCab/dictionary warmups. +- Added per-stage debug logs for warmup progress and skip reasons: + - `stage start/ready: yomitan-extension` + - `stage start/ready: mecab` + - `stage start/ready: subtitle-dictionaries` + - `stage start/ready: jellyfin-remote-session` + - `stage skipped: jellyfin-remote-session (disabled|auto-connect off)` +- Added regression tests for stage-level logging and earlier startup ordering: + - `src/main/runtime/startup-warmups.test.ts` + - `src/main/runtime/startup-warmups-main-deps.test.ts` + - `src/core/services/app-ready.test.ts` diff --git a/src/core/services/app-ready.test.ts b/src/core/services/app-ready.test.ts index c56bdff..4a0a734 100644 --- a/src/core/services/app-ready.test.ts +++ b/src/core/services/app-ready.test.ts @@ -131,12 +131,30 @@ test('runAppReadyRuntime does not await background warmups', async () => { }); await runAppReadyRuntime(deps); - assert.deepEqual(calls.slice(0, 2), ['handleInitialArgs', 'startBackgroundWarmups']); + assert.ok(calls.includes('startBackgroundWarmups')); + assert.ok(calls.includes('handleInitialArgs')); + assert.ok(calls.indexOf('startBackgroundWarmups') < calls.indexOf('handleInitialArgs')); assert.equal(calls.includes('warmupDone'), false); assert.ok(releaseWarmup); releaseWarmup(); }); +test('runAppReadyRuntime starts background warmups before core runtime services', async () => { + const calls: string[] = []; + const { deps } = makeDeps({ + startBackgroundWarmups: () => { + calls.push('startBackgroundWarmups'); + }, + loadSubtitlePosition: () => calls.push('loadSubtitlePosition'), + createMpvClient: () => calls.push('createMpvClient'), + }); + + await runAppReadyRuntime(deps); + + assert.ok(calls.indexOf('startBackgroundWarmups') < calls.indexOf('loadSubtitlePosition')); + assert.ok(calls.indexOf('startBackgroundWarmups') < calls.indexOf('createMpvClient')); +}); + test('runAppReadyRuntime exits before service init when critical anki mappings are invalid', async () => { const capturedErrors: string[][] = []; const { deps, calls } = makeDeps({ diff --git a/src/core/services/startup.ts b/src/core/services/startup.ts index a9e4098..c7f7122 100644 --- a/src/core/services/startup.ts +++ b/src/core/services/startup.ts @@ -184,6 +184,7 @@ export async function runAppReadyRuntime(deps: AppReadyRuntimeDeps): Promise { const calls: string[] = []; + let warmupStarts = 0; const setVisible = createBuildSetVisibleOverlayVisibleMainDepsHandler({ setVisibleOverlayVisibleCore: () => calls.push('visible-core'), setVisibleOverlayVisibleState: (visible) => calls.push(`visible-state:${visible}`), updateVisibleOverlayVisibility: () => calls.push('update-visible'), + onVisibleOverlayEnabled: () => { + warmupStarts += 1; + }, })(); setVisible.setVisibleOverlayVisibleCore({ visible: true, @@ -20,6 +24,7 @@ test('overlay visibility action main deps builders map callbacks', () => { }); setVisible.setVisibleOverlayVisibleState(true); setVisible.updateVisibleOverlayVisibility(); + setVisible.onVisibleOverlayEnabled?.(); const toggleVisible = createBuildToggleVisibleOverlayMainDepsHandler({ getVisibleOverlayVisible: () => false, @@ -34,4 +39,5 @@ test('overlay visibility action main deps builders map callbacks', () => { 'update-visible', 'toggle-visible:true', ]); + assert.equal(warmupStarts, 1); }); diff --git a/src/main/runtime/overlay-visibility-actions-main-deps.ts b/src/main/runtime/overlay-visibility-actions-main-deps.ts index a707f8e..d46e2e9 100644 --- a/src/main/runtime/overlay-visibility-actions-main-deps.ts +++ b/src/main/runtime/overlay-visibility-actions-main-deps.ts @@ -13,6 +13,7 @@ export function createBuildSetVisibleOverlayVisibleMainDepsHandler( setVisibleOverlayVisibleCore: (options) => deps.setVisibleOverlayVisibleCore(options), setVisibleOverlayVisibleState: (visible: boolean) => deps.setVisibleOverlayVisibleState(visible), updateVisibleOverlayVisibility: () => deps.updateVisibleOverlayVisibility(), + onVisibleOverlayEnabled: deps.onVisibleOverlayEnabled, }); } diff --git a/src/main/runtime/overlay-visibility-actions.test.ts b/src/main/runtime/overlay-visibility-actions.test.ts index 068f087..692f446 100644 --- a/src/main/runtime/overlay-visibility-actions.test.ts +++ b/src/main/runtime/overlay-visibility-actions.test.ts @@ -7,6 +7,7 @@ import { test('set visible overlay handler forwards dependencies to core', () => { const calls: string[] = []; + let warmupStarts = 0; const setVisible = createSetVisibleOverlayVisibleHandler({ setVisibleOverlayVisibleCore: (options) => { calls.push(`core:${options.visible}`); @@ -15,6 +16,9 @@ test('set visible overlay handler forwards dependencies to core', () => { }, setVisibleOverlayVisibleState: (visible) => calls.push(`state:${visible}`), updateVisibleOverlayVisibility: () => calls.push('update-visible'), + onVisibleOverlayEnabled: () => { + warmupStarts += 1; + }, }); setVisible(true); @@ -23,6 +27,10 @@ test('set visible overlay handler forwards dependencies to core', () => { 'state:true', 'update-visible', ]); + assert.equal(warmupStarts, 1); + + setVisible(false); + assert.equal(warmupStarts, 1); }); test('toggle visible overlay flips current visible state', () => { diff --git a/src/main/runtime/overlay-visibility-actions.ts b/src/main/runtime/overlay-visibility-actions.ts index 67f1637..092dee8 100644 --- a/src/main/runtime/overlay-visibility-actions.ts +++ b/src/main/runtime/overlay-visibility-actions.ts @@ -6,8 +6,12 @@ export function createSetVisibleOverlayVisibleHandler(deps: { }) => void; setVisibleOverlayVisibleState: (visible: boolean) => void; updateVisibleOverlayVisibility: () => void; + onVisibleOverlayEnabled?: () => void; }) { return (visible: boolean): void => { + if (visible) { + deps.onVisibleOverlayEnabled?.(); + } deps.setVisibleOverlayVisibleCore({ visible, setVisibleOverlayVisibleState: deps.setVisibleOverlayVisibleState, diff --git a/src/main/runtime/overlay-visibility-runtime.test.ts b/src/main/runtime/overlay-visibility-runtime.test.ts index 1b7b3b5..56b499c 100644 --- a/src/main/runtime/overlay-visibility-runtime.test.ts +++ b/src/main/runtime/overlay-visibility-runtime.test.ts @@ -5,6 +5,7 @@ import { createOverlayVisibilityRuntime } from './overlay-visibility-runtime'; test('overlay visibility runtime wires set/toggle handlers through composed deps', () => { let visible = false; let setVisibleCoreCalls = 0; + let warmupStarts = 0; const runtime = createOverlayVisibilityRuntime({ setVisibleOverlayVisibleDeps: { @@ -17,6 +18,9 @@ test('overlay visibility runtime wires set/toggle handlers through composed deps visible = nextVisible; }, updateVisibleOverlayVisibility: () => {}, + onVisibleOverlayEnabled: () => { + warmupStarts += 1; + }, }, getVisibleOverlayVisible: () => visible, }); @@ -34,4 +38,5 @@ test('overlay visibility runtime wires set/toggle handlers through composed deps assert.equal(visible, false); assert.equal(setVisibleCoreCalls, 4); + assert.equal(warmupStarts, 2); }); diff --git a/src/main/runtime/startup-warmups-main-deps.test.ts b/src/main/runtime/startup-warmups-main-deps.test.ts index 2825e2f..c641460 100644 --- a/src/main/runtime/startup-warmups-main-deps.test.ts +++ b/src/main/runtime/startup-warmups-main-deps.test.ts @@ -42,6 +42,7 @@ test('startup warmups main deps builders map callbacks', async () => { startJellyfinRemoteSession: async () => { calls.push('jellyfin'); }, + logDebug: (message) => calls.push(`start-debug:${message}`), })(); assert.equal(start.getStarted(), false); start.setStarted(true); @@ -58,6 +59,7 @@ test('startup warmups main deps builders map callbacks', async () => { assert.equal(start.shouldWarmupJellyfinRemoteSession(), true); assert.equal(start.shouldAutoConnectJellyfinRemote(), true); await start.startJellyfinRemoteSession(); + start.logDebug?.('z'); assert.deepEqual(calls, [ 'debug:x', @@ -69,5 +71,6 @@ test('startup warmups main deps builders map callbacks', async () => { 'yomitan', 'dict', 'jellyfin', + 'start-debug:z', ]); }); diff --git a/src/main/runtime/startup-warmups-main-deps.ts b/src/main/runtime/startup-warmups-main-deps.ts index 5e4ff60..45cf122 100644 --- a/src/main/runtime/startup-warmups-main-deps.ts +++ b/src/main/runtime/startup-warmups-main-deps.ts @@ -31,5 +31,6 @@ export function createBuildStartBackgroundWarmupsMainDepsHandler(deps: StartBack shouldWarmupJellyfinRemoteSession: () => deps.shouldWarmupJellyfinRemoteSession(), shouldAutoConnectJellyfinRemote: () => deps.shouldAutoConnectJellyfinRemote(), startJellyfinRemoteSession: () => deps.startJellyfinRemoteSession(), + logDebug: deps.logDebug, }); } diff --git a/src/main/runtime/startup-warmups.test.ts b/src/main/runtime/startup-warmups.test.ts index 5ab47e7..f4cf45d 100644 --- a/src/main/runtime/startup-warmups.test.ts +++ b/src/main/runtime/startup-warmups.test.ts @@ -83,7 +83,7 @@ test('startBackgroundWarmups respects per-integration warmup toggles', () => { startWarmups(); assert.equal(started, true); - assert.deepEqual(labels, ['yomitan-extension']); + assert.deepEqual(labels, ['subtitle-tokenization']); }); test('startBackgroundWarmups schedules jellyfin warmup when all jellyfin flags are enabled', () => { @@ -116,12 +116,7 @@ test('startBackgroundWarmups schedules jellyfin warmup when all jellyfin flags a startWarmups(); assert.equal(started, true); - assert.deepEqual(labels, [ - 'mecab', - 'yomitan-extension', - 'subtitle-dictionaries', - 'jellyfin-remote-session', - ]); + assert.deepEqual(labels, ['subtitle-tokenization', 'jellyfin-remote-session']); }); test('startBackgroundWarmups skips jellyfin warmup when warmup is deferred', () => { @@ -154,5 +149,48 @@ test('startBackgroundWarmups skips jellyfin warmup when warmup is deferred', () startWarmups(); assert.equal(started, true); - assert.deepEqual(labels, ['yomitan-extension']); + assert.deepEqual(labels, ['subtitle-tokenization']); +}); + +test('startBackgroundWarmups logs per-stage progress for enabled tokenization warmups', async () => { + const debugLogs: string[] = []; + const labels: string[] = []; + let started = false; + const startWarmups = createStartBackgroundWarmupsHandler({ + getStarted: () => started, + setStarted: (value) => { + started = value; + }, + isTexthookerOnlyMode: () => false, + launchTask: (label, task) => { + labels.push(label); + void task(); + }, + createMecabTokenizerAndCheck: async () => {}, + ensureYomitanExtensionLoaded: async () => {}, + prewarmSubtitleDictionaries: async () => {}, + shouldWarmupMecab: () => true, + shouldWarmupYomitanExtension: () => true, + shouldWarmupSubtitleDictionaries: () => true, + shouldWarmupJellyfinRemoteSession: () => true, + shouldAutoConnectJellyfinRemote: () => true, + startJellyfinRemoteSession: async () => {}, + logDebug: (message) => { + debugLogs.push(message); + }, + }); + + startWarmups(); + await Promise.resolve(); + await Promise.resolve(); + + assert.deepEqual(labels, ['subtitle-tokenization', 'jellyfin-remote-session']); + assert.ok(debugLogs.includes('[startup-warmup] stage start: yomitan-extension')); + assert.ok(debugLogs.includes('[startup-warmup] stage ready: yomitan-extension')); + assert.ok(debugLogs.includes('[startup-warmup] stage start: mecab')); + assert.ok(debugLogs.includes('[startup-warmup] stage ready: mecab')); + assert.ok(debugLogs.includes('[startup-warmup] stage start: subtitle-dictionaries')); + assert.ok(debugLogs.includes('[startup-warmup] stage ready: subtitle-dictionaries')); + assert.ok(debugLogs.includes('[startup-warmup] stage start: jellyfin-remote-session')); + assert.ok(debugLogs.includes('[startup-warmup] stage ready: jellyfin-remote-session')); }); diff --git a/src/main/runtime/startup-warmups.ts b/src/main/runtime/startup-warmups.ts index c62509a..00381f7 100644 --- a/src/main/runtime/startup-warmups.ts +++ b/src/main/runtime/startup-warmups.ts @@ -30,31 +30,63 @@ export function createStartBackgroundWarmupsHandler(deps: { shouldWarmupJellyfinRemoteSession: () => boolean; shouldAutoConnectJellyfinRemote: () => boolean; startJellyfinRemoteSession: () => Promise; + logDebug?: (message: string) => void; }) { return (): void => { if (deps.getStarted()) return; if (deps.isTexthookerOnlyMode()) return; + const warmupMecab = deps.shouldWarmupMecab(); + const warmupYomitanExtension = deps.shouldWarmupYomitanExtension(); + const warmupSubtitleDictionaries = deps.shouldWarmupSubtitleDictionaries(); + const warmupJellyfinRemoteSession = deps.shouldWarmupJellyfinRemoteSession(); + const autoConnectJellyfinRemote = deps.shouldAutoConnectJellyfinRemote(); + deps.setStarted(true); - if (deps.shouldWarmupMecab()) { - deps.launchTask('mecab', async () => { - await deps.createMecabTokenizerAndCheck(); + const shouldWarmupTokenization = + warmupMecab || warmupYomitanExtension || warmupSubtitleDictionaries; + if (shouldWarmupTokenization) { + deps.launchTask('subtitle-tokenization', async () => { + if (warmupYomitanExtension) { + deps.logDebug?.('[startup-warmup] stage start: yomitan-extension'); + await deps.ensureYomitanExtensionLoaded(); + deps.logDebug?.('[startup-warmup] stage ready: yomitan-extension'); + } else { + deps.logDebug?.('[startup-warmup] stage skipped: yomitan-extension'); + } + + await Promise.all([ + warmupMecab + ? (async () => { + deps.logDebug?.('[startup-warmup] stage start: mecab'); + await deps.createMecabTokenizerAndCheck(); + deps.logDebug?.('[startup-warmup] stage ready: mecab'); + })() + : Promise.resolve().then(() => { + deps.logDebug?.('[startup-warmup] stage skipped: mecab'); + }), + warmupSubtitleDictionaries + ? (async () => { + deps.logDebug?.('[startup-warmup] stage start: subtitle-dictionaries'); + await deps.prewarmSubtitleDictionaries(); + deps.logDebug?.('[startup-warmup] stage ready: subtitle-dictionaries'); + })() + : Promise.resolve().then(() => { + deps.logDebug?.('[startup-warmup] stage skipped: subtitle-dictionaries'); + }), + ]); }); } - if (deps.shouldWarmupYomitanExtension()) { - deps.launchTask('yomitan-extension', async () => { - await deps.ensureYomitanExtensionLoaded(); - }); - } - if (deps.shouldWarmupSubtitleDictionaries()) { - deps.launchTask('subtitle-dictionaries', async () => { - await deps.prewarmSubtitleDictionaries(); - }); - } - if (deps.shouldWarmupJellyfinRemoteSession() && deps.shouldAutoConnectJellyfinRemote()) { + if (warmupJellyfinRemoteSession && autoConnectJellyfinRemote) { deps.launchTask('jellyfin-remote-session', async () => { + deps.logDebug?.('[startup-warmup] stage start: jellyfin-remote-session'); await deps.startJellyfinRemoteSession(); + deps.logDebug?.('[startup-warmup] stage ready: jellyfin-remote-session'); }); + } else if (!warmupJellyfinRemoteSession) { + deps.logDebug?.('[startup-warmup] stage skipped: jellyfin-remote-session (disabled)'); + } else { + deps.logDebug?.('[startup-warmup] stage skipped: jellyfin-remote-session (auto-connect off)'); } }; }