replication/driver: fs.debug() helper that automatically prefixes with fs name

refs #140
refs #302

.circleci/config.yml

@@ -92,21 +92,11 @@ jobs:
             REPO="zrepl/zrepl"
             COMMIT="${CIRCLE_SHA1}"
             JOB_NAME="${CIRCLE_JOB}"
-            curl "https://api.github.com/repos/$REPO/statuses/$COMMIT" \
+            curl "https://api.github.com/repos/$REPO/statuses/$COMMIT?access_token=$GITHUB_COMMIT_STATUS_TOKEN" \
               -H "Content-Type: application/json" \
-              -H "Authorization: token $GITHUB_COMMIT_STATUS_TOKEN" \
               -X POST \
               -d '{"context":"zrepl/publish-ci-artifacts", "state": "success", "description":"CI Build Artifacts for '"$JOB_NAME"'", "target_url":"https://minio.cschwarz.com/minio/zrepl-ci-artifacts/'"$COMMIT"'/"}'
 
-      - run:
-          shell: /bin/bash -euo pipefail
-          command: |
-            # Trigger Debian Package Build
-            curl -v -X POST https://api.github.com/repos/zrepl/debian-binary-packaging/dispatches \
-              -H 'Accept: application/vnd.github.v3+json' \
-              -H "Authorization: token $ZREPL_DEBIAN_BINARYPACKAGIN_TRIGGER_BUILD_GITHUB_TOKEN" \
-              --data '{"event_type": "push", "client_payload": { "zrepl_main_repo_commit": "'"$CIRCLE_SHA1"'", "go_version": "'"${CIRCLE_JOB##build-}"'" }}'
-
   build-1.11:
     <<: *build-latest
     docker:

Makefile

@@ -23,7 +23,8 @@ GOHOSTARCH ?= $(shell bash -c 'source <($(GO) env) && echo "$$GOHOSTARCH"')
 GO_ENV_VARS := GO111MODULE=on
 GO_LDFLAGS := "-X github.com/zrepl/zrepl/version.zreplVersion=$(_ZREPL_VERSION)"
 GO_MOD_READONLY := -mod=readonly
-GO_BUILDFLAGS := $(GO_MOD_READONLY)
+GO_EXTRA_BUILDFLAGS :=
+GO_BUILDFLAGS := $(GO_MOD_READONLY) $(GO_EXTRA_BUILDFLAGS)
 GO_BUILD := $(GO_ENV_VARS) $(GO) build $(GO_BUILDFLAGS) -ldflags $(GO_LDFLAGS)
 GOLANGCI_LINT := golangci-lint
 ifneq ($(GOARM),)
@@ -65,7 +66,6 @@ wrapup-and-checksum:
 		-acf $(NOARCH_TARBALL) \
 		$(ARTIFACTDIR)/docs/html \
 		$(ARTIFACTDIR)/bash_completion \
-		$(ARTIFACTDIR)/_zrepl.zsh_completion \
 		$(ARTIFACTDIR)/go_env.txt \
 		dist \
 		config/samples
@@ -160,7 +160,7 @@ platformtest: # do not track dependency on platformtest-bin to allow build of pl
 		$(ZREPL_PLATFORMTEST_ARGS)
 
 ##################### NOARCH #####################
-.PHONY: noarch $(ARTIFACTDIR)/bash_completion $(ARTIFACTDIR)/_zrepl.zsh_completion $(ARTIFACTDIR)/go_env.txt docs docs-clean
+.PHONY: noarch $(ARTIFACTDIR)/bash_completion $(ARTIFACTDIR)/go_env.txt docs docs-clean
 
 
 $(ARTIFACTDIR):
@@ -168,16 +168,12 @@ $(ARTIFACTDIR):
 $(ARTIFACTDIR)/docs: $(ARTIFACTDIR)
 	mkdir -p "$@"
 
-noarch: $(ARTIFACTDIR)/bash_completion $(ARTIFACTDIR)/_zrepl.zsh_completion $(ARTIFACTDIR)/go_env.txt docs
+noarch: $(ARTIFACTDIR)/bash_completion $(ARTIFACTDIR)/go_env.txt docs
 	# pass
 
 $(ARTIFACTDIR)/bash_completion:
 	$(MAKE) zrepl-bin GOOS=$(GOHOSTOS) GOARCH=$(GOHOSTARCH)
-	artifacts/zrepl-$(GOHOSTOS)-$(GOHOSTARCH) gencompletion bash "$@"
-
-$(ARTIFACTDIR)/_zrepl.zsh_completion:
-	$(MAKE) zrepl-bin GOOS=$(GOHOSTOS) GOARCH=$(GOHOSTARCH)
-	artifacts/zrepl-$(GOHOSTOS)-$(GOHOSTARCH) gencompletion zsh "$@"
+	artifacts/zrepl-$(GOHOSTOS)-$(GOHOSTARCH) bashcomp "$@"
 
 $(ARTIFACTDIR)/go_env.txt:
 	$(GO_ENV_VARS) $(GO) env > $@

cli/cli.go

@@ -19,55 +19,29 @@ var rootCmd = &cobra.Command{
 	Short: "One-stop ZFS replication solution",
 }
 
-func init() {
-	rootCmd.PersistentFlags().StringVar(&rootArgs.configPath, "config", "", "config file path")
-}
-
-var genCompletionCmd = &cobra.Command{
-	Use:   "gencompletion",
-	Short: "generate shell auto-completions",
-}
-
-type completionCmdInfo struct {
-	genFunc func(outpath string) error
-	help    string
-}
-
-var completionCmdMap = map[string]completionCmdInfo{
-	"zsh": {
-		rootCmd.GenZshCompletionFile,
-		"  save to file `_zrepl` in your zsh's $fpath",
-	},
-	"bash": {
-		rootCmd.GenBashCompletionFile,
-		"  save to a path and source that path in your .bashrc",
+var bashcompCmd = &cobra.Command{
+	Use:   "bashcomp path/to/out/file",
+	Short: "generate bash completions",
+	Run: func(cmd *cobra.Command, args []string) {
+		if len(args) != 1 {
+			fmt.Fprintf(os.Stderr, "specify exactly one positional agument\n")
+			err := cmd.Usage()
+			if err != nil {
+				panic(err)
+			}
+			os.Exit(1)
+		}
+		if err := rootCmd.GenBashCompletionFile(args[0]); err != nil {
+			fmt.Fprintf(os.Stderr, "error generating bash completion: %s", err)
+			os.Exit(1)
+		}
 	},
+	Hidden: true,
 }
 
 func init() {
-	for sh, info := range completionCmdMap {
-		sh, info := sh, info
-		genCompletionCmd.AddCommand(&cobra.Command{
-			Use:     fmt.Sprintf("%s path/to/out/file", sh),
-			Short:   fmt.Sprintf("generate %s completions", sh),
-			Example: info.help,
-			Run: func(cmd *cobra.Command, args []string) {
-				if len(args) != 1 {
-					fmt.Fprintf(os.Stderr, "specify exactly one positional agument\n")
-					err := cmd.Usage()
-					if err != nil {
-						panic(err)
-					}
-					os.Exit(1)
-				}
-				if err := info.genFunc(args[0]); err != nil {
-					fmt.Fprintf(os.Stderr, "error generating %s completion: %s", sh, err)
-					os.Exit(1)
-				}
-			},
-		})
-	}
-	rootCmd.AddCommand(genCompletionCmd)
+	rootCmd.PersistentFlags().StringVar(&rootArgs.configPath, "config", "", "config file path")
+	rootCmd.AddCommand(bashcompCmd)
 }
 
 type Subcommand struct {

client/hold_create_step_hold.go

@@ -12,28 +12,28 @@ import (
 	"github.com/zrepl/zrepl/zfs"
 )
 
-var zabsCreateStepHoldFlags struct {
+var holdsCreateStepHoldFlags struct {
 	target string
 	jobid  JobIDFlag
 }
 
-var zabsCmdCreateStepHold = &cli.Subcommand{
+var holdsCmdCreateStepHold = &cli.Subcommand{
 	Use:             "step",
-	Run:             doZabsCreateStep,
+	Run:             doHoldsCreateStep,
 	NoRequireConfig: true,
 	Short:           `create a step hold or bookmark`,
 	SetupFlags: func(f *pflag.FlagSet) {
-		f.StringVarP(&zabsCreateStepHoldFlags.target, "target", "t", "", "snapshot to be held / bookmark to be held")
-		f.VarP(&zabsCreateStepHoldFlags.jobid, "jobid", "j", "jobid for which the hold is installed")
+		f.StringVarP(&holdsCreateStepHoldFlags.target, "target", "t", "", "snapshot to be held / bookmark to be held")
+		f.VarP(&holdsCreateStepHoldFlags.jobid, "jobid", "j", "jobid for which the hold is installed")
 	},
 }
 
-func doZabsCreateStep(sc *cli.Subcommand, args []string) error {
+func doHoldsCreateStep(sc *cli.Subcommand, args []string) error {
 	if len(args) > 0 {
 		return errors.New("subcommand takes no arguments")
 	}
 
-	f := &zabsCreateStepHoldFlags
+	f := &holdsCreateStepHoldFlags
 
 	fs, _, _, err := zfs.DecomposeVersionString(f.target)
 	if err != nil {

client/holds.go

@@ -14,15 +14,15 @@ import (
 )
 
 var (
-	ZFSAbstractionsCmd = &cli.Subcommand{
-		Use:   "zfs-abstraction",
-		Short: "manage abstractions that zrepl builds on top of ZFS",
+	HoldsCmd = &cli.Subcommand{
+		Use:   "holds",
+		Short: "manage holds & step bookmarks",
 		SetupSubcommands: func() []*cli.Subcommand {
 			return []*cli.Subcommand{
-				zabsCmdList,
-				zabsCmdReleaseAll,
-				zabsCmdReleaseStale,
-				zabsCmdCreate,
+				holdsCmdList,
+				holdsCmdReleaseAll,
+				holdsCmdReleaseStale,
+				holdsCmdCreate,
 			}
 		},
 	}
@@ -30,7 +30,7 @@ var (
 
 // a common set of CLI flags that map to the fields of an
 // endpoint.ListZFSHoldsAndBookmarksQuery
-type zabsFilterFlags struct {
+type holdsFilterFlags struct {
 	Filesystems FilesystemsFilterFlag
 	Job         JobIDFlag
 	Types       AbstractionTypesFlag
@@ -38,7 +38,7 @@ type zabsFilterFlags struct {
 }
 
 // produce a query from the CLI flags
-func (f zabsFilterFlags) Query() (endpoint.ListZFSHoldsAndBookmarksQuery, error) {
+func (f holdsFilterFlags) Query() (endpoint.ListZFSHoldsAndBookmarksQuery, error) {
 	q := endpoint.ListZFSHoldsAndBookmarksQuery{
 		FS:          f.Filesystems.FlagValue(),
 		What:        f.Types.FlagValue(),
@@ -48,7 +48,7 @@ func (f zabsFilterFlags) Query() (endpoint.ListZFSHoldsAndBookmarksQuery, error)
 	return q, q.Validate()
 }
 
-func (f *zabsFilterFlags) registerZabsFilterFlags(s *pflag.FlagSet, verb string) {
+func (f *holdsFilterFlags) registerHoldsFilterFlags(s *pflag.FlagSet, verb string) {
 	// Note: the default value is defined in the .FlagValue methods
 	s.Var(&f.Filesystems, "fs", fmt.Sprintf("only %s holds on the specified filesystem [default: all filesystems] [comma-separated list of <dataset-pattern>:<ok|!> pairs]", verb))
 	s.Var(&f.Job, "job", fmt.Sprintf("only %s holds created by the specified job [default: any job]", verb))

client/holds_create.go

@@ -0,0 +1,14 @@
+package client
+
+import "github.com/zrepl/zrepl/cli"
+
+var holdsCmdCreate = &cli.Subcommand{
+	Use:             "create",
+	NoRequireConfig: true,
+	Short:           `create zrepl-managed holds and boomkmarks (for debugging & development only!)`,
+	SetupSubcommands: func() []*cli.Subcommand {
+		return []*cli.Subcommand{
+			holdsCmdCreateStepHold,
+		}
+	},
+}

client/holds_list.go

@@ -16,23 +16,23 @@ import (
 	"github.com/zrepl/zrepl/util/chainlock"
 )
 
-var zabsListFlags struct {
-	Filter zabsFilterFlags
+var holdsListFlags struct {
+	Filter holdsFilterFlags
 	Json   bool
 }
 
-var zabsCmdList = &cli.Subcommand{
+var holdsCmdList = &cli.Subcommand{
 	Use:             "list",
-	Short:           `list zrepl ZFS abstractions`,
-	Run:             doZabsList,
+	Run:             doHoldsList,
 	NoRequireConfig: true,
+	Short:           "list holds and bookmarks",
 	SetupFlags: func(f *pflag.FlagSet) {
-		zabsListFlags.Filter.registerZabsFilterFlags(f, "list")
-		f.BoolVar(&zabsListFlags.Json, "json", false, "emit JSON")
+		holdsListFlags.Filter.registerHoldsFilterFlags(f, "list")
+		f.BoolVar(&holdsListFlags.Json, "json", false, "emit JSON")
 	},
 }
 
-func doZabsList(sc *cli.Subcommand, args []string) error {
+func doHoldsList(sc *cli.Subcommand, args []string) error {
 	var err error
 	ctx := context.Background()
 
@@ -40,7 +40,7 @@ func doZabsList(sc *cli.Subcommand, args []string) error {
 		return errors.New("this subcommand takes no positional arguments")
 	}
 
-	q, err := zabsListFlags.Filter.Query()
+	q, err := holdsListFlags.Filter.Query()
 	if err != nil {
 		return errors.Wrap(err, "invalid filter specification on command line")
 	}
@@ -62,7 +62,7 @@ func doZabsList(sc *cli.Subcommand, args []string) error {
 		for a := range abstractions {
 			func() {
 				defer line.Lock().Unlock()
-				if zabsListFlags.Json {
+				if holdsListFlags.Json {
 					enc.SetIndent("", "  ")
 					if err := enc.Encode(abstractions); err != nil {
 						panic(err)

client/holds_release.go

@@ -15,35 +15,35 @@ import (
 )
 
 // shared between release-all and release-step
-var zabsReleaseFlags struct {
-	Filter zabsFilterFlags
+var holdsReleaseFlags struct {
+	Filter holdsFilterFlags
 	Json   bool
 	DryRun bool
 }
 
-func registerZabsReleaseFlags(s *pflag.FlagSet) {
-	zabsReleaseFlags.Filter.registerZabsFilterFlags(s, "release")
-	s.BoolVar(&zabsReleaseFlags.Json, "json", false, "emit json instead of pretty-printed")
-	s.BoolVar(&zabsReleaseFlags.DryRun, "dry-run", false, "do a dry-run")
+func registerHoldsReleaseFlags(s *pflag.FlagSet) {
+	holdsReleaseFlags.Filter.registerHoldsFilterFlags(s, "release")
+	s.BoolVar(&holdsReleaseFlags.Json, "json", false, "emit json instead of pretty-printed")
+	s.BoolVar(&holdsReleaseFlags.DryRun, "dry-run", false, "do a dry-run")
 }
 
-var zabsCmdReleaseAll = &cli.Subcommand{
+var holdsCmdReleaseAll = &cli.Subcommand{
 	Use:             "release-all",
-	Run:             doZabsReleaseAll,
+	Run:             doHoldsReleaseAll,
 	NoRequireConfig: true,
-	Short:           `(DANGEROUS) release ALL zrepl ZFS abstractions (mostly useful for uninstalling zrepl completely or for "de-zrepl-ing" a filesystem)`,
-	SetupFlags:      registerZabsReleaseFlags,
+	Short:           `(DANGEROUS) release all zrepl-managed holds and bookmarks, mostly useful for uninstalling zrepl`,
+	SetupFlags:      registerHoldsReleaseFlags,
 }
 
-var zabsCmdReleaseStale = &cli.Subcommand{
+var holdsCmdReleaseStale = &cli.Subcommand{
 	Use:             "release-stale",
-	Run:             doZabsReleaseStale,
+	Run:             doHoldsReleaseStale,
 	NoRequireConfig: true,
-	Short:           `release stale zrepl ZFS abstractions (useful if zrepl has a bug and does not do it by itself)`,
-	SetupFlags:      registerZabsReleaseFlags,
+	Short:           `release stale zrepl-managed holds and boomkarks (useful if zrepl has a bug and doesn't do it by itself)`,
+	SetupFlags:      registerHoldsReleaseFlags,
 }
 
-func doZabsReleaseAll(sc *cli.Subcommand, args []string) error {
+func doHoldsReleaseAll(sc *cli.Subcommand, args []string) error {
 	var err error
 	ctx := context.Background()
 
@@ -51,7 +51,7 @@ func doZabsReleaseAll(sc *cli.Subcommand, args []string) error {
 		return errors.New("this subcommand takes no positional arguments")
 	}
 
-	q, err := zabsReleaseFlags.Filter.Query()
+	q, err := holdsReleaseFlags.Filter.Query()
 	if err != nil {
 		return errors.Wrap(err, "invalid filter specification on command line")
 	}
@@ -65,10 +65,10 @@ func doZabsReleaseAll(sc *cli.Subcommand, args []string) error {
 		// proceed anyways with rest of abstractions
 	}
 
-	return doZabsRelease_Common(ctx, abstractions)
+	return doHoldsRelease_Common(ctx, abstractions)
 }
 
-func doZabsReleaseStale(sc *cli.Subcommand, args []string) error {
+func doHoldsReleaseStale(sc *cli.Subcommand, args []string) error {
 
 	var err error
 	ctx := context.Background()
@@ -77,7 +77,7 @@ func doZabsReleaseStale(sc *cli.Subcommand, args []string) error {
 		return errors.New("this subcommand takes no positional arguments")
 	}
 
-	q, err := zabsReleaseFlags.Filter.Query()
+	q, err := holdsReleaseFlags.Filter.Query()
 	if err != nil {
 		return errors.Wrap(err, "invalid filter specification on command line")
 	}
@@ -87,13 +87,13 @@ func doZabsReleaseStale(sc *cli.Subcommand, args []string) error {
 		return err // context clear by invocation of command
 	}
 
-	return doZabsRelease_Common(ctx, stalenessInfo.Stale)
+	return doHoldsRelease_Common(ctx, stalenessInfo.Stale)
 }
 
-func doZabsRelease_Common(ctx context.Context, destroy []endpoint.Abstraction) error {
+func doHoldsRelease_Common(ctx context.Context, destroy []endpoint.Abstraction) error {
 
-	if zabsReleaseFlags.DryRun {
-		if zabsReleaseFlags.Json {
+	if holdsReleaseFlags.DryRun {
+		if holdsReleaseFlags.Json {
 			m, err := json.MarshalIndent(destroy, "", "  ")
 			if err != nil {
 				panic(err)
@@ -121,7 +121,7 @@ func doZabsRelease_Common(ctx context.Context, destroy []endpoint.Abstraction) e
 
 	for res := range outcome {
 		hadErr = hadErr || res.DestroyErr != nil
-		if zabsReleaseFlags.Json {
+		if holdsReleaseFlags.Json {
 			err := enc.Encode(res)
 			if err != nil {
 				colorErr.Fprintf(os.Stderr, "cannot marshal there were errors in destroying the abstractions")

client/zfsabstractions_create.go

@@ -1,14 +0,0 @@
-package client
-
-import "github.com/zrepl/zrepl/cli"
-
-var zabsCmdCreate = &cli.Subcommand{
-	Use:             "create",
-	NoRequireConfig: true,
-	Short:           `create zrepl ZFS abstractions (mostly useful for debugging & development, users should not need to use this command)`,
-	SetupSubcommands: func() []*cli.Subcommand {
-		return []*cli.Subcommand{
-			zabsCmdCreateStepHold,
-		}
-	},
-}

docs/changelog.rst

@@ -62,9 +62,7 @@ Actual changelog:
 * |bugfix| |docs| snapshotting: clarify sync-up behavior and warn about filesystems
   that will not be snapshotted until the sync-up phase is over
 * |docs| Document new replication features in the :ref:`config overview <overview-how-replication-works>` and :repomasterlink:`replication/design.md`.
-* |feature| documented subcommand to generate ``bash`` and ``zsh`` completions
 * **[MAINTAINER NOTICE]** New platform tests in this version, please make sure you run them for your distro!
-* **[MAINTAINER NOTICE]** Please add the shell completions to the zrepl packages.
 
 0.2.1
 -----

docs/usage.rst

@@ -38,8 +38,8 @@ CLI Overview
     * - ``zrepl migrate``
       - | perform on-disk state / ZFS property migrations
         | (see :ref:`changelog <changelog>` for details)
-    * - ``zrepl zfs-abstractions``
-      - list and remove zrepl's abstractions on top of ZFS, e.g. holds and step bookmarks (see :ref:`overview <replication-cursor-and-last-received-hold>` )
+    * - ``zrepl holds``
+      - list and remove holds and step bookmarks created by zrepl (see :ref:`overview <replication-cursor-and-last-received-hold>` )
 
 .. _usage-zrepl-daemon:
 

endpoint/endpoint.go

@@ -806,7 +806,7 @@ func (s *Receiver) Receive(ctx context.Context, req *pdu.ReceiveReq, receive zfs
 	if err := zfs.ZFSRecv(ctx, lp.ToString(), to, receive, recvOpts); err != nil {
 		getLogger(ctx).
 			WithError(err).
-			WithField("opts", recvOpts).
+			WithField("opts", fmt.Sprintf("%#v", recvOpts)).
 			Error("zfs receive failed")
 		return nil, err
 	}

main.go

@@ -17,7 +17,7 @@ func init() {
 	cli.AddSubcommand(client.PprofCmd)
 	cli.AddSubcommand(client.TestCmd)
 	cli.AddSubcommand(client.MigrateCmd)
-	cli.AddSubcommand(client.ZFSAbstractionsCmd)
+	cli.AddSubcommand(client.HoldsCmd)
 }
 
 func main() {

replication/driver/replication_driver.go

@@ -355,7 +355,7 @@ func (a *attempt) do(ctx context.Context, prev *attempt) {
 	// invariant: prevs contains an entry for each unambiguous correspondence
 
 	stepQueue := newStepQueue()
-	defer stepQueue.Start(1)() // TODO parallel replication
+	defer stepQueue.Start(envconst.Int("ZREPL_REPLICATION_EXPERIMENTAL_REPLICATION_CONCURRENCY", 1))() // TODO parallel replication
 	var fssesDone sync.WaitGroup
 	for _, f := range a.fss {
 		fssesDone.Add(1)
@@ -370,54 +370,57 @@ func (a *attempt) do(ctx context.Context, prev *attempt) {
 	a.finishedAt = time.Now()
 }
 
-func (fs *fs) do(ctx context.Context, pq *stepQueue, prev *fs) {
+func (f *fs) debug(format string, args ...interface{}) {
+	debugPrefix("fs=%s", f.fs.ReportInfo().Name)(format, args...)
+}
 
-	defer fs.l.Lock().Unlock()
+func (f *fs) do(ctx context.Context, pq *stepQueue, prev *fs) {
+
+	defer f.l.Lock().Unlock()
 
 	// get planned steps from replication logic
 	var psteps []Step
 	var errTime time.Time
 	var err error
-	fs.l.DropWhile(func() {
+	f.l.DropWhile(func() {
 		// TODO hacky
 		// choose target time that is earlier than any snapshot, so fs planning is always prioritized
 		targetDate := time.Unix(0, 0)
-		defer pq.WaitReady(fs, targetDate)()
-		psteps, err = fs.fs.PlanFS(ctx) // no shadow
-		errTime = time.Now()            // no shadow
+		defer pq.WaitReady(f, targetDate)()
+		psteps, err = f.fs.PlanFS(ctx) // no shadow
+		errTime = time.Now()           // no shadow
 	})
-	debug := debugPrefix("fs=%s", fs.fs.ReportInfo().Name)
-	fs.planning.done = true
+	f.planning.done = true
 	if err != nil {
-		fs.planning.err = newTimedError(err, errTime)
+		f.planning.err = newTimedError(err, errTime)
 		return
 	}
 	for _, pstep := range psteps {
 		step := &step{
-			l:    fs.l,
+			l:    f.l,
 			step: pstep,
 		}
-		fs.planned.steps = append(fs.planned.steps, step)
+		f.planned.steps = append(f.planned.steps, step)
 	}
-	debug("initial len(fs.planned.steps) = %d", len(fs.planned.steps))
+	f.debug("initial len(fs.planned.steps) = %d", len(f.planned.steps))
 
 	// for not-first attempts, only allow fs.planned.steps
 	// up to including the originally planned target snapshot
 	if prev != nil && prev.planning.done && prev.planning.err == nil {
 		prevUncompleted := prev.planned.steps[prev.planned.step:]
 		if len(prevUncompleted) == 0 {
-			debug("prevUncompleted is empty")
+			f.debug("prevUncompleted is empty")
 			return
 		}
-		if len(fs.planned.steps) == 0 {
-			debug("fs.planned.steps is empty")
+		if len(f.planned.steps) == 0 {
+			f.debug("fs.planned.steps is empty")
 			return
 		}
 		prevFailed := prevUncompleted[0]
-		curFirst := fs.planned.steps[0]
+		curFirst := f.planned.steps[0]
 		// we assume that PlanFS retries prevFailed (using curFirst)
 		if !prevFailed.step.TargetEquals(curFirst.step) {
-			debug("Targets don't match")
+			f.debug("Targets don't match")
 			// Two options:
 			// A: planning algorithm is broken
 			// B: manual user intervention inbetween
@@ -433,43 +436,43 @@ func (fs *fs) do(ctx context.Context, pq *stepQueue, prev *fs) {
 			}
 			msg := fmt.Sprintf("last attempt's uncompleted step %s does not correspond to this attempt's first planned step %s",
 				stepFmt(prevFailed), stepFmt(curFirst))
-			fs.planned.stepErr = newTimedError(errors.New(msg), time.Now())
+			f.planned.stepErr = newTimedError(errors.New(msg), time.Now())
 			return
 		}
 		// only allow until step targets diverge
 		min := len(prevUncompleted)
-		if min > len(fs.planned.steps) {
-			min = len(fs.planned.steps)
+		if min > len(f.planned.steps) {
+			min = len(f.planned.steps)
 		}
 		diverge := 0
 		for ; diverge < min; diverge++ {
-			debug("diverge compare iteration %d", diverge)
-			if !fs.planned.steps[diverge].step.TargetEquals(prevUncompleted[diverge].step) {
+			f.debug("diverge compare iteration %d", diverge)
+			if !f.planned.steps[diverge].step.TargetEquals(prevUncompleted[diverge].step) {
 				break
 			}
 		}
-		debug("diverge is %d", diverge)
-		fs.planned.steps = fs.planned.steps[0:diverge]
+		f.debug("diverge is %d", diverge)
+		f.planned.steps = f.planned.steps[0:diverge]
 	}
-	debug("post-prev-merge len(fs.planned.steps) = %d", len(fs.planned.steps))
+	f.debug("post-prev-merge len(fs.planned.steps) = %d", len(f.planned.steps))
 
-	for i, s := range fs.planned.steps {
+	for i, s := range f.planned.steps {
 		var (
 			err     error
 			errTime time.Time
 		)
 		// lock must not be held while executing step in order for reporting to work
-		fs.l.DropWhile(func() {
+		f.l.DropWhile(func() {
 			targetDate := s.step.TargetDate()
-			defer pq.WaitReady(fs, targetDate)()
+			defer pq.WaitReady(f, targetDate)()
 			err = s.step.Step(ctx) // no shadow
 			errTime = time.Now()   // no shadow
 		})
 		if err != nil {
-			fs.planned.stepErr = newTimedError(err, errTime)
+			f.planned.stepErr = newTimedError(err, errTime)
 			break
 		}
-		fs.planned.step = i + 1 // fs.planned.step must be == len(fs.planned.steps) if all went OK
+		f.planned.step = i + 1 // fs.planned.step must be == len(fs.planned.steps) if all went OK
 	}
 }
 

zfs/zfscmd/zfscmd_logging.go

@@ -1,7 +1,6 @@
 package zfscmd
 
 import (
-	"os/exec"
 	"time"
 )
 
@@ -29,22 +28,10 @@ func waitPreLogging(c *Cmd, now time.Time) {
 }
 
 func waitPostLogging(c *Cmd, err error, now time.Time) {
-
-	var total, system, user float64
-
-	total = c.Runtime().Seconds()
-	if ee, ok := err.(*exec.ExitError); ok {
-		system = ee.ProcessState.SystemTime().Seconds()
-		user = ee.ProcessState.UserTime().Seconds()
-	} else {
-		system = -1
-		user = -1
-	}
-
 	log := c.log().
-		WithField("total_time_s", total).
-		WithField("systemtime_s", system).
-		WithField("usertime_s", user)
+		WithField("total_time_s", c.Runtime().Seconds()).
+		WithField("systemtime_s", c.cmd.ProcessState.SystemTime().Seconds()).
+		WithField("usertime_s", c.cmd.ProcessState.UserTime().Seconds())
 
 	if err == nil {
 		log.Info("command exited without error")

zfs/zfscmd/zfscmd_platform_test.go

@@ -1,9 +1,7 @@
 package zfscmd
 
 import (
-	"bufio"
 	"bytes"
-	"context"
 	"io"
 	"os/exec"
 	"testing"
@@ -60,30 +58,3 @@ func TestCmdStderrBehaviorStdoutPipe(t *testing.T) {
 	require.True(t, ok)
 	require.Empty(t, ee.Stderr) // !!!!! probably not what one would expect if we only redirect stdout
 }
-
-func TestCmdProcessState(t *testing.T) {
-
-	ctx, cancel := context.WithCancel(context.Background())
-	defer cancel()
-	cmd := exec.CommandContext(ctx, "bash", "-c", "echo running; sleep 3600")
-	stdout, err := cmd.StdoutPipe()
-	require.NoError(t, err)
-	err = cmd.Start()
-	require.NoError(t, err)
-
-	r := bufio.NewReader(stdout)
-	line, err := r.ReadString('\n')
-	require.NoError(t, err)
-	require.Equal(t, "running\n", line)
-
-	// we know it's running and sleeping
-	cancel()
-	err = cmd.Wait()
-	t.Logf("wait err %T\n%s", err, err)
-	require.Error(t, err)
-	ee, ok := err.(*exec.ExitError)
-	require.True(t, ok)
-	require.NotNil(t, ee.ProcessState)
-	require.Contains(t, ee.Error(), "killed")
-
-}