doc: fixup 0.3 changelog 05f1237a6d

refs #219
fixes #329

.circleci/config.yml

@@ -60,10 +60,10 @@ jobs:
 
       - run: make zrepl-bin
       - run: make vet
-      - run: make test
       - run: make lint
       - run: make release
-
+      - run: make test-go
+      # cannot run test-platform because circle-ci runs in linux containers
 
       - store_artifacts:
           path: ./artifacts/release
@@ -92,11 +92,21 @@ jobs:
             REPO="zrepl/zrepl"
             COMMIT="${CIRCLE_SHA1}"
             JOB_NAME="${CIRCLE_JOB}"
-            curl "https://api.github.com/repos/$REPO/statuses/$COMMIT?access_token=$GITHUB_COMMIT_STATUS_TOKEN" \
+            curl "https://api.github.com/repos/$REPO/statuses/$COMMIT" \
               -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:

.github/FUNDING.yml

@@ -1,3 +1,4 @@
+github: problame
 patreon: zrepl
 liberapay: zrepl
 custom: https://www.paypal.com/cgi-bin/webscr?cmd=_s-xclick&hosted_button_id=R5QSXJVYHGX96

Makefile

@@ -27,6 +27,8 @@ 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
+GOCOVMERGE := gocovmerge
+
 ifneq ($(GOARM),)
 	ZREPL_TARGET_TUPLE := $(GOOS)-$(GOARCH)v$(GOARM)
 else
@@ -45,7 +47,7 @@ printvars:
 
 release: clean
 	# no cross-platform support for target test
-	$(MAKE) test
+	$(MAKE) test-go
 	$(MAKE) bins-all
 	$(MAKE) noarch
 	$(MAKE) wrapup-and-checksum
@@ -99,9 +101,9 @@ clean: docs-clean
 	rm -rf "$(ARTIFACTDIR)"
 
 ##################### BINARIES #####################
-.PHONY: bins-all lint test vet zrepl-bin platformtest-bin
+.PHONY: bins-all lint test-go test-platform cover-merge cover-html vet zrepl-bin test-platform-bin generate-platform-test-list
 
-BINS_ALL_TARGETS := zrepl-bin platformtest-bin vet lint
+BINS_ALL_TARGETS := zrepl-bin test-platform-bin vet lint
 GO_SUPPORTS_ILLUMOS := $(shell $(GO) version | gawk -F '.' '/^go version /{split($$0, comps, " "); split(comps[3], v, "."); if (v[1] == "go1" && v[2] >= 13) { print "illumos"; } else { print "noillumos"; }}')
 bins-all:
 	$(MAKE) $(BINS_ALL_TARGETS) GOOS=freebsd   GOARCH=amd64
@@ -122,27 +124,34 @@ endif
 
 lint:
 	$(GO_ENV_VARS) $(GOLANGCI_LINT) run ./...
-test:
+
-	$(GO_ENV_VARS) $(GO) test $(GO_BUILDFLAGS) ./...
 vet:
 	$(GO_ENV_VARS) $(GO) vet $(GO_BUILDFLAGS) ./...
 
+test-go: $(ARTIFACTDIR)
+	rm -f "$(ARTIFACTDIR)/gotest.cover"
+ifeq ($(COVER),1)
+	$(GO_ENV_VARS) $(GO) test $(GO_BUILDFLAGS) \
+		-coverpkg github.com/zrepl/zrepl/... \
+		-covermode atomic \
+		-coverprofile "$(ARTIFACTDIR)/gotest.cover" \
+		./...
+else
+	$(GO_ENV_VARS) $(GO) test $(GO_BUILDFLAGS) \
+		./...
+endif
+
 zrepl-bin:
 	$(GO_BUILD) -o "$(ARTIFACTDIR)/zrepl-$(ZREPL_TARGET_TUPLE)"
 
-platformtest-bin:
+generate-platform-test-list:
-	$(GO_BUILD) -o "$(ARTIFACTDIR)/platformtest-$(ZREPL_TARGET_TUPLE)" ./platformtest/harness
+	$(GO_BUILD) -o $(ARTIFACTDIR)/generate-platform-test-list ./platformtest/tests/gen
 
-##################### DEV TARGETS #####################
+test-platform-bin:
-# not part of the build, must do that manually
+	$(GO_ENV_VARS) $(GO) test $(GO_BUILDFLAGS) \
-.PHONY: generate format platformtest
+		-c -o "$(ARTIFACTDIR)/platformtest-$(ZREPL_TARGET_TUPLE)" \
-
+		-covermode=atomic -cover -coverpkg github.com/zrepl/zrepl/... \
-generate:
+		./platformtest/harness
-	protoc -I=replication/logic/pdu --go_out=plugins=grpc:replication/logic/pdu replication/logic/pdu/pdu.proto
-	$(GO_ENV_VARS) $(GO) generate $(GO_BUILDFLAGS) -x ./...
-
-format:
-	goimports -srcdir . -local 'github.com/zrepl/zrepl' -w $(shell find . -type f -name '*.go' -not -path "./vendor/*" -not -name '*.pb.go' -not -name '*_enumer.go')
 
 ZREPL_PLATFORMTEST_POOLNAME := zreplplatformtest
 ZREPL_PLATFORMTEST_IMAGEPATH := /tmp/zreplplatformtest.pool.img
@@ -150,16 +159,42 @@ ZREPL_PLATFORMTEST_MOUNTPOINT := /tmp/zreplplatformtest.pool
 ZREPL_PLATFORMTEST_ZFS_LOG := /tmp/zreplplatformtest.zfs.log
 # ZREPL_PLATFORMTEST_STOP_AND_KEEP := -failure.stop-and-keep-pool
 ZREPL_PLATFORMTEST_ARGS := 
-platformtest: # do not track dependency on platformtest-bin to allow build of platformtest outside of test VM
+test-platform: $(ARTIFACTDIR) # do not track dependency on test-platform-bin to allow build of platformtest outside of test VM
 	rm -f "$(ZREPL_PLATFORMTEST_ZFS_LOG)"
+	rm -f "$(ARTIFACTDIR)/platformtest.cover"
 	platformtest/logmockzfs/logzfsenv "$(ZREPL_PLATFORMTEST_ZFS_LOG)" `which zfs` \
 	"$(ARTIFACTDIR)/platformtest-$(ZREPL_TARGET_TUPLE)" \
+		-test.coverprofile "$(ARTIFACTDIR)/platformtest.cover" \
+		-test.v \
+		__DEVEL--i-heard-you-like-tests \
 		-poolname "$(ZREPL_PLATFORMTEST_POOLNAME)" \
 		-imagepath "$(ZREPL_PLATFORMTEST_IMAGEPATH)" \
 		-mountpoint "$(ZREPL_PLATFORMTEST_MOUNTPOINT)" \
 		$(ZREPL_PLATFORMTEST_STOP_AND_KEEP) \
 		$(ZREPL_PLATFORMTEST_ARGS)
 
+cover-merge: $(ARTIFACTDIR)
+	$(GOCOVMERGE) $(ARTIFACTDIR)/platformtest.cover $(ARTIFACTDIR)/gotest.cover > $(ARTIFACTDIR)/merged.cover
+cover-html: cover-merge
+	$(GO) tool cover -html "$(ARTIFACTDIR)/merged.cover" -o "$(ARTIFACTDIR)/merged.cover.html"
+
+test-full:
+	test "$$(id -u)" = "0" || echo "MUST RUN AS ROOT" 1>&2
+	$(MAKE) test-go COVER=1
+	$(MAKE) test-platform
+	$(MAKE) cover-html
+
+##################### DEV TARGETS #####################
+# not part of the build, must do that manually
+.PHONY: generate format
+
+generate: generate-platform-test-list
+	protoc -I=replication/logic/pdu --go_out=plugins=grpc:replication/logic/pdu replication/logic/pdu/pdu.proto
+	$(GO_ENV_VARS) $(GO) generate $(GO_BUILDFLAGS) -x ./...
+
+format:
+	goimports -srcdir . -local 'github.com/zrepl/zrepl' -w $(shell find . -type f -name '*.go' -not -path "./vendor/*" -not -name '*.pb.go' -not -name '*_enumer.go')
+
 ##################### NOARCH #####################
 .PHONY: noarch $(ARTIFACTDIR)/bash_completion $(ARTIFACTDIR)/_zrepl.zsh_completion $(ARTIFACTDIR)/go_env.txt docs docs-clean
 

README.md

@@ -2,7 +2,8 @@
 [![Language: Go](https://img.shields.io/badge/language-Go-6ad7e5.svg)](https://golang.org/)
 [![User Docs](https://img.shields.io/badge/docs-web-blue.svg)](https://zrepl.github.io)
 [![Donate via Patreon](https://img.shields.io/endpoint.svg?url=https%3A%2F%2Fshieldsio-patreon.herokuapp.com%2Fzrepl%2Fpledges&style=flat&color=yellow)](https://www.patreon.com/zrepl)
-[![Donate via Liberapay](https://img.shields.io/liberapay/receives/zrepl.svg?logo=liberapay)](https://liberapay.com/zrepl/donate)
+[![Donate via GitHub Sponsors](https://img.shields.io/static/v1?label=Sponsor&message=%E2%9D%A4&logo=GitHub&style=flat&color=yellow)](https://github.com/sponsors/problame)
+[![Donate via Liberapay](https://img.shields.io/liberapay/patrons/zrepl.svg?logo=liberapay)](https://liberapay.com/zrepl/donate)
 [![Donate via PayPal](https://img.shields.io/badge/donate-paypal-yellow.svg)](https://www.paypal.com/cgi-bin/webscr?cmd=_s-xclick&hosted_button_id=R5QSXJVYHGX96)
 [![Twitter](https://img.shields.io/twitter/url/https/github.com/zrepl/zrepl.svg?style=social)](https://twitter.com/intent/tweet?text=Wow:&url=https%3A%2F%2Fgithub.com%2Fzrepl%2Fzrepl)
 
@@ -39,7 +40,7 @@ Check out the *Coding Workflow* section below for details.
 * Ship other material provided in `./dist`, e.g. in `/usr/share/zrepl/`.
 * Use `make release ZREPL_VERSION='mydistro-1.2.3_1'`
     * Your distro's name and any versioning supplemental to zrepl's (e.g. package revision) should be in this string
-* Use `make platformtest` **on a test system** to validate that zrepl's abstractions on top of ZFS work with the system ZFS.
+* Use `sudo make test-platform` **on a test system** to validate that zrepl's abstractions on top of ZFS work with the system ZFS.
 * Make sure you are informed about new zrepl versions, e.g. by subscribing to GitHub's release RSS feed.
 
 ## Developer Documentation
@@ -47,10 +48,18 @@ Check out the *Coding Workflow* section below for details.
 zrepl is written in [Go](https://golang.org) and uses [Go modules](https://github.com/golang/go/wiki/Modules) to manage dependencies.
 The documentation is written in [ReStructured Text](http://docutils.sourceforge.net/rst.html) using the [Sphinx](https://www.sphinx-doc.org) framework.
 
-To get started, run `./lazy.sh devsetup` to easily install build dependencies and read `docs/installation.rst -> Compiling from Source`.
+Install **build dependencies** using  `./lazy.sh devsetup`.
 `lazy.sh` uses `python3-pip` to fetch the build dependencies for the docs - you might want to use a [venv](https://docs.python.org/3/library/venv.html).
 If you just want to install the Go dependencies, run `./lazy.sh godep`.
 
+The **test suite** is split into pure **Go tests** (`make test-go`) and **platform tests** that interact with ZFS and thus generally **require root privileges** (`sudo make test-platform`).
+Platform tests run on their own pool with the name `zreplplatformtest`, which is created using the file vdev in `/tmp`.
+
+For a full **code coverage** profile, run `make test-go COVER=1 && sudo make test-platform && make cover-merge`.
+An HTML report can be generated using `make cover-html`.
+
+**Code generation** is triggered by `make generate`. Generated code is committed to the source tree.
+
 ### Project Structure
 
 ```

build/go.mod

@@ -28,6 +28,7 @@ require (
 	github.com/spf13/jwalterweatherman v1.1.0 // indirect
 	github.com/spf13/viper v1.3.2 // indirect
 	github.com/stretchr/testify v1.4.0 // indirect
+	github.com/wadey/gocovmerge v0.0.0-20160331181800-b5bfa59ec0ad // indirect
 	golang.org/x/net v0.0.0-20190613194153-d28f0bde5980 // indirect
 	golang.org/x/sys v0.0.0-20191010194322-b09406accb47 // indirect
 	golang.org/x/tools v0.0.0-20190524210228-3d17549cdc6b

build/go.sum

@@ -214,6 +214,8 @@ github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyC
 github.com/valyala/fasthttp v1.2.0/go.mod h1:4vX61m6KN+xDduDNwXrhIAVZaZaZiQ1luJk8LWSxF3s=
 github.com/valyala/quicktemplate v1.1.1/go.mod h1:EH+4AkTd43SvgIbQHYu59/cJyxDoOVRUAfrukLPuGJ4=
 github.com/valyala/tcplisten v0.0.0-20161114210144-ceec8f93295a/go.mod h1:v3UYOV9WzVtRmSR+PDvWpU/qWl4Wa5LApYYX4ZtKbio=
+github.com/wadey/gocovmerge v0.0.0-20160331181800-b5bfa59ec0ad h1:W0LEBv82YCGEtcmPA3uNZBI33/qF//HAAs3MawDjRa0=
+github.com/wadey/gocovmerge v0.0.0-20160331181800-b5bfa59ec0ad/go.mod h1:Hy8o65+MXnS6EwGElrSRjUzQDLXreJlzYLlWiHtt8hM=
 github.com/xordataexchange/crypt v0.0.3-0.20170626215501-b2862e3d0a77/go.mod h1:aYKd//L2LvnjZzWKhF00oedf4jCCReLcmhLdhm1A27Q=
 golang.org/x/crypto v0.0.0-20181203042331-505ab145d0a9/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
 golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=

build/tools.go

@@ -6,6 +6,7 @@ import (
 	_ "github.com/alvaroloes/enumer"
 	_ "github.com/golang/protobuf/protoc-gen-go"
 	_ "github.com/golangci/golangci-lint/cmd/golangci-lint"
+	_ "github.com/wadey/gocovmerge"
 	_ "golang.org/x/tools/cmd/goimports"
 	_ "golang.org/x/tools/cmd/stringer"
 )

cli/cli.go

@@ -1,11 +1,13 @@
 package cli
 
 import (
+	"context"
 	"fmt"
 	"os"
 
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 )
@@ -75,7 +77,7 @@ type Subcommand struct {
 	Short            string
 	Example          string
 	NoRequireConfig  bool
-	Run              func(subcommand *Subcommand, args []string) error
+	Run              func(ctx context.Context, subcommand *Subcommand, args []string) error
 	SetupFlags       func(f *pflag.FlagSet)
 	SetupSubcommands func() []*Subcommand
 
@@ -96,7 +98,11 @@ func (s *Subcommand) Config() *config.Config {
 
 func (s *Subcommand) run(cmd *cobra.Command, args []string) {
 	s.tryParseConfig()
-	err := s.Run(s, args)
+	ctx := context.Background()
+	endTask := trace.WithTaskFromStackUpdateCtx(&ctx)
+	defer endTask()
+	err := s.Run(ctx, s, args)
+	endTask()
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "%s\n", err)
 		os.Exit(1)

client/configcheck.go

@@ -1,6 +1,7 @@
 package client
 
 import (
+	"context"
 	"encoding/json"
 	"fmt"
 	"os"
@@ -29,7 +30,7 @@ var ConfigcheckCmd = &cli.Subcommand{
 		f.StringVar(&configcheckArgs.format, "format", "", "dump parsed config object [pretty|yaml|json]")
 		f.StringVar(&configcheckArgs.what, "what", "all", "what to print [all|config|jobs|logging]")
 	},
-	Run: func(subcommand *cli.Subcommand, args []string) error {
+	Run: func(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 		formatMap := map[string]func(interface{}){
 			"": func(i interface{}) {},
 			"pretty": func(i interface{}) {

client/migrate.go

@@ -48,14 +48,13 @@ var migratePlaceholder0_1Args struct {
 	dryRun bool
 }
 
-func doMigratePlaceholder0_1(sc *cli.Subcommand, args []string) error {
+func doMigratePlaceholder0_1(ctx context.Context, sc *cli.Subcommand, args []string) error {
 	if len(args) != 0 {
 		return fmt.Errorf("migration does not take arguments, got %v", args)
 	}
 
 	cfg := sc.Config()
 
-	ctx := context.Background()
 	allFSS, err := zfs.ZFSListMapping(ctx, zfs.NoFilter())
 	if err != nil {
 		return errors.Wrap(err, "cannot list filesystems")
@@ -124,7 +123,7 @@ var fail = color.New(color.FgRed)
 
 var migrateReplicationCursorSkipSentinel = fmt.Errorf("skipping this filesystem")
 
-func doMigrateReplicationCursor(sc *cli.Subcommand, args []string) error {
+func doMigrateReplicationCursor(ctx context.Context, sc *cli.Subcommand, args []string) error {
 	if len(args) != 0 {
 		return fmt.Errorf("migration does not take arguments, got %v", args)
 	}
@@ -137,8 +136,6 @@ func doMigrateReplicationCursor(sc *cli.Subcommand, args []string) error {
 		return fmt.Errorf("exiting migration after error")
 	}
 
-	ctx := context.Background()
-
 	v1cursorJobs := make([]job.Job, 0, len(cfg.Jobs))
 	for i, j := range cfg.Jobs {
 		if jobs[i].Name() != j.Name() {

client/pprof.go

@@ -1,67 +1,10 @@
 package client
 
-import (
+import "github.com/zrepl/zrepl/cli"
-	"errors"
-	"log"
-	"os"
-
-	"github.com/zrepl/zrepl/cli"
-	"github.com/zrepl/zrepl/config"
-	"github.com/zrepl/zrepl/daemon"
-)
-
-var pprofArgs struct {
-	daemon.PprofServerControlMsg
-}
 
 var PprofCmd = &cli.Subcommand{
-	Use:   "pprof off | [on TCP_LISTEN_ADDRESS]",
+	Use: "pprof",
-	Short: "start a http server exposing go-tool-compatible profiling endpoints at TCP_LISTEN_ADDRESS",
+	SetupSubcommands: func() []*cli.Subcommand {
-	Run: func(subcommand *cli.Subcommand, args []string) error {
+		return []*cli.Subcommand{PprofListenCmd, pprofActivityTraceCmd}
-		if len(args) < 1 {
-			goto enargs
-		}
-		switch args[0] {
-		case "on":
-			pprofArgs.Run = true
-			if len(args) != 2 {
-				return errors.New("must specify TCP_LISTEN_ADDRESS as second positional argument")
-			}
-			pprofArgs.HttpListenAddress = args[1]
-		case "off":
-			if len(args) != 1 {
-				goto enargs
-			}
-			pprofArgs.Run = false
-		}
-
-		RunPProf(subcommand.Config())
-		return nil
-	enargs:
-		return errors.New("invalid number of positional arguments")
-
 	},
 }
-
-func RunPProf(conf *config.Config) {
-	log := log.New(os.Stderr, "", 0)
-
-	die := func() {
-		log.Printf("exiting after error")
-		os.Exit(1)
-	}
-
-	log.Printf("connecting to zrepl daemon")
-
-	httpc, err := controlHttpClient(conf.Global.Control.SockPath)
-	if err != nil {
-		log.Printf("error creating http client: %s", err)
-		die()
-	}
-	err = jsonRequestResponse(httpc, daemon.ControlJobEndpointPProf, pprofArgs.PprofServerControlMsg, struct{}{})
-	if err != nil {
-		log.Printf("error sending control message: %s", err)
-		die()
-	}
-	log.Printf("finished")
-}

client/pprof_activity_trace.go

@@ -0,0 +1,44 @@
+package client
+
+import (
+	"context"
+	"io"
+	"log"
+	"os"
+
+	"golang.org/x/net/websocket"
+
+	"github.com/zrepl/zrepl/cli"
+)
+
+var pprofActivityTraceCmd = &cli.Subcommand{
+	Use:   "activity-trace ZREPL_PPROF_HOST:ZREPL_PPROF_PORT",
+	Short: "attach to zrepl daemon with activated pprof listener and dump an activity-trace to stdout",
+	Run:   runPProfActivityTrace,
+}
+
+func runPProfActivityTrace(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
+	log := log.New(os.Stderr, "", 0)
+
+	die := func() {
+		log.Printf("exiting after error")
+		os.Exit(1)
+	}
+
+	if len(args) != 1 {
+		log.Printf("exactly one positional argument is required")
+		die()
+	}
+
+	url := "ws://" + args[0] + "/debug/zrepl/activity-trace" // FIXME dont' repeat that
+
+	log.Printf("attaching to activity trace stream %s", url)
+	ws, err := websocket.Dial(url, "", url)
+	if err != nil {
+		log.Printf("error: %s", err)
+		die()
+	}
+
+	_, err = io.Copy(os.Stdout, ws)
+	return err
+}

client/pprof_listen.go

@@ -0,0 +1,68 @@
+package client
+
+import (
+	"context"
+	"errors"
+	"log"
+	"os"
+
+	"github.com/zrepl/zrepl/cli"
+	"github.com/zrepl/zrepl/config"
+	"github.com/zrepl/zrepl/daemon"
+)
+
+var pprofListenCmd struct {
+	daemon.PprofServerControlMsg
+}
+
+var PprofListenCmd = &cli.Subcommand{
+	Use:   "listen off | [on TCP_LISTEN_ADDRESS]",
+	Short: "start a http server exposing go-tool-compatible profiling endpoints at TCP_LISTEN_ADDRESS",
+	Run: func(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
+		if len(args) < 1 {
+			goto enargs
+		}
+		switch args[0] {
+		case "on":
+			pprofListenCmd.Run = true
+			if len(args) != 2 {
+				return errors.New("must specify TCP_LISTEN_ADDRESS as second positional argument")
+			}
+			pprofListenCmd.HttpListenAddress = args[1]
+		case "off":
+			if len(args) != 1 {
+				goto enargs
+			}
+			pprofListenCmd.Run = false
+		}
+
+		RunPProf(subcommand.Config())
+		return nil
+	enargs:
+		return errors.New("invalid number of positional arguments")
+
+	},
+}
+
+func RunPProf(conf *config.Config) {
+	log := log.New(os.Stderr, "", 0)
+
+	die := func() {
+		log.Printf("exiting after error")
+		os.Exit(1)
+	}
+
+	log.Printf("connecting to zrepl daemon")
+
+	httpc, err := controlHttpClient(conf.Global.Control.SockPath)
+	if err != nil {
+		log.Printf("error creating http client: %s", err)
+		die()
+	}
+	err = jsonRequestResponse(httpc, daemon.ControlJobEndpointPProf, pprofListenCmd.PprofServerControlMsg, struct{}{})
+	if err != nil {
+		log.Printf("error sending control message: %s", err)
+		die()
+	}
+	log.Printf("finished")
+}

client/signal.go

@@ -1,6 +1,8 @@
 package client
 
 import (
+	"context"
+
 	"github.com/pkg/errors"
 
 	"github.com/zrepl/zrepl/cli"
@@ -11,7 +13,7 @@ import (
 var SignalCmd = &cli.Subcommand{
 	Use:   "signal [wakeup|reset] JOB",
 	Short: "wake up a job from wait state or abort its current invocation",
-	Run: func(subcommand *cli.Subcommand, args []string) error {
+	Run: func(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 		return runSignalCmd(subcommand.Config(), args)
 	},
 }

client/status.go

@@ -1,6 +1,7 @@
 package client
 
 import (
+	"context"
 	"fmt"
 	"io"
 	"math"
@@ -180,7 +181,7 @@ var StatusCmd = &cli.Subcommand{
 	Run: runStatus,
 }
 
-func runStatus(s *cli.Subcommand, args []string) error {
+func runStatus(ctx context.Context, s *cli.Subcommand, args []string) error {
 	httpc, err := controlHttpClient(s.Config().Global.Control.SockPath)
 	if err != nil {
 		return err

client/stdinserver.go

@@ -17,7 +17,7 @@ import (
 var StdinserverCmd = &cli.Subcommand{
 	Use:   "stdinserver CLIENT_IDENTITY",
 	Short: "stdinserver transport mode (started from authorized_keys file as forced command)",
-	Run: func(subcommand *cli.Subcommand, args []string) error {
+	Run: func(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 		return runStdinserver(subcommand.Config(), args)
 	},
 }

client/testcmd.go

@@ -39,7 +39,7 @@ var testFilter = &cli.Subcommand{
 	Run: runTestFilterCmd,
 }
 
-func runTestFilterCmd(subcommand *cli.Subcommand, args []string) error {
+func runTestFilterCmd(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 
 	if testFilterArgs.job == "" {
 		return fmt.Errorf("must specify --job flag")
@@ -49,7 +49,6 @@ func runTestFilterCmd(subcommand *cli.Subcommand, args []string) error {
 	}
 
 	conf := subcommand.Config()
-	ctx := context.Background()
 
 	var confFilter config.FilesystemsFilter
 	job, err := conf.Job(testFilterArgs.job)
@@ -137,10 +136,9 @@ var testPlaceholder = &cli.Subcommand{
 	Run: runTestPlaceholder,
 }
 
-func runTestPlaceholder(subcommand *cli.Subcommand, args []string) error {
+func runTestPlaceholder(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 
 	var checkDPs []*zfs.DatasetPath
-	ctx := context.Background()
 
 	// all actions first
 	if testPlaceholderArgs.all {
@@ -197,11 +195,11 @@ var testDecodeResumeToken = &cli.Subcommand{
 	Run: runTestDecodeResumeTokenCmd,
 }
 
-func runTestDecodeResumeTokenCmd(subcommand *cli.Subcommand, args []string) error {
+func runTestDecodeResumeTokenCmd(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 	if testDecodeResumeTokenArgs.token == "" {
 		return fmt.Errorf("token argument must be specified")
 	}
-	token, err := zfs.ParseResumeToken(context.Background(), testDecodeResumeTokenArgs.token)
+	token, err := zfs.ParseResumeToken(ctx, testDecodeResumeTokenArgs.token)
 	if err != nil {
 		return err
 	}

client/version.go

@@ -1,6 +1,7 @@
 package client
 
 import (
+	"context"
 	"fmt"
 	"os"
 
@@ -25,7 +26,7 @@ var VersionCmd = &cli.Subcommand{
 	SetupFlags: func(f *pflag.FlagSet) {
 		f.StringVar(&versionArgs.Show, "show", "", "version info to show (client|daemon)")
 	},
-	Run: func(subcommand *cli.Subcommand, args []string) error {
+	Run: func(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
 		versionArgs.Config = subcommand.Config()
 		versionArgs.ConfigErr = subcommand.ConfigParsingError()
 		return runVersionCmd()

client/zfsabstractions_create_step_hold.go

@@ -28,7 +28,7 @@ var zabsCmdCreateStepHold = &cli.Subcommand{
 	},
 }
 
-func doZabsCreateStep(sc *cli.Subcommand, args []string) error {
+func doZabsCreateStep(ctx context.Context, sc *cli.Subcommand, args []string) error {
 	if len(args) > 0 {
 		return errors.New("subcommand takes no arguments")
 	}
@@ -44,8 +44,6 @@ func doZabsCreateStep(sc *cli.Subcommand, args []string) error {
 		return errors.Errorf("jobid must be set")
 	}
 
-	ctx := context.Background()
-
 	v, err := zfs.ZFSGetFilesystemVersion(ctx, f.target)
 	if err != nil {
 		return errors.Wrapf(err, "get info about target %q", f.target)

client/zfsabstractions_list.go

@@ -32,9 +32,8 @@ var zabsCmdList = &cli.Subcommand{
 	},
 }
 
-func doZabsList(sc *cli.Subcommand, args []string) error {
+func doZabsList(ctx context.Context, sc *cli.Subcommand, args []string) error {
 	var err error
-	ctx := context.Background()
 
 	if len(args) > 0 {
 		return errors.New("this subcommand takes no positional arguments")

client/zfsabstractions_release.go

@@ -43,9 +43,8 @@ var zabsCmdReleaseStale = &cli.Subcommand{
 	SetupFlags:      registerZabsReleaseFlags,
 }
 
-func doZabsReleaseAll(sc *cli.Subcommand, args []string) error {
+func doZabsReleaseAll(ctx context.Context, sc *cli.Subcommand, args []string) error {
 	var err error
-	ctx := context.Background()
 
 	if len(args) > 0 {
 		return errors.New("this subcommand takes no positional arguments")
@@ -68,10 +67,9 @@ func doZabsReleaseAll(sc *cli.Subcommand, args []string) error {
 	return doZabsRelease_Common(ctx, abstractions)
 }
 
-func doZabsReleaseStale(sc *cli.Subcommand, args []string) error {
+func doZabsReleaseStale(ctx context.Context, sc *cli.Subcommand, args []string) error {
 
 	var err error
-	ctx := context.Background()
 
 	if len(args) > 0 {
 		return errors.New("this subcommand takes no positional arguments")

config/config.go

@@ -76,7 +76,12 @@ type SnapJob struct {
 }
 
 type SendOptions struct {
-	Encrypted bool `yaml:"encrypted"`
+	Encrypted bool                 `yaml:"encrypted"`
+	StepHolds SendOptionsStepHolds `yaml:"step_holds,optional"`
+}
+
+type SendOptionsStepHolds struct {
+	DisableIncremental bool `yaml:"disable_incremental,optional"`
 }
 
 var _ yaml.Defaulter = (*SendOptions)(nil)

config/samples/quickstart_backup_to_external_disk.yml

@@ -0,0 +1,85 @@
+# This config serves as an example for a local zrepl installation that
+# backups the entire zpool `system` to `backuppool/zrepl/sink`
+#
+# The requirements covered by this setup are described in the zrepl documentation's
+# quick start section which inlines this example.
+#
+# CUSTOMIZATIONS YOU WILL LIKELY WANT TO APPLY:
+# - adjust the name of the production pool `system` in the `filesystems` filter of jobs `snapjob` and `push_to_derive`
+# - adjust the name of the backup pool `backuppool` in the `backuppool_sink` job
+# - adjust the occurences of `myhostname` to the name of the system you are backing up (cannot be easily changed once you start replicating)
+# - make sure the `zrepl_` prefix is not being used by any other zfs tools you might have installed (it likely isn't)
+
+jobs:
+
+# this job takes care of snapshot creation + pruning
+- name: snapjob
+  type: snap
+  filesystems: {
+      "system<": true,
+  }
+  # create snapshots with prefix `zrepl_` every 15 minutes
+  snapshotting:
+    type: periodic
+    interval: 15m
+    prefix: zrepl_
+  pruning:
+    keep:
+    # fade-out scheme for snapshots starting with `zrepl_`
+    # - keep all created in the last hour
+    # - then destroy snapshots such that we keep 24 each 1 hour apart
+    # - then destroy snapshots such that we keep 14 each 1 day apart
+    # - then destroy all older snapshots
+    - type: grid
+      grid: 1x1h(keep=all) | 24x1h | 14x1d
+      regex: "^zrepl_.*"
+    # keep all snapshots that don't have the `zrepl_` prefix
+    - type: regex
+      negate: true
+      regex: "^zrepl_.*"
+
+# This job pushes to the local sink defined in job `backuppool_sink`.
+# We trigger replication manually from the command line / udev rules using
+#  `zrepl signal wakeup push_to_drive`
+- type: push
+  name: push_to_drive
+  connect:
+    type: local
+    listener_name: backuppool_sink
+    client_identity: myhostname
+  filesystems: {
+      "system<": true
+  }
+  send:
+    encrypted: true
+    # disable incremental step holds so that
+    # - we can yank out the backup drive during replication
+    # - thereby sacrificing resumability
+    # - in exchange for the replicating snapshot not sticking around until we reconnect the backup drive
+    step_holds:
+      disable_incremental: true
+  snapshotting:
+    type: manual
+  pruning:
+    # no-op prune rule on sender (keep all snapshots), job `snapshot` takes care of this
+    keep_sender:
+    - type: regex
+      regex: ".*"
+    # retain 
+    keep_receiver:
+    # longer retention on the backup drive, we have more space there
+    - type: grid
+      grid: 1x1h(keep=all) | 24x1h | 360x1d
+      regex: "^zrepl_.*"
+    # retain all non-zrepl snapshots on the backup drive
+    - type: regex
+      negate: true
+      regex: "^zrepl_.*"
+
+# This job receives from job `push_to_drive` into `backuppool/zrepl/sink/myhostname`
+- type: sink
+  name: backuppool_sink
+  root_fs: "backuppool/zrepl/sink"
+  serve:
+    type: local
+    listener_name: backuppool_sink

config/samples/quickstart_continuous_server_backup_receiver.yml

@@ -0,0 +1,12 @@
+jobs:
+- name: sink
+  type: sink
+  serve:
+      type: tls
+      listen: ":8888"
+      ca: "/etc/zrepl/prod.crt"
+      cert: "/etc/zrepl/backups.crt"
+      key: "/etc/zrepl/backups.key"
+      client_cns:
+        - "prod"
+  root_fs: "storage/zrepl/sink"

config/samples/quickstart_continuous_server_backup_sender.yml

@@ -0,0 +1,28 @@
+jobs:
+- name: prod_to_backups
+  type: push
+  connect:
+    type: tls
+    address: "backups.example.com:8888"
+    ca: /etc/zrepl/backups.crt
+    cert: /etc/zrepl/prod.crt
+    key:  /etc/zrepl/prod.key
+    server_cn: "backups"
+  filesystems: {
+    "zroot/var/db": true,
+    "zroot/usr/home<": true,
+    "zroot/usr/home/paranoid": false
+  }
+  snapshotting:
+    type: periodic
+    prefix: zrepl_
+    interval: 10m
+  pruning:
+    keep_sender:
+    - type: not_replicated
+    - type: last_n
+      count: 10
+    keep_receiver:
+    - type: grid
+      grid: 1x1h(keep=all) | 24x1h | 30x1d | 6x30d
+      regex: "^zrepl_"

config/samples/source.yml

@@ -5,7 +5,11 @@ jobs:
     type: tcp
     listen: "0.0.0.0:8888"
     clients: {
-      "192.168.122.123" : "client1"
+      "192.168.122.123" :               "mysql01",
+      "192.168.122.42" :                "mx01",
+      "2001:0db8:85a3::8a2e:0370:7334": "gateway",
+      "10.23.42.0/24":       "cluster-*",
+      "fde4:8dba:82e1::/64": "san-*",
     }
   filesystems: {
     "<": true,

daemon/control.go

@@ -120,7 +120,13 @@ func (j *controlJob) Run(ctx context.Context) {
 		jsonResponder{log, func() (interface{}, error) {
 			jobs := j.jobs.status()
 			globalZFS := zfscmd.GetReport()
-			s := Status{Jobs: jobs, Global: GlobalStatus{ZFSCmds: globalZFS}}
+			envconstReport := envconst.GetReport()
+			s := Status{
+				Jobs: jobs,
+				Global: GlobalStatus{
+					ZFSCmds:  globalZFS,
+					Envconst: envconstReport,
+				}}
 			return s, nil
 		}})
 

daemon/daemon.go

@@ -12,6 +12,9 @@ import (
 
 	"github.com/pkg/errors"
 	"github.com/prometheus/client_golang/prometheus"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
+	"github.com/zrepl/zrepl/endpoint"
+	"github.com/zrepl/zrepl/util/envconst"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/job"
@@ -23,9 +26,8 @@ import (
 	"github.com/zrepl/zrepl/zfs/zfscmd"
 )
 
-func Run(conf *config.Config) error {
+func Run(ctx context.Context, conf *config.Config) error {
-
+	ctx, cancel := context.WithCancel(ctx)
-	ctx, cancel := context.WithCancel(context.Background())
 
 	defer cancel()
 	sigChan := make(chan os.Signal, 1)
@@ -39,6 +41,7 @@ func Run(conf *config.Config) error {
 	if err != nil {
 		return errors.Wrap(err, "cannot build logging from config")
 	}
+	outlets.Add(newPrometheusLogOutlet(), logger.Debug)
 
 	confJobs, err := job.JobsFromConfig(conf)
 	if err != nil {
@@ -48,14 +51,23 @@ func Run(conf *config.Config) error {
 	log := logger.NewLogger(outlets, 1*time.Second)
 	log.Info(version.NewZreplVersionInformation().String())
 
+	ctx = logging.WithLoggers(ctx, logging.SubsystemLoggersWithUniversalLogger(log))
+	trace.RegisterCallback(trace.Callback{
+		OnBegin: func(ctx context.Context) { logging.GetLogger(ctx, logging.SubsysTraceData).Debug("begin span") },
+		OnEnd: func(ctx context.Context, spanInfo trace.SpanInfo) {
+			logging.
+				GetLogger(ctx, logging.SubsysTraceData).
+				WithField("duration_s", spanInfo.EndedAt().Sub(spanInfo.StartedAt()).Seconds()).
+				Debug("finished span " + spanInfo.TaskAndSpanStack(trace.SpanStackKindAnnotation))
+		},
+	})
+
 	for _, job := range confJobs {
 		if IsInternalJobName(job.Name()) {
 			panic(fmt.Sprintf("internal job name used for config job '%s'", job.Name())) //FIXME
 		}
 	}
 
-	ctx = job.WithLogger(ctx, log)
-
 	jobs := newJobs()
 
 	// start control socket
@@ -83,7 +95,10 @@ func Run(conf *config.Config) error {
 	}
 
 	// register global (=non job-local) metrics
+	version.PrometheusRegister(prometheus.DefaultRegisterer)
 	zfscmd.RegisterMetrics(prometheus.DefaultRegisterer)
+	trace.RegisterMetrics(prometheus.DefaultRegisterer)
+	endpoint.RegisterMetrics(prometheus.DefaultRegisterer)
 
 	log.Info("starting daemon")
 
@@ -98,6 +113,8 @@ func Run(conf *config.Config) error {
 	case <-ctx.Done():
 		log.WithError(ctx.Err()).Info("context finished")
 	}
+	log.Info("waiting for jobs to finish")
+	<-jobs.wait()
 	log.Info("daemon exiting")
 	return nil
 }
@@ -120,14 +137,11 @@ func newJobs() *jobs {
 	}
 }
 
-const (
-	logJobField string = "job"
-)
-
 func (s *jobs) wait() <-chan struct{} {
 	ch := make(chan struct{})
 	go func() {
 		s.wg.Wait()
+		close(ch)
 	}()
 	return ch
 }
@@ -138,7 +152,8 @@ type Status struct {
 }
 
 type GlobalStatus struct {
-	ZFSCmds *zfscmd.Report
+	ZFSCmds  *zfscmd.Report
+	Envconst *envconst.Report
 }
 
 func (s *jobs) status() map[string]*job.Status {
@@ -202,9 +217,8 @@ func (s *jobs) start(ctx context.Context, j job.Job, internal bool) {
 	s.m.Lock()
 	defer s.m.Unlock()
 
-	jobLog := job.GetLogger(ctx).
+	ctx = logging.WithInjectedField(ctx, logging.JobField, j.Name())
-		WithField(logJobField, j.Name()).
+
-		WithOutlet(newPrometheusLogOutlet(j.Name()), logger.Debug)
 	jobName := j.Name()
 	if !internal && IsInternalJobName(jobName) {
 		panic(fmt.Sprintf("internal job name used for non-internal job %s", jobName))
@@ -219,7 +233,6 @@ func (s *jobs) start(ctx context.Context, j job.Job, internal bool) {
 	j.RegisterMetrics(prometheus.DefaultRegisterer)
 
 	s.jobs[jobName] = j
-	ctx = job.WithLogger(ctx, jobLog)
 	ctx = zfscmd.WithJobID(ctx, j.Name())
 	ctx, wakeup := wakeup.Context(ctx)
 	ctx, resetFunc := reset.Context(ctx)
@@ -229,8 +242,8 @@ func (s *jobs) start(ctx context.Context, j job.Job, internal bool) {
 	s.wg.Add(1)
 	go func() {
 		defer s.wg.Done()
-		jobLog.Info("starting job")
+		job.GetLogger(ctx).Info("starting job")
-		defer jobLog.Info("job exited")
+		defer job.GetLogger(ctx).Info("job exited")
 		j.Run(ctx)
 	}()
 }

daemon/hooks/hook_logging.go

@@ -6,29 +6,17 @@ import (
 	"context"
 	"sync"
 
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/logger"
 	"github.com/zrepl/zrepl/util/envconst"
 )
 
-type contextKey int
-
-const (
-	contextKeyLog contextKey = 0
-)
-
 type Logger = logger.Logger
 
-func WithLogger(ctx context.Context, log Logger) context.Context {
-	return context.WithValue(ctx, contextKeyLog, log)
-}
-
 func GetLogger(ctx context.Context) Logger { return getLogger(ctx) }
 
 func getLogger(ctx context.Context) Logger {
-	if log, ok := ctx.Value(contextKeyLog).(Logger); ok {
+	return logging.GetLogger(ctx, logging.SubsysHooks)
-		return log
-	}
-	return logger.NewNullLogger()
 }
 
 const MAX_HOOK_LOG_SIZE_DEFAULT int = 1 << 20

daemon/hooks/hooks_test.go

@@ -10,9 +10,11 @@ import (
 	"text/template"
 
 	"github.com/stretchr/testify/require"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/hooks"
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/logger"
 	"github.com/zrepl/zrepl/zfs"
 )
@@ -69,6 +71,9 @@ func curry(f comparisonAssertionFunc, expected interface{}, right bool) (ret val
 }
 
 func TestHooks(t *testing.T) {
+	ctx, end := trace.WithTaskFromStack(context.Background())
+	defer end()
+
 	testFSName := "testpool/testdataset"
 	testSnapshotName := "testsnap"
 
@@ -418,9 +423,8 @@ jobs:
 
 			cbReached = false
 
-			ctx := context.Background()
 			if testing.Verbose() && !tt.SuppressOutput {
-				ctx = hooks.WithLogger(ctx, log)
+				ctx = logging.WithLoggers(ctx, logging.SubsystemLoggersWithUniversalLogger(log))
 			}
 			plan.Run(ctx, false)
 			report := plan.Report()

daemon/job/active.go

@@ -8,12 +8,13 @@ import (
 
 	"github.com/pkg/errors"
 	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/common/log"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/filters"
 	"github.com/zrepl/zrepl/daemon/job/reset"
 	"github.com/zrepl/zrepl/daemon/job/wakeup"
-	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/daemon/pruner"
 	"github.com/zrepl/zrepl/daemon/snapper"
 	"github.com/zrepl/zrepl/endpoint"
@@ -79,7 +80,7 @@ func (a *ActiveSide) updateTasks(u func(*activeSideTasks)) activeSideTasks {
 }
 
 type activeMode interface {
-	ConnectEndpoints(rpcLoggers rpc.Loggers, connecter transport.Connecter)
+	ConnectEndpoints(ctx context.Context, connecter transport.Connecter)
 	DisconnectEndpoints()
 	SenderReceiver() (logic.Sender, logic.Receiver)
 	Type() Type
@@ -98,14 +99,14 @@ type modePush struct {
 	snapper       *snapper.PeriodicOrManual
 }
 
-func (m *modePush) ConnectEndpoints(loggers rpc.Loggers, connecter transport.Connecter) {
+func (m *modePush) ConnectEndpoints(ctx context.Context, connecter transport.Connecter) {
 	m.setupMtx.Lock()
 	defer m.setupMtx.Unlock()
 	if m.receiver != nil || m.sender != nil {
 		panic("inconsistent use of ConnectEndpoints and DisconnectEndpoints")
 	}
 	m.sender = endpoint.NewSender(*m.senderConfig)
-	m.receiver = rpc.NewClient(connecter, loggers)
+	m.receiver = rpc.NewClient(connecter, rpc.GetLoggersOrPanic(ctx))
 }
 
 func (m *modePush) DisconnectEndpoints() {
@@ -151,9 +152,10 @@ func modePushFromConfig(g *config.Global, in *config.PushJob, jobID endpoint.Job
 	}
 
 	m.senderConfig = &endpoint.SenderConfig{
-		FSF:     fsf,
+		FSF:                         fsf,
-		Encrypt: &zfs.NilBool{B: in.Send.Encrypted},
+		Encrypt:                     &zfs.NilBool{B: in.Send.Encrypted},
-		JobID:   jobID,
+		DisableIncrementalStepHolds: in.Send.StepHolds.DisableIncremental,
+		JobID:                       jobID,
 	}
 	m.plannerPolicy = &logic.PlannerPolicy{
 		EncryptedSend: logic.TriFromBool(in.Send.Encrypted),
@@ -176,14 +178,14 @@ type modePull struct {
 	interval       config.PositiveDurationOrManual
 }
 
-func (m *modePull) ConnectEndpoints(loggers rpc.Loggers, connecter transport.Connecter) {
+func (m *modePull) ConnectEndpoints(ctx context.Context, connecter transport.Connecter) {
 	m.setupMtx.Lock()
 	defer m.setupMtx.Unlock()
 	if m.receiver != nil || m.sender != nil {
 		panic("inconsistent use of ConnectEndpoints and DisconnectEndpoints")
 	}
 	m.receiver = endpoint.NewReceiver(m.receiverConfig)
-	m.sender = rpc.NewClient(connecter, loggers)
+	m.sender = rpc.NewClient(connecter, rpc.GetLoggersOrPanic(ctx))
 }
 
 func (m *modePull) DisconnectEndpoints() {
@@ -375,16 +377,31 @@ func (j *ActiveSide) SenderConfig() *endpoint.SenderConfig {
 	return push.senderConfig
 }
 
+// The active side of a replication uses one end (sender or receiver)
+// directly by method invocation, without going through a transport that
+// provides a client identity.
+// However, in order to avoid the need to distinguish between direct-method-invocating
+// clients and RPC client, we use an invalid client identity as a sentinel value.
+func FakeActiveSideDirectMethodInvocationClientIdentity(jobId endpoint.JobID) string {
+	return fmt.Sprintf("<local><active><job><client><identity><job=%q>", jobId.String())
+}
+
 func (j *ActiveSide) Run(ctx context.Context) {
+	ctx, endTask := trace.WithTaskAndSpan(ctx, "active-side-job", j.Name())
+	defer endTask()
+
+	ctx = context.WithValue(ctx, endpoint.ClientIdentityKey, FakeActiveSideDirectMethodInvocationClientIdentity(j.name))
+
 	log := GetLogger(ctx)
-	ctx = logging.WithSubsystemLoggers(ctx, log)
 
 	defer log.Info("job exiting")
 
 	periodicDone := make(chan struct{})
 	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
-	go j.mode.RunPeriodic(ctx, periodicDone)
+	periodicCtx, endTask := trace.WithTask(ctx, "periodic")
+	defer endTask()
+	go j.mode.RunPeriodic(periodicCtx, periodicDone)
 
 	invocationCount := 0
 outer:
@@ -400,17 +417,15 @@ outer:
 		case <-periodicDone:
 		}
 		invocationCount++
-		invLog := log.WithField("invocation", invocationCount)
+		invocationCtx, endSpan := trace.WithSpan(ctx, fmt.Sprintf("invocation-%d", invocationCount))
-		j.do(WithLogger(ctx, invLog))
+		j.do(invocationCtx)
+		endSpan()
 	}
 }
 
 func (j *ActiveSide) do(ctx context.Context) {
 
-	log := GetLogger(ctx)
+	j.mode.ConnectEndpoints(ctx, j.connecter)
-	ctx = logging.WithSubsystemLoggers(ctx, log)
-	loggers := rpc.GetLoggersOrPanic(ctx) // filled by WithSubsystemLoggers
-	j.mode.ConnectEndpoints(loggers, j.connecter)
 	defer j.mode.DisconnectEndpoints()
 
 	// allow cancellation of an invocation (this function)
@@ -433,20 +448,22 @@ func (j *ActiveSide) do(ctx context.Context) {
 			return
 		default:
 		}
+		ctx, endSpan := trace.WithSpan(ctx, "replication")
 		ctx, repCancel := context.WithCancel(ctx)
 		var repWait driver.WaitFunc
 		j.updateTasks(func(tasks *activeSideTasks) {
 			// reset it
 			*tasks = activeSideTasks{}
-			tasks.replicationCancel = repCancel
+			tasks.replicationCancel = func() { repCancel(); endSpan() }
 			tasks.replicationReport, repWait = replication.Do(
 				ctx, logic.NewPlanner(j.promRepStateSecs, j.promBytesReplicated, sender, receiver, j.mode.PlannerPolicy()),
 			)
 			tasks.state = ActiveSideReplicating
 		})
-		log.Info("start replication")
+		GetLogger(ctx).Info("start replication")
 		repWait(true) // wait blocking
 		repCancel()   // always cancel to free up context resources
+		endSpan()
 	}
 
 	{
@@ -455,16 +472,18 @@ func (j *ActiveSide) do(ctx context.Context) {
 			return
 		default:
 		}
+		ctx, endSpan := trace.WithSpan(ctx, "prune_sender")
 		ctx, senderCancel := context.WithCancel(ctx)
 		tasks := j.updateTasks(func(tasks *activeSideTasks) {
 			tasks.prunerSender = j.prunerFactory.BuildSenderPruner(ctx, sender, sender)
-			tasks.prunerSenderCancel = senderCancel
+			tasks.prunerSenderCancel = func() { senderCancel(); endSpan() }
 			tasks.state = ActiveSidePruneSender
 		})
-		log.Info("start pruning sender")
+		GetLogger(ctx).Info("start pruning sender")
 		tasks.prunerSender.Prune()
-		log.Info("finished pruning sender")
+		GetLogger(ctx).Info("finished pruning sender")
 		senderCancel()
+		endSpan()
 	}
 	{
 		select {
@@ -472,16 +491,18 @@ func (j *ActiveSide) do(ctx context.Context) {
 			return
 		default:
 		}
+		ctx, endSpan := trace.WithSpan(ctx, "prune_recever")
 		ctx, receiverCancel := context.WithCancel(ctx)
 		tasks := j.updateTasks(func(tasks *activeSideTasks) {
 			tasks.prunerReceiver = j.prunerFactory.BuildReceiverPruner(ctx, receiver, sender)
-			tasks.prunerReceiverCancel = receiverCancel
+			tasks.prunerReceiverCancel = func() { receiverCancel(); endSpan() }
 			tasks.state = ActiveSidePruneReceiver
 		})
-		log.Info("start pruning receiver")
+		GetLogger(ctx).Info("start pruning receiver")
 		tasks.prunerReceiver.Prune()
-		log.Info("finished pruning receiver")
+		GetLogger(ctx).Info("finished pruning receiver")
 		receiverCancel()
+		endSpan()
 	}
 
 	j.updateTasks(func(tasks *activeSideTasks) {

daemon/job/active_test.go

@@ -0,0 +1,19 @@
+package job
+
+import (
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"github.com/zrepl/zrepl/endpoint"
+	"github.com/zrepl/zrepl/transport"
+)
+
+func TestFakeActiveSideDirectMethodInvocationClientIdentityDoesNotPassValidityTest(t *testing.T) {
+	jobid, err := endpoint.MakeJobID("validjobname")
+	require.NoError(t, err)
+	clientIdentity := FakeActiveSideDirectMethodInvocationClientIdentity(jobid)
+	t.Logf("%v", clientIdentity)
+	err = transport.ValidateClientIdentity(clientIdentity)
+	assert.Error(t, err)
+}

daemon/job/job.go

@@ -7,6 +7,7 @@ import (
 
 	"github.com/prometheus/client_golang/prometheus"
 
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/endpoint"
 	"github.com/zrepl/zrepl/logger"
 	"github.com/zrepl/zrepl/zfs"
@@ -14,21 +15,8 @@ import (
 
 type Logger = logger.Logger
 
-type contextKey int
-
-const (
-	contextKeyLog contextKey = iota
-)
-
 func GetLogger(ctx context.Context) Logger {
-	if l, ok := ctx.Value(contextKeyLog).(Logger); ok {
+	return logging.GetLogger(ctx, logging.SubsysJob)
-		return l
-	}
-	return logger.NewNullLogger()
-}
-
-func WithLogger(ctx context.Context, l Logger) context.Context {
-	return context.WithValue(ctx, contextKeyLog, l)
 }
 
 type Job interface {

daemon/job/passive.go

@@ -6,6 +6,7 @@ import (
 
 	"github.com/pkg/errors"
 	"github.com/prometheus/client_golang/prometheus"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/filters"
@@ -78,9 +79,10 @@ func modeSourceFromConfig(g *config.Global, in *config.SourceJob, jobID endpoint
 		return nil, errors.Wrap(err, "cannot build filesystem filter")
 	}
 	m.senderConfig = &endpoint.SenderConfig{
-		FSF:     fsf,
+		FSF:                         fsf,
-		Encrypt: &zfs.NilBool{B: in.Send.Encrypted},
+		Encrypt:                     &zfs.NilBool{B: in.Send.Encrypted},
-		JobID:   jobID,
+		DisableIncrementalStepHolds: in.Send.StepHolds.DisableIncremental,
+		JobID:                       jobID,
 	}
 
 	if m.snapper, err = snapper.FromConfig(g, fsf, in.Snapshotting); err != nil {
@@ -164,12 +166,14 @@ func (j *PassiveSide) SenderConfig() *endpoint.SenderConfig {
 func (*PassiveSide) RegisterMetrics(registerer prometheus.Registerer) {}
 
 func (j *PassiveSide) Run(ctx context.Context) {
-
+	ctx, endTask := trace.WithTaskAndSpan(ctx, "passive-side-job", j.Name())
+	defer endTask()
 	log := GetLogger(ctx)
 	defer log.Info("job exiting")
-	ctx = logging.WithSubsystemLoggers(ctx, log)
 	{
-		ctx, cancel := context.WithCancel(ctx) // shadowing
+		ctx, endTask := trace.WithTask(ctx, "periodic") // shadowing
+		defer endTask()
+		ctx, cancel := context.WithCancel(ctx)
 		defer cancel()
 		go j.mode.RunPeriodic(ctx)
 	}
@@ -179,8 +183,14 @@ func (j *PassiveSide) Run(ctx context.Context) {
 		panic(fmt.Sprintf("implementation error: j.mode.Handler() returned nil: %#v", j))
 	}
 
-	ctxInterceptor := func(handlerCtx context.Context) context.Context {
+	ctxInterceptor := func(handlerCtx context.Context, info rpc.HandlerContextInterceptorData, handler func(ctx context.Context)) {
-		return logging.WithSubsystemLoggers(handlerCtx, log)
+		// the handlerCtx is clean => need to inherit logging and tracing config from job context
+		handlerCtx = logging.WithInherit(handlerCtx, ctx)
+		handlerCtx = trace.WithInherit(handlerCtx, ctx)
+
+		handlerCtx, endTask := trace.WithTaskAndSpan(handlerCtx, "handler", fmt.Sprintf("job=%q client=%q method=%q", j.Name(), info.ClientIdentity(), info.FullMethod()))
+		defer endTask()
+		handler(handlerCtx)
 	}
 
 	rpcLoggers := rpc.GetLoggersOrPanic(ctx) // WithSubsystemLoggers above

daemon/job/snapjob.go

@@ -2,15 +2,16 @@ package job
 
 import (
 	"context"
+	"fmt"
 	"sort"
 
 	"github.com/pkg/errors"
 	"github.com/prometheus/client_golang/prometheus"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/filters"
 	"github.com/zrepl/zrepl/daemon/job/wakeup"
-	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/daemon/pruner"
 	"github.com/zrepl/zrepl/daemon/snapper"
 	"github.com/zrepl/zrepl/endpoint"
@@ -89,15 +90,18 @@ func (j *SnapJob) OwnedDatasetSubtreeRoot() (rfs *zfs.DatasetPath, ok bool) {
 func (j *SnapJob) SenderConfig() *endpoint.SenderConfig { return nil }
 
 func (j *SnapJob) Run(ctx context.Context) {
+	ctx, endTask := trace.WithTaskAndSpan(ctx, "snap-job", j.Name())
+	defer endTask()
 	log := GetLogger(ctx)
-	ctx = logging.WithSubsystemLoggers(ctx, log)
 
 	defer log.Info("job exiting")
 
 	periodicDone := make(chan struct{})
 	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
-	go j.snapper.Run(ctx, periodicDone)
+	periodicCtx, endTask := trace.WithTask(ctx, "snapshotting")
+	defer endTask()
+	go j.snapper.Run(periodicCtx, periodicDone)
 
 	invocationCount := 0
 outer:
@@ -112,8 +116,10 @@ outer:
 		case <-periodicDone:
 		}
 		invocationCount++
-		invLog := log.WithField("invocation", invocationCount)
+
-		j.doPrune(WithLogger(ctx, invLog))
+		invocationCtx, endSpan := trace.WithSpan(ctx, fmt.Sprintf("invocation-%d", invocationCount))
+		j.doPrune(invocationCtx)
+		endSpan()
 	}
 }
 
@@ -161,13 +167,16 @@ func (h alwaysUpToDateReplicationCursorHistory) ListFilesystems(ctx context.Cont
 }
 
 func (j *SnapJob) doPrune(ctx context.Context) {
+	ctx, endSpan := trace.WithSpan(ctx, "snap-job-do-prune")
+	defer endSpan()
 	log := GetLogger(ctx)
-	ctx = logging.WithSubsystemLoggers(ctx, log)
 	sender := endpoint.NewSender(endpoint.SenderConfig{
 		JobID: j.name,
 		FSF:   j.fsfilter,
 		// FIXME encryption setting is irrelevant for SnapJob because the endpoint is only used as pruner.Target
 		Encrypt: &zfs.NilBool{B: true},
+		// FIXME DisableIncrementalStepHolds setting is irrelevant for SnapJob because the endpoint is only used as pruner.Target
+		DisableIncrementalStepHolds: false,
 	})
 	j.pruner = j.prunerFactory.BuildLocalPruner(ctx, sender, alwaysUpToDateReplicationCursorHistory{sender})
 	log.Info("start pruning")

daemon/logging/build_logging.go

@@ -9,20 +9,10 @@ import (
 
 	"github.com/mattn/go-isatty"
 	"github.com/pkg/errors"
-
 	"github.com/zrepl/zrepl/config"
-	"github.com/zrepl/zrepl/daemon/hooks"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
-	"github.com/zrepl/zrepl/daemon/pruner"
-	"github.com/zrepl/zrepl/daemon/snapper"
-	"github.com/zrepl/zrepl/endpoint"
 	"github.com/zrepl/zrepl/logger"
-	"github.com/zrepl/zrepl/replication/driver"
-	"github.com/zrepl/zrepl/replication/logic"
-	"github.com/zrepl/zrepl/rpc"
-	"github.com/zrepl/zrepl/rpc/transportmux"
 	"github.com/zrepl/zrepl/tlsconf"
-	"github.com/zrepl/zrepl/transport"
-	"github.com/zrepl/zrepl/zfs/zfscmd"
 )
 
 func OutletsFromConfig(in config.LoggingOutletEnumList) (*logger.Outlets, error) {
@@ -70,6 +60,8 @@ func OutletsFromConfig(in config.LoggingOutletEnumList) (*logger.Outlets, error)
 type Subsystem string
 
 const (
+	SubsysMeta         Subsystem = "meta"
+	SubsysJob          Subsystem = "job"
 	SubsysReplication  Subsystem = "repl"
 	SubsysEndpoint     Subsystem = "endpoint"
 	SubsysPruning      Subsystem = "pruning"
@@ -81,30 +73,103 @@ const (
 	SubsysRPCControl   Subsystem = "rpc.ctrl"
 	SubsysRPCData      Subsystem = "rpc.data"
 	SubsysZFSCmd       Subsystem = "zfs.cmd"
+	SubsysTraceData    Subsystem = "trace.data"
+	SubsysPlatformtest Subsystem = "platformtest"
 )
 
-func WithSubsystemLoggers(ctx context.Context, log logger.Logger) context.Context {
+var AllSubsystems = []Subsystem{
-	ctx = logic.WithLogger(ctx, log.WithField(SubsysField, SubsysReplication))
+	SubsysMeta,
-	ctx = driver.WithLogger(ctx, log.WithField(SubsysField, SubsysReplication))
+	SubsysJob,
-	ctx = endpoint.WithLogger(ctx, log.WithField(SubsysField, SubsysEndpoint))
+	SubsysReplication,
-	ctx = pruner.WithLogger(ctx, log.WithField(SubsysField, SubsysPruning))
+	SubsysEndpoint,
-	ctx = snapper.WithLogger(ctx, log.WithField(SubsysField, SubsysSnapshot))
+	SubsysPruning,
-	ctx = hooks.WithLogger(ctx, log.WithField(SubsysField, SubsysHooks))
+	SubsysSnapshot,
-	ctx = transport.WithLogger(ctx, log.WithField(SubsysField, SubsysTransport))
+	SubsysHooks,
-	ctx = transportmux.WithLogger(ctx, log.WithField(SubsysField, SubsysTransportMux))
+	SubsysTransport,
-	ctx = zfscmd.WithLogger(ctx, log.WithField(SubsysField, SubsysZFSCmd))
+	SubsysTransportMux,
-	ctx = rpc.WithLoggers(ctx,
+	SubsysRPC,
-		rpc.Loggers{
+	SubsysRPCControl,
-			General: log.WithField(SubsysField, SubsysRPC),
+	SubsysRPCData,
-			Control: log.WithField(SubsysField, SubsysRPCControl),
+	SubsysZFSCmd,
-			Data:    log.WithField(SubsysField, SubsysRPCData),
+	SubsysTraceData,
-		},
+	SubsysPlatformtest,
-	)
-	return ctx
 }
 
-func LogSubsystem(log logger.Logger, subsys Subsystem) logger.Logger {
+type injectedField struct {
-	return log.ReplaceField(SubsysField, subsys)
+	field  string
+	value  interface{}
+	parent *injectedField
+}
+
+func WithInjectedField(ctx context.Context, field string, value interface{}) context.Context {
+	var parent *injectedField
+	parentI := ctx.Value(contextKeyInjectedField)
+	if parentI != nil {
+		parent = parentI.(*injectedField)
+	}
+	// TODO sanity-check `field` now
+	this := &injectedField{field, value, parent}
+	return context.WithValue(ctx, contextKeyInjectedField, this)
+}
+
+func iterInjectedFields(ctx context.Context, cb func(field string, value interface{})) {
+	injI := ctx.Value(contextKeyInjectedField)
+	if injI == nil {
+		return
+	}
+	inj := injI.(*injectedField)
+	for ; inj != nil; inj = inj.parent {
+		cb(inj.field, inj.value)
+	}
+}
+
+type SubsystemLoggers map[Subsystem]logger.Logger
+
+func SubsystemLoggersWithUniversalLogger(l logger.Logger) SubsystemLoggers {
+	loggers := make(SubsystemLoggers)
+	for _, s := range AllSubsystems {
+		loggers[s] = l
+	}
+	return loggers
+}
+
+func WithLoggers(ctx context.Context, loggers SubsystemLoggers) context.Context {
+	return context.WithValue(ctx, contextKeyLoggers, loggers)
+}
+
+func GetLoggers(ctx context.Context) SubsystemLoggers {
+	loggers, ok := ctx.Value(contextKeyLoggers).(SubsystemLoggers)
+	if !ok {
+		return nil
+	}
+	return loggers
+}
+
+func GetLogger(ctx context.Context, subsys Subsystem) logger.Logger {
+	return getLoggerImpl(ctx, subsys, true)
+}
+
+func getLoggerImpl(ctx context.Context, subsys Subsystem, panicIfEnded bool) logger.Logger {
+	loggers, ok := ctx.Value(contextKeyLoggers).(SubsystemLoggers)
+	if !ok || loggers == nil {
+		return logger.NewNullLogger()
+	}
+	l, ok := loggers[subsys]
+	if !ok {
+		return logger.NewNullLogger()
+	}
+
+	l = l.WithField(SubsysField, subsys)
+
+	l = l.WithField(SpanField, trace.GetSpanStackOrDefault(ctx, *trace.StackKindId, "NOSPAN"))
+
+	fields := make(logger.Fields)
+	iterInjectedFields(ctx, func(field string, value interface{}) {
+		fields[field] = value
+	})
+	l = l.WithFields(fields)
+
+	return l
 }
 
 func parseLogFormat(i interface{}) (f EntryFormatter, err error) {

daemon/logging/logging_context.go

@@ -0,0 +1,24 @@
+package logging
+
+import "context"
+
+type contextKey int
+
+const (
+	contextKeyLoggers contextKey = 1 + iota
+	contextKeyInjectedField
+)
+
+var contextKeys = []contextKey{
+	contextKeyLoggers,
+	contextKeyInjectedField,
+}
+
+func WithInherit(ctx, inheritFrom context.Context) context.Context {
+	for _, k := range contextKeys {
+		if v := inheritFrom.Value(k); v != nil {
+			ctx = context.WithValue(ctx, k, v) // no shadow
+		}
+	}
+	return ctx
+}

daemon/logging/logging_formatters.go

@@ -22,6 +22,7 @@ const (
 const (
 	JobField    string = "job"
 	SubsysField string = "subsystem"
+	SpanField   string = "span"
 )
 
 type MetadataFlags int64
@@ -85,7 +86,7 @@ func (f *HumanFormatter) Format(e *logger.Entry) (out []byte, err error) {
 		fmt.Fprintf(&line, "[%s]", col.Sprint(e.Level.Short()))
 	}
 
-	prefixFields := []string{JobField, SubsysField}
+	prefixFields := []string{JobField, SubsysField, SpanField}
 	prefixed := make(map[string]bool, len(prefixFields)+2)
 	for _, field := range prefixFields {
 		val, ok := e.Fields[field]
@@ -174,8 +175,8 @@ func (f *LogfmtFormatter) Format(e *logger.Entry) ([]byte, error) {
 	}
 
 	// at least try and put job and task in front
-	prefixed := make(map[string]bool, 2)
+	prefixed := make(map[string]bool, 3)
-	prefix := []string{JobField, SubsysField}
+	prefix := []string{JobField, SubsysField, SpanField}
 	for _, pf := range prefix {
 		v, ok := e.Fields[pf]
 		if !ok {

daemon/logging/trace/trace.go

@@ -0,0 +1,386 @@
+// package trace provides activity tracing via ctx through Tasks and Spans
+//
+// Basic Concepts
+//
+// Tracing can be used to identify where a piece of code spends its time.
+//
+// The Go standard library provides package runtime/trace which is useful to identify CPU bottlenecks or
+// to understand what happens inside the Go runtime.
+// However, it is not ideal for application level tracing, in particular if those traces should be understandable
+// to tech-savvy users (albeit not developers).
+//
+// This package provides the concept of Tasks and Spans to express what activity is happening within an application:
+//
+//  - Neither task nor span is really tangible but instead contained within the context.Context tree
+//  - Tasks represent concurrent activity (i.e. goroutines).
+//  - Spans represent a semantic stack trace within a task.
+//
+// As a consequence, whenever a context is propagated across goroutine boundary, you need to create a child task:
+//
+//   go func(ctx context.Context) {
+//     ctx, endTask = WithTask(ctx, "what-happens-inside-the-child-task")
+//     defer endTask()
+//     // ...
+//   }(ctx)
+//
+// Within the task, you can open up a hierarchy of spans.
+// In contrast to tasks, which have can multiple concurrently running child tasks,
+// spans must nest and not cross the goroutine boundary.
+//
+//  ctx, endSpan = WithSpan(ctx, "copy-dir")
+//  defer endSpan()
+//  for _, f := range dir.Files() {
+//    func() {
+//      ctx, endSpan := WithSpan(ctx, fmt.Sprintf("copy-file %q", f))
+//      defer endspan()
+//      b, _ := ioutil.ReadFile(f)
+//      _ = ioutil.WriteFile(f + ".copy", b, 0600)
+//    }()
+//  }
+//
+// In combination:
+//  ctx, endTask = WithTask(ctx, "copy-dirs")
+//  defer endTask()
+//  for i := range dirs {
+//    go func(dir string) {
+//      ctx, endTask := WithTask(ctx, "copy-dir")
+//      defer endTask()
+//      for _, f := range filesIn(dir) {
+//        func() {
+//          ctx, endSpan := WithSpan(ctx, fmt.Sprintf("copy-file %q", f))
+//          defer endspan()
+//          b, _ := ioutil.ReadFile(f)
+//          _ = ioutil.WriteFile(f + ".copy", b, 0600)
+//        }()
+//      }
+//    }()
+//  }
+//
+// Note that a span ends at the time you call endSpan - not before and not after that.
+// If you violate the stack-like nesting of spans by forgetting an endSpan() invocation,
+// the out-of-order endSpan() will panic.
+//
+// A similar rule applies to the endTask closure returned by WithTask:
+// If a task has live child tasks at the time you call endTask(), the call will panic.
+//
+// Recovering from endSpan() or endTask() panics will corrupt the trace stack and lead to corrupt tracefile output.
+//
+//
+// Best Practices For Naming Tasks And Spans
+//
+// Tasks should always have string constants as names, and must not contain the `#` character. WHy?
+// First, the visualization by chrome://tracing draws a horizontal bar for each task in the trace.
+// Also, the package appends `#NUM` for each concurrently running instance of a task name.
+// Note that the `#NUM` suffix will be reused if a task has ended, in order to avoid an
+// infinite number of horizontal bars in the visualization.
+//
+//
+// Chrome-compatible Tracefile Support
+//
+// The activity trace generated by usage of WithTask and WithSpan can be rendered to a JSON output file
+// that can be loaded into chrome://tracing .
+// Apart from function GetSpanStackOrDefault, this is the main benefit of this package.
+//
+// First, there is a convenience environment variable 'ZREPL_ACTIVITY_TRACE' that can be set to an output path.
+// From process start onward, a trace is written to that path.
+//
+// More consumers can attach to the activity trace through the ChrometraceClientWebsocketHandler websocket handler.
+//
+// If a write error is encountered with any consumer (including the env-var based one), the consumer is closed and
+// will not receive further trace output.
+package trace
+
+import (
+	"context"
+	"fmt"
+	"strings"
+	"time"
+
+	"github.com/pkg/errors"
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/zrepl/zrepl/util/chainlock"
+)
+
+var metrics struct {
+	activeTasks prometheus.Gauge
+}
+var taskNamer *uniqueConcurrentTaskNamer = newUniqueTaskNamer()
+
+func init() {
+	metrics.activeTasks = prometheus.NewGauge(prometheus.GaugeOpts{
+		Namespace: "zrepl",
+		Subsystem: "trace",
+		Name:      "active_tasks",
+		Help:      "number of active (tracing-level) tasks in the daemon",
+	})
+}
+
+func RegisterMetrics(r prometheus.Registerer) {
+	r.MustRegister(metrics.activeTasks)
+}
+
+type traceNode struct {
+	id         string
+	annotation string
+	parentTask *traceNode
+
+	mtx chainlock.L
+
+	activeChildTasks int32 // only for task nodes, insignificant for span nodes
+	parentSpan       *traceNode
+	activeChildSpan  *traceNode // nil if task or span doesn't have an active child span
+
+	startedAt time.Time
+	endedAt   time.Time
+}
+
+func (s *traceNode) StartedAt() time.Time { return s.startedAt }
+func (s *traceNode) EndedAt() time.Time   { return s.endedAt }
+
+// Returned from WithTask or WithSpan.
+// Must be called once the task or span ends.
+// See package-level docs for nesting rules.
+// Wrong call order / forgetting to call it will result in panics.
+type DoneFunc func()
+
+var ErrTaskStillHasActiveChildTasks = fmt.Errorf("end task: task still has active child tasks")
+
+// Start a new root task or create a child task of an existing task.
+//
+// This is required when starting a new goroutine and
+// passing an existing task context to it.
+//
+// taskName should be a constantand must not contain '#'
+//
+// The implementation ensures that,
+// if multiple tasks with the same name exist simultaneously,
+// a unique suffix is appended to uniquely identify the task opened with this function.
+func WithTask(ctx context.Context, taskName string) (context.Context, DoneFunc) {
+
+	var parentTask *traceNode
+	nodeI := ctx.Value(contextKeyTraceNode)
+	if nodeI != nil {
+		node := nodeI.(*traceNode)
+		if node.parentSpan != nil {
+			parentTask = node.parentTask
+		} else {
+			parentTask = node
+		}
+	}
+	// find the first ancestor that hasn't ended yet (nil if need be)
+	if parentTask != nil {
+		parentTask.mtx.Lock()
+	}
+	for parentTask != nil && !parentTask.endedAt.IsZero() {
+		thisParent := parentTask
+		parentTask = parentTask.parentTask
+		// lock parent first such that it isn't modified by other callers to thisParent
+		if parentTask != nil {
+			parentTask.mtx.Lock()
+		}
+		thisParent.mtx.Unlock()
+	}
+	// invariant: either parentTask != nil and we hold the lock on parentTask, or parentTask is nil
+
+	taskName, taskNameDone := taskNamer.UniqueConcurrentTaskName(taskName)
+
+	this := &traceNode{
+		id:               genID(),
+		annotation:       taskName,
+		parentTask:       parentTask,
+		activeChildTasks: 0,
+		parentSpan:       nil,
+		activeChildSpan:  nil,
+
+		startedAt: time.Now(),
+		endedAt:   time.Time{},
+	}
+
+	if parentTask != nil {
+		this.parentTask.activeChildTasks++
+		parentTask.mtx.Unlock()
+	}
+
+	ctx = context.WithValue(ctx, contextKeyTraceNode, this)
+
+	chrometraceBeginTask(this)
+
+	metrics.activeTasks.Inc()
+
+	endTaskFunc := func() {
+
+		// only hold locks while manipulating the tree
+		// (trace writer might block too long and unlike spans, tasks are updated concurrently)
+		alreadyEnded := func() (alreadyEnded bool) {
+			if this.parentTask != nil {
+				defer this.parentTask.mtx.Lock().Unlock()
+			}
+			defer this.mtx.Lock().Unlock()
+
+			if this.activeChildTasks != 0 {
+				panic(errors.Wrapf(ErrTaskStillHasActiveChildTasks, "end task: %v active child tasks", this.activeChildTasks))
+			}
+
+			// support idempotent task ends
+			if !this.endedAt.IsZero() {
+				return true
+			}
+			this.endedAt = time.Now()
+
+			if this.parentTask != nil {
+				this.parentTask.activeChildTasks--
+				if this.parentTask.activeChildTasks < 0 {
+					panic("impl error: parent task with negative activeChildTasks count")
+				}
+			}
+			return false
+		}()
+		if alreadyEnded {
+			return
+		}
+
+		chrometraceEndTask(this)
+
+		metrics.activeTasks.Dec()
+
+		taskNameDone()
+	}
+
+	return ctx, endTaskFunc
+}
+
+var ErrAlreadyActiveChildSpan = fmt.Errorf("create child span: span already has an active child span")
+var ErrSpanStillHasActiveChildSpan = fmt.Errorf("end span: span still has active child spans")
+
+// Start a new span.
+// Important: ctx must have an active task (see WithTask)
+func WithSpan(ctx context.Context, annotation string) (context.Context, DoneFunc) {
+	var parentSpan, parentTask *traceNode
+	nodeI := ctx.Value(contextKeyTraceNode)
+	if nodeI != nil {
+		parentSpan = nodeI.(*traceNode)
+		if parentSpan.parentSpan == nil {
+			parentTask = parentSpan
+		} else {
+			parentTask = parentSpan.parentTask
+		}
+	} else {
+		panic("must be called from within a task")
+	}
+
+	this := &traceNode{
+		id:              genID(),
+		annotation:      annotation,
+		parentTask:      parentTask,
+		parentSpan:      parentSpan,
+		activeChildSpan: nil,
+
+		startedAt: time.Now(),
+		endedAt:   time.Time{},
+	}
+
+	parentSpan.mtx.HoldWhile(func() {
+		if parentSpan.activeChildSpan != nil {
+			panic(ErrAlreadyActiveChildSpan)
+		}
+		parentSpan.activeChildSpan = this
+	})
+
+	ctx = context.WithValue(ctx, contextKeyTraceNode, this)
+	chrometraceBeginSpan(this)
+	callbackEndSpan := callbackBeginSpan(ctx)
+
+	endTaskFunc := func() {
+
+		defer parentSpan.mtx.Lock().Unlock()
+		if parentSpan.activeChildSpan != this && this.endedAt.IsZero() {
+			panic("impl error: activeChildSpan should not change while != nil because there can only be one")
+		}
+
+		defer this.mtx.Lock().Unlock()
+		if this.activeChildSpan != nil {
+			panic(ErrSpanStillHasActiveChildSpan)
+		}
+
+		if !this.endedAt.IsZero() {
+			return // support idempotent span ends
+		}
+
+		parentSpan.activeChildSpan = nil
+		this.endedAt = time.Now()
+
+		chrometraceEndSpan(this)
+		callbackEndSpan(this)
+	}
+
+	return ctx, endTaskFunc
+}
+
+type StackKind struct {
+	symbolizeTask func(t *traceNode) string
+	symbolizeSpan func(s *traceNode) string
+}
+
+var (
+	StackKindId = &StackKind{
+		symbolizeTask: func(t *traceNode) string { return t.id },
+		symbolizeSpan: func(s *traceNode) string { return s.id },
+	}
+	SpanStackKindCombined = &StackKind{
+		symbolizeTask: func(t *traceNode) string { return fmt.Sprintf("(%s %q)", t.id, t.annotation) },
+		symbolizeSpan: func(s *traceNode) string { return fmt.Sprintf("(%s %q)", s.id, s.annotation) },
+	}
+	SpanStackKindAnnotation = &StackKind{
+		symbolizeTask: func(t *traceNode) string { return t.annotation },
+		symbolizeSpan: func(s *traceNode) string { return s.annotation },
+	}
+)
+
+func (n *traceNode) task() *traceNode {
+	task := n.parentTask
+	if n.parentSpan == nil {
+		task = n
+	}
+	return task
+}
+
+func (n *traceNode) TaskName() string {
+	task := n.task()
+	return task.annotation
+}
+
+func (this *traceNode) TaskAndSpanStack(kind *StackKind) (spanIdStack string) {
+	task := this.task()
+
+	var spansInTask []*traceNode
+	for s := this; s != nil; s = s.parentSpan {
+		spansInTask = append(spansInTask, s)
+	}
+
+	var tasks []*traceNode
+	for t := task; t != nil; t = t.parentTask {
+		tasks = append(tasks, t)
+	}
+
+	var taskIdsRev []string
+	for i := len(tasks) - 1; i >= 0; i-- {
+		taskIdsRev = append(taskIdsRev, kind.symbolizeTask(tasks[i]))
+	}
+
+	var spanIdsRev []string
+	for i := len(spansInTask) - 1; i >= 0; i-- {
+		spanIdsRev = append(spanIdsRev, kind.symbolizeSpan(spansInTask[i]))
+	}
+
+	taskStack := strings.Join(taskIdsRev, "$")
+	return fmt.Sprintf("%s$%s", taskStack, strings.Join(spanIdsRev, "."))
+}
+
+func GetSpanStackOrDefault(ctx context.Context, kind StackKind, def string) string {
+	if nI := ctx.Value(contextKeyTraceNode); nI != nil {
+		n := nI.(*traceNode)
+		return n.TaskAndSpanStack(StackKindId)
+	} else {
+		return def
+	}
+}

daemon/logging/trace/trace_callback.go

@@ -0,0 +1,54 @@
+package trace
+
+import (
+	"context"
+	"time"
+
+	"github.com/zrepl/zrepl/util/chainlock"
+)
+
+type SpanInfo interface {
+	StartedAt() time.Time
+	EndedAt() time.Time
+	TaskAndSpanStack(kind *StackKind) string
+}
+
+type Callback struct {
+	OnBegin func(ctx context.Context)
+	OnEnd   func(ctx context.Context, spanInfo SpanInfo)
+}
+
+var callbacks struct {
+	mtx chainlock.L
+	cs  []Callback
+}
+
+func RegisterCallback(c Callback) {
+	callbacks.mtx.HoldWhile(func() {
+		callbacks.cs = append(callbacks.cs, c)
+	})
+}
+
+func callbackBeginSpan(ctx context.Context) func(SpanInfo) {
+	// capture the current state of callbacks into a local variable
+	// this is safe because the slice is append-only and immutable
+
+	// (it is important that a callback registered _after_ callbackBeginSpin is called does not get called on OnEnd)
+
+	var cbs []Callback
+	callbacks.mtx.HoldWhile(func() {
+		cbs = callbacks.cs
+	})
+	for _, cb := range cbs {
+		if cb.OnBegin != nil {
+			cb.OnBegin(ctx)
+		}
+	}
+	return func(spanInfo SpanInfo) {
+		for _, cb := range cbs {
+			if cb.OnEnd != nil {
+				cb.OnEnd(ctx, spanInfo)
+			}
+		}
+	}
+}

daemon/logging/trace/trace_chrometrace.go

@@ -0,0 +1,230 @@
+package trace
+
+// The functions in this file are concerned with the generation
+// of trace files based on the information from WithTask and WithSpan.
+//
+// The emitted trace files are open-ended array of JSON objects
+// that follow the Chrome trace file format:
+//   https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
+//
+// The emitted JSON can be loaded into Chrome's chrome://tracing view.
+//
+// The trace file can be written to a file whose path is specified in an env file,
+// and be written to web sockets established on ChrometraceHttpHandler
+
+import (
+	"bufio"
+	"bytes"
+	"encoding/json"
+	"fmt"
+	"io"
+	"os"
+	"sync"
+	"sync/atomic"
+
+	"golang.org/x/net/websocket"
+
+	"github.com/zrepl/zrepl/util/envconst"
+)
+
+var chrometracePID string
+
+func init() {
+	var err error
+	chrometracePID, err = os.Hostname()
+	if err != nil {
+		panic(err)
+	}
+	chrometracePID = fmt.Sprintf("%q", chrometracePID)
+}
+
+type chrometraceEvent struct {
+	Cat                       string   `json:"cat,omitempty"`
+	Name                      string   `json:"name"`
+	Stack                     []string `json:"stack,omitempty"`
+	Phase                     string   `json:"ph"`
+	TimestampUnixMicroseconds int64    `json:"ts"`
+	DurationMicroseconds      int64    `json:"dur,omitempty"`
+	Pid                       string   `json:"pid"`
+	Tid                       string   `json:"tid"`
+	Id                        string   `json:"id,omitempty"`
+}
+
+func chrometraceBeginSpan(s *traceNode) {
+	taskName := s.TaskName()
+	chrometraceWrite(chrometraceEvent{
+		Name:                      s.annotation,
+		Phase:                     "B",
+		TimestampUnixMicroseconds: s.startedAt.UnixNano() / 1000,
+		Pid:                       chrometracePID,
+		Tid:                       taskName,
+	})
+}
+
+func chrometraceEndSpan(s *traceNode) {
+	taskName := s.TaskName()
+	chrometraceWrite(chrometraceEvent{
+		Name:                      s.annotation,
+		Phase:                     "E",
+		TimestampUnixMicroseconds: s.endedAt.UnixNano() / 1000,
+		Pid:                       chrometracePID,
+		Tid:                       taskName,
+	})
+}
+
+var chrometraceFlowId uint64
+
+func chrometraceBeginTask(s *traceNode) {
+	chrometraceBeginSpan(s)
+
+	if s.parentTask == nil {
+		return
+	}
+	// beginning of a task that has a parent
+	// => use flow events to link parent and child
+
+	flowId := atomic.AddUint64(&chrometraceFlowId, 1)
+	flowIdStr := fmt.Sprintf("%x", flowId)
+
+	parentTask := s.parentTask.TaskName()
+	chrometraceWrite(chrometraceEvent{
+		Cat:                       "task", // seems to be necessary, otherwise the GUI shows some `indexOf` JS error
+		Name:                      "child-task",
+		Phase:                     "s",
+		TimestampUnixMicroseconds: s.startedAt.UnixNano() / 1000, // yes, the child's timestamp (=> from-point of the flow line is at right x-position of parent's bar)
+		Pid:                       chrometracePID,
+		Tid:                       parentTask,
+		Id:                        flowIdStr,
+	})
+
+	childTask := s.TaskName()
+	if parentTask == childTask {
+		panic(parentTask)
+	}
+	chrometraceWrite(chrometraceEvent{
+		Cat:                       "task", // seems to be necessary, otherwise the GUI shows some `indexOf` JS error
+		Name:                      "child-task",
+		Phase:                     "f",
+		TimestampUnixMicroseconds: s.startedAt.UnixNano() / 1000,
+		Pid:                       chrometracePID,
+		Tid:                       childTask,
+		Id:                        flowIdStr,
+	})
+}
+
+func chrometraceEndTask(s *traceNode) {
+	chrometraceEndSpan(s)
+}
+
+type chrometraceConsumerRegistration struct {
+	w io.Writer
+	// errored must have capacity 1, the writer thread will send to it non-blocking, then close it
+	errored chan error
+}
+
+var chrometraceConsumers struct {
+	register  chan chrometraceConsumerRegistration
+	consumers map[chrometraceConsumerRegistration]bool
+	write     chan []byte
+}
+
+func init() {
+	chrometraceConsumers.register = make(chan chrometraceConsumerRegistration)
+	chrometraceConsumers.consumers = make(map[chrometraceConsumerRegistration]bool)
+	chrometraceConsumers.write = make(chan []byte)
+	go func() {
+		kickConsumer := func(c chrometraceConsumerRegistration, err error) {
+			debug("chrometrace kicking consumer %#v after error %v", c, err)
+			select {
+			case c.errored <- err:
+			default:
+			}
+			close(c.errored)
+			delete(chrometraceConsumers.consumers, c)
+		}
+		for {
+			select {
+			case reg := <-chrometraceConsumers.register:
+				debug("registered chrometrace consumer %#v", reg)
+				chrometraceConsumers.consumers[reg] = true
+				n, err := reg.w.Write([]byte("[\n"))
+				if err != nil {
+					kickConsumer(reg, err)
+				} else if n != 2 {
+					kickConsumer(reg, fmt.Errorf("short write: %v", n))
+				}
+				// successfully registered
+
+			case buf := <-chrometraceConsumers.write:
+				debug("chrometrace write request: %s", string(buf))
+				var r bytes.Reader
+				for c := range chrometraceConsumers.consumers {
+					r.Reset(buf)
+					n, err := io.Copy(c.w, &r)
+					debug("chrometrace wrote n=%v bytes to consumer %#v", n, c)
+					if err != nil {
+						kickConsumer(c, err)
+					}
+				}
+			}
+		}
+	}()
+}
+
+func chrometraceWrite(i interface{}) {
+	var buf bytes.Buffer
+	err := json.NewEncoder(&buf).Encode(i)
+	if err != nil {
+		panic(err)
+	}
+	buf.WriteString(",")
+	chrometraceConsumers.write <- buf.Bytes()
+}
+
+func ChrometraceClientWebsocketHandler(conn *websocket.Conn) {
+	defer conn.Close()
+
+	var wg sync.WaitGroup
+	defer wg.Wait()
+	wg.Add(1)
+	go func() {
+		defer wg.Done()
+		r := bufio.NewReader(conn)
+		_, _, _ = r.ReadLine() // ignore errors
+		conn.Close()
+	}()
+
+	errored := make(chan error, 1)
+	chrometraceConsumers.register <- chrometraceConsumerRegistration{
+		w:       conn,
+		errored: errored,
+	}
+
+	wg.Add(1)
+	go func() {
+		defer wg.Done()
+		<-errored
+		conn.Close()
+	}()
+}
+
+var chrometraceFileConsumerPath = envconst.String("ZREPL_ACTIVITY_TRACE", "")
+
+func init() {
+	if chrometraceFileConsumerPath != "" {
+		var err error
+		f, err := os.Create(chrometraceFileConsumerPath)
+		if err != nil {
+			panic(err)
+		}
+		errored := make(chan error, 1)
+		chrometraceConsumers.register <- chrometraceConsumerRegistration{
+			w:       f,
+			errored: errored,
+		}
+		go func() {
+			<-errored
+			f.Close()
+		}()
+	}
+}

daemon/logging/trace/trace_context.go

@@ -0,0 +1,27 @@
+package trace
+
+import "context"
+
+type contextKey int
+
+const (
+	contextKeyTraceNode contextKey = 1 + iota
+)
+
+var contextKeys = []contextKey{
+	contextKeyTraceNode,
+}
+
+// WithInherit inherits the task hierarchy from inheritFrom into ctx.
+// The returned context is a child of ctx, but its task and span are those of inheritFrom.
+//
+// Note that in most use cases, callers most likely want to call WithTask since it will most likely
+// be in some sort of connection handler context.
+func WithInherit(ctx, inheritFrom context.Context) context.Context {
+	for _, k := range contextKeys {
+		if v := inheritFrom.Value(k); v != nil {
+			ctx = context.WithValue(ctx, k, v) // no shadow
+		}
+	}
+	return ctx
+}

daemon/logging/trace/trace_convenience.go

@@ -0,0 +1,74 @@
+package trace
+
+import (
+	"context"
+	"fmt"
+	"runtime"
+	"strings"
+	"sync"
+)
+
+// use like this:
+//
+//	defer WithSpanFromStackUpdateCtx(&existingCtx)()
+//
+//
+func WithSpanFromStackUpdateCtx(ctx *context.Context) DoneFunc {
+	childSpanCtx, end := WithSpan(*ctx, getMyCallerOrPanic())
+	*ctx = childSpanCtx
+	return end
+}
+
+// derive task name from call stack (caller's name)
+func WithTaskFromStack(ctx context.Context) (context.Context, DoneFunc) {
+	return WithTask(ctx, getMyCallerOrPanic())
+}
+
+// derive task name from call stack (caller's name) and update *ctx
+// to point to be the child task ctx
+func WithTaskFromStackUpdateCtx(ctx *context.Context) DoneFunc {
+	child, end := WithTask(*ctx, getMyCallerOrPanic())
+	*ctx = child
+	return end
+}
+
+// create a task and a span within it in one call
+func WithTaskAndSpan(ctx context.Context, task string, span string) (context.Context, DoneFunc) {
+	ctx, endTask := WithTask(ctx, task)
+	ctx, endSpan := WithSpan(ctx, fmt.Sprintf("%s %s", task, span))
+	return ctx, func() {
+		endSpan()
+		endTask()
+	}
+}
+
+// create a span during which several child tasks are spawned using the `add` function
+func WithTaskGroup(ctx context.Context, taskGroup string) (_ context.Context, add func(f func(context.Context)), waitEnd DoneFunc) {
+	var wg sync.WaitGroup
+	ctx, endSpan := WithSpan(ctx, taskGroup)
+	add = func(f func(context.Context)) {
+		wg.Add(1)
+		defer wg.Done()
+		ctx, endTask := WithTask(ctx, taskGroup)
+		defer endTask()
+		f(ctx)
+	}
+	waitEnd = func() {
+		wg.Wait()
+		endSpan()
+	}
+	return ctx, add, waitEnd
+}
+
+func getMyCallerOrPanic() string {
+	pc, _, _, ok := runtime.Caller(2)
+	if !ok {
+		panic("cannot get caller")
+	}
+	details := runtime.FuncForPC(pc)
+	if ok && details != nil {
+		const prefix = "github.com/zrepl/zrepl"
+		return strings.TrimPrefix(strings.TrimPrefix(details.Name(), prefix), "/")
+	}
+	return ""
+}

daemon/logging/trace/trace_convenience_test.go

@@ -0,0 +1,16 @@
+package trace
+
+import (
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+)
+
+func TestGetCallerOrPanic(t *testing.T) {
+	withStackFromCtxMock := func() string {
+		return getMyCallerOrPanic()
+	}
+	ret := withStackFromCtxMock()
+	// zrepl prefix is stripped
+	assert.Equal(t, "daemon/logging/trace.TestGetCallerOrPanic", ret)
+}

daemon/logging/trace/trace_debug.go

@@ -0,0 +1,15 @@
+package trace
+
+import (
+	"fmt"
+	"os"
+)
+
+const debugEnabled = false
+
+func debug(format string, args ...interface{}) {
+	if !debugEnabled {
+		return
+	}
+	fmt.Fprintf(os.Stderr, format+"\n", args...)
+}

daemon/logging/trace/trace_genID.go

@@ -0,0 +1,47 @@
+package trace
+
+import (
+	"encoding/base64"
+	"math/rand"
+	"os"
+	"strings"
+	"time"
+
+	"github.com/zrepl/zrepl/util/envconst"
+)
+
+var genIdPRNG = rand.New(rand.NewSource(1))
+
+func init() {
+	genIdPRNG.Seed(time.Now().UnixNano())
+	genIdPRNG.Seed(int64(os.Getpid()))
+}
+
+var genIdNumBytes = envconst.Int("ZREPL_TRACE_ID_NUM_BYTES", 3)
+
+func init() {
+	if genIdNumBytes < 1 {
+		panic("trace node id byte length must be at least 1")
+	}
+}
+
+func genID() string {
+	var out strings.Builder
+	enc := base64.NewEncoder(base64.RawStdEncoding, &out)
+	buf := make([]byte, genIdNumBytes)
+	for i := 0; i < len(buf); {
+		n, err := genIdPRNG.Read(buf[i:])
+		if err != nil {
+			panic(err)
+		}
+		i += n
+	}
+	n, err := enc.Write(buf[:])
+	if err != nil || n != len(buf) {
+		panic(err)
+	}
+	if err := enc.Close(); err != nil {
+		panic(err)
+	}
+	return out.String()
+}

daemon/logging/trace/trace_test.go

@@ -0,0 +1,205 @@
+package trace
+
+import (
+	"context"
+	"fmt"
+	"testing"
+
+	"github.com/gitchander/permutation"
+	"github.com/pkg/errors"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestRegularSpanUsage(t *testing.T) {
+	root, endRoot := WithTask(context.Background(), "root")
+	defer endRoot()
+
+	s1, endS1 := WithSpan(root, "parent")
+	s2, endS2 := WithSpan(s1, "child")
+	_, endS3 := WithSpan(s2, "grand-child")
+	require.NotPanics(t, func() { endS3() })
+	require.NotPanics(t, func() { endS2() })
+
+	// reuse
+	_, endS4 := WithSpan(s1, "child-2")
+	require.NotPanics(t, func() { endS4() })
+
+	// close parent
+	require.NotPanics(t, func() { endS1() })
+}
+
+func TestMultipleActiveChildSpansNotAllowed(t *testing.T) {
+	root, endRoot := WithTask(context.Background(), "root")
+	defer endRoot()
+
+	s1, _ := WithSpan(root, "s1")
+	_, endS2 := WithSpan(s1, "s1-child1")
+
+	require.PanicsWithValue(t, ErrAlreadyActiveChildSpan, func() {
+		_, _ = WithSpan(s1, "s1-child2")
+	})
+
+	endS2()
+
+	require.NotPanics(t, func() {
+		_, _ = WithSpan(s1, "s1-child2")
+	})
+}
+
+func TestForkingChildSpansNotAllowed(t *testing.T) {
+	root, endRoot := WithTask(context.Background(), "root")
+	defer endRoot()
+
+	s1, _ := WithSpan(root, "s1")
+	sc, endSC := WithSpan(s1, "s1-child")
+	_, _ = WithSpan(sc, "s1-child-child")
+
+	require.PanicsWithValue(t, ErrSpanStillHasActiveChildSpan, func() {
+		endSC()
+	})
+}
+
+func TestRegularTaskUsage(t *testing.T) {
+	// assert concurrent activities on different tasks can end in any order
+	closeOrder := []int{0, 1, 2}
+	closeOrders := permutation.New(permutation.IntSlice(closeOrder))
+	for closeOrders.Next() {
+		t.Run(fmt.Sprintf("%v", closeOrder), func(t *testing.T) {
+			root, endRoot := WithTask(context.Background(), "root")
+			defer endRoot()
+
+			c1, endC1 := WithTask(root, "c1")
+			defer endC1()
+			c2, endC2 := WithTask(root, "c2")
+			defer endC2()
+
+			// begin 3 concurrent activities
+			_, endAR := WithSpan(root, "aR")
+			_, endAC1 := WithSpan(c1, "aC1")
+			_, endAC2 := WithSpan(c2, "aC2")
+
+			endFuncs := []DoneFunc{endAR, endAC1, endAC2}
+			for _, i := range closeOrder {
+				require.NotPanics(t, func() {
+					endFuncs[i]()
+				}, "%v", i)
+			}
+		})
+	}
+}
+
+func TestTaskEndWithActiveChildTaskNotAllowed(t *testing.T) {
+	root, _ := WithTask(context.Background(), "root")
+	c, endC := WithTask(root, "child")
+	_, _ = WithTask(c, "grand-child")
+	func() {
+		defer func() {
+			r := recover()
+			require.NotNil(t, r)
+			err, ok := r.(error)
+			require.True(t, ok)
+			require.Equal(t, ErrTaskStillHasActiveChildTasks, errors.Cause(err))
+		}()
+		endC()
+	}()
+
+}
+
+func TestIdempotentEndTask(t *testing.T) {
+	_, end := WithTask(context.Background(), "root")
+	end()
+	require.NotPanics(t, func() { end() })
+}
+
+func TestSpansPanicIfNoParentTask(t *testing.T) {
+	require.Panics(t, func() { WithSpan(context.Background(), "taskless-span") })
+}
+
+func TestIdempotentEndSpan(t *testing.T) {
+	root, _ := WithTask(context.Background(), "root")
+	_, end := WithSpan(root, "span")
+	end()
+	require.NotPanics(t, func() { end() })
+}
+
+func logAndGetTraceNode(t *testing.T, descr string, ctx context.Context) *traceNode {
+	n, ok := ctx.Value(contextKeyTraceNode).(*traceNode)
+	require.True(t, ok)
+	t.Logf("% 20s %p %#v", descr, n, n)
+	return n
+}
+
+func TestWhiteboxHierachy(t *testing.T) {
+	root, e1 := WithTask(context.Background(), "root")
+	rootN := logAndGetTraceNode(t, "root", root)
+	assert.Nil(t, rootN.parentTask)
+	assert.Nil(t, rootN.parentSpan)
+
+	child, e2 := WithSpan(root, "child")
+	childN := logAndGetTraceNode(t, "child", child)
+	assert.Equal(t, rootN, childN.parentTask)
+	assert.Equal(t, rootN, childN.parentSpan)
+
+	grandchild, e3 := WithSpan(child, "grandchild")
+	grandchildN := logAndGetTraceNode(t, "grandchild", grandchild)
+	assert.Equal(t, rootN, grandchildN.parentTask)
+	assert.Equal(t, childN, grandchildN.parentSpan)
+
+	gcTask, e4 := WithTask(grandchild, "grandchild-task")
+	gcTaskN := logAndGetTraceNode(t, "grandchild-task", gcTask)
+	assert.Equal(t, rootN, gcTaskN.parentTask)
+	assert.Nil(t, gcTaskN.parentSpan)
+
+	// it is allowed that a child task outlives the _span_ in which it was created
+	// (albeit not its parent task)
+	e3()
+	e2()
+	gcTaskSpan, e5 := WithSpan(gcTask, "granschild-task-span")
+	gcTaskSpanN := logAndGetTraceNode(t, "granschild-task-span", gcTaskSpan)
+	assert.Equal(t, gcTaskN, gcTaskSpanN.parentTask)
+	assert.Equal(t, gcTaskN, gcTaskSpanN.parentSpan)
+	e5()
+
+	e4()
+	e1()
+}
+
+func TestOrphanTasksBecomeNewRootWhenAllAncestorsAreDead(t *testing.T) {
+	parent, e1 := WithTask(context.Background(), "parent")
+	_ = logAndGetTraceNode(t, "parent-task", parent)
+	e1()
+
+	var child context.Context
+	var e2 DoneFunc
+	require.NotPanics(t, func() {
+		child, e2 = WithTask(parent, "child")
+	})
+	childN := logAndGetTraceNode(t, "child-task", child)
+	assert.Nil(t, childN.parentTask)
+
+	grandchild, _ := WithTask(child, "grandchild")
+	grandchildN := logAndGetTraceNode(t, "grandchild-task", grandchild)
+	assert.Equal(t, childN, grandchildN.parentTask)
+
+	require.Panics(t, func() { e2() }, "if the parent was alive at creation of child task, wrong termination order remains a panicable offense though")
+}
+
+func TestOrphanTaskBecomesChildToNearestLiveAncestor(t *testing.T) {
+	parent, e1 := WithTask(context.Background(), "parent")
+	parentN := logAndGetTraceNode(t, "parent-task", parent)
+
+	child, e2 := WithTask(parent, "child")
+	childN := logAndGetTraceNode(t, "child-task", child)
+	assert.Equal(t, parentN, childN.parentTask)
+	e2()
+
+	grandchild, e3 := WithTask(child, "grandchild")
+	grandchildN := logAndGetTraceNode(t, "grandchild-task", grandchild)
+	assert.Equal(t, parentN, grandchildN.parentTask) // child is already dead
+
+	require.NotPanics(t, func() {
+		e3()
+		e1()
+	})
+}

daemon/logging/trace/trace_unique_concurrent_task_namer.go

@@ -0,0 +1,53 @@
+package trace
+
+import (
+	"fmt"
+	"strings"
+	"sync"
+
+	"github.com/willf/bitset"
+)
+
+type uniqueConcurrentTaskNamer struct {
+	mtx    sync.Mutex
+	active map[string]*bitset.BitSet
+}
+
+// bitvecLengthGauge may be nil
+func newUniqueTaskNamer() *uniqueConcurrentTaskNamer {
+	return &uniqueConcurrentTaskNamer{
+		active: make(map[string]*bitset.BitSet),
+	}
+}
+
+// appends `#%d` to `name` such that until `done` is called,
+// it is guaranteed that `#%d` is not returned a second time for the same `name`
+func (namer *uniqueConcurrentTaskNamer) UniqueConcurrentTaskName(name string) (uniqueName string, done func()) {
+	if strings.Contains(name, "#") {
+		panic(name)
+	}
+	namer.mtx.Lock()
+	act, ok := namer.active[name]
+	if !ok {
+		act = bitset.New(64) // FIXME magic const
+		namer.active[name] = act
+	}
+	id, ok := act.NextClear(0)
+	if !ok {
+		// if !ok, all bits are 1 and act.Len() returns the next bit
+		id = act.Len()
+		// FIXME unbounded growth without reclamation
+	}
+	act.Set(id)
+	namer.mtx.Unlock()
+
+	return fmt.Sprintf("%s#%d", name, id), func() {
+		namer.mtx.Lock()
+		defer namer.mtx.Unlock()
+		act, ok := namer.active[name]
+		if !ok {
+			panic("must be initialized upon entry")
+		}
+		act.Clear(id)
+	}
+}

daemon/logging/trace/trace_unique_concurrent_task_namer_test.go

@@ -0,0 +1,58 @@
+package trace
+
+import (
+	"fmt"
+	"sync"
+	"sync/atomic"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+	"github.com/willf/bitset"
+)
+
+func TestBitsetFeaturesForUniqueConcurrentTaskNamer(t *testing.T) {
+	var b bitset.BitSet
+	require.Equal(t, uint(0), b.Len())
+	require.Equal(t, uint(0), b.Count())
+
+	b.Set(0)
+	require.Equal(t, uint(1), b.Len())
+	require.Equal(t, uint(1), b.Count())
+
+	b.Set(8)
+	require.Equal(t, uint(9), b.Len())
+	require.Equal(t, uint(2), b.Count())
+
+	b.Set(1)
+	require.Equal(t, uint(9), b.Len())
+	require.Equal(t, uint(3), b.Count())
+}
+
+func TestUniqueConcurrentTaskNamer(t *testing.T) {
+	namer := newUniqueTaskNamer()
+
+	var wg sync.WaitGroup
+
+	const N = 8128
+	const Q = 23
+
+	var fails uint32
+	var m sync.Map
+	wg.Add(N)
+	for i := 0; i < N; i++ {
+		go func(i int) {
+			defer wg.Done()
+			name := fmt.Sprintf("%d", i/Q)
+			uniqueName, done := namer.UniqueConcurrentTaskName(name)
+			act, _ := m.LoadOrStore(uniqueName, i)
+			if act.(int) != i {
+				atomic.AddUint32(&fails, 1)
+			}
+			m.Delete(uniqueName)
+			done()
+		}(i)
+	}
+	wg.Wait()
+
+	require.Equal(t, uint32(0), fails)
+}

daemon/main.go

@@ -1,6 +1,8 @@
 package daemon
 
 import (
+	"context"
+
 	"github.com/zrepl/zrepl/cli"
 	"github.com/zrepl/zrepl/logger"
 )
@@ -10,7 +12,7 @@ type Logger = logger.Logger
 var DaemonCmd = &cli.Subcommand{
 	Use:   "daemon",
 	Short: "run the zrepl daemon",
-	Run: func(subcommand *cli.Subcommand, args []string) error {
+	Run: func(ctx context.Context, subcommand *cli.Subcommand, args []string) error {
-		return Run(subcommand.Config())
+		return Run(ctx, subcommand.Config())
 	},
 }

daemon/pprof.go

@@ -8,7 +8,11 @@ import (
 	"net"
 	"net/http/pprof"
 
+	"github.com/prometheus/client_golang/prometheus/promhttp"
+	"golang.org/x/net/websocket"
+
 	"github.com/zrepl/zrepl/daemon/job"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 )
 
 type pprofServer struct {
@@ -64,6 +68,8 @@ outer:
 			mux.Handle("/debug/pprof/profile", http.HandlerFunc(pprof.Profile))
 			mux.Handle("/debug/pprof/symbol", http.HandlerFunc(pprof.Symbol))
 			mux.Handle("/debug/pprof/trace", http.HandlerFunc(pprof.Trace))
+			mux.Handle("/metrics", promhttp.Handler())
+			mux.Handle("/debug/zrepl/activity-trace", websocket.Handler(trace.ChrometraceClientWebsocketHandler))
 			go func() {
 				err := http.Serve(s.listener, mux)
 				if ctx.Err() != nil {

daemon/prometheus.go

@@ -10,6 +10,7 @@ import (
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/job"
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/endpoint"
 	"github.com/zrepl/zrepl/logger"
 	"github.com/zrepl/zrepl/rpc/dataconn/frameconn"
@@ -86,16 +87,19 @@ func (j *prometheusJob) Run(ctx context.Context) {
 }
 
 type prometheusJobOutlet struct {
-	jobName string
 }
 
 var _ logger.Outlet = prometheusJobOutlet{}
 
-func newPrometheusLogOutlet(jobName string) prometheusJobOutlet {
+func newPrometheusLogOutlet() prometheusJobOutlet {
-	return prometheusJobOutlet{jobName}
+	return prometheusJobOutlet{}
 }
 
 func (o prometheusJobOutlet) WriteEntry(entry logger.Entry) error {
-	prom.taskLogEntries.WithLabelValues(o.jobName, entry.Level.String()).Inc()
+	jobFieldVal, ok := entry.Fields[logging.JobField].(string)
+	if !ok {
+		jobFieldVal = "_nojobid"
+	}
+	prom.taskLogEntries.WithLabelValues(jobFieldVal, entry.Level.String()).Inc()
 	return nil
 }

daemon/pruner/pruner.go

@@ -12,6 +12,7 @@ import (
 	"github.com/prometheus/client_golang/prometheus"
 
 	"github.com/zrepl/zrepl/config"
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/logger"
 	"github.com/zrepl/zrepl/pruning"
 	"github.com/zrepl/zrepl/replication/logic/pdu"
@@ -35,17 +36,13 @@ type Logger = logger.Logger
 
 type contextKey int
 
-const contextKeyLogger contextKey = 0
+const (
-
+	contextKeyPruneSide contextKey = 1 + iota
-func WithLogger(ctx context.Context, log Logger) context.Context {
+)
-	return context.WithValue(ctx, contextKeyLogger, log)
-}
 
 func GetLogger(ctx context.Context) Logger {
-	if l, ok := ctx.Value(contextKeyLogger).(Logger); ok {
+	pruneSide := ctx.Value(contextKeyPruneSide).(string)
-		return l
+	return logging.GetLogger(ctx, logging.SubsysPruning).WithField("prune_side", pruneSide)
-	}
-	return logger.NewNullLogger()
 }
 
 type args struct {
@@ -138,7 +135,7 @@ func NewPrunerFactory(in config.PruningSenderReceiver, promPruneSecs *prometheus
 func (f *PrunerFactory) BuildSenderPruner(ctx context.Context, target Target, receiver History) *Pruner {
 	p := &Pruner{
 		args: args{
-			WithLogger(ctx, GetLogger(ctx).WithField("prune_side", "sender")),
+			context.WithValue(ctx, contextKeyPruneSide, "sender"),
 			target,
 			receiver,
 			f.senderRules,
@@ -154,7 +151,7 @@ func (f *PrunerFactory) BuildSenderPruner(ctx context.Context, target Target, re
 func (f *PrunerFactory) BuildReceiverPruner(ctx context.Context, target Target, receiver History) *Pruner {
 	p := &Pruner{
 		args: args{
-			WithLogger(ctx, GetLogger(ctx).WithField("prune_side", "receiver")),
+			context.WithValue(ctx, contextKeyPruneSide, "receiver"),
 			target,
 			receiver,
 			f.receiverRules,
@@ -170,7 +167,7 @@ func (f *PrunerFactory) BuildReceiverPruner(ctx context.Context, target Target,
 func (f *LocalPrunerFactory) BuildLocalPruner(ctx context.Context, target Target, receiver History) *Pruner {
 	p := &Pruner{
 		args: args{
-			ctx,
+			context.WithValue(ctx, contextKeyPruneSide, "local"),
 			target,
 			receiver,
 			f.keepRules,

daemon/snapper/snapper.go

@@ -8,10 +8,12 @@ import (
 	"time"
 
 	"github.com/pkg/errors"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/filters"
 	"github.com/zrepl/zrepl/daemon/hooks"
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/logger"
 	"github.com/zrepl/zrepl/util/envconst"
 	"github.com/zrepl/zrepl/zfs"
@@ -45,7 +47,6 @@ type snapProgress struct {
 
 type args struct {
 	ctx            context.Context
-	log            Logger
 	prefix         string
 	interval       time.Duration
 	fsf            *filters.DatasetMapFilter
@@ -102,23 +103,10 @@ func (s State) sf() state {
 type updater func(u func(*Snapper)) State
 type state func(a args, u updater) state
 
-type contextKey int
-
-const (
-	contextKeyLog contextKey = 0
-)
-
 type Logger = logger.Logger
 
-func WithLogger(ctx context.Context, log Logger) context.Context {
-	return context.WithValue(ctx, contextKeyLog, log)
-}
-
 func getLogger(ctx context.Context) Logger {
-	if log, ok := ctx.Value(contextKeyLog).(Logger); ok {
+	return logging.GetLogger(ctx, logging.SubsysSnapshot)
-		return log
-	}
-	return logger.NewNullLogger()
 }
 
 func PeriodicFromConfig(g *config.Global, fsf *filters.DatasetMapFilter, in *config.SnapshottingPeriodic) (*Snapper, error) {
@@ -146,13 +134,12 @@ func PeriodicFromConfig(g *config.Global, fsf *filters.DatasetMapFilter, in *con
 }
 
 func (s *Snapper) Run(ctx context.Context, snapshotsTaken chan<- struct{}) {
-
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 	getLogger(ctx).Debug("start")
 	defer getLogger(ctx).Debug("stop")
 
 	s.args.snapshotsTaken = snapshotsTaken
 	s.args.ctx = ctx
-	s.args.log = getLogger(ctx)
 	s.args.dryRun = false // for future expansion
 
 	u := func(u func(*Snapper)) State {
@@ -190,7 +177,7 @@ func onErr(err error, u updater) state {
 		case Snapshotting:
 			s.state = ErrorWait
 		}
-		s.args.log.WithError(err).WithField("pre_state", preState).WithField("post_state", s.state).Error("snapshotting error")
+		getLogger(s.args.ctx).WithError(err).WithField("pre_state", preState).WithField("post_state", s.state).Error("snapshotting error")
 	}).sf()
 }
 
@@ -209,7 +196,7 @@ func syncUp(a args, u updater) state {
 	if err != nil {
 		return onErr(err, u)
 	}
-	syncPoint, err := findSyncPoint(a.log, fss, a.prefix, a.interval)
+	syncPoint, err := findSyncPoint(a.ctx, fss, a.prefix, a.interval)
 	if err != nil {
 		return onErr(err, u)
 	}
@@ -266,18 +253,18 @@ func snapshot(a args, u updater) state {
 		suffix := time.Now().In(time.UTC).Format("20060102_150405_000")
 		snapname := fmt.Sprintf("%s%s", a.prefix, suffix)
 
-		l := a.log.
+		ctx := logging.WithInjectedField(a.ctx, "fs", fs.ToString())
-			WithField("fs", fs.ToString()).
+		ctx = logging.WithInjectedField(ctx, "snap", snapname)
-			WithField("snap", snapname)
 
 		hookEnvExtra := hooks.Env{
 			hooks.EnvFS:       fs.ToString(),
 			hooks.EnvSnapshot: snapname,
 		}
 
-		jobCallback := hooks.NewCallbackHookForFilesystem("snapshot", fs, func(_ context.Context) (err error) {
+		jobCallback := hooks.NewCallbackHookForFilesystem("snapshot", fs, func(ctx context.Context) (err error) {
+			l := getLogger(ctx)
 			l.Debug("create snapshot")
-			err = zfs.ZFSSnapshot(a.ctx, fs, snapname, false) // TODO propagate context to ZFSSnapshot
+			err = zfs.ZFSSnapshot(ctx, fs, snapname, false) // TODO propagate context to ZFSSnapshot
 			if err != nil {
 				l.WithError(err).Error("cannot create snapshot")
 			}
@@ -290,7 +277,7 @@ func snapshot(a args, u updater) state {
 		{
 			filteredHooks, err := a.hooks.CopyFilteredForFilesystem(fs)
 			if err != nil {
-				l.WithError(err).Error("unexpected filter error")
+				getLogger(ctx).WithError(err).Error("unexpected filter error")
 				fsHadErr = true
 				goto updateFSState
 			}
@@ -303,7 +290,7 @@ func snapshot(a args, u updater) state {
 			plan, planErr = hooks.NewPlan(&filteredHooks, hooks.PhaseSnapshot, jobCallback, hookEnvExtra)
 			if planErr != nil {
 				fsHadErr = true
-				l.WithError(planErr).Error("cannot create job hook plan")
+				getLogger(ctx).WithError(planErr).Error("cannot create job hook plan")
 				goto updateFSState
 			}
 		}
@@ -314,15 +301,14 @@ func snapshot(a args, u updater) state {
 			progress.state = SnapStarted
 		})
 		{
-			l := hooks.GetLogger(a.ctx).WithField("fs", fs.ToString()).WithField("snap", snapname)
+			getLogger(ctx).WithField("report", plan.Report().String()).Debug("begin run job plan")
-			l.WithField("report", plan.Report().String()).Debug("begin run job plan")
+			plan.Run(ctx, a.dryRun)
-			plan.Run(hooks.WithLogger(a.ctx, l), a.dryRun)
 			planReport = plan.Report()
 			fsHadErr = planReport.HadError() // not just fatal errors
 			if fsHadErr {
-				l.WithField("report", planReport.String()).Error("end run job plan with error")
+				getLogger(ctx).WithField("report", planReport.String()).Error("end run job plan with error")
 			} else {
-				l.WithField("report", planReport.String()).Info("end run job plan successful")
+				getLogger(ctx).WithField("report", planReport.String()).Info("end run job plan successful")
 			}
 		}
 
@@ -342,7 +328,7 @@ func snapshot(a args, u updater) state {
 	case a.snapshotsTaken <- struct{}{}:
 	default:
 		if a.snapshotsTaken != nil {
-			a.log.Warn("callback channel is full, discarding snapshot update event")
+			getLogger(a.ctx).Warn("callback channel is full, discarding snapshot update event")
 		}
 	}
 
@@ -355,7 +341,7 @@ func snapshot(a args, u updater) state {
 					break
 				}
 			}
-			a.log.WithField("hook", h.String()).WithField("hook_number", hookIdx+1).Warn("hook did not match any snapshotted filesystems")
+			getLogger(a.ctx).WithField("hook", h.String()).WithField("hook_number", hookIdx+1).Warn("hook did not match any snapshotted filesystems")
 		}
 	}
 
@@ -376,7 +362,7 @@ func wait(a args, u updater) state {
 		lastTick := snapper.lastInvocation
 		snapper.sleepUntil = lastTick.Add(a.interval)
 		sleepUntil = snapper.sleepUntil
-		log := a.log.WithField("sleep_until", sleepUntil).WithField("duration", a.interval)
+		log := getLogger(a.ctx).WithField("sleep_until", sleepUntil).WithField("duration", a.interval)
 		logFunc := log.Debug
 		if snapper.state == ErrorWait || snapper.state == SyncUpErrWait {
 			logFunc = log.Error
@@ -404,7 +390,7 @@ func listFSes(ctx context.Context, mf *filters.DatasetMapFilter) (fss []*zfs.Dat
 var syncUpWarnNoSnapshotUntilSyncupMinDuration = envconst.Duration("ZREPL_SNAPPER_SYNCUP_WARN_MIN_DURATION", 1*time.Second)
 
 // see docs/snapshotting.rst
-func findSyncPoint(log Logger, fss []*zfs.DatasetPath, prefix string, interval time.Duration) (syncPoint time.Time, err error) {
+func findSyncPoint(ctx context.Context, fss []*zfs.DatasetPath, prefix string, interval time.Duration) (syncPoint time.Time, err error) {
 
 	const (
 		prioHasVersions int = iota
@@ -426,10 +412,10 @@ func findSyncPoint(log Logger, fss []*zfs.DatasetPath, prefix string, interval t
 
 	now := time.Now()
 
-	log.Debug("examine filesystem state to find sync point")
+	getLogger(ctx).Debug("examine filesystem state to find sync point")
 	for _, d := range fss {
-		l := log.WithField("fs", d.ToString())
+		ctx := logging.WithInjectedField(ctx, "fs", d.ToString())
-		syncPoint, err := findSyncPointFSNextOptimalSnapshotTime(l, now, interval, prefix, d)
+		syncPoint, err := findSyncPointFSNextOptimalSnapshotTime(ctx, now, interval, prefix, d)
 		if err == findSyncPointFSNoFilesystemVersionsErr {
 			snaptimes = append(snaptimes, snapTime{
 				ds:   d,
@@ -438,9 +424,9 @@ func findSyncPoint(log Logger, fss []*zfs.DatasetPath, prefix string, interval t
 			})
 		} else if err != nil {
 			hardErrs++
-			l.WithError(err).Error("cannot determine optimal sync point for this filesystem")
+			getLogger(ctx).WithError(err).Error("cannot determine optimal sync point for this filesystem")
 		} else {
-			l.WithField("syncPoint", syncPoint).Debug("found optimal sync point for this filesystem")
+			getLogger(ctx).WithField("syncPoint", syncPoint).Debug("found optimal sync point for this filesystem")
 			snaptimes = append(snaptimes, snapTime{
 				ds:   d,
 				prio: prioHasVersions,
@@ -467,7 +453,7 @@ func findSyncPoint(log Logger, fss []*zfs.DatasetPath, prefix string, interval t
 	})
 
 	winnerSyncPoint := snaptimes[0].time
-	l := log.WithField("syncPoint", winnerSyncPoint.String())
+	l := getLogger(ctx).WithField("syncPoint", winnerSyncPoint.String())
 	l.Info("determined sync point")
 	if winnerSyncPoint.Sub(now) > syncUpWarnNoSnapshotUntilSyncupMinDuration {
 		for _, st := range snaptimes {
@@ -483,9 +469,9 @@ func findSyncPoint(log Logger, fss []*zfs.DatasetPath, prefix string, interval t
 
 var findSyncPointFSNoFilesystemVersionsErr = fmt.Errorf("no filesystem versions")
 
-func findSyncPointFSNextOptimalSnapshotTime(l Logger, now time.Time, interval time.Duration, prefix string, d *zfs.DatasetPath) (time.Time, error) {
+func findSyncPointFSNextOptimalSnapshotTime(ctx context.Context, now time.Time, interval time.Duration, prefix string, d *zfs.DatasetPath) (time.Time, error) {
 
-	fsvs, err := zfs.ZFSListFilesystemVersions(context.TODO(), d, zfs.ListFilesystemVersionsOptions{
+	fsvs, err := zfs.ZFSListFilesystemVersions(ctx, d, zfs.ListFilesystemVersionsOptions{
 		Types:           zfs.Snapshots,
 		ShortnamePrefix: prefix,
 	})
@@ -502,7 +488,7 @@ func findSyncPointFSNextOptimalSnapshotTime(l Logger, now time.Time, interval ti
 	})
 
 	latest := fsvs[len(fsvs)-1]
-	l.WithField("creation", latest.Creation).Debug("found latest snapshot")
+	getLogger(ctx).WithField("creation", latest.Creation).Debug("found latest snapshot")
 
 	since := now.Sub(latest.Creation)
 	if since < 0 {

dist/grafana/grafana-prometheus-zrepl-0.1.json

@@ -1,595 +0,0 @@
-{
-  "annotations": {
-    "list": [
-      {
-        "$$hashKey": "object:3351",
-        "builtIn": 1,
-        "datasource": "-- Grafana --",
-        "enable": true,
-        "hide": true,
-        "iconColor": "rgba(0, 211, 255, 1)",
-        "name": "Annotations & Alerts",
-        "type": "dashboard"
-      }
-    ]
-  },
-  "editable": true,
-  "gnetId": null,
-  "graphTooltip": 1,
-  "id": 7,
-  "iteration": 1552746418826,
-  "links": [],
-  "panels": [
-    {
-      "content": "# zrepl Prometheus Metrics\n\nzrepl exposes Prometheus metrics and ships with this Grafana dashboard.\nThe exported metrics are suitable for health checks:\n\n* The log should generally be warning & error-free\n  * The `Log Messages that require attention` graph visualizes log message counts indicating problems.\n* The number of goroutines should not grow unboundedly over time.\n  * During replication, the number of goroutines can be way higher than during idle time.\n  * If the goroutine count grows with each replication, there is clearly a goroutine leak. Please open a bug report.\n* The sys memory consumption should not grow unboundedly over time.\n  * Note that the Go runtime pre-allocates some of its heap from the OS.\n  * zrepl actually uses much less memory than allocated from the OS.\n  * Since Go 1.11, Go pre-allocates more aggressively.\n* Monitor that some data is replicated, although that metric does not guarantee that replication was successful.\n\n**In general, note that the exported metrics are not stable unless declared otherwise.**",
-      "gridPos": {
-        "h": 9,
-        "w": 24,
-        "x": 0,
-        "y": 0
-      },
-      "id": 35,
-      "mode": "markdown",
-      "title": "Panel Title",
-      "type": "text"
-    },
-    {
-      "aliasColors": {},
-      "bars": false,
-      "dashLength": 10,
-      "dashes": false,
-      "datasource": null,
-      "fill": 1,
-      "gridPos": {
-        "h": 9,
-        "w": 12,
-        "x": 0,
-        "y": 9
-      },
-      "id": 15,
-      "legend": {
-        "avg": false,
-        "current": false,
-        "max": false,
-        "min": false,
-        "show": true,
-        "total": false,
-        "values": false
-      },
-      "lines": true,
-      "linewidth": 1,
-      "links": [],
-      "nullPointMode": "null",
-      "percentage": false,
-      "pointradius": 5,
-      "points": false,
-      "renderer": "flot",
-      "seriesOverrides": [],
-      "spaceLength": 10,
-      "stack": true,
-      "steppedLine": false,
-      "targets": [
-        {
-          "$$hashKey": "object:3436",
-          "expr": "up{job='$prom_job_name'}",
-          "format": "time_series",
-          "intervalFactor": 1,
-          "refId": "A"
-        }
-      ],
-      "thresholds": [],
-      "timeFrom": null,
-      "timeShift": null,
-      "title": "zrepl Instances Up",
-      "tooltip": {
-        "shared": true,
-        "sort": 0,
-        "value_type": "individual"
-      },
-      "type": "graph",
-      "xaxis": {
-        "buckets": null,
-        "mode": "time",
-        "name": null,
-        "show": true,
-        "values": []
-      },
-      "yaxes": [
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": "5",
-          "min": "0",
-          "show": true
-        },
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        }
-      ]
-    },
-    {
-      "aliasColors": {},
-      "bars": false,
-      "dashLength": 10,
-      "dashes": false,
-      "datasource": null,
-      "fill": 1,
-      "gridPos": {
-        "h": 9,
-        "w": 12,
-        "x": 12,
-        "y": 9
-      },
-      "id": 22,
-      "legend": {
-        "avg": false,
-        "current": false,
-        "max": false,
-        "min": false,
-        "show": true,
-        "total": false,
-        "values": false
-      },
-      "lines": true,
-      "linewidth": 1,
-      "links": [],
-      "nullPointMode": "null",
-      "percentage": false,
-      "pointradius": 5,
-      "points": false,
-      "renderer": "flot",
-      "seriesOverrides": [],
-      "spaceLength": 10,
-      "stack": false,
-      "steppedLine": false,
-      "targets": [
-        {
-          "expr": "increase(zrepl_daemon_log_entries{job='$prom_job_name',level=~'warn|error'}[$__interval])",
-          "format": "time_series",
-          "intervalFactor": 1,
-          "refId": "A"
-        }
-      ],
-      "thresholds": [],
-      "timeFrom": null,
-      "timeShift": null,
-      "title": "Log Messages that require attention",
-      "tooltip": {
-        "shared": true,
-        "sort": 0,
-        "value_type": "individual"
-      },
-      "type": "graph",
-      "xaxis": {
-        "buckets": null,
-        "mode": "time",
-        "name": null,
-        "show": true,
-        "values": []
-      },
-      "yaxes": [
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": "0",
-          "show": true
-        },
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        }
-      ]
-    },
-    {
-      "aliasColors": {},
-      "bars": false,
-      "dashLength": 10,
-      "dashes": false,
-      "datasource": null,
-      "fill": 1,
-      "gridPos": {
-        "h": 9,
-        "w": 12,
-        "x": 0,
-        "y": 18
-      },
-      "id": 33,
-      "legend": {
-        "avg": false,
-        "current": false,
-        "max": false,
-        "min": false,
-        "show": true,
-        "total": false,
-        "values": false
-      },
-      "lines": true,
-      "linewidth": 1,
-      "links": [],
-      "nullPointMode": "null",
-      "percentage": false,
-      "pointradius": 5,
-      "points": false,
-      "renderer": "flot",
-      "seriesOverrides": [
-        {
-          "alias": "/replicated bytes in last.*/",
-          "yaxis": 2
-        }
-      ],
-      "spaceLength": 10,
-      "stack": false,
-      "steppedLine": false,
-      "targets": [
-        {
-          "expr": "sum(rate(zrepl_replication_bytes_replicated{job='$prom_job_name'}[$__interval])) by (zrepl_job)",
-          "format": "time_series",
-          "hide": false,
-          "interval": "",
-          "intervalFactor": 1,
-          "legendFormat": "replication data rate zrepl_job={{zrepl_job}}",
-          "refId": "A"
-        },
-        {
-          "expr": "sum(increase(zrepl_replication_bytes_replicated{job='$prom_job_name'}[10m])) by (zrepl_job)",
-          "format": "time_series",
-          "hide": false,
-          "interval": "",
-          "intervalFactor": 1,
-          "legendFormat": "replicated bytes in last 10min zrepl_job={{zrepl_job}}",
-          "refId": "B"
-        }
-      ],
-      "thresholds": [],
-      "timeFrom": null,
-      "timeShift": null,
-      "title": "Replication Data Rate and Volume(integrates last 10min)",
-      "tooltip": {
-        "shared": true,
-        "sort": 0,
-        "value_type": "individual"
-      },
-      "type": "graph",
-      "xaxis": {
-        "buckets": null,
-        "mode": "time",
-        "name": null,
-        "show": true,
-        "values": []
-      },
-      "yaxes": [
-        {
-          "format": "Bps",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        },
-        {
-          "format": "bytes",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        }
-      ]
-    },
-    {
-      "aliasColors": {},
-      "bars": false,
-      "dashLength": 10,
-      "dashes": false,
-      "datasource": null,
-      "fill": 1,
-      "gridPos": {
-        "h": 9,
-        "w": 12,
-        "x": 12,
-        "y": 18
-      },
-      "id": 23,
-      "legend": {
-        "avg": false,
-        "current": false,
-        "max": false,
-        "min": false,
-        "show": true,
-        "total": false,
-        "values": false
-      },
-      "lines": true,
-      "linewidth": 1,
-      "links": [],
-      "nullPointMode": "null",
-      "percentage": false,
-      "pointradius": 5,
-      "points": false,
-      "renderer": "flot",
-      "seriesOverrides": [],
-      "spaceLength": 10,
-      "stack": false,
-      "steppedLine": false,
-      "targets": [
-        {
-          "expr": "sum(increase(zrepl_daemon_log_entries{job='$prom_job_name',zrepl_job=~\"^[^_].*\"}[$__interval])) by (instance,zrepl_job)",
-          "format": "time_series",
-          "intervalFactor": 1,
-          "refId": "A"
-        }
-      ],
-      "thresholds": [],
-      "timeFrom": null,
-      "timeShift": null,
-      "title": "Log Activity (without internal jobs)",
-      "tooltip": {
-        "shared": true,
-        "sort": 0,
-        "value_type": "individual"
-      },
-      "type": "graph",
-      "xaxis": {
-        "buckets": null,
-        "mode": "time",
-        "name": null,
-        "show": true,
-        "values": []
-      },
-      "yaxes": [
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": "0",
-          "show": true
-        },
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        }
-      ]
-    },
-    {
-      "aliasColors": {},
-      "bars": false,
-      "dashLength": 10,
-      "dashes": false,
-      "datasource": null,
-      "fill": 1,
-      "gridPos": {
-        "h": 9,
-        "w": 12,
-        "x": 0,
-        "y": 27
-      },
-      "id": 17,
-      "legend": {
-        "avg": false,
-        "current": false,
-        "max": false,
-        "min": false,
-        "show": true,
-        "total": false,
-        "values": false
-      },
-      "lines": true,
-      "linewidth": 1,
-      "links": [],
-      "nullPointMode": "null",
-      "percentage": false,
-      "pointradius": 5,
-      "points": false,
-      "renderer": "flot",
-      "seriesOverrides": [],
-      "spaceLength": 10,
-      "stack": false,
-      "steppedLine": false,
-      "targets": [
-        {
-          "$$hashKey": "object:3535",
-          "expr": "go_memstats_sys_bytes{job='$prom_job_name'}",
-          "format": "time_series",
-          "hide": false,
-          "intervalFactor": 1,
-          "refId": "A"
-        }
-      ],
-      "thresholds": [],
-      "timeFrom": null,
-      "timeShift": null,
-      "title": "Memory Allocated by the Go runtime from the OS (should not grow unboundedly)",
-      "tooltip": {
-        "shared": true,
-        "sort": 0,
-        "value_type": "individual"
-      },
-      "type": "graph",
-      "xaxis": {
-        "buckets": null,
-        "mode": "time",
-        "name": null,
-        "show": true,
-        "values": []
-      },
-      "yaxes": [
-        {
-          "format": "bytes",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": "0",
-          "show": true
-        },
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        }
-      ]
-    },
-    {
-      "aliasColors": {},
-      "bars": false,
-      "dashLength": 10,
-      "dashes": false,
-      "datasource": null,
-      "fill": 1,
-      "gridPos": {
-        "h": 9,
-        "w": 12,
-        "x": 12,
-        "y": 27
-      },
-      "id": 19,
-      "legend": {
-        "avg": false,
-        "current": false,
-        "max": false,
-        "min": false,
-        "show": true,
-        "total": false,
-        "values": false
-      },
-      "lines": true,
-      "linewidth": 1,
-      "links": [],
-      "nullPointMode": "null",
-      "percentage": false,
-      "pointradius": 5,
-      "points": false,
-      "renderer": "flot",
-      "seriesOverrides": [],
-      "spaceLength": 10,
-      "stack": false,
-      "steppedLine": false,
-      "targets": [
-        {
-          "expr": "go_goroutines{job='$prom_job_name'}",
-          "format": "time_series",
-          "intervalFactor": 1,
-          "refId": "A"
-        }
-      ],
-      "thresholds": [],
-      "timeFrom": null,
-      "timeShift": null,
-      "title": "number of goroutines (should not grow unboundedly)",
-      "tooltip": {
-        "shared": true,
-        "sort": 0,
-        "value_type": "individual"
-      },
-      "type": "graph",
-      "xaxis": {
-        "buckets": null,
-        "mode": "time",
-        "name": null,
-        "show": true,
-        "values": []
-      },
-      "yaxes": [
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": "0",
-          "show": true
-        },
-        {
-          "format": "short",
-          "label": null,
-          "logBase": 1,
-          "max": null,
-          "min": null,
-          "show": true
-        }
-      ]
-    }
-  ],
-  "refresh": "1m",
-  "schemaVersion": 16,
-  "style": "dark",
-  "tags": [],
-  "templating": {
-    "list": [
-      {
-        "allValue": null,
-        "current": {
-          "text": "zrepl",
-          "value": "zrepl"
-        },
-        "datasource": "prometheus",
-        "hide": 0,
-        "includeAll": false,
-        "label": "Prometheus Job Name",
-        "multi": false,
-        "name": "prom_job_name",
-        "options": [],
-        "query": "label_values(up, job)",
-        "refresh": 1,
-        "regex": "",
-        "sort": 1,
-        "tagValuesQuery": "",
-        "tags": [],
-        "tagsQuery": "",
-        "type": "query",
-        "useTags": false
-      }
-    ]
-  },
-  "time": {
-    "from": "now-2d",
-    "to": "now"
-  },
-  "timepicker": {
-    "refresh_intervals": [
-      "5s",
-      "10s",
-      "30s",
-      "1m",
-      "5m",
-      "15m",
-      "30m",
-      "1h",
-      "2h",
-      "1d"
-    ],
-    "time_options": [
-      "5m",
-      "15m",
-      "1h",
-      "6h",
-      "12h",
-      "24h",
-      "2d",
-      "7d",
-      "30d"
-    ]
-  },
-  "timezone": "",
-  "title": "zrepl 0.1",
-  "uid": "xTljn4qmk",
-  "version": 6
-}

docs/changelog.rst

@@ -35,18 +35,23 @@ This is a big one! Headlining features:
 * **Resumable Send & Recv Support**
   No knobs required, automatically used where supported.
 * **Hold-Protected Send & Recv**
-  Automatic ZFS holds to ensure that we can always resume a replication step.
+  Automatic ZFS holds to ensure that we can always use resumable send&recv for a replication step.
-* **Encrypted Send & Recv Support** for OpenZFS native encryption.
+* **Encrypted Send & Recv Support** for OpenZFS native encryption,
-  :ref:`Configurable <job-send-options>` at the job level, i.e., for all filesystems a job is responsible for.
+  :ref:`configurable <job-send-options>` at the job level, i.e., for all filesystems a job is responsible for.
 * **Receive-side hold on last received dataset**
   The counterpart to the replication cursor bookmark on the send-side.
   Ensures that incremental replication will always be possible between a sender and receiver.
 
-Actual changelog:
+.. TIP::
 
-* |break_config| **more restrictive job names than in prior zrepl versions**
+   We highly recommend studying the :ref:`overview section of the configuration chapter <overview-how-replication-works>` to understand how replication works.
-  Starting with this version, job names are going to be embedded into ZFS holds and bookmark names.
 
+Additional changelog:
+
+* |break| |break_config| **more restrictive job names than in prior zrepl versions**
+  Starting with this version, job names are going to be embedded into ZFS holds and bookmark names (see :ref:`here<replication-cursor-and-last-received-hold>` and :ref:`here<step-holds-and-bookmarks>`).
+  Therefore you might need to adjust your job names.
+  **Note that jobs** :issue:`cannot be renamed easily` **once you start using zrepl 0.3.**
 * |break| |mig| replication cursor representation changed
 
   * zrepl now manages the :ref:`replication cursor bookmark <replication-cursor-and-last-received-hold>` per job-filesystem tuple instead of a single replication cursor per filesystem.
@@ -56,16 +61,29 @@ Actual changelog:
   * Run ``zrepl migrate replication-cursor:v1-v2`` to safely destroy old-format cursors.
     The migration will ensure that only those old-format cursors are destroyed that have been superseeded by new-format cursors.
 
+* |feature| New option ``listen_freebind`` (tcp, tls, prometheus listener)
+* |feature| :issue:`265` transport/tcp: support for CIDR masks in client IP whitelist
+* |feature| documented subcommand to generate ``bash`` and ``zsh`` completions
+* |feature| :issue:`307` ``chrome://trace`` -compatible activity tracing of zrepl daemon activity
+* |feature| logging: trace IDs for better log entry correlation with concurrent replication jobs
+* |feature| experimental environment variable for parallel replication (see :issue:`306` )
 * |bugfix| missing logger context vars in control connection handlers
 * |bugfix| improved error messages on ``zfs send`` errors
-* |feature| New option ``listen_freebind`` (tcp, tls, prometheus listener)
 * |bugfix| |docs| snapshotting: clarify sync-up behavior and warn about filesystems
+* |bugfix| transport/ssh: do not leak zombie ssh process on connection failures
   that will not be snapshotted until the sync-up phase is over
+* |docs| Installation: :ref:`FreeBSD jail with iocage <installation-freebsd-jail-with-iocage>`
 * |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.
 
+.. NOTE::
+   |  zrepl is a spare-time project primarily developed by `Christian Schwarz <https://cschwarz.com>`_.
+   |  You can support maintenance and feature development through one of the following services:
+   |  |Donate via Patreon| |Donate via GitHub Sponsors| |Donate via Liberapay| |Donate via PayPal|
+   |  Note that PayPal processing fees are relatively high for small donations.
+   |  For SEPA wire transfer and **commercial support**, please `contact Christian directly <https://cschwarz.com>`_.
+
 0.2.1
 -----
 
@@ -102,14 +120,6 @@ Actual changelog:
   The pool name ``zreplplatformtest`` is reserved for this use case.
   Only run ``make platformtest`` on test systems, e.g. a FreeBSD VM image.
 
-.. NOTE::
-   |  zrepl is a spare-time project primarily developed by `Christian Schwarz <https://cschwarz.com>`_.
-   |  You can support maintenance and feature development through one of the following services:
-   |  |Donate via Patreon| |Donate via Liberapay| |Donate via PayPal|
-   |  Note that PayPal processing fees are relatively high for small donations.
-   |  For SEPA wire transfer and **commercial support**, please `contact Christian directly <https://cschwarz.com>`_.
-
-
 0.1.1
 -----
 

docs/configuration/jobs.rst

@@ -19,7 +19,7 @@ Job Type ``push``
     * - ``type``
       - = ``push``
     * - ``name``
-      - unique name of the job
+      - unique name of the job :issue:`(must not change)<327>`
     * - ``connect``
       - |connect-transport|
     * - ``filesystems``
@@ -47,7 +47,7 @@ Job Type ``sink``
     * - ``type``
       - = ``sink``
     * - ``name``
-      - unique name of the job
+      - unique name of the job :issue:`(must not change)<327>`
     * - ``serve``
       - |serve-transport|
     * - ``root_fs``
@@ -70,7 +70,7 @@ Job Type ``pull``
     * - ``type``
       - = ``pull``
     * - ``name``
-      - unique name of the job
+      - unique name of the job :issue:`(must not change)<327>`
     * - ``connect``
       - |connect-transport|
     * - ``root_fs``
@@ -98,7 +98,7 @@ Job Type ``source``
     * - ``type``
       - = ``source``
     * - ``name``
-      - unique name of the job
+      - unique name of the job :issue:`(must not change)<327>`
     * - ``serve``
       - |serve-transport|
     * - ``filesystems``
@@ -137,7 +137,7 @@ Job type that only takes snapshots and performs pruning on the local machine.
     * - ``type``
       - = ``snap``
     * - ``name``
-      - unique name of the job
+      - unique name of the job :issue:`(must not change)<327>`
     * - ``filesystems``
       - |filter-spec| for filesystems to be snapshotted
     * - ``snapshotting``

docs/configuration/overview.rst

@@ -12,7 +12,7 @@ The following paths are considered:
 The ``zrepl configcheck`` subcommand can be used to validate the configuration.
 The command will output nothing and exit with zero status code if the configuration is valid.
 The error messages vary in quality and usefulness: please report confusing config errors to the tracking :issue:`155`.
-Full example configs such as in the :ref:`tutorial` or the :sampleconf:`/` directory might also be helpful.
+Full example configs such as in the :ref:`quick-start guides <quickstart-toc>` or the :sampleconf:`/` directory might also be helpful.
 However, copy-pasting examples is no substitute for reading documentation!
 
 Config File Structure
@@ -39,6 +39,10 @@ A *job* is the unit of activity tracked by the zrepl daemon.
 The ``type`` of a job determines its role in a replication setup and in snapshot management.
 Jobs are identified by their ``name``, both in log files and the ``zrepl status`` command.
 
+.. NOTE::
+   The job name is persisted in several places on disk and thus :issue:`cannot be changed easily<327>`.
+
+
 Replication always happens between a pair of jobs: one is the **active side**, and one the **passive side**.
 The active side connects to the passive side using a :ref:`transport <transport>` and starts executing the replication logic.
 The passive side responds to requests from the active side after checking its permissions.
@@ -99,7 +103,7 @@ One of the major design goals of the replication module is to avoid any duplicat
 As such, the code works on abstract senders and receiver **endpoints**, where typically one will be implemented by a local program object and the other is an RPC client instance.
 Regardless of push- or pull-style setup, the logic executes on the active side, i.e. in the ``push`` or ``pull`` job.
 
-The following steps take place during replication and can be monitored using the ``zrepl status`` subcommand:
+The following high-level steps take place during replication and can be monitored using the ``zrepl status`` subcommand:
 
 * Plan the replication:
 
@@ -107,9 +111,9 @@ The following steps take place during replication and can be monitored using the
   * Build the **replication plan**
 
     * Per filesystem, compute a diff between sender and receiver snapshots
-    * Build a list of replication steps
+    * Build a list of **replication steps**
 
-      * If possible, use incremental and resumable sends (``zfs send -i``)
+      * If possible, use incremental and resumable sends
       * Otherwise, use full send of most recent snapshot on sender
 
   * Retry on errors that are likely temporary (i.e. network failures).
@@ -128,16 +132,8 @@ The following steps take place during replication and can be monitored using the
    
 The idea behind the execution order of replication steps is that if the sender snapshots all filesystems simultaneously at fixed intervals, the receiver will have all filesystems snapshotted at time ``T1`` before the first snapshot at ``T2 = T1 + $interval`` is replicated.
 
-.. _replication-cursor-and-last-received-hold:
+Placeholder Filesystems
-
+^^^^^^^^^^^^^^^^^^^^^^^
-**Replication cursor** bookmark and **last-received-hold** are managed by zrepl to ensure that future replications can always be done incrementally:
-the replication cursor is a send-side bookmark of the most recent successfully replicated snapshot,
-and the last-received-hold is a hold of that snapshot on the receiving side.
-The replication cursor has the format ``#zrepl_CUSOR_G_<GUID>_J_<JOBNAME>``.
-The last-received-hold tag has the format ``#zrepl_last_received_J_<JOBNAME>``.
-Encoding the job name in the names ensures that multiple sending jobs can replicate the same filesystem to different receivers without interference.
-The ``zrepl holds list`` provides a listing of all bookmarks and holds managed by zrepl.
-
 .. _replication-placeholder-property:
 
 **Placeholder filesystems** on the receiving side are regular ZFS filesystems with the placeholder property ``zrepl:placeholder=on``.
@@ -148,16 +144,83 @@ Thus, zrepl creates the parent filesystems as placeholders on the receiving side
 If at some point ``S/H`` and ``S`` shall be replicated, the receiving side invalidates the placeholder flag automatically.
 The ``zrepl test placeholder`` command can be used to check whether a filesystem is a placeholder.
 
+ZFS Background Knowledge
+^^^^^^^^^^^^^^^^^^^^^^^^
+
+This section gives some background knowledge about ZFS features that zrepl uses to guarantee that
+**incremental replication is always possible and that started replication steps can always be resumed if they are interrupted.**
+
+**ZFS Send Modes & Bookmarks**
+ZFS supports full sends (``zfs send fs@to``) and incremental sends (``zfs send -i @from fs@to``).
+Full sends are used to create a new filesystem on the receiver with the send-side state of ``fs@to``.
+Incremental sends only transfer the delta between ``@from`` and ``@to``.
+Incremental sends require that ``@from`` be present on the receiving side when receiving the incremental stream.
+Incremental sends can also use a ZFS bookmark as *from* on the sending side (``zfs send -i #bm_from fs@to``), where ``#bm_from`` was created using ``zfs bookmark fs@from fs#bm_from``.
+The receiving side must always have the actual snapshot ``@from``, regardless of whether the sending side uses ``@from`` or a bookmark of it.
+
+**Resumable Send & Recv**
+The ``-s`` flag for ``zfs recv`` tells zfs to save the partially received send stream in case it is interrupted.
+To resume the replication, the receiving side filesystem's ``receive_resume_token`` must be passed to a new ``zfs send -t <value> | zfs recv`` command.
+A full send can only be resumed if ``@to`` still exists.
+An incremental send can only be resumed if ``@to`` still exists *and* either ``@from`` still exists *or* a bookmark ``#fbm`` of ``@from`` still exists.
+
+**ZFS Holds**
+ZFS holds prevent a snapshot from being deleted through ``zfs destroy``, letting the destroy fail with a ``datset is busy`` error.
+Holds are created and referred to by a user-defined *tag*. They can be thought of as a named, persistent lock on the snapshot.
+
+.. _replication-cursor-and-last-received-hold:
+
+Guaranteeing That Incremental Sends Are Always Possible
+^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
+
+**Replication cursor** bookmark and **last-received-hold** are managed by zrepl to ensure that future replications can always be done incrementally.
+The replication cursor is a send-side bookmark of the most recent successfully replicated snapshot,
+and the last-received-hold is a hold of that snapshot on the receiving side.
+Both are moved aomically after the receiving side has confirmed that a replication step is complete.
+
+The replication cursor has the format ``#zrepl_CUSOR_G_<GUID>_J_<JOBNAME>``.
+The last-received-hold tag has the format ``zrepl_last_received_J_<JOBNAME>``.
+Encoding the job name in the names ensures that multiple sending jobs can replicate the same filesystem to different receivers without interference.
+
+The ``zrepl zfs-abstraction list`` command provides a listing of all bookmarks and holds managed by zrepl.
+
+.. _step-holds-and-bookmarks:
+
+Guaranteeing That Sends Are Always Resumable
+^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
+
+**Step holds** are zfs holds managed by zrepl to ensure that a replication step can always be resumed if it is interrupted, e.g., due to network outage.
+zrepl creates step holds before it attempts a replication step and releases them after the receiver confirms that the replication step is complete.
+For an initial replication ``full @initial_snap``, zrepl puts a zfs hold on ``@initial_snap``.
+For an incremental send ``@from -> @to``, zrepl puts a zfs hold on both ``@from`` and ``@to``.
+Note that ``@from`` is not strictly necessary for resumability -- a bookmark on the sending side would be sufficient --, but size-estimation in currently used OpenZFS versions only works if ``@from`` is a snapshot.
+
+The hold tag has the format ``zrepl_STEP_J_<JOBNAME>``.
+A job only ever has one active send per filesystem.
+Thus, there are never more than two step holds for a given pair of ``(job,filesystem)``.
+
+**Step bookmarks** are zrepl's equivalent for holds on bookmarks (ZFS does not support putting holds on bookmarks).
+They are intended for a situation where a replication step uses a bookmark ``#bm`` as incremental ``from`` that is not managed by zrepl.
+To ensure resumability, zrepl copies ``#bm`` to step bookmark ``#zrepl_STEP_G_<GUID>_J_<JOBNAME>``.
+If the replication is interrupted and ``#bm`` is deleted by the user, the step bookmark remains as an incremental source for the resumable send.
+Note that zrepl does not yet support creating step bookmarks because the `corresponding ZFS feature for copying bookmarks <https://github.com/openzfs/zfs/pull/9571>`_ is not yet widely available .
+Subscribe to zrepl :issue:`326` for details.
+
+The ``zrepl zfs-abstraction list`` command provides a listing of all bookmarks and holds managed by zrepl.
+
+.. NOTE::
+
+    More details can be found in the design document :repomasterlink:`replication/design.md`.
+
+Limitations
+^^^^^^^^^^^
+
 .. ATTENTION::
 
     Currently, zrepl does not replicate filesystem properties.
     When receiving a filesystem, it is never mounted (`-u` flag)  and `mountpoint=none` is set.
     This is temporary and being worked on :issue:`24`.
 
-.. NOTE::
-
-    More details can be found in the design document :repomasterlink:`replication/design.md`.
-
 
 .. _jobs-multiple-jobs:
 
@@ -177,7 +240,7 @@ Multiple Jobs & More than 2 Machines
 If you would like to see improvements to multi-job setups, please `open an issue on GitHub <https://github.com/zrepl/zrepl/issues/new>`_.
 
 No Overlapping
-~~~~~~~~~~~~~~
+^^^^^^^^^^^^^^
 
 Jobs run independently of each other.
 If two jobs match the same filesystem with their ``filesystems`` filter, they will operate on that filesystem independently and potentially in parallel.
@@ -185,14 +248,14 @@ For example, if job A prunes snapshots that job B is planning to replicate, the
 However, the next replication attempt will re-examine the situation from scratch and should work.
 
 N push jobs to 1 sink
-~~~~~~~~~~~~~~~~~~~~~
+^^^^^^^^^^^^^^^^^^^^^
 
 The :ref:`sink job <job-sink>` namespaces by client identity.
 It is thus safe to push to one sink job with different client identities.
 If the push jobs have the same client identity, the filesystems matched by the push jobs must be disjoint to avoid races.
 
 N pull jobs from 1 source
-~~~~~~~~~~~~~~~~~~~~~~~~~
+^^^^^^^^^^^^^^^^^^^^^^^^^
 
 Multiple pull jobs pulling from the same source have potential for race conditions during pruning:
 each pull job prunes the source side independently, causing replication-prune and prune-prune races.

docs/configuration/sendrecvoptions.rst

@@ -16,6 +16,8 @@ Send Options
      filesystems: ...
      send:
        encrypted: true
+       step_holds:
+         disable_incremental: false
      ...
 
 :ref:`Source<job-source>` and :ref:`push<job-push>` jobs have an optional ``send`` configuration section.
@@ -34,6 +36,24 @@ Filesystems matched by ``filesystems`` that are not encrypted are not sent and w
 
 If ``encryption=false``, zrepl expects that filesystems matching ``filesystems`` are not encrypted or have loaded encryption keys.
 
+.. _job-send-option-step-holds-disable-incremental:
+
+``step_holds.disable_incremental`` option
+-----------------------------------------
+
+The ``step_holds.disable_incremental`` variable controls whether the creation of :ref:`step holds <step-holds-and-bookmarks>` should be disabled for incremental replication.
+The default value is ``false``.
+
+Disabling step holds has the disadvantage that steps :ref:`might not be resumable <step-holds-and-bookmarks>` if interrupted.
+Non-resumability means that replication progress is no longer monotonic which might result in a replication setup that never makes progress if mid-step interruptions are too frequent (e.g. frequent network outages).
+
+However, the advantage and :issue:`reason for existence <288>` of this flag is that it allows the pruner to delete snapshots of interrupted replication steps
+which is useful if replication happens so rarely (or fails so frequently) that the amount of disk space exclusively referenced by the step's snapshots becomes intolerable.
+
+.. NOTE::
+
+   When setting this flag to ``true``, existing step holds for the job will be destroyed on the next replication attempt.
+
 .. _job-recv-options:
 
 Recv Options

docs/configuration/transports.rst

@@ -52,8 +52,15 @@ Serve
         listen: ":8888"
         listen_freebind: true # optional, default false
         clients: {
-          "192.168.122.123" : "mysql01"
+          "192.168.122.123" :               "mysql01",
-          "192.168.122.123" : "mx01"
+          "192.168.122.42" :                "mx01",
+          "2001:0db8:85a3::8a2e:0370:7334": "gateway",
+
+          # CIDR masks require a '*' in the client identity string
+          # that is expanded to the client's IP address
+
+          "10.23.42.0/24":       "cluster-*"
+          "fde4:8dba:82e1::/64": "san-*"
         }
       ...
 

docs/gen-sphinx-versioning-flags.py

@@ -0,0 +1,76 @@
+#!/usr/bin/env python3
+
+import subprocess
+import re
+
+output = subprocess.run(["git", "tag", "-l"], capture_output=True, check=True, text=True)
+tagRE = re.compile(r"^v(?P<major>\d+)\.(?P<minor>\d+)\.(?P<patch>\d+)(-rc(?P<rc>\d+))?$")
+class Tag:
+    orig: str
+    major: int
+    minor: int
+    patch: int
+    rc: int
+
+    def __str__(self):
+        return self.orig
+
+    def __repr__(self):
+        return self.orig
+
+tags = []
+for line in output.stdout.split("\n"):
+    m = tagRE.match(line)
+    if not m:
+        continue
+    m = m.groupdict()
+
+    t = Tag()
+    t.orig = line
+    t.major = int(m["major"])   
+    t.minor = int(m["minor"])   
+    t.patch = int(m["patch"])
+    t.rc = int(m["rc"] if m["rc"] is not None else 0)
+
+    tags.append(t)
+
+by_major_minor = {}
+
+for tag in tags:
+    key = (tag.major, tag.minor)
+    l = by_major_minor.get(key, [])
+    l.append(tag)
+    by_major_minor[key] = l
+
+latest_by_major_minor = []
+for (mm, l) in by_major_minor.items():
+    # sort ascending by patch-level (rc's weigh less)
+    l.sort(key=lambda tag: (tag.patch, int(tag.rc == 0), tag.rc))
+    latest_by_major_minor.append(l[-1])
+latest_by_major_minor.sort(key=lambda tag: (tag.major, tag.minor))
+
+# print(by_major_minor)
+# print(latest_by_major_minor)
+
+cmdline = []
+
+for latest_patch in latest_by_major_minor:
+    cmdline.append("--whitelist-tags")
+    cmdline.append(f"^{re.escape(latest_patch.orig)}$")
+
+# we want to render the latest non-rc version as the default page
+# (latest_by_major_minor is already sorted)
+default_version = latest_by_major_minor[-1]
+for tag in reversed(latest_by_major_minor):
+    if tag.rc == 0:
+        default_version = tag
+        break
+
+cmdline.extend(["--root-ref", f"{default_version}"])
+cmdline.extend(["--banner-main-ref", f"{default_version}"])
+cmdline.extend(["--show-banner"])
+cmdline.extend(["--sort", "semver"])
+
+cmdline.extend(["--whitelist-branches", "master"])
+
+print(" ".join(cmdline))

docs/global.rst.inc

@@ -11,10 +11,12 @@
    :target: https://zrepl.github.io
 .. |Donate via PayPal| image:: https://img.shields.io/badge/donate-paypal-yellow.svg
    :target: https://www.paypal.com/cgi-bin/webscr?cmd=_s-xclick&hosted_button_id=R5QSXJVYHGX96
-.. |Donate via Liberapay| image:: https://img.shields.io/liberapay/receives/zrepl.svg?logo=liberapay
+.. |Donate via Liberapay| image:: https://img.shields.io/liberapay/patrons/zrepl.svg?logo=liberapay
    :target: https://liberapay.com/zrepl/donate
 .. |Donate via Patreon| image:: https://img.shields.io/endpoint.svg?url=https%3A%2F%2Fshieldsio-patreon.herokuapp.com%2Fzrepl%2Fpledges&style=flat&color=yellow
    :target: https://www.patreon.com/zrepl
+.. |Donate via GitHub Sponsors| image:: https://img.shields.io/static/v1?label=Sponsor&message=%E2%9D%A4&logo=GitHub&style=flat&color=yellow
+   :target: https://github.com/sponsors/problame
 .. |Twitter| image:: https://img.shields.io/twitter/url/https/github.com/zrepl/zrepl.svg?style=social
    :target: https://twitter.com/intent/tweet?text=Wow:&url=https%3A%2F%2Fgithub.com%2Fzrepl%2Fzrepl
 
@@ -25,4 +27,8 @@
 .. |recv-options| replace:: :ref:`recv options<job-recv-options>`
 .. |snapshotting-spec| replace:: :ref:`snapshotting specification <job-snapshotting-spec>`
 .. |pruning-spec| replace:: :ref:`pruning specification <prune>`
-.. |filter-spec| replace:: :ref:`filter specification<pattern-filter>`
+.. |filter-spec| replace:: :ref:`filter specification<pattern-filter>`
+
+.. |br| raw:: html
+
+   <br/>

docs/index.rst

@@ -5,7 +5,7 @@
 
 .. include:: global.rst.inc
 
-|GitHub license| |Language: Go| |Twitter| |Donate via Patreon| |Donate via Liberapay| |Donate via PayPal| 
+|GitHub license| |Language: Go| |Twitter| |Donate via Patreon| |Donate via GitHub Sponsors| |Donate via Liberapay| |Donate via PayPal|
 
 
 zrepl - ZFS replication
@@ -44,7 +44,7 @@ zrepl - ZFS replication
 Getting started
 ~~~~~~~~~~~~~~~
 
-The :ref:`10 minutes tutorial setup <tutorial>` gives you a first impression.
+The :ref:`10 minute quick-start guides <quickstart-toc>` give you a first impression.
 
 Main Features
 ~~~~~~~~~~~~~
@@ -125,7 +125,7 @@ Table of Contents
    :maxdepth: 2
    :caption: Contents:
 
-   tutorial
+   quickstart
    installation
    configuration
    usage

docs/installation.rst

@@ -1,138 +1,19 @@
-.. _binary releases: https://github.com/zrepl/zrepl/releases
 
-.. _installation:
+.. _installation_toc:
 
+************
 Installation
-============
+************
 
 .. TIP::
 
-    Note: check out the :ref:`tutorial` if you want a first impression of zrepl.
+    Note: check out the :ref:`quick-start guides <quickstart-toc>` if you want a first impression of zrepl.
 
-User Privileges
+.. toctree::
----------------
 
-It is possible to run zrepl as an unprivileged user in combination with
+    installation/user-privileges
-`ZFS delegation <https://www.freebsd.org/doc/handbook/zfs-zfs-allow.html>`_.
+    installation/packages
-Also, there is the possibility to run it in a jail on FreeBSD by delegating a dataset to the jail.
+    installation/apt-repos
-However, until we get around documenting those setups, you will have to run zrepl as root or experiment yourself :)
+    installation/compile-from-source
-
+    installation/freebsd-jail-with-iocage
-Packages
+    installation/what-next
---------
-
-zrepl source releases are signed & tagged by the author in the git repository.
-Your OS vendor may provide binary packages of zrepl through the package manager.
-Additionally, `binary releases`_ are provided on GitHub.
-The following list may be incomplete, feel free to submit a PR with an update:
-
-.. list-table::
-    :header-rows: 1
-
-    * - OS / Distro
-      - Install Command
-      - Link
-    * - FreeBSD
-      - ``pkg install zrepl``
-      - `<https://www.freshports.org/sysutils/zrepl/>`_
-    * - MacOS
-      - ``brew install zrepl``
-      - Available on `homebrew <https://brew.sh>`_
-    * - Arch Linux
-      - ``yay install zrepl``
-      - Available on `AUR <https://aur.archlinux.org/packages/zrepl>`_
-    * - Fedora
-      - ``dnf install zrepl``
-      - Available on `COPR <https://copr.fedorainfracloud.org/coprs/poettlerric/zrepl/>`_
-    * - CentOS/RHEL
-      - ``yum install zrepl``
-      - Available on `COPR <https://copr.fedorainfracloud.org/coprs/poettlerric/zrepl/>`_
-    * - Debian + Ubuntu
-      - ``apt install zrepl``
-      - APT repository config :ref:`see below <installation-apt-repos>`
-    * - OmniOS
-      - ``pkg install zrepl``
-      - Available since `r151030 <https://pkg.omniosce.org/r151030/extra/en/search.shtml?token=zrepl&action=Search>`_
-    * - Void Linux
-      - ``xbps-install zrepl``
-      - Available since `a88a2a4 <https://github.com/void-linux/void-packages/commit/a88a2a4d7bf56072dadf61ab56b8424e39155890>`_
-    * - Others
-      -
-      - Use `binary releases`_ or build from source.
-
-.. _installation-apt-repos:
-
-Debian / Ubuntu APT repositories
-~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
-
-We maintain APT repositories for Debian, Ubuntu and derivatives.
-The fingerprint of the signing key is ``E101 418F D3D6 FBCB 9D65  A62D 7086 99FC 5F2E BF16``.
-It is available at `<https://zrepl.cschwarz.com/apt/apt-key.asc>`_ .
-Please open an issue `in the packaging repository <https://github.com/zrepl/debian-binary-packaging>`_ if you encounter any issues with the repository.
-
-The following snippet configure the repository for your Debian or Ubuntu release:
-
-::
-
-    apt update && apt install curl gnupg lsb-release; \
-    ARCH="$(dpkg --print-architecture)"; \
-    CODENAME="$(lsb_release -i -s | tr '[:upper:]' '[:lower:]') $(lsb_release -c -s | tr '[:upper:]' '[:lower:]')"; \
-    echo "Using Distro and Codename: $CODENAME"; \
-    (curl https://zrepl.cschwarz.com/apt/apt-key.asc | apt-key add -) && \
-    (echo "deb [arch=$ARCH] https://zrepl.cschwarz.com/apt/$CODENAME main" > /etc/apt/sources.list.d/zrepl.list) && \
-    apt update
-
-
-.. NOTE::
-
-   Until zrepl reaches 1.0, all APT repositories will be updated to the latest zrepl release immediately.
-   This includes breaking changes between zrepl versions.
-   Use ``apt-mark hold zrepl`` to prevent upgrades of zrepl.
-
-Compile From Source
-~~~~~~~~~~~~~~~~~~~
-
-Producing a release requires **Go 1.11** or newer and **Python 3** + **pip3** + ``docs/requirements.txt`` for the Sphinx documentation.
-A tutorial to install Go is available over at `golang.org <https://golang.org/doc/install>`_.
-Python and pip3 should probably be installed via your distro's package manager.
-
-Alternatively, you can use the Docker build process:
-it is used to produce the official zrepl `binary releases`_
-and serves as a reference for build dependencies and procedure:
-
-::
-
-    git clone https://github.com/zrepl/zrepl.git && \
-    cd zrepl && \
-    sudo docker build -t zrepl_build -f build.Dockerfile . && \
-    sudo docker run -it --rm \
-        -v "${PWD}:/src" \
-        --user "$(id -u):$(id -g)" \
-        zrepl_build make release
-
-Alternatively, you can install build dependencies on your local system and then build in your ``$GOPATH``:
-
-::
-
-    mkdir -p "${GOPATH}/src/github.com/zrepl/zrepl"
-    git clone https://github.com/zrepl/zrepl.git "${GOPATH}/src/github.com/zrepl/zrepl"
-    cd "${GOPATH}/src/github.com/zrepl/zrepl"
-    python3 -m venv3
-    source venv3/bin/activate
-    ./lazy.sh devsetup
-    make release
-
-The Python venv is used for the documentation build dependencies.
-If you just want to build the zrepl binary, leave it out and use `./lazy.sh godep` instead.
-Either way, all build results are located in the ``artifacts/`` directory.
-
-.. NOTE::
-
-    It is your job to install the appropriate binary in the zrepl users's ``$PATH``, e.g. ``/usr/local/bin/zrepl``.
-    Otherwise, the examples in the :ref:`tutorial` may need to be adjusted.
-
-What next?
-----------
-
-Read the :ref:`configuration chapter<configuration_toc>` and then continue with the :ref:`usage chapter<usage>`.
-
-**Reminder**: If you want a quick introduction, please read the :ref:`tutorial`.

docs/installation/apt-repos.rst

@@ -0,0 +1,29 @@
+
+.. _installation-apt-repos:
+
+Debian / Ubuntu APT repositories
+~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+
+We maintain APT repositories for Debian, Ubuntu and derivatives.
+The fingerprint of the signing key is ``E101 418F D3D6 FBCB 9D65  A62D 7086 99FC 5F2E BF16``.
+It is available at `<https://zrepl.cschwarz.com/apt/apt-key.asc>`_ .
+Please open an issue `in the packaging repository <https://github.com/zrepl/debian-binary-packaging>`_ if you encounter any issues with the repository.
+
+The following snippet configure the repository for your Debian or Ubuntu release:
+
+::
+
+    apt update && apt install curl gnupg lsb-release; \
+    ARCH="$(dpkg --print-architecture)"; \
+    CODENAME="$(lsb_release -i -s | tr '[:upper:]' '[:lower:]') $(lsb_release -c -s | tr '[:upper:]' '[:lower:]')"; \
+    echo "Using Distro and Codename: $CODENAME"; \
+    (curl https://zrepl.cschwarz.com/apt/apt-key.asc | apt-key add -) && \
+    (echo "deb [arch=$ARCH] https://zrepl.cschwarz.com/apt/$CODENAME main" > /etc/apt/sources.list.d/zrepl.list) && \
+    apt update
+
+
+.. NOTE::
+
+   Until zrepl reaches 1.0, all APT repositories will be updated to the latest zrepl release immediately.
+   This includes breaking changes between zrepl versions.
+   Use ``apt-mark hold zrepl`` to prevent upgrades of zrepl.

docs/installation/compile-from-source.rst

@@ -0,0 +1,45 @@
+.. _binary releases: https://github.com/zrepl/zrepl/releases
+
+.. _installation-compile-from-source:
+
+Compile From Source
+~~~~~~~~~~~~~~~~~~~
+
+Producing a release requires **Go 1.11** or newer and **Python 3** + **pip3** + ``docs/requirements.txt`` for the Sphinx documentation.
+A tutorial to install Go is available over at `golang.org <https://golang.org/doc/install>`_.
+Python and pip3 should probably be installed via your distro's package manager.
+
+Alternatively, you can use the Docker build process:
+it is used to produce the official zrepl `binary releases`_
+and serves as a reference for build dependencies and procedure:
+
+::
+
+    git clone https://github.com/zrepl/zrepl.git && \
+    cd zrepl && \
+    sudo docker build -t zrepl_build -f build.Dockerfile . && \
+    sudo docker run -it --rm \
+        -v "${PWD}:/src" \
+        --user "$(id -u):$(id -g)" \
+        zrepl_build make release
+
+Alternatively, you can install build dependencies on your local system and then build in your ``$GOPATH``:
+
+::
+
+    mkdir -p "${GOPATH}/src/github.com/zrepl/zrepl"
+    git clone https://github.com/zrepl/zrepl.git "${GOPATH}/src/github.com/zrepl/zrepl"
+    cd "${GOPATH}/src/github.com/zrepl/zrepl"
+    python3 -m venv3
+    source venv3/bin/activate
+    ./lazy.sh devsetup
+    make release
+
+The Python venv is used for the documentation build dependencies.
+If you just want to build the zrepl binary, leave it out and use `./lazy.sh godep` instead.
+Either way, all build results are located in the ``artifacts/`` directory.
+
+.. NOTE::
+
+    It is your job to install the appropriate binary in the zrepl users's ``$PATH``, e.g. ``/usr/local/bin/zrepl``.
+    Otherwise, the examples in the :ref:`quick-start guides <quickstart-toc>` may need to be adjusted.

docs/installation/freebsd-jail-with-iocage.rst

@@ -0,0 +1,140 @@
+.. include:: ../global.rst.inc
+
+.. _installation-freebsd-jail-with-iocage:
+
+FreeBSD Jail With iocage
+========================
+
+
+This tutorial shows how zrepl can be installed on FreeBSD, or FreeNAS in a jail using iocage.
+While this tutorial focuses on using iocage, much of the setup would be similar
+using a different jail manager.
+
+.. NOTE::
+
+   From a security perspective, just keep in mind that ``zfs send``/``recv`` was never designed with
+   jails in mind, an attacker could probably crash the receive-side kernel or worse induce stateful
+   damage to the receive-side pool if they were able to get access to the jail.
+
+   The jail doesn't provide security benefits, but only management ones.
+
+Requirements
+------------
+
+A dataset that will be delegated to the jail needs to be created if one does not already exist.
+For the tutorial ``tank/zrepl`` will be used.
+
+.. code-block:: bash
+
+   zfs create -o mountpoint=none tank/zrepl
+
+The only software requirements on the host system are ``iocage``, which can be installed
+from ports or packages.
+
+.. code-block:: bash
+
+   pkg install py37-iocage
+
+.. NOTE::
+
+   By default ``iocage`` will "activate" on first use which will set up some defaults such as
+   which pool will be used. To activate ``iocage`` manually the ``iocage activate`` command can be used.
+
+Jail Creation
+-------------
+
+There are two options for jail creation using FreeBSD.
+
+1. Manually set up the jail from scratch
+2. Create the jail using the ``zrepl`` plugin. On FreeNAS this is possible from the user interface using the community index.
+
+Manual Jail
+###########
+
+Create a jail, using the same release as the host, called ``zrepl`` that will be automatically started at boot.
+The jail will have ``tank/zrepl`` delegated into it.
+
+.. code-block:: bash
+
+   iocage create --release "$(freebsd-version -k | cut -d '-' -f '1,2')" --name zrepl \
+          boot=on nat=1 \
+          jail_zfs=on \
+          jail_zfs_dataset=zrepl \
+          jail_zfs_mountpoint='none'
+
+Enter the jail:
+
+.. code-block:: bash
+
+   iocage console zrepl
+
+Install ``zrepl``
+
+.. code-block:: bash
+
+   pkg update && pkg upgrade
+   pkg install zrepl
+
+Create the log file ``/var/log/zrepl.log``
+
+.. code-block:: bash
+
+   touch /var/log/zrepl.log && service newsyslog restart
+
+Tell syslogd to redirect facility local0 to the ``zrepl.log`` file:
+
+.. code-block:: bash
+
+   service syslogd reload
+
+Enable the zrepl daemon to start automatically at boot:
+
+.. code-block:: bash
+
+   sysrc zrepl_enable="YES"
+
+
+Plugin
+######
+
+When using the plugin, ``zrepl`` will be installed for you in a jail using the following ``iocage`` properties.
+
+* ``nat=1``
+* ``jail_zfs=on``
+* ``jail_zfs_mountpoint=none``
+
+Additionally the delegated dataset should be specified upon creation, and optionally start on boot can be set.
+This can also be done from the FreeNAS webui.
+
+.. code-block:: bash
+
+   fetch https://raw.githubusercontent.com/ix-plugin-hub/iocage-plugin-index/master/zrepl.json -o /tmp/zrepl.json
+   iocage fetch -P /tmp/zrepl.json --name zrepl jail_zfs_dataset=zrepl boot=on
+
+Configuration
+-------------
+
+Now ``zrepl`` can be configured.
+
+Enter the jail.
+
+.. code-block:: bash
+
+   iocage console zrepl
+
+Modify the ``/usr/local/etc/zrepl/zrepl.yml`` configuration file.
+
+.. TIP::
+
+    Note: check out the :ref:`quick-start guides <quickstart-toc>` for examples of a ``sink`` job.
+
+Now ``zrepl`` can be started.
+
+.. code-block:: bash
+
+   service zrepl start
+
+Summary
+-------
+
+Congratulations, you have a working jail!

docs/installation/packages.rst

@@ -0,0 +1,50 @@
+.. _installation-packages:
+
+.. _binary releases: https://github.com/zrepl/zrepl/releases
+
+Packages
+--------
+
+zrepl source releases are signed & tagged by the author in the git repository.
+Your OS vendor may provide binary packages of zrepl through the package manager.
+Additionally, `binary releases`_ are provided on GitHub.
+The following list may be incomplete, feel free to submit a PR with an update:
+
+.. list-table::
+    :header-rows: 1
+
+    * - OS / Distro
+      - Install Command
+      - Link
+    * - FreeBSD
+      - ``pkg install zrepl``
+      - `<https://www.freshports.org/sysutils/zrepl/>`_
+      
+        :ref:`installation-freebsd-jail-with-iocage`
+    * - FreeNAS
+      -
+      - :ref:`installation-freebsd-jail-with-iocage`
+    * - MacOS
+      - ``brew install zrepl``
+      - Available on `homebrew <https://brew.sh>`_
+    * - Arch Linux
+      - ``yay install zrepl``
+      - Available on `AUR <https://aur.archlinux.org/packages/zrepl>`_
+    * - Fedora
+      - ``dnf install zrepl``
+      - Available on `COPR <https://copr.fedorainfracloud.org/coprs/poettlerric/zrepl/>`_
+    * - CentOS/RHEL
+      - ``yum install zrepl``
+      - Available on `COPR <https://copr.fedorainfracloud.org/coprs/poettlerric/zrepl/>`_
+    * - Debian + Ubuntu
+      - ``apt install zrepl``
+      - APT repository config :ref:`see below <installation-apt-repos>`
+    * - OmniOS
+      - ``pkg install zrepl``
+      - Available since `r151030 <https://pkg.omniosce.org/r151030/extra/en/search.shtml?token=zrepl&action=Search>`_
+    * - Void Linux
+      - ``xbps-install zrepl``
+      - Available since `a88a2a4 <https://github.com/void-linux/void-packages/commit/a88a2a4d7bf56072dadf61ab56b8424e39155890>`_
+    * - Others
+      -
+      - Use `binary releases`_ or build from source.

docs/installation/user-privileges.rst

@@ -0,0 +1,12 @@
+.. _installation-user-privileges:
+
+User Privileges
+---------------
+
+It is possible to run zrepl as an unprivileged user in combination with
+`ZFS delegation <https://www.freebsd.org/doc/handbook/zfs-zfs-allow.html>`_.
+Also, there is the possibility to run it in a jail on FreeBSD by delegating a dataset to the jail.
+
+.. TIP::
+
+    Note: check out the :ref:`installation-freebsd-jail-with-iocage` for FreeBSD jail setup instructions.

docs/installation/what-next.rst

@@ -0,0 +1,8 @@
+.. _installation-what-next:
+
+What next?
+----------
+
+Read the :ref:`configuration chapter<configuration_toc>` and then continue with the :ref:`usage chapter<usage>`.
+
+**Reminder**: If you want a quick introduction, please read the :ref:`quick-start guides <quickstart-toc>`.

docs/publish.sh

@@ -51,11 +51,10 @@ git rm -rf .
 popd
 
 echo "building site"
+
 set -e
 sphinx-versioning build \
-   --show-banner \
+   $(python3 gen-sphinx-versioning-flags.py) \
-   --whitelist-branches '^master$' \
-   --whitelist-tags '(v)?\d+\.[1-9][0-9]*.\d+$' \
    docs ./public_git \
    -- -c sphinxconf # older conf.py throw errors because they used
                     # version = subprocess.show_output(["git", "describe"])

docs/quickstart.rst

@@ -0,0 +1,87 @@
+.. include:: global.rst.inc
+
+.. _quickstart-toc:
+
+***********************
+Quick Start by Use Case
+***********************
+
+The goal of this quick-start guide is to give you an impression of how zrepl can accomodate your use case.
+
+Install zrepl
+=============
+
+Follow the :ref:`OS-specific installation instructions <installation_toc>` and come back here.
+
+Overview Of How zrepl Works
+============================
+
+Check out the :ref:`overview section <job-overview>` to get a rough idea of what you are going to configure in the next step, then come back here.
+
+Configuration Examples
+======================
+
+zrepl is configured through a YAML configuration file in ``/etc/zrepl/zrepl.yml``.
+We have prepared example use cases that show-case typical deployments and different functionality of zrepl.
+We encourage you to read through all of the examples to get an idea of what zrepl has to offer, and how you can mix-and-match configurations for your use case.
+Keep the :ref:`full config documentation <configuration_toc>` handy if a config snippet is unclear.
+
+**Example Use Cases**
+
+.. toctree::
+   :titlesonly:
+
+   quickstart/continuous_server_backup
+   quickstart/backup_to_external_disk
+
+Use ``zrepl configcheck`` to validate your configuration.
+No output indicates that everything is fine.
+
+.. NOTE::
+
+   Please open an issue on GitHub if your use case for zrepl is significantly different from those listed above.
+   Or even better, write it up in the same style as above and open a PR!
+
+.. _quickstart-apply-config:
+
+Apply Configuration Changes
+===========================
+
+We hope that you have found a configuration that fits your use case.
+Use ``zrepl configcheck`` once again to make sure the config is correct (output indicates that everything is fine).
+Then restart the zrepl daemon on all systems involved in the replication, likely using ``service zrepl restart`` or ``systemctl restart zrepl``.
+
+Watch it Work
+=============
+
+Run ``zrepl status`` on the active side of the replication setup to monitor snaphotting, replication and pruning activity.
+To re-trigger replication (snapshots are separate!), use ``zrepl signal wakeup JOBNAME``.
+(refer to the example use case document if you are uncertain which job you want to wake up).
+
+You can also use basic UNIX tools to inspect see what's going on.
+If you like tmux, here is a handy script that works on FreeBSD: ::
+
+    pkg install gnu-watch tmux
+    tmux new -s zrepl -d
+    tmux split-window -t zrepl "tail -f /var/log/messages"
+    tmux split-window -t zrepl "gnu-watch 'zfs list -t snapshot -o name,creation -s creation'"
+    tmux split-window -t zrepl "zrepl status"
+    tmux select-layout -t zrepl tiled
+    tmux attach -t zrepl
+
+The Linux equivalent might look like this: ::
+
+    # make sure tmux is installed & let's assume you use systemd + journald
+    tmux new -s zrepl -d
+    tmux split-window -t zrepl  "journalctl -f -u zrepl.service"
+    tmux split-window -t zrepl "watch 'zfs list -t snapshot -o name,creation -s creation'"
+    tmux split-window -t zrepl "zrepl status"
+    tmux select-layout -t zrepl tiled
+    tmux attach -t zrepl
+
+What Next?
+==========
+
+* Read more about :ref:`configuration format, options & job types <configuration_toc>`
+* Configure :ref:`logging <logging>` \& :ref:`monitoring <monitoring>`.
+

docs/quickstart/backup_to_external_disk.rst

@@ -0,0 +1,36 @@
+.. include:: ../global.rst.inc
+
+.. _quickstart-backup-to-external-disk:
+
+Local Snapshots + Offline Backup to an External Disk
+====================================================
+
+This config example shows how we can use zrepl to make periodic snapshots of our local workstation and back it up to a zpool on an external disk which we occassionally connect.
+
+The local snapshots should be taken every 15 minutes for pain-free recovery from CLI disasters (``rm -rf /`` and the like).
+However, we do not want to keep the snapshots around for very long because our workstation is a little tight on disk space.
+Thus, we only keep one hour worth of high-resolution snapshots, then fade them out to one per hour for a day (24 hours), then one per day for 14 days.
+
+At the end of each work day, we connect our external disk that serves as our workstation's local offline backup.
+We want zrepl to inspect the filesystems and snapshots on the external pool, figure out which snapshots were created since the last time we connected the external disk, and use incremental replication to efficiently mirror our workstation to our backup disk.
+Afterwards, we want to clean up old snapshots on the backup pool: we want to keep all snapshots younger than one hour, 24 for each hor of the first day, then 360 daily backups.
+
+A few additional requirements:
+
+* Snapshot creation and pruning on our workstation should happen in the background, without interaction from our side.
+* However, we want to explicitly trigger replication via the command line.
+* We want to use OpenZFS native encryption to protect our data on the external disk.
+  It is absolutely critical that only encrypted data leaves our workstation.
+  **zrepl should provide an easy config knob for this and prevent replication of unencrypted datasets to the external disk.**
+* We want to be able to put off the backups for more than three weeks, i.e., longer than the lifetime of the automatically created snapshots on our workstation.
+  **zrepl should use bookmarks and holds to achieve this goal**.
+* When we yank out the drive during replication and go on a long vacation, we do *not* want the partially replicated snapshot to stick around as it would hold on to too much disk space over time.
+  Therefore, we want zrepl to deviate from its :ref:`default step-hold behavior <step-holds-and-bookmarks>` and sacrifice resumability, but nonetheless retain the ability to do incremental replication once we return from our vacation.
+  **zrepl should provide an easy config knob to disable step holds for incremental replication**.
+
+The following config snippet implements the setup described above.
+You will likely want to customize some aspects mentioned in the top comment in the file.
+
+.. literalinclude:: ../../config/samples/quickstart_backup_to_external_disk.yml
+
+:ref:`Click here <quickstart-apply-config>` to go back to the quickstart guide.

docs/quickstart/continuous_server_backup.rst

@@ -0,0 +1,97 @@
+.. include:: ../global.rst.inc
+
+.. _quickstart-continuous-replication:
+
+Continuous Backup of a Server
+=============================
+
+This config example shows how we can backup our ZFS-based server to another machine using a zrepl push job.
+
+* Production server ``prod`` with filesystems to back up:
+
+  * ``zroot/var/db``
+  * ``zroot/usr/home`` and all its child filesystems
+  * **except** ``zroot/usr/home/paranoid`` belonging to a user doing backups themselves
+
+* Backup server ``backups`` with
+
+  * Filesystem ``storage/zrepl/sink/prod`` + children dedicated to backups of ``prod``
+
+Our backup solution should fulfill the following requirements:
+
+* Periodically snapshot the filesystems on ``prod`` *every 10 minutes*
+* Incrementally replicate these snapshots to ``storage/zrepl/sink/prod/*`` on ``backups``
+* Keep only very few snapshots on ``prod`` to save disk space
+* Keep a fading history (24 hourly, 30 daily, 6 monthly) of snapshots on ``backups``
+* The network is untrusted - zrepl should use TLS to protect its communication and our data.
+
+Analysis
+--------
+
+We can model this situation as two jobs:
+
+* A **push job** on ``prod``
+
+  * Creates the snapshots
+  * Keeps a short history of local snapshots to enable incremental replication to ``backups``
+  * Connects to the ``zrepl daemon`` process on ``backups``
+  * Pushes snapshots ``backups``
+  * Prunes snapshots on ``backups`` after replication is complete
+
+* A **sink job** on ``backups``
+
+  * Accepts connections & responds to requests from ``prod``
+  * Limits client ``prod`` access to filesystem sub-tree ``storage/zrepl/sink/prod``
+
+Generate TLS Certificates
+-------------------------
+
+We use the :ref:`TLS client authentication transport <transport-tcp+tlsclientauth>` to protect our data on the wire.
+To get things going quickly, we skip setting up a CA and generate two self-signed certificates as described :ref:`here <transport-tcp+tlsclientauth-2machineopenssl>`.
+For convenience, we generate the key pairs on our local machine and distribute them using ssh:
+
+.. code-block:: bash
+   :emphasize-lines: 6,13
+
+   openssl req -x509 -sha256 -nodes \
+      -newkey rsa:4096 \
+      -days 365 \
+      -keyout backups.key \
+      -out backups.crt
+   # ... and use "backups" as Common Name (CN)
+
+   openssl req -x509 -sha256 -nodes \
+      -newkey rsa:4096 \
+      -days 365 \
+      -keyout prod.key \
+      -out prod.crt
+   # ... and use "prod" as Common Name (CN)
+
+   ssh root@backups "mkdir /etc/zrepl"
+   scp  backups.key backups.crt prod.crt root@backups:/etc/zrepl
+
+   ssh root@prod "mkdir /etc/zrepl"
+   scp  prod.key prod.crt backups.crt root@prod:/etc/zrepl
+
+Note that alternative transports exist, e.g. via :ref:`TCP without TLS <transport-tcp>` or :ref:`ssh <transport-ssh+stdinserver>`.
+
+Configure server ``prod``
+-------------------------
+
+We define a **push job** named ``prod_to_backups`` in ``/etc/zrepl/zrepl.yml`` on host ``prod`` :
+
+.. literalinclude:: ../../config/samples/quickstart_continuous_server_backup_sender.yml
+
+.. _tutorial-configure-prod:
+
+Configure server ``backups``
+----------------------------
+
+We define a corresponding **sink job** named ``sink`` in ``/etc/zrepl/zrepl.yml`` on host ``backups`` :
+
+.. literalinclude:: ../../config/samples/quickstart_continuous_server_backup_receiver.yml
+
+Go Back To Quickstart Guide
+---------------------------
+
+:ref:`Click here <quickstart-apply-config>` to go back to the quickstart guide.

docs/supporters.rst

@@ -2,7 +2,7 @@
 
 .. _supporters:
 
-|Donate via Patreon| |Donate via Liberapay| |Donate via PayPal|
+|Donate via Patreon| |Donate via GitHub Sponsors| |Donate via Liberapay| |Donate via PayPal|
 
 zrepl is a spare-time project primarily developed by `Christian Schwarz <https://cschwarz.com>`_.
 You can support maintenance and feature development through one of the services listed above.
@@ -32,6 +32,9 @@ We would like to thank the following people and organizations for supporting zre
 
    <div class="fa fa-code" style="width: 1em;"></div>
 
+* |supporter-std| Henning Kessler
+* |supporter-std| `John Ramsden <https://github.com/johnramsden>`_
+* |supporter-std| `DrLuke <https://github.com/drluke>`_
 * |supporter-gold| `Mateusz Kwiatkowski (runhyve.app) <https://runhyve.app>`_
 * |supporter-std| `Gaelan D'costa <https://www.robot-disco.net>`_
 * |supporter-std| `Tenzin Lhakhang <https://confluence.tenzin.io>`_

docs/tutorial.rst

@@ -1,177 +0,0 @@
-.. include:: global.rst.inc
-
-.. _tutorial:
-
-Tutorial
-========
-
-
-This tutorial shows how zrepl can be used to implement a ZFS-based push backup.
-We assume the following scenario:
-
-* Production server ``prod`` with filesystems to back up:
-
-  * ``zroot/var/db``
-  * ``zroot/usr/home`` and all its child filesystems
-  * **except** ``zroot/usr/home/paranoid`` belonging to a user doing backups themselves
-
-* Backup server ``backups`` with
-
-  * Filesystem ``storage/zrepl/sink/prod`` + children dedicated to backups of ``prod``
-
-Our backup solution should fulfill the following requirements:
-
-* Periodically snapshot the filesystems on ``prod`` *every 10 minutes*
-* Incrementally replicate these snapshots to ``storage/zrepl/sink/prod/*`` on ``backups``
-* Keep only very few snapshots on ``prod`` to save disk space
-* Keep a fading history (24 hourly, 30 daily, 6 monthly) of snapshots on ``backups``
-
-Analysis
---------
-
-We can model this situation as two jobs:
-
-* A **push job** on ``prod``
-
-  * Creates the snapshots
-  * Keeps a short history of local snapshots to enable incremental replication to ``backups``
-  * Connects to the ``zrepl daemon`` process on ``backups``
-  * Pushes snapshots ``backups``
-  * Prunes snapshots on ``backups`` after replication is complete
-
-* A **sink job** on ``backups``
-
-  * Accepts connections & responds to requests from ``prod``
-  * Limits client ``prod`` access to filesystem sub-tree ``storage/zrepl/sink/prod``
-
-Install zrepl
--------------
-
-Follow the :ref:`OS-specific installation instructions <installation>` and come back here.
-
-Generate TLS Certificates
--------------------------
-
-We use the :ref:`TLS client authentication transport <transport-tcp+tlsclientauth>` to protect our data on the wire.
-To get things going quickly, we skip setting up a CA and generate two self-signed certificates as described :ref:`here <transport-tcp+tlsclientauth-2machineopenssl>`.
-For convenience, we generate the key pairs on our local machine and distribute them using ssh:
-
-.. code-block:: bash
-   :emphasize-lines: 6,13
-
-   openssl req -x509 -sha256 -nodes \
-      -newkey rsa:4096 \
-      -days 365 \
-      -keyout backups.key \
-      -out backups.crt
-   # ... and use "backups" as Common Name (CN)
-
-   openssl req -x509 -sha256 -nodes \
-      -newkey rsa:4096 \
-      -days 365 \
-      -keyout prod.key \
-      -out prod.crt
-   # ... and use "prod" as Common Name (CN)
-
-   ssh root@backups "mkdir /etc/zrepl"
-   scp  backups.key backups.crt prod.crt root@backups:/etc/zrepl
-
-   ssh root@prod "mkdir /etc/zrepl"
-   scp  prod.key prod.crt backups.crt root@prod:/etc/zrepl
-
-
-Configure server ``prod``
--------------------------
-
-We define a **push job** named ``prod_to_backups`` in ``/etc/zrepl/zrepl.yml`` on host ``prod`` : ::
-
-    jobs:
-    - name: prod_to_backups
-      type: push 
-      connect:
-        type: tls
-        address: "backups.example.com:8888"
-        ca: /etc/zrepl/backups.crt
-        cert: /etc/zrepl/prod.crt
-        key:  /etc/zrepl/prod.key
-        server_cn: "backups"
-      filesystems: {
-        "zroot/var/db": true,
-        "zroot/usr/home<": true,
-        "zroot/usr/home/paranoid": false
-      }
-      snapshotting:
-        type: periodic
-        prefix: zrepl_
-        interval: 10m
-      pruning:
-        keep_sender:
-        - type: not_replicated
-        - type: last_n
-          count: 10
-        keep_receiver:
-        - type: grid
-          grid: 1x1h(keep=all) | 24x1h | 30x1d | 6x30d
-          regex: "^zrepl_"
-
-.. _tutorial-configure-prod:
-
-Configure server ``backups``
-----------------------------
-
-We define a corresponding **sink job** named ``sink`` in ``/etc/zrepl/zrepl.yml`` on host ``backups`` : ::
-
-    jobs:
-    - name: sink
-      type: sink 
-      serve:
-         type: tls
-         listen: ":8888"
-         ca: "/etc/zrepl/prod.crt"
-         cert: "/etc/zrepl/backups.crt"
-         key: "/etc/zrepl/backups.key"
-         client_cns:
-           - "prod"
-      root_fs: "storage/zrepl/sink"
-
-
-Apply Configuration Changes
----------------------------
-
-We use ``zrepl configcheck`` to catch any configuration errors: no output indicates that everything is fine.
-If that is the case, restart the zrepl daemon on **both** ``prod`` and ``backups`` using ``service zrepl restart`` or ``systemctl restart zrepl``.
-
-
-Watch it Work
--------------
-
-Run ``zrepl status`` on ``prod`` to monitor the replication and pruning activity.
-To re-trigger replication (snapshots are separate!), use ``zrepl signal wakeup prod_to_backups`` on ``prod``.
-
-If you like tmux, here is a handy script that works on FreeBSD: ::
-
-    pkg install gnu-watch tmux
-    tmux new -s zrepl -d
-    tmux split-window -t zrepl "tail -f /var/log/messages"
-    tmux split-window -t zrepl "gnu-watch 'zfs list -t snapshot -o name,creation -s creation | grep zrepl_'"
-    tmux split-window -t zrepl "zrepl status"
-    tmux select-layout -t zrepl tiled
-    tmux attach -t zrepl
-
-The Linux equivalent might look like this: ::
-
-    # make sure tmux is installed & let's assume you use systemd + journald
-    tmux new -s zrepl -d
-    tmux split-window -t zrepl  "journalctl -f -u zrepl.service"
-    tmux split-window -t zrepl "watch 'zfs list -t snapshot -o name,creation -s creation | grep zrepl_'"
-    tmux split-window -t zrepl "zrepl status"
-    tmux select-layout -t zrepl tiled
-    tmux attach -t zrepl
-
-Summary
--------
-
-Congratulations, you have a working push backup. Where to go next?
-
-* Read more about :ref:`configuration format, options & job types <configuration_toc>`
-* Configure :ref:`logging <logging>` \& :ref:`monitoring <monitoring>`.

docs/usage.rst

@@ -38,7 +38,7 @@ CLI Overview
     * - ``zrepl migrate``
       - | perform on-disk state / ZFS property migrations
         | (see :ref:`changelog <changelog>` for details)
-    * - ``zrepl zfs-abstractions``
+    * - ``zrepl zfs-abstraction``
       - 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>` )
 
 .. _usage-zrepl-daemon:

endpoint/context.go

@@ -3,25 +3,18 @@ package endpoint
 import (
 	"context"
 
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/logger"
 )
 
 type contextKey int
 
 const (
-	contextKeyLogger contextKey = iota
+	ClientIdentityKey contextKey = iota
-	ClientIdentityKey
 )
 
 type Logger = logger.Logger
 
-func WithLogger(ctx context.Context, log Logger) context.Context {
-	return context.WithValue(ctx, contextKeyLogger, log)
-}
-
 func getLogger(ctx context.Context) Logger {
-	if l, ok := ctx.Value(contextKeyLogger).(Logger); ok {
+	return logging.GetLogger(ctx, logging.SubsysEndpoint)
-		return l
-	}
-	return logger.NewNullLogger()
 }

endpoint/endpoint.go

@@ -7,9 +7,10 @@ import (
 	"fmt"
 	"io"
 	"path"
-	"sync"
 
+	"github.com/kr/pretty"
 	"github.com/pkg/errors"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/replication/logic/pdu"
 	"github.com/zrepl/zrepl/util/chainedio"
@@ -20,9 +21,10 @@ import (
 )
 
 type SenderConfig struct {
-	FSF     zfs.DatasetFilter
+	FSF                         zfs.DatasetFilter
-	Encrypt *zfs.NilBool
+	Encrypt                     *zfs.NilBool
-	JobID   JobID
+	DisableIncrementalStepHolds bool
+	JobID                       JobID
 }
 
 func (c *SenderConfig) Validate() error {
@@ -38,9 +40,10 @@ func (c *SenderConfig) Validate() error {
 
 // Sender implements replication.ReplicationEndpoint for a sending side
 type Sender struct {
-	FSFilter zfs.DatasetFilter
+	FSFilter                    zfs.DatasetFilter
-	encrypt  *zfs.NilBool
+	encrypt                     *zfs.NilBool
-	jobId    JobID
+	disableIncrementalStepHolds bool
+	jobId                       JobID
 }
 
 func NewSender(conf SenderConfig) *Sender {
@@ -48,9 +51,10 @@ func NewSender(conf SenderConfig) *Sender {
 		panic("invalid config" + err.Error())
 	}
 	return &Sender{
-		FSFilter: conf.FSF,
+		FSFilter:                    conf.FSF,
-		encrypt:  conf.Encrypt,
+		encrypt:                     conf.Encrypt,
-		jobId:    conf.JobID,
+		disableIncrementalStepHolds: conf.DisableIncrementalStepHolds,
+		jobId:                       conf.JobID,
 	}
 }
 
@@ -73,6 +77,8 @@ func (s *Sender) filterCheckFS(fs string) (*zfs.DatasetPath, error) {
 }
 
 func (s *Sender) ListFilesystems(ctx context.Context, r *pdu.ListFilesystemReq) (*pdu.ListFilesystemRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	fss, err := zfs.ZFSListMapping(ctx, s.FSFilter)
 	if err != nil {
 		return nil, err
@@ -95,6 +101,8 @@ func (s *Sender) ListFilesystems(ctx context.Context, r *pdu.ListFilesystemReq)
 }
 
 func (s *Sender) ListFilesystemVersions(ctx context.Context, r *pdu.ListFilesystemVersionsReq) (*pdu.ListFilesystemVersionsRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	lp, err := s.filterCheckFS(r.GetFilesystem())
 	if err != nil {
 		return nil, err
@@ -112,118 +120,8 @@ func (s *Sender) ListFilesystemVersions(ctx context.Context, r *pdu.ListFilesyst
 
 }
 
-func (p *Sender) HintMostRecentCommonAncestor(ctx context.Context, r *pdu.HintMostRecentCommonAncestorReq) (*pdu.HintMostRecentCommonAncestorRes, error) {
+var maxConcurrentZFSSend = envconst.Int64("ZREPL_ENDPOINT_MAX_CONCURRENT_SEND", 10)
-
+var maxConcurrentZFSSendSemaphore = semaphore.New(maxConcurrentZFSSend)
-	fsp, err := p.filterCheckFS(r.GetFilesystem())
-	if err != nil {
-		return nil, err
-	}
-	fs := fsp.ToString()
-
-	log := getLogger(ctx).WithField("fs", fs).WithField("hinted_most_recent", fmt.Sprintf("%#v", r.GetSenderVersion()))
-
-	log.WithField("full_hint", r).Debug("full hint")
-
-	if r.GetSenderVersion() == nil {
-		// no common ancestor found, likely due to failed prior replication attempt
-		// => release stale step holds to prevent them from accumulating
-		//    (they can accumulate on initial replication because each inital replication step might hold a different `to`)
-		// => replication cursors cannot accumulate because we always _move_ the replication cursor
-		log.Debug("releasing all step holds on the filesystem")
-		TryReleaseStepStaleFS(ctx, fs, p.jobId)
-		return &pdu.HintMostRecentCommonAncestorRes{}, nil
-	}
-
-	// we were hinted a specific common ancestor
-
-	mostRecentVersion, err := sendArgsFromPDUAndValidateExistsAndGetVersion(ctx, fs, r.GetSenderVersion())
-	if err != nil {
-		msg := "HintMostRecentCommonAncestor rpc with nonexistent most recent version"
-		log.Warn(msg)
-		return nil, errors.Wrap(err, msg)
-	}
-
-	// move replication cursor to this position
-	destroyedCursors, err := MoveReplicationCursor(ctx, fs, mostRecentVersion, p.jobId)
-	if err == zfs.ErrBookmarkCloningNotSupported {
-		log.Debug("not creating replication cursor from bookmark because ZFS does not support it")
-		// fallthrough
-	} else if err != nil {
-		return nil, errors.Wrap(err, "cannot set replication cursor to hinted version")
-	}
-
-	// take care of stale step holds
-	log.WithField("step-holds-cleanup-mode", senderHintMostRecentCommonAncestorStepCleanupMode).
-		Debug("taking care of possibly stale step holds")
-	doStepCleanup := false
-	var stepCleanupSince *CreateTXGRangeBound
-	switch senderHintMostRecentCommonAncestorStepCleanupMode {
-	case StepCleanupNoCleanup:
-		doStepCleanup = false
-	case StepCleanupRangeSinceUnbounded:
-		doStepCleanup = true
-		stepCleanupSince = nil
-	case StepCleanupRangeSinceReplicationCursor:
-		doStepCleanup = true
-		// Use the destroyed replication cursors as indicator how far the previous replication got.
-		// To be precise: We limit the amount of visisted snapshots to exactly those snapshots
-		// created since the last successful replication cursor movement (i.e. last successful replication step)
-		//
-		// If we crash now, we'll leak the step we are about to release, but the performance gain
-		// of limiting the amount of snapshots we visit makes up for that.
-		// Users have the `zrepl holds release-stale` command to cleanup leaked step holds.
-		for _, destroyed := range destroyedCursors {
-			if stepCleanupSince == nil {
-				stepCleanupSince = &CreateTXGRangeBound{
-					CreateTXG: destroyed.GetCreateTXG(),
-					Inclusive: &zfs.NilBool{B: true},
-				}
-			} else if destroyed.GetCreateTXG() < stepCleanupSince.CreateTXG {
-				stepCleanupSince.CreateTXG = destroyed.GetCreateTXG()
-			}
-		}
-	default:
-		panic(senderHintMostRecentCommonAncestorStepCleanupMode)
-	}
-	if !doStepCleanup {
-		log.Info("skipping cleanup of prior invocations' step holds due to environment variable setting")
-	} else {
-		if err := ReleaseStepCummulativeInclusive(ctx, fs, stepCleanupSince, mostRecentVersion, p.jobId); err != nil {
-			return nil, errors.Wrap(err, "cannot cleanup prior invocation's step holds and bookmarks")
-		} else {
-			log.Info("step hold cleanup done")
-		}
-	}
-
-	return &pdu.HintMostRecentCommonAncestorRes{}, nil
-}
-
-type HintMostRecentCommonAncestorStepCleanupMode struct{ string }
-
-var (
-	StepCleanupRangeSinceReplicationCursor = HintMostRecentCommonAncestorStepCleanupMode{"range-since-replication-cursor"}
-	StepCleanupRangeSinceUnbounded         = HintMostRecentCommonAncestorStepCleanupMode{"range-since-unbounded"}
-	StepCleanupNoCleanup                   = HintMostRecentCommonAncestorStepCleanupMode{"no-cleanup"}
-)
-
-func (m HintMostRecentCommonAncestorStepCleanupMode) String() string { return string(m.string) }
-func (m *HintMostRecentCommonAncestorStepCleanupMode) Set(s string) error {
-	switch s {
-	case StepCleanupRangeSinceReplicationCursor.String():
-		*m = StepCleanupRangeSinceReplicationCursor
-	case StepCleanupRangeSinceUnbounded.String():
-		*m = StepCleanupRangeSinceUnbounded
-	case StepCleanupNoCleanup.String():
-		*m = StepCleanupNoCleanup
-	default:
-		return fmt.Errorf("unknown step cleanup mode %q", s)
-	}
-	return nil
-}
-
-var senderHintMostRecentCommonAncestorStepCleanupMode = *envconst.Var("ZREPL_ENDPOINT_SENDER_HINT_MOST_RECENT_STEP_HOLD_CLEANUP_MODE", &StepCleanupRangeSinceReplicationCursor).(*HintMostRecentCommonAncestorStepCleanupMode)
-
-var maxConcurrentZFSSendSemaphore = semaphore.New(envconst.Int64("ZREPL_ENDPOINT_MAX_CONCURRENT_SEND", 10))
 
 func uncheckedSendArgsFromPDU(fsv *pdu.FilesystemVersion) *zfs.ZFSSendArgVersion {
 	if fsv == nil {
@@ -245,6 +143,7 @@ func sendArgsFromPDUAndValidateExistsAndGetVersion(ctx context.Context, fs strin
 }
 
 func (s *Sender) Send(ctx context.Context, r *pdu.SendReq) (*pdu.SendRes, io.ReadCloser, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 
 	_, err := s.filterCheckFS(r.Filesystem)
 	if err != nil {
@@ -312,10 +211,11 @@ func (s *Sender) Send(ctx context.Context, r *pdu.SendReq) (*pdu.SendRes, io.Rea
 		return res, nil, nil
 	}
 
-	// update replication cursor
+	// create a replication cursor for `From` (usually an idempotent no-op because SendCompleted already created it before)
+	var fromReplicationCursor Abstraction
 	if sendArgs.From != nil {
 		// For all but the first replication, this should always be a no-op because SendCompleted already moved the cursor
-		_, err = MoveReplicationCursor(ctx, sendArgs.FS, sendArgs.FromVersion, s.jobId)
+		fromReplicationCursor, err = CreateReplicationCursor(ctx, sendArgs.FS, *sendArgs.FromVersion, s.jobId) // no shadow
 		if err == zfs.ErrBookmarkCloningNotSupported {
 			getLogger(ctx).Debug("not creating replication cursor from bookmark because ZFS does not support it")
 			// fallthrough
@@ -324,9 +224,12 @@ func (s *Sender) Send(ctx context.Context, r *pdu.SendReq) (*pdu.SendRes, io.Rea
 		}
 	}
 
+	takeStepHolds := sendArgs.FromVersion == nil || !s.disableIncrementalStepHolds
+
+	var fromHold, toHold Abstraction
 	// make sure `From` doesn't go away in order to make this step resumable
-	if sendArgs.From != nil {
+	if sendArgs.From != nil && takeStepHolds {
-		_, err := HoldStep(ctx, sendArgs.FS, *sendArgs.FromVersion, s.jobId)
+		fromHold, err = HoldStep(ctx, sendArgs.FS, *sendArgs.FromVersion, s.jobId) // no shadow
 		if err == zfs.ErrBookmarkCloningNotSupported {
 			getLogger(ctx).Debug("not creating step bookmark because ZFS does not support it")
 			// fallthrough
@@ -334,22 +237,80 @@ func (s *Sender) Send(ctx context.Context, r *pdu.SendReq) (*pdu.SendRes, io.Rea
 			return nil, nil, errors.Wrapf(err, "cannot hold `from` version %q before starting send", *sendArgs.FromVersion)
 		}
 	}
-	// make sure `To` doesn't go away in order to make this step resumable
+	if takeStepHolds {
-	_, err = HoldStep(ctx, sendArgs.FS, sendArgs.ToVersion, s.jobId)
+		// make sure `To` doesn't go away in order to make this step resumable
-	if err != nil {
+		toHold, err = HoldStep(ctx, sendArgs.FS, sendArgs.ToVersion, s.jobId)
-		return nil, nil, errors.Wrapf(err, "cannot hold `to` version %q before starting send", sendArgs.ToVersion)
+		if err != nil {
+			return nil, nil, errors.Wrapf(err, "cannot hold `to` version %q before starting send", sendArgs.ToVersion)
+		}
 	}
 
-	// step holds & replication cursor released / moved forward in s.SendCompleted => s.moveCursorAndReleaseSendHolds
+	// cleanup the mess that _this function_ might have created in prior failed attempts:
+	//
+	// In summary, we delete every endpoint ZFS abstraction created on this filesystem for this job id,
+	// except for the ones we just created above.
+	//
+	// This is the most robust approach to avoid leaking (= forgetting to clean up) endpoint ZFS abstractions,
+	// all under the assumption that there will only ever be one send for a (jobId,fs) combination at any given time.
+	//
+	// Note that the SendCompleted rpc can't be relied upon for this purpose:
+	// - it might be lost due to network errors,
+	// - or never be sent by a potentially malicious or buggy client,
+	// - or never be send because the replication step failed at some point
+	//   (potentially leaving a resumable state on the receiver, which is the case where we really do not want to blow away the step holds too soon.)
+	//
+	// Note further that a resuming send, due to the idempotent nature of func CreateReplicationCursor and HoldStep,
+	// will never lose its step holds because we just (idempotently re-)created them above, before attempting the cleanup.
+	liveAbs := []Abstraction{fromHold, toHold, fromReplicationCursor}
+	func() {
+		ctx, endSpan := trace.WithSpan(ctx, "cleanup-stale-abstractions")
+		defer endSpan()
+
+		keep := func(a Abstraction) (keep bool) {
+			keep = false
+			for _, k := range liveAbs {
+				keep = keep || AbstractionEquals(a, k)
+			}
+			return keep
+		}
+		check := func(obsoleteAbs []Abstraction) {
+			// last line of defense: check that we don't destroy the incremental `from` and `to`
+			// if we did that, we might be about to blow away the last common filesystem version between sender and receiver
+			mustLiveVersions := []zfs.FilesystemVersion{sendArgs.ToVersion}
+			if sendArgs.FromVersion != nil {
+				mustLiveVersions = append(mustLiveVersions, *sendArgs.FromVersion)
+			}
+			for _, staleVersion := range obsoleteAbs {
+				for _, mustLiveVersion := range mustLiveVersions {
+					isSendArg := zfs.FilesystemVersionEqualIdentity(mustLiveVersion, staleVersion.GetFilesystemVersion())
+					isStepHoldWeMightHaveCreatedWithCurrentValueOf_takeStepHolds :=
+						takeStepHolds && staleVersion.GetType() == AbstractionStepHold
+					if isSendArg && isStepHoldWeMightHaveCreatedWithCurrentValueOf_takeStepHolds {
+						panic(fmt.Sprintf("impl error: %q would be destroyed because it is considered stale but it is part of of sendArgs=%s", mustLiveVersion.String(), pretty.Sprint(sendArgs)))
+					}
+				}
+			}
+		}
+		sendAbstractionsCacheSingleton.TryBatchDestroy(ctx, s.jobId, sendArgs.FS, keep, check)
+	}()
+	// now add the newly created abstractions to the cleaned-up cache
+	for _, a := range liveAbs {
+		if a != nil {
+			sendAbstractionsCacheSingleton.Put(a)
+		}
+	}
 
 	sendStream, err := zfs.ZFSSend(ctx, sendArgs)
 	if err != nil {
+		// it's ok to not destroy the abstractions we just created here, a new send attempt will take care of it
 		return nil, nil, errors.Wrap(err, "zfs send failed")
 	}
+
 	return res, sendStream, nil
 }
 
 func (p *Sender) SendCompleted(ctx context.Context, r *pdu.SendCompletedReq) (*pdu.SendCompletedRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 
 	orig := r.GetOriginalReq() // may be nil, always use proto getters
 	fsp, err := p.filterCheckFS(orig.GetFilesystem())
@@ -371,76 +332,44 @@ func (p *Sender) SendCompleted(ctx context.Context, r *pdu.SendCompletedReq) (*p
 		return nil, errors.Wrap(err, "validate `to` exists")
 	}
 
-	log := getLogger(ctx).WithField("to_guid", to.Guid).
+	log := func(ctx context.Context) Logger {
-		WithField("fs", fs).
+		log := getLogger(ctx).WithField("to_guid", to.Guid).
-		WithField("to", to.RelName)
+			WithField("fs", fs).
-	if from != nil {
+			WithField("to", to.RelName)
-		log = log.WithField("from", from.RelName).WithField("from_guid", from.Guid)
+		if from != nil {
+			log = log.WithField("from", from.RelName).WithField("from_guid", from.Guid)
+		}
+		return log
 	}
 
-	log.Debug("move replication cursor to most recent common version")
+	toReplicationCursor, err := CreateReplicationCursor(ctx, fs, to, p.jobId)
-	destroyedCursors, err := MoveReplicationCursor(ctx, fs, to, p.jobId)
 	if err != nil {
 		if err == zfs.ErrBookmarkCloningNotSupported {
-			log.Debug("not setting replication cursor, bookmark cloning not supported")
+			log(ctx).Debug("not setting replication cursor, bookmark cloning not supported")
 		} else {
 			msg := "cannot move replication cursor, keeping hold on `to` until successful"
-			log.WithError(err).Error(msg)
+			log(ctx).WithError(err).Error(msg)
 			err = errors.Wrap(err, msg)
-			// it is correct to not release the hold if we can't move the cursor!
+			// it is correct to not destroy from and to step holds if we can't move the cursor!
 			return &pdu.SendCompletedRes{}, err
 		}
 	} else {
-		log.Info("successfully moved replication cursor")
+		sendAbstractionsCacheSingleton.Put(toReplicationCursor)
+		log(ctx).WithField("to_cursor", toReplicationCursor.String()).Info("successfully created `to` replication cursor")
 	}
 
-	// kick off releasing of step holds / bookmarks
+	keep := func(a Abstraction) bool {
-	// if we fail to release them, don't bother the caller:
+		return AbstractionEquals(a, toReplicationCursor)
-	// they are merely an implementation detail on the sender for better resumability
+	}
-	var wg sync.WaitGroup
+	sendAbstractionsCacheSingleton.TryBatchDestroy(ctx, p.jobId, fs, keep, nil)
-	wg.Add(2)
-	go func() {
-		defer wg.Done()
-		log.Debug("release step-hold of or step-bookmark on `to`")
-		err = ReleaseStep(ctx, fs, to, p.jobId)
-		if err != nil {
-			log.WithError(err).Error("cannot release step-holds on or destroy step-bookmark of `to`")
-		} else {
-			log.Info("successfully released step-holds on or destroyed step-bookmark of `to`")
-		}
-
-	}()
-	go func() {
-		defer wg.Done()
-		if from == nil {
-			return
-		}
-		log.Debug("release step-hold of or step-bookmark on `from`")
-		err := ReleaseStep(ctx, fs, *from, p.jobId)
-		if err != nil {
-			if dne, ok := err.(*zfs.DatasetDoesNotExist); ok {
-				// If bookmark cloning is not supported, `from` might be the old replication cursor
-				// and thus have already been destroyed by MoveReplicationCursor above
-				// In that case, nonexistence of `from` is not an error, otherwise it is.
-				for _, c := range destroyedCursors {
-					if c.GetFullPath() == dne.Path {
-						log.Info("`from` was a replication cursor and has already been destroyed")
-						return
-					}
-				}
-				// fallthrough
-			}
-			log.WithError(err).Error("cannot release step-holds on or destroy step-bookmark of `from`")
-		} else {
-			log.Info("successfully released step-holds on or destroyed step-bookmark of `from`")
-		}
-	}()
-	wg.Wait()
 
 	return &pdu.SendCompletedRes{}, nil
+
 }
 
 func (p *Sender) DestroySnapshots(ctx context.Context, req *pdu.DestroySnapshotsReq) (*pdu.DestroySnapshotsRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	dp, err := p.filterCheckFS(req.Filesystem)
 	if err != nil {
 		return nil, err
@@ -449,6 +378,8 @@ func (p *Sender) DestroySnapshots(ctx context.Context, req *pdu.DestroySnapshots
 }
 
 func (p *Sender) Ping(ctx context.Context, req *pdu.PingReq) (*pdu.PingRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	res := pdu.PingRes{
 		Echo: req.GetMessage(),
 	}
@@ -456,14 +387,20 @@ func (p *Sender) Ping(ctx context.Context, req *pdu.PingReq) (*pdu.PingRes, erro
 }
 
 func (p *Sender) PingDataconn(ctx context.Context, req *pdu.PingReq) (*pdu.PingRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	return p.Ping(ctx, req)
 }
 
 func (p *Sender) WaitForConnectivity(ctx context.Context) error {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	return nil
 }
 
 func (p *Sender) ReplicationCursor(ctx context.Context, req *pdu.ReplicationCursorReq) (*pdu.ReplicationCursorRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	dp, err := p.filterCheckFS(req.Filesystem)
 	if err != nil {
 		return nil, err
@@ -594,6 +531,15 @@ func (f subroot) MapToLocal(fs string) (*zfs.DatasetPath, error) {
 }
 
 func (s *Receiver) ListFilesystems(ctx context.Context, req *pdu.ListFilesystemReq) (*pdu.ListFilesystemRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
+	// first make sure that root_fs is imported
+	if rphs, err := zfs.ZFSGetFilesystemPlaceholderState(ctx, s.conf.RootWithoutClientComponent); err != nil {
+		return nil, errors.Wrap(err, "cannot determine whether root_fs exists")
+	} else if !rphs.FSExists {
+		return nil, errors.New("root_fs does not exist")
+	}
+
 	root := s.clientRootFromCtx(ctx)
 	filtered, err := zfs.ZFSListMapping(ctx, subroot{root})
 	if err != nil {
@@ -644,6 +590,8 @@ func (s *Receiver) ListFilesystems(ctx context.Context, req *pdu.ListFilesystemR
 }
 
 func (s *Receiver) ListFilesystemVersions(ctx context.Context, req *pdu.ListFilesystemVersionsReq) (*pdu.ListFilesystemVersionsRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	root := s.clientRootFromCtx(ctx)
 	lp, err := subroot{root}.MapToLocal(req.GetFilesystem())
 	if err != nil {
@@ -665,6 +613,8 @@ func (s *Receiver) ListFilesystemVersions(ctx context.Context, req *pdu.ListFile
 }
 
 func (s *Receiver) Ping(ctx context.Context, req *pdu.PingReq) (*pdu.PingRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	res := pdu.PingRes{
 		Echo: req.GetMessage(),
 	}
@@ -672,24 +622,30 @@ func (s *Receiver) Ping(ctx context.Context, req *pdu.PingReq) (*pdu.PingRes, er
 }
 
 func (s *Receiver) PingDataconn(ctx context.Context, req *pdu.PingReq) (*pdu.PingRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 	return s.Ping(ctx, req)
 }
 
 func (s *Receiver) WaitForConnectivity(ctx context.Context) error {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 	return nil
 }
 
-func (s *Receiver) ReplicationCursor(context.Context, *pdu.ReplicationCursorReq) (*pdu.ReplicationCursorRes, error) {
+func (s *Receiver) ReplicationCursor(ctx context.Context, _ *pdu.ReplicationCursorReq) (*pdu.ReplicationCursorRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 	return nil, fmt.Errorf("ReplicationCursor not implemented for Receiver")
 }
 
 func (s *Receiver) Send(ctx context.Context, req *pdu.SendReq) (*pdu.SendRes, io.ReadCloser, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
 	return nil, nil, fmt.Errorf("receiver does not implement Send()")
 }
 
 var maxConcurrentZFSRecvSemaphore = semaphore.New(envconst.Int64("ZREPL_ENDPOINT_MAX_CONCURRENT_RECV", 10))
 
 func (s *Receiver) Receive(ctx context.Context, req *pdu.ReceiveReq, receive io.ReadCloser) (*pdu.ReceiveRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	getLogger(ctx).Debug("incoming Receive")
 	defer receive.Close()
 
@@ -812,9 +768,9 @@ func (s *Receiver) Receive(ctx context.Context, req *pdu.ReceiveReq, receive io.
 	}
 	defer guard.Release()
 
-	log.Info("peeking 1M ahead")
 	var peek bytes.Buffer
 	var MaxPeek = envconst.Int64("ZREPL_ENDPOINT_RECV_PEEK_SIZE", 1<<20)
+	log.WithField("max_peek_bytes", MaxPeek).Info("peeking incoming stream")
 	if _, err := io.Copy(&peek, io.LimitReader(receive, MaxPeek)); err != nil {
 		log.WithError(err).Error("cannot read peek-buffer from send stream")
 	}
@@ -918,6 +874,8 @@ func (s *Receiver) Receive(ctx context.Context, req *pdu.ReceiveReq, receive io.
 }
 
 func (s *Receiver) DestroySnapshots(ctx context.Context, req *pdu.DestroySnapshotsReq) (*pdu.DestroySnapshotsRes, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
 	root := s.clientRootFromCtx(ctx)
 	lp, err := subroot{root}.MapToLocal(req.Filesystem)
 	if err != nil {
@@ -926,16 +884,9 @@ func (s *Receiver) DestroySnapshots(ctx context.Context, req *pdu.DestroySnapsho
 	return doDestroySnapshots(ctx, lp, req.Snapshots)
 }
 
-func (p *Receiver) HintMostRecentCommonAncestor(ctx context.Context, r *pdu.HintMostRecentCommonAncestorReq) (*pdu.HintMostRecentCommonAncestorRes, error) {
+func (p *Receiver) SendCompleted(ctx context.Context, _ *pdu.SendCompletedReq) (*pdu.SendCompletedRes, error) {
-	// we don't move last-received-hold as part of this hint
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
-	// because that wouldn't give us any benefit wrt resumability.
-	//
-	// Other reason: the replication logic that issues this RPC would require refactoring
-	// to include the receiver's FilesystemVersion in the request)
-	return &pdu.HintMostRecentCommonAncestorRes{}, nil
-}
 
-func (p *Receiver) SendCompleted(context.Context, *pdu.SendCompletedReq) (*pdu.SendCompletedRes, error) {
 	return &pdu.SendCompletedRes{}, nil
 }
 
@@ -957,7 +908,7 @@ func doDestroySnapshots(ctx context.Context, lp *zfs.DatasetPath, snaps []*pdu.F
 			ErrOut:     &errs[i],
 		}
 	}
-	zfs.ZFSDestroyFilesystemVersions(reqs)
+	zfs.ZFSDestroyFilesystemVersions(ctx, reqs)
 	for i := range reqs {
 		if errs[i] != nil {
 			if de, ok := errs[i].(*zfs.DestroySnapshotsError); ok && len(de.Reason) == 1 {

endpoint/endpoint_metrics.go

@@ -0,0 +1,7 @@
+package endpoint
+
+import "github.com/prometheus/client_golang/prometheus"
+
+func RegisterMetrics(r prometheus.Registerer) {
+	r.MustRegister(sendAbstractionsCacheMetrics.count)
+}

endpoint/endpoint_send_abstractions_cache.go

@@ -0,0 +1,207 @@
+package endpoint
+
+import (
+	"context"
+	"fmt"
+	"sync"
+
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
+	"github.com/zrepl/zrepl/util/chainlock"
+)
+
+var sendAbstractionsCacheMetrics struct {
+	count prometheus.Gauge
+}
+
+func init() {
+	sendAbstractionsCacheMetrics.count = prometheus.NewGauge(prometheus.GaugeOpts{
+		Namespace: "zrepl",
+		Subsystem: "endpoint",
+		Name:      "send_abstractions_cache_entry_count",
+		Help:      "number of send abstractions tracked in the sendAbstractionsCache data structure",
+	})
+}
+
+var sendAbstractionsCacheSingleton = newSendAbstractionsCache()
+
+func SendAbstractionsCacheInvalidate(fs string) {
+	sendAbstractionsCacheSingleton.InvalidateFSCache(fs)
+}
+
+type sendAbstractionsCacheDidLoadFSState int
+
+const (
+	sendAbstractionsCacheDidLoadFSStateNo sendAbstractionsCacheDidLoadFSState = iota // 0-value has meaning
+	sendAbstractionsCacheDidLoadFSStateInProgress
+	sendAbstractionsCacheDidLoadFSStateDone
+)
+
+type sendAbstractionsCache struct {
+	mtx              chainlock.L
+	abstractions     []Abstraction
+	didLoadFS        map[string]sendAbstractionsCacheDidLoadFSState
+	didLoadFSChanged *sync.Cond
+}
+
+func newSendAbstractionsCache() *sendAbstractionsCache {
+	c := &sendAbstractionsCache{
+		didLoadFS: make(map[string]sendAbstractionsCacheDidLoadFSState),
+	}
+	c.didLoadFSChanged = c.mtx.NewCond()
+	return c
+}
+
+func (s *sendAbstractionsCache) Put(a Abstraction) {
+	defer s.mtx.Lock().Unlock()
+
+	var zeroJobId JobID
+	if a.GetJobID() == nil {
+		panic("abstraction must not have nil job id")
+	} else if *a.GetJobID() == zeroJobId {
+		panic(fmt.Sprintf("abstraction must not have zero-value job id: %s", a))
+	}
+
+	s.abstractions = append(s.abstractions, a)
+	sendAbstractionsCacheMetrics.count.Set(float64(len(s.abstractions)))
+}
+
+func (s *sendAbstractionsCache) InvalidateFSCache(fs string) {
+	// FIXME: O(n)
+	newAbs := make([]Abstraction, 0, len(s.abstractions))
+	for _, a := range s.abstractions {
+		if a.GetFS() != fs {
+			newAbs = append(newAbs, a)
+		}
+	}
+	s.abstractions = newAbs
+	sendAbstractionsCacheMetrics.count.Set(float64(len(s.abstractions)))
+
+	s.didLoadFS[fs] = sendAbstractionsCacheDidLoadFSStateNo
+	s.didLoadFSChanged.Broadcast()
+
+}
+
+// - logs errors in getting on-disk abstractions
+// - only fetches on-disk abstractions once, but every time from the in-memory store
+//
+// That means that for precise results, all abstractions created by the endpoint must be .Put into this cache.
+func (s *sendAbstractionsCache) GetAndDeleteByJobIDAndFS(ctx context.Context, jobID JobID, fs string, keep func(a Abstraction) bool) (ret []Abstraction) {
+	defer s.mtx.Lock().Unlock()
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+	var zeroJobId JobID
+	if jobID == zeroJobId {
+		panic("must not pass zero-value job id")
+	}
+	if fs == "" {
+		panic("must not pass zero-value fs")
+	}
+
+	s.tryLoadOnDiskSendAbstractions(ctx, fs)
+
+	// FIXME O(n)
+	var remaining []Abstraction
+	for _, a := range s.abstractions {
+		aJobId := *a.GetJobID()
+		aFS := a.GetFS()
+		if aJobId == jobID && aFS == fs && !keep(a) {
+			ret = append(ret, a)
+		} else {
+			remaining = append(remaining, a)
+		}
+	}
+	s.abstractions = remaining
+	sendAbstractionsCacheMetrics.count.Set(float64(len(s.abstractions)))
+
+	return ret
+}
+
+// caller must hold s.mtx
+func (s *sendAbstractionsCache) tryLoadOnDiskSendAbstractions(ctx context.Context, fs string) {
+	for s.didLoadFS[fs] != sendAbstractionsCacheDidLoadFSStateDone {
+		if s.didLoadFS[fs] == sendAbstractionsCacheDidLoadFSStateInProgress {
+			s.didLoadFSChanged.Wait()
+			continue
+		}
+		if s.didLoadFS[fs] != sendAbstractionsCacheDidLoadFSStateNo {
+			panic(fmt.Sprintf("unreachable: %v", s.didLoadFS[fs]))
+		}
+
+		s.didLoadFS[fs] = sendAbstractionsCacheDidLoadFSStateInProgress
+		defer s.didLoadFSChanged.Broadcast()
+
+		var onDiskAbs []Abstraction
+		var err error
+		s.mtx.DropWhile(func() {
+			onDiskAbs, err = s.tryLoadOnDiskSendAbstractionsImpl(ctx, fs) // no shadow
+		})
+
+		if err != nil {
+			s.didLoadFS[fs] = sendAbstractionsCacheDidLoadFSStateNo
+			getLogger(ctx).WithField("fs", fs).WithError(err).Error("cannot list send step abstractions for filesystem")
+		} else {
+			s.didLoadFS[fs] = sendAbstractionsCacheDidLoadFSStateDone
+			s.abstractions = append(s.abstractions, onDiskAbs...)
+			getLogger(ctx).WithField("fs", fs).WithField("abstractions", onDiskAbs).Debug("loaded step abstractions for filesystem")
+		}
+		return
+	}
+}
+
+// caller should _not hold s.mtx
+func (s *sendAbstractionsCache) tryLoadOnDiskSendAbstractionsImpl(ctx context.Context, fs string) ([]Abstraction, error) {
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
+	q := ListZFSHoldsAndBookmarksQuery{
+		FS: ListZFSHoldsAndBookmarksQueryFilesystemFilter{
+			FS: &fs,
+		},
+		JobID: nil,
+		What: AbstractionTypeSet{
+			AbstractionStepHold:                    true,
+			AbstractionStepBookmark:                true,
+			AbstractionReplicationCursorBookmarkV2: true,
+		},
+		Concurrency: 1,
+	}
+	abs, absErrs, err := ListAbstractions(ctx, q)
+	if err != nil {
+		return nil, err
+	}
+	// safe to ignore absErrs here, this is best-effort cleanup
+	if len(absErrs) > 0 {
+		return nil, ListAbstractionsErrors(absErrs)
+	}
+	return abs, nil
+}
+
+func (s *sendAbstractionsCache) TryBatchDestroy(ctx context.Context, jobId JobID, fs string, keep func(a Abstraction) bool, check func(willDestroy []Abstraction)) {
+	// no s.mtx, we only use the public interface in this function
+
+	defer trace.WithSpanFromStackUpdateCtx(&ctx)()
+
+	obsoleteAbs := s.GetAndDeleteByJobIDAndFS(ctx, jobId, fs, keep)
+
+	if check != nil {
+		check(obsoleteAbs)
+	}
+
+	hadErr := false
+	for res := range BatchDestroy(ctx, obsoleteAbs) {
+		if res.DestroyErr != nil {
+			hadErr = true
+			getLogger(ctx).
+				WithField("abstraction", res.Abstraction).
+				WithError(res.DestroyErr).
+				Error("cannot destroy stale send step abstraction")
+		} else {
+			getLogger(ctx).
+				WithField("abstraction", res.Abstraction).
+				Info("destroyed stale send step abstraction")
+		}
+	}
+	if hadErr {
+		s.InvalidateFSCache(fs)
+	}
+
+}

endpoint/endpoint_zfs_abstraction.go

@@ -11,6 +11,7 @@ import (
 
 	"github.com/pkg/errors"
 
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 	"github.com/zrepl/zrepl/util/envconst"
 	"github.com/zrepl/zrepl/util/semaphore"
 	"github.com/zrepl/zrepl/zfs"
@@ -53,6 +54,30 @@ type Abstraction interface {
 	json.Marshaler
 }
 
+func AbstractionEquals(a, b Abstraction) bool {
+	if (a != nil) != (b != nil) {
+		return false
+	}
+	if a == nil && b == nil {
+		return true
+	}
+	var aJobId, bJobId JobID
+	if aJid := a.GetJobID(); aJid != nil {
+		aJobId = *aJid
+	}
+	if bJid := b.GetJobID(); bJid != nil {
+		bJobId = *bJid
+	}
+	return a.GetType() == b.GetType() &&
+		a.GetFS() == b.GetFS() &&
+		a.GetName() == b.GetName() &&
+		a.GetFullPath() == b.GetFullPath() &&
+		aJobId == bJobId &&
+		a.GetCreateTXG() == b.GetCreateTXG() &&
+		zfs.FilesystemVersionEqualIdentity(a.GetFilesystemVersion(), b.GetFilesystemVersion()) &&
+		a.String() == b.String()
+}
+
 func (t AbstractionType) Validate() error {
 	switch t {
 	case AbstractionStepBookmark:
@@ -467,7 +492,7 @@ func (e ListAbstractionsErrors) Error() string {
 	}
 	msgs := make([]string, len(e))
 	for i := range e {
-		msgs[i] = e.Error()
+		msgs[i] = e[i].Error()
 	}
 	return fmt.Sprintf("list endpoint abstractions: multiple errors:\n%s", strings.Join(msgs, "\n"))
 }
@@ -529,15 +554,16 @@ func ListAbstractionsStreamed(ctx context.Context, query ListZFSHoldsAndBookmark
 	}
 
 	sem := semaphore.New(int64(query.Concurrency))
+	ctx, endTask := trace.WithTask(ctx, "list-abstractions-streamed-producer")
 	go func() {
+		defer endTask()
 		defer close(out)
 		defer close(outErrs)
-		var wg sync.WaitGroup
+
-		defer wg.Wait()
+		_, add, wait := trace.WithTaskGroup(ctx, "list-abstractions-impl-fs")
+		defer wait()
 		for i := range fss {
-			wg.Add(1)
+			add(func(ctx context.Context) {
-			go func(i int) {
-				defer wg.Done()
 				g, err := sem.Acquire(ctx)
 				if err != nil {
 					errCb(err, fss[i], err.Error())
@@ -547,7 +573,7 @@ func ListAbstractionsStreamed(ctx context.Context, query ListZFSHoldsAndBookmark
 					defer g.Release()
 					listAbstractionsImplFS(ctx, fss[i], &query, emitAbstraction, errCb)
 				}()
-			}(i)
+			})
 		}
 	}()
 
@@ -588,23 +614,23 @@ func listAbstractionsImplFS(ctx context.Context, fs string, query *ListZFSHoldsA
 			panic("implementation error: extractors misconfigured for " + at)
 		}
 		for _, v := range fsvs {
-			var a Abstraction
 			if v.Type == zfs.Bookmark && bmE != nil {
-				a = bmE(fsp, v)
+				if a := bmE(fsp, v); a != nil {
+					emitCandidate(a)
+				}
 			}
-			if v.Type == zfs.Snapshot && holdE != nil && query.CreateTXG.Contains(v.GetCreateTXG()) && (!v.UserRefs.Valid || v.UserRefs.Value > 0) {
+			if v.Type == zfs.Snapshot && holdE != nil && query.CreateTXG.Contains(v.GetCreateTXG()) && (!v.UserRefs.Valid || v.UserRefs.Value > 0) { // FIXME review v.UserRefsValid
 				holds, err := zfs.ZFSHolds(ctx, fsp.ToString(), v.Name)
 				if err != nil {
 					errCb(err, v.ToAbsPath(fsp), "get hold on snap")
 					continue
 				}
 				for _, tag := range holds {
-					a = holdE(fsp, v, tag)
+					if a := holdE(fsp, v, tag); a != nil {
+						emitCandidate(a)
+					}
 				}
 			}
-			if a != nil {
-				emitCandidate(a)
-			}
 		}
 	}
 }
@@ -731,6 +757,9 @@ func listStaleFiltering(abs []Abstraction, sinceBound *CreateTXGRangeBound) *Sta
 	}
 	stepFirstNotStaleCandidates := make(map[fsAndJobId]stepFirstNotStaleCandidate) // empty map => will always return nil
 	for _, a := range abs {
+		if a.GetJobID() == nil {
+			continue // already put those into always-live list noJobId in above loop
+		}
 		key := fsAndJobId{a.GetFS(), *a.GetJobID()}
 		c := stepFirstNotStaleCandidates[key]
 

endpoint/endpoint_zfs_abstraction_cursor_and_last_received_hold.go

@@ -118,31 +118,32 @@ func GetReplicationCursors(ctx context.Context, dp *zfs.DatasetPath, jobID JobID
 	return candidates, nil
 }
 
-type ReplicationCursorTarget interface {
+// idempotently create a replication cursor targeting `target`
-	IsSnapshot() bool
-	GetGuid() uint64
-	GetCreateTXG() uint64
-	ToSendArgVersion() zfs.ZFSSendArgVersion
-}
-
-// `target` is validated before replication cursor is set. if validation fails, the cursor is not moved.
 //
 // returns ErrBookmarkCloningNotSupported if version is a bookmark and bookmarking bookmarks is not supported by ZFS
-func MoveReplicationCursor(ctx context.Context, fs string, target ReplicationCursorTarget, jobID JobID) (destroyedCursors []Abstraction, err error) {
+func CreateReplicationCursor(ctx context.Context, fs string, target zfs.FilesystemVersion, jobID JobID) (a Abstraction, err error) {
-
-	if !target.IsSnapshot() {
-		return nil, zfs.ErrBookmarkCloningNotSupported
-	}
 
 	bookmarkname, err := ReplicationCursorBookmarkName(fs, target.GetGuid(), jobID)
 	if err != nil {
 		return nil, errors.Wrap(err, "determine replication cursor name")
 	}
 
-	// idempotently create bookmark (guid is encoded in it, hence we'll most likely add a new one
+	if target.IsBookmark() && target.GetName() == bookmarkname {
-	// cleanup the old one afterwards
+		return &bookmarkBasedAbstraction{
+			Type:              AbstractionReplicationCursorBookmarkV2,
+			FS:                fs,
+			FilesystemVersion: target,
+			JobID:             jobID,
+		}, nil
+	}
 
-	err = zfs.ZFSBookmark(ctx, fs, target.ToSendArgVersion(), bookmarkname)
+	if !target.IsSnapshot() {
+		return nil, zfs.ErrBookmarkCloningNotSupported
+	}
+
+	// idempotently create bookmark (guid is encoded in it)
+
+	cursorBookmark, err := zfs.ZFSBookmark(ctx, fs, target, bookmarkname)
 	if err != nil {
 		if err == zfs.ErrBookmarkCloningNotSupported {
 			return nil, err // TODO go1.13 use wrapping
@@ -150,65 +151,17 @@ func MoveReplicationCursor(ctx context.Context, fs string, target ReplicationCur
 		return nil, errors.Wrapf(err, "cannot create bookmark")
 	}
 
-	destroyedCursors, err = DestroyObsoleteReplicationCursors(ctx, fs, target, jobID)
+	return &bookmarkBasedAbstraction{
-	if err != nil {
+		Type:              AbstractionReplicationCursorBookmarkV2,
-		return nil, errors.Wrap(err, "destroy obsolete replication cursors")
+		FS:                fs,
-	}
+		FilesystemVersion: cursorBookmark,
-
+		JobID:             jobID,
-	return destroyedCursors, nil
+	}, nil
 }
 
-type ReplicationCursor interface {
+const (
-	GetCreateTXG() uint64
+	ReplicationCursorBookmarkNamePrefix = "zrepl_last_received_J_"
-}
+)
-
-func DestroyObsoleteReplicationCursors(ctx context.Context, fs string, current ReplicationCursor, jobID JobID) (_ []Abstraction, err error) {
-
-	q := ListZFSHoldsAndBookmarksQuery{
-		FS: ListZFSHoldsAndBookmarksQueryFilesystemFilter{
-			FS: &fs,
-		},
-		What: AbstractionTypeSet{
-			AbstractionReplicationCursorBookmarkV2: true,
-		},
-		JobID: &jobID,
-		CreateTXG: CreateTXGRange{
-			Since: nil,
-			Until: &CreateTXGRangeBound{
-				CreateTXG: current.GetCreateTXG(),
-				Inclusive: &zfs.NilBool{B: false},
-			},
-		},
-		Concurrency: 1,
-	}
-	abs, absErr, err := ListAbstractions(ctx, q)
-	if err != nil {
-		return nil, errors.Wrap(err, "list abstractions")
-	}
-	if len(absErr) > 0 {
-		return nil, errors.Wrap(ListAbstractionsErrors(absErr), "list abstractions")
-	}
-
-	var destroyed []Abstraction
-	var errs []error
-	for res := range BatchDestroy(ctx, abs) {
-		log := getLogger(ctx).
-			WithField("replication_cursor_bookmark", res.Abstraction)
-		if res.DestroyErr != nil {
-			errs = append(errs, res.DestroyErr)
-			log.WithError(err).
-				Error("cannot destroy obsolete replication cursor bookmark")
-		} else {
-			destroyed = append(destroyed, res.Abstraction)
-			log.Info("destroyed obsolete replication cursor bookmark")
-		}
-	}
-	if len(errs) == 0 {
-		return destroyed, nil
-	} else {
-		return destroyed, errorarray.Wrap(errs, "destroy obsolete replication cursor")
-	}
-}
 
 var lastReceivedHoldTagRE = regexp.MustCompile("^zrepl_last_received_J_(.+)$")
 
@@ -230,22 +183,22 @@ func LastReceivedHoldTag(jobID JobID) (string, error) {
 }
 
 func lastReceivedHoldImpl(jobid string) (string, error) {
-	tag := fmt.Sprintf("zrepl_last_received_J_%s", jobid)
+	tag := fmt.Sprintf("%s%s", ReplicationCursorBookmarkNamePrefix, jobid)
 	if err := zfs.ValidHoldTag(tag); err != nil {
 		return "", err
 	}
 	return tag, nil
 }
 
-func MoveLastReceivedHold(ctx context.Context, fs string, to zfs.FilesystemVersion, jobID JobID) error {
+func CreateLastReceivedHold(ctx context.Context, fs string, to zfs.FilesystemVersion, jobID JobID) (Abstraction, error) {
 
 	if !to.IsSnapshot() {
-		return errors.Errorf("last-received-hold: target must be a snapshot: %s", to.FullPath(fs))
+		return nil, errors.Errorf("last-received-hold: target must be a snapshot: %s", to.FullPath(fs))
 	}
 
 	tag, err := LastReceivedHoldTag(jobID)
 	if err != nil {
-		return errors.Wrap(err, "last-received-hold: hold tag")
+		return nil, errors.Wrap(err, "last-received-hold: hold tag")
 	}
 
 	// we never want to be without a hold
@@ -253,7 +206,23 @@ func MoveLastReceivedHold(ctx context.Context, fs string, to zfs.FilesystemVersi
 
 	err = zfs.ZFSHold(ctx, fs, to, tag)
 	if err != nil {
-		return errors.Wrap(err, "last-received-hold: hold newly received")
+		return nil, errors.Wrap(err, "last-received-hold: hold newly received")
+	}
+
+	return &holdBasedAbstraction{
+		Type:              AbstractionLastReceivedHold,
+		FS:                fs,
+		FilesystemVersion: to,
+		JobID:             jobID,
+		Tag:               tag,
+	}, nil
+}
+
+func MoveLastReceivedHold(ctx context.Context, fs string, to zfs.FilesystemVersion, jobID JobID) error {
+
+	_, err := CreateLastReceivedHold(ctx, fs, to, jobID)
+	if err != nil {
+		return err
 	}
 
 	q := ListZFSHoldsAndBookmarksQuery{

endpoint/endpoint_zfs_abstraction_step.go

@@ -7,7 +7,6 @@ import (
 
 	"github.com/pkg/errors"
 
-	"github.com/zrepl/zrepl/util/errorarray"
 	"github.com/zrepl/zrepl/zfs"
 )
 
@@ -93,7 +92,7 @@ func HoldStep(ctx context.Context, fs string, v zfs.FilesystemVersion, jobID Job
 		return nil, errors.Wrap(err, "create step bookmark: determine bookmark name")
 	}
 	// idempotently create bookmark
-	err = zfs.ZFSBookmark(ctx, fs, v.ToSendArgVersion(), bmname)
+	stepBookmark, err := zfs.ZFSBookmark(ctx, fs, v, bmname)
 	if err != nil {
 		if err == zfs.ErrBookmarkCloningNotSupported {
 			// TODO we could actually try to find a local snapshot that has the requested GUID
@@ -108,137 +107,11 @@ func HoldStep(ctx context.Context, fs string, v zfs.FilesystemVersion, jobID Job
 	return &bookmarkBasedAbstraction{
 		Type:              AbstractionStepBookmark,
 		FS:                fs,
-		FilesystemVersion: v,
+		FilesystemVersion: stepBookmark,
 		JobID:             jobID,
 	}, nil
 }
 
-// idempotently release the step-hold on v if v is a snapshot
-// or idempotently destroy the step-bookmark  of v if v is a bookmark
-//
-// note that this operation leaves v itself untouched, unless v is the step-bookmark itself, in which case v is destroyed
-//
-// returns an instance of *zfs.DatasetDoesNotExist if `v` does not exist
-func ReleaseStep(ctx context.Context, fs string, v zfs.FilesystemVersion, jobID JobID) error {
-
-	if v.IsSnapshot() {
-		tag, err := StepHoldTag(jobID)
-		if err != nil {
-			return errors.Wrap(err, "step release tag")
-		}
-
-		if err := zfs.ZFSRelease(ctx, tag, v.FullPath(fs)); err != nil {
-			return errors.Wrap(err, "step release: zfs")
-		}
-
-		return nil
-	}
-	if !v.IsBookmark() {
-		panic(fmt.Sprintf("impl error: expecting version to be a bookmark, got %#v", v))
-	}
-
-	bmname, err := StepBookmarkName(fs, v.Guid, jobID)
-	if err != nil {
-		return errors.Wrap(err, "step release: determine bookmark name")
-	}
-	// idempotently destroy bookmark
-
-	if err := zfs.ZFSDestroyIdempotent(ctx, bmname); err != nil {
-		return errors.Wrap(err, "step release: bookmark destroy: zfs")
-	}
-
-	return nil
-}
-
-// release {step holds, step bookmarks} earlier and including `mostRecent`
-func ReleaseStepCummulativeInclusive(ctx context.Context, fs string, since *CreateTXGRangeBound, mostRecent zfs.FilesystemVersion, jobID JobID) error {
-	q := ListZFSHoldsAndBookmarksQuery{
-		What: AbstractionTypeSet{
-			AbstractionStepHold:     true,
-			AbstractionStepBookmark: true,
-		},
-		FS: ListZFSHoldsAndBookmarksQueryFilesystemFilter{
-			FS: &fs,
-		},
-		JobID: &jobID,
-		CreateTXG: CreateTXGRange{
-			Since: since,
-			Until: &CreateTXGRangeBound{
-				CreateTXG: mostRecent.CreateTXG,
-				Inclusive: &zfs.NilBool{B: true},
-			},
-		},
-		Concurrency: 1,
-	}
-	abs, absErrs, err := ListAbstractions(ctx, q)
-	if err != nil {
-		return errors.Wrap(err, "step release cummulative: list")
-	}
-	if len(absErrs) > 0 {
-		return errors.Wrap(ListAbstractionsErrors(absErrs), "step release cummulative: list")
-	}
-
-	getLogger(ctx).WithField("step_holds_and_bookmarks", fmt.Sprintf("%s", abs)).Debug("releasing step holds and bookmarks")
-
-	var errs []error
-	for res := range BatchDestroy(ctx, abs) {
-		log := getLogger(ctx).
-			WithField("step_hold_or_bookmark", res.Abstraction)
-		if res.DestroyErr != nil {
-			errs = append(errs, res.DestroyErr)
-			log.WithError(err).
-				Error("cannot release step hold or bookmark")
-		} else {
-			log.Info("released step hold or bookmark")
-		}
-	}
-	if len(errs) == 0 {
-		return nil
-	} else {
-		return errorarray.Wrap(errs, "step release cummulative: release")
-	}
-}
-
-func TryReleaseStepStaleFS(ctx context.Context, fs string, jobID JobID) {
-
-	q := ListZFSHoldsAndBookmarksQuery{
-		FS: ListZFSHoldsAndBookmarksQueryFilesystemFilter{
-			FS: &fs,
-		},
-		JobID: &jobID,
-		What: AbstractionTypeSet{
-			AbstractionStepHold:                    true,
-			AbstractionStepBookmark:                true,
-			AbstractionReplicationCursorBookmarkV2: true,
-		},
-		Concurrency: 1,
-	}
-	staleness, err := ListStale(ctx, q)
-	if _, ok := err.(*ListStaleQueryError); ok {
-		panic(err)
-	} else if err != nil {
-		getLogger(ctx).WithError(err).Error("cannot list stale step holds and bookmarks")
-		return
-	}
-	for _, s := range staleness.Stale {
-		getLogger(ctx).WithField("stale_step_hold_or_bookmark", s).Info("batch-destroying stale step hold or bookmark")
-	}
-	for res := range BatchDestroy(ctx, staleness.Stale) {
-		if res.DestroyErr != nil {
-			getLogger(ctx).
-				WithField("stale_step_hold_or_bookmark", res.Abstraction).
-				WithError(res.DestroyErr).
-				Error("cannot destroy stale step-hold or bookmark")
-		} else {
-			getLogger(ctx).
-				WithField("stale_step_hold_or_bookmark", res.Abstraction).
-				WithError(res.DestroyErr).
-				Info("destroyed stale step-hold or bookmark")
-		}
-	}
-
-}
-
 var _ BookmarkExtractor = StepBookmarkExtractor
 
 func StepBookmarkExtractor(fs *zfs.DatasetPath, v zfs.FilesystemVersion) (_ Abstraction) {

go.mod

@@ -5,6 +5,7 @@ go 1.12
 require (
 	github.com/fatih/color v1.7.0
 	github.com/gdamore/tcell v1.2.0
+	github.com/gitchander/permutation v0.0.0-20181107151852-9e56b92e9909
 	github.com/go-logfmt/logfmt v0.4.0
 	github.com/go-sql-driver/mysql v1.4.1-0.20190907122137-b2c03bcae3d4
 	github.com/golang/protobuf v1.3.2
@@ -21,18 +22,21 @@ require (
 	github.com/onsi/gomega v1.7.0 // indirect
 	github.com/pkg/errors v0.8.1
 	github.com/pkg/profile v1.2.1
-	github.com/problame/go-netssh v0.0.0-20191209123953-18d8aa6923c7
+	github.com/problame/go-netssh v0.0.0-20200601114649-26439f9f0dc5
 	github.com/prometheus/client_golang v1.2.1
+	github.com/prometheus/common v0.7.0
 	github.com/sergi/go-diff v1.0.1-0.20180205163309-da645544ed44 // go1.12 thinks it needs this
 	github.com/spf13/cobra v0.0.2
 	github.com/spf13/pflag v1.0.5
 	github.com/stretchr/testify v1.4.0
+	github.com/willf/bitset v1.1.10
 	github.com/yudai/gojsondiff v0.0.0-20170107030110-7b1b7adf999d
 	github.com/yudai/golcs v0.0.0-20170316035057-ecda9a501e82 // go1.12 thinks it needs this
 	github.com/zrepl/yaml-config v0.0.0-20191220194647-cbb6b0cf4bdd
 	golang.org/x/net v0.0.0-20190613194153-d28f0bde5980
 	golang.org/x/sync v0.0.0-20190423024810-112230192c58
 	golang.org/x/sys v0.0.0-20191026070338-33540a1f6037
+	golang.org/x/tools v0.0.0-20190206041539-40960b6deb8e
 	gonum.org/v1/gonum v0.7.0 // indirect
 	google.golang.org/grpc v1.17.0
 )

go.sum

@@ -7,8 +7,10 @@ github.com/OpenPeeDeeP/depguard v0.0.0-20181229194401-1f388ab2d810/go.mod h1:7/4
 github.com/StackExchange/wmi v0.0.0-20180116203802-5d049714c4a6/go.mod h1:3eOhrUMpNV+6aFIbp5/iudMxNCF27Vw2OZgy4xEx0Fg=
 github.com/ajstarks/svgo v0.0.0-20180226025133-644b8db467af/go.mod h1:K08gAheRH3/J6wwsYMMT4xOr94bZjxIelGM0+d/wbFw=
 github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
+github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751 h1:JYp7IbQjafoB+tBA3gMyHYHrpOtNuDiK/uB5uXxq5wM=
 github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
 github.com/alecthomas/units v0.0.0-20151022065526-2efee857e7cf/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0=
+github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4 h1:Hs82Z41s6SdL1CELW+XaDYmOH4hkBN4/N9og/AsOv7E=
 github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0=
 github.com/alvaroloes/enumer v1.1.1/go.mod h1:FxrjvuXoDAx9isTJrv4c+T410zFi0DtXIT0m65DJ+Wo=
 github.com/armon/consul-api v0.0.0-20180202201655-eb2c6b5be1b6/go.mod h1:grANhF5doyWs3UAsr3K4I6qtAmlQcZDesFNEHPZAzj8=
@@ -38,6 +40,8 @@ github.com/gdamore/encoding v1.0.0 h1:+7OoQ1Bc6eTm5niUzBa0Ctsh6JbMW6Ra+YNuAtDBdk
 github.com/gdamore/encoding v1.0.0/go.mod h1:alR0ol34c49FCSBLjhosxzcPHQbf2trDkoo5dl+VrEg=
 github.com/gdamore/tcell v1.2.0 h1:ikixzsxc8K8o3V2/CEmyoEW8mJZaNYQQ3NP3VIQdUe4=
 github.com/gdamore/tcell v1.2.0/go.mod h1:Hjvr+Ofd+gLglo7RYKxxnzCBmev3BzsS67MebKS4zMM=
+github.com/gitchander/permutation v0.0.0-20181107151852-9e56b92e9909 h1:9NC8seTx6/zRmMTAdsHj/uOMi0EGHGQtjyLafBjk77Q=
+github.com/gitchander/permutation v0.0.0-20181107151852-9e56b92e9909/go.mod h1:lP+DW8LR6Rw3ru9Vo2/y/3iiLaLWmofYql/va+7zJOk=
 github.com/go-critic/go-critic v0.3.4/go.mod h1:AHR42Lk/E/aOznsrYdMYeIQS5RH10HZHSqP+rD6AJrc=
 github.com/go-critic/go-critic v0.3.5-0.20190526074819-1df300866540/go.mod h1:+sE8vrLDS2M0pZkBk0wy6+nLdKexVDrl/jBqQOTDThA=
 github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as=
@@ -208,6 +212,8 @@ github.com/problame/go-netssh v0.0.0-20191026123024-f34099f4f6b1 h1:HH8yzlaZq/A8
 github.com/problame/go-netssh v0.0.0-20191026123024-f34099f4f6b1/go.mod h1:JRs3nyBjvOv/9YHC+Vlw9z1Jfzl5s5t0BNnTzmclj1c=
 github.com/problame/go-netssh v0.0.0-20191209123953-18d8aa6923c7 h1:Oik8tLrLhoMq4fduDRuNNOAQ+q0M0dXkjAYLUf4+mAc=
 github.com/problame/go-netssh v0.0.0-20191209123953-18d8aa6923c7/go.mod h1:Ba6RaFpK1+IHWs1wLZ6sCBuXkt4iAVLeOG5GinXHusM=
+github.com/problame/go-netssh v0.0.0-20200601114649-26439f9f0dc5 h1:1eSrO2WAeSXjMol8WRKW9LekL1252VIMaKQwWkmEdvs=
+github.com/problame/go-netssh v0.0.0-20200601114649-26439f9f0dc5/go.mod h1:Ba6RaFpK1+IHWs1wLZ6sCBuXkt4iAVLeOG5GinXHusM=
 github.com/prometheus/client_golang v0.0.0-20180410130117-e11c6ff8170b/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw=
 github.com/prometheus/client_golang v0.9.1/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw=
 github.com/prometheus/client_golang v1.0.0/go.mod h1:db9x61etRT2tGnBNRi70OPL5FsnadC4Ky3P0J6CfImo=
@@ -242,6 +248,7 @@ github.com/shurcooL/go-goon v0.0.0-20170922171312-37c2f522c041/go.mod h1:N5mDOms
 github.com/sirupsen/logrus v1.0.5/go.mod h1:pMByvHTf9Beacp5x1UXfOR9xyW/9antXMhjMPG0dEzc=
 github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo=
 github.com/sirupsen/logrus v1.4.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo=
+github.com/sirupsen/logrus v1.4.2 h1:SPIRibHv4MatM3XXNO2BJeFLZwZ2LvZgfQ5+UNI2im4=
 github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE=
 github.com/sourcegraph/go-diff v0.5.1/go.mod h1:j2dHj3m8aZgQO8lMTcTnBcXkRRRqi34cd2MNlA9u1mE=
 github.com/spf13/afero v1.1.0/go.mod h1:j4pytiNVoe2o6bmDsKpLACNPDBIoEAkihy7loJ1B0CQ=
@@ -263,6 +270,7 @@ github.com/spf13/viper v1.0.2/go.mod h1:A8kyI5cUJhb8N+3pkfONlcEcZbueH6nhAm0Fq7Sr
 github.com/spf13/viper v1.3.2/go.mod h1:ZiWeW+zYFKm7srdB9IoDzzZXaJaI5eL9QjNiN/DMA2s=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
 github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/testify v1.2.1/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1w=
 github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
@@ -276,6 +284,8 @@ github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyC
 github.com/valyala/fasthttp v1.2.0/go.mod h1:4vX61m6KN+xDduDNwXrhIAVZaZaZiQ1luJk8LWSxF3s=
 github.com/valyala/quicktemplate v1.1.1/go.mod h1:EH+4AkTd43SvgIbQHYu59/cJyxDoOVRUAfrukLPuGJ4=
 github.com/valyala/tcplisten v0.0.0-20161114210144-ceec8f93295a/go.mod h1:v3UYOV9WzVtRmSR+PDvWpU/qWl4Wa5LApYYX4ZtKbio=
+github.com/willf/bitset v1.1.10 h1:NotGKqX0KwQ72NUzqrjZq5ipPNDQex9lo3WpaS8L2sc=
+github.com/willf/bitset v1.1.10/go.mod h1:RjeCKbqT1RxIR/KWY6phxZiaY1IyutSBfGjNPySAYV4=
 github.com/xordataexchange/crypt v0.0.3-0.20170626215501-b2862e3d0a77/go.mod h1:aYKd//L2LvnjZzWKhF00oedf4jCCReLcmhLdhm1A27Q=
 github.com/yudai/gojsondiff v0.0.0-20170107030110-7b1b7adf999d h1:yJIizrfO599ot2kQ6Af1enICnwBD3XoxgX3MrMwot2M=
 github.com/yudai/gojsondiff v0.0.0-20170107030110-7b1b7adf999d/go.mod h1:AY32+k2cwILAkW1fbgxQ5mUmMiZFgLIV+FBNExI05xg=
@@ -343,6 +353,7 @@ golang.org/x/tools v0.0.0-20181117154741-2ddaf7f79a09/go.mod h1:n7NCudcB/nEzxVGm
 golang.org/x/tools v0.0.0-20181205014116-22934f0fdb62/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
 golang.org/x/tools v0.0.0-20190110163146-51295c7ec13a/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
 golang.org/x/tools v0.0.0-20190121143147-24cd39ecf745/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
+golang.org/x/tools v0.0.0-20190206041539-40960b6deb8e h1:Io7mpb+aUAGF0MKxbyQ7HQl1VgB+cL6ZJZUFaFNqVV4=
 golang.org/x/tools v0.0.0-20190206041539-40960b6deb8e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
 golang.org/x/tools v0.0.0-20190213192042-740235f6c0d8/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
 golang.org/x/tools v0.0.0-20190311212946-11955173bddd/go.mod h1:LCzVGOaR6xXOjkQ3onu1FJEFr0SW1gC7cKk1uF8kGRs=
@@ -365,6 +376,7 @@ google.golang.org/grpc v1.16.0/go.mod h1:0JHn/cJsOMiMfNA9+DeHDlAU7KAAB5GDlYFpa9M
 google.golang.org/grpc v1.17.0 h1:TRJYBgMclJvGYn2rIMjj+h9KtMt5r1Ij7ODVRIZkwhk=
 google.golang.org/grpc v1.17.0/go.mod h1:6QZJwpn2B+Zp71q/5VxRsJ6NXXVCE5NRUHRo+f3cWCs=
 gopkg.in/airbrake/gobrake.v2 v2.0.9/go.mod h1:/h5ZAUhDkGaJfjzjKLSjv6zCL6O0LLBxU4K+aSYdM/U=
+gopkg.in/alecthomas/kingpin.v2 v2.2.6 h1:jMFz6MfLP0/4fUyZle81rXUoxOBFi19VUFKVDOQfozc=
 gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=

lazy.sh

@@ -36,9 +36,10 @@ godep() {
     go build -v -mod=readonly -o "$GOPATH/bin/enumer"        github.com/alvaroloes/enumer
     go build -v -mod=readonly -o "$GOPATH/bin/goimports"     golang.org/x/tools/cmd/goimports
     go build -v -mod=readonly -o "$GOPATH/bin/golangci-lint" github.com/golangci/golangci-lint/cmd/golangci-lint
+    go build -v -mod=readonly -o "$GOPATH/bin/gocovmerge"    github.com/wadey/gocovmerge
     set +x
     popd
-    if ! type stringer || ! type protoc-gen-go || ! type enumer || ! type goimports || ! type golangci-lint; then
+    if ! type stringer || ! type protoc-gen-go || ! type enumer || ! type goimports || ! type golangci-lint || ! type gocovmerge; then
         echo "Installed dependencies but can't find them in \$PATH, adjust it to contain \$GOPATH/bin" 1>&2
         exit 1
     fi

platformtest/harness/harness.go

@@ -11,6 +11,7 @@ import (
 
 	"github.com/fatih/color"
 	"github.com/pkg/errors"
+	"github.com/zrepl/zrepl/daemon/logging/trace"
 
 	"github.com/zrepl/zrepl/config"
 	"github.com/zrepl/zrepl/daemon/logging"
@@ -23,33 +24,36 @@ var bold = color.New(color.Bold)
 var boldRed = color.New(color.Bold, color.FgHiRed)
 var boldGreen = color.New(color.Bold, color.FgHiGreen)
 
-var args struct {
+const DefaultPoolImageSize = 200 * (1 << 20)
-	createArgs            platformtest.ZpoolCreateArgs
-	stopAndKeepPoolOnFail bool
-
-	run   string
-	runRE *regexp.Regexp
-}
 
 func main() {
-	if err := doMain(); err != nil {
+
+	var args HarnessArgs
+
+	flag.StringVar(&args.CreateArgs.PoolName, "poolname", "", "")
+	flag.StringVar(&args.CreateArgs.ImagePath, "imagepath", "", "")
+	flag.Int64Var(&args.CreateArgs.ImageSize, "imagesize", DefaultPoolImageSize, "")
+	flag.StringVar(&args.CreateArgs.Mountpoint, "mountpoint", "", "")
+	flag.BoolVar(&args.StopAndKeepPoolOnFail, "failure.stop-and-keep-pool", false, "if a test case fails, stop test execution and keep pool as it was when the test failed")
+	flag.StringVar(&args.Run, "run", "", "")
+	flag.Parse()
+
+	if err := HarnessRun(args); err != nil {
 		os.Exit(1)
 	}
 }
 
 var exitWithErr = fmt.Errorf("exit with error")
 
-func doMain() error {
+type HarnessArgs struct {
+	CreateArgs            platformtest.ZpoolCreateArgs
+	StopAndKeepPoolOnFail bool
+	Run                   string
+}
 
-	flag.StringVar(&args.createArgs.PoolName, "poolname", "", "")
+func HarnessRun(args HarnessArgs) error {
-	flag.StringVar(&args.createArgs.ImagePath, "imagepath", "", "")
-	flag.Int64Var(&args.createArgs.ImageSize, "imagesize", 200*(1<<20), "")
-	flag.StringVar(&args.createArgs.Mountpoint, "mountpoint", "", "")
-	flag.BoolVar(&args.stopAndKeepPoolOnFail, "failure.stop-and-keep-pool", false, "if a test case fails, stop test execution and keep pool as it was when the test failed")
-	flag.StringVar(&args.run, "run", "", "")
-	flag.Parse()
 
-	args.runRE = regexp.MustCompile(args.run)
+	runRE := regexp.MustCompile(args.Run)
 
 	outlets := logger.NewOutlets()
 	outlet, level, err := logging.ParseOutlet(config.LoggingOutletEnum{Ret: &config.StdoutLoggingOutlet{
@@ -64,11 +68,13 @@ func doMain() error {
 	outlets.Add(outlet, level)
 	logger := logger.NewLogger(outlets, 1*time.Second)
 
-	if err := args.createArgs.Validate(); err != nil {
+	if err := args.CreateArgs.Validate(); err != nil {
 		logger.Error(err.Error())
 		panic(err)
 	}
-	ctx := platformtest.WithLogger(context.Background(), logger)
+	ctx := context.Background()
+	defer trace.WithTaskFromStackUpdateCtx(&ctx)()
+	ctx = logging.WithLoggers(ctx, logging.SubsystemLoggersWithUniversalLogger(logger))
 	ex := platformtest.NewEx(logger)
 
 	type invocation struct {
@@ -78,7 +84,7 @@ func doMain() error {
 
 	invocations := make([]*invocation, 0, len(tests.Cases))
 	for _, c := range tests.Cases {
-		if args.runRE.MatchString(c.String()) {
+		if runRE.MatchString(c.String()) {
 			invocations = append(invocations, &invocation{runFunc: c})
 		}
 	}
@@ -87,7 +93,7 @@ func doMain() error {
 
 		bold.Printf("BEGIN TEST CASE %s\n", inv.runFunc.String())
 
-		pool, err := platformtest.CreateOrReplaceZpool(ctx, ex, args.createArgs)
+		pool, err := platformtest.CreateOrReplaceZpool(ctx, ex, args.CreateArgs)
 		if err != nil {
 			panic(errors.Wrap(err, "create test pool"))
 		}
@@ -103,7 +109,7 @@ func doMain() error {
 			fmt.Printf("%+v\n", res.failedStack) // print with stack trace
 		}
 
-		if res.failed && args.stopAndKeepPoolOnFail {
+		if res.failed && args.StopAndKeepPoolOnFail {
 			boldRed.Printf("STOPPING TEST RUN AT FAILING TEST PER USER REQUEST\n")
 			return exitWithErr
 		}

platformtest/harness/harness_test.go

@@ -1,6 +1,7 @@
 package main
 
 import (
+	"fmt"
 	"os"
 	"strings"
 	"testing"
@@ -21,22 +22,29 @@ import (
 //  https://github.com/wadey/gocovmerge
 
 func TestMain(t *testing.T) {
+	fmt.Println("incoming args: ", os.Args)
+
 	var (
-		args []string
+		args             []string
-		run  bool
+		run              bool
+		startCaptureArgs bool
 	)
 
-	for _, arg := range os.Args {
+	for i, arg := range os.Args {
 		switch {
 		case arg == "__DEVEL--i-heard-you-like-tests":
 			run = true
+			startCaptureArgs = true
 		case strings.HasPrefix(arg, "-test"):
 		case strings.HasPrefix(arg, "__DEVEL"):
-		default:
+		case i == 0:
+			args = append(args, arg)
+		case startCaptureArgs:
 			args = append(args, arg)
 		}
 	}
 	os.Args = args
+	fmt.Println("using args: ", os.Args)
 
 	if run {
 		main()

platformtest/platformtest.go

@@ -27,6 +27,7 @@ func (c *Context) Logf(format string, args ...interface{}) {
 
 func (c *Context) Errorf(format string, args ...interface{}) {
 	GetLog(c).Printf(format, args...)
+	c.FailNow()
 }
 
 func (c *Context) FailNow() {

platformtest/platformtest_logging.go

@@ -3,22 +3,12 @@ package platformtest
 import (
 	"context"
 
+	"github.com/zrepl/zrepl/daemon/logging"
 	"github.com/zrepl/zrepl/logger"
 )
 
 type Logger = logger.Logger
 
-type contextKey int
-
-const (
-	contextKeyLogger contextKey = iota
-)
-
-func WithLogger(ctx context.Context, logger Logger) context.Context {
-	ctx = context.WithValue(ctx, contextKeyLogger, logger)
-	return ctx
-}
-
 func GetLog(ctx context.Context) Logger {
-	return ctx.Value(contextKeyLogger).(Logger)
+	return logging.GetLogger(ctx, logging.SubsysPlatformtest)
 }

platformtest/platformtest_zpool.go

@@ -58,6 +58,14 @@ func CreateOrReplaceZpool(ctx context.Context, e Execer, args ZpoolCreateArgs) (
 		}
 	}
 
+	// clear the mountpoint dir
+	if err := os.RemoveAll(args.Mountpoint); err != nil {
+		return nil, errors.Wrapf(err, "remove mountpoint dir %q", args.Mountpoint)
+	}
+	if err := os.Mkdir(args.Mountpoint, 0700); err != nil {
+		return nil, errors.Wrapf(err, "create mountpoint dir %q", args.Mountpoint)
+	}
+
 	// idempotently (re)create the pool image
 	image, err := os.OpenFile(args.ImagePath, os.O_CREATE|os.O_RDWR, 0600)
 	if err != nil {
@@ -93,5 +101,9 @@ func (p *Zpool) Destroy(ctx context.Context, e Execer) error {
 		return errors.Wrapf(err, "remove pool image")
 	}
 
+	if err := os.RemoveAll(p.args.Mountpoint); err != nil {
+		return errors.Wrapf(err, "remove mountpoint dir %q", p.args.Mountpoint)
+	}
+
 	return nil
 }

platformtest/tests/batchDestroy.go

@@ -32,7 +32,7 @@ func BatchDestroy(ctx *platformtest.Context) {
 			Name:       "2",
 		},
 	}
-	zfs.ZFSDestroyFilesystemVersions(reqs)
+	zfs.ZFSDestroyFilesystemVersions(ctx, reqs)
 	if *reqs[0].ErrOut != nil {
 		panic("expecting no error")
 	}

platformtest/tests/gen/gen.go

@@ -0,0 +1,140 @@
+package main
+
+import (
+	"bytes"
+	"go/ast"
+	"go/format"
+	"go/parser"
+	"go/token"
+	"io/ioutil"
+	"os"
+	"sort"
+	"strings"
+	"text/template"
+
+	"golang.org/x/tools/go/packages"
+)
+
+func check(err error) {
+	if err != nil {
+		panic(err)
+	}
+}
+
+type platformtestFuncDeclFinder struct {
+	pkg       *packages.Package
+	testFuncs []*ast.FuncDecl
+}
+
+func isPlatformtestFunc(n *ast.FuncDecl) bool {
+	if !n.Name.IsExported() {
+		return false
+	}
+	if n.Recv != nil {
+		return false
+	}
+	if n.Type.Results.NumFields() != 0 {
+		return false
+	}
+	if n.Type.Params.NumFields() != 1 {
+		return false
+	}
+	se, ok := n.Type.Params.List[0].Type.(*ast.StarExpr)
+	if !ok {
+		return false
+	}
+	sel, ok := se.X.(*ast.SelectorExpr)
+	if !ok {
+		return false
+	}
+	x, ok := sel.X.(*ast.Ident)
+	if !ok {
+		return false
+	}
+	if x.Name != "platformtest" || sel.Sel.Name != "Context" {
+		return false
+	}
+	return true
+}
+
+func (e *platformtestFuncDeclFinder) Visit(n2 ast.Node) ast.Visitor {
+	switch n := n2.(type) {
+	case *ast.File:
+		return e
+	case *ast.FuncDecl:
+		if isPlatformtestFunc(n) {
+			e.testFuncs = append(e.testFuncs, n)
+		}
+		return nil
+	default:
+		return nil
+	}
+}
+
+func main() {
+
+	// TODO safeguards that prevent us from deleting non-generated generated_cases.go
+	os.Remove("generated_cases.go")
+	// (no error handling to easily cover the case where the file doesn't exist)
+
+	pkgs, err := packages.Load(
+		&packages.Config{
+			Mode:  packages.LoadFiles,
+			Tests: false,
+		},
+		os.Args[1],
+	)
+	check(err)
+
+	if len(pkgs) != 1 {
+		panic(pkgs)
+	}
+
+	p := pkgs[0]
+
+	var tests []*ast.FuncDecl
+
+	for _, f := range p.GoFiles {
+		s := token.NewFileSet()
+		a, err := parser.ParseFile(s, f, nil, parser.AllErrors)
+		check(err)
+		finder := &platformtestFuncDeclFinder{
+			pkg: p,
+		}
+		ast.Walk(finder, a)
+		tests = append(tests, finder.testFuncs...)
+	}
+
+	sort.Slice(tests, func(i, j int) bool {
+		return strings.Compare(tests[i].Name.Name, tests[j].Name.Name) < 0
+	})
+
+	{
+		casesTemplate := `
+// Code generated by zrepl tooling; DO NOT EDIT.
+
+package tests
+
+var Cases = []Case {
+{{- range . -}}
+	{{ .Name }},
+{{ end -}}
+}
+
+	`
+		t, err := template.New("CaseFunc").Parse(casesTemplate)
+		check(err)
+
+		var buf bytes.Buffer
+		err = t.Execute(&buf, tests)
+		check(err)
+
+		formatted, err := format.Source(buf.Bytes())
+		check(err)
+
+		err = ioutil.WriteFile("generated_cases.go", formatted, 0664)
+		check(err)
+
+	}
+
+}

platformtest/tests/generated_cases.go

@@ -0,0 +1,31 @@
+// Code generated by zrepl tooling; DO NOT EDIT.
+
+package tests
+
+var Cases = []Case{BatchDestroy,
+	CreateReplicationCursor,
+	GetNonexistent,
+	HoldsWork,
+	IdempotentBookmark,
+	IdempotentDestroy,
+	IdempotentHold,
+	ListFilesystemVersionsFilesystemNotExist,
+	ListFilesystemVersionsTypeFilteringAndPrefix,
+	ListFilesystemVersionsUserrefs,
+	ListFilesystemVersionsZeroExistIsNotAnError,
+	ListFilesystemsNoFilter,
+	ReceiveForceIntoEncryptedErr,
+	ReceiveForceRollbackWorksUnencrypted,
+	ReplicationIncrementalCleansUpStaleAbstractionsWithCacheOnSecondReplication,
+	ReplicationIncrementalCleansUpStaleAbstractionsWithoutCacheOnSecondReplication,
+	ReplicationIncrementalDestroysStepHoldsIffIncrementalStepHoldsAreDisabledButStepHoldsExist,
+	ReplicationIncrementalIsPossibleIfCommonSnapshotIsDestroyed,
+	ReplicationIsResumableFullSend__DisableIncrementalStepHolds_False,
+	ReplicationIsResumableFullSend__DisableIncrementalStepHolds_True,
+	ResumableRecvAndTokenHandling,
+	ResumeTokenParsing,
+	SendArgsValidationEncryptedSendOfUnencryptedDatasetForbidden,
+	SendArgsValidationResumeTokenDifferentFilesystemForbidden,
+	SendArgsValidationResumeTokenEncryptionMismatchForbidden,
+	UndestroyableSnapshotParsing,
+}

platformtest/tests/holds.go

@@ -0,0 +1,32 @@
+package tests
+
+import (
+	"path"
+
+	"github.com/stretchr/testify/require"
+	"github.com/zrepl/zrepl/platformtest"
+	"github.com/zrepl/zrepl/zfs"
+)
+
+func HoldsWork(ctx *platformtest.Context) {
+	platformtest.Run(ctx, platformtest.PanicErr, ctx.RootDataset, `
+		DESTROYROOT
+		CREATEROOT
+		+  "foo bar"
+		+  "foo bar@snap name"
+	`)
+
+	fs := path.Join(ctx.RootDataset, "foo bar")
+
+	err := zfs.ZFSHold(ctx, fs, fsversion(ctx, fs, "@snap name"), "tag 1")
+	require.NoError(ctx, err)
+
+	err = zfs.ZFSHold(ctx, fs, fsversion(ctx, fs, "@snap name"), "tag 2")
+	require.NoError(ctx, err)
+
+	holds, err := zfs.ZFSHolds(ctx, fs, "snap name")
+	require.NoError(ctx, err)
+	require.Len(ctx, holds, 2)
+	require.Contains(ctx, holds, "tag 1")
+	require.Contains(ctx, holds, "tag 2")
+}

platformtest/tests/idempotentBookmark.go

@@ -3,6 +3,7 @@ package tests
 import (
 	"fmt"
 
+	"github.com/stretchr/testify/assert"
 	"github.com/zrepl/zrepl/platformtest"
 	"github.com/zrepl/zrepl/zfs"
 )
@@ -19,22 +20,23 @@ func IdempotentBookmark(ctx *platformtest.Context) {
 
 	fs := fmt.Sprintf("%s/foo bar", ctx.RootDataset)
 
-	asnap := sendArgVersion(ctx, fs, "@a snap")
+	asnap := fsversion(ctx, fs, "@a snap")
-	anotherSnap := sendArgVersion(ctx, fs, "@another snap")
+	anotherSnap := fsversion(ctx, fs, "@another snap")
 
-	err := zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
+	aBookmark, err := zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
 	if err != nil {
 		panic(err)
 	}
 
 	// do it again, should be idempotent
-	err = zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
+	aBookmarkIdemp, err := zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
 	if err != nil {
 		panic(err)
 	}
+	assert.Equal(ctx, aBookmark, aBookmarkIdemp)
 
 	// should fail for another snapshot
-	err = zfs.ZFSBookmark(ctx, fs, anotherSnap, "a bookmark")
+	_, err = zfs.ZFSBookmark(ctx, fs, anotherSnap, "a bookmark")
 	if err == nil {
 		panic(err)
 	}
@@ -48,7 +50,7 @@ func IdempotentBookmark(ctx *platformtest.Context) {
 	}
 
 	// do it again, should fail with special error type
-	err = zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
+	_, err = zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
 	if err == nil {
 		panic(err)
 	}

platformtest/tests/idempotentDestroy.go

@@ -18,8 +18,8 @@ func IdempotentDestroy(ctx *platformtest.Context) {
 	`)
 
 	fs := fmt.Sprintf("%s/foo bar", ctx.RootDataset)
-	asnap := sendArgVersion(ctx, fs, "@a snap")
+	asnap := fsversion(ctx, fs, "@a snap")
-	err := zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
+	_, err := zfs.ZFSBookmark(ctx, fs, asnap, "a bookmark")
 	if err != nil {
 		panic(err)
 	}

platformtest/tests/listFilesystemVersions.go

@@ -85,9 +85,6 @@ func ListFilesystemVersionsZeroExistIsNotAnError(t *platformtest.Context) {
 	vs, err := zfs.ZFSListFilesystemVersions(t, mustDatasetPath(fs), zfs.ListFilesystemVersionsOptions{})
 	require.Empty(t, vs)
 	require.NoError(t, err)
-	dsne, ok := err.(*zfs.DatasetDoesNotExist)
-	require.True(t, ok)
-	require.Equal(t, fs, dsne.Path)
 }
 
 func ListFilesystemVersionsFilesystemNotExist(t *platformtest.Context) {