From d642a60c4d3547eacc91a4283ad10364cd4ee524 Mon Sep 17 00:00:00 2001 From: pixxon Date: Tue, 6 Feb 2024 21:05:38 +0100 Subject: [PATCH 1/5] Move cron scheduling inside application (#338) * Move cron scheduling inside application * Make envvar a fallback and check for errors * Panic significantly less * propagate error out of runBackup * Add structured logging * FIx error propagation to exit * Enable the new scheduler by default * Review fixes * Added docs and better error propagation --- Dockerfile | 2 +- cmd/backup/config.go | 1 + cmd/backup/config_provider.go | 81 +++++++++++++++++++++++ cmd/backup/main.go | 119 +++++++++++++++++++++++++++++++--- cmd/backup/script.go | 31 +-------- docs/reference/index.md | 19 +++++- go.mod | 2 + go.sum | 4 ++ 8 files changed, 218 insertions(+), 41 deletions(-) create mode 100644 cmd/backup/config_provider.go diff --git a/Dockerfile b/Dockerfile index 4570ec86..b85440f3 100644 --- a/Dockerfile +++ b/Dockerfile @@ -18,4 +18,4 @@ 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"] diff --git a/cmd/backup/config.go b/cmd/backup/config.go index db39acac..7138ba00 100644 --- a/cmd/backup/config.go +++ b/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"` diff --git a/cmd/backup/config_provider.go b/cmd/backup/config_provider.go new file mode 100644 index 00000000..424afab6 --- /dev/null +++ b/cmd/backup/config_provider.go @@ -0,0 +1,81 @@ +// Copyright 2021-2022 - Offen Authors +// 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("failed to process configuration values, error: %w", err) + } + + return c, nil +} + +func loadEnvVars() (*Config, error) { + return loadConfig(os.LookupEnv) +} + +func loadEnvFiles(directory string) ([]*Config, error) { + items, err := os.ReadDir(directory) + if err != nil { + if os.IsNotExist(err) { + return nil, err + } + return nil, fmt.Errorf("failed to read files from env directory, error: %w", err) + } + + var cs = make([]*Config, 0) + for _, item := range items { + if !item.IsDir() { + p := filepath.Join(directory, item.Name()) + envFile, err := godotenv.Read(p) + if err != nil { + return nil, fmt.Errorf("error reading config file %s, error: %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("error loading config from file %s, error: %w", p, err) + } + cs = append(cs, c) + } + } + + return cs, nil +} diff --git a/cmd/backup/main.go b/cmd/backup/main.go index 12db052e..c10b9b1e 100644 --- a/cmd/backup/main.go +++ b/cmd/backup/main.go @@ -4,21 +4,33 @@ package main import ( + "flag" "fmt" + "log/slog" "os" + "os/signal" + "syscall" + + "github.com/robfig/cron/v3" ) -func main() { - s, err := newScript() +func runScript(c *Config) (ret error) { + s, err := newScript(c) if err != nil { - panic(err) + return err } unlock, err := s.lock("/var/lock/dockervolumebackup.lock") + if err != nil { + return err + } + defer func() { - s.must(unlock()) + err = unlock() + if err != nil { + ret = err + } }() - s.must(err) defer func() { if pArg := recover(); pArg != nil { @@ -31,9 +43,14 @@ func main() { fmt.Sprintf("An error occurred calling the registered hooks: %s", hookErr), ) } - os.Exit(1) + ret = err + } else { + s.logger.Error( + fmt.Sprintf("Executing the script encountered an unrecoverable panic: %v", err), + ) + + panic(pArg) } - panic(pArg) } if err := s.runHooks(nil); err != nil { @@ -43,7 +60,7 @@ func main() { err, ), ) - os.Exit(1) + ret = err } s.logger.Info("Finished running backup tasks.") }() @@ -65,4 +82,90 @@ func main() { s.must(s.withLabeledCommands(lifecyclePhaseProcess, s.encryptArchive)()) s.must(s.withLabeledCommands(lifecyclePhaseCopy, s.copyArchive)()) s.must(s.withLabeledCommands(lifecyclePhasePrune, s.pruneBackups)()) + + return nil +} + +func runInForeground() error { + cr := cron.New( + cron.WithParser( + cron.NewParser( + cron.SecondOptional | cron.Minute | cron.Hour | cron.Dom | cron.Month | cron.Dow | cron.Descriptor, + ), + ), + ) + + addJob := func(c *Config) error { + _, err := cr.AddFunc(c.BackupCronExpression, func() { + err := runScript(c) + if err != nil { + slog.Error("unexpected error during backup", "error", err) + } + }) + return err + } + + cs, err := loadEnvFiles("/etc/dockervolumebackup/conf.d") + if err != nil { + if !os.IsNotExist(err) { + return fmt.Errorf("could not load config from environment files, error: %w", err) + } + + c, err := loadEnvVars() + if err != nil { + return fmt.Errorf("could not load config from environment variables") + } else { + err = addJob(c) + if err != nil { + return fmt.Errorf("could not add cron job, error: %w", err) + } + } + } else { + for _, c := range cs { + err = addJob(c) + if err != nil { + return fmt.Errorf("could not add cron job, error: %w", err) + } + } + } + + 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 runAsCommand() error { + c, err := loadEnvVars() + if err != nil { + return fmt.Errorf("could not load config from environment variables, error: %w", err) + } + + err = runScript(c) + if err != nil { + return fmt.Errorf("unexpected error during backup, error: %w", err) + } + + return nil +} + +func main() { + serve := flag.Bool("foreground", false, "run the tool in the foreground") + flag.Parse() + + var err error + if *serve { + err = runInForeground() + } else { + err = runAsCommand() + } + + if err != nil { + slog.Error("ran into an issue during execution", "error", err) + os.Exit(1) + } } diff --git a/cmd/backup/script.go b/cmd/backup/script.go index 747a4ddc..324f5a0d 100644 --- a/cmd/backup/script.go +++ b/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) diff --git a/docs/reference/index.md b/docs/reference/index.md index 8caf7755..0353b4dd 100644 --- a/docs/reference/index.md +++ b/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 * * *" diff --git a/go.mod b/go.mod index bf0ef4d3..9987c30a 100644 --- a/go.mod +++ b/go.mod @@ -28,6 +28,8 @@ require ( github.com/golang-jwt/jwt/v5 v5.2.0 // indirect github.com/golang/protobuf v1.5.3 // indirect golang.org/x/time v0.0.0-20220609170525-579cf78fd858 // indirect + github.com/joho/godotenv v1.5.1 // indirect + github.com/robfig/cron/v3 v3.0.0 // indirect google.golang.org/appengine v1.6.7 // indirect google.golang.org/protobuf v1.31.0 // indirect ) diff --git a/go.sum b/go.sum index e67f8a31..29fefb6d 100644 --- a/go.sum +++ b/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= From f1753a0f3581df363f0f125e27abb58c0d358fa1 Mon Sep 17 00:00:00 2001 From: Frederik Ring Date: Tue, 6 Feb 2024 21:46:18 +0100 Subject: [PATCH 2/5] Entrypoint script is not needed anymore (#346) --- Dockerfile | 1 - entrypoint.sh | 26 -------------------------- go.mod | 4 ++-- 3 files changed, 2 insertions(+), 29 deletions(-) delete mode 100644 entrypoint.sh diff --git a/Dockerfile b/Dockerfile index b85440f3..6d0be0d7 100644 --- a/Dockerfile +++ b/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 ["/usr/bin/backup", "-foreground"] diff --git a/entrypoint.sh b/entrypoint.sh deleted file mode 100644 index edbf6c9a..00000000 --- a/entrypoint.sh +++ /dev/null @@ -1,26 +0,0 @@ -#!/bin/sh - -# Copyright 2021 - Offen Authors -# 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 diff --git a/go.mod b/go.mod index 9987c30a..7147ca09 100644 --- a/go.mod +++ b/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 @@ -28,8 +30,6 @@ require ( github.com/golang-jwt/jwt/v5 v5.2.0 // indirect github.com/golang/protobuf v1.5.3 // indirect golang.org/x/time v0.0.0-20220609170525-579cf78fd858 // indirect - github.com/joho/godotenv v1.5.1 // indirect - github.com/robfig/cron/v3 v3.0.0 // indirect google.golang.org/appengine v1.6.7 // indirect google.golang.org/protobuf v1.31.0 // indirect ) From 6cea183715d160ba4f5a3e41d880304dedd32c19 Mon Sep 17 00:00:00 2001 From: Frederik Ring Date: Fri, 9 Feb 2024 10:24:28 +0100 Subject: [PATCH 3/5] Hoist control for exiting script a level up (#348) * 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 --- cmd/backup/config_provider.go | 44 ++++--- cmd/backup/cron.go | 29 +++++ cmd/backup/exec.go | 15 ++- cmd/backup/main.go | 222 +++++++++++++++++++++------------- cmd/backup/script.go | 11 -- test/confd/run.sh | 2 + 6 files changed, 204 insertions(+), 119 deletions(-) create mode 100644 cmd/backup/cron.go diff --git a/cmd/backup/config_provider.go b/cmd/backup/config_provider.go index 424afab6..50a588d4 100644 --- a/cmd/backup/config_provider.go +++ b/cmd/backup/config_provider.go @@ -38,7 +38,7 @@ func loadConfig(lookup envProxy) (*Config, error) { var c = &Config{} if err := envconfig.Process("", c); err != nil { - return nil, fmt.Errorf("failed to process configuration values, error: %w", err) + return nil, fmt.Errorf("loadConfig: failed to process configuration values: %w", err) } return c, nil @@ -48,33 +48,39 @@ func loadEnvVars() (*Config, error) { return loadConfig(os.LookupEnv) } -func loadEnvFiles(directory string) ([]*Config, error) { +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("failed to read files from env directory, error: %w", err) + return nil, fmt.Errorf("loadEnvFiles: failed to read files from env directory: %w", err) } - var cs = make([]*Config, 0) + cs := []configFile{} for _, item := range items { - if !item.IsDir() { - p := filepath.Join(directory, item.Name()) - envFile, err := godotenv.Read(p) - if err != nil { - return nil, fmt.Errorf("error reading config file %s, error: %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("error loading config from file %s, error: %w", p, err) - } - cs = append(cs, c) + 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 diff --git a/cmd/backup/cron.go b/cmd/backup/cron.go new file mode 100644 index 00000000..9416591b --- /dev/null +++ b/cmd/backup/cron.go @@ -0,0 +1,29 @@ +// Copyright 2024 - Offen Authors +// 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 +} diff --git a/cmd/backup/exec.go b/cmd/backup/exec.go index 0f4f7b5d..1fa09976 100644 --- a/cmd/backup/exec.go +++ b/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 } } diff --git a/cmd/backup/main.go b/cmd/backup/main.go index c10b9b1e..34211ee5 100644 --- a/cmd/backup/main.go +++ b/cmd/backup/main.go @@ -14,79 +14,115 @@ import ( "github.com/robfig/cron/v3" ) -func runScript(c *Config) (ret error) { - s, err := newScript(c) - if err != nil { - return err +type command struct { + logger *slog.Logger +} + +func newCommand() *command { + return &command{ + logger: slog.New(slog.NewTextHandler(os.Stdout, nil)), } +} - unlock, err := s.lock("/var/lock/dockervolumebackup.lock") +func (c *command) must(err error) { if err != nil { - return err + c.logger.Error( + fmt.Sprintf("Fatal error running command: %v", err), + "error", + err, + ) + os.Exit(1) } +} +func runScript(c *Config) (err error) { defer func() { - err = unlock() - if err != nil { - ret = err + if derr := recover(); derr != nil { + err = fmt.Errorf("runScript: unexpected panic running script: %v", 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), - ) + 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() { + derr := restartContainersAndServices() + if err == nil { + err = derr + } + }() + if err != nil { + return } - ret = err - } else { - s.logger.Error( - fmt.Sprintf("Executing the script encountered an unrecoverable panic: %v", err), - ) + err = s.createArchive() + return + })(); err != nil { + return err + } - panic(pArg) + 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 err := s.runHooks(nil); err != nil { - s.logger.Error( - fmt.Sprintf( - "Backup procedure ran successfully, but an error ocurred calling the registered hooks: %v", - err, - ), + 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, ) - ret = err } - s.logger.Info("Finished running backup tasks.") - }() - - s.must(s.withLabeledCommands(lifecyclePhaseArchive, func() 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()) - }() - if err != nil { - return err + if scriptErr != nil { + return fmt.Errorf("runScript: error running script: %w", scriptErr) } - return s.createArchive() - })()) - - s.must(s.withLabeledCommands(lifecyclePhaseProcess, s.encryptArchive)()) - s.must(s.withLabeledCommands(lifecyclePhaseCopy, s.copyArchive)()) - s.must(s.withLabeledCommands(lifecyclePhasePrune, s.pruneBackups)()) + return nil + }() - return nil + if runErr != nil { + s.logger.Error( + fmt.Sprintf("Script run failed: %v", runErr), "error", runErr, + ) + } + return runErr } -func runInForeground() error { +func (c *command) runInForeground() error { cr := cron.New( cron.WithParser( cron.NewParser( @@ -95,36 +131,60 @@ func runInForeground() error { ), ) - addJob := func(c *Config) error { - _, err := cr.AddFunc(c.BackupCronExpression, func() { - err := runScript(c) - if err != nil { - slog.Error("unexpected error during backup", "error", err) + 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, + ) } - }) - return 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("could not load config from environment files, error: %w", err) + return fmt.Errorf("runInForeground: could not load config from environment files: %w", err) } c, err := loadEnvVars() if err != nil { - return fmt.Errorf("could not load config from environment variables") + return fmt.Errorf("runInForeground: could not load config from environment variables: %w", err) } else { - err = addJob(c) + err = addJob(c, "from environment") if err != nil { - return fmt.Errorf("could not add cron job, error: %w", err) + return fmt.Errorf("runInForeground: error adding job from env: %w", err) } } } else { - for _, c := range cs { - err = addJob(c) + 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("could not add cron job, error: %w", err) + return fmt.Errorf("runInForeground: error adding jobs from conf files: %w", err) } } } @@ -139,33 +199,27 @@ func runInForeground() error { return nil } -func runAsCommand() error { - c, err := loadEnvVars() +func (c *command) runAsCommand() error { + config, err := loadEnvVars() if err != nil { - return fmt.Errorf("could not load config from environment variables, error: %w", err) + return fmt.Errorf("runAsCommand: error loading env vars: %w", err) } - - err = runScript(c) + err = runScript(config) if err != nil { - return fmt.Errorf("unexpected error during backup, error: %w", err) + return fmt.Errorf("runAsCommand: error running script: %w", err) } return nil } func main() { - serve := flag.Bool("foreground", false, "run the tool in the foreground") + foreground := flag.Bool("foreground", false, "run the tool in the foreground") flag.Parse() - var err error - if *serve { - err = runInForeground() + c := newCommand() + if *foreground { + c.must(c.runInForeground()) } else { - err = runAsCommand() - } - - if err != nil { - slog.Error("ran into an issue during execution", "error", err) - os.Exit(1) + c.must(c.runAsCommand()) } } diff --git a/cmd/backup/script.go b/cmd/backup/script.go index 324f5a0d..fa9719f9 100644 --- a/cmd/backup/script.go +++ b/cmd/backup/script.go @@ -480,17 +480,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 { diff --git a/test/confd/run.sh b/test/confd/run.sh index 3a5fca92..f81407a5 100755 --- a/test/confd/run.sh +++ b/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 From dc200be2e905da1722532971e8daa80b6c01b0fb Mon Sep 17 00:00:00 2001 From: Frederik Ring Date: Fri, 9 Feb 2024 20:55:37 +0100 Subject: [PATCH 4/5] Docker client expects to be closed after usage in long running program --- cmd/backup/script.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/cmd/backup/script.go b/cmd/backup/script.go index fa9719f9..b16d23b1 100644 --- a/cmd/backup/script.go +++ b/cmd/backup/script.go @@ -112,6 +112,12 @@ func newScript(c *Config) (*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) { From e76b4dab41ad56d76753a80de9257d0ca7abbb20 Mon Sep 17 00:00:00 2001 From: Frederik Ring Date: Sat, 10 Feb 2024 12:10:16 +0100 Subject: [PATCH 5/5] Periodically collect runtime info when requested --- cmd/backup/main.go | 28 ++++++++++++++++++++++++++-- 1 file changed, 26 insertions(+), 2 deletions(-) diff --git a/cmd/backup/main.go b/cmd/backup/main.go index 34211ee5..f52183c3 100644 --- a/cmd/backup/main.go +++ b/cmd/backup/main.go @@ -9,6 +9,7 @@ import ( "log/slog" "os" "os/signal" + "runtime" "syscall" "github.com/robfig/cron/v3" @@ -122,7 +123,7 @@ func runScript(c *Config) (err error) { return runErr } -func (c *command) runInForeground() error { +func (c *command) runInForeground(profileCronExpression string) error { cr := cron.New( cron.WithParser( cron.NewParser( @@ -189,6 +190,28 @@ func (c *command) runInForeground() error { } } + if profileCronExpression != "" { + if _, err := 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), + "memory_heap_objects", + memStats.HeapObjects, + ) + }); err != nil { + return fmt.Errorf("runInForeground: error adding profiling job: %w", err) + } + } + var quit = make(chan os.Signal, 1) signal.Notify(quit, syscall.SIGTERM, syscall.SIGINT) cr.Start() @@ -214,11 +237,12 @@ func (c *command) runAsCommand() error { 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()) + c.must(c.runInForeground(*profile)) } else { c.must(c.runAsCommand()) }