From 6a39f43404c4dfa36ef813b9e87ffa36887da512 Mon Sep 17 00:00:00 2001 From: jochen Date: Wed, 4 Nov 2026 11:46:12 +0100 Subject: [PATCH 1/2] restic: a failed command reports the tail of its output, not only its exit status Issue 1585: the backup before a nats move failed with only 'sh: exit status 1'. Claude-Session: https://claude.ai/code/session_01JG73KG7AfSdh6FP8VrBqCn --- modules/restic/cmd/restic-backups/backups.go | 42 ++++++++++++------- .../restic/cmd/restic-backups/backups_test.go | 17 ++++++++ 2 files changed, 44 insertions(+), 15 deletions(-) diff --git a/modules/restic/cmd/restic-backups/backups.go b/modules/restic/cmd/restic-backups/backups.go index f0954581..bc8181e7 100644 --- a/modules/restic/cmd/restic-backups/backups.go +++ b/modules/restic/cmd/restic-backups/backups.go @@ -61,25 +61,37 @@ func execRunner(ctx context.Context, name string, args ...string) (string, error cmd := exec.CommandContext(ctx, program, argv...) cmd.Stdout, cmd.Stderr = &stdout, &stderr if err := cmd.Run(); err != nil { - said := strings.TrimSpace(stderr.String()) - if said == "" { - said = strings.TrimSpace(stdout.String()) - } - if program == "sudo" && strings.HasPrefix(said, "sudo:") { - return "", fmt.Errorf("%s needs root and the runtime's account may not run it without a prompt: %s", name, said) - } - lines := strings.Split(said, "\n") - if len(lines) > 3 { - lines = lines[len(lines)-3:] - } - if said == "" { - return "", fmt.Errorf("%s: %w", name, err) - } - return "", errors.New(strings.Join(lines, " / ")) + return "", failure(program, name, err, stdout.String(), stderr.String()) } return stdout.String(), nil } +// failureTail bounds what a failed command's output adds to the failure it reports: its last 2 KB. +const failureTail = 2048 + +var secretLooking = regexp.MustCompile(`(?i)((?:pass(?:word|wd)?|secret|token|api[_-]?key)\s*[=:]\s*)\S+`) + +// failure is the error of a command that exited badly: its last lines of stderr (stdout when stderr is +// empty), bounded to failureTail bytes, with what looks like a secret blotted out, so the report of a +// failed dump says why and not only that it exited. With nothing printed it keeps the exit status. +func failure(program, name string, err error, stdout, stderr string) error { + said := strings.TrimSpace(stderr) + if said == "" { + said = strings.TrimSpace(stdout) + } + if program == "sudo" && strings.HasPrefix(said, "sudo:") { + return fmt.Errorf("%s needs root and the runtime's account may not run it without a prompt: %s", name, said) + } + if said == "" { + return fmt.Errorf("%s: %w (it printed nothing)", name, err) + } + if len(said) > failureTail { + said = "..." + said[len(said)-failureTail:] + } + said = secretLooking.ReplaceAllString(said, "${1}***") + return fmt.Errorf("%s: %v: %s", name, err, strings.Join(strings.Split(said, "\n"), " / ")) +} + // Declared is what one module declared. type Declared struct { Module string `json:"module"` diff --git a/modules/restic/cmd/restic-backups/backups_test.go b/modules/restic/cmd/restic-backups/backups_test.go index 3a545185..64695cff 100644 --- a/modules/restic/cmd/restic-backups/backups_test.go +++ b/modules/restic/cmd/restic-backups/backups_test.go @@ -333,3 +333,20 @@ func TestARestoreBesideAnotherAccountsDirectoryGoesToTheState(t *testing.T) { } _ = ran } + +func TestAFailedCommandReportsTheTailOfWhatItPrintedWithSecretsBlotted(t *testing.T) { + exit := errors.New("exit status 1") + long := strings.Repeat("x", 5000) + "\npg_dump: error: password=hunter2 refused" + for _, c := range []struct{ name, program, out, errOut, want, not string }{ + {"stderr", "sh", "", "pg_dump: connection refused\nsecond", "sh: exit status 1: pg_dump: connection refused / second", ""}, + {"stdout when stderr is empty", "sh", "dump failed\n", "", "sh: exit status 1: dump failed", ""}, + {"nothing printed", "sh", "", "", "sh: exit status 1 (it printed nothing)", ""}, + {"bounded and blotted", "sh", "", long, "password=*** refused", "hunter2"}, + {"sudo prompt", "sudo", "", "sudo: a password is required", "needs root", ""}, + } { + got := failure(c.program, "sh", exit, c.out, c.errOut).Error() + if !strings.Contains(got, c.want) || (c.not != "" && strings.Contains(got, c.not)) || len(got) > failureTail+100 { + t.Errorf("%s: got %q", c.name, got) + } + } +} -- 2.54.0 From 4aa77a4237ddac724018b03b2b31b101732d7342 Mon Sep 17 00:00:00 2001 From: jochen Date: Wed, 4 Nov 2026 11:50:29 +0100 Subject: [PATCH 2/2] nats dump keeps and says the snapshot's exit status; restic blots JSON credentials and cuts on a character Claude-Session: https://claude.ai/code/session_01JG73KG7AfSdh6FP8VrBqCn --- modules/nats/dump_test.go | 72 +++++++++++++++++++ modules/nats/module.json | 2 +- modules/restic/cmd/restic-backups/backups.go | 9 ++- .../restic/cmd/restic-backups/backups_test.go | 2 + 4 files changed, 82 insertions(+), 3 deletions(-) create mode 100644 modules/nats/dump_test.go diff --git a/modules/nats/dump_test.go b/modules/nats/dump_test.go new file mode 100644 index 00000000..7f8009c6 --- /dev/null +++ b/modules/nats/dump_test.go @@ -0,0 +1,72 @@ +package main_test + +import ( + "encoding/json" + "os" + "os/exec" + "path/filepath" + "strings" + "testing" +) + +// A failed snapshot dump keeps and says the real exit status (a container killed by a signal answers +// 137), names the container's state, and leaves no partial archive. +func TestTheDumpKeepsAndSaysTheStatusOfAFailedSnapshot(t *testing.T) { + raw, err := os.ReadFile("module.json") + if err != nil { + t.Fatal(err) + } + var m struct { + Data struct { + Own []struct { + ID string `json:"id"` + Backup struct { + Dump string `json:"dump"` + } `json:"backup"` + } `json:"own"` + } `json:"data"` + } + if err := json.Unmarshal(raw, &m); err != nil { + t.Fatal(err) + } + dump := "" + for _, d := range m.Data.Own { + if d.ID == "jetstream" { + dump = d.Backup.Dump + } + } + for _, c := range []struct { + name string + status string + want string + }{{"killed", "137", "exited 137 (killed by a signal)"}, {"failed", "3", "exited 3"}} { + dir := t.TempDir() + bin := filepath.Join(dir, "bin") + os.MkdirAll(bin, 0o755) + fake := "#!/bin/sh\nif [ \"$1\" = inspect ]; then echo 'container exited since yesterday'; exit 0; fi\necho partial-bytes\nexit " + c.status + "\n" + os.WriteFile(filepath.Join(bin, "docker"), []byte(fake), 0o755) + os.WriteFile(filepath.Join(dir, "broker"), nil, 0o644) + cmdline := strings.NewReplacer("${dir:snapshots}", dir, "${dir:mesh-state}", dir).Replace(dump) + cmd := exec.Command("sh", "-c", cmdline) + cmd.Env = []string{"PATH=" + bin + ":/usr/bin:/bin"} + out, err := cmd.CombinedOutput() + ee, ok := err.(*exec.ExitError) + if !ok || ee.ExitCode() != atoi(c.status) { + t.Errorf("%s: exit %v, want %s; output %s", c.name, err, c.status, out) + } + if !strings.Contains(string(out), c.want) || !strings.Contains(string(out), "container exited since") { + t.Errorf("%s: output %q", c.name, out) + } + if _, err := os.Stat(filepath.Join(dir, "bus.tar.partial")); err == nil { + t.Errorf("%s: partial left", c.name) + } + } +} + +func atoi(s string) int { + n := 0 + for _, r := range s { + n = n*10 + int(r-'0') + } + return n +} diff --git a/modules/nats/module.json b/modules/nats/module.json index 3e58475c..4f028cc2 100644 --- a/modules/nats/module.json +++ b/modules/nats/module.json @@ -82,7 +82,7 @@ "class": "valuable", "active": "1d", "backup": { - "dump": "docker exec -i mesh-broker-nats /opt/mesh/mesh-nats-snapshot snapshot < ${dir:mesh-state}/broker > ${dir:snapshots}/bus.tar.partial && mv ${dir:snapshots}/bus.tar.partial ${dir:snapshots}/bus.tar || { rm -f ${dir:snapshots}/bus.tar.partial; exit 1; }", + "dump": "p=${dir:snapshots}/bus.tar.partial; s=0; docker exec -i mesh-broker-nats /opt/mesh/mesh-nats-snapshot snapshot < ${dir:mesh-state}/broker > \"$p\" || s=$?; if [ $s -ne 0 ]; then echo \"mesh-nats-snapshot snapshot exited $s$([ $s -eq 137 -o $s -eq 143 ] && echo ' (killed by a signal)')\" >&2; docker inspect -f 'container {{.State.Status}} since {{.State.StartedAt}}' mesh-broker-nats >&2; rm -f \"$p\"; exit $s; fi; mv \"$p\" ${dir:snapshots}/bus.tar || exit 1", "into": "snapshots" }, "why": "the bus's streams and key-value buckets: the hand-act log, conditions, every module's state; written all the time, so copied by the server's own snapshot of each stream (novox/hq ADR 0235), never as live files" diff --git a/modules/restic/cmd/restic-backups/backups.go b/modules/restic/cmd/restic-backups/backups.go index bc8181e7..6c468dcc 100644 --- a/modules/restic/cmd/restic-backups/backups.go +++ b/modules/restic/cmd/restic-backups/backups.go @@ -36,6 +36,7 @@ import ( "sync" "syscall" "time" + "unicode/utf8" ) // Runner runs one command and answers what it printed, so the backups can be tested without restic @@ -69,7 +70,7 @@ func execRunner(ctx context.Context, name string, args ...string) (string, error // failureTail bounds what a failed command's output adds to the failure it reports: its last 2 KB. const failureTail = 2048 -var secretLooking = regexp.MustCompile(`(?i)((?:pass(?:word|wd)?|secret|token|api[_-]?key)\s*[=:]\s*)\S+`) +var secretLooking = regexp.MustCompile(`(?i)((?:pass(?:word|wd)?|secret|token|api[_-]?key)["']?\s*[=:]\s*)("[^"]*"|'[^']*'|\S+)`) // failure is the error of a command that exited badly: its last lines of stderr (stdout when stderr is // empty), bounded to failureTail bytes, with what looks like a secret blotted out, so the report of a @@ -86,7 +87,11 @@ func failure(program, name string, err error, stdout, stderr string) error { return fmt.Errorf("%s: %w (it printed nothing)", name, err) } if len(said) > failureTail { - said = "..." + said[len(said)-failureTail:] + cut := len(said) - failureTail + for cut < len(said) && !utf8.RuneStart(said[cut]) { + cut++ + } + said = "..." + said[cut:] } said = secretLooking.ReplaceAllString(said, "${1}***") return fmt.Errorf("%s: %v: %s", name, err, strings.Join(strings.Split(said, "\n"), " / ")) diff --git a/modules/restic/cmd/restic-backups/backups_test.go b/modules/restic/cmd/restic-backups/backups_test.go index 64695cff..c0560558 100644 --- a/modules/restic/cmd/restic-backups/backups_test.go +++ b/modules/restic/cmd/restic-backups/backups_test.go @@ -342,6 +342,8 @@ func TestAFailedCommandReportsTheTailOfWhatItPrintedWithSecretsBlotted(t *testin {"stdout when stderr is empty", "sh", "dump failed\n", "", "sh: exit status 1: dump failed", ""}, {"nothing printed", "sh", "", "", "sh: exit status 1 (it printed nothing)", ""}, {"bounded and blotted", "sh", "", long, "password=*** refused", "hunter2"}, + {"json credential", "sh", "", `{"password": "hunter2", "user": "a"}`, `"password": ***`, "hunter2"}, + {"cut on a character", "sh", "", strings.Repeat("é", 1500), "...é", ""}, {"sudo prompt", "sudo", "", "sudo: a password is required", "needs root", ""}, } { got := failure(c.program, "sh", exit, c.out, c.errOut).Error() -- 2.54.0