Periodically collect runtime info when requested

* Hoist control for exiting script a level up

* Do not accidentally nil out errors

* Log when running schedule

* Remove duplicate log line

* Warn on cron schedule that will never run

Dockerfile

@@ -16,6 +16,5 @@ WORKDIR /root
 RUN apk add --no-cache ca-certificates
 
 COPY --from=builder /app/cmd/backup/backup /usr/bin/backup
-COPY --chmod=755 ./entrypoint.sh /root/
 
-ENTRYPOINT ["/root/entrypoint.sh"]
+ENTRYPOINT ["/usr/bin/backup", "-foreground"]

cmd/backup/config.go

@@ -34,6 +34,7 @@ type Config struct {
 	BackupFilenameExpand          bool            `split_words:"true"`
 	BackupLatestSymlink           string          `split_words:"true"`
 	BackupArchive                 string          `split_words:"true" default:"/archive"`
+	BackupCronExpression          string          `split_words:"true" default:"@daily"`
 	BackupRetentionDays           int32           `split_words:"true" default:"-1"`
 	BackupPruningLeeway           time.Duration   `split_words:"true" default:"1m"`
 	BackupPruningPrefix           string          `split_words:"true"`

cmd/backup/config_provider.go

@@ -0,0 +1,87 @@
+// Copyright 2021-2022 - Offen Authors <hioffen@posteo.de>
+// SPDX-License-Identifier: MPL-2.0
+
+package main
+
+import (
+	"fmt"
+	"os"
+	"path/filepath"
+
+	"github.com/joho/godotenv"
+	"github.com/offen/envconfig"
+)
+
+// envProxy is a function that mimics os.LookupEnv but can read values from any other source
+type envProxy func(string) (string, bool)
+
+func loadConfig(lookup envProxy) (*Config, error) {
+	envconfig.Lookup = func(key string) (string, bool) {
+		value, okValue := lookup(key)
+		location, okFile := lookup(key + "_FILE")
+
+		switch {
+		case okValue && !okFile: // only value
+			return value, true
+		case !okValue && okFile: // only file
+			contents, err := os.ReadFile(location)
+			if err != nil {
+				return "", false
+			}
+			return string(contents), true
+		case okValue && okFile: // both
+			return "", false
+		default: // neither, ignore
+			return "", false
+		}
+	}
+
+	var c = &Config{}
+	if err := envconfig.Process("", c); err != nil {
+		return nil, fmt.Errorf("loadConfig: failed to process configuration values: %w", err)
+	}
+
+	return c, nil
+}
+
+func loadEnvVars() (*Config, error) {
+	return loadConfig(os.LookupEnv)
+}
+
+type configFile struct {
+	name   string
+	config *Config
+}
+
+func loadEnvFiles(directory string) ([]configFile, error) {
+	items, err := os.ReadDir(directory)
+	if err != nil {
+		if os.IsNotExist(err) {
+			return nil, err
+		}
+		return nil, fmt.Errorf("loadEnvFiles: failed to read files from env directory: %w", err)
+	}
+
+	cs := []configFile{}
+	for _, item := range items {
+		if item.IsDir() {
+			continue
+		}
+		p := filepath.Join(directory, item.Name())
+		envFile, err := godotenv.Read(p)
+		if err != nil {
+			return nil, fmt.Errorf("loadEnvFiles: error reading config file %s: %w", p, err)
+		}
+		lookup := func(key string) (string, bool) {
+			val, ok := envFile[key]
+			return val, ok
+		}
+		c, err := loadConfig(lookup)
+		if err != nil {
+			return nil, fmt.Errorf("loadEnvFiles: error loading config from file %s: %w", p, err)
+		}
+		cs = append(cs, configFile{config: c, name: item.Name()})
+	}
+
+	return cs, nil
+}

cmd/backup/cron.go

@@ -0,0 +1,29 @@
+// Copyright 2024 - Offen Authors <hioffen@posteo.de>
+// SPDX-License-Identifier: MPL-2.0
+
+package main
+
+import (
+	"time"
+
+	"github.com/robfig/cron/v3"
+)
+
+// checkCronSchedule detects whether the given cron expression will actually
+// ever be executed or not.
+func checkCronSchedule(expression string) (ok bool) {
+	defer func() {
+		if err := recover(); err != nil {
+			ok = false
+		}
+	}()
+	sched, err := cron.ParseStandard(expression)
+	if err != nil {
+		ok = false
+		return
+	}
+	now := time.Now()
+	sched.Next(now) // panics when the cron would never run
+	ok = true
+	return
+}

cmd/backup/exec.go

@@ -188,13 +188,18 @@ func (s *script) withLabeledCommands(step lifecyclePhase, cb func() error) func(
 	if s.cli == nil {
 		return cb
 	}
-	return func() error {
-		if err := s.runLabeledCommands(fmt.Sprintf("docker-volume-backup.%s-pre", step)); err != nil {
-			return fmt.Errorf("withLabeledCommands: %s: error running pre commands: %w", step, err)
+	return func() (err error) {
+		if err = s.runLabeledCommands(fmt.Sprintf("docker-volume-backup.%s-pre", step)); err != nil {
+			err = fmt.Errorf("withLabeledCommands: %s: error running pre commands: %w", step, err)
+			return
 		}
 		defer func() {
-			s.must(s.runLabeledCommands(fmt.Sprintf("docker-volume-backup.%s-post", step)))
+			derr := s.runLabeledCommands(fmt.Sprintf("docker-volume-backup.%s-post", step))
+			if err == nil && derr != nil {
+				err = derr
+			}
 		}()
-		return cb()
+		err = cb()
+		return
 	}
 }

cmd/backup/main.go

@@ -4,65 +4,242 @@
 package main
 
 import (
+	"flag"
 	"fmt"
+	"log/slog"
 	"os"
+	"os/signal"
+	"runtime"
+	"syscall"
+
+	"github.com/robfig/cron/v3"
 )
 
-func main() {
-	s, err := newScript()
+type command struct {
+	logger *slog.Logger
+}
+
+func newCommand() *command {
+	return &command{
+		logger: slog.New(slog.NewTextHandler(os.Stdout, nil)),
+	}
+}
+
+func (c *command) must(err error) {
 	if err != nil {
-		panic(err)
-	}
-
-	unlock, err := s.lock("/var/lock/dockervolumebackup.lock")
-	defer func() {
-		s.must(unlock())
-	}()
-	s.must(err)
-
-	defer func() {
-		if pArg := recover(); pArg != nil {
-			if err, ok := pArg.(error); ok {
-				s.logger.Error(
-					fmt.Sprintf("Executing the script encountered a panic: %v", err),
-				)
-				if hookErr := s.runHooks(err); hookErr != nil {
-					s.logger.Error(
-						fmt.Sprintf("An error occurred calling the registered hooks: %s", hookErr),
-					)
-				}
-				os.Exit(1)
-			}
-			panic(pArg)
-		}
-
-		if err := s.runHooks(nil); err != nil {
-			s.logger.Error(
-				fmt.Sprintf(
-					"Backup procedure ran successfully, but an error ocurred calling the registered hooks: %v",
+		c.logger.Error(
+			fmt.Sprintf("Fatal error running command: %v", err),
+			"error",
 			err,
-				),
 		)
 		os.Exit(1)
 	}
-		s.logger.Info("Finished running backup tasks.")
+}
+
+func runScript(c *Config) (err error) {
+	defer func() {
+		if derr := recover(); derr != nil {
+			err = fmt.Errorf("runScript: unexpected panic running script: %v", err)
+		}
 	}()
 
-	s.must(s.withLabeledCommands(lifecyclePhaseArchive, func() error {
+	s, err := newScript(c)
+	if err != nil {
+		err = fmt.Errorf("runScript: error instantiating script: %w", err)
+		return
+	}
+
+	runErr := func() (err error) {
+		unlock, err := s.lock("/var/lock/dockervolumebackup.lock")
+		if err != nil {
+			err = fmt.Errorf("runScript: error acquiring file lock: %w", err)
+			return
+		}
+
+		defer func() {
+			derr := unlock()
+			if err == nil && derr != nil {
+				err = fmt.Errorf("runScript: error releasing file lock: %w", derr)
+			}
+		}()
+
+		scriptErr := func() error {
+			if err := s.withLabeledCommands(lifecyclePhaseArchive, func() (err error) {
 				restartContainersAndServices, err := s.stopContainersAndServices()
 				// The mechanism for restarting containers is not using hooks as it
 				// should happen as soon as possible (i.e. before uploading backups or
 				// similar).
 				defer func() {
-			s.must(restartContainersAndServices())
+					derr := restartContainersAndServices()
+					if err == nil {
+						err = derr
+					}
 				}()
 				if err != nil {
+					return
+				}
+				err = s.createArchive()
+				return
+			})(); err != nil {
 				return err
 			}
-		return s.createArchive()
-	})())
 
-	s.must(s.withLabeledCommands(lifecyclePhaseProcess, s.encryptArchive)())
-	s.must(s.withLabeledCommands(lifecyclePhaseCopy, s.copyArchive)())
-	s.must(s.withLabeledCommands(lifecyclePhasePrune, s.pruneBackups)())
+			if err := s.withLabeledCommands(lifecyclePhaseProcess, s.encryptArchive)(); err != nil {
+				return err
+			}
+			if err := s.withLabeledCommands(lifecyclePhaseCopy, s.copyArchive)(); err != nil {
+				return err
+			}
+			if err := s.withLabeledCommands(lifecyclePhasePrune, s.pruneBackups)(); err != nil {
+				return err
+			}
+			return nil
+		}()
+
+		if hookErr := s.runHooks(scriptErr); hookErr != nil {
+			if scriptErr != nil {
+				return fmt.Errorf(
+					"runScript: error %w executing the script followed by %w calling the registered hooks",
+					scriptErr,
+					hookErr,
+				)
+			}
+			return fmt.Errorf(
+				"runScript: the script ran successfully, but an error occurred calling the registered hooks: %w",
+				hookErr,
+			)
+		}
+		if scriptErr != nil {
+			return fmt.Errorf("runScript: error running script: %w", scriptErr)
+		}
+		return nil
+	}()
+
+	if runErr != nil {
+		s.logger.Error(
+			fmt.Sprintf("Script run failed: %v", runErr), "error", runErr,
+		)
+	}
+	return runErr
+}
+
+func (c *command) runInForeground(profileCronExpression string) error {
+	cr := cron.New(
+		cron.WithParser(
+			cron.NewParser(
+				cron.SecondOptional | cron.Minute | cron.Hour | cron.Dom | cron.Month | cron.Dow | cron.Descriptor,
+			),
+		),
+	)
+
+	addJob := func(config *Config, name string) error {
+		if _, err := cr.AddFunc(config.BackupCronExpression, func() {
+			c.logger.Info(
+				fmt.Sprintf(
+					"Now running script on schedule %s",
+					config.BackupCronExpression,
+				),
+			)
+			if err := runScript(config); err != nil {
+				c.logger.Error(
+					fmt.Sprintf(
+						"Unexpected error running schedule %s: %v",
+						config.BackupCronExpression,
+						err,
+					),
+					"error",
+					err,
+				)
+			}
+		}); err != nil {
+			return fmt.Errorf("addJob: error adding schedule %s: %w", config.BackupCronExpression, err)
+		}
+
+		c.logger.Info(fmt.Sprintf("Successfully scheduled backup %s with expression %s", name, config.BackupCronExpression))
+		if ok := checkCronSchedule(config.BackupCronExpression); !ok {
+			c.logger.Warn(
+				fmt.Sprintf("Scheduled cron expression %s will never run, is this intentional?", config.BackupCronExpression),
+			)
+		}
+
+		return nil
+	}
+
+	cs, err := loadEnvFiles("/etc/dockervolumebackup/conf.d")
+	if err != nil {
+		if !os.IsNotExist(err) {
+			return fmt.Errorf("runInForeground: could not load config from environment files: %w", err)
+		}
+
+		c, err := loadEnvVars()
+		if err != nil {
+			return fmt.Errorf("runInForeground: could not load config from environment variables: %w", err)
+		} else {
+			err = addJob(c, "from environment")
+			if err != nil {
+				return fmt.Errorf("runInForeground: error adding job from env: %w", err)
+			}
+		}
+	} else {
+		c.logger.Info("/etc/dockervolumebackup/conf.d was found, using configuration files from this directory.")
+		for _, config := range cs {
+			err = addJob(config.config, config.name)
+			if err != nil {
+				return fmt.Errorf("runInForeground: error adding jobs from conf files: %w", err)
+			}
+		}
+	}
+
+	if profileCronExpression != "" {
+		cr.AddFunc(profileCronExpression, func() {
+			memStats := runtime.MemStats{}
+			runtime.ReadMemStats(&memStats)
+			c.logger.Info(
+				"Collecting runtime information",
+				"num_goroutines",
+				runtime.NumGoroutine(),
+				"memory_heap_alloc",
+				formatBytes(memStats.HeapAlloc, false),
+				"memory_heap_inuse",
+				formatBytes(memStats.HeapInuse, false),
+				"memory_heap_sys",
+				formatBytes(memStats.HeapSys, false),
+			)
+		})
+	}
+
+	var quit = make(chan os.Signal, 1)
+	signal.Notify(quit, syscall.SIGTERM, syscall.SIGINT)
+	cr.Start()
+	<-quit
+	ctx := cr.Stop()
+	<-ctx.Done()
+
+	return nil
+}
+
+func (c *command) runAsCommand() error {
+	config, err := loadEnvVars()
+	if err != nil {
+		return fmt.Errorf("runAsCommand: error loading env vars: %w", err)
+	}
+	err = runScript(config)
+	if err != nil {
+		return fmt.Errorf("runAsCommand: error running script: %w", err)
+	}
+
+	return nil
+}
+
+func main() {
+	foreground := flag.Bool("foreground", false, "run the tool in the foreground")
+	profile := flag.String("profile", "", "collect runtime metrics and log them periodically on the given cron expression")
+	flag.Parse()
+
+	c := newCommand()
+	if *foreground {
+		c.must(c.runInForeground(*profile))
+	} else {
+		c.must(c.runAsCommand())
+	}
 }

cmd/backup/script.go

@@ -30,7 +30,6 @@ import (
 	"github.com/containrrr/shoutrrr/pkg/router"
 	"github.com/docker/docker/client"
 	"github.com/leekchan/timeutil"
-	"github.com/offen/envconfig"
 	"github.com/otiai10/copy"
 	"golang.org/x/sync/errgroup"
 )
@@ -58,10 +57,10 @@ type script struct {
 // remote resources like the Docker engine or remote storage locations. All
 // reading from env vars or other configuration sources is expected to happen
 // in this method.
-func newScript() (*script, error) {
+func newScript(c *Config) (*script, error) {
 	stdOut, logBuffer := buffer(os.Stdout)
 	s := &script{
-		c:      &Config{},
+		c:      c,
 		logger: slog.New(slog.NewTextHandler(stdOut, nil)),
 		stats: &Stats{
 			StartTime: time.Now(),
@@ -83,32 +82,6 @@ func newScript() (*script, error) {
 		return nil
 	})
 
-	envconfig.Lookup = func(key string) (string, bool) {
-		value, okValue := os.LookupEnv(key)
-		location, okFile := os.LookupEnv(key + "_FILE")
-
-		switch {
-		case okValue && !okFile: // only value
-			return value, true
-		case !okValue && okFile: // only file
-			contents, err := os.ReadFile(location)
-			if err != nil {
-				s.must(fmt.Errorf("newScript: failed to read %s! Error: %s", location, err))
-				return "", false
-			}
-			return string(contents), true
-		case okValue && okFile: // both
-			s.must(fmt.Errorf("newScript: both %s and %s are set!", key, key+"_FILE"))
-			return "", false
-		default: // neither, ignore
-			return "", false
-		}
-	}
-
-	if err := envconfig.Process("", s.c); err != nil {
-		return nil, fmt.Errorf("newScript: failed to process configuration values: %w", err)
-	}
-
 	s.file = path.Join("/tmp", s.c.BackupFilename)
 
 	tmplFileName, tErr := template.New("extension").Parse(s.file)
@@ -139,6 +112,12 @@ func newScript() (*script, error) {
 			return nil, fmt.Errorf("newScript: failed to create docker client")
 		}
 		s.cli = cli
+		s.registerHook(hookLevelPlumbing, func(err error) error {
+			if err := s.cli.Close(); err != nil {
+				return fmt.Errorf("newScript: failed to close docker client: %w", err)
+			}
+			return nil
+		})
 	}
 
 	logFunc := func(logType storage.LogLevel, context string, msg string, params ...any) {
@@ -507,17 +486,6 @@ func (s *script) pruneBackups() error {
 	return nil
 }
 
-// must exits the script run prematurely in case the given error
-// is non-nil.
-func (s *script) must(err error) {
-	if err != nil {
-		s.logger.Error(
-			fmt.Sprintf("Fatal error running backup: %s", err),
-		)
-		panic(err)
-	}
-}
-
 // skipPrune returns true if the given backend name is contained in the
 // list of skipped backends.
 func skipPrune(name string, skippedBackends []string) bool {

docs/reference/index.md

@@ -23,9 +23,22 @@ You can populate below template according to your requirements and use it as you
 ```
 ########### BACKUP SCHEDULE
 
-# Backups run on the given cron schedule in `busybox` flavor. If no
-# value is set, `@daily` will be used. If you do not want the cron
-# to ever run, use `0 0 5 31 2 ?`.
+
+# A cron expression represents a set of times, using 5 or 6 space-separated fields.
+#
+# Field name   | Mandatory? | Allowed values  | Allowed special characters
+# ----------   | ---------- | --------------  | --------------------------
+# Seconds      | No         | 0-59            | * / , -
+# Minutes      | Yes        | 0-59            | * / , -
+# Hours        | Yes        | 0-23            | * / , -
+# Day of month | Yes        | 1-31            | * / , - ?
+# Month        | Yes        | 1-12 or JAN-DEC | * / , -
+# Day of week  | Yes        | 0-6 or SUN-SAT  | * / , - ?
+#
+# Month and Day-of-week field values are case insensitive.
+# "SUN", "Sun", and "sun" are equally accepted.
+# If no value is set, `@daily` will be used.
+# If you do not want the cron to ever run, use `0 0 5 31 2 ?`.
 
 # BACKUP_CRON_EXPRESSION="0 2 * * *"
 

entrypoint.sh

@@ -1,26 +0,0 @@
-#!/bin/sh
-
-# Copyright 2021 - Offen Authors <hioffen@posteo.de>
-# SPDX-License-Identifier: MPL-2.0
-
-set -e
-
-if [ ! -d "/etc/dockervolumebackup/conf.d" ]; then
-  BACKUP_CRON_EXPRESSION="${BACKUP_CRON_EXPRESSION:-@daily}"
-
-  echo "Installing cron.d entry with expression $BACKUP_CRON_EXPRESSION."
-  echo "$BACKUP_CRON_EXPRESSION backup 2>&1" | crontab -
-else
-  echo "/etc/dockervolumebackup/conf.d was found, using configuration files from this directory."
-
-  crontab -r && crontab /dev/null
-  for file in /etc/dockervolumebackup/conf.d/*; do
-    source $file
-    BACKUP_CRON_EXPRESSION="${BACKUP_CRON_EXPRESSION:-@daily}"
-    echo "Appending cron.d entry with expression $BACKUP_CRON_EXPRESSION and configuration file $file"
-    (crontab -l; echo "$BACKUP_CRON_EXPRESSION /bin/sh -c 'set -a; source $file; set +a && backup' 2>&1") | crontab -
-  done
-fi
-
-echo "Starting cron in foreground."
-crond -f -d 8

go.mod

@@ -10,12 +10,14 @@ require (
 	github.com/docker/cli v24.0.1+incompatible
 	github.com/docker/docker v24.0.7+incompatible
 	github.com/gofrs/flock v0.8.1
+	github.com/joho/godotenv v1.5.1
 	github.com/klauspost/compress v1.17.6
 	github.com/leekchan/timeutil v0.0.0-20150802142658-28917288c48d
 	github.com/minio/minio-go/v7 v7.0.66
 	github.com/offen/envconfig v1.5.0
 	github.com/otiai10/copy v1.14.0
 	github.com/pkg/sftp v1.13.6
+	github.com/robfig/cron/v3 v3.0.0
 	github.com/studio-b12/gowebdav v0.9.0
 	golang.org/x/crypto v0.18.0
 	golang.org/x/oauth2 v0.16.0

go.sum

@@ -443,6 +443,8 @@ github.com/ianlancetaylor/demangle v0.0.0-20200824232613-28f6c0f3b639/go.mod h1:
 github.com/inconshreveable/mousetrap v1.0.1/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw=
 github.com/jarcoal/httpmock v1.2.0 h1:gSvTxxFR/MEMfsGrvRbdfpRUMBStovlSRLw0Ep1bwwc=
 github.com/jarcoal/httpmock v1.2.0/go.mod h1:oCoTsnAz4+UoOUIf5lJOWV2QQIW5UoeUI6aM2YnWAZk=
+github.com/joho/godotenv v1.5.1 h1:7eLL/+HRGLY0ldzfGMeQkb7vMd0as4CfYvUVzLqw0N0=
+github.com/joho/godotenv v1.5.1/go.mod h1:f4LDr5Voq0i2e/R5DDNOoa2zzDfwtkZa6DnEwAbqwq4=
 github.com/jpillora/backoff v1.0.0/go.mod h1:J/6gKK9jxlEcS3zixgDgUAsiuZ7yrSoa/FX5e0EB2j4=
 github.com/json-iterator/go v1.1.6/go.mod h1:+SdeFBvtyEkXs7REEP0seUULqWtbJapLOCVDaaPEHmU=
 github.com/json-iterator/go v1.1.9/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/uOdHXbAo4=
@@ -593,6 +595,8 @@ github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsT
 github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A=
 github.com/prometheus/procfs v0.1.3/go.mod h1:lV6e/gmhEcM9IjHGsFOCxxuZ+z1YqCvr4OA4YeYWdaU=
 github.com/prometheus/procfs v0.6.0/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1xBZuNvfVA=
+github.com/robfig/cron/v3 v3.0.0 h1:kQ6Cb7aHOHTSzNVNEhmp8EcWKLb4CbiMW9h9VyIhO4E=
+github.com/robfig/cron/v3 v3.0.0/go.mod h1:eQICP3HwyT7UooqI/z+Ov+PtYAWygg1TEWWzGIFLtro=
 github.com/rogpeppe/fastuuid v1.2.0/go.mod h1:jVj6XXZzXRy/MSR5jhDC/2q6DgLz+nrA6LYCDYWNEvQ=
 github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4=
 github.com/rogpeppe/go-internal v1.6.1/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTEfhy4qGm1nDQc=

test/confd/run.sh

@@ -13,6 +13,8 @@ docker compose up -d --quiet-pull
 # sleep until a backup is guaranteed to have happened on the 1 minute schedule
 sleep 100
 
+docker compose logs backup
+
 if [ ! -f "$LOCAL_DIR/conf.tar.gz" ]; then
   fail "Config from file was not used."
 fi