From a271afe7e3e840071ee3d2d18861ccd31548db89 Mon Sep 17 00:00:00 2001 From: Gareth Date: Wed, 27 Aug 2025 22:05:13 -0700 Subject: [PATCH] fix: rework output handling in restic pkg to improve error capturing and consistency --- internal/ioutil/ioutil.go | 2 +- pkg/restic/error.go | 40 +++++-- pkg/restic/outputs.go | 10 +- pkg/restic/outputs_test.go | 50 +++++++- pkg/restic/restic.go | 233 ++++++++++++++++++++++--------------- pkg/restic/restic_test.go | 110 +++++++++-------- 6 files changed, 280 insertions(+), 165 deletions(-) diff --git a/internal/ioutil/ioutil.go b/internal/ioutil/ioutil.go index 60b07730..f3864a4e 100644 --- a/internal/ioutil/ioutil.go +++ b/internal/ioutil/ioutil.go @@ -19,7 +19,7 @@ func (l *LimitWriter) Write(p []byte) (rnw int, err error) { rnw = len(p) if l.N <= 0 { l.D += len(p) - return 0, nil + return } if len(p) > l.N { l.D += len(p) - l.N diff --git a/pkg/restic/error.go b/pkg/restic/error.go index a4c9af9a..17679c3e 100644 --- a/pkg/restic/error.go +++ b/pkg/restic/error.go @@ -1,7 +1,7 @@ package restic import ( - "context" + "bytes" "fmt" "os/exec" ) @@ -28,7 +28,7 @@ func (e *CmdError) Is(target error) bool { } // newCmdError creates a new error indicating that running a command failed. -func newCmdError(ctx context.Context, cmd *exec.Cmd, err error) *CmdError { +func newCmdError(cmd *exec.Cmd, err error) *CmdError { shortCmd := cmd.String() if len(shortCmd) > 100 { shortCmd = shortCmd[:100] + "..." @@ -59,18 +59,38 @@ func (e *ErrorWithOutput) Is(target error) bool { return ok } -// newErrorWithOutput creates a new error with the given output. -func newErrorWithOutput(err error, output string) error { - if output == "" { +type errorMessageCollector struct { + Output *bytes.Buffer + DroppedBytes int +} + +func (e *errorMessageCollector) Write(p []byte) (int, error) { + if e.Output == nil { + e.Output = &bytes.Buffer{} + } + if e.Output.Len() >= outputBufferLimit { + e.DroppedBytes += len(p) + return len(p), nil + } + return e.Output.Write(p) +} + +func (e *errorMessageCollector) AddOutputToError(err error) error { + if e.Output == nil { return err } - - if len(output) > outputBufferLimit { - output = output[:outputBufferLimit] + fmt.Sprintf("\n... %d bytes truncated ...\n", len(output)-outputBufferLimit) + if e.DroppedBytes > 0 { + return &ErrorWithOutput{ + Err: err, + Output: fmt.Sprintf("%s\n... %d bytes truncated ...", e.Output.String(), e.DroppedBytes), + } } - return &ErrorWithOutput{ Err: err, - Output: output, + Output: e.Output.String(), } } + +func (e *errorMessageCollector) AddCmdOutputToError(cmd *exec.Cmd, err error) error { + return newCmdError(cmd, e.AddOutputToError(err)) +} diff --git a/pkg/restic/outputs.go b/pkg/restic/outputs.go index d5e252a2..a2cea229 100644 --- a/pkg/restic/outputs.go +++ b/pkg/restic/outputs.go @@ -2,7 +2,6 @@ package restic import ( "bufio" - "bytes" "encoding/json" "errors" "fmt" @@ -210,7 +209,7 @@ func processProgressOutput[T ProgressEntryValidator]( scanner := bufio.NewScanner(output) scanner.Split(bufio.ScanLines) - nonJSONOutput := bytes.NewBuffer(nil) + nonJSONOutput := &errorMessageCollector{} var captureNonJSON io.Writer = nonJSONOutput if logger != nil { captureNonJSON = io.MultiWriter(nonJSONOutput, logger) @@ -230,7 +229,7 @@ func processProgressOutput[T ProgressEntryValidator]( } if err := event.IsFatalError(); err != nil { - return summary, newErrorWithOutput(fmt.Errorf("restic died with error: %v", err), nonJSONOutput.String()) + return summary, nonJSONOutput.AddOutputToError(err) } if err := event.Validate(); err != nil { @@ -250,11 +249,10 @@ func processProgressOutput[T ProgressEntryValidator]( } if err := scanner.Err(); err != nil { - return summary, newErrorWithOutput(err, nonJSONOutput.String()) + return summary, nonJSONOutput.AddOutputToError(err) } - if !gotSummary { - return summary, newErrorWithOutput(errors.New("no summary event found"), nonJSONOutput.String()) + return summary, nonJSONOutput.AddOutputToError(errors.New("no summary event found")) } return summary, nil diff --git a/pkg/restic/outputs_test.go b/pkg/restic/outputs_test.go index 062331a3..7a374b02 100644 --- a/pkg/restic/outputs_test.go +++ b/pkg/restic/outputs_test.go @@ -2,6 +2,8 @@ package restic import ( "bytes" + "reflect" + "strings" "testing" ) @@ -26,11 +28,53 @@ func TestReadBackupProgressEntries(t *testing.T) { } } +func TestReadVerboseBackupProgressEntries(t *testing.T) { + t.Parallel() + + testInput := `{"message_type":"status","seconds_elapsed":8,"percent_done":0,"total_files":10,"files_done":1,"total_bytes":27557,"current_files":["/cur/file.txt"]} +{"message_type":"verbose_status","action":"modified","item":"/foo/bar.txt","duration":0.024449704,"data_size":0,"data_size_in_repo":0,"metadata_size":0,"metadata_size_in_repo":0,"total_files":0} +{"message_type":"exit_error","code":1,"message":"my sentinel error message"}` + + events := []BackupProgressEntry{} + _, err := processProgressOutput[*BackupProgressEntry](bytes.NewBuffer([]byte(testInput)), nil, func(event *BackupProgressEntry) { + events = append(events, *event) + }) + if err == nil || !strings.Contains(err.Error(), "my sentinel error message") { + t.Fatalf("wanted error containing 'my sentinel error message', got: %v", err) + } + // Assert that we get exactly the expected set of events. + wantEvents := []BackupProgressEntry{ + { + MessageType: "status", + PercentDone: 0, + TotalFiles: 10, + FilesDone: 1, + TotalBytes: 27557, + CurrentFiles: []string{"/cur/file.txt"}, + }, + { + MessageType: "verbose_status", + Action: "modified", + Item: "/foo/bar.txt", + }, + } + + if len(events) != len(wantEvents) { + t.Fatalf("wanted %d events, got: %d", len(wantEvents), len(events)) + } + + for i, event := range events { + if !reflect.DeepEqual(event, wantEvents[i]) { + t.Errorf("event %d: wanted %v, got %v", i, wantEvents[i], event) + } + } +} + func TestReadLs(t *testing.T) { testInput := `{"time":"2023-11-10T19:14:17.053824063-08:00","tree":"3e2918b261948e69602ee9504b8f475bcc7cdc4dcec0b3f34ecdb014287d07b2","paths":["/backrest"],"hostname":"pop-os","username":"dontpanic","uid":1000,"gid":1000,"id":"db155169d788e6e432e320aedbdff5a54cc439653093bb56944a67682528aa52","short_id":"db155169","struct_type":"snapshot"} - {"name":".git","type":"dir","path":"/.git","uid":1000,"gid":1000,"mode":2147484157,"mtime":"2023-11-10T18:32:38.156599473-08:00","atime":"2023-11-10T18:32:38.156599473-08:00","ctime":"2023-11-10T18:32:38.156599473-08:00","struct_type":"node"} - {"name":".gitignore","type":"file","path":"/.gitignore","uid":1000,"gid":1000,"size":22,"mode":436,"mtime":"2023-11-10T00:41:26.611346634-08:00","atime":"2023-11-10T00:41:26.611346634-08:00","ctime":"2023-11-10T00:41:26.611346634-08:00","struct_type":"node"} - {"name":"README.md","type":"file","path":"/README.md","uid":1000,"gid":1000,"size":762,"mode":436,"mtime":"2023-11-10T00:59:06.842538768-08:00","atime":"2023-11-10T00:59:06.842538768-08:00","ctime":"2023-11-10T00:59:06.842538768-08:00","struct_type":"node"}` +{"name":".git","type":"dir","path":"/.git","uid":1000,"gid":1000,"mode":2147484157,"mtime":"2023-11-10T18:32:38.156599473-08:00","atime":"2023-11-10T18:32:38.156599473-08:00","ctime":"2023-11-10T18:32:38.156599473-08:00","struct_type":"node"} +{"name":".gitignore","type":"file","path":"/.gitignore","uid":1000,"gid":1000,"size":22,"mode":436,"mtime":"2023-11-10T00:41:26.611346634-08:00","atime":"2023-11-10T00:41:26.611346634-08:00","ctime":"2023-11-10T00:41:26.611346634-08:00","struct_type":"node"} +{"name":"README.md","type":"file","path":"/README.md","uid":1000,"gid":1000,"size":762,"mode":436,"mtime":"2023-11-10T00:59:06.842538768-08:00","atime":"2023-11-10T00:59:06.842538768-08:00","ctime":"2023-11-10T00:59:06.842538768-08:00","struct_type":"node"}` b := bytes.NewBuffer([]byte(testInput)) diff --git a/pkg/restic/restic.go b/pkg/restic/restic.go index 1e184514..5416c192 100644 --- a/pkg/restic/restic.go +++ b/pkg/restic/restic.go @@ -66,64 +66,106 @@ func (r *Repo) commandWithContext(ctx context.Context, args []string, opts ...Ge cmd := exec.CommandContext(ctx, fullCmd[0], fullCmd[1:]...) cmd.Env = append(cmd.Env, opt.extraEnv...) - logger := LoggerFromContext(ctx) - if logger != nil { - sw := &ioutil.SynchronizedWriter{W: logger} - cmd.Stderr = sw - cmd.Stdout = sw - fmt.Fprintf(logger, "command: %q\n", fullCmd) - } - return cmd } -func (r *Repo) pipeCmdOutputToWriter(cmd *exec.Cmd, handlers ...io.Writer) { - stdoutHandlers := slices.Clone(handlers) - stderrHandlers := slices.Clone(handlers) - - if cmd.Stdout != nil { - handlers = append(stdoutHandlers, cmd.Stdout) - } - if cmd.Stderr != nil { - handlers = append(stderrHandlers, cmd.Stderr) - } - - mw := io.MultiWriter(handlers...) - mw = &ioutil.SynchronizedWriter{W: mw} - cmd.Stdout = mw - cmd.Stderr = mw +type outputOpts struct { + stdErrWriters []io.Writer + stdOutWriters []io.Writer } -// executeWithOutput runs a command and captures the output in a buffer -func (r *Repo) executeWithOutput(ctx context.Context, args []string, opts ...GenericOption) ([]byte, error) { - cmd := r.commandWithContext(ctx, args, opts...) - output := bytes.NewBuffer(nil) - r.pipeCmdOutputToWriter(cmd, output) +func withStdErrTo(writer io.Writer) func(cmd *exec.Cmd, opts *outputOpts) { + return func(cmd *exec.Cmd, opts *outputOpts) { + opts.stdErrWriters = append(opts.stdErrWriters, writer) + } +} - err := cmd.Run() - if err != nil { - return output.Bytes(), newCmdError(ctx, cmd, newErrorWithOutput(err, output.String())) +func withStdOutTo(writer io.Writer) func(cmd *exec.Cmd, opts *outputOpts) { + return func(cmd *exec.Cmd, opts *outputOpts) { + opts.stdOutWriters = append(opts.stdOutWriters, writer) + } +} + +func withAllTo(writer io.Writer) func(cmd *exec.Cmd, opts *outputOpts) { + return func(cmd *exec.Cmd, opts *outputOpts) { + sw := &ioutil.SynchronizedWriter{W: writer} + opts.stdErrWriters = append(opts.stdErrWriters, sw) + opts.stdOutWriters = append(opts.stdOutWriters, sw) + } +} + +func withLogWriterFromContext(ctx context.Context) func(cmd *exec.Cmd, opts *outputOpts) { + return func(cmd *exec.Cmd, opts *outputOpts) { + logger := LoggerFromContext(ctx) + if logger != nil { + fmt.Fprintf(logger, "command: %q\n", cmd) + opts.stdErrWriters = append(opts.stdErrWriters, logger) + opts.stdOutWriters = append(opts.stdOutWriters, logger) + } + } +} + +func (r *Repo) handleOutput(cmd *exec.Cmd, opts ...func(cmd *exec.Cmd, opts *outputOpts)) { + outputOpts := &outputOpts{} + + for _, opt := range opts { + opt(cmd, outputOpts) } - return output.Bytes(), nil + var stdOutWriter io.Writer + if len(outputOpts.stdOutWriters) > 1 { + stdOutWriter = io.MultiWriter(outputOpts.stdOutWriters...) + } else if len(outputOpts.stdOutWriters) == 1 { + stdOutWriter = outputOpts.stdOutWriters[0] + } + + var stdErrWriter io.Writer + if len(outputOpts.stdErrWriters) > 1 { + stdErrWriter = io.MultiWriter(outputOpts.stdErrWriters...) + } else if len(outputOpts.stdErrWriters) == 1 { + stdErrWriter = outputOpts.stdErrWriters[0] + } + + if stdOutWriter != nil { + if cmd.Stdout != nil { + cmd.Stdout = io.MultiWriter(cmd.Stdout, stdOutWriter) + } else { + cmd.Stdout = stdOutWriter + } + } + if stdErrWriter != nil { + if cmd.Stderr != nil { + cmd.Stderr = io.MultiWriter(cmd.Stderr, stdErrWriter) + } else { + cmd.Stderr = stdErrWriter + } + } } // executeWithJSONOutput runs a command and parses its JSON output func (r *Repo) executeWithJSONOutput(ctx context.Context, args []string, result interface{}, opts ...GenericOption) error { - output, err := r.executeWithOutput(ctx, args, opts...) - if err != nil { - return err + // Create a pipe + errorCollector := errorMessageCollector{} + stdoutOutput := bytes.NewBuffer(nil) + + // Run the command + cmd := r.commandWithContext(ctx, args, opts...) + r.handleOutput(cmd, withAllTo(&errorCollector), withStdOutTo(stdoutOutput), withLogWriterFromContext(ctx)) + if err := cmd.Run(); err != nil { + return errorCollector.AddCmdOutputToError(cmd, err) } + stdOutBytes := stdoutOutput.Bytes() + // Try to parse the entire output first - origErr := json.Unmarshal(output, result) + origErr := json.Unmarshal(stdOutBytes, result) if origErr == nil { return nil } // Find the index afterwhich everything is whitespace - allWhitespaceAfterIdx := len(output) - for i, b := range output { + allWhitespaceAfterIdx := len(stdoutOutput.Bytes()) + for i, b := range stdoutOutput.Bytes() { if unicode.IsSpace(rune(b)) { allWhitespaceAfterIdx = i } @@ -132,16 +174,15 @@ func (r *Repo) executeWithJSONOutput(ctx context.Context, args []string, result // If that fails, try by skipping bytes until a newline is found start := 0 for start < allWhitespaceAfterIdx { - if err := json.Unmarshal(output[start:], result); err == nil { - zap.S().Warnf("Command %v output may have contained a skipped warning from restic that was not valid JSON: %s", args, string(output[start:])) + if err := json.Unmarshal(stdOutBytes[start:], result); err == nil { + zap.S().Warnf("Command %v output may have contained a skipped warning from restic that was not valid JSON: %s", args, string(stdOutBytes[start:])) return nil } - start = start + bytes.IndexRune(output[start:], '\n') + start = start + bytes.IndexRune(stdOutBytes[start:], '\n') start++ // skip the newline itself } - return newCmdError(ctx, r.commandWithContext(ctx, args), - newErrorWithOutput(fmt.Errorf("command output is not valid JSON: %w", origErr), string(output))) + return errorCollector.AddCmdOutputToError(cmd, fmt.Errorf("command output is not valid JSON: %w", origErr)) } // Exists checks if the repository exists. @@ -149,16 +190,17 @@ func (r *Repo) executeWithJSONOutput(ctx context.Context, args []string, result func (r *Repo) Exists(ctx context.Context, opts ...GenericOption) error { r.checkExists.Do(func() { output := bytes.NewBuffer(nil) + errorCollector := errorMessageCollector{} cmd := r.commandWithContext(ctx, []string{"cat", "config"}, opts...) - r.pipeCmdOutputToWriter(cmd, output) + r.handleOutput(cmd, withAllTo(&errorCollector), withStdOutTo(output), withLogWriterFromContext(ctx)) if err := cmd.Run(); err != nil { var exitErr *exec.ExitError if errors.As(err, &exitErr) && exitErr.ExitCode() == 10 { err = ErrRepoNotFound } - r.exists = newCmdError(ctx, cmd, newErrorWithOutput(err, output.String())) + r.exists = errorCollector.AddCmdOutputToError(cmd, err) } else if err := json.Unmarshal(output.Bytes(), &r.repoConfig); err != nil { - r.exists = newCmdError(ctx, cmd, newErrorWithOutput(fmt.Errorf("command output is not valid JSON: %w", err), output.String())) + r.exists = errorCollector.AddCmdOutputToError(cmd, fmt.Errorf("command output is not valid JSON: %w", err)) } else { r.exists = nil } @@ -175,17 +217,18 @@ func (r *Repo) init(ctx context.Context, opts ...GenericOption) error { r.shouldInitialize.Do(func() { cmd := r.commandWithContext(ctx, []string{"init", "--json"}, opts...) output := bytes.NewBuffer(nil) - r.pipeCmdOutputToWriter(cmd, output) + errorCollector := errorMessageCollector{} + r.handleOutput(cmd, withAllTo(&errorCollector), withStdOutTo(output), withLogWriterFromContext(ctx)) if err := cmd.Run(); err != nil { if strings.Contains(output.String(), "config file already exists") || strings.Contains(output.String(), "already initialized") { r.initialized = errAlreadyInitialized } else { - r.initialized = newCmdError(ctx, cmd, newCmdError(ctx, cmd, newErrorWithOutput(err, output.String()))) + r.initialized = errorCollector.AddCmdOutputToError(cmd, err) } } else { if err := json.Unmarshal(output.Bytes(), &r.repoConfig); err != nil { - r.initialized = newCmdError(ctx, cmd, newErrorWithOutput(fmt.Errorf("command output is not valid JSON: %w", err), output.String())) + r.initialized = errorCollector.AddCmdOutputToError(cmd, fmt.Errorf("command output is not valid JSON: %w", err)) } r.exists = r.initialized } @@ -205,40 +248,34 @@ func (r *Repo) Config(ctx context.Context, opts ...GenericOption) (RepoConfig, e return r.repoConfig, nil } -type cmdRunnerWithProgress[T ProgressEntryValidator] struct { - repo *Repo - callback func(T) - failureErr error -} - -// handleExitError processes a command exit error and converts it to an appropriate error type -func (cr *cmdRunnerWithProgress[T]) handleExitError(err error) error { +func handleResticExitError(err error, failureErr error) error { var exitErr *exec.ExitError if errors.As(err, &exitErr) { if exitErr.ExitCode() == 3 { return ErrPartialBackup - } else { - return fmt.Errorf("exit code %d: %w", exitErr.ExitCode(), cr.failureErr) } + return fmt.Errorf("exit code %d: %w", exitErr.ExitCode(), failureErr) } return err } -func (cr *cmdRunnerWithProgress[T]) Run(ctx context.Context, args []string, opts ...GenericOption) (T, error) { +func runCommandWithProgress[T ProgressEntryValidator](ctx context.Context, r *Repo, args []string, callback func(T), failureErr error, opts ...GenericOption) (T, error) { logger := LoggerFromContext(ctx) cmdCtx, cancel := context.WithCancel(ctx) defer cancel() cmdCtx = ContextWithLogger(cmdCtx, nil) // ensure no logger is used - cmd := cr.repo.commandWithContext(cmdCtx, args, opts...) + cmd := r.commandWithContext(cmdCtx, args, opts...) // Ensure the command is logged since we're overriding the logger if logger != nil { fmt.Fprintf(logger, "command: %q\n", cmd) + } else { + logger = io.Discard } - buf := buffer.New(32 * 1024) // 32KB IO buffer for the realtime event parsing + buf := buffer.New(8 * 1024) // 8KB IO buffer for the realtime event parsing reader, writer := nio.Pipe(buf) - cr.repo.pipeCmdOutputToWriter(cmd, writer) + r.handleOutput(cmd, withAllTo(writer)) var readErr error var summary T @@ -247,7 +284,7 @@ func (cr *cmdRunnerWithProgress[T]) Run(ctx context.Context, args []string, opts wg.Add(1) go func() { defer wg.Done() - result, err := processProgressOutput[T](reader, logger, cr.callback) + result, err := processProgressOutput[T](reader, logger, callback) summary = result if err != nil { readErr = fmt.Errorf("output processing: %w", err) @@ -260,9 +297,9 @@ func (cr *cmdRunnerWithProgress[T]) Run(ctx context.Context, args []string, opts if cmdErr != nil || readErr != nil { if cmdErr != nil { - cmdErr = cr.handleExitError(cmdErr) + cmdErr = handleResticExitError(cmdErr, failureErr) } - return summary, newCmdError(ctx, cmd, errors.Join(cmdErr, readErr)) + return summary, newCmdError(cmd, errors.Join(cmdErr, readErr)) } return summary, nil @@ -279,27 +316,18 @@ func (r *Repo) Backup(ctx context.Context, paths []string, progressCallback func args = append(args, paths...) opts = append(slices.Clone(opts), WithEnv("RESTIC_PROGRESS_FPS=2")) - cr := cmdRunnerWithProgress[*BackupProgressEntry]{ - repo: r, - callback: progressCallback, - failureErr: ErrBackupFailed, - } - return cr.Run(ctx, args, opts...) + return runCommandWithProgress(ctx, r, args, progressCallback, ErrBackupFailed, opts...) } func (r *Repo) Restore(ctx context.Context, snapshot string, callback func(*RestoreProgressEntry), opts ...GenericOption) (*RestoreProgressEntry, error) { opts = append(slices.Clone(opts), WithEnv("RESTIC_PROGRESS_FPS=2")) args := []string{"restore", "--json", snapshot} - cr := cmdRunnerWithProgress[*RestoreProgressEntry]{ - repo: r, - callback: callback, - failureErr: ErrRestoreFailed, - } - return cr.Run(ctx, args, opts...) + return runCommandWithProgress(ctx, r, args, callback, ErrRestoreFailed, opts...) } func (r *Repo) Snapshots(ctx context.Context, opts ...GenericOption) ([]*Snapshot, error) { + var snapshots []*Snapshot if err := r.executeWithJSONOutput(ctx, []string{"snapshots", "--json"}, &snapshots, opts...); err != nil { return nil, err @@ -335,8 +363,13 @@ func (r *Repo) Forget(ctx context.Context, policy *RetentionPolicy, opts ...Gene func (r *Repo) ForgetSnapshot(ctx context.Context, snapshotId string, opts ...GenericOption) error { args := []string{"forget", "--json", snapshotId} - _, err := r.executeWithOutput(ctx, args, opts...) - return err + cmd := r.commandWithContext(ctx, args, opts...) + errorCollector := errorMessageCollector{} + r.handleOutput(cmd, withAllTo(&errorCollector), withLogWriterFromContext(ctx)) + if err := cmd.Run(); err != nil { + return errorCollector.AddCmdOutputToError(cmd, err) + } + return nil } func (r *Repo) Prune(ctx context.Context, pruneOutput io.Writer, opts ...GenericOption) error { @@ -344,24 +377,18 @@ func (r *Repo) Prune(ctx context.Context, pruneOutput io.Writer, opts ...Generic } func (r *Repo) Check(ctx context.Context, checkOutput io.Writer, opts ...GenericOption) error { - cmd := r.commandWithContext(ctx, []string{"check"}, opts...) - if checkOutput != nil { - r.pipeCmdOutputToWriter(cmd, checkOutput) - } - if err := cmd.Run(); err != nil { - return newCmdError(ctx, cmd, err) - } - return nil + return r.runSimpleCommand(ctx, []string{"check"}, checkOutput, opts...) } // runSimpleCommand executes a command with optional output capture func (r *Repo) runSimpleCommand(ctx context.Context, args []string, outputWriter io.Writer, opts ...GenericOption) error { cmd := r.commandWithContext(ctx, args, opts...) + errorCollector := errorMessageCollector{} if outputWriter != nil { - r.pipeCmdOutputToWriter(cmd, outputWriter) + r.handleOutput(cmd, withStdOutTo(outputWriter), withAllTo(&errorCollector), withLogWriterFromContext(ctx)) } if err := cmd.Run(); err != nil { - return newCmdError(ctx, cmd, err) + return errorCollector.AddCmdOutputToError(cmd, err) } return nil } @@ -373,22 +400,28 @@ func (r *Repo) ListDirectory(ctx context.Context, snapshot string, path string, } cmd := r.commandWithContext(ctx, []string{"ls", "--json", snapshot, path}, opts...) + errorCollector := errorMessageCollector{} output := bytes.NewBuffer(nil) - r.pipeCmdOutputToWriter(cmd, output) + r.handleOutput(cmd, withStdOutTo(output), withAllTo(&errorCollector), withLogWriterFromContext(ctx)) if err := cmd.Run(); err != nil { - return nil, nil, newCmdError(ctx, cmd, newErrorWithOutput(err, output.String())) + return nil, nil, errorCollector.AddCmdOutputToError(cmd, fmt.Errorf("error running command: %w", err)) } snap, entries, err := readLs(output) if err != nil { - return nil, nil, newCmdError(ctx, cmd, fmt.Errorf("error parsing JSON: %w", err)) + return nil, nil, errorCollector.AddCmdOutputToError(cmd, fmt.Errorf("error parsing JSON: %w", err)) } return snap, entries, nil } func (r *Repo) Unlock(ctx context.Context, opts ...GenericOption) error { - _, err := r.executeWithOutput(ctx, []string{"unlock"}, opts...) - return err + errorCollector := errorMessageCollector{} + cmd := r.commandWithContext(ctx, []string{"unlock"}, opts...) + r.handleOutput(cmd, withAllTo(&errorCollector), withLogWriterFromContext(ctx)) + if err := cmd.Run(); err != nil { + return errorCollector.AddCmdOutputToError(cmd, err) + } + return nil } func (r *Repo) Stats(ctx context.Context, opts ...GenericOption) (*RepoStats, error) { @@ -406,12 +439,18 @@ func (r *Repo) AddTags(ctx context.Context, snapshotIDs []string, tags []string, args = append(args, "--add", strings.Join(tags, ",")) args = append(args, snapshotIDs...) - _, err := r.executeWithOutput(ctx, args, opts...) - return err + errorCollector := errorMessageCollector{} + cmd := r.commandWithContext(ctx, args, opts...) + r.handleOutput(cmd, withAllTo(&errorCollector), withLogWriterFromContext(ctx)) + if err := cmd.Run(); err != nil { + return errorCollector.AddCmdOutputToError(cmd, err) + } + return nil } func (r *Repo) GenericCommand(ctx context.Context, args []string, opts ...GenericOption) error { cmd := r.commandWithContext(ctx, args, opts...) + r.handleOutput(cmd, withLogWriterFromContext(ctx)) if err := cmd.Run(); err != nil { return err } diff --git a/pkg/restic/restic_test.go b/pkg/restic/restic_test.go index a113512b..7faaefad 100644 --- a/pkg/restic/restic_test.go +++ b/pkg/restic/restic_test.go @@ -638,62 +638,76 @@ func TestResticExitError(t *testing.T) { } } -func TestJSONCommandResilantToBeginningWarnings(t *testing.T) { +func TestJSONCommand(t *testing.T) { t.Parallel() if runtime.GOOS == "windows" { t.Skip("this test is designed to run on Linux, as it uses bash") } - r := NewRepo("bash", "") - var result struct { - Foo string `json:"foo"` - } - if err := r.executeWithJSONOutput(context.Background(), []string{"-c", "echo 'warning: this is a warning' >&2; echo '{\"foo\": \"bar\"}';"}, &result); err != nil { - t.Fatalf("expected command to succeed, got error: %v", err) + tests := []struct { + name string + command string + expectedResult string + expectError bool + errorContains string + }{ + { + name: "resilient to beginning prints", + command: "echo 'warning: this is a warning' >&1; echo '{\"foo\": \"bar\"}';", + expectedResult: "bar", + expectError: false, + }, + { + name: "resilient to beginning warnings", + command: "echo 'warning: this is a warning' >&2; echo '{\"foo\": \"bar\"}';", + expectedResult: "bar", + expectError: false, + }, + { + name: "fails with prints after JSON", + command: "echo '{\"foo\": \"bar\"}'; echo 'warning: this is a warning' >&1;", + expectError: true, + errorContains: "command output is not valid JSON", + }, + { + name: "succeeds with warnings after JSON", + command: "echo '{\"foo\": \"bar\"}'; echo 'warning: this is a warning' >&2;", + expectError: false, + expectedResult: "bar", + }, + { + name: "fails if no valid JSON", + command: "echo 'not really any valid\njson here\n'", + expectError: true, + errorContains: "command output is not valid JSON", + }, } - if result.Foo != "bar" { - t.Errorf("expected foo to be 'bar', got: %s", result.Foo) - } -} + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + r := NewRepo("bash", "") + var result struct { + Foo string `json:"foo"` + } + err := r.executeWithJSONOutput(context.Background(), []string{"-c", tc.command}, &result) -func TestJSONCommandFailsWithWarningsAtEnd(t *testing.T) { - t.Parallel() - if runtime.GOOS == "windows" { - t.Skip("this test is designed to run on Linux, as it uses bash") - } - - r := NewRepo("bash", "") - var result struct { - Foo string `json:"foo"` - } - err := r.executeWithJSONOutput(context.Background(), []string{"-c", "echo '{\"foo\": \"bar\"}'; echo 'warning: this is a warning' >&2;"}, &result) - if err == nil { - t.Fatal("expected command to fail with warnings after JSON output, but it succeeded") - } - - if !strings.Contains(err.Error(), "command output is not valid JSON") { - t.Errorf("expected error to contain 'command output is not valid JSON', got: %v", err) - } -} - -func TestJSONCommandFailsIfNoValidJSON(t *testing.T) { - t.Parallel() - if runtime.GOOS == "windows" { - t.Skip("this test is designed to run on Linux, as it uses bash") - } - - r := NewRepo("bash", "") - var result struct { - Foo string `json:"foo"` - } - err := r.executeWithJSONOutput(context.Background(), []string{"-c", "echo 'not really any valid\njson here\n'"}, &result) - if err == nil { - t.Fatal("expected command to fail with empty JSON output, but it succeeded") - } - - if !strings.Contains(err.Error(), "command output is not valid JSON") { - t.Errorf("expected error to contain 'command output is not valid JSON', got: %v", err) + if tc.expectError { + if err == nil { + t.Fatal("expected command to fail, but it succeeded") + } + if !strings.Contains(err.Error(), tc.errorContains) { + t.Errorf("expected error to contain '%s', got: %v", tc.errorContains, err) + } + } else { + if err != nil { + t.Fatalf("expected command to succeed, got error: %v", err) + } + if result.Foo != tc.expectedResult { + t.Errorf("expected foo to be '%s', got: '%s'", tc.expectedResult, result.Foo) + } + } + }) } }