From 5ce927281ac90e3bc8f2d6d94a9102e2b1e5f4d2 Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:23:17 +0200 Subject: [PATCH 01/10] Hoist the log tag in gameHandlers Sixty-three hand-typed provenance prefixes, sixteen of them under a shorter spelling of the file name than the other forty-seven, become one constant the log lines interpolate. Grepping the logs for this file now finds all of its lines instead of three quarters of them. --- src/ipc/handlers/gameHandlers.ts | 139 +++++++++++++++---------------- 1 file changed, 65 insertions(+), 74 deletions(-) diff --git a/src/ipc/handlers/gameHandlers.ts b/src/ipc/handlers/gameHandlers.ts index 25bac33b..e89fe281 100644 --- a/src/ipc/handlers/gameHandlers.ts +++ b/src/ipc/handlers/gameHandlers.ts @@ -47,6 +47,8 @@ import type { ProcessProbeRequest } from "@domain/ports" +const LOG_PREFIX = "[back] [ipc] [ipc/handlers/gameHandlers.ts]" + async function assertExecutable(pathValue: string): Promise { const stats = await fse.lstat(pathValue) if (!stats.isFile() || stats.isSymbolicLink()) throw new Error("Invalid game executable") @@ -158,14 +160,11 @@ async function adoptRefreshedSession(accountId: string, secrets: AccountSecrets) try { const outcome = await saveAccountSecrets(accountId, secrets) if (outcome === "saved-after-rebuild") - logMessage( - "warn", - `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] The account store could not be read; it was copied aside and rebuilt around this adoption. Other saved accounts must log in again.` - ) - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] The game had already refreshed this account's session. Adopted it instead of overwriting it.`) + logMessage("warn", `${LOG_PREFIX} [EXECUTE_GAME] The account store could not be read; it was copied aside and rebuilt around this adoption. Other saved accounts must log in again.`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] The game had already refreshed this account's session. Adopted it instead of overwriting it.`) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Could not store the session the game refreshed. Launching anyway.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Could not store the session the game refreshed. Launching anyway.`) + logMessage("debug", `${LOG_PREFIX} [EXECUTE_GAME] ${getErrorMessage(err)}`) } } @@ -208,8 +207,8 @@ function realGameProcess(): GameProcess { // UNKNOWN, so a truncated or quarantined Vintagestory.exe lands here rather // than on the event below; without this the whole handler rejects and the // launch stops being a reason the player is told. - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error running Vintage Story.`) - logMessage("verbose", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Error running Vintage Story.`) + logMessage("verbose", `${LOG_PREFIX} [EXECUTE_GAME] ${getErrorMessage(err)}`) settle({ started: false, error: getErrorMessage(err) }) return } @@ -226,15 +225,15 @@ function realGameProcess(): GameProcess { externalApp.stderr.on("data", (data) => { const text = data.toString() stderrScan = appendStderrScan(stderrScan, text) - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Vintage Story threw an error! Check verbose logs for more info.`) - logMessage("verbose", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${text.slice(0, 2_048)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Vintage Story threw an error! Check verbose logs for more info.`) + logMessage("verbose", `${LOG_PREFIX} [EXECUTE_GAME] ${text.slice(0, 2_048)}`) }) externalApp.on("close", (code) => settle({ started: true, exitCode: code, missingRuntime: hasMissingDotnetSentinel(stderrScan) })) externalApp.on("error", (error) => { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error running Vintage Story.`) - logMessage("verbose", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${error}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Error running Vintage Story.`) + logMessage("verbose", `${LOG_PREFIX} [EXECUTE_GAME] ${error}`) settle({ started: false, error: getErrorMessage(error) }) }) }) @@ -272,28 +271,28 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un const config = await getConfig() const account = config.accounts.find((candidate) => candidate.playerUid === config.activeAccountId) ?? null const accountSecrets = account ? await getAccountSecrets(account.playerUid) : null - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Trying to run Vintage Story ${safeVersion.version}.`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Trying to run Vintage Story ${safeVersion.version}.`) let connectTarget: string | undefined if (serverId !== undefined) { const safeServerId = assertString(serverId, "server bookmark id", 128) const bookmark = safeInstallation.id ? resolveServerBookmark(config.installations, safeInstallation.id, safeServerId) : null if (!bookmark) { - logMessage("warn", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Refused a server that is not one this installation has saved.`) + logMessage("warn", `${LOG_PREFIX} [EXECUTE_GAME] Refused a server that is not one this installation has saved.`) return invalidRequestResult() } connectTarget = joinTargetUrl(bookmark) // One fixed line, and nothing of the server in it. A server address is somebody's machine, // often somebody's home, and redactSensitiveText strips paths rather than host names. - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Joining a saved server.`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Joining a saved server.`) } let processEnv: Record try { processEnv = parseSafeEnvironment(safeInstallation.envVars) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Refused invalid environment variables for this installation.`) - logMessage("verbose", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Refused invalid environment variables for this installation.`) + logMessage("verbose", `${LOG_PREFIX} [EXECUTE_GAME] ${getErrorMessage(err)}`) return invalidRequestResult() } @@ -301,7 +300,7 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un if (os.platform() === "linux" && safeInstallation.launchWrapper) { const resolvedWrapper = await resolveLaunchWrapper(safeInstallation.launchWrapper) if (!resolvedWrapper) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Refused an unavailable or non-executable launch wrapper.`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Refused an unavailable or non-executable launch wrapper.`) return invalidExecutableResult() } launchWrapper = resolvedWrapper @@ -311,8 +310,8 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un try { fileNames = await fse.readdir(safeVersion.path) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error detecting how to run Vintage Story.`) - logMessage("verbose", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error detecting how to run Vintage Story: ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Error detecting how to run Vintage Story.`) + logMessage("verbose", `${LOG_PREFIX} [EXECUTE_GAME] Error detecting how to run Vintage Story: ${getErrorMessage(err)}`) return noExecutableResult() } @@ -331,7 +330,7 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un ) if (!planned.ok) { - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Couldn't find a way to run Vintage Story on ${os.platform()} (${planned.reason}), aborting...`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Couldn't find a way to run Vintage Story on ${os.platform()} (${planned.reason}), aborting...`) return launchPlanFailureResult(planned.reason) } @@ -340,20 +339,20 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un try { await assertExecutable(plan.executablePath) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Refused to run an invalid game executable.`) - logMessage("verbose", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Refused to run an invalid game executable.`) + logMessage("verbose", `${LOG_PREFIX} [EXECUTE_GAME] ${getErrorMessage(err)}`) return invalidExecutableResult() } if (account && accountSecrets) { - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Logged in. Setting session keys.`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Logged in. Setting session keys.`) let settingsPath: string try { settingsPath = await assertManagedPath(join(safeInstallation.path, CLIENT_SETTINGS_FILE_NAME), "client settings", { allowMissing: true }) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error setting login session keys.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Refused the client settings path: ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Error setting login session keys.`) + logMessage("debug", `${LOG_PREFIX} [EXECUTE_GAME] Refused the client settings path: ${getErrorMessage(err)}`) return sessionWriteFailedResult() } @@ -380,14 +379,10 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un // Never logs what the file held: the path this installation was copied out of is untrusted // input and stays out of the log. The path we put there is our own and may be named. const modPathsNotice = "modPaths" in written ? written.modPaths : undefined - if (modPathsNotice === "repointed") logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Repointed this installation's mod folder list at [PATH].`) + if (modPathsNotice === "repointed") logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Repointed this installation's mod folder list at [PATH].`) else if (modPathsNotice === "repoint-write-failed") - logMessage( - "warn", - `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] This installation's mod folder list needed repointing but the settings file could not be written; the game's own session was kept.` - ) - else if (modPathsNotice === "left-as-found") - logMessage("warn", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] This installation's mod folder list is not the game's default one and was left as found.`) + logMessage("warn", `${LOG_PREFIX} [EXECUTE_GAME] This installation's mod folder list needed repointing but the settings file could not be written; the game's own session was kept.`) + else if (modPathsNotice === "left-as-found") logMessage("warn", `${LOG_PREFIX} [EXECUTE_GAME] This installation's mod folder list is not the game's default one and was left as found.`) switch (written.outcome) { case "written": @@ -397,8 +392,8 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un break case "unreadable-settings": case "write-failed": - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error setting login session keys.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error setting login session keys: ${written.outcome}.`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Error setting login session keys.`) + logMessage("debug", `${LOG_PREFIX} [EXECUTE_GAME] Error setting login session keys: ${written.outcome}.`) return sessionWriteFailedResult() } } else if (account && !accountSecrets) { @@ -414,8 +409,8 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un try { settingsPath = await assertManagedPath(join(safeInstallation.path, CLIENT_SETTINGS_FILE_NAME), "client settings", { allowMissing: true }) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Error checking for another player's session keys.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Refused the client settings path: ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Error checking for another player's session keys.`) + logMessage("debug", `${LOG_PREFIX} [EXECUTE_GAME] Refused the client settings path: ${getErrorMessage(err)}`) return sessionWriteFailedResult() } @@ -423,19 +418,19 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un switch (cleared.outcome) { case "cleared": - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Cleared another player's session before launching without one of our own.`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Cleared another player's session before launching without one of our own.`) break case "not-foreign": break case "unreadable-settings": case "write-failed": - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Could not confirm this installation is not still signed in as another player.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] ${cleared.outcome}.`) + logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Could not confirm this installation is not still signed in as another player.`) + logMessage("debug", `${LOG_PREFIX} [EXECUTE_GAME] ${cleared.outcome}.`) return sessionWriteFailedResult() } } - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Running Vintagestory with a validated executable${launchWrapper ? ` through ${launchWrapper}` : ""}.`) + logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Running Vintagestory with a validated executable${launchWrapper ? ` through ${launchWrapper}` : ""}.`) // The id comes from the config the launcher wrote, never from the renderer's own object, so the // file name a session lands under cannot be chosen by whatever sent the launch. @@ -460,16 +455,12 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.EXECUTE_GAME, async (event, version: un if (session && installationId) { const stored = await recordPlaySession(installationId, session) const shape = session.partial ? "partial" : "complete" - if (stored) logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Recorded a ${shape} play session of ${session.samples.length} readings.`) - else logMessage("warn", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Could not record this play session; the sessions file was left as it was.`) + if (stored) logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Recorded a ${shape} play session of ${session.samples.length} readings.`) + else logMessage("warn", `${LOG_PREFIX} [EXECUTE_GAME] Could not record this play session; the sessions file was left as it was.`) } - if (!outcome.started) - logMessage( - "error", - `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Failed to run Vintage Story${launchWrapper ? ` through ${launchWrapper}` : ""}: ${outcome.error ?? "unknown error"}.` - ) - else logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [EXECUTE_GAME] Vintage Story closed: ${outcome.exitCode}`) + if (!outcome.started) logMessage("error", `${LOG_PREFIX} [EXECUTE_GAME] Failed to run Vintage Story${launchWrapper ? ` through ${launchWrapper}` : ""}: ${outcome.error ?? "unknown error"}.`) + else logMessage("info", `${LOG_PREFIX} [EXECUTE_GAME] Vintage Story closed: ${outcome.exitCode}`) return gameProcessOutcomeToResult(outcome) }) @@ -488,8 +479,8 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.GET_PLAY_SESSIONS, async (event, instal assertTrustedIpcSender(event) const read = await readPlaySessions(installationId) - if (!read.ok) logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_PLAY_SESSIONS] Refused: ${read.reason}.`) - else logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_PLAY_SESSIONS] Read ${read.sessions.length} play sessions.`) + if (!read.ok) logMessage("info", `${LOG_PREFIX} [GET_PLAY_SESSIONS] Refused: ${read.reason}.`) + else logMessage("info", `${LOG_PREFIX} [GET_PLAY_SESSIONS] Read ${read.sessions.length} play sessions.`) return read }) @@ -497,7 +488,7 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.FORGET_PLAY_SESSIONS, async (event, ins assertTrustedIpcSender(event) const ok = await forgetPlaySessions(installationId) - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [FORGET_PLAY_SESSIONS] Cleared the play sessions: ${ok}.`) + logMessage("info", `${LOG_PREFIX} [FORGET_PLAY_SESSIONS] Cleared the play sessions: ${ok}.`) return { ok } }) @@ -530,13 +521,13 @@ function realProcessProbe(): ProcessProbe { try { await assertExecutable(request.command === "mono" ? (request.args[0] ?? "") : request.command) } catch (err) { - logMessage("error", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Refused to probe an invalid executable.`) - logMessage("verbose", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Refused to probe an invalid executable.`) + logMessage("verbose", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] ${getErrorMessage(err)}`) return { ok: false, stdout: "", error: getErrorMessage(err) } } return new Promise((resolve) => { - logMessage("info", "[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Checking Vintage Story with a validated executable.") + logMessage("info", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Checking Vintage Story with a validated executable.`) let stdout = "" let settled = false @@ -558,14 +549,14 @@ function realProcessProbe(): ProcessProbe { } catch (err) { // Same throw-instead-of-emit split as EXECUTE_GAME's spawn above, settled // the way the "error" event below settles it. - logMessage("error", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Error looking for the Vintage Story version.`) - logMessage("verbose", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Error looking for the Vintage Story version.`) + logMessage("verbose", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] ${getErrorMessage(err)}`) settle({ ok: false, stdout, error: getErrorMessage(err) }) return } timer = setTimeout(() => { - logMessage("error", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Timed out waiting for Vintage Story to report its version.`) + logMessage("error", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Timed out waiting for Vintage Story to report its version.`) externalApp.kill() settle({ ok: false, stdout, error: "Timed out waiting for a response." }) }, LOOK_FOR_A_GAME_VERSION_PROBE_TIMEOUT_MS) @@ -575,18 +566,18 @@ function realProcessProbe(): ProcessProbe { }) externalApp.stderr.on("data", (data) => { - logMessage("error", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Vintage Story threw an error! Check verbose logs for more info.`) - logMessage("verbose", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] ${data}`) + logMessage("error", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Vintage Story threw an error! Check verbose logs for more info.`) + logMessage("verbose", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] ${data}`) }) externalApp.on("close", (code) => { - logMessage("info", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Vintage Story closed: ${code}`) + logMessage("info", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Vintage Story closed: ${code}`) settle({ ok: true, stdout }) }) externalApp.on("error", (error) => { - logMessage("error", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Error looking for the Vintage Story version.`) - logMessage("verbose", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] ${error}`) + logMessage("error", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Error looking for the Vintage Story version.`) + logMessage("verbose", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] ${error}`) settle({ ok: false, stdout, error: getErrorMessage(error) }) }) }) @@ -625,25 +616,25 @@ function tasklistProbe(): ProcessProbe { ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.LOOK_FOR_A_GAME_VERSION, async (event, path: unknown): Promise => { assertTrustedIpcSender(event) const safePath = await assertManagedPath(path, "game version path", { allowMissing: true }) - logMessage("info", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Looking for the game at [PATH]`) + logMessage("info", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Looking for the game at [PATH]`) let fileNames: string[] try { fileNames = await fse.readdir(safePath) } catch (err) { - logMessage("error", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Error reading the folder.`) - logMessage("verbose", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Error reading the folder.`) + logMessage("verbose", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] ${getErrorMessage(err)}`) return NOT_FOUND } const result = await detectInstalledGameVersion({ paths, processProbe: realProcessProbe() }, { platform: os.platform(), folder: safePath, fileNames }) if (!result.ok) { - logMessage("info", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] No version found: ${result.reason}.`) + logMessage("info", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] No version found: ${result.reason}.`) return NOT_FOUND } - logMessage("info", `[back] [ipc] [gameHandlers.ts] [LOOK_FOR_A_GAME_VERSION] Found Vintage Story ${result.version}.`) + logMessage("info", `${LOG_PREFIX} [LOOK_FOR_A_GAME_VERSION] Found Vintage Story ${result.version}.`) const variant = toWireBuildVariant(result.variant) return variant ? { exists: true, installedGameVersion: result.version, variant } : { exists: true, installedGameVersion: result.version } }) @@ -737,7 +728,7 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.GET_GAME_LOG_REPORT, async (event, inst try { installation = await assertConfiguredInstallationPath(installationPath) } catch { - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_GAME_LOG_REPORT] Refused: not a configured Installation.`) + logMessage("info", `${LOG_PREFIX} [GET_GAME_LOG_REPORT] Refused: not a configured Installation.`) return { ok: false, reason: "refused" } } @@ -751,13 +742,13 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.GET_GAME_LOG_REPORT, async (event, inst mainLog = await readBoundedText(mainLogPath, WHOLE_LOG_BYTES, LOG_HEAD_BYTES, LOG_TAIL_BYTES) crashFile = await readBoundedText(crashPath, CRASH_FILE_BYTES, CRASH_FILE_BYTES, 0) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_GAME_LOG_REPORT] Could not read this Installation's logs.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_GAME_LOG_REPORT] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [GET_GAME_LOG_REPORT] Could not read this Installation's logs.`) + logMessage("debug", `${LOG_PREFIX} [GET_GAME_LOG_REPORT] ${getErrorMessage(err)}`) return { ok: false, reason: "unreadable" } } if (!mainLog && !crashFile) { - logMessage("info", `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_GAME_LOG_REPORT] No session logs to read yet.`) + logMessage("info", `${LOG_PREFIX} [GET_GAME_LOG_REPORT] No session logs to read yet.`) return { ok: false, reason: "no-logs" } } @@ -772,7 +763,7 @@ ipcMain.handle(IPC_CHANNELS.GAME_MANAGER.GET_GAME_LOG_REPORT, async (event, inst logMessage( "info", - `[back] [ipc] [ipc/handlers/gameHandlers.ts] [GET_GAME_LOG_REPORT] Built a session report: ${report.mods.length} groups, ${report.unattributed.length} other lines, crash ${report.crash ? 1 : 0}, truncated ${report.source.truncated ? 1 : 0}.` + `${LOG_PREFIX} [GET_GAME_LOG_REPORT] Built a session report: ${report.mods.length} groups, ${report.unattributed.length} other lines, crash ${report.crash ? 1 : 0}, truncated ${report.source.truncated ? 1 : 0}.` ) return { ok: true, report } }) From 4a69c4edb1f836ff6313895b1a9a6f01ff6b45e1 Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:23:56 +0200 Subject: [PATCH 02/10] Hoist the log tag in pathsHandlers Twenty-five copies of the same provenance prefix become one constant. The five that were plain strings become template literals, which puts them inside the reach of the log provenance scan for the first time. --- src/ipc/handlers/pathsHandlers.ts | 55 +++++++++++++++---------------- 1 file changed, 27 insertions(+), 28 deletions(-) diff --git a/src/ipc/handlers/pathsHandlers.ts b/src/ipc/handlers/pathsHandlers.ts index a60e627c..e7e420e8 100644 --- a/src/ipc/handlers/pathsHandlers.ts +++ b/src/ipc/handlers/pathsHandlers.ts @@ -28,6 +28,8 @@ import innoExtractWorker from "@src/ipc/workers/innoExtractWorker?modulePath" import changePermsWorker from "@src/ipc/workers/changePermsWorker?modulePath" import downloadWorkerPath from "@src/ipc/workers/downloadWorker?modulePath" +const LOG_PREFIX = "[back] [ipc] [ipc/handlers/pathsHandlers.ts]" + const WORKER_TIMEOUTS_MS: Record = { DOWNLOAD_ON_PATH: 45 * 60 * 1_000, EXTRACT_ON_PATH: 30 * 60 * 1_000, @@ -248,8 +250,8 @@ function runTrackedWorker( } const onError = (error: Error): void => { - logMessage("error", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [${operation}] Worker error.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [${operation}] ${getErrorMessage(error)}`) + logMessage("error", `${LOG_PREFIX} [${operation}] Worker error.`) + logMessage("debug", `${LOG_PREFIX} [${operation}] ${getErrorMessage(error)}`) rejectOnce(error) } @@ -277,12 +279,12 @@ ipcMain.handle(IPC_CHANNELS.PATHS_MANAGER.DELETE_PATH, async (event, pathValue: try { const safePath = await assertManagedDeletionPath(pathValue) - logMessage("info", "[back] [ipc] [ipc/handlers/pathsHandlers.ts] [DELETE_PATH] Deleting an approved path.") + logMessage("info", `${LOG_PREFIX} [DELETE_PATH] Deleting an approved path.`) await fse.remove(safePath) return true } catch (err) { - logMessage("error", "[back] [ipc] [ipc/handlers/pathsHandlers.ts] [DELETE_PATH] Error deleting path.") - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [DELETE_PATH] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [DELETE_PATH] Error deleting path.`) + logMessage("debug", `${LOG_PREFIX} [DELETE_PATH] ${getErrorMessage(err)}`) return false } }) @@ -298,12 +300,12 @@ ipcMain.handle(IPC_CHANNELS.PATHS_MANAGER.MOVE_PATH, async (event, fromPath: str if (safeFromPath === safeToPath) throw new TypeError("Source and destination paths must differ") if (await fse.pathExists(safeToPath)) throw new TypeError("Destination path already exists") - logMessage("info", "[back] [ipc] [ipc/handlers/pathsHandlers.ts] [MOVE_PATH] Moving an approved path.") + logMessage("info", `${LOG_PREFIX} [MOVE_PATH] Moving an approved path.`) await fse.move(safeFromPath, safeToPath) return true } catch (err) { - logMessage("error", "[back] [ipc] [ipc/handlers/pathsHandlers.ts] [MOVE_PATH] Error moving path.") - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [MOVE_PATH] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [MOVE_PATH] Error moving path.`) + logMessage("debug", `${LOG_PREFIX} [MOVE_PATH] ${getErrorMessage(err)}`) return false } }) @@ -364,8 +366,8 @@ ipcMain.handle(IPC_CHANNELS.PATHS_MANAGER.ENSURE_PATH_EXISTS, async (event, path await fse.ensureDir(await assertManagedPath(pathValue, "path", { allowMissing: true })) return true } catch (err) { - logMessage("error", "[back] [ipc] [ipc/handlers/pathsHandlers.ts] [ENSURE_PATH_EXISTS] Error ensuring path.") - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [ENSURE_PATH_EXISTS] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [ENSURE_PATH_EXISTS] Error ensuring path.`) + logMessage("debug", `${LOG_PREFIX} [ENSURE_PATH_EXISTS] ${getErrorMessage(err)}`) return false } }) @@ -390,7 +392,7 @@ ipcMain.handle(IPC_CHANNELS.PATHS_MANAGER.DOWNLOAD_ON_PATH, async (event, id: st const optimumManifest = expectedSha256 ? await getCachedOptimumManifest() : undefined const maxBytes = optimumManifest?.archive.size - logMessage("info", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [DOWNLOAD_ON_PATH] [${safeId}] Starting a bounded download.`) + logMessage("info", `${LOG_PREFIX} [DOWNLOAD_ON_PATH] [${safeId}] Starting a bounded download.`) const downloadedPath = await downloadConcurrency.run(() => { sendProgress(event, IPC_CHANNELS.PATHS_MANAGER.DOWNLOAD_PROGRESS, safeId, 0) return runTrackedWorker( @@ -457,7 +459,7 @@ ipcMain.handle(IPC_CHANNELS.PATHS_MANAGER.EXTRACT_ON_PATH, async (event, id: str const isBackupArchive = await isLauncherBackupArchive(safeFilePath) - logMessage("info", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [EXTRACT_ON_PATH] [${safeId}] Starting a bounded extraction.`) + logMessage("info", `${LOG_PREFIX} [EXTRACT_ON_PATH] [${safeId}] Starting a bounded extraction.`) await archiveConcurrency.run(() => { sendProgress(event, IPC_CHANNELS.PATHS_MANAGER.EXTRACT_PROGRESS, safeId, 0) return runTrackedWorker( @@ -524,7 +526,7 @@ async function extractInstallerPayload( safeOutputPath: string, shouldDeleteInstaller: boolean ): Promise<"extracted" | "failed" | "format-refused"> { - logMessage("info", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] Extracting the installer payload instead of running it.`) + logMessage("info", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] Extracting the installer payload instead of running it.`) try { return await archiveConcurrency.run(() => { @@ -543,18 +545,18 @@ async function extractInstallerPayload( (message) => { if (message.verdict === "format-refused") { const reason = typeof message.reason === "string" ? message.reason : "no reason given" - logMessage("warn", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] The installer format was refused, falling back to running it. reason=${reason}`) + logMessage("warn", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] The installer format was refused, falling back to running it. reason=${reason}`) return "format-refused" } if (message.verdict !== "extracted") throw new Error("Installer payload extraction returned an unknown verdict") - logMessage("info", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] Extracted ${message.filesWritten} files, ${message.bytesWritten} bytes.`) + logMessage("info", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] Extracted ${message.filesWritten} files, ${message.bytesWritten} bytes.`) return "extracted" } ) }) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] Installer payload extraction failed.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] Installer payload extraction failed.`) + logMessage("debug", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] ${getErrorMessage(err)}`) return "failed" } } @@ -587,15 +589,12 @@ function spawnInstaller(event: IpcMainInvokeEvent, safeId: string, safeFilePath: const installer = spawn(exePath, ["/VERYSILENT", "/SUPPRESSMSGBOXES", "/NORESTART", "/CURRENTUSER", "/NOICONS", `/DIR=${safeOutputPath}`], { shell: false, windowsHide: true }) const timeoutHandle = setTimeout(() => { - logMessage( - "error", - `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] Timed out after ${RUN_INSTALLER_TIMEOUT_MS}ms waiting on the installer; killing its process tree. reason=installer-timed-out` - ) + logMessage("error", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] Timed out after ${RUN_INSTALLER_TIMEOUT_MS}ms waiting on the installer; killing its process tree. reason=installer-timed-out`) attemptInstallerTreeKill( installer.pid, process.platform, (command, args) => spawn(command, args, { shell: false, windowsHide: true }), - (level, message) => logMessage(level, `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] ${message}`) + (level, message) => logMessage(level, `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] ${message}`) ) finish("timed-out") }, RUN_INSTALLER_TIMEOUT_MS) @@ -610,14 +609,14 @@ function spawnInstaller(event: IpcMainInvokeEvent, safeId: string, safeFilePath: } installer.on("error", (error) => { - logMessage("error", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] Error launching installer.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] ${getErrorMessage(error)}`) + logMessage("error", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] Error launching installer.`) + logMessage("debug", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] ${getErrorMessage(error)}`) finish("failed") }) installer.on("close", (code) => finish(code === 0 ? "installed" : "failed")) } catch (err) { - logMessage("error", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] Installer setup failed.`) - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [RUN_INSTALLER] [${safeId}] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] Installer setup failed.`) + logMessage("debug", `${LOG_PREFIX} [RUN_INSTALLER] [${safeId}] ${getErrorMessage(err)}`) resolvePromise(spawnInstallerOutcomeToResult("failed")) } }) @@ -633,7 +632,7 @@ ipcMain.handle( const safeOutputFileName = assertSafeFileName(outputFileName, "output file name") const safeCompressionLevel = assertInteger(compressionLevel, "compression level", 0, 9) - logMessage("info", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [COMPRESS_ON_PATH] [${safeId}] Starting bounded compression.`) + logMessage("info", `${LOG_PREFIX} [COMPRESS_ON_PATH] [${safeId}] Starting bounded compression.`) await archiveConcurrency.run(() => { sendProgress(event, IPC_CHANNELS.PATHS_MANAGER.COMPRESS_PROGRESS, safeId, 0) return runTrackedWorker( @@ -668,7 +667,7 @@ ipcMain.handle(IPC_CHANNELS.PATHS_MANAGER.CHANGE_PERMS, async (event, paths: str * the log afterwards needs, and it is the half that was missing entirely. */ function refuseIconCopy(reason: CustomIconCopyFailureReason, cause: unknown): { status: false; reason: CustomIconCopyFailureReason } { - logMessage("debug", `[back] [ipc] [ipc/handlers/pathsHandlers.ts] [COPY_TO_ICONS] Refused an icon (${reason}): ${cause instanceof Error ? cause.message : String(cause)}.`) + logMessage("debug", `${LOG_PREFIX} [COPY_TO_ICONS] Refused an icon (${reason}): ${cause instanceof Error ? cause.message : String(cause)}.`) return { status: false, reason } } From f9a900f113cea3c9cbe91bc04886056f6c984826 Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:24:15 +0200 Subject: [PATCH 03/10] Hoist the log tag in modsHandlers Thirty-three copies of the same prefix become one constant. --- src/ipc/handlers/modsHandlers.ts | 69 ++++++++++++++++---------------- 1 file changed, 35 insertions(+), 34 deletions(-) diff --git a/src/ipc/handlers/modsHandlers.ts b/src/ipc/handlers/modsHandlers.ts index d7d7a628..fdb866f8 100644 --- a/src/ipc/handlers/modsHandlers.ts +++ b/src/ipc/handlers/modsHandlers.ts @@ -17,6 +17,8 @@ import { MAX_MODPACK_MOD_NAME_LENGTH } from "@domain/mods/importModpack" import { emptyModProfilesDocument, MAX_MOD_PROFILES_FILE_BYTES, MOD_PROFILES_FILE_NAME, normalizeModProfilesDocument } from "@domain/mods/profiles" import { normalizeServerBookmarks } from "@domain/servers/bookmarks" +const LOG_PREFIX = "[back] [mods] [ipc/handlers/modsHandlers.ts]" + const MAX_MODPACK_ENTRIES = 2_000 // Narrows DOWNLOAD_URL_RULES, which already lists this host for archive downloads, to the one host @@ -50,7 +52,7 @@ async function cacheModImage(urlValue: unknown): Promise { if (!isPngBytes(bytes) && !isJpegBytes(bytes)) throw new TypeError("Downloaded ModDB image is not a PNG or JPEG") return (await images.store(key, bytes)) ?? staleName } catch (err) { - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [CACHE_MOD_IMAGE] Could not cache ModDB image: ${getErrorMessage(err)}`) + logMessage("debug", `${LOG_PREFIX} [CACHE_MOD_IMAGE] Could not cache ModDB image: ${getErrorMessage(err)}`) return staleName } } @@ -100,31 +102,30 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.GET_INSTALLED_MODS, async (event, path: // policy as before. path = await assertManagedPath(path, "mods path", { allowMissing: true, allowSymlinks: true }) try { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] Looking for mods at [PATH].`) + logMessage("info", `${LOG_PREFIX} [GET_INSTALLED_MODS] Looking for mods at [PATH].`) if (!(await fse.pathExists(path))) { // pathExists follows a link, so a linked Mods folder whose disk is not mounted lands here too. // That folder is not empty, it is out of reach, and a caller that records the folder must know. if (await fse.lstat(path).catch(() => false)) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] That path is a link to nothing. Its mods can't be read.`) + logMessage("info", `${LOG_PREFIX} [GET_INSTALLED_MODS] That path is a link to nothing. Its mods can't be read.`) return { mods: [], errors: [], unreadable: true } } - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] That path does not exists. 0 mods detected.`) + logMessage("info", `${LOG_PREFIX} [GET_INSTALLED_MODS] That path does not exists. 0 mods detected.`) return { mods: [], errors: [] } } const scan = await scanInstalledMods(createScanInstalledModsPorts(), { folder: path }) - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] Found ${scan.mods.length} mods and ${scan.errors.length} mods with errors.`) - if (scan.errors.length > 0) - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] Found ${scan.errors.length} mods with errors: ${scan.errors.map((archive) => archive.problem).join(", ")}`) + logMessage("info", `${LOG_PREFIX} [GET_INSTALLED_MODS] Found ${scan.mods.length} mods and ${scan.errors.length} mods with errors.`) + if (scan.errors.length > 0) logMessage("debug", `${LOG_PREFIX} [GET_INSTALLED_MODS] Found ${scan.errors.length} mods with errors: ${scan.errors.map((archive) => archive.problem).join(", ")}`) void pruneModIconCache() return { mods: scan.mods.map(toWireMod), errors: scan.errors.map((archive) => ({ zipname: archive.zipname, path: archive.path })) } } catch (err) { - logMessage("error", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] Error getting installed mods.`) - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_INSTALLED_MODS] Error getting installed mods: ${err}`) + logMessage("error", `${LOG_PREFIX} [GET_INSTALLED_MODS] Error getting installed mods.`) + logMessage("debug", `${LOG_PREFIX} [GET_INSTALLED_MODS] Error getting installed mods: ${err}`) return { mods: [], errors: [], unreadable: true } } }) @@ -148,14 +149,14 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.GET_SERVER_MODS, async (event, installa const folder = await assertManagedPath(join(installation, MODS_BY_SERVER_FOLDER_NAME), "server mods path", { allowMissing: true, allowSymlinks: true }) if (!(await fse.pathExists(folder))) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_SERVER_MODS] This installation has no server mods folder.`) + logMessage("info", `${LOG_PREFIX} [GET_SERVER_MODS] This installation has no server mods folder.`) return { groups: [] } } const scan = await scanServerMods(createScanInstalledModsPorts(), { folder }) const scanned = scan.groups.reduce((total, group) => total + group.mods.length, 0) - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_SERVER_MODS] Found ${scan.groups.length} server folders and ${scanned} mods.`) + logMessage("info", `${LOG_PREFIX} [GET_SERVER_MODS] Found ${scan.groups.length} server folders and ${scanned} mods.`) const groups = scan.groups.map((group) => { const wire = { server: group.server, path: group.path, mods: group.mods.map(toWireMod), unreadable: group.unreadable, ...(group.truncated ? { truncated: true as const } : {}) } @@ -163,8 +164,8 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.GET_SERVER_MODS, async (event, installa }) return scan.truncated ? { groups, truncated: true } : { groups } } catch (err) { - logMessage("error", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_SERVER_MODS] Error getting server mods.`) - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_SERVER_MODS] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [GET_SERVER_MODS] Error getting server mods.`) + logMessage("debug", `${LOG_PREFIX} [GET_SERVER_MODS] ${getErrorMessage(err)}`) return { groups: [], unreadable: true } } }) @@ -198,7 +199,7 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.SET_MOD_ENABLED, async (event, pathValu const rename = renameModArchiveTo(assertSafeFileName(basename(safePath), "mod archive name"), wanted) if (!rename.ok) { - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SET_MOD_ENABLED] Nothing to rename: ${rename.reason}.`) + logMessage("debug", `${LOG_PREFIX} [SET_MOD_ENABLED] Nothing to rename: ${rename.reason}.`) return rename.reason === "already-in-state" ? { ok: false, reason: "already-in-state" } : { ok: false, reason: "refused" } } @@ -208,19 +209,19 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.SET_MOD_ENABLED, async (event, pathValu await assertManagedPath(target, "mod archive path", { allowMissing: true, allowSymlinks: true }) if (await fse.pathExists(target)) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SET_MOD_ENABLED] The other name is already taken, leaving both archives alone.`) + logMessage("info", `${LOG_PREFIX} [SET_MOD_ENABLED] The other name is already taken, leaving both archives alone.`) return { ok: false, reason: "name-taken" } } - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SET_MOD_ENABLED] Renaming a mod archive to turn it ${wanted ? "on" : "off"}.`) + logMessage("info", `${LOG_PREFIX} [SET_MOD_ENABLED] Renaming a mod archive to turn it ${wanted ? "on" : "off"}.`) // move rather than rename: it refuses an existing destination on every platform, so the check // above losing a race cannot end with one archive written over the other. await fse.move(safePath, target) return { ok: true, path: target } } catch (err) { - logMessage("error", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SET_MOD_ENABLED] Error renaming a mod archive.`) - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SET_MOD_ENABLED] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [SET_MOD_ENABLED] Error renaming a mod archive.`) + logMessage("debug", `${LOG_PREFIX} [SET_MOD_ENABLED] ${getErrorMessage(err)}`) return { ok: false, reason: "refused" } } }) @@ -229,7 +230,7 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.EXPORT_MODPACK, async (event, manifest: assertTrustedIpcSender(event) try { const safeManifest = parseModpackManifest(manifest) - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [EXPORT_MODPACK] Exporting a modpack with ${safeManifest.mods.length} mods and ${safeManifest.servers?.length ?? 0} servers.`) + logMessage("info", `${LOG_PREFIX} [EXPORT_MODPACK] Exporting a modpack with ${safeManifest.mods.length} mods and ${safeManifest.servers?.length ?? 0} servers.`) const result = await dialog.showSaveDialog({ title: "Export Modpack", @@ -238,7 +239,7 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.EXPORT_MODPACK, async (event, manifest: }) if (result.canceled || !result.filePath) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [EXPORT_MODPACK] Export cancelled.`) + logMessage("info", `${LOG_PREFIX} [EXPORT_MODPACK] Export cancelled.`) return { success: false } } @@ -246,11 +247,11 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.EXPORT_MODPACK, async (event, manifest: const safeOutputPath = await assertManagedPath(result.filePath, "modpack path", { allowMissing: true }) await writeJsonAtomic(safeOutputPath, safeManifest, { spaces: 2 }) - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [EXPORT_MODPACK] Modpack exported to [PATH].`) + logMessage("info", `${LOG_PREFIX} [EXPORT_MODPACK] Modpack exported to [PATH].`) return { success: true, path: result.filePath } } catch (err) { - logMessage("error", `[back] [mods] [ipc/handlers/modsHandlers.ts] [EXPORT_MODPACK] Error exporting modpack.`) - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [EXPORT_MODPACK] Error exporting modpack: ${err}`) + logMessage("error", `${LOG_PREFIX} [EXPORT_MODPACK] Error exporting modpack.`) + logMessage("debug", `${LOG_PREFIX} [EXPORT_MODPACK] Error exporting modpack: ${err}`) return { success: false } } }) @@ -258,7 +259,7 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.EXPORT_MODPACK, async (event, manifest: ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.IMPORT_MODPACK, async (event): Promise<{ success: boolean; manifest?: ModpackManifestType; error?: string }> => { assertTrustedIpcSender(event) try { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [IMPORT_MODPACK] Opening file dialog for modpack import.`) + logMessage("info", `${LOG_PREFIX} [IMPORT_MODPACK] Opening file dialog for modpack import.`) const result = await dialog.showOpenDialog({ title: "Import Modpack", @@ -267,13 +268,13 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.IMPORT_MODPACK, async (event): Promise< }) if (result.canceled || result.filePaths.length === 0) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [IMPORT_MODPACK] Import cancelled.`) + logMessage("info", `${LOG_PREFIX} [IMPORT_MODPACK] Import cancelled.`) return { success: false } } const filePath = result.filePaths[0] if (!filePath) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [IMPORT_MODPACK] Import cancelled.`) + logMessage("info", `${LOG_PREFIX} [IMPORT_MODPACK] Import cancelled.`) return { success: false } } registerUserSelectedPaths([filePath]) @@ -284,11 +285,11 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.IMPORT_MODPACK, async (event): Promise< const manifest = parseModpackManifest(parsedManifest) - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [IMPORT_MODPACK] A modpack loaded with ${manifest.mods.length} mods and ${manifest.servers?.length ?? 0} servers.`) + logMessage("info", `${LOG_PREFIX} [IMPORT_MODPACK] A modpack loaded with ${manifest.mods.length} mods and ${manifest.servers?.length ?? 0} servers.`) return { success: true, manifest } } catch (err) { - logMessage("error", `[back] [mods] [ipc/handlers/modsHandlers.ts] [IMPORT_MODPACK] Error importing modpack.`) - logMessage("debug", `[back] [mods] [ipc/handlers/modsHandlers.ts] [IMPORT_MODPACK] Error importing modpack: ${err}`) + logMessage("error", `${LOG_PREFIX} [IMPORT_MODPACK] Error importing modpack.`) + logMessage("debug", `${LOG_PREFIX} [IMPORT_MODPACK] Error importing modpack: ${err}`) return { success: false, error: "Error reading modpack file." } } }) @@ -345,11 +346,11 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.GET_MOD_PROFILES, async (event, install const location = await locateModProfiles(installationPath) const read = location.ok ? await readModProfilesFile(location.path) : location if (!read.ok) { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_MOD_PROFILES] Refused: ${read.reason}.`) + logMessage("info", `${LOG_PREFIX} [GET_MOD_PROFILES] Refused: ${read.reason}.`) return read } - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [GET_MOD_PROFILES] Read ${read.document.profiles.length} profiles.`) + logMessage("info", `${LOG_PREFIX} [GET_MOD_PROFILES] Read ${read.document.profiles.length} profiles.`) return read }) @@ -357,7 +358,7 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.SAVE_MOD_PROFILES, async (event, instal assertTrustedIpcSender(event) function refuse(reason: "newer-format" | "unreadable" | "invalid" | "refused"): ModProfilesSaveResult { - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SAVE_MOD_PROFILES] Refused: ${reason}.`) + logMessage("info", `${LOG_PREFIX} [SAVE_MOD_PROFILES] Refused: ${reason}.`) return { ok: false, reason } } @@ -381,10 +382,10 @@ ipcMain.handle(IPC_CHANNELS.MODS_MANAGER.SAVE_MOD_PROFILES, async (event, instal try { await writeJsonAtomic(location.path, cleaned.document, { spaces: 2 }) } catch { - logMessage("error", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SAVE_MOD_PROFILES] Could not write the profiles file.`) + logMessage("error", `${LOG_PREFIX} [SAVE_MOD_PROFILES] Could not write the profiles file.`) return { ok: false, reason: "refused" } } - logMessage("info", `[back] [mods] [ipc/handlers/modsHandlers.ts] [SAVE_MOD_PROFILES] Saved ${cleaned.document.profiles.length} profiles.`) + logMessage("info", `${LOG_PREFIX} [SAVE_MOD_PROFILES] Saved ${cleaned.document.profiles.length} profiles.`) return { ok: true } }) From 82ed179527327e189b28d9ba66f6216566c127b4 Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:24:15 +0200 Subject: [PATCH 04/10] Hoist the log tag in the mod scan adapter Ten copies of the same prefix become one constant, including the cache sweep's origin field, which carries the same text into the sweep's own log lines. --- src/ipc/adapters/modScan.ts | 22 ++++++++++++---------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/src/ipc/adapters/modScan.ts b/src/ipc/adapters/modScan.ts index c843d092..375cf342 100644 --- a/src/ipc/adapters/modScan.ts +++ b/src/ipc/adapters/modScan.ts @@ -13,6 +13,8 @@ import { sweepCacheFolder } from "@src/ipc/cacheSweep" import { assertSafeFileName } from "@src/ipc/validation" import { logMessage } from "@src/utils/logManager" +const LOG_PREFIX = "[back] [mods] [ipc/adapters/modScan.ts]" + /** Entry inside a mod archive carrying its metadata. */ const MODINFO_ENTRY = "modinfo.json" @@ -45,7 +47,7 @@ function readModArchive(archivePath: string): Promise { return new Promise((resolve) => { yauzl.open(archivePath, { lazyEntries: true }, (openErr, zip) => { if (openErr || !zip) { - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [readModArchive] Could not open a mod archive.`) + logMessage("debug", `${LOG_PREFIX} [readModArchive] Could not open a mod archive.`) return resolve({ ok: false, problem: "unreadable-archive" }) } @@ -79,7 +81,7 @@ function readModArchive(archivePath: string): Promise { const collect = (entry: yauzl.Entry, limit: number, onDone: (bytes: Buffer) => void, onOversize: () => void, onUnreadable: () => void): void => { zip.openReadStream(entry, (streamErr, stream) => { if (streamErr || !stream) { - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [readModArchive] Could not read a mod archive entry.`) + logMessage("debug", `${LOG_PREFIX} [readModArchive] Could not read a mod archive entry.`) return onUnreadable() } @@ -97,7 +99,7 @@ function readModArchive(archivePath: string): Promise { }) stream.on("end", () => onDone(Buffer.concat(chunks))) stream.on("error", () => { - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [readModArchive] Error reading a mod archive entry.`) + logMessage("debug", `${LOG_PREFIX} [readModArchive] Error reading a mod archive entry.`) onUnreadable() }) }) @@ -146,7 +148,7 @@ function readModArchive(archivePath: string): Promise { zip.on("end", () => settle({ ok: true, content })) zip.on("error", () => { - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [readModArchive] Error walking a mod archive.`) + logMessage("debug", `${LOG_PREFIX} [readModArchive] Error walking a mod archive.`) settle({ ok: false, problem: "unreadable-archive" }) }) @@ -194,8 +196,8 @@ export function createIconStorePort(): IconStore { } return imageName } catch (err) { - logMessage("error", `[back] [mods] [ipc/adapters/modScan.ts] [createIconStorePort] Error saving a mod's icon.`) - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [createIconStorePort] Error saving a mod's icon: ${err}`) + logMessage("error", `${LOG_PREFIX} [createIconStorePort] Error saving a mod's icon.`) + logMessage("debug", `${LOG_PREFIX} [createIconStorePort] Error saving a mod's icon: ${err}`) return undefined } } @@ -265,8 +267,8 @@ export function createModImageStorePort(): ModImageCache { await writeFileAtomic(target, bytes) return name } catch (err) { - logMessage("error", `[back] [mods] [ipc/adapters/modScan.ts] [createModImageStorePort] Error saving a ModDB logo.`) - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [createModImageStorePort] Error saving a ModDB logo: ${err}`) + logMessage("error", `${LOG_PREFIX} [createModImageStorePort] Error saving a ModDB logo.`) + logMessage("debug", `${LOG_PREFIX} [createModImageStorePort] Error saving a ModDB logo: ${err}`) return undefined } } @@ -319,7 +321,7 @@ export async function pruneModIconCache(maxBytes: number = MOD_ICON_CACHE_MAX_BY async function doPruneModIconCache(maxBytes: number): Promise { await sweepCacheFolder({ folder: modImagesFolder(), - origin: "[back] [mods] [ipc/adapters/modScan.ts] [pruneModIconCache]", + origin: `${LOG_PREFIX} [pruneModIconCache]`, subject: "the icon cache", accepts: (name) => { // Throws its own reason rather than returning false, and the sweep logs it. @@ -363,7 +365,7 @@ export function createModsDirectoryReaderPort(): DirectoryReader { try { assertSafeFileName(entry) if ((await fse.lstat(join(path, entry))).isSymbolicLink()) { - logMessage("debug", `[back] [mods] [ipc/adapters/modScan.ts] [listFileNames] Skipping a symbolic link inside the Mods folder.`) + logMessage("debug", `${LOG_PREFIX} [listFileNames] Skipping a symbolic link inside the Mods folder.`) continue } names.push(entry) From a3118d2b8d9deaa68b40cb9ea947ca557f541b3e Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:24:46 +0200 Subject: [PATCH 05/10] Hoist the log tag in configManager Fourteen copies under two spellings of the file name become one constant under the path qualified spelling its neighbours use. --- src/config/configManager.ts | 30 ++++++++++++++++-------------- 1 file changed, 16 insertions(+), 14 deletions(-) diff --git a/src/config/configManager.ts b/src/config/configManager.ts index b238705e..e6f0fe28 100644 --- a/src/config/configManager.ts +++ b/src/config/configManager.ts @@ -14,6 +14,8 @@ import { normalizeReceiveBetaUpdates } from "@domain/appUpdate/betaUpdates" import { DEFAULT_COMPRESSION_LEVEL, DEFAULT_CONFIG_BASE } from "@domain/config/defaults" import { normalizeServerBookmarks } from "@domain/servers/bookmarks" +const LOG_PREFIX = "[back] [config] [config/configManager.ts]" + const defaultConfig: ConfigType = { ...DEFAULT_CONFIG_BASE, schemaVersion: CURRENT_CONFIG_SCHEMA, @@ -90,8 +92,8 @@ export async function saveConfig(config: ConfigType): Promise { configReady = true return true } catch (err) { - logMessage("error", "[back] [config] [config/configManager.ts] [saveConfig] Error saving configuration.") - logMessage("debug", `[back] [config] [config/configManager.ts] [saveConfig] ${err}`) + logMessage("error", `${LOG_PREFIX} [saveConfig] Error saving configuration.`) + logMessage("debug", `${LOG_PREFIX} [saveConfig] ${err}`) return false } } @@ -118,8 +120,8 @@ export async function getConfig(): Promise { if (mustSave) await saveConfig(ensuredConfig) return ensuredConfig } catch (err) { - logMessage("error", `[back] [config] [config/configManager.ts] [getConfig] Error getting config at [PATH]. Using default config.`) - logMessage("debug", `[back] [config] [config/configManager.ts] [getConfig] Error getting config at [PATH]: ${err}`) + logMessage("error", `${LOG_PREFIX} [getConfig] Error getting config at [PATH]. Using default config.`) + logMessage("debug", `${LOG_PREFIX} [getConfig] Error getting config at [PATH]: ${err}`) await saveConfig(defaultConfig) return defaultConfig } @@ -130,22 +132,22 @@ export async function ensureConfig(): Promise { configPath = join(app.getPath("userData"), "config.json") try { if (!(await fse.pathExists(configPath))) { - logMessage("info", `[back] [config] [config/configManager.ts] [ensureConfig] Config not found. Creating default config.`) + logMessage("info", `${LOG_PREFIX} [ensureConfig] Config not found. Creating default config.`) return await saveConfig(defaultConfig) } configReady = true - logMessage("info", `[back] [config] [config/configManager.ts] [ensureConfig] Config found at [PATH].`) + logMessage("info", `${LOG_PREFIX} [ensureConfig] Config found at [PATH].`) return true } catch (err) { - logMessage("error", `[back] [config] [config/configManager.ts] [ensureConfig] Error ensuring config.`) - logMessage("error", `[back] [config] [config/configManager.ts] [ensureConfig] Error ensuring config at [PATH]: ${err}`) + logMessage("error", `${LOG_PREFIX} [ensureConfig] Error ensuring config.`) + logMessage("error", `${LOG_PREFIX} [ensureConfig] Error ensuring config at [PATH]: ${err}`) return false } } /** Says what the schema pipeline did with the stored document, and at what level it deserves saying. */ function logConfigMigration(migration: ReturnType): void { - const prefix = "[back] [config] [config/configManager.ts] [getConfig]" + const prefix = `${LOG_PREFIX} [getConfig]` const steps = migration.applied.map((step) => `${step.fromSchema}->${step.toSchema}`).join(", ") switch (migration.outcome) { @@ -189,10 +191,10 @@ async function migrateLegacyAccount(config: unknown): Promise { try { await saveAccountSecrets(legacyAccount.publicAccount.playerUid, legacyAccount.secrets) } catch { - logMessage("warn", "[back] [config] [configManager.ts] Legacy account credentials were not migrated to secure storage.") + logMessage("warn", `${LOG_PREFIX} Legacy account credentials were not migrated to secure storage.`) } } else { - logMessage("warn", "[back] [config] [configManager.ts] Legacy account credentials were invalid and were discarded.") + logMessage("warn", `${LOG_PREFIX} Legacy account credentials were invalid and were discarded.`) } return true @@ -235,7 +237,7 @@ async function migrateAccountStore(legacyDocument: unknown, config: ConfigType): try { return await adoptLegacySingleAccountSecrets(uid) } catch { - logMessage("warn", "[back] [config] [configManager.ts] The stored account session was not carried into the multi-account store. Retrying on the next launch.") + logMessage("warn", `${LOG_PREFIX} The stored account session was not carried into the multi-account store. Retrying on the next launch.`) return false } } @@ -299,8 +301,8 @@ async function reconcileConfigBackup(migrationRan: boolean): Promise { stripLegacyAccountSecrets(document) await writeJsonAtomic(backupPath, document, { mode: 0o600, spaces: 2 }) } catch (err) { - logMessage("warn", "[back] [config] [configManager.ts] Could not reconcile the pre-migration config backup.") - logMessage("debug", `[back] [config] [configManager.ts] ${err}`) + logMessage("warn", `${LOG_PREFIX} Could not reconcile the pre-migration config backup.`) + logMessage("debug", `${LOG_PREFIX} ${err}`) } } From 63d19c8d440600fd4443fae380534ec6bba41a18 Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:24:46 +0200 Subject: [PATCH 06/10] Hoist the log tag in the orphaned temporary file sweep Seven copies of a bare file name become one constant, path qualified like the rest of the host layer. The lines still go out through the injected log port, so what the sweep's tests observe is unchanged. --- src/main/orphanedTempFiles.ts | 16 +++++++++------- 1 file changed, 9 insertions(+), 7 deletions(-) diff --git a/src/main/orphanedTempFiles.ts b/src/main/orphanedTempFiles.ts index 167275c7..74a81145 100644 --- a/src/main/orphanedTempFiles.ts +++ b/src/main/orphanedTempFiles.ts @@ -5,6 +5,8 @@ import { isRestoreStagingWorkspaceName } from "@src/ipc/validation" import { DOWNLOAD_TEMP_FILE_NAMESPACE } from "@src/ipc/workers/download" import { logMessage } from "@src/utils/logManager" +const LOG_PREFIX = "[back] [maintenance] [main/orphanedTempFiles.ts]" + /** A week leaves plenty of time for a slow or interrupted download to be resumed manually. */ export const ORPHANED_TEMP_FILE_MAX_AGE_MS = 7 * 24 * 60 * 60 * 1_000 @@ -79,7 +81,7 @@ async function sweepDirectory(target: TemporaryFileSweepTarget, options: Require try { entries = await fse.readdir(folder, { withFileTypes: true }) } catch (error) { - if (!isMissing(error)) options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Could not inspect ${folder}: ${error}`) + if (!isMissing(error)) options.log("debug", `${LOG_PREFIX} Could not inspect ${folder}: ${error}`) return 0 } @@ -101,7 +103,7 @@ async function sweepDirectory(target: TemporaryFileSweepTarget, options: Require try { stats = await fse.lstat(entryPath) } catch (error) { - if (!isMissing(error)) options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Could not inspect ${entryPath}: ${error}`) + if (!isMissing(error)) options.log("debug", `${LOG_PREFIX} Could not inspect ${entryPath}: ${error}`) continue } if (stats.isSymbolicLink() || options.nowMs - stats.mtimeMs <= options.maxAgeMs) continue @@ -109,9 +111,9 @@ async function sweepDirectory(target: TemporaryFileSweepTarget, options: Require try { await fse.remove(entryPath) removed += 1 - options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Removed ${label} ${entryPath}.`) + options.log("debug", `${LOG_PREFIX} Removed ${label} ${entryPath}.`) } catch (error) { - if (!isMissing(error)) options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Could not remove ${entryPath}: ${error}`) + if (!isMissing(error)) options.log("debug", `${LOG_PREFIX} Could not remove ${entryPath}: ${error}`) } continue } @@ -129,7 +131,7 @@ async function sweepDirectory(target: TemporaryFileSweepTarget, options: Require // between readdir and this check. stats = await fse.lstat(entryPath) } catch (error) { - if (!isMissing(error)) options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Could not inspect ${entryPath}: ${error}`) + if (!isMissing(error)) options.log("debug", `${LOG_PREFIX} Could not inspect ${entryPath}: ${error}`) continue } @@ -138,9 +140,9 @@ async function sweepDirectory(target: TemporaryFileSweepTarget, options: Require try { await fse.unlink(entryPath) removed += 1 - options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Removed orphaned temporary file ${entryPath}.`) + options.log("debug", `${LOG_PREFIX} Removed orphaned temporary file ${entryPath}.`) } catch (error) { - if (!isMissing(error)) options.log("debug", `[back] [maintenance] [orphanedTempFiles.ts] Could not remove ${entryPath}: ${error}`) + if (!isMissing(error)) options.log("debug", `${LOG_PREFIX} Could not remove ${entryPath}: ${error}`) } } From 852df8682e6a0ff3826d73b61e0e12cf57f41dc5 Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:24:46 +0200 Subject: [PATCH 07/10] Hoist the log tag in accountHandlers Eight copies of a bare file name become one constant, path qualified like its neighbours. --- src/ipc/handlers/accountHandlers.ts | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/src/ipc/handlers/accountHandlers.ts b/src/ipc/handlers/accountHandlers.ts index 103d3201..b3ba330d 100644 --- a/src/ipc/handlers/accountHandlers.ts +++ b/src/ipc/handlers/accountHandlers.ts @@ -13,6 +13,8 @@ import { AccountStoreUnreadableError, removeAccountSecrets, saveAccountSecrets } import type { AccountSaveOutcome } from "@src/ipc/accountStore" import { getErrorMessage, logMessage } from "@src/utils/logManager" +const LOG_PREFIX = "[back] [ipc] [ipc/handlers/accountHandlers.ts]" + const LOGIN_URL = new URL("https://auth3.vintagestory.at/v2/gamelogin") /** @@ -71,19 +73,18 @@ async function settle(verdict: LoginVerdict): Promise { // socket: `ENOSPC` from a keyring write and `ENOSPC` from a socket look identical // by then, and this call site is the only one that knows which it was. if (!(error instanceof AccountStoreUnreadableError)) throw new AccountStorageFailure(error) - logMessage("error", "[back] [ipc] [accountHandlers.ts] [LOGIN] The account store is unreadable and could not be copied aside, so it was left untouched. The session was not saved.") - logMessage("debug", `[back] [ipc] [accountHandlers.ts] [LOGIN] ${getErrorMessage(error)}`) + logMessage("error", `${LOG_PREFIX} [LOGIN] The account store is unreadable and could not be copied aside, so it was left untouched. The session was not saved.`) + logMessage("debug", `${LOG_PREFIX} [LOGIN] ${getErrorMessage(error)}`) return sessionStoreUnreadableResult() } if (outcome === "saved-after-rebuild") - logMessage("warn", "[back] [ipc] [accountHandlers.ts] [LOGIN] The account store could not be read; it was copied aside and rebuilt around this login. Other saved accounts must log in again.") + logMessage("warn", `${LOG_PREFIX} [LOGIN] The account store could not be read; it was copied aside and rebuilt around this login. Other saved accounts must log in again.`) // No keyring on this machine, so nothing was written and the session lives in this process // only (#481). The login itself stands: the service accepted these credentials, and refusing // to report that left the player unable to play at all over a missing wallet. - if (outcome === "saved-in-memory") - logMessage("warn", "[back] [ipc] [accountHandlers.ts] [LOGIN] No system keyring is available, so this session is held in memory for this run and was not written to disk.") + if (outcome === "saved-in-memory") logMessage("warn", `${LOG_PREFIX} [LOGIN] No system keyring is available, so this session is held in memory for this run and was not written to disk.`) return { status: "success", @@ -100,11 +101,11 @@ async function settle(verdict: LoginVerdict): Promise { // The toast collapses every refusal into "invalid email or password"; the // service's own reason string is the only way to tell a real credential // mismatch from anything else it may refuse for. Server enum, never user data. - logMessage("debug", `[back] [ipc] [accountHandlers.ts] [LOGIN] Service refused the login, reason: "${verdict.serverReason}".`) + logMessage("debug", `${LOG_PREFIX} [LOGIN] Service refused the login, reason: "${verdict.serverReason}".`) return badCredentialsResult() case "unreadable-response": { const outcome = unexpectedResponseOutcome(verdict) - logMessage("error", `[back] [ipc] [accountHandlers.ts] [LOGIN] ${outcome.logMessage}`) + logMessage("error", `${LOG_PREFIX} [LOGIN] ${outcome.logMessage}`) return outcome.result } } @@ -140,8 +141,8 @@ ipcMain.handle(IPC_CHANNELS.ACCOUNT_MANAGER.LOGIN, async (event, email: unknown, // instead, which still tells a network failure from an HTTP status from a // keyring that is not there from a disk with no room left on it. const reason = loginFailureReason(error) - logMessage("error", "[back] [ipc] [accountHandlers.ts] [LOGIN] Login failed.") - logMessage("debug", `[back] [ipc] [accountHandlers.ts] [LOGIN] Login failure reason: ${reason}.`) + logMessage("error", `${LOG_PREFIX} [LOGIN] Login failed.`) + logMessage("debug", `${LOG_PREFIX} [LOGIN] Login failure reason: ${reason}.`) // A reason `loginFailureFamily` can place resolves instead of throwing, so the // renderer can say which of DNS/refused/timeout, a certificate, an HTTP error the From 459c37bb215c041a4e0b5616388b007e3a65196b Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:25:12 +0200 Subject: [PATCH 08/10] Hoist the log tag in the main entry point Sixteen copies of the same prefix become one constant. --- src/main/index.ts | 34 ++++++++++++++++++---------------- 1 file changed, 18 insertions(+), 16 deletions(-) diff --git a/src/main/index.ts b/src/main/index.ts index 40825d6d..063deab5 100644 --- a/src/main/index.ts +++ b/src/main/index.ts @@ -33,6 +33,8 @@ import fse from "fs-extra" import "@src/ipc" import { clearTimeout, setTimeout } from "node:timers" +const LOG_PREFIX = "[back] [index] [main/index.ts]" + // #247: when the terminal that started the launcher exits, the next console write fails, and // Node reports that failure as an "error" event on process.stdout with no listener, i.e. an // uncaught exception Electron shows as "A JavaScript error occurred in the main process". @@ -53,7 +55,7 @@ Logger.transports.file.resolvePathFn = (variables, message): string => { return join(logsPath, `${message.level}.log`) } -logMessage("info", `[back] [index] [main/index.ts] [setUpUserDataFolder] ${describeUserDataSetup(userDataSetup)}`) +logMessage("info", `${LOG_PREFIX} [setUpUserDataFolder] ${describeUserDataSetup(userDataSetup)}`) /** * The one setting that has to be answered before Electron starts. @@ -77,7 +79,7 @@ function storedAllowBasicSessionStore(): boolean { const passwordStore = basicPasswordStoreSwitch(process.platform, storedAllowBasicSessionStore()) if (passwordStore) { app.commandLine.appendSwitch("password-store", passwordStore) - logMessage("info", "[back] [index] [main/index.ts] [passwordStore] Starting with the basic password store, as this launcher's session storage setting asks.") + logMessage("info", `${LOG_PREFIX} [passwordStore] Starting with the basic password store, as this launcher's session storage setting asks.`) } let mainWindow: BrowserWindow @@ -124,7 +126,7 @@ protocol.registerSchemesAsPrivileged(privilegedSchemes) // in Electron's other child processes (GPU, utility, and sandbox helpers) without // collecting crash reports or sending telemetry anywhere. app.on("child-process-gone", (_event, details) => { - logMessage("error", `[back] [index] [main/index.ts] [child-process-gone] ${details.type} process exited: ${details.reason} (exit code ${details.exitCode}).`) + logMessage("error", `${LOG_PREFIX} [child-process-gone] ${details.type} process exited: ${details.reason} (exit code ${details.exitCode}).`) }) function createWindow(): void { @@ -162,19 +164,19 @@ function createWindow(): void { const isAllowedMainFrameUrl = (url: string): boolean => isAllowedRendererUrl(url, is.dev ? process.env["ELECTRON_RENDERER_URL"] : undefined, packagedRendererPath) mainWindow.webContents.on("render-process-gone", (_event, details) => { - logMessage("error", `[back] [index] [main/index.ts] [createWindow] Renderer process exited: ${details.reason}.`) + logMessage("error", `${LOG_PREFIX} [createWindow] Renderer process exited: ${details.reason}.`) }) mainWindow.webContents.on("unresponsive", () => { - logMessage("warn", "[back] [index] [main/index.ts] [createWindow] Renderer became unresponsive.") + logMessage("warn", `${LOG_PREFIX} [createWindow] Renderer became unresponsive.`) }) mainWindow.webContents.on("responsive", () => { - logMessage("info", "[back] [index] [main/index.ts] [createWindow] Renderer became responsive again.") + logMessage("info", `${LOG_PREFIX} [createWindow] Renderer became responsive again.`) }) mainWindow.on("ready-to-show", async () => { - logMessage("info", "[back] [index] [main/index.ts] [createWindow] Main window ready to show. Opening.") + logMessage("info", `${LOG_PREFIX} [createWindow] Main window ready to show. Opening.`) const config = await getConfig() const oldWindowsState = config.window @@ -191,7 +193,7 @@ function createWindow(): void { if (!hasSweptOrphanedTempFiles) { hasSweptOrphanedTempFiles = true void sweepOrphanedTempFiles(getOrphanedTempFileSweepTargets(app.getPath("userData"), config)).catch((error: unknown) => { - logMessage("debug", `[back] [index] [main/index.ts] [ready-to-show] Could not sweep orphaned temporary files: ${error}`) + logMessage("debug", `${LOG_PREFIX} [ready-to-show] Could not sweep orphaned temporary files: ${error}`) }) } }) @@ -201,7 +203,7 @@ function createWindow(): void { const safeUrl = assertAllowedBrowserUrl(details.url) void shell.openExternal(safeUrl.toString()) } catch { - logMessage("warn", "[back] [index] [main/index.ts] [createWindow] Blocked an unsafe external window URL.") + logMessage("warn", `${LOG_PREFIX} [createWindow] Blocked an unsafe external window URL.`) } return { action: "deny" } }) @@ -240,10 +242,10 @@ function createWindow(): void { if (getShouldPreventClose()) { e.preventDefault() if (!mainWindow.isDestroyed()) mainWindow.webContents.send(IPC_CHANNELS.UTILS.PREVENTED_APP_CLOSE) - logMessage("info", "[back] [index] [main/index.ts] [createWindow] Main window prevented from closing.") + logMessage("info", `${LOG_PREFIX} [createWindow] Main window prevented from closing.`) return false } - logMessage("info", "[back] [index] [main/index.ts] [createWindow] Main window closing.") + logMessage("info", `${LOG_PREFIX} [createWindow] Main window closing.`) return true }) @@ -276,7 +278,7 @@ function readLinuxPackageType(): string | undefined { // This method will be called when Electron has finished initialization and is ready to create browser windows. Some APIs can only be used after this event occurs. app.whenReady().then(async () => { - logMessage("info", "[back] [index] [main/index.ts] [whenReady] Electron ready.") + logMessage("info", `${LOG_PREFIX} [whenReady] Electron ready.`) session.defaultSession.setPermissionCheckHandler(() => false) session.defaultSession.setPermissionRequestHandler((_webContents, _permission, callback) => callback(false)) @@ -395,10 +397,10 @@ app.whenReady().then(async () => { // A packaged build missing its own updater is a broken package, not a reason to refuse to // launch: everything else in the app works without it, and this is the only line that // would otherwise have gone unreported now that the import is no longer at module scope. - logMessage("error", `[back] [index] [main/index.ts] [whenReady] Could not load the auto-updater: ${getErrorMessage(error)}.`) + logMessage("error", `${LOG_PREFIX} [whenReady] Could not load the auto-updater: ${getErrorMessage(error)}.`) }) } else { - logMessage("info", `[back] [index] [main/index.ts] [whenReady] Auto-update disabled: ${updateDecision.reason}.`) + logMessage("info", `${LOG_PREFIX} [whenReady] Auto-update disabled: ${updateDecision.reason}.`) } app.on("activate", function () { @@ -411,10 +413,10 @@ app.whenReady().then(async () => { app.on("window-all-closed", () => { if (getShouldPreventClose() && mainWindow && !mainWindow.isDestroyed()) { mainWindow.webContents.send(IPC_CHANNELS.UTILS.PREVENTED_APP_CLOSE) - return logMessage("info", "[back] [index] [main/index.ts] [window-all-closed] Main window prevented from closing.") + return logMessage("info", `${LOG_PREFIX} [window-all-closed] Main window prevented from closing.`) } - logMessage("info", "[back] [index] [main/index.ts] [window-all-closed] All windows closed.") + logMessage("info", `${LOG_PREFIX} [window-all-closed] All windows closed.`) clearModIconMemoryCache(modIconMemoryCache) if (process.platform !== "darwin") { app.quit() From dae6badfb29a736b4e9f8fcb2412ece13463f2ee Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:25:12 +0200 Subject: [PATCH 09/10] Hoist the log tag in netHandlers Ten copies of the same prefix become one constant. --- src/ipc/handlers/netHandlers.ts | 25 ++++++++++++------------- 1 file changed, 12 insertions(+), 13 deletions(-) diff --git a/src/ipc/handlers/netHandlers.ts b/src/ipc/handlers/netHandlers.ts index cc49e79b..f2bd75cf 100644 --- a/src/ipc/handlers/netHandlers.ts +++ b/src/ipc/handlers/netHandlers.ts @@ -21,6 +21,8 @@ import { import { getConfig, saveConfig } from "@src/config/configManager" import { getErrorMessage, logMessage } from "@src/utils/logManager" +const LOG_PREFIX = "[back] [ipc] [ipc/handlers/netHandlers.ts]" + const MOD_CATALOG_HOSTNAME = "mods.vintagestory.at" const MOD_CATALOG_PATHNAME = "/api/mods" @@ -76,7 +78,7 @@ export async function queryUrl(url: unknown): Promise { const text = await queryConcurrency.run(() => requestBoundedText(safeUrl, { maxBytes })) if (isCatalog) { await writeCatalogCache(safeUrl, text).catch((cacheErr: unknown) => { - logMessage("debug", `[back] [ipc] [ipc/handlers/netHandlers.ts] [QUERY_URL] Failed to write mod catalog cache: ${getErrorMessage(cacheErr)}`) + logMessage("debug", `${LOG_PREFIX} [QUERY_URL] Failed to write mod catalog cache: ${getErrorMessage(cacheErr)}`) }) } return text @@ -84,8 +86,8 @@ export async function queryUrl(url: unknown): Promise { if (isCatalog) { const cached = await readCatalogCache(safeUrl) if (cached !== null) { - logMessage("warn", "[back] [ipc] [ipc/handlers/netHandlers.ts] [QUERY_URL] Mod catalog fetch failed, serving last good cached response.") - logMessage("debug", `[back] [ipc] [ipc/handlers/netHandlers.ts] [QUERY_URL] ${getErrorMessage(err)}`) + logMessage("warn", `${LOG_PREFIX} [QUERY_URL] Mod catalog fetch failed, serving last good cached response.`) + logMessage("debug", `${LOG_PREFIX} [QUERY_URL] ${getErrorMessage(err)}`) return cached } } @@ -125,7 +127,7 @@ export async function fetchModDbListingArchive(listingVersion: string): Promise< if (!detail.ok) return "unreachable" fileId = releaseFileIdForVersion(detail.payload, listingVersion) } catch (err) { - logMessage("debug", `[back] [ipc] [ipc/handlers/netHandlers.ts] [COUNT_MODDB_DOWNLOAD] ${getErrorMessage(err)}`) + logMessage("debug", `${LOG_PREFIX} [COUNT_MODDB_DOWNLOAD] ${getErrorMessage(err)}`) return "unreachable" } @@ -143,14 +145,11 @@ export async function fetchModDbListingArchive(listingVersion: string): Promise< // ever rewords it the request still behaves exactly the same and only this line falls back // to the branch below. if (message.toLowerCase().includes("redirect")) { - logMessage( - "debug", - "[back] [ipc] [ipc/handlers/netHandlers.ts] [COUNT_MODDB_DOWNLOAD] The listing download endpoint answered with its redirect, which is the counted outcome. Not followed on purpose." - ) + logMessage("debug", `${LOG_PREFIX} [COUNT_MODDB_DOWNLOAD] The listing download endpoint answered with its redirect, which is the counted outcome. Not followed on purpose.`) return "counted" } - logMessage("debug", `[back] [ipc] [ipc/handlers/netHandlers.ts] [COUNT_MODDB_DOWNLOAD] ${message}`) + logMessage("debug", `${LOG_PREFIX} [COUNT_MODDB_DOWNLOAD] ${message}`) return "unreachable" } } @@ -226,7 +225,7 @@ ipcMain.handle(IPC_CHANNELS.NET_MANAGER.COUNT_MODDB_DOWNLOAD, async (event, cons // Fixed text and the outcome's own token only, never a URL or a response body: the provenance // rule tests/log-provenance.test.ts holds every network log in this file to. - logMessage("info", `[back] [ipc] [ipc/handlers/netHandlers.ts] [COUNT_MODDB_DOWNLOAD] ModDB listing count for this version: ${result.reason}.`) + logMessage("info", `${LOG_PREFIX} [COUNT_MODDB_DOWNLOAD] ModDB listing count for this version: ${result.reason}.`) return result }) @@ -237,8 +236,8 @@ ipcMain.handle(IPC_CHANNELS.NET_MANAGER.QUERY_URL, async (event, url: unknown): try { return await queryUrl(url) } catch (err) { - logMessage("error", "[back] [ipc] [ipc/handlers/netHandlers.ts] [QUERY_URL] Network request failed.") - logMessage("debug", `[back] [ipc] [ipc/handlers/netHandlers.ts] [QUERY_URL] ${getErrorMessage(err)}`) + logMessage("error", `${LOG_PREFIX} [QUERY_URL] Network request failed.`) + logMessage("debug", `${LOG_PREFIX} [QUERY_URL] ${getErrorMessage(err)}`) throw err } }) @@ -371,7 +370,7 @@ ipcMain.handle(IPC_CHANNELS.NET_MANAGER.FETCH_RELEASE_NOTES, async (event): Prom // Fixed text and the failure's own reason token only: never the response body, a release name // or the URL, the same provenance rule every other network log in this file already follows. - if (!result.ok) logMessage("info", `[back] [ipc] [ipc/handlers/netHandlers.ts] [FETCH_RELEASE_NOTES] Release notes fetch failed: ${result.reason}.`) + if (!result.ok) logMessage("info", `${LOG_PREFIX} [FETCH_RELEASE_NOTES] Release notes fetch failed: ${result.reason}.`) return result }) From fb1c0c17ad063b6107747c7073aaf95dad89b77f Mon Sep 17 00:00:00 2001 From: Pixnop <77785313+Pixnop@users.noreply.github.com> Date: Sun, 20 Sep 2026 14:25:12 +0200 Subject: [PATCH 10/10] Hoist the log tag in utilsHandlers Nine copies of the same prefix become one constant. All but one were plain strings, so they enter the log provenance scan for the first time. --- src/ipc/handlers/utilsHandlers.ts | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) diff --git a/src/ipc/handlers/utilsHandlers.ts b/src/ipc/handlers/utilsHandlers.ts index 717b9532..9e7532ec 100644 --- a/src/ipc/handlers/utilsHandlers.ts +++ b/src/ipc/handlers/utilsHandlers.ts @@ -8,6 +8,8 @@ import { logMessage } from "@src/utils/logManager" import { setShouldPreventClose } from "@src/utils/shouldPreventClose" import { registerUserSelectedPaths } from "@src/ipc/pathPolicy" +const LOG_PREFIX = "[back] [ipc] [ipc/handlers/utilsHandlers.ts]" + ipcMain.handle(IPC_CHANNELS.UTILS.GET_APP_VERSION, (event) => { assertTrustedIpcSender(event) return app.getVersion() @@ -25,7 +27,7 @@ ipcMain.on(IPC_CHANNELS.UTILS.LOG_MESSAGE, (event, mode: ErrorTypes, message: st try { logMessage(mode, assertString(message, "log message", 16_384)) } catch { - logMessage("warn", "[back] [ipc] [ipc/handlers/utilsHandlers.ts] [LOG_MESSAGE] Rejected an invalid log message.") + logMessage("warn", `${LOG_PREFIX} [LOG_MESSAGE] Rejected an invalid log message.`) } }) @@ -36,7 +38,7 @@ ipcMain.on(IPC_CHANNELS.UTILS.SET_PREVENT_APP_CLOSE, (event, action: "add" | "re try { setShouldPreventClose(action, assertSafeTaskId(id), assertString(desc, "task description", 256)) } catch { - logMessage("warn", "[back] [ipc] [ipc/handlers/utilsHandlers.ts] [SET_PREVENT_APP_CLOSE] Rejected invalid task state.") + logMessage("warn", `${LOG_PREFIX} [SET_PREVENT_APP_CLOSE] Rejected invalid task state.`) } }) @@ -45,12 +47,12 @@ ipcMain.on(IPC_CHANNELS.UTILS.OPEN_ON_BROWSER, (event, url: string): void => { try { const safeUrl = assertAllowedBrowserUrl(url) - logMessage("info", "[back] [ipc] [ipc/handlers/utilsHandlers.ts] [OPEN_ON_BROWSER] Opening an approved URL on the default browser.") + logMessage("info", `${LOG_PREFIX} [OPEN_ON_BROWSER] Opening an approved URL on the default browser.`) void shell.openExternal(safeUrl.toString()).catch(() => { - logMessage("warn", "[back] [ipc] [ipc/handlers/utilsHandlers.ts] [OPEN_ON_BROWSER] The default browser rejected the URL.") + logMessage("warn", `${LOG_PREFIX} [OPEN_ON_BROWSER] The default browser rejected the URL.`) }) } catch { - logMessage("warn", "[back] [ipc] [ipc/handlers/utilsHandlers.ts] [OPEN_ON_BROWSER] Rejected an unsafe URL.") + logMessage("warn", `${LOG_PREFIX} [OPEN_ON_BROWSER] Rejected an unsafe URL.`) } }) @@ -67,14 +69,14 @@ ipcMain.handle(IPC_CHANNELS.UTILS.COPY_TO_CLIPBOARD, (event, text: string): bool clipboard.writeText(assertString(text, "clipboard text", 2_048)) return true } catch { - logMessage("warn", "[back] [ipc] [ipc/handlers/utilsHandlers.ts] [COPY_TO_CLIPBOARD] The clipboard refused the write.") + logMessage("warn", `${LOG_PREFIX} [COPY_TO_CLIPBOARD] The clipboard refused the write.`) return false } }) ipcMain.handle(IPC_CHANNELS.UTILS.SELECT_FOLDER_DIALOG, async (event, options?: { type?: "file" | "folder"; mode?: "single" | "multi"; extensions?: string[] }): Promise => { assertTrustedIpcSender(event) - logMessage("info", `[back] [ipc] [ipc/handlers/utilsHandlers.ts] [SELECT_FOLDER_DIALOG] Opening folder selection.`) + logMessage("info", `${LOG_PREFIX} [SELECT_FOLDER_DIALOG] Opening folder selection.`) if (options !== undefined) { if (!isRecord(options)) throw new TypeError("Invalid dialog options") @@ -101,11 +103,11 @@ ipcMain.handle(IPC_CHANNELS.UTILS.SELECT_FOLDER_DIALOG, async (event, options?: }) if (result.canceled) { - logMessage("warn", `[back] [ipc] [ipc/handlers/utilsHandlers.ts] [SELECT_FOLDER_DIALOG] Operation cancelled.`) + logMessage("warn", `${LOG_PREFIX} [SELECT_FOLDER_DIALOG] Operation cancelled.`) return [] } - logMessage("info", `[back] [ipc] [ipc/handlers/utilsHandlers.ts] [SELECT_FOLDER_DIALOG] Selection completed with ${result.filePaths.length} path(s).`) + logMessage("info", `${LOG_PREFIX} [SELECT_FOLDER_DIALOG] Selection completed with ${result.filePaths.length} path(s).`) registerUserSelectedPaths(result.filePaths) return result.filePaths