sudacode/SubMiner
1
0
Fork 0
mirror of https://github.com/ksyasuda/SubMiner.git synced 2026-02-27 18:22:41 -08:00
Code Issues Packages Projects Releases Wiki Activity

perf(main): buffer MPV OSD log writes asynchronously

Browse Source 
Move OSD log appends off sync fs calls to reduce main-process blocking under frequent OSD activity. Add buffered flush wiring into quit cleanup so pending log lines are drained best-effort during shutdown.
This commit is contained in:
Kyle Yasuda
2026-02-21 15:51:11 -08:00
parent 10b94ce889
commit 7e1a7df403
13 changed files with 221 additions and 64 deletions
Download Patch File Download Diff File Expand all files Collapse all files

47
backlog/tasks/task-75 - Move-mpv-osd-log-writes-to-buffered-async-path.md
View File

@@ -1,10 +1,10 @@
---
id: TASK-75
title: Move mpv OSD log writes to buffered async path
status: To Do
status: Done
assignee: []
created_date: '2026-02-18 11:35'
updated_date: '2026-02-18 11:35'
updated_date: '2026-02-21 23:48'
labels:
- logging
- performance
@@ -31,14 +31,45 @@ priority: low
## Acceptance Criteria
<!-- AC:BEGIN -->
- [ ] #1 OSD log path no longer uses synchronous fs calls
- [ ] #2 Logging remains best-effort and does not break runtime behavior on fs failure
- [ ] #3 Shutdown flush behavior verified by tests
- [x] #1 OSD log path no longer uses synchronous fs calls
- [x] #2 Logging remains best-effort and does not break runtime behavior on fs failure
- [x] #3 Shutdown flush behavior verified by tests
<!-- AC:END -->
## Implementation Plan
<!-- SECTION:PLAN:BEGIN -->
1) Add failing tests for buffered async MPV OSD log behavior + explicit flush semantics in mpv-osd runtime tests.
2) Replace sync mpv-osd log deps/handler with buffered async queue/drain implementation and expose flushMpvLog runtime surface.
3) Wire flushMpvLog into onWillQuit cleanup deps/action path and main.ts runtime composition.
4) Add shutdown-flush assertions in lifecycle cleanup tests.
5) Run `bun run build && bun run test:core:dist`, then record AC/DoD evidence and finalize task metadata.
<!-- SECTION:PLAN:END -->
## Implementation Notes
<!-- SECTION:NOTES:BEGIN -->
2026-02-21: Started execution in codex session `codex-task75-mpv-osd-buffered-20260221T231816Z-yj32`. Running writing-plans then executing-plans workflow; no commit requested.
Implemented buffered async MPV OSD log path in `src/main/runtime/mpv-osd-log.ts` with queued drains and explicit `flushMpvLog()` surface; removed sync fs dependency usage from runtime wiring in `src/main.ts`.
Wired shutdown flush into startup lifecycle cleanup via `flushMpvLog` dependency in `app-lifecycle-main-cleanup` + `app-lifecycle-actions` so quit cleanup invokes pending log drain before socket destroy.
Added/updated tests for async queueing, best-effort fs failures, runtime composition flush surface, and shutdown cleanup flush invocation across mpv-osd and lifecycle runtime tests.
Verification: `bun run test:core:src` PASS (219 pass, 0 fail); focused runtime tests PASS via bundled node lane: `bun build ... --outdir /tmp/task75-tests && node --test /tmp/task75-tests/*.js`.
`bun run build` currently fails on pre-existing unrelated tokenizer typing issue at `src/core/services/tokenizer.ts` (`Logger` not assignable to `LoggerLike`).
<!-- SECTION:NOTES:END -->
## Final Summary
<!-- SECTION:FINAL_SUMMARY:BEGIN -->
Moved MPV OSD log writes off sync fs APIs by introducing buffered async queue/drain behavior with explicit flush support and preserving best-effort failure semantics. Integrated shutdown flush into on-will-quit cleanup and added targeted runtime/lifecycle tests to verify queue flush + quit-time drain behavior without user-visible OSD regression.
<!-- SECTION:FINAL_SUMMARY:END -->
## Definition of Done
<!-- DOD:BEGIN -->
- [ ] #1 Core tests pass with new logging path
- [ ] #2 No user-visible regression in MPV OSD/log output behavior
- [x] #1 Core tests pass with new logging path
- [x] #2 No user-visible regression in MPV OSD/log output behavior
<!-- DOD:END -->

41
src/main.ts
View File

@@ -68,7 +68,11 @@ import { createLogger, setLogLevel, type LogLevelSource } from './logger';
import { commandNeedsOverlayRuntime, parseArgs, shouldStartApp } from './cli/args';
import type { CliArgs, CliCommandSource } from './cli/args';
import { printHelp } from './cli/help';
import { buildConfigWarningNotificationBody } from './main/config-validation';
import {
buildConfigParseErrorDetails,
buildConfigWarningNotificationBody,
failStartupFromConfig,
} from './main/config-validation';
import { createImmersionMediaRuntime } from './main/runtime/domains/startup';
import { createAnilistStateRuntime } from './main/runtime/domains/anilist';
import { createConfigDerivedRuntime } from './main/runtime/domains/startup';
@@ -420,6 +424,7 @@ import {
} from './main/anilist-url-guard';
import {
ConfigService,
ConfigStartupParseError,
DEFAULT_CONFIG,
DEFAULT_KEYBINDINGS,
generateConfigTemplate,
@@ -511,7 +516,24 @@ const CONFIG_DIR = resolveConfigDir({
const USER_DATA_PATH = CONFIG_DIR;
const DEFAULT_MPV_LOG_PATH = process.env.SUBMINER_MPV_LOG?.trim() || DEFAULT_MPV_LOG_FILE;
const DEFAULT_IMMERSION_DB_PATH = path.join(USER_DATA_PATH, 'immersion.sqlite');
const configService = new ConfigService(CONFIG_DIR);
const configService = (() => {
try {
return new ConfigService(CONFIG_DIR);
} catch (error) {
if (error instanceof ConfigStartupParseError) {
failStartupFromConfig(
'SubMiner config parse error',
buildConfigParseErrorDetails(error.path, error.parseError),
{
logError: (details) => console.error(details),
showErrorBox: (title, details) => dialog.showErrorBox(title, details),
quit: () => app.quit(),
},
);
}
throw error;
}
})();
const anilistTokenStore = createAnilistTokenStore(
path.join(USER_DATA_PATH, ANILIST_TOKEN_STORE_FILE),
{
@@ -1719,6 +1741,7 @@ const saveSubtitlePositionMainDeps = buildSaveSubtitlePositionMainDepsHandler();
const saveSubtitlePosition = createSaveSubtitlePositionHandler(saveSubtitlePositionMainDeps);
registerSubminerProtocolClient();
let flushPendingMpvLogWrites = (): void => {};
const {
registerProtocolUrlHandlers: registerProtocolUrlHandlersHandler,
onWillQuitCleanup: onWillQuitCleanupHandler,
@@ -1755,6 +1778,7 @@ const {
appState.yomitanParserInitPromise = null;
},
getWindowTracker: () => appState.windowTracker,
flushMpvLog: () => flushPendingMpvLogWrites(),
getMpvSocket: () => appState.mpvClient?.socket ?? null,
getReconnectTimer: () => appState.reconnectTimer,
clearReconnectTimerRef: () => {
@@ -2305,12 +2329,16 @@ const {
},
});
const { appendToMpvLog, showMpvOsd } = createMpvOsdRuntimeHandlers({
const { appendToMpvLog, flushMpvLog, showMpvOsd } = createMpvOsdRuntimeHandlers({
appendToMpvLogMainDeps: {
logPath: DEFAULT_MPV_LOG_PATH,
dirname: (targetPath) => path.dirname(targetPath),
mkdirSync: (targetPath, options) => fs.mkdirSync(targetPath, options),
appendFileSync: (targetPath, data, options) => fs.appendFileSync(targetPath, data, options),
mkdir: async (targetPath, options) => {
await fs.promises.mkdir(targetPath, options);
},
appendFile: async (targetPath, data, options) => {
await fs.promises.appendFile(targetPath, data, options);
},
now: () => new Date(),
},
buildShowMpvOsdMainDeps: (appendToMpvLogHandler) => ({
@@ -2321,6 +2349,9 @@ const { appendToMpvLog, showMpvOsd } = createMpvOsdRuntimeHandlers({
logInfo: (line) => logger.info(line),
}),
});
flushPendingMpvLogWrites = () => {
void flushMpvLog();
};
const cycleSecondarySubMode = createCycleSecondarySubModeRuntimeHandler({
cycleSecondarySubModeMainDeps: {

4
src/main/runtime/app-lifecycle-actions.test.ts
View File

@@ -18,6 +18,7 @@ test('on will quit cleanup handler runs all cleanup steps', () => {
destroyYomitanParserWindow: () => calls.push('destroy-yomitan-window'),
clearYomitanParserState: () => calls.push('clear-yomitan-state'),
stopWindowTracker: () => calls.push('stop-tracker'),
flushMpvLog: () => calls.push('flush-mpv-log'),
destroyMpvSocket: () => calls.push('destroy-socket'),
clearReconnectTimer: () => calls.push('clear-reconnect'),
destroySubtitleTimingTracker: () => calls.push('destroy-subtitle-tracker'),
@@ -31,9 +32,10 @@ test('on will quit cleanup handler runs all cleanup steps', () => {
});
cleanup();
assert.equal(calls.length, 19);
assert.equal(calls.length, 20);
assert.equal(calls[0], 'destroy-tray');
assert.equal(calls[calls.length - 1], 'stop-jellyfin-remote');
assert.ok(calls.indexOf('flush-mpv-log') < calls.indexOf('destroy-socket'));
});
test('should restore windows on activate requires initialized runtime and no windows', () => {

2
src/main/runtime/app-lifecycle-actions.ts
View File

@@ -8,6 +8,7 @@ export function createOnWillQuitCleanupHandler(deps: {
destroyYomitanParserWindow: () => void;
clearYomitanParserState: () => void;
stopWindowTracker: () => void;
flushMpvLog: () => void;
destroyMpvSocket: () => void;
clearReconnectTimer: () => void;
destroySubtitleTimingTracker: () => void;
@@ -29,6 +30,7 @@ export function createOnWillQuitCleanupHandler(deps: {
deps.destroyYomitanParserWindow();
deps.clearYomitanParserState();
deps.stopWindowTracker();
deps.flushMpvLog();
deps.destroyMpvSocket();
deps.clearReconnectTimer();
deps.destroySubtitleTimingTracker();

3
src/main/runtime/app-lifecycle-main-cleanup.test.ts
View File

@@ -25,6 +25,7 @@ test('cleanup deps builder returns handlers that guard optional runtime objects'
clearYomitanParserState: () => calls.push('clear-yomitan-state'),
getWindowTracker: () => ({ stop: () => calls.push('stop-tracker') }),
flushMpvLog: () => calls.push('flush-mpv-log'),
getMpvSocket: () => ({ destroy: () => calls.push('destroy-socket') }),
getReconnectTimer: () => reconnectTimer,
clearReconnectTimerRef: () => {
@@ -53,6 +54,7 @@ test('cleanup deps builder returns handlers that guard optional runtime objects'
assert.ok(calls.includes('destroy-tray'));
assert.ok(calls.includes('destroy-yomitan-window'));
assert.ok(calls.includes('flush-mpv-log'));
assert.ok(calls.includes('destroy-socket'));
assert.ok(calls.includes('clear-reconnect-ref'));
assert.ok(calls.includes('destroy-immersion'));
@@ -77,6 +79,7 @@ test('cleanup deps builder skips destroyed yomitan window', () => {
}),
clearYomitanParserState: () => {},
getWindowTracker: () => null,
flushMpvLog: () => {},
getMpvSocket: () => null,
getReconnectTimer: () => null,
clearReconnectTimerRef: () => {},

2
src/main/runtime/app-lifecycle-main-cleanup.ts
View File

@@ -29,6 +29,7 @@ export function createBuildOnWillQuitCleanupDepsHandler(deps: {
clearYomitanParserState: () => void;
getWindowTracker: () => Stoppable | null;
flushMpvLog: () => void;
getMpvSocket: () => SocketLike | null;
getReconnectTimer: () => TimerLike | null;
clearReconnectTimerRef: () => void;
@@ -63,6 +64,7 @@ export function createBuildOnWillQuitCleanupDepsHandler(deps: {
const tracker = deps.getWindowTracker();
tracker?.stop();
},
flushMpvLog: () => deps.flushMpvLog(),
destroyMpvSocket: () => {
const socket = deps.getMpvSocket();
socket?.destroy();

1
src/main/runtime/composers/startup-lifecycle-composer.test.ts
View File

@@ -22,6 +22,7 @@ test('composeStartupLifecycleHandlers returns callable startup lifecycle handler
getYomitanParserWindow: () => null,
clearYomitanParserState: () => {},
getWindowTracker: () => null,
flushMpvLog: () => {},
getMpvSocket: () => null,
getReconnectTimer: () => null,
clearReconnectTimerRef: () => {},

14
src/main/runtime/mpv-osd-log-main-deps.test.ts
View File

@@ -5,7 +5,7 @@ import {
createBuildShowMpvOsdMainDepsHandler,
} from './mpv-osd-log-main-deps';
test('append to mpv log main deps map filesystem functions and log path', () => {
test('append to mpv log main deps map filesystem functions and log path', async () => {
const calls: string[] = [];
const deps = createBuildAppendToMpvLogMainDepsHandler({
logPath: '/tmp/mpv.log',
@@ -13,15 +13,19 @@ test('append to mpv log main deps map filesystem functions and log path', () =>
calls.push(`dirname:${targetPath}`);
return '/tmp';
},
mkdirSync: (targetPath) => calls.push(`mkdir:${targetPath}`),
appendFileSync: (_targetPath, data) => calls.push(`append:${data}`),
mkdir: async (targetPath) => {
calls.push(`mkdir:${targetPath}`);
},
appendFile: async (_targetPath, data) => {
calls.push(`append:${data}`);
},
now: () => new Date('2026-02-20T00:00:00.000Z'),
})();
assert.equal(deps.logPath, '/tmp/mpv.log');
assert.equal(deps.dirname('/tmp/mpv.log'), '/tmp');
deps.mkdirSync('/tmp', { recursive: true });
deps.appendFileSync('/tmp/mpv.log', 'line', { encoding: 'utf8' });
await deps.mkdir('/tmp', { recursive: true });
await deps.appendFile('/tmp/mpv.log', 'line', { encoding: 'utf8' });
assert.equal(deps.now().toISOString(), '2026-02-20T00:00:00.000Z');
assert.deepEqual(calls, ['dirname:/tmp/mpv.log', 'mkdir:/tmp', 'append:line']);
});

11
src/main/runtime/mpv-osd-log-main-deps.ts
View File

@@ -1,17 +1,16 @@
export function createBuildAppendToMpvLogMainDepsHandler(deps: {
logPath: string;
dirname: (targetPath: string) => string;
mkdirSync: (targetPath: string, options: { recursive: boolean }) => void;
appendFileSync: (targetPath: string, data: string, options: { encoding: 'utf8' }) => void;
mkdir: (targetPath: string, options: { recursive: boolean }) => Promise<void>;
appendFile: (targetPath: string, data: string, options: { encoding: 'utf8' }) => Promise<void>;
now: () => Date;
}) {
return () => ({
logPath: deps.logPath,
dirname: (targetPath: string) => deps.dirname(targetPath),
mkdirSync: (targetPath: string, options: { recursive: boolean }) =>
deps.mkdirSync(targetPath, options),
appendFileSync: (targetPath: string, data: string, options: { encoding: 'utf8' }) =>
deps.appendFileSync(targetPath, data, options),
mkdir: (targetPath: string, options: { recursive: boolean }) => deps.mkdir(targetPath, options),
appendFile: (targetPath: string, data: string, options: { encoding: 'utf8' }) =>
deps.appendFile(targetPath, data, options),
now: () => deps.now(),
});
}

82
src/main/runtime/mpv-osd-log.test.ts
View File

@@ -3,44 +3,92 @@ import assert from 'node:assert/strict';
import { createAppendToMpvLogHandler, createShowMpvOsdHandler } from './mpv-osd-log';
test('append mpv log writes timestamped message', () => {
const calls: string[] = [];
const appendToMpvLog = createAppendToMpvLogHandler({
const writes: string[] = [];
const { appendToMpvLog, flushMpvLog } = createAppendToMpvLogHandler({
logPath: '/tmp/subminer/mpv.log',
dirname: (targetPath) => {
calls.push(`dirname:${targetPath}`);
dirname: (targetPath: string) => {
writes.push(`dirname:${targetPath}`);
return '/tmp/subminer';
},
mkdirSync: (targetPath) => {
calls.push(`mkdir:${targetPath}`);
mkdir: async (targetPath: string) => {
writes.push(`mkdir:${targetPath}`);
},
appendFileSync: (_targetPath, data) => {
calls.push(`append:${data.trimEnd()}`);
appendFile: async (_targetPath: string, data: string) => {
writes.push(`append:${data.trimEnd()}`);
},
now: () => new Date('2026-02-20T00:00:00.000Z'),
});
appendToMpvLog('hello');
assert.deepEqual(calls, [
'dirname:/tmp/subminer/mpv.log',
'mkdir:/tmp/subminer',
'append:[2026-02-20T00:00:00.000Z] hello',
]);
return flushMpvLog().then(() => {
assert.deepEqual(writes, [
'dirname:/tmp/subminer/mpv.log',
'mkdir:/tmp/subminer',
'append:[2026-02-20T00:00:00.000Z] hello',
]);
});
});
test('append mpv log swallows filesystem errors', () => {
const appendToMpvLog = createAppendToMpvLogHandler({
test('append mpv log queues multiple messages and flush waits for pending write', async () => {
const writes: string[] = [];
const { appendToMpvLog, flushMpvLog } = createAppendToMpvLogHandler({
logPath: '/tmp/subminer/mpv.log',
dirname: () => '/tmp/subminer',
mkdirSync: () => {
mkdir: async () => {
writes.push('mkdir');
},
appendFile: async (_targetPath: string, data: string) => {
writes.push(`append:${data.trimEnd()}`);
await new Promise<void>((resolve) => {
setTimeout(resolve, 25);
});
},
now: (() => {
const values = ['2026-02-20T00:00:00.000Z', '2026-02-20T00:00:01.000Z'];
let index = 0;
return () => {
const nextValue = values[index] ?? values[values.length - 1] ?? values[0] ?? '';
index += 1;
return new Date(nextValue);
};
})(),
});
appendToMpvLog('first');
appendToMpvLog('second');
let flushed = false;
const flushPromise = flushMpvLog().then(() => {
flushed = true;
});
await Promise.resolve();
assert.equal(flushed, false);
await flushPromise;
const appendedPayload = writes
.filter((entry) => entry.startsWith('append:'))
.map((entry) => entry.replace('append:', ''))
.join('\n');
assert.ok(appendedPayload.includes('[2026-02-20T00:00:00.000Z] first'));
assert.ok(appendedPayload.includes('[2026-02-20T00:00:01.000Z] second'));
});
test('append mpv log swallows async filesystem errors', async () => {
const { appendToMpvLog, flushMpvLog } = createAppendToMpvLogHandler({
logPath: '/tmp/subminer/mpv.log',
dirname: () => '/tmp/subminer',
mkdir: async () => {
throw new Error('disk error');
},
appendFileSync: () => {
appendFile: async () => {
throw new Error('should not reach');
},
now: () => new Date('2026-02-20T00:00:00.000Z'),
});
assert.doesNotThrow(() => appendToMpvLog('hello'));
await assert.doesNotReject(async () => flushMpvLog());
});
test('show mpv osd logs marker and forwards fallback logging', () => {

56
src/main/runtime/mpv-osd-log.ts
View File

@@ -3,24 +3,52 @@ import type { MpvRuntimeClientLike } from '../../core/services/mpv';
export function createAppendToMpvLogHandler(deps: {
logPath: string;
dirname: (targetPath: string) => string;
mkdirSync: (targetPath: string, options: { recursive: boolean }) => void;
appendFileSync: (
targetPath: string,
data: string,
options: { encoding: 'utf8' },
) => void;
mkdir: (targetPath: string, options: { recursive: boolean }) => Promise<void>;
appendFile: (targetPath: string, data: string, options: { encoding: 'utf8' }) => Promise<void>;
now: () => Date;
}) {
return (message: string): void => {
try {
deps.mkdirSync(deps.dirname(deps.logPath), { recursive: true });
deps.appendFileSync(deps.logPath, `[${deps.now().toISOString()}] ${message}\n`, {
encoding: 'utf8',
});
} catch {
// best-effort logging
const pendingLines: string[] = [];
let drainPromise: Promise<void> | null = null;
const drainPendingLines = async (): Promise<void> => {
while (pendingLines.length > 0) {
const chunk = pendingLines.splice(0, pendingLines.length).join('');
try {
await deps.mkdir(deps.dirname(deps.logPath), { recursive: true });
await deps.appendFile(deps.logPath, chunk, { encoding: 'utf8' });
} catch {
// best-effort logging
}
}
};
const scheduleDrain = (): Promise<void> => {
if (drainPromise) return drainPromise;
drainPromise = (async () => {
try {
await drainPendingLines();
} finally {
drainPromise = null;
}
})();
return drainPromise;
};
const appendToMpvLog = (message: string): void => {
pendingLines.push(`[${deps.now().toISOString()}] ${message}\n`);
void scheduleDrain();
};
const flushMpvLog = async (): Promise<void> => {
while (pendingLines.length > 0 || drainPromise) {
await scheduleDrain();
}
};
return {
appendToMpvLog,
flushMpvLog,
};
}
export function createShowMpvOsdHandler(deps: {

11
src/main/runtime/mpv-osd-runtime-handlers.test.ts
View File

@@ -2,14 +2,16 @@ import assert from 'node:assert/strict';
import test from 'node:test';
import { createMpvOsdRuntimeHandlers } from './mpv-osd-runtime-handlers';
test('mpv osd runtime handlers compose append and osd logging flow', () => {
test('mpv osd runtime handlers compose append and osd logging flow', async () => {
const calls: string[] = [];
const runtime = createMpvOsdRuntimeHandlers({
appendToMpvLogMainDeps: {
logPath: '/tmp/subminer/mpv.log',
dirname: () => '/tmp/subminer',
mkdirSync: () => {},
appendFileSync: (_targetPath, data) => calls.push(`append:${data.trimEnd()}`),
mkdir: async () => {},
appendFile: async (_targetPath: string, data: string) => {
calls.push(`append:${data.trimEnd()}`);
},
now: () => new Date('2026-02-20T00:00:00.000Z'),
},
buildShowMpvOsdMainDeps: (appendToMpvLog) => ({
@@ -24,10 +26,11 @@ test('mpv osd runtime handlers compose append and osd logging flow', () => {
});
runtime.showMpvOsd('hello');
await runtime.flushMpvLog();
assert.deepEqual(calls, [
'append:[2026-02-20T00:00:00.000Z] [OSD] hello',
'show:hello',
'info:fallback',
'append:[2026-02-20T00:00:00.000Z] [OSD] hello',
]);
});

11
src/main/runtime/mpv-osd-runtime-handlers.ts
View File

@@ -11,10 +11,12 @@ export function createMpvOsdRuntimeHandlers(deps: {
appendToMpvLogMainDeps: AppendToMpvLogMainDeps;
buildShowMpvOsdMainDeps: (appendToMpvLog: (message: string) => void) => ShowMpvOsdMainDeps;
}) {
const appendToMpvLogMainDeps =
createBuildAppendToMpvLogMainDepsHandler(deps.appendToMpvLogMainDeps)();
const appendToMpvLogHandler = createAppendToMpvLogHandler(appendToMpvLogMainDeps);
const appendToMpvLog = (message: string) => appendToMpvLogHandler(message);
const appendToMpvLogMainDeps = createBuildAppendToMpvLogMainDepsHandler(
deps.appendToMpvLogMainDeps,
)();
const appendToMpvLogRuntime = createAppendToMpvLogHandler(appendToMpvLogMainDeps);
const appendToMpvLog = (message: string) => appendToMpvLogRuntime.appendToMpvLog(message);
const flushMpvLog = async () => appendToMpvLogRuntime.flushMpvLog();
const showMpvOsdMainDeps = createBuildShowMpvOsdMainDepsHandler(
deps.buildShowMpvOsdMainDeps(appendToMpvLog),
@@ -24,6 +26,7 @@ export function createMpvOsdRuntimeHandlers(deps: {
return {
appendToMpvLog,
flushMpvLog,
showMpvOsd,
};
}