fix(startup): replace fixed overlay sleeps with readiness retries

This commit is contained in:
2026-02-27 21:02:21 -08:00
parent cc2f9ef325
commit 895401de51
5 changed files with 728 additions and 5 deletions

View File

@@ -0,0 +1,72 @@
---
id: TASK-73
title: 'MPV plugin: split into modules and optimize startup/command runtime'
status: In Progress
assignee: []
created_date: '2026-02-28 20:50'
labels: []
dependencies: []
references:
- plugin/subminer/main.lua
- plugin/subminer/bootstrap.lua
- plugin/subminer/process.lua
- plugin/subminer/lifecycle.lua
- plugin/subminer/messages.lua
- plugin/subminer/ui.lua
- plugin/subminer/hover.lua
- plugin/subminer/options.lua
- plugin/subminer/state.lua
- plugin/subminer.conf
- scripts/test-plugin-start-gate.lua
- scripts/test-plugin-process-start-retries.lua
- launcher/commands/playback-command.ts
- launcher/mpv.ts
- launcher/mpv.test.ts
- launcher/smoke.e2e.test.ts
- Makefile
- package.json
- docs/mpv-plugin.md
- docs/installation.md
- docs/architecture.md
- README.md
priority: medium
---
## Description
<!-- SECTION:DESCRIPTION:BEGIN -->
Scope: Replace monolithic `plugin/subminer.lua` with modular plugin runtime; optimize command execution paths; align install/docs/tests; fix launcher smoke instability.
Delivered behavior:
- Full plugin cutover to `plugin/subminer/main.lua` + module directory (no runtime compatibility shim with old monolith file).
- Process/control command path moved toward async subprocess usage for non-start actions (`stop`, `toggle`, `settings`, restart stop leg), reducing synchronous blocking in mpv script runtime.
- Startup/runtime loading updated with lazy module initialization via bootstrap proxies.
- Plugin install flow updated to copy `plugin/subminer/` directory and remove legacy `~/.config/mpv/scripts/subminer.lua` file.
- Added plugin gate script wiring to package scripts (`test:plugin:src`) and launcher test flow.
- Smoke tests stabilized across sandbox environments where UNIX socket bind can return `EPERM` while preserving normal-path assertions.
- Playback command cleanup race fixed when mpv exits before exit-listener registration.
Risk/impact context:
- mpv plugin loading path changed from single-file to module directory; packaging/install paths must stay consistent with release assets.
- Async control path changes reduce blocking but can surface timing differences; regression checks added for cold start and launcher smoke behavior.
<!-- SECTION:DESCRIPTION:END -->
## Final Summary
<!-- SECTION:FINAL_SUMMARY:BEGIN -->
Startup fixed-sleep removal delivered in launcher + plugin start paths:
- `launcher/mpv.ts:startOverlay` no longer blocks on hard `2000ms`; now uses bounded readiness/event checks:
- bounded wait for mpv IPC socket readiness
- bounded wait for spawned overlay command settle (`exit`/`error`)
- `plugin/subminer/process.lua` removed fixed `0.35s` texthooker delay and fixed `0.6s` startup visibility delay.
- Overlay start now uses short bounded retries on non-ready start failures, then applies startup overlay visibility once start succeeds.
Regression coverage added:
- `launcher/mpv.test.ts` adds guard that `startOverlay` resolves quickly when readiness arrives.
- `scripts/test-plugin-process-start-retries.lua` asserts retry behavior and guards against reintroducing fixed `0.35/0.6` timers.
Validation run:
- `bun test launcher/mpv.test.ts` pass.
- `lua scripts/test-plugin-process-start-retries.lua` pass.
- Existing broader plugin gate suite still has unrelated failure in current tree (`scripts/test-plugin-start-gate.lua` AniSkip async curl assertion).
<!-- SECTION:FINAL_SUMMARY:END -->

View File

@@ -4,7 +4,8 @@ import fs from 'node:fs';
import path from 'node:path';
import net from 'node:net';
import { EventEmitter } from 'node:events';
import { waitForUnixSocketReady } from './mpv';
import type { Args } from './types';
import { startOverlay, state, waitForUnixSocketReady } from './mpv';
import * as mpvModule from './mpv';
function createTempSocketPath(): { dir: string; socketPath: string } {
@@ -59,3 +60,82 @@ test('waitForUnixSocketReady returns true when socket becomes connectable before
fs.rmSync(dir, { recursive: true, force: true });
}
});
function makeArgs(overrides: Partial<Args> = {}): Args {
return {
backend: 'x11',
directory: '.',
recursive: false,
profile: '',
startOverlay: false,
youtubeSubgenMode: 'off',
whisperBin: '',
whisperModel: '',
youtubeSubgenOutDir: '',
youtubeSubgenAudioFormat: 'wav',
youtubeSubgenKeepTemp: false,
youtubePrimarySubLangs: [],
youtubeSecondarySubLangs: [],
youtubeAudioLangs: [],
youtubeWhisperSourceLanguage: 'ja',
useTexthooker: false,
autoStartOverlay: false,
texthookerOnly: false,
useRofi: false,
logLevel: 'error',
passwordStore: '',
target: '',
targetKind: '',
jimakuApiKey: '',
jimakuApiKeyCommand: '',
jimakuApiBaseUrl: '',
jimakuLanguagePreference: 'none',
jimakuMaxEntryResults: 10,
jellyfin: false,
jellyfinLogin: false,
jellyfinLogout: false,
jellyfinPlay: false,
jellyfinDiscovery: false,
doctor: false,
configPath: false,
configShow: false,
mpvIdle: false,
mpvSocket: false,
mpvStatus: false,
appPassthrough: false,
appArgs: [],
jellyfinServer: '',
jellyfinUsername: '',
jellyfinPassword: '',
...overrides,
};
}
test('startOverlay resolves without fixed 2s sleep when readiness signals arrive quickly', async () => {
const { dir, socketPath } = createTempSocketPath();
const appPath = path.join(dir, 'fake-subminer.sh');
fs.writeFileSync(appPath, '#!/bin/sh\nexit 0\n');
fs.chmodSync(appPath, 0o755);
fs.writeFileSync(socketPath, '');
const originalCreateConnection = net.createConnection;
try {
net.createConnection = (() => {
const socket = new EventEmitter() as net.Socket;
socket.destroy = (() => socket) as net.Socket['destroy'];
socket.setTimeout = (() => socket) as net.Socket['setTimeout'];
setTimeout(() => socket.emit('connect'), 10);
return socket;
}) as typeof net.createConnection;
const startedAt = Date.now();
await startOverlay(appPath, makeArgs(), socketPath);
const elapsedMs = Date.now() - startedAt;
assert.ok(elapsedMs < 1200, `expected startOverlay <1200ms, got ${elapsedMs}ms`);
} finally {
net.createConnection = originalCreateConnection;
state.overlayProc = null;
state.overlayManagedByLauncher = false;
fs.rmSync(dir, { recursive: true, force: true });
}
});

View File

@@ -28,6 +28,8 @@ export const state = {
};
const DETACHED_IDLE_MPV_PID_FILE = path.join(os.tmpdir(), 'subminer-idle-mpv.pid');
const OVERLAY_START_SOCKET_READY_TIMEOUT_MS = 900;
const OVERLAY_START_COMMAND_SETTLE_TIMEOUT_MS = 700;
function readTrackedDetachedMpvPid(): number | null {
try {
@@ -498,7 +500,47 @@ export function startMpv(
state.mpvProc = spawn('mpv', mpvArgs, { stdio: 'inherit' });
}
export function startOverlay(appPath: string, args: Args, socketPath: string): Promise<void> {
async function waitForOverlayStartCommandSettled(
proc: ReturnType<typeof spawn>,
logLevel: LogLevel,
timeoutMs: number,
): Promise<void> {
await new Promise<void>((resolve) => {
let settled = false;
let timer: ReturnType<typeof setTimeout> | null = null;
const finish = () => {
if (settled) return;
settled = true;
if (timer) clearTimeout(timer);
proc.off('exit', onExit);
proc.off('error', onError);
resolve();
};
const onExit = (code: number | null) => {
if (typeof code === 'number' && code !== 0) {
log('warn', logLevel, `Overlay start command exited with status ${code}`);
}
finish();
};
const onError = (error: Error) => {
log('warn', logLevel, `Overlay start command failed: ${error.message}`);
finish();
};
proc.once('exit', onExit);
proc.once('error', onError);
timer = setTimeout(finish, timeoutMs);
if (proc.exitCode !== null && proc.exitCode !== undefined) {
onExit(proc.exitCode);
}
});
}
export async function startOverlay(appPath: string, args: Args, socketPath: string): Promise<void> {
const backend = detectBackend(args.backend);
log('info', args.logLevel, `Starting SubMiner overlay (backend: ${backend})...`);
@@ -512,9 +554,22 @@ export function startOverlay(appPath: string, args: Args, socketPath: string): P
});
state.overlayManagedByLauncher = true;
return new Promise((resolve) => {
setTimeout(resolve, 2000);
});
const [socketReady] = await Promise.all([
waitForUnixSocketReady(socketPath, OVERLAY_START_SOCKET_READY_TIMEOUT_MS),
waitForOverlayStartCommandSettled(
state.overlayProc,
args.logLevel,
OVERLAY_START_COMMAND_SETTLE_TIMEOUT_MS,
),
]);
if (!socketReady) {
log(
'debug',
args.logLevel,
'Overlay start continuing before mpv socket readiness was confirmed',
);
}
}
export function launchTexthookerOnly(appPath: string, args: Args): never {

388
plugin/subminer/process.lua Normal file
View File

@@ -0,0 +1,388 @@
local M = {}
local OVERLAY_START_RETRY_DELAY_SECONDS = 0.2
local OVERLAY_START_MAX_ATTEMPTS = 6
local STARTUP_OVERLAY_ACTION_RETRY_DELAY_SECONDS = 0.2
local STARTUP_OVERLAY_ACTION_MAX_ATTEMPTS = 6
function M.create(ctx)
local mp = ctx.mp
local opts = ctx.opts
local state = ctx.state
local binary = ctx.binary
local environment = ctx.environment
local options_helper = ctx.options_helper
local subminer_log = ctx.log.subminer_log
local show_osd = ctx.log.show_osd
local normalize_log_level = ctx.log.normalize_log_level
local function resolve_backend(override_backend)
local selected = override_backend
if selected == nil or selected == "" then
selected = opts.backend
end
if selected == "auto" then
return environment.detect_backend()
end
return selected
end
local function build_command_args(action, overrides)
overrides = overrides or {}
local args = { state.binary_path }
table.insert(args, "--" .. action)
local log_level = normalize_log_level(overrides.log_level or opts.log_level)
if log_level ~= "info" then
table.insert(args, "--log-level")
table.insert(args, log_level)
end
if action == "start" then
local backend = resolve_backend(overrides.backend)
if backend and backend ~= "" then
table.insert(args, "--backend")
table.insert(args, backend)
end
local socket_path = overrides.socket_path or opts.socket_path
table.insert(args, "--socket")
table.insert(args, socket_path)
end
return args
end
local function run_control_command_async(action, overrides, callback)
local args = build_command_args(action, overrides)
subminer_log("debug", "process", "Control command: " .. table.concat(args, " "))
mp.command_native_async({
name = "subprocess",
args = args,
playback_only = false,
capture_stdout = true,
capture_stderr = true,
}, function(success, result, error)
local ok = success and (result == nil or result.status == 0)
if callback then
callback(ok, result, error)
end
end)
end
local function parse_start_script_message_overrides(...)
local overrides = {}
for i = 1, select("#", ...) do
local token = select(i, ...)
if type(token) == "string" and token ~= "" then
local key, value = token:match("^([%w_%-]+)=(.+)$")
if key and value then
local normalized_key = key:lower()
if normalized_key == "backend" then
local backend = value:lower()
if backend == "auto" or backend == "hyprland" or backend == "sway" or backend == "x11" or backend == "macos" then
overrides.backend = backend
end
elseif normalized_key == "socket" or normalized_key == "socket_path" then
overrides.socket_path = value
elseif normalized_key == "texthooker" or normalized_key == "texthooker_enabled" then
local parsed = options_helper.coerce_bool(value, nil)
if parsed ~= nil then
overrides.texthooker_enabled = parsed
end
elseif normalized_key == "log-level" or normalized_key == "log_level" then
overrides.log_level = normalize_log_level(value)
end
end
end
end
return overrides
end
local function resolve_visible_overlay_startup()
return options_helper.coerce_bool(opts.auto_start_visible_overlay, false)
end
local function apply_startup_overlay_preferences()
local should_show_visible = resolve_visible_overlay_startup()
local visible_action = should_show_visible and "show-visible-overlay" or "hide-visible-overlay"
local function try_apply(attempt)
run_control_command_async(visible_action, nil, function(ok)
if ok then
subminer_log(
"debug",
"process",
"Applied visible startup action: " .. visible_action .. " (attempt " .. tostring(attempt) .. ")"
)
return
end
if attempt >= STARTUP_OVERLAY_ACTION_MAX_ATTEMPTS then
subminer_log("warn", "process", "Failed to apply visible startup action: " .. visible_action)
return
end
mp.add_timeout(STARTUP_OVERLAY_ACTION_RETRY_DELAY_SECONDS, function()
try_apply(attempt + 1)
end)
end)
end
try_apply(1)
end
local function build_texthooker_args()
local args = { state.binary_path, "--texthooker", "--port", tostring(opts.texthooker_port) }
local log_level = normalize_log_level(opts.log_level)
if log_level ~= "info" then
table.insert(args, "--log-level")
table.insert(args, log_level)
end
return args
end
local function ensure_texthooker_running(callback)
if not opts.texthooker_enabled then
callback()
return
end
if state.texthooker_running then
callback()
return
end
local args = build_texthooker_args()
subminer_log("info", "texthooker", "Starting texthooker process: " .. table.concat(args, " "))
state.texthooker_running = true
mp.command_native_async({
name = "subprocess",
args = args,
playback_only = false,
capture_stdout = true,
capture_stderr = true,
}, function(success, result, error)
if not success or (result and result.status ~= 0) then
state.texthooker_running = false
subminer_log(
"warn",
"texthooker",
"Texthooker process exited unexpectedly: " .. (error or (result and result.stderr) or "unknown error")
)
end
end)
-- Start overlay immediately; overlay start path retries on readiness failures.
callback()
end
local function start_overlay(overrides)
if not binary.ensure_binary_available() then
subminer_log("error", "binary", "SubMiner binary not found")
show_osd("Error: binary not found")
return
end
if state.overlay_running then
subminer_log("info", "process", "Overlay already running")
show_osd("Already running")
return
end
overrides = overrides or {}
local texthooker_enabled = overrides.texthooker_enabled
if texthooker_enabled == nil then
texthooker_enabled = opts.texthooker_enabled
end
local function launch_overlay_with_retry(attempt)
local args = build_command_args("start", overrides)
if attempt == 1 then
subminer_log("info", "process", "Starting overlay: " .. table.concat(args, " "))
else
subminer_log(
"warn",
"process",
"Retrying overlay start (attempt " .. tostring(attempt) .. "): " .. table.concat(args, " ")
)
end
if attempt == 1 then
show_osd("Starting...")
end
state.overlay_running = true
mp.command_native_async({
name = "subprocess",
args = args,
playback_only = false,
capture_stdout = true,
capture_stderr = true,
}, function(success, result, error)
if not success or (result and result.status ~= 0) then
local reason = error or (result and result.stderr) or "unknown error"
if attempt < OVERLAY_START_MAX_ATTEMPTS then
mp.add_timeout(OVERLAY_START_RETRY_DELAY_SECONDS, function()
launch_overlay_with_retry(attempt + 1)
end)
return
end
state.overlay_running = false
subminer_log("error", "process", "Overlay start failed after retries: " .. reason)
show_osd("Overlay start failed")
return
end
apply_startup_overlay_preferences()
end)
end
if texthooker_enabled then
ensure_texthooker_running(function()
launch_overlay_with_retry(1)
end)
else
launch_overlay_with_retry(1)
end
end
local function start_overlay_from_script_message(...)
local overrides = parse_start_script_message_overrides(...)
start_overlay(overrides)
end
local function stop_overlay()
if not binary.ensure_binary_available() then
subminer_log("error", "binary", "SubMiner binary not found")
show_osd("Error: binary not found")
return
end
run_control_command_async("stop", nil, function(ok, result)
if ok then
subminer_log("info", "process", "Overlay stopped")
else
subminer_log(
"warn",
"process",
"Stop command returned non-zero status: " .. tostring(result and result.status or "unknown")
)
end
end)
state.overlay_running = false
state.texthooker_running = false
show_osd("Stopped")
end
local function toggle_overlay()
if not binary.ensure_binary_available() then
subminer_log("error", "binary", "SubMiner binary not found")
show_osd("Error: binary not found")
return
end
run_control_command_async("toggle", nil, function(ok)
if not ok then
subminer_log("warn", "process", "Toggle command failed")
show_osd("Toggle failed")
end
end)
end
local function open_options()
if not binary.ensure_binary_available() then
subminer_log("error", "binary", "SubMiner binary not found")
show_osd("Error: binary not found")
return
end
run_control_command_async("settings", nil, function(ok)
if ok then
subminer_log("info", "process", "Options window opened")
show_osd("Options opened")
else
subminer_log("warn", "process", "Failed to open options")
show_osd("Failed to open options")
end
end)
end
local function restart_overlay()
if not binary.ensure_binary_available() then
subminer_log("error", "binary", "SubMiner binary not found")
show_osd("Error: binary not found")
return
end
subminer_log("info", "process", "Restarting overlay...")
show_osd("Restarting...")
run_control_command_async("stop", nil, function()
state.overlay_running = false
state.texthooker_running = false
ensure_texthooker_running(function()
local start_args = build_command_args("start")
subminer_log("info", "process", "Starting overlay: " .. table.concat(start_args, " "))
state.overlay_running = true
mp.command_native_async({
name = "subprocess",
args = start_args,
playback_only = false,
capture_stdout = true,
capture_stderr = true,
}, function(success, result, error)
if not success or (result and result.status ~= 0) then
state.overlay_running = false
subminer_log(
"error",
"process",
"Overlay start failed: " .. (error or (result and result.stderr) or "unknown error")
)
show_osd("Restart failed")
else
show_osd("Restarted successfully")
end
end)
end)
end)
end
local function check_status()
if not binary.ensure_binary_available() then
show_osd("Status: binary not found")
return
end
local status = state.overlay_running and "running" or "stopped"
show_osd("Status: overlay is " .. status)
subminer_log("info", "process", "Status check: overlay is " .. status)
end
local function check_binary_available()
return binary.ensure_binary_available()
end
return {
build_command_args = build_command_args,
run_control_command_async = run_control_command_async,
parse_start_script_message_overrides = parse_start_script_message_overrides,
apply_startup_overlay_preferences = apply_startup_overlay_preferences,
ensure_texthooker_running = ensure_texthooker_running,
start_overlay = start_overlay,
start_overlay_from_script_message = start_overlay_from_script_message,
stop_overlay = stop_overlay,
toggle_overlay = toggle_overlay,
open_options = open_options,
restart_overlay = restart_overlay,
check_status = check_status,
check_binary_available = check_binary_available,
}
end
return M

View File

@@ -0,0 +1,128 @@
local function assert_true(condition, message)
if condition then
return
end
error(message)
end
local function has_flag(call, flag)
local args = call.args or {}
for _, arg in ipairs(args) do
if arg == flag then
return true
end
end
return false
end
local function has_timeout(timeouts, target)
for _, value in ipairs(timeouts) do
if math.abs(value - target) < 0.0001 then
return true
end
end
return false
end
local recorded = {
async_calls = {},
timeouts = {},
logs = {},
}
local start_attempts = 0
local mp = {}
function mp.command_native_async(command, callback)
recorded.async_calls[#recorded.async_calls + 1] = command
local success = true
local result = { status = 0, stdout = "", stderr = "" }
local err = nil
if has_flag(command, "--start") then
start_attempts = start_attempts + 1
if start_attempts == 1 then
success = false
result = { status = 1, stdout = "", stderr = "startup-not-ready" }
err = "startup-not-ready"
end
end
if callback then
callback(success, result, err)
end
end
function mp.add_timeout(seconds, callback)
recorded.timeouts[#recorded.timeouts + 1] = seconds
if callback then
callback()
end
end
local process_module = dofile("plugin/subminer/process.lua")
local process = process_module.create({
mp = mp,
opts = {
backend = "x11",
socket_path = "/tmp/subminer.sock",
log_level = "debug",
texthooker_enabled = true,
texthooker_port = 5174,
auto_start_visible_overlay = false,
},
state = {
binary_path = "/tmp/subminer",
overlay_running = false,
texthooker_running = false,
},
binary = {
ensure_binary_available = function()
return true
end,
},
environment = {
detect_backend = function()
return "x11"
end,
},
options_helper = {
coerce_bool = function(value, default_value)
if value == true or value == "yes" or value == "true" then
return true
end
if value == false or value == "no" or value == "false" then
return false
end
return default_value
end,
},
log = {
subminer_log = function(_level, _scope, line)
recorded.logs[#recorded.logs + 1] = line
end,
show_osd = function(_) end,
normalize_log_level = function(value)
return value or "info"
end,
},
})
process.start_overlay()
assert_true(start_attempts == 2, "expected start overlay command retry after readiness failure")
assert_true(not has_timeout(recorded.timeouts, 0.35), "fixed texthooker wait (0.35s) should be removed")
assert_true(not has_timeout(recorded.timeouts, 0.6), "fixed startup visibility delay (0.6s) should be removed")
local retry_timeout_seen = false
for _, timeout_seconds in ipairs(recorded.timeouts) do
if timeout_seconds > 0 and timeout_seconds <= 0.25 then
retry_timeout_seen = true
break
end
end
assert_true(retry_timeout_seen, "expected shorter bounded retry timeout")
print("plugin process retry regression tests: OK")