danvics/zerobyte
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions 1

fix: report timeout as errors (#569)

Browse source 
Closes #485
This commit is contained in:
Nico 2026-02-25 18:02:47 +01:00 committed by GitHub
parent 5b8f05bdf8
commit 00e7118771
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
9 changed files with 340 additions and 33 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

4
app/server/modules/backends/rclone/rclone-backend.ts
View file

@ -8,7 +8,7 @@ import { withTimeout } from "../../../utils/timeout";
import type { VolumeBackend } from "../backend";
import { executeUnmount } from "../utils/backend-utils";
import { BACKEND_STATUS, type BackendConfig } from "~/schemas/volumes";
import { exec } from "~/server/utils/spawn";
import { safeExec } from "~/server/utils/spawn";
const mount = async (config: BackendConfig, path: string) => {
logger.debug(`Mounting rclone volume ${path}...`);
@ -50,7 +50,7 @@ const mount = async (config: BackendConfig, path: string) => {
logger.debug(`Mounting rclone volume ${path}...`);
logger.info(`Executing rclone: rclone ${args.join(" ")}`);
const result = await exec({ command: "rclone", args });
const result = await safeExec({ command: "rclone", args });
if (result.exitCode !== 0) {
const errorMsg = result.stderr.toString() || result.stdout.toString() || "Unknown error";

6
app/server/modules/backends/utils/backend-utils.ts
View file

@ -2,7 +2,7 @@ import * as fs from "node:fs/promises";
import * as npath from "node:path";
import { toMessage } from "../../../utils/errors";
import { logger } from "../../../utils/logger";
import { exec } from "~/server/utils/spawn";
import { safeExec } from "~/server/utils/spawn";
export const executeMount = async (args: string[]): Promise<void> => {
const shouldBeVerbose = process.env.LOG_LEVEL === "debug" || process.env.NODE_ENV !== "production";
@ -10,7 +10,7 @@ export const executeMount = async (args: string[]): Promise<void> => {
const effectiveArgs = shouldBeVerbose && !hasVerboseFlag ? ["-v", ...args] : args;
logger.debug(`Executing mount ${effectiveArgs.join(" ")}`);
const result = await exec({ command: "mount", args: effectiveArgs, timeout: 10000 });
const result = await safeExec({ command: "mount", args: effectiveArgs, timeout: 10000 });
const stdout = result.stdout.toString().trim();
const stderr = result.stderr.toString().trim();
@ -31,7 +31,7 @@ export const executeUnmount = async (path: string): Promise<void> => {
let stderr: string | undefined;
logger.debug(`Executing umount -l ${path}`);
const result = await exec({ command: "umount", args: ["-l", path], timeout: 10000 });
const result = await safeExec({ command: "umount", args: ["-l", path], timeout: 10000 });
stderr = result.stderr.toString();

4
app/server/modules/lifecycle/migrations/00001-retag-snapshots.ts
View file

@ -3,7 +3,7 @@ import { db } from "../../../db/db";
import { backupScheduleMirrorsTable, type Repository } from "../../../db/schema";
import { logger } from "../../../utils/logger";
import { toMessage } from "~/server/utils/errors";
import { exec } from "~/server/utils/spawn";
import { safeExec } from "~/server/utils/spawn";
import { addCommonArgs, buildEnv, buildRepoUrl, cleanupTemporaryKeys } from "~/server/utils/restic";
const migrateTag = async (
@ -20,7 +20,7 @@ const migrateTag = async (
addCommonArgs(args, env);
logger.info(`Migrating snapshots for schedule '${scheduleName}' from tag '${oldTag}' to '${newTag}'`);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {

5
app/server/modules/repositories/repositories.service.ts
View file

@ -9,6 +9,7 @@ import {
type RepositoryConfig,
repositoryConfigSchema,
} from "~/schemas/restic";
import { config as appConfig } from "~/server/core/config";
import { serverEvents } from "~/server/core/events";
import { getOrganizationId } from "~/server/core/request-context";
import { logger } from "~/server/utils/logger";
@ -164,7 +165,9 @@ const createRepository = async (name: string, config: RepositoryConfig, compress
error = result.error;
} else {
const initResult = await restic.init(encryptedConfig, organizationId, { timeoutMs: 20000 });
const initResult = await restic.init(encryptedConfig, organizationId, {
timeoutMs: appConfig.serverIdleTimeout * 1000,
});
error = initResult.error;
}

307
app/server/utils/__tests__/spawn.test.ts Normal file
View file

@ -0,0 +1,307 @@
import { describe, expect, test } from "bun:test";
import { safeExec, safeSpawn } from "../spawn";
describe("safeExec", () => {
describe("successful commands", () => {
test("returns exitCode 0 and output for successful command", async () => {
const result = await safeExec({ command: "echo", args: ["hello"] });
expect(result.exitCode).toBe(0);
expect(result.stdout.trim()).toBe("hello");
expect(result.stderr).toBe("");
expect(result.timedOut).toBe(false);
});
});
describe("failed commands", () => {
test("returns non-zero exitCode for failed command", async () => {
const result = await safeExec({
command: "sh",
args: ["-c", "exit 1"],
});
expect(result.exitCode).toBe(1);
expect(result.timedOut).toBe(false);
});
test("captures stderr from failed command", async () => {
const result = await safeExec({
command: "sh",
args: ["-c", "echo 'error message' >&2 && exit 1"],
});
expect(result.exitCode).toBe(1);
expect(result.stderr).toContain("error message");
expect(result.timedOut).toBe(false);
});
});
describe("timeout handling", () => {
test("detects timeout and sets timedOut flag", async () => {
const result = await safeExec({
command: "sleep",
args: ["10"],
timeout: 100,
});
expect(result.timedOut).toBe(true);
expect(result.exitCode).toBe(1);
expect(result.stderr).toBe("Command timed out before completing");
});
test("returns timedOut false when command completes within timeout", async () => {
const result = await safeExec({
command: "echo",
args: ["quick"],
timeout: 5000,
});
expect(result.timedOut).toBe(false);
expect(result.exitCode).toBe(0);
});
});
describe("env", () => {
test("passes custom env variables to the command", async () => {
const result = await safeExec({
command: "sh",
args: ["-c", "echo $TEST_EXEC_VAR"],
env: { TEST_EXEC_VAR: "exec_value" },
});
expect(result.exitCode).toBe(0);
expect(result.stdout.trim()).toBe("exec_value");
});
});
describe("shell injection protection", () => {
test("treats semicolon-separated commands as a single literal argument", async () => {
const result = await safeExec({
command: "echo",
args: ["safe; echo injected"],
});
expect(result.exitCode).toBe(0);
expect(result.stdout.trim()).toBe("safe; echo injected");
});
test("does not evaluate command substitution syntax", async () => {
const result = await safeExec({
command: "echo",
args: ["$(echo injected)"],
});
expect(result.exitCode).toBe(0);
expect(result.stdout.trim()).toBe("$(echo injected)");
});
test("does not expand glob patterns", async () => {
const result = await safeExec({
command: "echo",
args: ["*.ts"],
});
expect(result.exitCode).toBe(0);
expect(result.stdout.trim()).toBe("*.ts");
});
});
describe("stdout on failure", () => {
test("captures stdout written before a non-zero exit", async () => {
const result = await safeExec({
command: "sh",
args: ["-c", "echo output_before_failure && exit 1"],
});
expect(result.exitCode).toBe(1);
expect(result.stdout).toContain("output_before_failure");
});
});
});
describe("safeSpawn", () => {
describe("successful commands", () => {
test("returns exitCode 0 and correct summary", async () => {
const result = await safeSpawn({ command: "echo", args: ["hello"] });
expect(result.exitCode).toBe(0);
expect(result.summary).toBe("hello");
expect(result.error).toBe("");
});
test("summary is the last non-empty stdout line", async () => {
const result = await safeSpawn({
command: "sh",
args: ["-c", "echo first && echo second && echo third"],
});
expect(result.exitCode).toBe(0);
expect(result.summary).toBe("third");
});
test("skips blank and whitespace-only lines when tracking summary", async () => {
const result = await safeSpawn({
command: "sh",
args: ["-c", "printf 'first\\n\\n \\n'"],
});
expect(result.exitCode).toBe(0);
expect(result.summary).toBe("first");
});
});
describe("callbacks", () => {
test("calls onStdout once per stdout line", async () => {
const lines: string[] = [];
await safeSpawn({
command: "sh",
args: ["-c", "echo line1 && echo line2 && echo line3"],
onStdout: (line) => lines.push(line),
});
expect(lines).toEqual(["line1", "line2", "line3"]);
});
test("calls onStderr once per stderr line", async () => {
const errors: string[] = [];
await safeSpawn({
command: "sh",
args: ["-c", "echo err1 >&2 && echo err2 >&2"],
onStderr: (line) => errors.push(line),
});
expect(errors).toEqual(["err1", "err2"]);
});
test("calls onSpawn immediately with the child process", async () => {
let receivedChild: ReturnType<typeof import("node:child_process").spawn> | null = null;
await safeSpawn({
command: "echo",
args: ["test"],
onSpawn: (child) => {
receivedChild = child;
},
});
expect(receivedChild).not.toBeNull();
});
});
describe("failed commands", () => {
test("returns the exact non-zero exit code", async () => {
const result = await safeSpawn({
command: "sh",
args: ["-c", "exit 42"],
});
expect(result.exitCode).toBe(42);
});
test("error contains the last stderr line", async () => {
const result = await safeSpawn({
command: "sh",
args: ["-c", "echo err_first >&2 && echo err_last >&2 && exit 1"],
});
expect(result.exitCode).toBe(1);
expect(result.error).toBe("err_last");
});
test("returns exitCode -1 when the command is not found", async () => {
const result = await safeSpawn({
command: "this-command-does-not-exist-zerobyte",
args: [],
});
expect(result.exitCode).toBe(-1);
expect(result.error.length).toBeGreaterThan(0);
});
});
describe("stdoutMode", () => {
test("raw mode skips readline and leaves summary empty", async () => {
const result = await safeSpawn({
command: "echo",
args: ["hello"],
stdoutMode: "raw",
onSpawn: (child) => {
child.stdout?.resume();
},
});
expect(result.summary).toBe("");
});
test("raw mode exposes the raw stdout stream via onSpawn", async () => {
const chunks: Buffer[] = [];
await safeSpawn({
command: "echo",
args: ["raw_output"],
stdoutMode: "raw",
onSpawn: (child) => {
child.stdout?.on("data", (chunk: Buffer) => chunks.push(chunk));
},
});
const output = Buffer.concat(chunks).toString("utf8").trim();
expect(output).toBe("raw_output");
});
});
describe("env", () => {
test("passes custom env variables to the spawned process", async () => {
const lines: string[] = [];
await safeSpawn({
command: "sh",
args: ["-c", "echo $TEST_SPAWN_VAR"],
env: { TEST_SPAWN_VAR: "spawn_value" },
onStdout: (line) => lines.push(line),
});
expect(lines).toContain("spawn_value");
});
});
describe("shell injection protection", () => {
test("treats semicolon-separated commands as a single literal argument", async () => {
const lines: string[] = [];
await safeSpawn({
command: "echo",
args: ["safe; echo injected"],
onStdout: (line) => lines.push(line),
});
expect(lines).toEqual(["safe; echo injected"]);
});
test("does not evaluate command substitution syntax", async () => {
const lines: string[] = [];
await safeSpawn({
command: "echo",
args: ["$(echo injected)"],
onStdout: (line) => lines.push(line),
});
expect(lines).toEqual(["$(echo injected)"]);
});
test("does not expand glob patterns", async () => {
const lines: string[] = [];
await safeSpawn({
command: "echo",
args: ["*.ts"],
onStdout: (line) => lines.push(line),
});
expect(lines).toEqual(["*.ts"]);
});
});
});

6
app/server/utils/rclone.ts
View file

@ -1,13 +1,13 @@
import { logger } from "./logger";
import { toMessage } from "./errors";
import { exec } from "./spawn";
import { safeExec } from "./spawn";
/**
* List all configured rclone remotes
* @returns Array of remote names
*/
export async function listRcloneRemotes(): Promise<string[]> {
const result = await exec({ command: "rclone", args: ["listremotes"] });
const result = await safeExec({ command: "rclone", args: ["listremotes"] });
if (result.exitCode !== 0) {
logger.error(`Failed to list rclone remotes: ${result.stderr.toString()}`);
@ -34,7 +34,7 @@ export async function getRcloneRemoteInfo(
remote: string,
): Promise<{ type: string; config: Record<string, string> } | null> {
try {
const result = await exec({ command: "rclone", args: ["config", "show", remote] });
const result = await safeExec({ command: "rclone", args: ["config", "show", remote] });
if (result.exitCode !== 0) {
logger.error(`Failed to get info for remote ${remote}: ${result.stderr.toString()}`);

27
app/server/utils/restic.ts
View file

@ -25,7 +25,7 @@ import { cryptoUtils } from "./crypto";
import { ResticError } from "./errors";
import { safeJsonParse } from "./json";
import { logger } from "./logger";
import { exec, safeSpawn } from "./spawn";
import { safeExec, safeSpawn } from "./spawn";
import { findCommonAncestor } from "~/utils/common-ancestor";
const snapshotInfoSchema = type({
@ -245,12 +245,7 @@ const init = async (config: RepositoryConfig, organizationId: string, options?:
const args = ["init", "--repo", repoUrl];
addCommonArgs(args, env, config);
const res = await exec({
command: "restic",
args,
env,
timeout: options?.timeoutMs ?? 20000,
});
const res = await safeExec({ command: "restic", args, env, timeout: options?.timeoutMs ?? 60000 });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {
@ -674,7 +669,7 @@ const snapshots = async (config: RepositoryConfig, options: { tags?: string[]; o
addCommonArgs(args, env, config);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {
@ -699,7 +694,7 @@ const stats = async (config: RepositoryConfig, options: { organizationId: string
const args = ["--repo", repoUrl, "stats", "--mode", "raw-data"];
addCommonArgs(args, env, config);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {
@ -793,7 +788,7 @@ const forget = async (
addCommonArgs(args, env, config);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {
@ -818,7 +813,7 @@ const deleteSnapshots = async (config: RepositoryConfig, snapshotIds: string[],
const args: string[] = ["--repo", repoUrl, "forget", ...snapshotIds, "--prune"];
addCommonArgs(args, env, config);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {
@ -868,7 +863,7 @@ const tagSnapshots = async (
addCommonArgs(args, env, config);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(env);
if (res.exitCode !== 0) {
@ -1003,7 +998,7 @@ const unlock = async (config: RepositoryConfig, options: { signal?: AbortSignal;
const args = ["unlock", "--repo", repoUrl, "--remove-all"];
addCommonArgs(args, env, config);
const res = await exec({
const res = await safeExec({
command: "restic",
args,
env,
@ -1044,7 +1039,7 @@ const check = async (
addCommonArgs(args, env, config);
const res = await exec({
const res = await safeExec({
command: "restic",
args,
env,
@ -1092,7 +1087,7 @@ const repairIndex = async (config: RepositoryConfig, options: { signal?: AbortSi
const args = ["repair", "index", "--repo", repoUrl];
addCommonArgs(args, env, config);
const res = await exec({
const res = await safeExec({
command: "restic",
args,
env,
@ -1166,7 +1161,7 @@ const copy = async (
logger.info(`Copying snapshots from ${sourceRepoUrl} to ${destRepoUrl}...`);
logger.debug(`Executing: restic ${args.join(" ")}`);
const res = await exec({ command: "restic", args, env });
const res = await safeExec({ command: "restic", args, env });
await cleanupTemporaryKeys(sourceEnv);
await cleanupTemporaryKeys(destEnv);

4
app/server/utils/shoutrrr.ts
View file

@ -1,4 +1,4 @@
import { exec } from "./spawn";
import { safeExec } from "./spawn";
import { logger } from "./logger";
import { toMessage } from "./errors";
@ -16,7 +16,7 @@ export async function sendNotification(params: SendNotificationParams) {
logger.debug(`Sending notification via Shoutrrr: ${title}`);
const result = await exec({ command: "shoutrrr", args });
const result = await safeExec({ command: "shoutrrr", args });
if (result.exitCode === 0) {
logger.debug(`Notification sent successfully: ${title}`);

10
app/server/utils/spawn.ts
View file

@ -8,7 +8,7 @@ type ExecProps = {
env?: NodeJS.ProcessEnv;
} & ExecFileOptions;
export const exec = async ({ command, args = [], env = {}, ...rest }: ExecProps) => {
export const safeExec = async ({ command, args = [], env = {}, ...rest }: ExecProps) => {
const options = {
env: { ...process.env, ...env },
};
@ -20,14 +20,16 @@ export const exec = async ({ command, args = [], env = {}, ...rest }: ExecProps)
encoding: "utf8",
});
return { exitCode: 0, stdout, stderr };
return { exitCode: 0, stdout, stderr, timedOut: false };
} catch (error) {
const execError = error as ExecException;
const execError = error as ExecException & { killed?: boolean };
const timedOut = execError.killed === true && execError.code === null;
return {
exitCode: typeof execError.code === "number" ? execError.code : 1,
stdout: execError.stdout || "",
stderr: execError.stderr || "",
stderr: timedOut ? "Command timed out before completing" : execError.stderr || "",
timedOut,
};
}
};