fix: log anime dictionary progress

backlog/tasks/task-96 - Add-launcher-app-log-progress-for-anime-dictionary-generate-update-flow.md

@@ -0,0 +1,47 @@
+---
+id: TASK-96
+title: Add launcher/app log progress for anime dictionary generate/update flow
+status: Done
+assignee: []
+created_date: '2026-03-06 09:30'
+updated_date: '2026-03-06 09:33'
+labels:
+  - logging
+  - dictionary
+  - launcher
+dependencies: []
+references:
+  - >-
+    /home/sudacode/projects/japanese/SubMiner/src/main/character-dictionary-runtime.ts
+  - /home/sudacode/projects/japanese/SubMiner/src/core/services/cli-command.ts
+  - >-
+    /home/sudacode/projects/japanese/SubMiner/launcher/commands/playback-command.ts
+priority: medium
+---
+
+## Description
+
+<!-- SECTION:DESCRIPTION:BEGIN -->
+Surface user-visible log progress while the anime character dictionary is being generated or refreshed so launcher/app output no longer appears hung before mpv launches.
+<!-- SECTION:DESCRIPTION:END -->
+
+## Acceptance Criteria
+<!-- AC:BEGIN -->
+- [x] #1 Dictionary generation logs a start/progress message before the first AniList/network/cache work begins.
+- [x] #2 Dictionary refresh/update path logs progress messages during the wait before completion.
+- [x] #3 Regression coverage verifies the new progress logging behavior.
+<!-- AC:END -->
+
+## Implementation Notes
+
+<!-- SECTION:NOTES:BEGIN -->
+Added progress logging to character dictionary generation at anime resolution, AniList match, snapshot miss, character-page fetch, image download start, and ZIP build stages.
+
+Added auto-sync progress logging at snapshot sync start, active AniList set selection, merged rebuild, Yomitan import, and settings application stages.
+<!-- SECTION:NOTES:END -->
+
+## Final Summary
+
+<!-- SECTION:FINAL_SUMMARY:BEGIN -->
+Character dictionary generation/update no longer appears hung before mpv resumes. Added runtime progress logs for anime resolution, AniList lookup, snapshot rebuild, image-download phase, ZIP build, and auto-sync merged-dictionary import/settings stages. Added regression coverage in the runtime and auto-sync test suites and verified with focused Bun tests.
+<!-- SECTION:FINAL_SUMMARY:END -->

src/main/character-dictionary-runtime.test.ts

@@ -578,6 +578,132 @@ test('getOrCreateCurrentSnapshot rebuilds snapshots written with an older format
   }
 });
 
+test('generateForCurrentMedia logs progress while resolving and rebuilding snapshot data', async () => {
+  const userDataPath = makeTempDir();
+  const originalFetch = globalThis.fetch;
+  const logs: string[] = [];
+
+  globalThis.fetch = (async (input: string | URL | Request, init?: RequestInit) => {
+    const url = typeof input === 'string' ? input : input instanceof URL ? input.href : input.url;
+    if (url === GRAPHQL_URL) {
+      const body = JSON.parse(String(init?.body ?? '{}')) as {
+        query?: string;
+      };
+
+      if (body.query?.includes('Page(perPage: 10)')) {
+        return new Response(
+          JSON.stringify({
+            data: {
+              Page: {
+                media: [
+                  {
+                    id: 130298,
+                    episodes: 20,
+                    title: {
+                      romaji: 'Kage no Jitsuryokusha ni Naritakute!',
+                      english: 'The Eminence in Shadow',
+                      native: '陰の実力者になりたくて！',
+                    },
+                  },
+                ],
+              },
+            },
+          }),
+          {
+            status: 200,
+            headers: { 'content-type': 'application/json' },
+          },
+        );
+      }
+
+      if (body.query?.includes('characters(page: $page')) {
+        return new Response(
+          JSON.stringify({
+            data: {
+              Media: {
+                title: {
+                  romaji: 'Kage no Jitsuryokusha ni Naritakute!',
+                  english: 'The Eminence in Shadow',
+                  native: '陰の実力者になりたくて！',
+                },
+                characters: {
+                  pageInfo: { hasNextPage: false },
+                  edges: [
+                    {
+                      role: 'MAIN',
+                      node: {
+                        id: 321,
+                        description: 'Alpha is the second-in-command of Shadow Garden.',
+                        image: {
+                          large: 'https://example.com/alpha.png',
+                          medium: null,
+                        },
+                        name: {
+                          full: 'Alpha',
+                          native: 'アルファ',
+                        },
+                      },
+                    },
+                  ],
+                },
+              },
+            },
+          }),
+          {
+            status: 200,
+            headers: { 'content-type': 'application/json' },
+          },
+        );
+      }
+    }
+
+    if (url === 'https://example.com/alpha.png') {
+      return new Response(PNG_1X1, {
+        status: 200,
+        headers: { 'content-type': 'image/png' },
+      });
+    }
+
+    throw new Error(`Unexpected fetch URL: ${url}`);
+  }) as typeof globalThis.fetch;
+
+  try {
+    const runtime = createCharacterDictionaryRuntimeService({
+      userDataPath,
+      getCurrentMediaPath: () => '/tmp/eminence-s01e05.mkv',
+      getCurrentMediaTitle: () => 'The Eminence in Shadow - S01E05',
+      resolveMediaPathForJimaku: (mediaPath) => mediaPath,
+      guessAnilistMediaInfo: async () => ({
+        title: 'The Eminence in Shadow',
+        episode: 5,
+        source: 'fallback',
+      }),
+      now: () => 1_700_000_000_100,
+      sleep: async () => undefined,
+      logInfo: (message) => {
+        logs.push(message);
+      },
+    });
+
+    await runtime.generateForCurrentMedia();
+
+    assert.deepEqual(logs, [
+      '[dictionary] resolving current anime for character dictionary generation',
+      '[dictionary] current anime guess: The Eminence in Shadow (episode 5)',
+      '[dictionary] AniList match: The Eminence in Shadow -> AniList 130298',
+      '[dictionary] snapshot miss for AniList 130298, fetching characters',
+      '[dictionary] downloaded AniList character page 1 for AniList 130298',
+      '[dictionary] downloading 1 character images for AniList 130298',
+      '[dictionary] stored snapshot for AniList 130298: 32 terms',
+      '[dictionary] building ZIP for AniList 130298',
+      '[dictionary] generated AniList 130298: 32 terms -> ' +
+        path.join(userDataPath, 'character-dictionaries', 'anilist-130298.zip'),
+    ]);
+  } finally {
+    globalThis.fetch = originalFetch;
+  }
+});
+
 test('buildMergedDictionary combines stored snapshots into one stable dictionary', async () => {
   const userDataPath = makeTempDir();
   const originalFetch = globalThis.fetch;

src/main/character-dictionary-runtime.ts

@@ -974,6 +974,7 @@ async function resolveAniListMediaIdFromGuess(
 async function fetchCharactersForMedia(
   mediaId: number,
   beforeRequest?: () => Promise<void>,
+  onPageFetched?: (page: number) => void,
 ): Promise<{
   mediaTitle: string;
   characters: CharacterRecord[];
@@ -1020,6 +1021,7 @@ async function fetchCharactersForMedia(
       },
       beforeRequest,
     );
+    onPageFetched?.(page);
 
     const media = data.Media;
     if (!media) {
@@ -1219,6 +1221,7 @@ export function createCharacterDictionaryRuntimeService(deps: CharacterDictionar
     targetPath?: string,
     beforeRequest?: () => Promise<void>,
   ): Promise<ResolvedAniListMedia> => {
+    deps.logInfo?.('[dictionary] resolving current anime for character dictionary generation');
     const dictionaryTarget = targetPath?.trim() || '';
     const guessInput =
       dictionaryTarget.length > 0
@@ -1233,7 +1236,14 @@ export function createCharacterDictionaryRuntimeService(deps: CharacterDictionar
     if (!guessed || !guessed.title.trim()) {
       throw new Error('Unable to resolve current anime from media path/title.');
     }
-    return resolveAniListMediaIdFromGuess(guessed, beforeRequest);
+    deps.logInfo?.(
+      `[dictionary] current anime guess: ${guessed.title.trim()}${
+        typeof guessed.episode === 'number' && guessed.episode > 0 ? ` (episode ${guessed.episode})` : ''
+      }`,
+    );
+    const resolved = await resolveAniListMediaIdFromGuess(guessed, beforeRequest);
+    deps.logInfo?.(`[dictionary] AniList match: ${resolved.title} -> AniList ${resolved.id}`);
+    return resolved;
   };
 
   const getOrCreateSnapshot = async (
@@ -1254,15 +1264,26 @@ export function createCharacterDictionaryRuntimeService(deps: CharacterDictionar
       };
     }
 
+    deps.logInfo?.(`[dictionary] snapshot miss for AniList ${mediaId}, fetching characters`);
+
     const { mediaTitle: fetchedMediaTitle, characters } = await fetchCharactersForMedia(
       mediaId,
       beforeRequest,
+      (page) => {
+        deps.logInfo?.(`[dictionary] downloaded AniList character page ${page} for AniList ${mediaId}`);
+      },
     );
     if (characters.length === 0) {
       throw new Error(`No characters returned for AniList media ${mediaId}.`);
     }
 
     const imagesByCharacterId = new Map<number, CharacterDictionarySnapshotImage>();
+    const charactersWithImages = characters.filter((character) => Boolean(character.imageUrl)).length;
+    if (charactersWithImages > 0) {
+      deps.logInfo?.(
+        `[dictionary] downloading ${charactersWithImages} character images for AniList ${mediaId}`,
+      );
+    }
     let hasAttemptedCharacterImageDownload = false;
     for (const character of characters) {
       if (!character.imageUrl) continue;
@@ -1369,6 +1390,7 @@ export function createCharacterDictionaryRuntimeService(deps: CharacterDictionar
       const dictionaryTitle = buildDictionaryTitle(resolvedMedia.id);
       const description = `Character names from ${storedSnapshot.mediaTitle} [AniList media ID ${resolvedMedia.id}]`;
       const zipPath = path.join(outputDir, `anilist-${resolvedMedia.id}.zip`);
+      deps.logInfo?.(`[dictionary] building ZIP for AniList ${resolvedMedia.id}`);
       buildDictionaryZip(
         zipPath,
         dictionaryTitle,

src/main/runtime/character-dictionary-auto-sync.test.ts

@@ -15,6 +15,7 @@ test('auto sync imports merged dictionary and persists MRU state', async () => {
   const deleted: string[] = [];
   const upserts: Array<{ title: string; scope: 'all' | 'active' }> = [];
   const mergedBuilds: number[][] = [];
+  const logs: string[] = [];
 
   let importedRevision: string | null = null;
 
@@ -60,6 +61,9 @@ test('auto sync imports merged dictionary and persists MRU state', async () => {
       return true;
     },
     now: () => 1000,
+    logInfo: (message) => {
+      logs.push(message);
+    },
   });
 
   await runtime.runSyncNow();
@@ -78,6 +82,14 @@ test('auto sync imports merged dictionary and persists MRU state', async () => {
   assert.deepEqual(state.activeMediaIds, [130298]);
   assert.equal(state.mergedRevision, 'rev-1');
   assert.equal(state.mergedDictionaryTitle, 'SubMiner Character Dictionary');
+  assert.deepEqual(logs, [
+    '[dictionary:auto-sync] syncing current anime snapshot',
+    '[dictionary:auto-sync] active AniList media set: 130298',
+    '[dictionary:auto-sync] rebuilding merged dictionary for active anime set',
+    '[dictionary:auto-sync] importing merged dictionary: /tmp/subminer-character-dictionary.zip',
+    '[dictionary:auto-sync] applying Yomitan settings for SubMiner Character Dictionary',
+    '[dictionary:auto-sync] synced AniList 130298: SubMiner Character Dictionary (2544 entries)',
+  ]);
 });
 
 test('auto sync skips rebuild/import on unchanged revisit when merged dictionary is current', async () => {

src/main/runtime/character-dictionary-auto-sync.ts

@@ -133,12 +133,16 @@ export function createCharacterDictionaryAutoSyncRuntimeService(
       return;
     }
 
+    deps.logInfo?.('[dictionary:auto-sync] syncing current anime snapshot');
     const snapshot = await deps.getOrCreateCurrentSnapshot();
     const state = readAutoSyncState(statePath);
     const nextActiveMediaIds = [
       snapshot.mediaId,
       ...state.activeMediaIds.filter((mediaId) => mediaId !== snapshot.mediaId),
     ].slice(0, Math.max(1, Math.floor(config.maxLoaded)));
+    deps.logInfo?.(
+      `[dictionary:auto-sync] active AniList media set: ${nextActiveMediaIds.join(', ')}`,
+    );
 
     const retainedChanged = !arraysEqual(nextActiveMediaIds, state.activeMediaIds);
     let merged: MergedCharacterDictionaryBuildResult | null = null;
@@ -148,6 +152,7 @@ export function createCharacterDictionaryAutoSyncRuntimeService(
       !state.mergedDictionaryTitle ||
       !snapshot.fromCache
     ) {
+      deps.logInfo?.('[dictionary:auto-sync] rebuilding merged dictionary for active anime set');
       merged = await deps.buildMergedDictionary(nextActiveMediaIds);
     }
 
@@ -189,6 +194,7 @@ export function createCharacterDictionaryAutoSyncRuntimeService(
       }
     }
 
+    deps.logInfo?.(`[dictionary:auto-sync] applying Yomitan settings for ${dictionaryTitle}`);
     await withOperationTimeout(
       `upsertYomitanDictionarySettings(${dictionaryTitle})`,
       deps.upsertYomitanDictionarySettings(dictionaryTitle, config.profileScope),