fix: restic cli commands through 'run command' are cancelled when clo…

…sing dialogue
garethgeorge · Aug 26, 2024 · bb00afa · bb00afa
1 parent 79cae5b
commit bb00afa
Show file tree

Hide file tree

Showing 4 changed files with 48 additions and 22 deletions.
diff --git a/internal/api/backresthandler.go b/internal/api/backresthandler.go
@@ -439,10 +439,14 @@ func (s *BackrestHandler) RunCommand(ctx context.Context, req *connect.Request[v
 	errChan := make(chan error, 1)
 	go func() {
 		start := time.Now()
+		zap.S().Infof("running command for webui: %v", req.Msg.Command)
 		if err := repo.RunCommand(ctx, req.Msg.Command, func(output []byte) {
 			outputs <- bytes.Clone(output)
-		}); err != nil {
+		}); err != nil && ctx.Err() == nil {
+			zap.S().Errorf("error running command for webui: %v", err)
 			errChan <- err
+		} else {
+			zap.S().Infof("command completed for webui: %v", time.Since(start))
 		}
 		outputs <- []byte("took " + time.Since(start).String())
 		cancel()

diff --git a/internal/orchestrator/repo/repo.go b/internal/orchestrator/repo/repo.go
@@ -12,6 +12,7 @@ import (
 	"time"
 
 	v1 "github.com/garethgeorge/backrest/gen/go/v1"
+	"github.com/garethgeorge/backrest/internal/orchestrator/logging"
 	"github.com/garethgeorge/backrest/internal/protoutil"
 	"github.com/garethgeorge/backrest/pkg/restic"
 	"github.com/google/shlex"
@@ -23,7 +24,6 @@ import (
 type RepoOrchestrator struct {
 	mu sync.Mutex
 
-	l          *zap.Logger
 	config     *v1.Config
 	repoConfig *v1.Repo
 	repo       *restic.Repo
@@ -76,10 +76,13 @@ func NewRepoOrchestrator(config *v1.Config, repoConfig *v1.Repo, resticPath stri
 		config:     config,
 		repoConfig: repoConfig,
 		repo:       repo,
-		l:          zap.L().With(zap.String("repo", repoConfig.Id)),
 	}, nil
 }
 
+func (r *RepoOrchestrator) logger(ctx context.Context) *zap.Logger {
+	return logging.Logger(ctx).With(zap.String("repo", r.repoConfig.Id))
+}
+
 func (r *RepoOrchestrator) Init(ctx context.Context) error {
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
@@ -117,7 +120,8 @@ func (r *RepoOrchestrator) SnapshotsForPlan(ctx context.Context, plan *v1.Plan)
 }
 
 func (r *RepoOrchestrator) Backup(ctx context.Context, plan *v1.Plan, progressCallback func(event *restic.BackupProgressEntry)) (*restic.BackupProgressEntry, error) {
-	zap.L().Debug("repo orchestrator starting backup", zap.String("repo", r.repoConfig.Id))
+	l := r.logger(ctx)
+	l.Debug("repo orchestrator starting backup", zap.String("repo", r.repoConfig.Id))
 
 	r.mu.Lock()
 	defer r.mu.Unlock()
@@ -127,7 +131,7 @@ func (r *RepoOrchestrator) Backup(ctx context.Context, plan *v1.Plan, progressCa
 		return nil, fmt.Errorf("failed to get snapshots for plan: %w", err)
 	}
 
-	r.l.Debug("got snapshots for plan", zap.String("repo", r.repoConfig.Id), zap.Int("count", len(snapshots)), zap.String("plan", plan.Id), zap.String("tag", TagForPlan(plan.Id)))
+	l.Debug("got snapshots for plan", zap.String("repo", r.repoConfig.Id), zap.Int("count", len(snapshots)), zap.String("plan", plan.Id), zap.String("tag", TagForPlan(plan.Id)))
 
 	startTime := time.Now()
 
@@ -163,13 +167,13 @@ func (r *RepoOrchestrator) Backup(ctx context.Context, plan *v1.Plan, progressCa
 
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
-	r.l.Debug("starting backup", zap.String("repo", r.repoConfig.Id), zap.String("plan", plan.Id))
+	l.Debug("starting backup", zap.String("repo", r.repoConfig.Id), zap.String("plan", plan.Id))
 	summary, err := r.repo.Backup(ctx, plan.Paths, progressCallback, opts...)
 	if err != nil {
 		return summary, fmt.Errorf("failed to backup: %w", err)
 	}
 
-	r.l.Debug("backup completed", zap.String("repo", r.repoConfig.Id), zap.Duration("duration", time.Since(startTime)))
+	l.Debug("backup completed", zap.String("repo", r.repoConfig.Id), zap.Duration("duration", time.Since(startTime)))
 	return summary, nil
 }
 
@@ -219,7 +223,7 @@ func (r *RepoOrchestrator) Forget(ctx context.Context, plan *v1.Plan, tags []str
 		forgotten = append(forgotten, snapshotProto)
 	}
 
-	zap.L().Debug("forget snapshots", zap.String("plan", plan.Id), zap.Int("count", len(forgotten)), zap.Any("policy", policy))
+	r.logger(ctx).Debug("forget snapshots", zap.String("plan", plan.Id), zap.Int("count", len(forgotten)), zap.Any("policy", policy))
 
 	return forgotten, nil
 }
@@ -230,7 +234,7 @@ func (r *RepoOrchestrator) ForgetSnapshot(ctx context.Context, snapshotId string
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
 
-	r.l.Debug("forget snapshot with ID", zap.String("snapshot", snapshotId), zap.String("repo", r.repoConfig.Id))
+	r.logger(ctx).Debug("forget snapshot with ID", zap.String("snapshot", snapshotId), zap.String("repo", r.repoConfig.Id))
 	return r.repo.ForgetSnapshot(ctx, snapshotId)
 }
 
@@ -254,7 +258,7 @@ func (r *RepoOrchestrator) Prune(ctx context.Context, output io.Writer) error {
 		opts = append(opts, restic.WithFlags("--max-unused", fmt.Sprintf("%v%%", policy.MaxUnusedPercent)))
 	}
 
-	r.l.Debug("prune snapshots")
+	r.logger(ctx).Debug("prune snapshots")
 	err := r.repo.Prune(ctx, output, opts...)
 	if err != nil {
 		return fmt.Errorf("prune snapshots for repo %v: %w", r.repoConfig.Id, err)
@@ -280,7 +284,7 @@ func (r *RepoOrchestrator) Check(ctx context.Context, output io.Writer) error {
 		}
 	}
 
-	r.l.Debug("checking repo")
+	r.logger(ctx).Debug("checking repo")
 	err := r.repo.Check(ctx, output, opts...)
 	if err != nil {
 		return fmt.Errorf("check repo %v: %w", r.repoConfig.Id, err)
@@ -294,7 +298,7 @@ func (r *RepoOrchestrator) Restore(ctx context.Context, snapshotId string, path
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
 
-	r.l.Debug("restore snapshot", zap.String("snapshot", snapshotId), zap.String("target", target))
+	r.logger(ctx).Debug("restore snapshot", zap.String("snapshot", snapshotId), zap.String("target", target))
 
 	var opts []restic.GenericOption
 	opts = append(opts, restic.WithFlags("--target", target))
@@ -324,7 +328,7 @@ func (r *RepoOrchestrator) UnlockIfAutoEnabled(ctx context.Context) error {
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
 
-	zap.L().Debug("auto-unlocking repo", zap.String("repo", r.repoConfig.Id))
+	r.logger(ctx).Debug("auto-unlocking repo", zap.String("repo", r.repoConfig.Id))
 
 	return r.repo.Unlock(ctx)
 }
@@ -333,7 +337,7 @@ func (r *RepoOrchestrator) Unlock(ctx context.Context) error {
 	r.mu.Lock()
 	defer r.mu.Unlock()
 
-	r.l.Debug("unlocking repo", zap.String("repo", r.repoConfig.Id))
+	r.logger(ctx).Debug("unlocking repo", zap.String("repo", r.repoConfig.Id))
 	r.repo.Unlock(ctx)
 
 	return nil
@@ -345,7 +349,7 @@ func (r *RepoOrchestrator) Stats(ctx context.Context) (*v1.RepoStats, error) {
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
 
-	r.l.Debug("getting repo stats", zap.String("repo", r.repoConfig.Id))
+	r.logger(ctx).Debug("getting repo stats", zap.String("repo", r.repoConfig.Id))
 	stats, err := r.repo.Stats(ctx)
 	if err != nil {
 		return nil, fmt.Errorf("stats for repo %v: %w", r.repoConfig.Id, err)
@@ -361,7 +365,7 @@ func (r *RepoOrchestrator) AddTags(ctx context.Context, snapshotIDs []string, ta
 	defer flush()
 
 	for idx, snapshotIDs := range chunkBy(snapshotIDs, 20) {
-		r.l.Debug("adding tag to snapshots", zap.Strings("snapshots", snapshotIDs), zap.Strings("tags", tags))
+		r.logger(ctx).Debug("adding tag to snapshots", zap.Strings("snapshots", snapshotIDs), zap.Strings("tags", tags))
 		if err := r.repo.AddTags(ctx, snapshotIDs, tags); err != nil {
 			return fmt.Errorf("batch %v: %w", idx, err)
 		}
@@ -377,7 +381,7 @@ func (r *RepoOrchestrator) RunCommand(ctx context.Context, command string, onPro
 	ctx, flush := forwardResticLogs(ctx)
 	defer flush()
 
-	r.l.Debug("running command", zap.String("command", command))
+	r.logger(ctx).Debug("running command", zap.String("command", command))
 	args, err := shlex.Split(command)
 	if err != nil {
 		return fmt.Errorf("parse command: %w", err)

diff --git a/webui/src/components/ActivityBar.tsx b/webui/src/components/ActivityBar.tsx
@@ -67,7 +67,7 @@ export const ActivityBar = () => {
         return (
           <span key={idx}>
             {displayName} in progress for plan {op.planId} to {op.repoId} for{" "}
-            {formatDuration(Number(op.unixTimeStartMs - op.unixTimeEndMs))}
+            {formatDuration(Number(op.unixTimeEndMs - op.unixTimeStartMs))}
           </span>
         );
       })}

diff --git a/webui/src/views/RunCommandModal.tsx b/webui/src/views/RunCommandModal.tsx
@@ -4,6 +4,7 @@ import { useShowModal } from "../components/ModalManager";
 import { backrestService } from "../api";
 import { SpinButton } from "../components/SpinButton";
 import { ConnectError } from "@connectrpc/connect";
+import { useAlertApi } from "../components/Alerts";
 
 interface Invocation {
   command: string;
@@ -13,11 +14,19 @@ interface Invocation {
 
 export const RunCommandModal = ({ repoId }: { repoId: string }) => {
   const showModal = useShowModal();
+  const alertApi = useAlertApi()!;
   const [command, setCommand] = React.useState("");
   const [running, setRunning] = React.useState(false);
   const [invocations, setInvocations] = React.useState<Invocation[]>([]);
+  const [abortController, setAbortController] = React.useState<
+    AbortController | undefined
+  >();
 
   const handleCancel = () => {
+    if (abortController) {
+      alertApi.warning("In-progress restic command was aborted");
+      abortController.abort();
+    }
     showModal(null);
   };
 
@@ -31,10 +40,18 @@ export const RunCommandModal = ({ repoId }: { repoId: string }) => {
     let segments: string[] = [];
 
     try {
-      for await (const bytes of backrestService.runCommand({
-        repoId,
-        command,
-      })) {
+      const abortController = new AbortController();
+      setAbortController(abortController);
+
+      for await (const bytes of backrestService.runCommand(
+        {
+          repoId,
+          command,
+        },
+        {
+          signal: abortController.signal,
+        }
+      )) {
         const output = new TextDecoder("utf-8").decode(bytes.value);
         segments.push(output);
         setInvocations((invocations) => {
@@ -57,6 +74,7 @@ export const RunCommandModal = ({ repoId }: { repoId: string }) => {
       });
     } finally {
       setRunning(false);
+      setAbortController(undefined);
     }
   };