From 6775402907564390ac70eccb132a36122a370245 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sat, 22 Mar 2025 09:31:58 +0100 Subject: [PATCH 01/28] build: added pre-commit hooks --- .pre-commit-config.yaml | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml index caa20be..b18bc00 100644 --- a/.pre-commit-config.yaml +++ b/.pre-commit-config.yaml @@ -11,3 +11,18 @@ repos: rev: v3.2.1 hooks: - id: editorconfig-checker + + - repo: https://github.com/python-jsonschema/check-jsonschema + rev: 0.31.3 + hooks: + - id: check-gitlab-ci + - id: check-taskfile + + - repo: local + hooks: + - id: go-mod-tidy + name: Check go.sum + entry: go mod tidy -diff + language: golang + files: '(\.go|go\.(mod|sum))$' + pass_filenames: false -- GitLab From 3eedacfafd759918198e6012bfd060c0c049b382 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sat, 22 Mar 2025 09:32:38 +0100 Subject: [PATCH 02/28] feat: allow to append logs into a log file. --- cmd/monitor/logging.go | 104 +++++++++++++++++++++++++++++++++++++++++ cmd/monitor/main.go | 71 +++++++++++----------------- go.mod | 6 +++ go.sum | 4 ++ 4 files changed, 140 insertions(+), 45 deletions(-) create mode 100644 cmd/monitor/logging.go diff --git a/cmd/monitor/logging.go b/cmd/monitor/logging.go new file mode 100644 index 0000000..fee824a --- /dev/null +++ b/cmd/monitor/logging.go @@ -0,0 +1,104 @@ +package main + +import ( + "fmt" + "io" + "log/slog" + "os" + "path" + "time" + + "github.com/lmittmann/tint" + "github.com/mattn/go-isatty" + multi "github.com/samber/slog-multi" +) + +type LoggingConfig struct { + Verbose int + Quiet int + MetricsFilePath string + LogFilePath string +} + +func (l LoggingConfig) CreateLogLogger() (*slog.Logger, error) { + handler, err := l.createLogHandler() + if err != nil { + return nil, err + } + return slog.New(handler), nil +} + +func (l LoggingConfig) createLogHandler() (slog.Handler, error) { + fileHandler, err := l.createLogFileHandler(l.LogFilePath) + if err != nil { + return nil, err + } + if fileHandler == nil { + return l.createConsoleHandler(), nil + } + return multi.Failover()(fileHandler, l.createConsoleHandler()), nil +} + +func (l LoggingConfig) createLogFileHandler(filePath string) (slog.Handler, error) { + file, err := l.openFile(filePath) + if file == nil || err == nil { + return nil, err + } + opts := slog.HandlerOptions{Level: l.LogLevel()} + if path.Ext(filePath) == ".json" { + return slog.NewJSONHandler(file, &opts), nil + } + return slog.NewTextHandler(file, &opts), nil +} + +func (l LoggingConfig) LogLevel() slog.Leveler { + verbosity := l.Verbose - l.Quiet + if verbosity < 0 { + return slog.LevelError + + } else if verbosity == 1 { + return slog.LevelInfo + } else if verbosity > 1 { + return slog.LevelDebug + } + return slog.LevelWarn +} + +func (l LoggingConfig) openFile(path string) (io.Writer, error) { + if path == "-" || path == "" { + return nil, nil + } + file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777) + if err != nil { + return nil, fmt.Errorf("could not open file for appending: %w", err) + } + return file, err +} + +func (l LoggingConfig) createConsoleHandler() slog.Handler { + return tint.NewHandler(os.Stderr, &tint.Options{ + TimeFormat: time.DateTime, + Level: l.LogLevel(), + NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(os.Stderr.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), + }) +} + +func (l LoggingConfig) CreateMetricsLogger() (*slog.Logger, error) { + handler, err := l.createMetricsHandler() + if err != nil { + return nil, err + } + return slog.New(handler), nil +} + +func (l LoggingConfig) createMetricsHandler() (slog.Handler, error) { + //var metricFile io.Writer + metricFile, err := l.openFile(l.MetricsFilePath) + if err != nil { + return nil, err + } + if metricFile == nil { + metricFile = os.Stdout + } + return slog.NewJSONHandler(metricFile, nil), nil +} diff --git a/cmd/monitor/main.go b/cmd/monitor/main.go index 083c94c..a427a49 100644 --- a/cmd/monitor/main.go +++ b/cmd/monitor/main.go @@ -10,30 +10,46 @@ import ( "time" "github.com/docker/docker/api/types/container" - "github.com/lmittmann/tint" - "github.com/mattn/go-isatty" flag "github.com/spf13/pflag" ) const MIN_DOCKER_API_VERSION = "v1.44" func main() { - var verbose = flag.CountP("verbose", "v", "show more messages (cumulative)") - var quiet = flag.CountP("quiet", "q", "only show error messages") + if err := mainWithError(); err != nil { + slog.Error("fatal error", "err", err) + os.Exit(1) + } +} + +func mainWithError() error { + var loggingConfig LoggingConfig + flag.CountVarP(&loggingConfig.Verbose, "verbose", "v", "show more messages (cumulative)") + flag.CountVarP(&loggingConfig.Quiet, "quiet", "q", "only show error messages") + flag.StringVarP(&loggingConfig.MetricsFilePath, "output", "o", "-", "append metrics to target file") + flag.StringVarP(&loggingConfig.LogFilePath, "log-file", "l", "", "append logs to target file") + var catchUp = flag.BoolP("catch-up", "c", false, "catch up on running containers") var period = flag.DurationP("period", "p", time.Minute, "period of time between intermediate metrics; 0 to disable") var filter = PRESET_ALL flag.VarP(&filter, "filter", "f", "container and label filter preset") - var outputPath = flag.StringP("output", "o", "-", "write metrics to target file") - flag.Parse() - slog.SetDefault(slog.New(consoleHandler(*verbose - *quiet))) + if logger, err := loggingConfig.CreateLogLogger(); err == nil { + slog.SetDefault(logger) + } else { + return fmt.Errorf("could not open log file: %w", err) + } + + metricsLogger, err := loggingConfig.CreateMetricsLogger() + if err != nil { + return fmt.Errorf("could not open output file: %w", err) + } f := FilteringContainerMonitorFactory{ - MetricsLogger: slog.New(metricsHandler(*outputPath)), + MetricsLogger: metricsLogger, ContainerFilter: filter.ContainerFilter(), LabelFilter: filter.LabelFilter(), Period: *period, @@ -44,8 +60,7 @@ func main() { m, err := NewEngineMonitor(MIN_DOCKER_API_VERSION, f, *catchUp) if err != nil { - slog.Error("could not start main client", "err", err) - os.Exit(1) + return fmt.Errorf("could not start main client: %w", err) } if *period > 0 { @@ -57,41 +72,7 @@ func main() { slog.Debug("filtering containers and labels", "preset", filter) } - if err := m.Run(ctx); err != nil { - slog.Error("fatal error", "err", err) - os.Exit(1) - } -} - -func consoleHandler(verbosity int) slog.Handler { - loggerOptions := tint.Options{ - TimeFormat: time.DateTime, - Level: slog.LevelWarn, - NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(os.Stderr.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), - } - if verbosity < 0 { - loggerOptions.Level = slog.LevelError - } else if verbosity == 1 { - loggerOptions.Level = slog.LevelInfo - } else if verbosity > 1 { - loggerOptions.Level = slog.LevelDebug - } - return tint.NewHandler(os.Stderr, &loggerOptions) -} - -func metricsHandler(outputPath string) slog.Handler { - output := os.Stdout - if len(outputPath) > 0 && outputPath != "-" { - var err error - output, err = os.OpenFile(outputPath, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777) - if err != nil { - slog.Error("could open output file", "path", outputPath, "err", err) - os.Exit(1) - } - slog.Debug("writing metrics to file", "path", output.Name()) - } - - return slog.NewJSONHandler(output, nil) + return m.Run(ctx) } // ============================== FilterPreset ============================== diff --git a/go.mod b/go.mod index 178f042..3e995f0 100644 --- a/go.mod +++ b/go.mod @@ -9,6 +9,11 @@ require ( github.com/stretchr/testify v1.10.0 ) +require ( + github.com/samber/lo v1.49.1 // indirect + golang.org/x/text v0.22.0 // indirect +) + require ( github.com/Microsoft/go-winio v0.6.2 // indirect github.com/containerd/log v0.1.0 // indirect @@ -27,6 +32,7 @@ require ( github.com/opencontainers/image-spec v1.1.1 // indirect github.com/pkg/errors v0.9.1 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/samber/slog-multi v1.4.0 github.com/spf13/pflag v1.0.6 go.opentelemetry.io/auto/sdk v1.1.0 // indirect go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.60.0 // indirect diff --git a/go.sum b/go.sum index a418aa8..79048f8 100644 --- a/go.sum +++ b/go.sum @@ -57,6 +57,10 @@ github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZb github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/rogpeppe/go-internal v1.13.1 h1:KvO1DLK/DRN07sQ1LQKScxyZJuNnedQ5/wKSR38lUII= github.com/rogpeppe/go-internal v1.13.1/go.mod h1:uMEvuHeurkdAXX61udpOXGD/AzZDWNMNyH2VO9fmH0o= +github.com/samber/lo v1.49.1 h1:4BIFyVfuQSEpluc7Fua+j1NolZHiEHEpaSEKdsH0tew= +github.com/samber/lo v1.49.1/go.mod h1:dO6KHFzUKXgP8LDhU0oI8d2hekjXnGOu0DB8Jecxd6o= +github.com/samber/slog-multi v1.4.0 h1:pwlPMIE7PrbTHQyKWDU+RIoxP1+HKTNOujk3/kdkbdg= +github.com/samber/slog-multi v1.4.0/go.mod h1:FsQ4Uv2L+E/8TZt+/BVgYZ1LoDWCbfCU21wVIoMMrO8= github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/spf13/pflag v1.0.6 h1:jFzHGLGAlb3ruxLB8MhbI6A8+AQX/2eW4qeyNZXNp2o= -- GitLab From 0f06cf38b8d4154a67023958c0fdd9a1d445a7fe Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sat, 22 Mar 2025 09:59:14 +0100 Subject: [PATCH 03/28] build: add a task to run from source and a task to lint sources --- Taskfile.yml | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/Taskfile.yml b/Taskfile.yml index c26ae01..842c188 100644 --- a/Taskfile.yml +++ b/Taskfile.yml @@ -4,6 +4,10 @@ env: GOPATH: "{{ .ROOT_DIR }}/.go" tasks: + lint: + cmds: + - pre-commit run -a + build: deps: [deps] sources: @@ -21,6 +25,15 @@ tasks: cmds: - go test {{.CLI_ARGS}} ./cmd/... ./lib/... + run: + deps: [deps] + sources: + - cmd/**/* + - lib/**/* + - exclude: "**/*_test.go" + cmds: + - go run ./cmd/monitor {{.CLI_ARGS}} + clear: run: always cmds: @@ -37,10 +50,10 @@ tasks: sources: - cmd/**/*.go - lib/**/*.go + generates: - go.mod - go.sum - generates: - - '{{ .GOPATH }}/**/*' + - "{{ .GOPATH }}/**/*" cmds: - mkdir -p "{{ .GOPATH }}" - go mod tidy -v -- GitLab From 1f24adc46d37a5895de346a8336739e77e3a51ce Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sat, 22 Mar 2025 09:59:41 +0100 Subject: [PATCH 04/28] refactor: open output file while parsing flags --- cmd/monitor/logging.go | 113 +++++++++++++++++++++-------------------- cmd/monitor/main.go | 22 +++----- 2 files changed, 67 insertions(+), 68 deletions(-) diff --git a/cmd/monitor/logging.go b/cmd/monitor/logging.go index fee824a..429ac68 100644 --- a/cmd/monitor/logging.go +++ b/cmd/monitor/logging.go @@ -2,7 +2,6 @@ package main import ( "fmt" - "io" "log/slog" "os" "path" @@ -11,47 +10,42 @@ import ( "github.com/lmittmann/tint" "github.com/mattn/go-isatty" multi "github.com/samber/slog-multi" + "github.com/spf13/pflag" ) +// ============================== LoggingConfig ============================== + type LoggingConfig struct { - Verbose int - Quiet int - MetricsFilePath string - LogFilePath string + Verbose int + Quiet int + MetricsFile LogFile + LogFile LogFile } -func (l LoggingConfig) CreateLogLogger() (*slog.Logger, error) { - handler, err := l.createLogHandler() - if err != nil { - return nil, err - } - return slog.New(handler), nil +func (l LoggingConfig) CreateMetricsLogger() *slog.Logger { + return slog.New(slog.NewJSONHandler(l.MetricsFile, nil)) } -func (l LoggingConfig) createLogHandler() (slog.Handler, error) { - fileHandler, err := l.createLogFileHandler(l.LogFilePath) - if err != nil { - return nil, err - } - if fileHandler == nil { - return l.createConsoleHandler(), nil - } - return multi.Failover()(fileHandler, l.createConsoleHandler()), nil +func (l LoggingConfig) CreateLogLogger() *slog.Logger { + return slog.New(l.createLogHandler()) } -func (l LoggingConfig) createLogFileHandler(filePath string) (slog.Handler, error) { - file, err := l.openFile(filePath) - if file == nil || err == nil { - return nil, err +func (l LoggingConfig) createLogHandler() slog.Handler { + file := l.LogFile.File + if file == os.Stderr { + return l.createConsoleHandler() } - opts := slog.HandlerOptions{Level: l.LogLevel()} - if path.Ext(filePath) == ".json" { - return slog.NewJSONHandler(file, &opts), nil + var fileHandler slog.Handler + opts := slog.HandlerOptions{Level: l.logLevel(), AddSource: l.addSource()} + if path.Ext(file.Name()) == ".json" { + fileHandler = slog.NewJSONHandler(file, &opts) + } else { + fileHandler = slog.NewTextHandler(file, &opts) } - return slog.NewTextHandler(file, &opts), nil + return multi.Failover()(fileHandler, l.createConsoleHandler()) } -func (l LoggingConfig) LogLevel() slog.Leveler { +func (l LoggingConfig) logLevel() slog.Leveler { verbosity := l.Verbose - l.Quiet if verbosity < 0 { return slog.LevelError @@ -64,41 +58,52 @@ func (l LoggingConfig) LogLevel() slog.Leveler { return slog.LevelWarn } -func (l LoggingConfig) openFile(path string) (io.Writer, error) { - if path == "-" || path == "" { - return nil, nil - } - file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777) - if err != nil { - return nil, fmt.Errorf("could not open file for appending: %w", err) - } - return file, err +func (l LoggingConfig) addSource() bool { + return l.Verbose-l.Quiet > 2 } func (l LoggingConfig) createConsoleHandler() slog.Handler { return tint.NewHandler(os.Stderr, &tint.Options{ TimeFormat: time.DateTime, - Level: l.LogLevel(), + Level: l.logLevel(), + AddSource: l.addSource(), NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(os.Stderr.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), }) } -func (l LoggingConfig) CreateMetricsLogger() (*slog.Logger, error) { - handler, err := l.createMetricsHandler() - if err != nil { - return nil, err - } - return slog.New(handler), nil +// ============================== LogFile ============================== + +type LogFile struct { + *os.File } -func (l LoggingConfig) createMetricsHandler() (slog.Handler, error) { - //var metricFile io.Writer - metricFile, err := l.openFile(l.MetricsFilePath) - if err != nil { - return nil, err - } - if metricFile == nil { - metricFile = os.Stdout +var _ pflag.Value = (*LogFile)(nil) + +// Set implements flag.Value. +func (l *LogFile) Set(path string) error { + switch path { + case "-", "/dev/stdout", "/dev/fd/1": + l.File = os.Stdout + return nil + case "/dev/stderr", "/dev/fd/2": + l.File = os.Stderr + return nil + default: + if file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777); err == nil { + l.File = file + return nil + } else { + return fmt.Errorf("could not open file for appending: %w", err) + } } - return slog.NewJSONHandler(metricFile, nil), nil +} + +// String implements flag.Value. +func (l *LogFile) String() string { + return l.Name() +} + +// Type implements pflag.Value. +func (l *LogFile) Type() string { + return "file-path" } diff --git a/cmd/monitor/main.go b/cmd/monitor/main.go index a427a49..0e4cfcd 100644 --- a/cmd/monitor/main.go +++ b/cmd/monitor/main.go @@ -23,11 +23,14 @@ func main() { } func mainWithError() error { - var loggingConfig LoggingConfig + loggingConfig := LoggingConfig{ + MetricsFile: LogFile{os.Stdout}, + LogFile: LogFile{os.Stderr}, + } flag.CountVarP(&loggingConfig.Verbose, "verbose", "v", "show more messages (cumulative)") flag.CountVarP(&loggingConfig.Quiet, "quiet", "q", "only show error messages") - flag.StringVarP(&loggingConfig.MetricsFilePath, "output", "o", "-", "append metrics to target file") - flag.StringVarP(&loggingConfig.LogFilePath, "log-file", "l", "", "append logs to target file") + flag.VarP(&loggingConfig.MetricsFile, "output", "o", "append metrics to file") + flag.VarP(&loggingConfig.LogFile, "log-file", "l", "append logs to file") var catchUp = flag.BoolP("catch-up", "c", false, "catch up on running containers") var period = flag.DurationP("period", "p", time.Minute, "period of time between intermediate metrics; 0 to disable") @@ -37,19 +40,10 @@ func mainWithError() error { flag.Parse() - if logger, err := loggingConfig.CreateLogLogger(); err == nil { - slog.SetDefault(logger) - } else { - return fmt.Errorf("could not open log file: %w", err) - } - - metricsLogger, err := loggingConfig.CreateMetricsLogger() - if err != nil { - return fmt.Errorf("could not open output file: %w", err) - } + slog.SetDefault(loggingConfig.CreateLogLogger()) f := FilteringContainerMonitorFactory{ - MetricsLogger: metricsLogger, + MetricsLogger: loggingConfig.CreateMetricsLogger(), ContainerFilter: filter.ContainerFilter(), LabelFilter: filter.LabelFilter(), Period: *period, -- GitLab From cb340e79f30de32ca13eccdf7c87e598615c8f41 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sat, 22 Mar 2025 10:34:08 +0100 Subject: [PATCH 05/28] refactor: do not open output files while parsing args. --- cmd/monitor/logging.go | 128 ++++++++++++++++++++++++++++++----------- cmd/monitor/main.go | 21 +++++-- 2 files changed, 108 insertions(+), 41 deletions(-) diff --git a/cmd/monitor/logging.go b/cmd/monitor/logging.go index 429ac68..0b1c22b 100644 --- a/cmd/monitor/logging.go +++ b/cmd/monitor/logging.go @@ -2,9 +2,11 @@ package main import ( "fmt" + "io" "log/slog" "os" "path" + "syscall" "time" "github.com/lmittmann/tint" @@ -16,33 +18,46 @@ import ( // ============================== LoggingConfig ============================== type LoggingConfig struct { - Verbose int - Quiet int - MetricsFile LogFile - LogFile LogFile + Verbose int + Quiet int + MetricsFilePath WriteFilePath + LogFilePath WriteFilePath } -func (l LoggingConfig) CreateMetricsLogger() *slog.Logger { - return slog.New(slog.NewJSONHandler(l.MetricsFile, nil)) +func (l LoggingConfig) CreateMetricsLogger() (*slog.Logger, error) { + writer, err := l.MetricsFilePath.Open() + if err != nil { + return nil, fmt.Errorf("could not open output for appending: %w", err) + } + return slog.New(slog.NewJSONHandler(writer, nil)), nil } -func (l LoggingConfig) CreateLogLogger() *slog.Logger { - return slog.New(l.createLogHandler()) +func (l LoggingConfig) CreateLogLogger() (*slog.Logger, error) { + if handler, err := l.createLogHandler(); err == nil { + return slog.New(handler), nil + } else { + return nil, err + } } -func (l LoggingConfig) createLogHandler() slog.Handler { - file := l.LogFile.File - if file == os.Stderr { - return l.createConsoleHandler() +func (l LoggingConfig) createLogHandler() (slog.Handler, error) { + if l.LogFilePath.IsStdfile() { + return l.createConsoleHandler(l.LogFilePath.StdFile()), nil + } + + writer, err := l.LogFilePath.Open() + if err != nil { + return nil, fmt.Errorf("could not open log file for appending: %w", err) } + var fileHandler slog.Handler opts := slog.HandlerOptions{Level: l.logLevel(), AddSource: l.addSource()} - if path.Ext(file.Name()) == ".json" { - fileHandler = slog.NewJSONHandler(file, &opts) + if l.LogFilePath.IsJSON() { + fileHandler = slog.NewJSONHandler(writer, &opts) } else { - fileHandler = slog.NewTextHandler(file, &opts) + fileHandler = slog.NewTextHandler(writer, &opts) } - return multi.Failover()(fileHandler, l.createConsoleHandler()) + return multi.Failover()(fileHandler, l.createConsoleHandler(os.Stderr)), nil } func (l LoggingConfig) logLevel() slog.Leveler { @@ -62,48 +77,91 @@ func (l LoggingConfig) addSource() bool { return l.Verbose-l.Quiet > 2 } -func (l LoggingConfig) createConsoleHandler() slog.Handler { - return tint.NewHandler(os.Stderr, &tint.Options{ +func (l LoggingConfig) createConsoleHandler(console *os.File) slog.Handler { + return tint.NewHandler(console, &tint.Options{ TimeFormat: time.DateTime, Level: l.logLevel(), AddSource: l.addSource(), - NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(os.Stderr.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), + NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(console.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), }) } // ============================== LogFile ============================== -type LogFile struct { - *os.File -} +type WriteFilePath string -var _ pflag.Value = (*LogFile)(nil) +var _ pflag.Value = (*WriteFilePath)(nil) // Set implements flag.Value. -func (l *LogFile) Set(path string) error { - switch path { - case "-", "/dev/stdout", "/dev/fd/1": - l.File = os.Stdout +func (l *WriteFilePath) Set(filePath string) error { + switch filePath { + case "", "-", "/dev/stdout", "/dev/fd/1": + *l = "/dev/stdout" return nil case "/dev/stderr", "/dev/fd/2": - l.File = os.Stderr + *l = "/dev/stderr" return nil default: - if file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777); err == nil { - l.File = file - return nil + info, err := os.Stat(filePath) + if os.IsNotExist(err) { + parent := path.Dir(filePath) + err = syscall.Access(parent, 0x2 /* W_OK */) + if err != nil { + return fmt.Errorf("cannot create %s in %s: %w", path.Base(filePath), parent, err) + } } else { - return fmt.Errorf("could not open file for appending: %w", err) + if err != nil { + return err + } + if info.IsDir() { + return fmt.Errorf("%s is a directory", filePath) + } + err = syscall.Access(filePath, 0x2 /* W_OK */) + if err != nil { + return fmt.Errorf("cannot write to %s: %w", filePath, err) + } } + *l = WriteFilePath(filePath) + return nil } } // String implements flag.Value. -func (l *LogFile) String() string { - return l.Name() +func (l *WriteFilePath) String() string { + return string(*l) } // Type implements pflag.Value. -func (l *LogFile) Type() string { +func (l *WriteFilePath) Type() string { return "file-path" } + +func (l WriteFilePath) Open() (io.WriteCloser, error) { + switch l { + case "/dev/stdout": + return os.Stdout, nil + case "/dev/stderr": + return os.Stderr, nil + default: + return os.OpenFile(string(l), os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0x777) + } +} + +func (l WriteFilePath) IsStdfile() bool { + return l == "/dev/stdout" || l == "/dev/stderr" +} + +func (l WriteFilePath) StdFile() *os.File { + switch l { + case "/dev/stdout": + return os.Stdout + case "/dev/stderr": + return os.Stderr + default: + panic(fmt.Sprintf("WriteFilePath.StdFile() called on %s", l)) + } +} + +func (l WriteFilePath) IsJSON() bool { + return path.Ext(string(l)) == ".json" +} diff --git a/cmd/monitor/main.go b/cmd/monitor/main.go index 0e4cfcd..f14a814 100644 --- a/cmd/monitor/main.go +++ b/cmd/monitor/main.go @@ -24,13 +24,13 @@ func main() { func mainWithError() error { loggingConfig := LoggingConfig{ - MetricsFile: LogFile{os.Stdout}, - LogFile: LogFile{os.Stderr}, + MetricsFilePath: WriteFilePath("/dev/stdout"), + LogFilePath: WriteFilePath("/dev/stderr"), } flag.CountVarP(&loggingConfig.Verbose, "verbose", "v", "show more messages (cumulative)") flag.CountVarP(&loggingConfig.Quiet, "quiet", "q", "only show error messages") - flag.VarP(&loggingConfig.MetricsFile, "output", "o", "append metrics to file") - flag.VarP(&loggingConfig.LogFile, "log-file", "l", "append logs to file") + flag.VarP(&loggingConfig.MetricsFilePath, "output", "o", "append metrics to file") + flag.VarP(&loggingConfig.LogFilePath, "log-file", "l", "append logs to file") var catchUp = flag.BoolP("catch-up", "c", false, "catch up on running containers") var period = flag.DurationP("period", "p", time.Minute, "period of time between intermediate metrics; 0 to disable") @@ -40,10 +40,19 @@ func mainWithError() error { flag.Parse() - slog.SetDefault(loggingConfig.CreateLogLogger()) + if logger, err := loggingConfig.CreateLogLogger(); err == nil { + slog.SetDefault(logger) + } else { + return err + } + + output, err := loggingConfig.CreateMetricsLogger() + if err != nil { + return err + } f := FilteringContainerMonitorFactory{ - MetricsLogger: loggingConfig.CreateMetricsLogger(), + MetricsLogger: output, ContainerFilter: filter.ContainerFilter(), LabelFilter: filter.LabelFilter(), Period: *period, -- GitLab From 1f6e3081ba652abb675947483a407c2e0bb971f5 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sat, 22 Mar 2025 12:54:12 +0100 Subject: [PATCH 06/28] feat: start implementing file rotation --- Taskfile.yml | 11 +- cmd/monitor/logging.go | 167 ----------------- cmd/monitor/main.go | 11 +- go.mod | 3 + go.sum | 12 ++ lib/logging/logging.go | 359 ++++++++++++++++++++++++++++++++++++ lib/logging/logging_test.go | 183 ++++++++++++++++++ 7 files changed, 574 insertions(+), 172 deletions(-) delete mode 100644 cmd/monitor/logging.go create mode 100644 lib/logging/logging.go create mode 100644 lib/logging/logging_test.go diff --git a/Taskfile.yml b/Taskfile.yml index 842c188..d9edbec 100644 --- a/Taskfile.yml +++ b/Taskfile.yml @@ -22,8 +22,17 @@ tasks: test: deps: [deps] + sources: + - lib/**/* + cmds: + - go test {{.CLI_ARGS}} ./lib/... + + test-lib: + deps: [deps] + sources: + - lib/{{ .CLI_ARGS }}/**/* cmds: - - go test {{.CLI_ARGS}} ./cmd/... ./lib/... + - go test -v ./lib/{{ .CLI_ARGS }}/... run: deps: [deps] diff --git a/cmd/monitor/logging.go b/cmd/monitor/logging.go deleted file mode 100644 index 0b1c22b..0000000 --- a/cmd/monitor/logging.go +++ /dev/null @@ -1,167 +0,0 @@ -package main - -import ( - "fmt" - "io" - "log/slog" - "os" - "path" - "syscall" - "time" - - "github.com/lmittmann/tint" - "github.com/mattn/go-isatty" - multi "github.com/samber/slog-multi" - "github.com/spf13/pflag" -) - -// ============================== LoggingConfig ============================== - -type LoggingConfig struct { - Verbose int - Quiet int - MetricsFilePath WriteFilePath - LogFilePath WriteFilePath -} - -func (l LoggingConfig) CreateMetricsLogger() (*slog.Logger, error) { - writer, err := l.MetricsFilePath.Open() - if err != nil { - return nil, fmt.Errorf("could not open output for appending: %w", err) - } - return slog.New(slog.NewJSONHandler(writer, nil)), nil -} - -func (l LoggingConfig) CreateLogLogger() (*slog.Logger, error) { - if handler, err := l.createLogHandler(); err == nil { - return slog.New(handler), nil - } else { - return nil, err - } -} - -func (l LoggingConfig) createLogHandler() (slog.Handler, error) { - if l.LogFilePath.IsStdfile() { - return l.createConsoleHandler(l.LogFilePath.StdFile()), nil - } - - writer, err := l.LogFilePath.Open() - if err != nil { - return nil, fmt.Errorf("could not open log file for appending: %w", err) - } - - var fileHandler slog.Handler - opts := slog.HandlerOptions{Level: l.logLevel(), AddSource: l.addSource()} - if l.LogFilePath.IsJSON() { - fileHandler = slog.NewJSONHandler(writer, &opts) - } else { - fileHandler = slog.NewTextHandler(writer, &opts) - } - return multi.Failover()(fileHandler, l.createConsoleHandler(os.Stderr)), nil -} - -func (l LoggingConfig) logLevel() slog.Leveler { - verbosity := l.Verbose - l.Quiet - if verbosity < 0 { - return slog.LevelError - - } else if verbosity == 1 { - return slog.LevelInfo - } else if verbosity > 1 { - return slog.LevelDebug - } - return slog.LevelWarn -} - -func (l LoggingConfig) addSource() bool { - return l.Verbose-l.Quiet > 2 -} - -func (l LoggingConfig) createConsoleHandler(console *os.File) slog.Handler { - return tint.NewHandler(console, &tint.Options{ - TimeFormat: time.DateTime, - Level: l.logLevel(), - AddSource: l.addSource(), - NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(console.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), - }) -} - -// ============================== LogFile ============================== - -type WriteFilePath string - -var _ pflag.Value = (*WriteFilePath)(nil) - -// Set implements flag.Value. -func (l *WriteFilePath) Set(filePath string) error { - switch filePath { - case "", "-", "/dev/stdout", "/dev/fd/1": - *l = "/dev/stdout" - return nil - case "/dev/stderr", "/dev/fd/2": - *l = "/dev/stderr" - return nil - default: - info, err := os.Stat(filePath) - if os.IsNotExist(err) { - parent := path.Dir(filePath) - err = syscall.Access(parent, 0x2 /* W_OK */) - if err != nil { - return fmt.Errorf("cannot create %s in %s: %w", path.Base(filePath), parent, err) - } - } else { - if err != nil { - return err - } - if info.IsDir() { - return fmt.Errorf("%s is a directory", filePath) - } - err = syscall.Access(filePath, 0x2 /* W_OK */) - if err != nil { - return fmt.Errorf("cannot write to %s: %w", filePath, err) - } - } - *l = WriteFilePath(filePath) - return nil - } -} - -// String implements flag.Value. -func (l *WriteFilePath) String() string { - return string(*l) -} - -// Type implements pflag.Value. -func (l *WriteFilePath) Type() string { - return "file-path" -} - -func (l WriteFilePath) Open() (io.WriteCloser, error) { - switch l { - case "/dev/stdout": - return os.Stdout, nil - case "/dev/stderr": - return os.Stderr, nil - default: - return os.OpenFile(string(l), os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0x777) - } -} - -func (l WriteFilePath) IsStdfile() bool { - return l == "/dev/stdout" || l == "/dev/stderr" -} - -func (l WriteFilePath) StdFile() *os.File { - switch l { - case "/dev/stdout": - return os.Stdout - case "/dev/stderr": - return os.Stderr - default: - panic(fmt.Sprintf("WriteFilePath.StdFile() called on %s", l)) - } -} - -func (l WriteFilePath) IsJSON() bool { - return path.Ext(string(l)) == ".json" -} diff --git a/cmd/monitor/main.go b/cmd/monitor/main.go index f14a814..8527061 100644 --- a/cmd/monitor/main.go +++ b/cmd/monitor/main.go @@ -11,6 +11,7 @@ import ( "github.com/docker/docker/api/types/container" flag "github.com/spf13/pflag" + "gitlab.com/adirelle/docker-stats/lib/logging" ) const MIN_DOCKER_API_VERSION = "v1.44" @@ -23,14 +24,16 @@ func main() { } func mainWithError() error { - loggingConfig := LoggingConfig{ - MetricsFilePath: WriteFilePath("/dev/stdout"), - LogFilePath: WriteFilePath("/dev/stderr"), - } + loggingConfig := logging.DefaultConfig() flag.CountVarP(&loggingConfig.Verbose, "verbose", "v", "show more messages (cumulative)") flag.CountVarP(&loggingConfig.Quiet, "quiet", "q", "only show error messages") flag.VarP(&loggingConfig.MetricsFilePath, "output", "o", "append metrics to file") flag.VarP(&loggingConfig.LogFilePath, "log-file", "l", "append logs to file") + flag.VarP(&loggingConfig.Rotation.Period, "rotate-time", "r", "rotate files at the given time interval") + flag.Var(&loggingConfig.Rotation.Size, "rotate-max-size", "rotate files bigger that the given size") + flag.Var(&loggingConfig.Rotation.MaxAge, "rotate-max-age", "delete rotated files older than the given age") + flag.UintVar(&loggingConfig.Rotation.MaxCount, "rotate-keep", 0, "delete rotateds files when their number exceeds the given count") + flag.BoolVar(&loggingConfig.Rotation.Compress, "rotate-compress", false, "compress files after rotation") var catchUp = flag.BoolP("catch-up", "c", false, "catch up on running containers") var period = flag.DurationP("period", "p", time.Minute, "period of time between intermediate metrics; 0 to disable") diff --git a/go.mod b/go.mod index 3e995f0..0438db0 100644 --- a/go.mod +++ b/go.mod @@ -4,13 +4,16 @@ go 1.24.0 require ( github.com/docker/docker v28.0.1+incompatible + github.com/gookit/slog v0.5.8 github.com/lmittmann/tint v1.0.7 github.com/mattn/go-isatty v0.0.20 github.com/stretchr/testify v1.10.0 ) require ( + github.com/gookit/goutil v0.6.18 // indirect github.com/samber/lo v1.49.1 // indirect + golang.org/x/sync v0.11.0 // indirect golang.org/x/text v0.22.0 // indirect ) diff --git a/go.sum b/go.sum index 79048f8..41e2b32 100644 --- a/go.sum +++ b/go.sum @@ -29,6 +29,12 @@ github.com/google/go-cmp v0.7.0 h1:wk8382ETsv4JYUZwIsn6YpYiWiBsYLSJiTsyBybVuN8= github.com/google/go-cmp v0.7.0/go.mod h1:pXiqmnSA92OHEEa9HXL2W4E7lf9JzCmGVUdgjX3N/iU= github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +github.com/gookit/color v1.5.4 h1:FZmqs7XOyGgCAxmWyPslpiok1k05wmY3SJTytgvYFs0= +github.com/gookit/color v1.5.4/go.mod h1:pZJOeOS8DM43rXbp4AZo1n9zCU2qjpcRko0b6/QJi9w= +github.com/gookit/goutil v0.6.18 h1:MUVj0G16flubWT8zYVicIuisUiHdgirPAkmnfD2kKgw= +github.com/gookit/goutil v0.6.18/go.mod h1:AY/5sAwKe7Xck+mEbuxj0n/bc3qwrGNe3Oeulln7zBA= +github.com/gookit/slog v0.5.8 h1:XZCeHLQvvOZWcSUDZcqxXITsL9+d1ESsKZoASBmK1lI= +github.com/gookit/slog v0.5.8/go.mod h1:s0ViFOY/IgUuT4MDPF0l9x5/npcciy8pL4xwWZadnoc= github.com/grpc-ecosystem/grpc-gateway/v2 v2.26.1 h1:e9Rjr40Z98/clHv5Yg79Is0NtosR5LXRvdr7o/6NwbA= github.com/grpc-ecosystem/grpc-gateway/v2 v2.26.1/go.mod h1:tIxuGz/9mpox++sgp9fJjHO0+q1X9/UOWd798aAm22M= github.com/kisielk/errcheck v1.5.0/go.mod h1:pFxgyoBC7bSaBwPgfKdkLd5X25qrDl4LWUI2bnpBCr8= @@ -67,6 +73,8 @@ github.com/spf13/pflag v1.0.6 h1:jFzHGLGAlb3ruxLB8MhbI6A8+AQX/2eW4qeyNZXNp2o= github.com/spf13/pflag v1.0.6/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= github.com/stretchr/testify v1.10.0 h1:Xv5erBjTwe/5IxqUQTdXv5kgmIvbHo3QQyRwhJsOfJA= github.com/stretchr/testify v1.10.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= +github.com/xo/terminfo v0.0.0-20220910002029-abceb7e1c41e h1:JVG44RsyaB9T2KIHavMF/ppJZNG9ZpyihvCd0w101no= +github.com/xo/terminfo v0.0.0-20220910002029-abceb7e1c41e/go.mod h1:RbqR21r5mrJuqunuUZ/Dhy/avygyECGrLceyNeo4LiM= github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= go.opentelemetry.io/auto/sdk v1.1.0 h1:cH53jehLUN6UFLY71z+NDOiNJqDdPRaXzTel0sJySYA= @@ -103,12 +111,16 @@ golang.org/x/net v0.35.0/go.mod h1:EglIi67kWsHKlRzzVMUD93VMSWGFOMSZgxFjparz1Qk= golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.11.0 h1:GGz8+XQP4FvTTrjZPzNKTMFtSXH80RAzG+5ghFPgK9w= +golang.org/x/sync v0.11.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.31.0 h1:ioabZlmFYtWhL+TRYpcnNlLwhyxaM9kWTDEmfnprqik= golang.org/x/sys v0.31.0/go.mod h1:BJP2sWEmIv4KK5OTEluFJCKSidICx8ciO85XgH3Ak8k= +golang.org/x/term v0.29.0 h1:L6pJp37ocefwRRtYPKSWOWzOtWSxVajvz2ldH/xi3iU= +golang.org/x/term v0.29.0/go.mod h1:6bl4lRlvVuDgSf3179VpIxBF0o10JUpXWOnI7nErv7s= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/text v0.22.0 h1:bofq7m3/HAFvbF51jz3Q9wLg3jkvSPuiZu/pD1XwgtM= diff --git a/lib/logging/logging.go b/lib/logging/logging.go new file mode 100644 index 0000000..e01d154 --- /dev/null +++ b/lib/logging/logging.go @@ -0,0 +1,359 @@ +package logging + +import ( + "fmt" + "io" + "log/slog" + "math" + "os" + "path" + "strconv" + "strings" + "syscall" + "time" + + "github.com/gookit/slog/rotatefile" + "github.com/lmittmann/tint" + "github.com/mattn/go-isatty" + multi "github.com/samber/slog-multi" + "github.com/spf13/pflag" +) + +// ============================== Config ============================== + +type Config struct { + Verbose int + Quiet int + MetricsFilePath WriteFilePath + LogFilePath WriteFilePath + Rotation RotationConfig +} + +type RotationConfig struct { + Period Period + Size FileSize + MaxAge Age + MaxCount uint + Compress bool +} + +func DefaultConfig() Config { + return Config{ + MetricsFilePath: WriteFilePath("/dev/stdout"), + LogFilePath: WriteFilePath("/dev/stderr"), + } +} + +func (l Config) CreateMetricsLogger() (*slog.Logger, error) { + writer, err := l.MetricsFilePath.Open() + if err != nil { + return nil, fmt.Errorf("could not open output for appending: %w", err) + } + return slog.New(slog.NewJSONHandler(writer, nil)), nil +} + +func (l Config) CreateLogLogger() (*slog.Logger, error) { + if handler, err := l.createLogHandler(); err == nil { + return slog.New(handler), nil + } else { + return nil, err + } +} + +func (l Config) createLogHandler() (slog.Handler, error) { + if l.LogFilePath.IsStdfile() { + return l.createConsoleHandler(l.LogFilePath.StdFile()), nil + } + + writer, err := l.LogFilePath.Open() + if err != nil { + return nil, fmt.Errorf("could not open log file for appending: %w", err) + } + + var fileHandler slog.Handler + opts := slog.HandlerOptions{Level: l.logLevel(), AddSource: l.addSource()} + if l.LogFilePath.IsJSON() { + fileHandler = slog.NewJSONHandler(writer, &opts) + } else { + fileHandler = slog.NewTextHandler(writer, &opts) + } + return multi.Failover()(fileHandler, l.createConsoleHandler(os.Stderr)), nil +} + +func (l Config) logLevel() slog.Leveler { + verbosity := l.Verbose - l.Quiet + if verbosity < 0 { + return slog.LevelError + + } else if verbosity == 1 { + return slog.LevelInfo + } else if verbosity > 1 { + return slog.LevelDebug + } + return slog.LevelWarn +} + +func (l Config) addSource() bool { + return l.Verbose-l.Quiet > 2 +} + +func (l Config) createConsoleHandler(console *os.File) slog.Handler { + return tint.NewHandler(console, &tint.Options{ + TimeFormat: time.DateTime, + Level: l.logLevel(), + AddSource: l.addSource(), + NoColor: len(os.Getenv("NO_COLOR")) > 0 || (!isatty.IsTerminal(console.Fd()) && len(os.Getenv("FORCE_COLOR")) == 0), + }) +} + +// ============================== LogFile ============================== + +type WriteFilePath string + +var _ pflag.Value = (*WriteFilePath)(nil) + +// Set implements flag.Value. +func (l *WriteFilePath) Set(filePath string) error { + switch filePath { + case "", "-", "/dev/stdout", "/dev/fd/1": + *l = "/dev/stdout" + return nil + case "/dev/stderr", "/dev/fd/2": + *l = "/dev/stderr" + return nil + default: + info, err := os.Stat(filePath) + if os.IsNotExist(err) { + parent := path.Dir(filePath) + err = syscall.Access(parent, 0x2 /* W_OK */) + if err != nil { + return fmt.Errorf("cannot create %s in %s: %w", path.Base(filePath), parent, err) + } + } else { + if err != nil { + return err + } + if info.IsDir() { + return fmt.Errorf("%s is a directory", filePath) + } + err = syscall.Access(filePath, 0x2 /* W_OK */) + if err != nil { + return fmt.Errorf("cannot write to %s: %w", filePath, err) + } + } + *l = WriteFilePath(filePath) + return nil + } +} + +// String implements flag.Value. +func (l *WriteFilePath) String() string { + return string(*l) +} + +// Type implements pflag.Value. +func (l *WriteFilePath) Type() string { + return "file-path" +} + +func (l WriteFilePath) Open() (io.WriteCloser, error) { + switch l { + case "/dev/stdout": + return os.Stdout, nil + case "/dev/stderr": + return os.Stderr, nil + default: + return os.OpenFile(string(l), os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0x777) + } +} + +func (l WriteFilePath) IsStdfile() bool { + return l == "/dev/stdout" || l == "/dev/stderr" +} + +func (l WriteFilePath) StdFile() *os.File { + switch l { + case "/dev/stdout": + return os.Stdout + case "/dev/stderr": + return os.Stderr + default: + panic(fmt.Sprintf("WriteFilePath.StdFile() called on %s", l)) + } +} + +func (l WriteFilePath) IsJSON() bool { + return path.Ext(string(l)) == ".json" +} + +// ============================== Period ============================== + +type Period string + +var _ pflag.Value = (*Period)(nil) + +const ( + PERIOD_HOURLY Period = "hourly" + PERIOD_DAILY Period = "daily" + PERIOD_WEEKLY Period = "weekly" + PERIOD_MONTHLY Period = "monthly" +) + +// Set implements pflag.Value. +func (p *Period) Set(value string) error { + switch value { + case string(PERIOD_HOURLY), "h": + *p = PERIOD_HOURLY + case string(PERIOD_DAILY), "d": + *p = PERIOD_DAILY + case string(PERIOD_WEEKLY), "w": + *p = PERIOD_WEEKLY + case string(PERIOD_MONTHLY), "m": + *p = PERIOD_MONTHLY + default: + return fmt.Errorf("invalid period: %v", value) + } + return nil +} + +// String implements pflag.Value. +func (p *Period) String() string { + return string(*p) +} + +// Type implements pflag.Value. +func (p *Period) Type() string { + return "period" +} + +func (p Period) RotateTime() rotatefile.RotateTime { + switch p { + case PERIOD_HOURLY: + return rotatefile.EveryHour + case PERIOD_DAILY, "": + return rotatefile.EveryDay + case PERIOD_WEEKLY: + return rotatefile.EveryDay * 7 + case PERIOD_MONTHLY: + return rotatefile.EveryMonth + default: + panic(fmt.Sprintf("unknown period: %v", string(p))) + } +} + +// ============================== Period ============================== + +type FileSize uint64 + +var _ pflag.Value = (*FileSize)(nil) + +var revSizeSuffixes = []string{"G", "M", "K"} + +// Set implements pflag.Value. +func (f *FileSize) Set(size string) error { + size = strings.ToUpper(size) + var err error + for i, suffix := range revSizeSuffixes { + if prefix, hasSuffix := stripSuffix(size, suffix); hasSuffix { + if value, err := strconv.ParseUint(prefix, 10, 64); err == nil { + *f = FileSize(value << (10 * (len(revSizeSuffixes) - i))) + return nil + } else { + return err + } + } + } + value, err := strconv.ParseUint(size, 10, 64) + if err != nil { + return err + } + *f = FileSize(value) + return nil +} + +func stripSuffix(s, suffix string) (string, bool) { + if strings.HasSuffix(s, suffix) { + return s[:len(s)-len(suffix)], true + } + return s, false +} + +var sizeSuffixes = []string{"", "K", "M"} + +// String implements pflag.Value. +func (f *FileSize) String() string { + value := uint64(*f) + if value == 0 { + return "0" + } + for _, suffix := range sizeSuffixes { + if value&0x2ff != 0 { + return fmt.Sprintf("%d%s", value, suffix) + } + value >>= 10 + } + return fmt.Sprintf("%dG", value) +} + +// Type implements pflag.Value. +func (f *FileSize) Type() string { + return "size" +} + +// ============================== Age ============================== + +type Age uint64 + +var _ pflag.Value = (*Age)(nil) + +var ageUnits = []struct { + suffix string + value uint64 +}{ + {"week", 7 * 86400}, + {"w", 7 * 86400}, + {"weeks", 7 * 86400}, + {"day", 86400}, + {"d", 86400}, + {"days", 86400}, + {"hour", 3600}, + {"h", 3600}, + {"hours", 3600}, + {"", 3600}, +} + +// Set implements pflag.Value. +func (a *Age) Set(age string) error { + for _, unit := range ageUnits { + if strings.HasSuffix(age, unit.suffix) { + value, err := strconv.ParseUint(strings.Trim(age[:len(age)-len(unit.suffix)], " "), 10, 64) + *a = Age(value * unit.value) + return err + } + } + panic("unreachable") +} + +// String implements pflag.Value. +func (a *Age) String() string { + value := uint64(*a) + if value == 0 { + return "0" + } + for _, unit := range ageUnits { + if value >= unit.value && math.Mod(float64(value), float64(unit.value)) == 0 { + value /= unit.value + if value != 1 { + return fmt.Sprintf("%d %ss", value, unit.suffix) + } else { + return fmt.Sprintf("%d %s", value, unit.suffix) + } + } + } + panic("unreachable") +} + +// Type implements pflag.Value. +func (a *Age) Type() string { + return "age" +} diff --git a/lib/logging/logging_test.go b/lib/logging/logging_test.go new file mode 100644 index 0000000..259f5bd --- /dev/null +++ b/lib/logging/logging_test.go @@ -0,0 +1,183 @@ +package logging_test + +import ( + "testing" + + "github.com/stretchr/testify/assert" + "gitlab.com/adirelle/docker-stats/lib/logging" +) + +func TestPeriodSet(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := map[string]logging.Period{ + "hourly": logging.PERIOD_HOURLY, + "h": logging.PERIOD_HOURLY, + "daily": logging.PERIOD_DAILY, + "d": logging.PERIOD_DAILY, + "weekly": logging.PERIOD_WEEKLY, + "w": logging.PERIOD_WEEKLY, + "monthly": logging.PERIOD_MONTHLY, + "m": logging.PERIOD_MONTHLY, + } + + for input, expected := range testCases { + t.Run(input, func(t *testing.T) { + var actual logging.Period + assert.NoError(t, actual.Set(input)) + assert.Equal(t, expected, actual) + }) + } +} + +func TestPeriodSetInvalid(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := []string{ + "hourl", + "foo", + "9d", + } + + for _, input := range testCases { + t.Run(input, func(t *testing.T) { + var actual logging.Period + assert.Error(t, actual.Set(input)) + }) + } +} + +func TestPeriodString(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := map[logging.Period]string{ + logging.PERIOD_HOURLY: "hourly", + logging.PERIOD_DAILY: "daily", + logging.PERIOD_WEEKLY: "weekly", + logging.PERIOD_MONTHLY: "monthly", + } + + for input, expected := range testCases { + t.Run(expected, func(t *testing.T) { + assert.Equal(t, expected, input.String()) + }) + } +} + +func TestFileSizeSet(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := map[string]logging.FileSize{ + "0": 0, + "15": 15, + "0K": 0, + "15K": 15360, + "15k": 15360, + "15M": 15728640, + "15m": 15728640, + "15G": 16106127360, + "15g": 16106127360, + } + + for input, expected := range testCases { + t.Run(input, func(t *testing.T) { + var actual logging.FileSize + assert.NoError(t, actual.Set(input)) + assert.Equal(t, expected, actual) + }) + } +} + +func TestFileSizeSetInvalid(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := []string{"15o", "15.0k", "pof"} + + for _, input := range testCases { + t.Run(input, func(t *testing.T) { + var size logging.FileSize + assert.Error(t, size.Set(input)) + }) + } +} + +func TestFileSizeString(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := map[logging.FileSize]string{ + 0: "0", + 1: "1", + 15: "15", + 1039: "1039", + 1024: "1K", + 15360: "15K", + 1063936: "1039K", + 1048576: "1M", + 15728640: "15M", + 1073741824: "1G", + 16106127360: "15G", + 16492674416640: "15360G", + } + + for input, expected := range testCases { + t.Run(expected, func(t *testing.T) { + assert.Equal(t, expected, input.String()) + }) + } +} + +func TestAgeSet(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := map[string]logging.Age{ + "0": 0, + "1": 3600, + "1h": 3600, + "1 hour": 3600, + "1hour": 3600, + "2 hours": 7200, + "1d": 86400, + "1 day": 86400, + "2 days": 2 * 86400, + "1w": 7 * 86400, + "1week": 7 * 86400, + "4 weeks": 28 * 86400, + } + + for input, expected := range testCases { + t.Run(input, func(t *testing.T) { + var actual logging.Age + assert.NoError(t, actual.Set(input)) + assert.Equal(t, expected, actual) + }) + } +} + +func TestAgeString(t *testing.T) { + t.Parallel() + t.Helper() + + testCases := map[logging.Age]string{ + 0: "0", + 3600: "1 hour", + 7200: "2 hours", + 27 * 3600: "27 hours", + 86400: "1 day", + 7 * 86400: "1 week", + 14 * 86400: "2 weeks", + 15 * 86400: "15 days", + } + + for input, expected := range testCases { + t.Run(expected, func(t *testing.T) { + assert.Equal(t, expected, input.String()) + }) + } +} -- GitLab From e6951d66478f1847d171ad2bd70afac04a16a903 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sun, 23 Mar 2025 10:14:25 +0100 Subject: [PATCH 07/28] feat: use rotatefile --- go.mod | 2 - go.sum | 4 - lib/logging/logging.go | 227 +++--------------- lib/logging/units.go | 212 ++++++++++++++++ .../{logging_test.go => units_test.go} | 1 + 5 files changed, 252 insertions(+), 194 deletions(-) create mode 100644 lib/logging/units.go rename lib/logging/{logging_test.go => units_test.go} (99%) diff --git a/go.mod b/go.mod index 0438db0..4bcd919 100644 --- a/go.mod +++ b/go.mod @@ -12,7 +12,6 @@ require ( require ( github.com/gookit/goutil v0.6.18 // indirect - github.com/samber/lo v1.49.1 // indirect golang.org/x/sync v0.11.0 // indirect golang.org/x/text v0.22.0 // indirect ) @@ -35,7 +34,6 @@ require ( github.com/opencontainers/image-spec v1.1.1 // indirect github.com/pkg/errors v0.9.1 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect - github.com/samber/slog-multi v1.4.0 github.com/spf13/pflag v1.0.6 go.opentelemetry.io/auto/sdk v1.1.0 // indirect go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.60.0 // indirect diff --git a/go.sum b/go.sum index 41e2b32..2620d2e 100644 --- a/go.sum +++ b/go.sum @@ -63,10 +63,6 @@ github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZb github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/rogpeppe/go-internal v1.13.1 h1:KvO1DLK/DRN07sQ1LQKScxyZJuNnedQ5/wKSR38lUII= github.com/rogpeppe/go-internal v1.13.1/go.mod h1:uMEvuHeurkdAXX61udpOXGD/AzZDWNMNyH2VO9fmH0o= -github.com/samber/lo v1.49.1 h1:4BIFyVfuQSEpluc7Fua+j1NolZHiEHEpaSEKdsH0tew= -github.com/samber/lo v1.49.1/go.mod h1:dO6KHFzUKXgP8LDhU0oI8d2hekjXnGOu0DB8Jecxd6o= -github.com/samber/slog-multi v1.4.0 h1:pwlPMIE7PrbTHQyKWDU+RIoxP1+HKTNOujk3/kdkbdg= -github.com/samber/slog-multi v1.4.0/go.mod h1:FsQ4Uv2L+E/8TZt+/BVgYZ1LoDWCbfCU21wVIoMMrO8= github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/spf13/pflag v1.0.6 h1:jFzHGLGAlb3ruxLB8MhbI6A8+AQX/2eW4qeyNZXNp2o= diff --git a/lib/logging/logging.go b/lib/logging/logging.go index e01d154..df503ee 100644 --- a/lib/logging/logging.go +++ b/lib/logging/logging.go @@ -4,18 +4,14 @@ import ( "fmt" "io" "log/slog" - "math" "os" "path" - "strconv" - "strings" "syscall" "time" "github.com/gookit/slog/rotatefile" "github.com/lmittmann/tint" "github.com/mattn/go-isatty" - multi "github.com/samber/slog-multi" "github.com/spf13/pflag" ) @@ -29,14 +25,6 @@ type Config struct { Rotation RotationConfig } -type RotationConfig struct { - Period Period - Size FileSize - MaxAge Age - MaxCount uint - Compress bool -} - func DefaultConfig() Config { return Config{ MetricsFilePath: WriteFilePath("/dev/stdout"), @@ -45,9 +33,15 @@ func DefaultConfig() Config { } func (l Config) CreateMetricsLogger() (*slog.Logger, error) { - writer, err := l.MetricsFilePath.Open() - if err != nil { - return nil, fmt.Errorf("could not open output for appending: %w", err) + var err error + var writer io.Writer + if l.MetricsFilePath.IsStdfile() { + writer = l.MetricsFilePath.StdFile() + } else { + writer, err = l.Rotation.Open(l.MetricsFilePath.Path()) + if err != nil { + return nil, fmt.Errorf("could not open output for appending: %w", err) + } } return slog.New(slog.NewJSONHandler(writer, nil)), nil } @@ -65,7 +59,7 @@ func (l Config) createLogHandler() (slog.Handler, error) { return l.createConsoleHandler(l.LogFilePath.StdFile()), nil } - writer, err := l.LogFilePath.Open() + writer, err := l.Rotation.Open(l.LogFilePath.Path()) if err != nil { return nil, fmt.Errorf("could not open log file for appending: %w", err) } @@ -77,7 +71,8 @@ func (l Config) createLogHandler() (slog.Handler, error) { } else { fileHandler = slog.NewTextHandler(writer, &opts) } - return multi.Failover()(fileHandler, l.createConsoleHandler(os.Stderr)), nil + return fileHandler, nil + // return multi.Failover()(fileHandler, l.createConsoleHandler(os.Stderr)), nil } func (l Config) logLevel() slog.Leveler { @@ -106,7 +101,7 @@ func (l Config) createConsoleHandler(console *os.File) slog.Handler { }) } -// ============================== LogFile ============================== +// ============================== WriteFilePath ============================== type WriteFilePath string @@ -156,15 +151,8 @@ func (l *WriteFilePath) Type() string { return "file-path" } -func (l WriteFilePath) Open() (io.WriteCloser, error) { - switch l { - case "/dev/stdout": - return os.Stdout, nil - case "/dev/stderr": - return os.Stderr, nil - default: - return os.OpenFile(string(l), os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0x777) - } +func (l WriteFilePath) Path() string { + return string(l) } func (l WriteFilePath) IsStdfile() bool { @@ -186,174 +174,37 @@ func (l WriteFilePath) IsJSON() bool { return path.Ext(string(l)) == ".json" } -// ============================== Period ============================== - -type Period string - -var _ pflag.Value = (*Period)(nil) - -const ( - PERIOD_HOURLY Period = "hourly" - PERIOD_DAILY Period = "daily" - PERIOD_WEEKLY Period = "weekly" - PERIOD_MONTHLY Period = "monthly" -) - -// Set implements pflag.Value. -func (p *Period) Set(value string) error { - switch value { - case string(PERIOD_HOURLY), "h": - *p = PERIOD_HOURLY - case string(PERIOD_DAILY), "d": - *p = PERIOD_DAILY - case string(PERIOD_WEEKLY), "w": - *p = PERIOD_WEEKLY - case string(PERIOD_MONTHLY), "m": - *p = PERIOD_MONTHLY - default: - return fmt.Errorf("invalid period: %v", value) - } - return nil -} - -// String implements pflag.Value. -func (p *Period) String() string { - return string(*p) -} - -// Type implements pflag.Value. -func (p *Period) Type() string { - return "period" -} - -func (p Period) RotateTime() rotatefile.RotateTime { - switch p { - case PERIOD_HOURLY: - return rotatefile.EveryHour - case PERIOD_DAILY, "": - return rotatefile.EveryDay - case PERIOD_WEEKLY: - return rotatefile.EveryDay * 7 - case PERIOD_MONTHLY: - return rotatefile.EveryMonth - default: - panic(fmt.Sprintf("unknown period: %v", string(p))) - } -} - -// ============================== Period ============================== - -type FileSize uint64 - -var _ pflag.Value = (*FileSize)(nil) +// ============================== RotationConfig ============================== -var revSizeSuffixes = []string{"G", "M", "K"} - -// Set implements pflag.Value. -func (f *FileSize) Set(size string) error { - size = strings.ToUpper(size) - var err error - for i, suffix := range revSizeSuffixes { - if prefix, hasSuffix := stripSuffix(size, suffix); hasSuffix { - if value, err := strconv.ParseUint(prefix, 10, 64); err == nil { - *f = FileSize(value << (10 * (len(revSizeSuffixes) - i))) - return nil - } else { - return err - } - } - } - value, err := strconv.ParseUint(size, 10, 64) - if err != nil { - return err - } - *f = FileSize(value) - return nil -} - -func stripSuffix(s, suffix string) (string, bool) { - if strings.HasSuffix(s, suffix) { - return s[:len(s)-len(suffix)], true - } - return s, false -} - -var sizeSuffixes = []string{"", "K", "M"} - -// String implements pflag.Value. -func (f *FileSize) String() string { - value := uint64(*f) - if value == 0 { - return "0" - } - for _, suffix := range sizeSuffixes { - if value&0x2ff != 0 { - return fmt.Sprintf("%d%s", value, suffix) - } - value >>= 10 - } - return fmt.Sprintf("%dG", value) -} - -// Type implements pflag.Value. -func (f *FileSize) Type() string { - return "size" +type RotationConfig struct { + Period Period + Size FileSize + MaxAge Age + MaxCount uint + Compress bool } -// ============================== Age ============================== - -type Age uint64 - -var _ pflag.Value = (*Age)(nil) - -var ageUnits = []struct { - suffix string - value uint64 -}{ - {"week", 7 * 86400}, - {"w", 7 * 86400}, - {"weeks", 7 * 86400}, - {"day", 86400}, - {"d", 86400}, - {"days", 86400}, - {"hour", 3600}, - {"h", 3600}, - {"hours", 3600}, - {"", 3600}, +func (c *RotationConfig) IsEnabled() bool { + return !(c.Period.IsNever() && c.Size.IsInfinite()) } -// Set implements pflag.Value. -func (a *Age) Set(age string) error { - for _, unit := range ageUnits { - if strings.HasSuffix(age, unit.suffix) { - value, err := strconv.ParseUint(strings.Trim(age[:len(age)-len(unit.suffix)], " "), 10, 64) - *a = Age(value * unit.value) - return err - } +func (c *RotationConfig) Open(path string) (io.Writer, error) { + if !c.IsEnabled() { + return os.OpenFile(path, os.O_APPEND|os.O_WRONLY|os.O_CREATE, rotatefile.DefaultFilePerm) } - panic("unreachable") -} -// String implements pflag.Value. -func (a *Age) String() string { - value := uint64(*a) - if value == 0 { - return "0" + cf := rotatefile.EmptyConfigWith() + cf.Filepath = path + if !c.Period.IsNever() { + cf.RotateTime = c.Period.RotateTime() } - for _, unit := range ageUnits { - if value >= unit.value && math.Mod(float64(value), float64(unit.value)) == 0 { - value /= unit.value - if value != 1 { - return fmt.Sprintf("%d %ss", value, unit.suffix) - } else { - return fmt.Sprintf("%d %s", value, unit.suffix) - } - } - } - panic("unreachable") -} + cf.DebugMode = c.Period.IsDebug() + cf.MaxSize = c.Size.Bytes() + // cf.Compress = c.Compress + cf.BackupTime = c.MaxAge.Hours() + cf.BackupNum = c.MaxCount + // cf.CloseLock = true + fmt.Printf("rotation config: %#v\n\n", cf) -// Type implements pflag.Value. -func (a *Age) Type() string { - return "age" + return rotatefile.NewWriter(cf) } diff --git a/lib/logging/units.go b/lib/logging/units.go new file mode 100644 index 0000000..ae0cdd1 --- /dev/null +++ b/lib/logging/units.go @@ -0,0 +1,212 @@ +package logging + +import ( + "fmt" + "math" + "strconv" + "strings" + + "github.com/gookit/slog/rotatefile" + "github.com/spf13/pflag" +) + +// ============================== Period ============================== + +type Period string + +var _ pflag.Value = (*Period)(nil) + +const ( + PERIOD_HOURLY Period = "hourly" + PERIOD_DAILY Period = "daily" + PERIOD_WEEKLY Period = "weekly" + PERIOD_MONTHLY Period = "monthly" + PERIOD_DEBUG Period = "debug" +) + +// Set implements pflag.Value. +func (p *Period) Set(value string) error { + switch value { + case string(PERIOD_HOURLY), "h": + *p = PERIOD_HOURLY + case string(PERIOD_DAILY), "d": + *p = PERIOD_DAILY + case string(PERIOD_WEEKLY), "w": + *p = PERIOD_WEEKLY + case string(PERIOD_MONTHLY), "m": + *p = PERIOD_DEBUG + case string(PERIOD_DEBUG): + *p = PERIOD_DEBUG + default: + return fmt.Errorf("invalid period: %v", value) + } + return nil +} + +// String implements pflag.Value. +func (p *Period) String() string { + return string(*p) +} + +// Type implements pflag.Value. +func (p *Period) Type() string { + return "period" +} + +func (p Period) IsNever() bool { + return string(p) == "" +} + +func (p Period) IsDebug() bool { + return p == PERIOD_DEBUG +} + +func (p Period) RotateTime() rotatefile.RotateTime { + switch p { + case PERIOD_HOURLY: + return rotatefile.EveryHour + case PERIOD_DAILY, "": + return rotatefile.EveryDay + case PERIOD_WEEKLY: + return rotatefile.EveryDay * 7 + case PERIOD_MONTHLY: + return rotatefile.EveryMonth + case PERIOD_DEBUG: + return rotatefile.EverySecond + default: + panic(fmt.Sprintf("unknown period: %v", string(p))) + } +} + +// ============================== FileSize ============================== + +type FileSize uint64 + +var _ pflag.Value = (*FileSize)(nil) + +var revSizeSuffixes = []string{"G", "M", "K"} + +// Set implements pflag.Value. +func (f *FileSize) Set(size string) error { + size = strings.ToUpper(size) + var err error + for i, suffix := range revSizeSuffixes { + if prefix, hasSuffix := stripSuffix(size, suffix); hasSuffix { + if value, err := strconv.ParseUint(prefix, 10, 64); err == nil { + *f = FileSize(value << (10 * (len(revSizeSuffixes) - i))) + return nil + } else { + return err + } + } + } + value, err := strconv.ParseUint(size, 10, 64) + if err != nil { + return err + } + *f = FileSize(value) + return nil +} + +func stripSuffix(s, suffix string) (string, bool) { + if strings.HasSuffix(s, suffix) { + return s[:len(s)-len(suffix)], true + } + return s, false +} + +var sizeSuffixes = []string{"", "K", "M"} + +// String implements pflag.Value. +func (f *FileSize) String() string { + value := uint64(*f) + if value == 0 { + return "0" + } + for _, suffix := range sizeSuffixes { + if value&0x2ff != 0 { + return fmt.Sprintf("%d%s", value, suffix) + } + value >>= 10 + } + return fmt.Sprintf("%dG", value) +} + +// Type implements pflag.Value. +func (f *FileSize) Type() string { + return "size" +} + +func (f FileSize) IsInfinite() bool { + return f == 0 +} + +func (f FileSize) Bytes() uint64 { + return uint64(f) +} + +// ============================== Age ============================== + +type Age uint + +var _ pflag.Value = (*Age)(nil) + +var ageUnits = []struct { + suffix string + value uint +}{ + {"week", 7 * 24}, + {"w", 7 * 24}, + {"weeks", 7 * 24}, + {"day", 24}, + {"d", 24}, + {"days", 24}, + {"hour", 1}, + {"h", 1}, + {"hours", 1}, + {"", 1}, +} + +// Set implements pflag.Value. +func (a *Age) Set(age string) error { + for _, unit := range ageUnits { + if strings.HasSuffix(age, unit.suffix) { + value, err := strconv.ParseUint(strings.Trim(age[:len(age)-len(unit.suffix)], " "), 10, 32) + *a = Age(uint(value) * unit.value) + return err + } + } + panic("unreachable") +} + +// String implements pflag.Value. +func (a *Age) String() string { + value := uint(*a) + if value == 0 { + return "0" + } + for _, unit := range ageUnits { + if value >= unit.value && math.Mod(float64(value), float64(unit.value)) == 0 { + value /= unit.value + if value != 1 { + return fmt.Sprintf("%d %ss", value, unit.suffix) + } else { + return fmt.Sprintf("%d %s", value, unit.suffix) + } + } + } + panic("unreachable") +} + +// Type implements pflag.Value. +func (a *Age) Type() string { + return "age" +} + +func (a Age) Hours() uint { + return uint(a) +} + +func (a Age) IsInfinite() bool { + return a == 0 +} diff --git a/lib/logging/logging_test.go b/lib/logging/units_test.go similarity index 99% rename from lib/logging/logging_test.go rename to lib/logging/units_test.go index 259f5bd..8d040f9 100644 --- a/lib/logging/logging_test.go +++ b/lib/logging/units_test.go @@ -20,6 +20,7 @@ func TestPeriodSet(t *testing.T) { "w": logging.PERIOD_WEEKLY, "monthly": logging.PERIOD_MONTHLY, "m": logging.PERIOD_MONTHLY, + "debug": logging.PERIOD_DEBUG, } for input, expected := range testCases { -- GitLab From 10fb7f38e709661d9abead93be3b6182bb4deb79 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Sun, 23 Mar 2025 10:14:51 +0100 Subject: [PATCH 08/28] feat: start writing our own rotating file writer --- lib/logging/writer/writer.go | 205 ++++++++++++++++++++++++++++++ lib/logging/writer/writer_test.go | 69 ++++++++++ 2 files changed, 274 insertions(+) create mode 100644 lib/logging/writer/writer.go create mode 100644 lib/logging/writer/writer_test.go diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go new file mode 100644 index 0000000..10ae028 --- /dev/null +++ b/lib/logging/writer/writer.go @@ -0,0 +1,205 @@ +package writer + +import ( + "fmt" + "io" + "log/slog" + "os" + "path" + "time" + + "github.com/lmittmann/tint" +) + +// ============================== Writer ============================== + +// Writer is an asynchronous io.WriteCloser with rotating capabilities +type Writer struct { + path string + maxSize uint64 + + chunks chan<- string + errs <-chan error + + file *os.File + size uint64 + + log *slog.Logger +} + +var _ io.WriteCloser = (*Writer)(nil) + +func NewWriter(path string, options ...ConfigOption) (*Writer, error) { + chunks := make(chan string, 10) + errs := make(chan error) + + w := &Writer{ + path: path, + chunks: chunks, + errs: errs, + log: slog.New(slog.DiscardHandler), + } + for _, opt := range options { + opt(w) + } + w.log = w.log.With("path", path) + + go w.backgroundWriter(chunks, errs) + + return w, nil +} + +// Write implements io.WriteCloser. +func (w *Writer) Write(p []byte) (n int, err error) { + select { + case err, open := <-w.errs: + if !open { + return 0, io.ErrClosedPipe + } + return 0, err + case w.chunks <- string(p): + return len(p), nil + } +} + +// Close implements io.WriteCloser. +func (w *Writer) Close() error { + select { + case err := <-w.errs: + return err + default: + close(w.chunks) + return <-w.errs + } +} + +func (w *Writer) backgroundWriter(chunks <-chan string, errs chan<- error) { + defer func() { + if err := w.close(); err != nil { + errs <- err + } + close(errs) + }() + + if err := w.innerBackgroundWriter(chunks); err != nil { + errs <- err + } +} + +func (w *Writer) innerBackgroundWriter(chunks <-chan string) error { + var err error + for chunk := range chunks { + if w.file == nil { + if err = w.openFile(); err != nil { + return err + } + } + + if w.shouldRotate(uint64(len(chunk))) { + w.log.Debug("file need rotation") + if err := w.rotate(); err != nil { + return err + } + } + + for written := 0; written < len(chunk); { + n, err := w.file.Write([]byte(chunk)) + if err != nil { + return err + } + written += n + w.size += uint64(n) + } + } + + return nil +} + +func (w *Writer) openFile() error { + var err error + w.file, err = os.OpenFile(w.path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777) + if err != nil { + w.log.Error("could not open file", "err", err) + return err + } + info, err := w.file.Stat() + w.size = uint64(info.Size()) + w.log.Debug("opened file for writing", "size", w.size) + return err +} + +func (w *Writer) close() error { + if w.file == nil { + return nil + } + err := w.file.Close() + if err != nil { + w.log.Error("error closing file", "err", err) + } else { + w.log.Debug("closed file") + } + w.file = nil + return err +} + +func (w *Writer) shouldRotate(toWrite uint64) bool { + return w.maxSize > 0 && w.size > 0 && w.size+toWrite > w.maxSize +} + +func (w *Writer) rotate() error { + if err := w.close(); err != nil { + return err + } + + renameTo, err := w.rotateName() + if err != nil { + return err + } + + w.log.Debug("rotating file", "renameTo", renameTo) + + if err = os.Rename(w.path, renameTo); err != nil { + return err + } + + return w.openFile() +} + +func (w *Writer) rotateName() (string, error) { + ext := path.Ext(w.path) + prefix := w.path[:len(w.path)-len(ext)] + + if w.maxSize > 0 { + for i := 1; true; i++ { + rotated_prefix := fmt.Sprintf("%s.%d", prefix, i) + if _, err := os.Stat(rotated_prefix + ext); os.IsNotExist(err) { + prefix = rotated_prefix + break + } else if err != nil { + return "", err + } + } + } + + return prefix + ext, nil +} + +// ============================== ConfigOption ============================== + +type ConfigOption func(c *Writer) + +func WithMaxSize(maxSize uint64) ConfigOption { + return func(w *Writer) { + w.maxSize = maxSize + } +} + +func WithDebug() ConfigOption { + return WithLogger(slog.New(tint.NewHandler(os.Stdout, &tint.Options{Level: slog.LevelDebug, TimeFormat: time.TimeOnly, AddSource: true}))) +} + +func WithLogger(logger *slog.Logger) ConfigOption { + return func(w *Writer) { + w.log = logger + } +} diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go new file mode 100644 index 0000000..ad9e510 --- /dev/null +++ b/lib/logging/writer/writer_test.go @@ -0,0 +1,69 @@ +package writer + +import ( + "io" + "os" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestSimpleWrite(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + filePath := root + "/logfile.txt" + + w, err := NewWriter(filePath, WithDebug()) + assert.NoError(err) + + assert.AssertWrite(w, "foo") + assert.AssertWrite(w, "bar") + + assert.NoError(w.Close()) + + assert.AssertFileContent(filePath, "foobar") +} + +func TestWriteWithMaxSize(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + w, err := NewWriter(root+"/logfile.txt", WithMaxSize(10), WithDebug()) + assert.NoError(err) + + assert.AssertWrite(w, "foobar1\n") + assert.AssertWrite(w, "foobar2\n") + assert.AssertWrite(w, "foobar3\n") + + assert.NoError(w.Close()) + + assert.AssertFileContent(root+"/logfile.txt", "foobar3\n") + assert.AssertFileContent(root+"/logfile.1.txt", "foobar1\n") + assert.AssertFileContent(root+"/logfile.2.txt", "foobar2\n") +} + +type fileAssert struct { + t *testing.T + assert.Assertions +} + +func NewFileAssert(t *testing.T) *fileAssert { + t.Helper() + return &fileAssert{t, *assert.New(t)} +} + +func (a *fileAssert) AssertWrite(w io.Writer, data string) { + a.t.Helper() + n, err := w.Write([]byte(data)) + if a.NoError(err) { + a.Equal(len(data), n) + } +} + +func (a *fileAssert) AssertFileContent(path, expected string) { + a.t.Helper() + actual, err := os.ReadFile(path) + if a.NoError(err) { + a.EqualValues(expected, string(actual)) + } +} -- GitLab From 3e6cab687867882d3e4330fe68cbf37ccb99ced8 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 09:10:12 +0100 Subject: [PATCH 09/28] feat(writer): properly handling multi closing and added time-based rotation. --- lib/logging/writer/writer.go | 332 +++++++++++++++++++++++------- lib/logging/writer/writer_test.go | 202 +++++++++++++++++- 2 files changed, 459 insertions(+), 75 deletions(-) diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 10ae028..5424ad3 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -1,117 +1,185 @@ package writer import ( + "context" + "errors" "fmt" "io" + "io/fs" "log/slog" "os" "path" + "strconv" "time" - - "github.com/lmittmann/tint" ) // ============================== Writer ============================== // Writer is an asynchronous io.WriteCloser with rotating capabilities type Writer struct { - path string - maxSize uint64 + path string + + sizeRotation SizeRotation + timeRotation TimeRotation - chunks chan<- string - errs <-chan error + reqs chan<- writeRequest + errs <-chan error + stop func() - file *os.File - size uint64 + file *os.File + size uint64 + lastModTime time.Time + + log *slog.Logger + clock clock +} - log *slog.Logger +type writeRequest struct { + data string + response chan<- writeResponse +} + +func makeWriteRequest(data []byte) (writeRequest, <-chan writeResponse) { + c := make(chan writeResponse, 1) + w := writeRequest{data: string(data), response: c} + return w, c +} + +func (w *writeRequest) reply(written uint64, err error) { + w.response <- writeResponse{written, err} + close(w.response) +} + +type writeResponse struct { + written uint64 + err error } var _ io.WriteCloser = (*Writer)(nil) -func NewWriter(path string, options ...ConfigOption) (*Writer, error) { - chunks := make(chan string, 10) +func NewWriter(path string, options ...WriterOption) (*Writer, error) { + reqs := make(chan writeRequest) errs := make(chan error) + ctx, stop := context.WithCancel(context.Background()) w := &Writer{ - path: path, - chunks: chunks, - errs: errs, - log: slog.New(slog.DiscardHandler), + path: path, + reqs: reqs, + errs: errs, + log: slog.New(slog.DiscardHandler), + clock: sysClock(0), + stop: stop, + timeRotation: ROTATE_NEVER, } for _, opt := range options { opt(w) } w.log = w.log.With("path", path) - go w.backgroundWriter(chunks, errs) + go w.backgroundWriter(ctx, reqs, errs) return w, nil } // Write implements io.WriteCloser. func (w *Writer) Write(p []byte) (n int, err error) { + req, resp := makeWriteRequest(p) select { case err, open := <-w.errs: if !open { return 0, io.ErrClosedPipe } return 0, err - case w.chunks <- string(p): - return len(p), nil + case w.reqs <- req: + r := <-resp + return int(r.written), r.err } } // Close implements io.WriteCloser. func (w *Writer) Close() error { - select { - case err := <-w.errs: - return err - default: - close(w.chunks) - return <-w.errs + w.stop() + var err error + for e := range w.errs { + err = errors.Join(err, e) } + return err } -func (w *Writer) backgroundWriter(chunks <-chan string, errs chan<- error) { +func (w *Writer) backgroundWriter(ctx context.Context, reqs <-chan writeRequest, errs chan<- error) { defer func() { - if err := w.close(); err != nil { + if err := w.closeFile(); err != nil { errs <- err } close(errs) }() - if err := w.innerBackgroundWriter(chunks); err != nil { + if err := w.innerBackgroundWriter(ctx, reqs); err != nil { errs <- err } } -func (w *Writer) innerBackgroundWriter(chunks <-chan string) error { - var err error - for chunk := range chunks { - if w.file == nil { - if err = w.openFile(); err != nil { +func (w *Writer) innerBackgroundWriter(ctx context.Context, reqs <-chan writeRequest) error { + for { + select { + case <-w.timeRotation.Next(w.clock.Now()): + w.log.Debug("rotation timer expired") + if w.shouldRotate(0) { + if err := w.rotate(); err != nil { + return err + } + } + case req := <-reqs: + if err := w.handleRequest(req); err != nil { return err } + case <-ctx.Done(): + for { + select { + case req := <-reqs: + req.reply(0, fs.ErrClosed) + default: + return nil + } + } } + } +} - if w.shouldRotate(uint64(len(chunk))) { - w.log.Debug("file need rotation") - if err := w.rotate(); err != nil { - return err - } +func (w *Writer) handleRequest(req writeRequest) (err error) { + var written uint64 + defer func() { + w.size += written + w.lastModTime = w.clock.Now() + if p := recover(); p != nil { + err = errors.Join(err, fmt.Errorf("recoverd panic: %v", p)) } + req.reply(written, err) + }() - for written := 0; written < len(chunk); { - n, err := w.file.Write([]byte(chunk)) - if err != nil { - return err - } - written += n - w.size += uint64(n) + toWrite := uint64(len(req.data)) + if w.shouldRotate(toWrite) { + if err := w.rotate(); err != nil { + return err } } + if toWrite == 0 { + return nil + } + + if w.file == nil { + if err := w.openFile(); err != nil { + return err + } + } + + var n int + for err == nil && written < toWrite { + n, err = w.file.Write([]byte(req.data)[written:]) + written += uint64(n) + } + return nil } @@ -124,11 +192,14 @@ func (w *Writer) openFile() error { } info, err := w.file.Stat() w.size = uint64(info.Size()) - w.log.Debug("opened file for writing", "size", w.size) + w.lastModTime = w.clock.Now() + + w.log.Debug("opened file for writing", "size", w.size, "modTime", w.lastModTime) + return err } -func (w *Writer) close() error { +func (w *Writer) closeFile() error { if w.file == nil { return nil } @@ -143,42 +214,45 @@ func (w *Writer) close() error { } func (w *Writer) shouldRotate(toWrite uint64) bool { - return w.maxSize > 0 && w.size > 0 && w.size+toWrite > w.maxSize + if w.sizeRotation.ShouldRotate(w.size + toWrite) { + w.log.Debug("size-based rotation", "size", w.size+toWrite) + return true + } + if now := w.clock.Now(); w.timeRotation.ShouldRotate(w.lastModTime, now) { + w.log.Debug("time-based rotation", "previous", w.lastModTime, "now", now) + return true + } + return false } func (w *Writer) rotate() error { - if err := w.close(); err != nil { + if w.file == nil { + return nil + } + + if err := w.closeFile(); err != nil { return err } - renameTo, err := w.rotateName() + renameTo, err := w.rotateName(w.lastModTime) if err != nil { return err } w.log.Debug("rotating file", "renameTo", renameTo) - if err = os.Rename(w.path, renameTo); err != nil { - return err - } - - return w.openFile() + return os.Rename(w.path, renameTo) } -func (w *Writer) rotateName() (string, error) { +func (w *Writer) rotateName(when time.Time) (string, error) { ext := path.Ext(w.path) prefix := w.path[:len(w.path)-len(ext)] - if w.maxSize > 0 { - for i := 1; true; i++ { - rotated_prefix := fmt.Sprintf("%s.%d", prefix, i) - if _, err := os.Stat(rotated_prefix + ext); os.IsNotExist(err) { - prefix = rotated_prefix - break - } else if err != nil { - return "", err - } - } + prefix += w.timeRotation.PathSuffix(when) + if sizeSuffix, err := w.sizeRotation.PathSuffix(prefix, ext); err == nil { + prefix += sizeSuffix + } else { + return "", err } return prefix + ext, nil @@ -186,20 +260,134 @@ func (w *Writer) rotateName() (string, error) { // ============================== ConfigOption ============================== -type ConfigOption func(c *Writer) +type WriterOption func(c *Writer) -func WithMaxSize(maxSize uint64) ConfigOption { +func WithMaxSize(maxSize uint64) WriterOption { return func(w *Writer) { - w.maxSize = maxSize + w.sizeRotation = SizeRotation(maxSize) } } -func WithDebug() ConfigOption { - return WithLogger(slog.New(tint.NewHandler(os.Stdout, &tint.Options{Level: slog.LevelDebug, TimeFormat: time.TimeOnly, AddSource: true}))) +func WithLogger(logger *slog.Logger) WriterOption { + return func(w *Writer) { + w.log = logger + } } -func WithLogger(logger *slog.Logger) ConfigOption { +func WithTimeRotation(timeRotation TimeRotation) WriterOption { return func(w *Writer) { - w.log = logger + w.timeRotation = timeRotation + } +} + +// ============================== SizeRotation ============================== + +type SizeRotation uint64 + +func (s SizeRotation) PathSuffix(prefix, ext string) (string, error) { + if s == 0 { + + return "", nil + } + for i := 1; true; i++ { + suffix := "." + strconv.Itoa(i) + if _, err := os.Stat(prefix + suffix + ext); os.IsNotExist(err) { + return suffix, nil + } else if err != nil { + return "", err + } + } + return "", nil +} + +func (s SizeRotation) FileGlob() string { + if s > 0 { + return ".*" + } else { + return "" } } + +func (s SizeRotation) ShouldRotate(size uint64) bool { + if s > 0 { + return size > uint64(s) + } else { + return false + } +} + +// ============================== TimeRotation ============================== + +type TimeRotation interface { + PathSuffix(now time.Time) string + FileGlob() string + ShouldRotate(previous, now time.Time) bool + Next(previous time.Time) <-chan struct{} +} + +// ============================== noTimeRotation ============================== + +type noTimeRotation int + +var ROTATE_NEVER TimeRotation = noTimeRotation(0) + +// FileGlob implements TimeRotation. +func (noTimeRotation) FileGlob() string { + return "" +} + +// Next implements TimeRotation. +func (noTimeRotation) Next(previous time.Time) <-chan struct{} { + return nil +} + +// PathSuffix implements TimeRotation. +func (noTimeRotation) PathSuffix(now time.Time) string { + return "" +} + +// ShouldRotate implements TimeRotation. +func (n noTimeRotation) ShouldRotate(previous time.Time, now time.Time) bool { + return false +} + +// ============================== dailyRotation ============================== + +type dailyRotation int + +var ROTATE_DAILY TimeRotation = dailyRotation(0) + +// FileGlob implements TimeRotation. +func (dailyRotation) FileGlob() string { + return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" +} + +// Next implements TimeRotation. +func (dailyRotation) Next(previous time.Time) <-chan struct{} { + return nil +} + +// PathSuffix implements TimeRotation. +func (dailyRotation) PathSuffix(now time.Time) string { + return now.Format("2006-01-02") +} + +// ShouldRotate implements TimeRotation. +func (dailyRotation) ShouldRotate(previous time.Time, now time.Time) bool { + return previous.Year() != now.Year() || previous.YearDay() != now.YearDay() +} + +// ============================== Clock ============================== + +type clock interface { + Now() time.Time +} + +type sysClock int + +var _ clock = sysClock(0) + +// Now implements Clock. +func (s sysClock) Now() time.Time { + return time.Now() +} diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index ad9e510..722bcc2 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -2,9 +2,14 @@ package writer import ( "io" + "log/slog" "os" + "runtime" + "sync" "testing" + "time" + "github.com/lmittmann/tint" "github.com/stretchr/testify/assert" ) @@ -13,7 +18,7 @@ func TestSimpleWrite(t *testing.T) { root := t.TempDir() filePath := root + "/logfile.txt" - w, err := NewWriter(filePath, WithDebug()) + w, err := NewWriter(filePath, withDebug()) assert.NoError(err) assert.AssertWrite(w, "foo") @@ -28,10 +33,11 @@ func TestWriteWithMaxSize(t *testing.T) { assert := NewFileAssert(t) root := t.TempDir() - w, err := NewWriter(root+"/logfile.txt", WithMaxSize(10), WithDebug()) + w, err := NewWriter(root+"/logfile.txt", WithMaxSize(10), withDebug()) assert.NoError(err) - assert.AssertWrite(w, "foobar1\n") + assert.AssertWrite(w, "foo") + assert.AssertWrite(w, "bar1\n") assert.AssertWrite(w, "foobar2\n") assert.AssertWrite(w, "foobar3\n") @@ -42,6 +48,76 @@ func TestWriteWithMaxSize(t *testing.T) { assert.AssertFileContent(root+"/logfile.2.txt", "foobar2\n") } +func TestWriteWithTimeRotation(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + c := newTestClock(t) + dtr := debugTimeRotation{c} + + w, err := NewWriter(root+"/logfile.txt", WithTimeRotation(&dtr), withDebug(), withClock(c)) + assert.NoError(err) + + assert.AssertWrite(w, "foobar1\n") + c.Advance(time.Second) + + assert.AssertWrite(w, "foobar2\n") + c.Advance(2 * time.Second) + + assert.AssertWrite(w, "foobar3\n") + c.Advance(time.Second) + + assert.AssertWrite(w, "foobar4\n") + + assert.NoError(w.Close()) + + assert.AssertFileContent(root+"/logfile.0001-01-01-000000.txt", "foobar1\n") + assert.AssertFileContent(root+"/logfile.0001-01-01-000001.txt", "foobar2\n") + assert.AssertFileContent(root+"/logfile.0001-01-01-000003.txt", "foobar3\n") + assert.AssertFileContent(root+"/logfile.txt", "foobar4\n") +} + +func TestMultiSyncClose(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + w, err := NewWriter(root+"/logfile.txt", withDebug()) + assert.NoError(err) + + for range 4 { + assert.NotPanics(func() { + assert.NoError(w.Close()) + }) + } +} + +func TestMultiAsyncClose(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + w, err := NewWriter(root+"/logfile.txt", withDebug()) + assert.NoError(err) + + var wg sync.WaitGroup + start := make(chan bool) + + for range 4 { + wg.Add(1) + go func() { + defer wg.Done() + <-start + assert.NotPanics(func() { + assert.NoError(w.Close()) + }) + }() + } + + close(start) + wg.Wait() +} + +// ============================== fileAssert ============================== + type fileAssert struct { t *testing.T assert.Assertions @@ -67,3 +143,123 @@ func (a *fileAssert) AssertFileContent(path, expected string) { a.EqualValues(expected, string(actual)) } } + +// ============================== testClock ============================== + +type testClock struct { + t *testing.T + now time.Time + timers []testTimer + l sync.Mutex +} + +var _ clock = (*testClock)(nil) + +func newTestClock(t *testing.T) *testClock { + return &testClock{t: t} +} + +type testTimer struct { + deadline time.Time + expired chan struct{} +} + +// Now implements clock. +func (t *testClock) Now() time.Time { + return t.now +} + +func (t *testClock) Advance(step time.Duration) { + t.t.Helper() + t.l.Lock() + defer t.l.Unlock() + t.now = t.now.Add(step) + t.t.Logf("now is %s", t.now) + t.fireTimers() + runtime.Gosched() +} + +func (t *testClock) fireTimers() { + t.t.Helper() + if t.timers == nil { + return + } + i := 0 + for _, timer := range t.timers { + if timer.deadline.After(t.now) { + t.timers[i] = timer + i += 1 + } else { + t.t.Logf("fire timer at %s", timer.deadline) + close(timer.expired) + runtime.Gosched() + } + } + if i > 0 { + t.timers = t.timers[:i] + } else { + t.timers = nil + } +} + +func (t *testClock) Deadline(deadline time.Time) <-chan struct{} { + t.t.Helper() + t.l.Lock() + defer t.l.Unlock() + for _, timer := range t.timers { + if timer.deadline == deadline { + return timer.expired + } + } + expired := make(chan struct{}) + t.timers = append(t.timers, testTimer{deadline, expired}) + t.t.Logf("created timer at %s", deadline) + return expired +} + +func (t *testClock) After(d time.Duration) <-chan struct{} { + t.t.Helper() + return t.Deadline(t.now.Add(d)) +} + +func withDebug() WriterOption { + return WithLogger(slog.New(tint.NewHandler(os.Stdout, &tint.Options{Level: slog.LevelDebug, TimeFormat: time.TimeOnly, AddSource: true}))) +} + +func withClock(c clock) WriterOption { + return func(w *Writer) { + w.clock = c + } +} + +// ============================== debugTimeRotation ============================== + +type debugTimeRotation struct { + c *testClock +} + +var _ TimeRotation = (*debugTimeRotation)(nil) + +// FileGlob implements TimeRotation. +func (d *debugTimeRotation) FileGlob() string { + return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]-[0-2][0-9][0-5][0-9][0-5][0-9]" +} + +// Next implements TimeRotation. +func (d *debugTimeRotation) Next(previous time.Time) <-chan struct{} { + return d.c.Deadline(previous.Add(time.Second)) +} + +// PathSuffix implements TimeRotation. +func (d *debugTimeRotation) PathSuffix(now time.Time) string { + return now.Format(".2006-01-02-150405") +} + +// ShouldRotate implements TimeRotation. +func (d *debugTimeRotation) ShouldRotate(previous time.Time, now time.Time) bool { + return now.Second() != previous.Second() || + now.Minute() != previous.Minute() || + now.Hour() != previous.Hour() || + now.Month() != previous.Month() || + now.Year() != previous.Year() +} -- GitLab From d16a47872c92e1ab3bb8abb634b30d5c39d8e825 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 14:10:19 +0100 Subject: [PATCH 10/28] feat: add an option to keep a limited number of archived files. --- lib/logging/writer/rotation.go | 104 +++++++++++ lib/logging/writer/writer.go | 285 ++++++++++++++++-------------- lib/logging/writer/writer_test.go | 78 ++++---- 3 files changed, 304 insertions(+), 163 deletions(-) create mode 100644 lib/logging/writer/rotation.go diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go new file mode 100644 index 0000000..221d235 --- /dev/null +++ b/lib/logging/writer/rotation.go @@ -0,0 +1,104 @@ +package writer + +import ( + "os" + "strconv" + "time" +) + +// ============================== SizeRotation ============================== + +type SizeRotation uint64 + +func (s SizeRotation) ShouldRotate(current, next uint64) bool { + if s > 0 && current > 0 { + return next > uint64(s) + } else { + return false + } +} + +func (s SizeRotation) PathSuffix(prefix, ext string) (string, error) { + if s > 0 { + for i := 1; true; i++ { + suffix := "." + strconv.Itoa(i) + if _, err := os.Stat(prefix + suffix + ext); os.IsNotExist(err) { + return suffix, nil + } else if err != nil { + return "", err + } + } + } + return "", nil +} + +func (s SizeRotation) FileGlob() string { + if s > 0 { + return ".*" + } else { + return "" + } +} + +// ============================== TimeRotation ============================== + +type TimeRotation interface { + PathSuffix(now time.Time) string + FileGlob() string + ShouldRotate(previous, now time.Time) bool + Next(previous time.Time) <-chan time.Time +} + +// ============================== noTimeRotation ============================== + +type noTimeRotation int + +var ROTATE_NEVER TimeRotation = noTimeRotation(0) + +// FileGlob implements TimeRotation. +func (noTimeRotation) FileGlob() string { + return "" +} + +// PathSuffix implements TimeRotation. +func (noTimeRotation) PathSuffix(now time.Time) string { + return "" +} + +// ShouldRotate implements TimeRotation. +func (n noTimeRotation) ShouldRotate(previous time.Time, now time.Time) bool { + return false +} + +// Next implements TimeRotation. +func (noTimeRotation) Next(previous time.Time) <-chan time.Time { + return nil +} + +// ============================== dailyRotation ============================== + +type dailyRotation int + +var ROTATE_DAILY TimeRotation = dailyRotation(0) + +// ShouldRotate implements TimeRotation. +func (dailyRotation) ShouldRotate(previous time.Time, now time.Time) bool { + return previous.YearDay() != now.YearDay() || previous.Year() != now.Year() +} + +// PathSuffix implements TimeRotation. +func (dailyRotation) PathSuffix(now time.Time) string { + return now.Format("2006-01-02") +} + +// FileGlob implements TimeRotation. +func (dailyRotation) FileGlob() string { + return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" +} + +// Next implements TimeRotation. +func (dailyRotation) Next(previous time.Time) <-chan time.Time { + y, m, d := previous.Date() + nextDay := time.Date(y, m, d+1, 0, 0, 0, 0, previous.Location()) + return time.After(time.Until(nextDay)) +} diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 5424ad3..4bb815f 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -9,7 +9,10 @@ import ( "log/slog" "os" "path" - "strconv" + "path/filepath" + "slices" + "strings" + "sync" "time" ) @@ -22,9 +25,14 @@ type Writer struct { sizeRotation SizeRotation timeRotation TimeRotation - reqs chan<- writeRequest - errs <-chan error - stop func() + pruneMaxCount uint + pruneMAxAge time.Duration + + reqs chan<- writeRequest + archived chan<- string + ctx context.Context + stop context.CancelCauseFunc + wg sync.WaitGroup file *os.File size uint64 @@ -59,13 +67,14 @@ var _ io.WriteCloser = (*Writer)(nil) func NewWriter(path string, options ...WriterOption) (*Writer, error) { reqs := make(chan writeRequest) - errs := make(chan error) - ctx, stop := context.WithCancel(context.Background()) + archived := make(chan string, 20) + ctx, stop := context.WithCancelCause(context.Background()) w := &Writer{ path: path, reqs: reqs, - errs: errs, + archived: archived, + ctx: ctx, log: slog.New(slog.DiscardHandler), clock: sysClock(0), stop: stop, @@ -74,52 +83,57 @@ func NewWriter(path string, options ...WriterOption) (*Writer, error) { for _, opt := range options { opt(w) } - w.log = w.log.With("path", path) + w.log = w.log.With("logfile", path) - go w.backgroundWriter(ctx, reqs, errs) + w.wg.Add(1) + go func() { + defer w.wg.Done() + if err := w.backgroundWriter(ctx, reqs); err != nil { + stop(err) + } + }() + + if w.needCleaner() { + w.wg.Add(1) + go func() { + defer w.wg.Done() + if err := w.backgroundCleaner(ctx, archived); err != nil { + stop(err) + } + }() + } return w, nil } // Write implements io.WriteCloser. func (w *Writer) Write(p []byte) (n int, err error) { - req, resp := makeWriteRequest(p) - select { - case err, open := <-w.errs: - if !open { - return 0, io.ErrClosedPipe - } + if err := context.Cause(w.ctx); err == context.Canceled { + return 0, os.ErrClosed + } else if err != nil { return 0, err - case w.reqs <- req: - r := <-resp - return int(r.written), r.err } + req, resp := makeWriteRequest(p) + w.reqs <- req + r := <-resp + return int(r.written), r.err } // Close implements io.WriteCloser. func (w *Writer) Close() error { - w.stop() - var err error - for e := range w.errs { - err = errors.Join(err, e) + w.stop(nil) + w.wg.Wait() + if err := context.Cause(w.ctx); err != nil && err != context.Canceled { + return err } - return err + return nil } -func (w *Writer) backgroundWriter(ctx context.Context, reqs <-chan writeRequest, errs chan<- error) { +func (w *Writer) backgroundWriter(ctx context.Context, reqs <-chan writeRequest) (err error) { defer func() { - if err := w.closeFile(); err != nil { - errs <- err - } - close(errs) + err = errors.Join(err, w.closeFile()) }() - if err := w.innerBackgroundWriter(ctx, reqs); err != nil { - errs <- err - } -} - -func (w *Writer) innerBackgroundWriter(ctx context.Context, reqs <-chan writeRequest) error { for { select { case <-w.timeRotation.Next(w.clock.Now()): @@ -214,7 +228,7 @@ func (w *Writer) closeFile() error { } func (w *Writer) shouldRotate(toWrite uint64) bool { - if w.sizeRotation.ShouldRotate(w.size + toWrite) { + if w.sizeRotation.ShouldRotate(w.size, w.size+toWrite) { w.log.Debug("size-based rotation", "size", w.size+toWrite) return true } @@ -234,147 +248,136 @@ func (w *Writer) rotate() error { return err } - renameTo, err := w.rotateName(w.lastModTime) + renameTo, err := w.newArchivePath(w.lastModTime) if err != nil { return err } w.log.Debug("rotating file", "renameTo", renameTo) - return os.Rename(w.path, renameTo) -} - -func (w *Writer) rotateName(when time.Time) (string, error) { - ext := path.Ext(w.path) - prefix := w.path[:len(w.path)-len(ext)] - - prefix += w.timeRotation.PathSuffix(when) - if sizeSuffix, err := w.sizeRotation.PathSuffix(prefix, ext); err == nil { - prefix += sizeSuffix - } else { - return "", err + if err = os.Rename(w.path, renameTo); err != nil { + return err } - return prefix + ext, nil + w.archived <- renameTo + + return nil } -// ============================== ConfigOption ============================== +func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) error { + for { + select { + case <-archived: + case <-ctx.Done(): + return nil + } -type WriterOption func(c *Writer) + archives, err := w.listArchives() + if err != nil { + return err + } -func WithMaxSize(maxSize uint64) WriterOption { - return func(w *Writer) { - w.sizeRotation = SizeRotation(maxSize) + if len(archives) > 0 { + w.log.Debug("found archived files", "archives", archives) + w.prune(archives) + } } } -func WithLogger(logger *slog.Logger) WriterOption { - return func(w *Writer) { - w.log = logger - } +func (w *Writer) needCleaner() bool { + return w.pruneMaxCount > 0 } -func WithTimeRotation(timeRotation TimeRotation) WriterOption { - return func(w *Writer) { - w.timeRotation = timeRotation +func (w *Writer) listArchives() ([]fileEntry, error) { + paths, err := filepath.Glob(w.archiveGlob()) + if err != nil { + return nil, err } -} -// ============================== SizeRotation ============================== + entries := make([]fileEntry, len(paths)) + for i, p := range paths { + if info, err := os.Stat(p); err == nil { + entries[i] = fileEntry{p, info} + } else { + return nil, err + } + } -type SizeRotation uint64 + slices.SortStableFunc(entries, func(a, b fileEntry) int { + if delta := b.ModTime().Compare(a.ModTime()); delta != 0 { + return delta + } else { + return strings.Compare(b.Path, a.Path) + } + }) -func (s SizeRotation) PathSuffix(prefix, ext string) (string, error) { - if s == 0 { + return entries, nil +} - return "", nil - } - for i := 1; true; i++ { - suffix := "." + strconv.Itoa(i) - if _, err := os.Stat(prefix + suffix + ext); os.IsNotExist(err) { - return suffix, nil - } else if err != nil { - return "", err +func (w *Writer) prune(archives []fileEntry) { + if w.pruneMaxCount > 0 && len(archives) > int(w.pruneMaxCount) { + w.log.Debug("the number of archived files exceeds the limit", "count", len(archives), "limit", w.pruneMaxCount) + for _, entry := range archives[w.pruneMaxCount:] { + if err := entry.Remove(); err != nil { + w.log.Error("could not remove file", "err", err) + return + } else { + w.log.Debug("removed archived file", "archive", entry.Path) + } } } - return "", nil } -func (s SizeRotation) FileGlob() string { - if s > 0 { - return ".*" - } else { - return "" - } -} +func (w *Writer) newArchivePath(when time.Time) (string, error) { + ext := path.Ext(w.path) + prefix := w.path[:len(w.path)-len(ext)] -func (s SizeRotation) ShouldRotate(size uint64) bool { - if s > 0 { - return size > uint64(s) + prefix += w.timeRotation.PathSuffix(when) + if sizeSuffix, err := w.sizeRotation.PathSuffix(prefix, ext); err == nil { + prefix += sizeSuffix } else { - return false + return "", err } -} -// ============================== TimeRotation ============================== - -type TimeRotation interface { - PathSuffix(now time.Time) string - FileGlob() string - ShouldRotate(previous, now time.Time) bool - Next(previous time.Time) <-chan struct{} -} - -// ============================== noTimeRotation ============================== - -type noTimeRotation int - -var ROTATE_NEVER TimeRotation = noTimeRotation(0) - -// FileGlob implements TimeRotation. -func (noTimeRotation) FileGlob() string { - return "" + return prefix + ext, nil } -// Next implements TimeRotation. -func (noTimeRotation) Next(previous time.Time) <-chan struct{} { - return nil -} +func (w *Writer) archiveGlob() string { + ext := path.Ext(w.path) + prefix := w.path[:len(w.path)-len(ext)] -// PathSuffix implements TimeRotation. -func (noTimeRotation) PathSuffix(now time.Time) string { - return "" -} + prefix += w.timeRotation.FileGlob() + prefix += w.sizeRotation.FileGlob() -// ShouldRotate implements TimeRotation. -func (n noTimeRotation) ShouldRotate(previous time.Time, now time.Time) bool { - return false + return prefix + ext } -// ============================== dailyRotation ============================== - -type dailyRotation int +// ============================== ConfigOption ============================== -var ROTATE_DAILY TimeRotation = dailyRotation(0) +type WriterOption func(c *Writer) -// FileGlob implements TimeRotation. -func (dailyRotation) FileGlob() string { - return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" +func WithMaxSize(maxSize uint64) WriterOption { + return func(w *Writer) { + w.sizeRotation = SizeRotation(maxSize) + } } -// Next implements TimeRotation. -func (dailyRotation) Next(previous time.Time) <-chan struct{} { - return nil +func WithLogger(logger *slog.Logger) WriterOption { + return func(w *Writer) { + w.log = logger + } } -// PathSuffix implements TimeRotation. -func (dailyRotation) PathSuffix(now time.Time) string { - return now.Format("2006-01-02") +func WithTimeRotation(timeRotation TimeRotation) WriterOption { + return func(w *Writer) { + w.timeRotation = timeRotation + } } -// ShouldRotate implements TimeRotation. -func (dailyRotation) ShouldRotate(previous time.Time, now time.Time) bool { - return previous.Year() != now.Year() || previous.YearDay() != now.YearDay() +func WithKeepMaxCount(count uint) WriterOption { + return func(w *Writer) { + w.pruneMaxCount = count + } } // ============================== Clock ============================== @@ -391,3 +394,21 @@ var _ clock = sysClock(0) func (s sysClock) Now() time.Time { return time.Now() } + +// ============================== fileEntry ============================== + +type fileEntry struct { + Path string + os.FileInfo +} + +var _ fmt.Stringer = fileEntry{} + +func (f fileEntry) Remove() error { + return os.Remove(f.Path) +} + +// LogValue implements slog.LogValuer. +func (f fileEntry) String() string { + return fmt.Sprintf("%s(%d bytes, %s)", f.Path, f.Size(), f.ModTime().Format(time.RFC3339)) +} diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 722bcc2..d4f1f22 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -21,12 +21,12 @@ func TestSimpleWrite(t *testing.T) { w, err := NewWriter(filePath, withDebug()) assert.NoError(err) - assert.AssertWrite(w, "foo") - assert.AssertWrite(w, "bar") + assert.WriteOk(w, "foo") + assert.WriteOk(w, "bar") assert.NoError(w.Close()) - assert.AssertFileContent(filePath, "foobar") + assert.FileContent(filePath, "foobar") } func TestWriteWithMaxSize(t *testing.T) { @@ -36,16 +36,16 @@ func TestWriteWithMaxSize(t *testing.T) { w, err := NewWriter(root+"/logfile.txt", WithMaxSize(10), withDebug()) assert.NoError(err) - assert.AssertWrite(w, "foo") - assert.AssertWrite(w, "bar1\n") - assert.AssertWrite(w, "foobar2\n") - assert.AssertWrite(w, "foobar3\n") + assert.WriteOk(w, "foo") + assert.WriteOk(w, "bar1\n") + assert.WriteOk(w, "foobar2\n") + assert.WriteOk(w, "foobar3\n") assert.NoError(w.Close()) - assert.AssertFileContent(root+"/logfile.txt", "foobar3\n") - assert.AssertFileContent(root+"/logfile.1.txt", "foobar1\n") - assert.AssertFileContent(root+"/logfile.2.txt", "foobar2\n") + assert.FileContent(root+"/logfile.txt", "foobar3\n") + assert.FileContent(root+"/logfile.1.txt", "foobar1\n") + assert.FileContent(root+"/logfile.2.txt", "foobar2\n") } func TestWriteWithTimeRotation(t *testing.T) { @@ -58,23 +58,43 @@ func TestWriteWithTimeRotation(t *testing.T) { w, err := NewWriter(root+"/logfile.txt", WithTimeRotation(&dtr), withDebug(), withClock(c)) assert.NoError(err) - assert.AssertWrite(w, "foobar1\n") + assert.WriteOk(w, "foobar1\n") c.Advance(time.Second) - assert.AssertWrite(w, "foobar2\n") + assert.WriteOk(w, "foobar2\n") c.Advance(2 * time.Second) - assert.AssertWrite(w, "foobar3\n") + assert.WriteOk(w, "foobar3\n") c.Advance(time.Second) - assert.AssertWrite(w, "foobar4\n") + assert.WriteOk(w, "foobar4\n") assert.NoError(w.Close()) - assert.AssertFileContent(root+"/logfile.0001-01-01-000000.txt", "foobar1\n") - assert.AssertFileContent(root+"/logfile.0001-01-01-000001.txt", "foobar2\n") - assert.AssertFileContent(root+"/logfile.0001-01-01-000003.txt", "foobar3\n") - assert.AssertFileContent(root+"/logfile.txt", "foobar4\n") + assert.FileContent(root+"/logfile.0001-01-01-000000.txt", "foobar1\n") + assert.FileContent(root+"/logfile.0001-01-01-000001.txt", "foobar2\n") + assert.FileContent(root+"/logfile.0001-01-01-000003.txt", "foobar3\n") + assert.FileContent(root+"/logfile.txt", "foobar4\n") +} + +func TestKeepMaxCount(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + w, err := NewWriter(root+"/logfile.txt", WithMaxSize(5), WithKeepMaxCount(2), withDebug()) + assert.NoError(err) + + for range 5 { + assert.WriteOk(w, "foobar\n") + } + + assert.NoError(w.Close()) + + assert.FileExists(root + "/logfile.txt") + assert.NoFileExists(root + "/logfile.1.txt") + assert.NoFileExists(root + "/logfile.2.txt") + assert.FileExists(root + "/logfile.3.txt") + assert.FileExists(root + "/logfile.4.txt") } func TestMultiSyncClose(t *testing.T) { @@ -128,7 +148,7 @@ func NewFileAssert(t *testing.T) *fileAssert { return &fileAssert{t, *assert.New(t)} } -func (a *fileAssert) AssertWrite(w io.Writer, data string) { +func (a *fileAssert) WriteOk(w io.Writer, data string) { a.t.Helper() n, err := w.Write([]byte(data)) if a.NoError(err) { @@ -136,11 +156,11 @@ func (a *fileAssert) AssertWrite(w io.Writer, data string) { } } -func (a *fileAssert) AssertFileContent(path, expected string) { +func (a *fileAssert) FileContent(path, expected string) { a.t.Helper() actual, err := os.ReadFile(path) if a.NoError(err) { - a.EqualValues(expected, string(actual)) + a.EqualValuesf(expected, string(actual), "%s should contains expected data", path) } } @@ -161,7 +181,7 @@ func newTestClock(t *testing.T) *testClock { type testTimer struct { deadline time.Time - expired chan struct{} + expired chan time.Time } // Now implements clock. @@ -191,6 +211,7 @@ func (t *testClock) fireTimers() { i += 1 } else { t.t.Logf("fire timer at %s", timer.deadline) + timer.expired <- timer.deadline close(timer.expired) runtime.Gosched() } @@ -202,22 +223,17 @@ func (t *testClock) fireTimers() { } } -func (t *testClock) Deadline(deadline time.Time) <-chan struct{} { +func (t *testClock) Deadline(deadline time.Time) <-chan time.Time { t.t.Helper() t.l.Lock() defer t.l.Unlock() - for _, timer := range t.timers { - if timer.deadline == deadline { - return timer.expired - } - } - expired := make(chan struct{}) + expired := make(chan time.Time, 1) t.timers = append(t.timers, testTimer{deadline, expired}) t.t.Logf("created timer at %s", deadline) return expired } -func (t *testClock) After(d time.Duration) <-chan struct{} { +func (t *testClock) After(d time.Duration) <-chan time.Time { t.t.Helper() return t.Deadline(t.now.Add(d)) } @@ -246,7 +262,7 @@ func (d *debugTimeRotation) FileGlob() string { } // Next implements TimeRotation. -func (d *debugTimeRotation) Next(previous time.Time) <-chan struct{} { +func (d *debugTimeRotation) Next(previous time.Time) <-chan time.Time { return d.c.Deadline(previous.Add(time.Second)) } -- GitLab From dbcee6d42876ab796ec9f47846746e3eb08b4aa1 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 16:07:03 +0100 Subject: [PATCH 11/28] feat: add an option to remove archived files older than a limit. --- lib/logging/writer/writer.go | 76 +++++++++++++++++++++---------- lib/logging/writer/writer_test.go | 28 +++++++++++- 2 files changed, 77 insertions(+), 27 deletions(-) diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 4bb815f..8311077 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -26,7 +26,7 @@ type Writer struct { timeRotation TimeRotation pruneMaxCount uint - pruneMAxAge time.Duration + pruneMaxAge time.Duration reqs chan<- writeRequest archived chan<- string @@ -37,6 +37,7 @@ type Writer struct { file *os.File size uint64 lastModTime time.Time + index uint log *slog.Logger clock clock @@ -65,7 +66,7 @@ type writeResponse struct { var _ io.WriteCloser = (*Writer)(nil) -func NewWriter(path string, options ...WriterOption) (*Writer, error) { +func NewWriter(path string, options ...Option) (*Writer, error) { reqs := make(chan writeRequest) archived := make(chan string, 20) ctx, stop := context.WithCancelCause(context.Background()) @@ -205,11 +206,13 @@ func (w *Writer) openFile() error { return err } info, err := w.file.Stat() + if err != nil { + return err + } + w.size = uint64(info.Size()) w.lastModTime = w.clock.Now() - w.log.Debug("opened file for writing", "size", w.size, "modTime", w.lastModTime) - return err } @@ -248,16 +251,19 @@ func (w *Writer) rotate() error { return err } - renameTo, err := w.newArchivePath(w.lastModTime) + refTime := w.lastModTime + renameTo, err := w.newArchivePath(refTime) if err != nil { return err } w.log.Debug("rotating file", "renameTo", renameTo) - if err = os.Rename(w.path, renameTo); err != nil { return err } + if err = os.Chtimes(renameTo, refTime, refTime); err != nil { + return err + } w.archived <- renameTo @@ -272,20 +278,19 @@ func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) return nil } - archives, err := w.listArchives() - if err != nil { + if archives, err := w.listArchives(); err != nil { return err - } - - if len(archives) > 0 { + } else if len(archives) > 0 { w.log.Debug("found archived files", "archives", archives) - w.prune(archives) + if err := w.prune(archives); err != nil { + return err + } } } } func (w *Writer) needCleaner() bool { - return w.pruneMaxCount > 0 + return w.pruneMaxCount > 0 || w.pruneMaxAge > 0 } func (w *Writer) listArchives() ([]fileEntry, error) { @@ -314,18 +319,30 @@ func (w *Writer) listArchives() ([]fileEntry, error) { return entries, nil } -func (w *Writer) prune(archives []fileEntry) { - if w.pruneMaxCount > 0 && len(archives) > int(w.pruneMaxCount) { - w.log.Debug("the number of archived files exceeds the limit", "count", len(archives), "limit", w.pruneMaxCount) - for _, entry := range archives[w.pruneMaxCount:] { +func (w *Writer) prune(archives []fileEntry) error { + for i, entry := range archives { + if w.shouldPrune(i, entry) { if err := entry.Remove(); err != nil { - w.log.Error("could not remove file", "err", err) - return + return fmt.Errorf("could not remove archived logfile: %w", err) } else { w.log.Debug("removed archived file", "archive", entry.Path) } } } + return nil +} + +func (w *Writer) shouldPrune(index int, entry fileEntry) bool { + if w.pruneMaxCount > 0 && uint(index) >= w.pruneMaxCount { + w.log.Debug("file index exceeds the limit", "index", index, "limit", w.pruneMaxCount, "path", entry.Path) + return true + } + age := w.clock.Now().Sub(entry.ModTime()) + if w.pruneMaxAge > 0 && age > w.pruneMaxAge { + w.log.Debug("file age exceeds the limit", "age", age, "limit", w.pruneMaxAge, "path", entry.Path) + return true + } + return false } func (w *Writer) newArchivePath(when time.Time) (string, error) { @@ -354,29 +371,38 @@ func (w *Writer) archiveGlob() string { // ============================== ConfigOption ============================== -type WriterOption func(c *Writer) +type Option func(c *Writer) -func WithMaxSize(maxSize uint64) WriterOption { +func WithMaxSize(maxSize uint64) Option { return func(w *Writer) { w.sizeRotation = SizeRotation(maxSize) } } -func WithLogger(logger *slog.Logger) WriterOption { +func WithLogger(logger *slog.Logger) Option { return func(w *Writer) { w.log = logger } } -func WithTimeRotation(timeRotation TimeRotation) WriterOption { +func WithTimeRotation(timeRotation TimeRotation) Option { return func(w *Writer) { w.timeRotation = timeRotation } } -func WithKeepMaxCount(count uint) WriterOption { +func WithKeepMaxCount(maxCount uint) Option { + return func(w *Writer) { + w.pruneMaxCount = maxCount + } +} + +func WithKeepMaxAge(maxAge time.Duration) Option { + if maxAge < 0 { + panic("negative maxAge") + } return func(w *Writer) { - w.pruneMaxCount = count + w.pruneMaxAge = maxAge } } diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index d4f1f22..c484461 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -97,6 +97,30 @@ func TestKeepMaxCount(t *testing.T) { assert.FileExists(root + "/logfile.4.txt") } +func TestKeepMaxAge(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + c := newTestClock(t) + c.now = time.Date(2000, 01, 01, 0, 0, 0, 0, time.Local) + dtr := debugTimeRotation{c} + + w, err := NewWriter(root+"/logfile.txt", WithTimeRotation(&dtr), WithKeepMaxAge(2*time.Second), withDebug(), withClock(c)) + assert.NoError(err) + + for range 4 { + assert.WriteOk(w, "foobar\n") + c.Advance(time.Second) + } + + assert.NoError(w.Close()) + + assert.NoFileExists(root + "/logfile.2000-01-01-000000.txt") + assert.NoFileExists(root + "/logfile.2000-01-01-000001.txt") + assert.FileExists(root + "/logfile.2000-01-01-000002.txt") + assert.FileExists(root + "/logfile.2000-01-01-000003.txt") +} + func TestMultiSyncClose(t *testing.T) { assert := NewFileAssert(t) root := t.TempDir() @@ -238,11 +262,11 @@ func (t *testClock) After(d time.Duration) <-chan time.Time { return t.Deadline(t.now.Add(d)) } -func withDebug() WriterOption { +func withDebug() Option { return WithLogger(slog.New(tint.NewHandler(os.Stdout, &tint.Options{Level: slog.LevelDebug, TimeFormat: time.TimeOnly, AddSource: true}))) } -func withClock(c clock) WriterOption { +func withClock(c clock) Option { return func(w *Writer) { w.clock = c } -- GitLab From 684ff2d7c6ff159881a2ef5b9f2c820fd43e6fc6 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 16:18:34 +0100 Subject: [PATCH 12/28] feat: add an option to keep the total size of archived files under a defined limit. --- lib/logging/writer/writer.go | 20 ++++++++++++++++---- lib/logging/writer/writer_test.go | 19 +++++++++++++++++++ 2 files changed, 35 insertions(+), 4 deletions(-) diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 8311077..3e01b79 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -27,6 +27,7 @@ type Writer struct { pruneMaxCount uint pruneMaxAge time.Duration + pruneMaxSize uint64 reqs chan<- writeRequest archived chan<- string @@ -37,7 +38,6 @@ type Writer struct { file *os.File size uint64 lastModTime time.Time - index uint log *slog.Logger clock clock @@ -290,7 +290,7 @@ func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) } func (w *Writer) needCleaner() bool { - return w.pruneMaxCount > 0 || w.pruneMaxAge > 0 + return w.pruneMaxCount > 0 || w.pruneMaxAge > 0 || w.pruneMaxSize > 0 } func (w *Writer) listArchives() ([]fileEntry, error) { @@ -320,8 +320,10 @@ func (w *Writer) listArchives() ([]fileEntry, error) { } func (w *Writer) prune(archives []fileEntry) error { + var totalSize uint64 for i, entry := range archives { - if w.shouldPrune(i, entry) { + totalSize += uint64(entry.Size()) + if w.shouldPrune(i, entry, totalSize) { if err := entry.Remove(); err != nil { return fmt.Errorf("could not remove archived logfile: %w", err) } else { @@ -332,7 +334,7 @@ func (w *Writer) prune(archives []fileEntry) error { return nil } -func (w *Writer) shouldPrune(index int, entry fileEntry) bool { +func (w *Writer) shouldPrune(index int, entry fileEntry, totalSize uint64) bool { if w.pruneMaxCount > 0 && uint(index) >= w.pruneMaxCount { w.log.Debug("file index exceeds the limit", "index", index, "limit", w.pruneMaxCount, "path", entry.Path) return true @@ -342,6 +344,10 @@ func (w *Writer) shouldPrune(index int, entry fileEntry) bool { w.log.Debug("file age exceeds the limit", "age", age, "limit", w.pruneMaxAge, "path", entry.Path) return true } + if w.pruneMaxSize > 0 && totalSize > w.pruneMaxSize { + w.log.Debug("total size exceeds the limit", "totalSize", totalSize, "limit", w.pruneMaxSize, "path", entry.Path) + return true + } return false } @@ -406,6 +412,12 @@ func WithKeepMaxAge(maxAge time.Duration) Option { } } +func WithKeepMaxSize(maxSize uint64) Option { + return func(w *Writer) { + w.pruneMaxSize = maxSize + } +} + // ============================== Clock ============================== type clock interface { diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index c484461..396eafd 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -121,6 +121,25 @@ func TestKeepMaxAge(t *testing.T) { assert.FileExists(root + "/logfile.2000-01-01-000003.txt") } +func TestKeepMaxSize(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + w, err := NewWriter(root+"/logfile.txt", WithMaxSize(5), WithKeepMaxSize(10), withDebug()) + assert.NoError(err) + + for range 4 { + assert.WriteOk(w, "foobar") + } + + assert.NoError(w.Close()) + + assert.NoFileExists(root + "/logfile.1.txt") + assert.NoFileExists(root + "/logfile.2.txt") + assert.FileExists(root + "/logfile.3.txt") + assert.FileExists(root + "/logfile.txt") +} + func TestMultiSyncClose(t *testing.T) { assert := NewFileAssert(t) root := t.TempDir() -- GitLab From 43af54887c6e53064b42d6267b7d68123ceff98e Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 16:58:55 +0100 Subject: [PATCH 13/28] fix(writer): do not reset file index when removing old files. --- lib/logging/writer/rotation.go | 27 +++++++++++++++++---------- lib/logging/writer/writer_test.go | 5 +++-- 2 files changed, 20 insertions(+), 12 deletions(-) diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index 221d235..bca058e 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -1,7 +1,7 @@ package writer import ( - "os" + "path/filepath" "strconv" "time" ) @@ -19,17 +19,24 @@ func (s SizeRotation) ShouldRotate(current, next uint64) bool { } func (s SizeRotation) PathSuffix(prefix, ext string) (string, error) { - if s > 0 { - for i := 1; true; i++ { - suffix := "." + strconv.Itoa(i) - if _, err := os.Stat(prefix + suffix + ext); os.IsNotExist(err) { - return suffix, nil - } else if err != nil { - return "", err - } + if s == 0 { + return "", nil + } + + existing, err := filepath.Glob(prefix + s.FileGlob() + ext) + if err != nil || len(existing) == 0 { + return ".1", err + } + + last, start, endOffset := 0, len(prefix)+1, len(ext) + for _, path := range existing { + last, err = strconv.Atoi(path[start : len(path)-endOffset]) + if err != nil { + return "", err } } - return "", nil + + return "." + strconv.Itoa(last+1), nil } func (s SizeRotation) FileGlob() string { diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 396eafd..34bd349 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -84,7 +84,7 @@ func TestKeepMaxCount(t *testing.T) { w, err := NewWriter(root+"/logfile.txt", WithMaxSize(5), WithKeepMaxCount(2), withDebug()) assert.NoError(err) - for range 5 { + for range 6 { assert.WriteOk(w, "foobar\n") } @@ -93,8 +93,9 @@ func TestKeepMaxCount(t *testing.T) { assert.FileExists(root + "/logfile.txt") assert.NoFileExists(root + "/logfile.1.txt") assert.NoFileExists(root + "/logfile.2.txt") - assert.FileExists(root + "/logfile.3.txt") + assert.NoFileExists(root + "/logfile.3.txt") assert.FileExists(root + "/logfile.4.txt") + assert.FileExists(root + "/logfile.5.txt") } func TestKeepMaxAge(t *testing.T) { -- GitLab From 0b7359b9dbc45516e59ab975c4d400d197721954 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 17:28:15 +0100 Subject: [PATCH 14/28] feat: add an option to compress archived log files. --- lib/logging/writer/writer.go | 72 ++++++++++++++++++++++++++++++- lib/logging/writer/writer_test.go | 22 +++++++++- 2 files changed, 90 insertions(+), 4 deletions(-) diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 3e01b79..9e535db 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -273,7 +273,12 @@ func (w *Writer) rotate() error { func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) error { for { select { - case <-archived: + case archive := <-archived: + if w.compression != nil { + if err := w.compression.Compress(archive); err != nil { + return fmt.Errorf("could not compress archived log file: %w", err) + } + } case <-ctx.Done(): return nil } @@ -290,7 +295,7 @@ func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) } func (w *Writer) needCleaner() bool { - return w.pruneMaxCount > 0 || w.pruneMaxAge > 0 || w.pruneMaxSize > 0 + return w.pruneMaxCount > 0 || w.pruneMaxAge > 0 || w.pruneMaxSize > 0 || w.compression != nil } func (w *Writer) listArchives() ([]fileEntry, error) { @@ -371,6 +376,7 @@ func (w *Writer) archiveGlob() string { prefix += w.timeRotation.FileGlob() prefix += w.sizeRotation.FileGlob() + ext += w.compression.FileGlob() return prefix + ext } @@ -418,6 +424,68 @@ func WithKeepMaxSize(maxSize uint64) Option { } } +func WithGZipCompression(levels ...int) Option { + level := gzip.DefaultCompression + if len(levels) > 0 { + level = levels[0] + } + return func(w *Writer) { + w.compression = gzipCompression(level) + } +} + +// ============================== Compression ============================== + +type Compression interface { + Compress(string) error + FileGlob() string +} + +type gzipCompression int + +var _ Compression = gzipCompression(gzip.DefaultCompression) + +// Compress implements Compression. +func (c gzipCompression) Compress(path string) error { + src, err := os.Open(path) + if err != nil { + slog.Error("could open source", "path", path, "err", err) + return err + } + defer src.Close() + + dest, err := os.OpenFile(path+".gz", os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0o777) + if err != nil { + slog.Error("could open dest", "path", path+".gz", "err", err) + return err + } + defer dest.Close() + + slog.Info("compressing", "src", src.Name(), "dest", dest.Name()) + + compressor, err := gzip.NewWriterLevel(dest, int(c)) + if err != nil { + slog.Error("could initialize compression", "level", int(c), "err", err) + return err + } + + if _, err = io.Copy(compressor, src); err != nil { + slog.Error("could initialize compression", "level", int(c), "err", err) + return err + } + + if err = src.Close(); err != nil { + return err + } + + return os.Remove(path) +} + +// FileGlob implements Compression. +func (n gzipCompression) FileGlob() string { + return ".gz" +} + // ============================== Clock ============================== type clock interface { diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 34bd349..32912fa 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -29,7 +29,7 @@ func TestSimpleWrite(t *testing.T) { assert.FileContent(filePath, "foobar") } -func TestWriteWithMaxSize(t *testing.T) { +func TestWriteSizeRotaton(t *testing.T) { assert := NewFileAssert(t) root := t.TempDir() @@ -48,7 +48,7 @@ func TestWriteWithMaxSize(t *testing.T) { assert.FileContent(root+"/logfile.2.txt", "foobar2\n") } -func TestWriteWithTimeRotation(t *testing.T) { +func TestWriteTimeRotation(t *testing.T) { assert := NewFileAssert(t) root := t.TempDir() @@ -141,6 +141,24 @@ func TestKeepMaxSize(t *testing.T) { assert.FileExists(root + "/logfile.txt") } +func TestWriteCompression(t *testing.T) { + assert := NewFileAssert(t) + root := t.TempDir() + + w, err := NewWriter(root+"/logfile.txt", WithMaxSize(5), WithGZipCompression(), withDebug()) + assert.NoError(err) + + assert.WriteOk(w, "foobar1\n") + assert.WriteOk(w, "foobar2\n") + assert.WriteOk(w, "foobar3\n") + + assert.NoError(w.Close()) + + assert.FileContent(root+"/logfile.txt", "foobar3\n") + assert.FileExists(root + "/logfile.1.txt.gz") + assert.FileExists(root + "/logfile.2.txt.gz") +} + func TestMultiSyncClose(t *testing.T) { assert := NewFileAssert(t) root := t.TempDir() -- GitLab From ffc5a57b0f27392e22f8329f900422808c46e34c Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 17:28:34 +0100 Subject: [PATCH 15/28] feat: enhance some error messages. --- lib/logging/writer/writer.go | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 9e535db..1ed6394 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -1,6 +1,7 @@ package writer import ( + "compress/gzip" "context" "errors" "fmt" @@ -22,6 +23,7 @@ import ( type Writer struct { path string + compression Compression sizeRotation SizeRotation timeRotation TimeRotation @@ -259,10 +261,10 @@ func (w *Writer) rotate() error { w.log.Debug("rotating file", "renameTo", renameTo) if err = os.Rename(w.path, renameTo); err != nil { - return err + return fmt.Errorf("could not archive log file: %w", err) } if err = os.Chtimes(renameTo, refTime, refTime); err != nil { - return err + return fmt.Errorf("could not set archive time: %w", err) } w.archived <- renameTo @@ -288,7 +290,7 @@ func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) } else if len(archives) > 0 { w.log.Debug("found archived files", "archives", archives) if err := w.prune(archives); err != nil { - return err + return fmt.Errorf("could not prune archived log files: %w", err) } } } @@ -301,7 +303,7 @@ func (w *Writer) needCleaner() bool { func (w *Writer) listArchives() ([]fileEntry, error) { paths, err := filepath.Glob(w.archiveGlob()) if err != nil { - return nil, err + return nil, fmt.Errorf("could not list archived log files: %w", err) } entries := make([]fileEntry, len(paths)) -- GitLab From 55b0c6529445db0d10f99eb7b459890aed2e767d Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 18:21:33 +0100 Subject: [PATCH 16/28] refactor: break the writer into smaller parts. --- lib/logging/writer/background.go | 198 +++++++++++++++ lib/logging/writer/cleaner.go | 122 ++++++++++ lib/logging/writer/clock.go | 20 ++ lib/logging/writer/config.go | 115 +++++++++ lib/logging/writer/writer.go | 386 ++---------------------------- lib/logging/writer/writer_test.go | 6 +- 6 files changed, 483 insertions(+), 364 deletions(-) create mode 100644 lib/logging/writer/background.go create mode 100644 lib/logging/writer/cleaner.go create mode 100644 lib/logging/writer/clock.go create mode 100644 lib/logging/writer/config.go diff --git a/lib/logging/writer/background.go b/lib/logging/writer/background.go new file mode 100644 index 0000000..ab15480 --- /dev/null +++ b/lib/logging/writer/background.go @@ -0,0 +1,198 @@ +package writer + +import ( + "context" + "errors" + "fmt" + "log/slog" + "os" + "time" +) + +type BackgroundWriter struct { + path string + pathPrefix string + pathExt string + + file *os.File + size uint64 + lastModTime time.Time + + sizeRotation SizeRotation + timeRotation TimeRotation + archived chan<- string + + log *slog.Logger + clock Clock +} + +func NewBackgroundWriter(c Config, archived chan<- string) *BackgroundWriter { + prefix, ext := c.SplitPath() + return &BackgroundWriter{ + path: c.Path, + pathPrefix: prefix, + pathExt: ext, + sizeRotation: c.SizeRotation, + timeRotation: c.TimeRotation, + archived: archived, + log: c.log, + clock: c.clock, + } +} + +func (w *BackgroundWriter) run(ctx context.Context, reqs <-chan writeRequest) (err error) { + defer func() { + err = errors.Join(err, w.closeFile()) + }() + + for { + select { + case <-w.timeRotation.Next(w.clock.Now()): + w.log.Debug("rotation timer expired") + if w.shouldRotate(0) { + if err := w.rotate(); err != nil { + return err + } + } + case req := <-reqs: + if err := w.handleRequest(req); err != nil { + return err + } + case <-ctx.Done(): + for { + select { + case req := <-reqs: + req.reply(0, os.ErrClosed) + default: + return nil + } + } + } + } +} + +func (w *BackgroundWriter) handleRequest(req writeRequest) (err error) { + var written uint64 + defer func() { + w.size += written + w.lastModTime = w.clock.Now() + if p := recover(); p != nil { + err = errors.Join(err, fmt.Errorf("recovered panic: %v", p)) + } + req.reply(written, err) + }() + + toWrite := uint64(len(req.data)) + if w.shouldRotate(toWrite) { + if err := w.rotate(); err != nil { + return err + } + } + + if toWrite == 0 { + return nil + } + + if err := w.openFile(); err != nil { + return err + } + + var n int + for err == nil && written < toWrite { + n, err = w.file.Write([]byte(req.data)[written:]) + written += uint64(n) + } + + return nil +} + +func (w *BackgroundWriter) openFile() error { + if w.file != nil { + return nil + } + + var err error + w.file, err = os.OpenFile(w.path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777) + if err != nil { + w.log.Error("could not open file", "err", err) + return err + } + + info, err := w.file.Stat() + if err != nil { + return err + } + w.size = uint64(info.Size()) + w.lastModTime = w.clock.Now() + + w.log.Debug("opened file for writing", "size", w.size, "modTime", w.lastModTime) + return err +} + +func (w *BackgroundWriter) closeFile() error { + if w.file == nil { + return nil + } + + err := w.file.Close() + if err != nil { + w.log.Error("error closing file", "err", err) + } else { + w.log.Debug("closed file") + } + w.file = nil + return err +} + +func (w *BackgroundWriter) shouldRotate(toWrite uint64) bool { + if w.sizeRotation.ShouldRotate(w.size, w.size+toWrite) { + w.log.Debug("size-based rotation", "size", w.size+toWrite) + return true + } + if now := w.clock.Now(); w.timeRotation.ShouldRotate(w.lastModTime, now) { + w.log.Debug("time-based rotation", "previous", w.lastModTime, "now", now) + return true + } + return false +} + +func (w *BackgroundWriter) rotate() error { + if w.file == nil { + return nil + } + + if err := w.closeFile(); err != nil { + return err + } + + refTime := w.lastModTime + archivePath, err := w.newArchivePath(refTime) + if err != nil { + return err + } + + w.log.Debug("rotating file", "archivePath", archivePath) + if err = os.Rename(w.path, archivePath); err != nil { + return fmt.Errorf("could not archive log file: %w", err) + } + if err = os.Chtimes(archivePath, refTime, refTime); err != nil { + return fmt.Errorf("could not set archive time: %w", err) + } + + if w.archived != nil { + w.archived <- archivePath + } + + return nil +} + +func (w *BackgroundWriter) newArchivePath(when time.Time) (string, error) { + prefix := w.pathPrefix + w.timeRotation.PathSuffix(when) + if sizeSuffix, err := w.sizeRotation.PathSuffix(prefix, w.pathExt); err == nil { + prefix += sizeSuffix + } else { + return "", err + } + + return prefix + w.pathExt, nil +} diff --git a/lib/logging/writer/cleaner.go b/lib/logging/writer/cleaner.go new file mode 100644 index 0000000..5002017 --- /dev/null +++ b/lib/logging/writer/cleaner.go @@ -0,0 +1,122 @@ +package writer + +import ( + "context" + "fmt" + "log/slog" + "os" + "path/filepath" + "slices" + "strings" + "time" +) + +type Cleaner struct { + archiveGlob string + + compression Compression + + maxAge time.Duration + maxCount uint + maxSize uint64 + + log *slog.Logger + clock Clock +} + +func NewCleaner(cfg Config) *Cleaner { + return &Cleaner{ + archiveGlob: cfg.archiveGlob(), + compression: cfg.Compression, + maxAge: cfg.MaxAge, + maxCount: cfg.MaxCount, + maxSize: cfg.MaxSize, + log: cfg.log, + clock: cfg.clock, + } +} + +func (c *Cleaner) run(ctx context.Context, archived <-chan string) error { + for { + select { + case archive := <-archived: + if c.compression != nil { + if err := c.compression.Compress(archive); err != nil { + return fmt.Errorf("could not compress archived log file: %w", err) + } + } + case <-ctx.Done(): + return nil + } + + if archives, err := c.listArchives(); err != nil { + return err + } else if len(archives) > 0 { + c.log.Debug("found archived files", "archives", archives) + if err := c.prune(archives); err != nil { + return fmt.Errorf("could not prune archived log files: %w", err) + } + } + } +} + +func (c *Cleaner) listArchives() ([]fileEntry, error) { + paths, err := filepath.Glob(c.archiveGlob) + if err != nil { + return nil, fmt.Errorf("could not list archived log files: %w", err) + } + + entries := make([]fileEntry, len(paths)) + for i, p := range paths { + if info, err := os.Stat(p); err == nil { + entries[i] = fileEntry{p, info} + } else { + return nil, err + } + } + + slices.SortStableFunc(entries, func(a, b fileEntry) int { + if delta := b.ModTime().Compare(a.ModTime()); delta != 0 { + return delta + } else { + return strings.Compare(b.Path, a.Path) + } + }) + + return entries, nil +} + +func (c *Cleaner) prune(archives []fileEntry) error { + var totalSize uint64 + for i, entry := range archives { + totalSize += uint64(entry.Size()) + if c.shouldPrune(i, entry, totalSize) { + if err := entry.Remove(); err != nil { + return fmt.Errorf("could not remove archived logfile: %w", err) + } else { + c.log.Debug("removed archived file", "archive", entry.Path) + } + } + } + return nil +} + +func (c *Cleaner) shouldPrune(index int, entry fileEntry, totalSize uint64) bool { + if c.maxCount > 0 && uint(index) >= c.maxCount { + c.log.Debug("file index exceeds the limit", "index", index, "limit", c.maxCount, "path", entry.Path) + return true + } + + age := c.clock.Now().Sub(entry.ModTime()) + if c.maxAge > 0 && age > c.maxAge { + c.log.Debug("file age exceeds the limit", "age", age, "limit", c.maxAge, "path", entry.Path) + return true + } + + if c.maxSize > 0 && totalSize > c.maxSize { + c.log.Debug("total size exceeds the limit", "totalSize", totalSize, "limit", c.maxSize, "path", entry.Path) + return true + } + + return false +} diff --git a/lib/logging/writer/clock.go b/lib/logging/writer/clock.go new file mode 100644 index 0000000..e2d3c73 --- /dev/null +++ b/lib/logging/writer/clock.go @@ -0,0 +1,20 @@ +package writer + +import "time" + +// ============================== Clock ============================== + +type Clock interface { + Now() time.Time +} + +type timeClock struct { + location *time.Location +} + +var DefaultClock Clock = timeClock{time.Local} + +// Now implements Clock. +func (s timeClock) Now() time.Time { + return time.Now().In(s.location) +} diff --git a/lib/logging/writer/config.go b/lib/logging/writer/config.go new file mode 100644 index 0000000..6506ee5 --- /dev/null +++ b/lib/logging/writer/config.go @@ -0,0 +1,115 @@ +package writer + +import ( + "compress/gzip" + "log/slog" + "path" + "time" +) + +// ============================== Config ============================== + +type Config struct { + Path string + + SizeRotation SizeRotation + TimeRotation TimeRotation + + Compression Compression + + MaxAge time.Duration + MaxCount uint + MaxSize uint64 + + log *slog.Logger + clock Clock +} + +func DefaultConfig(path string) Config { + return Config{ + Path: path, + TimeRotation: ROTATE_NEVER, + log: DefaultLogger, + clock: DefaultClock, + } +} + +func (c *Config) Apply(options ...Option) { + for _, option := range options { + option(c) + } +} + +func (c Config) needCleaner() bool { + return c.Compression != nil || c.MaxAge > 0 || c.MaxCount > 0 || c.MaxSize > 0 +} + +func (c Config) SplitPath() (prefix, ext string) { + ext = path.Ext(c.Path) + return c.Path[:len(c.Path)-len(ext)], ext +} + +func (c Config) archiveGlob() string { + prefix, ext := c.SplitPath() + + prefix += c.TimeRotation.FileGlob() + prefix += c.SizeRotation.FileGlob() + if c.Compression != nil { + ext += c.Compression.FileGlob() + } + + return prefix + ext +} + +// ============================== Option ============================== + +type Option func(c *Config) + +func WithMaxSize(maxSize uint64) Option { + return func(w *Config) { + w.SizeRotation = SizeRotation(maxSize) + } +} + +func WithLogger(logger *slog.Logger) Option { + return func(w *Config) { + w.log = logger + } +} + +func WithTimeRotation(timeRotation TimeRotation) Option { + return func(w *Config) { + w.TimeRotation = timeRotation + } +} + +func WithKeepMaxCount(maxCount uint) Option { + return func(w *Config) { + w.MaxCount = maxCount + } +} + +func WithKeepMaxAge(maxAge time.Duration) Option { + if maxAge < 0 { + panic("negative maxAge") + } + return func(w *Config) { + w.MaxAge = maxAge + } +} + +func WithKeepMaxSize(maxSize uint64) Option { + return func(w *Config) { + w.MaxSize = maxSize + } +} + +func WithGZipCompression(levels ...int) Option { + level := gzip.DefaultCompression + if len(levels) > 0 { + level = levels[0] + } + return func(w *Config) { + w.Compression = gzipCompression(level) + } +} diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 1ed6394..9fd6824 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -3,16 +3,10 @@ package writer import ( "compress/gzip" "context" - "errors" "fmt" "io" - "io/fs" "log/slog" "os" - "path" - "path/filepath" - "slices" - "strings" "sync" "time" ) @@ -23,26 +17,14 @@ import ( type Writer struct { path string - compression Compression - sizeRotation SizeRotation - timeRotation TimeRotation - - pruneMaxCount uint - pruneMaxAge time.Duration - pruneMaxSize uint64 - reqs chan<- writeRequest archived chan<- string ctx context.Context stop context.CancelCauseFunc wg sync.WaitGroup - file *os.File - size uint64 - lastModTime time.Time - log *slog.Logger - clock clock + clock Clock } type writeRequest struct { @@ -68,44 +50,45 @@ type writeResponse struct { var _ io.WriteCloser = (*Writer)(nil) +var DefaultLogger = slog.New(slog.DiscardHandler) + func NewWriter(path string, options ...Option) (*Writer, error) { + c := DefaultConfig(path) + c.Apply(options...) + reqs := make(chan writeRequest) - archived := make(chan string, 20) ctx, stop := context.WithCancelCause(context.Background()) w := &Writer{ - path: path, - reqs: reqs, - archived: archived, - ctx: ctx, - log: slog.New(slog.DiscardHandler), - clock: sysClock(0), - stop: stop, - timeRotation: ROTATE_NEVER, + reqs: reqs, + ctx: ctx, + log: c.log.With("logfile", path), + clock: c.clock, + stop: stop, } - for _, opt := range options { - opt(w) - } - w.log = w.log.With("logfile", path) - w.wg.Add(1) - go func() { - defer w.wg.Done() - if err := w.backgroundWriter(ctx, reqs); err != nil { - stop(err) - } - }() - - if w.needCleaner() { + var archived chan string + if c.needCleaner() { + archived = make(chan string, 20) w.wg.Add(1) go func() { defer w.wg.Done() - if err := w.backgroundCleaner(ctx, archived); err != nil { + cleaner := NewCleaner(c) + if err := cleaner.run(ctx, archived); err != nil { stop(err) } }() } + w.wg.Add(1) + go func() { + defer w.wg.Done() + b := NewBackgroundWriter(c, archived) + if err := b.run(ctx, reqs); err != nil { + stop(err) + } + }() + return w, nil } @@ -132,310 +115,6 @@ func (w *Writer) Close() error { return nil } -func (w *Writer) backgroundWriter(ctx context.Context, reqs <-chan writeRequest) (err error) { - defer func() { - err = errors.Join(err, w.closeFile()) - }() - - for { - select { - case <-w.timeRotation.Next(w.clock.Now()): - w.log.Debug("rotation timer expired") - if w.shouldRotate(0) { - if err := w.rotate(); err != nil { - return err - } - } - case req := <-reqs: - if err := w.handleRequest(req); err != nil { - return err - } - case <-ctx.Done(): - for { - select { - case req := <-reqs: - req.reply(0, fs.ErrClosed) - default: - return nil - } - } - } - } -} - -func (w *Writer) handleRequest(req writeRequest) (err error) { - var written uint64 - defer func() { - w.size += written - w.lastModTime = w.clock.Now() - if p := recover(); p != nil { - err = errors.Join(err, fmt.Errorf("recoverd panic: %v", p)) - } - req.reply(written, err) - }() - - toWrite := uint64(len(req.data)) - if w.shouldRotate(toWrite) { - if err := w.rotate(); err != nil { - return err - } - } - - if toWrite == 0 { - return nil - } - - if w.file == nil { - if err := w.openFile(); err != nil { - return err - } - } - - var n int - for err == nil && written < toWrite { - n, err = w.file.Write([]byte(req.data)[written:]) - written += uint64(n) - } - - return nil -} - -func (w *Writer) openFile() error { - var err error - w.file, err = os.OpenFile(w.path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o777) - if err != nil { - w.log.Error("could not open file", "err", err) - return err - } - info, err := w.file.Stat() - if err != nil { - return err - } - - w.size = uint64(info.Size()) - w.lastModTime = w.clock.Now() - w.log.Debug("opened file for writing", "size", w.size, "modTime", w.lastModTime) - return err -} - -func (w *Writer) closeFile() error { - if w.file == nil { - return nil - } - err := w.file.Close() - if err != nil { - w.log.Error("error closing file", "err", err) - } else { - w.log.Debug("closed file") - } - w.file = nil - return err -} - -func (w *Writer) shouldRotate(toWrite uint64) bool { - if w.sizeRotation.ShouldRotate(w.size, w.size+toWrite) { - w.log.Debug("size-based rotation", "size", w.size+toWrite) - return true - } - if now := w.clock.Now(); w.timeRotation.ShouldRotate(w.lastModTime, now) { - w.log.Debug("time-based rotation", "previous", w.lastModTime, "now", now) - return true - } - return false -} - -func (w *Writer) rotate() error { - if w.file == nil { - return nil - } - - if err := w.closeFile(); err != nil { - return err - } - - refTime := w.lastModTime - renameTo, err := w.newArchivePath(refTime) - if err != nil { - return err - } - - w.log.Debug("rotating file", "renameTo", renameTo) - if err = os.Rename(w.path, renameTo); err != nil { - return fmt.Errorf("could not archive log file: %w", err) - } - if err = os.Chtimes(renameTo, refTime, refTime); err != nil { - return fmt.Errorf("could not set archive time: %w", err) - } - - w.archived <- renameTo - - return nil -} - -func (w *Writer) backgroundCleaner(ctx context.Context, archived <-chan string) error { - for { - select { - case archive := <-archived: - if w.compression != nil { - if err := w.compression.Compress(archive); err != nil { - return fmt.Errorf("could not compress archived log file: %w", err) - } - } - case <-ctx.Done(): - return nil - } - - if archives, err := w.listArchives(); err != nil { - return err - } else if len(archives) > 0 { - w.log.Debug("found archived files", "archives", archives) - if err := w.prune(archives); err != nil { - return fmt.Errorf("could not prune archived log files: %w", err) - } - } - } -} - -func (w *Writer) needCleaner() bool { - return w.pruneMaxCount > 0 || w.pruneMaxAge > 0 || w.pruneMaxSize > 0 || w.compression != nil -} - -func (w *Writer) listArchives() ([]fileEntry, error) { - paths, err := filepath.Glob(w.archiveGlob()) - if err != nil { - return nil, fmt.Errorf("could not list archived log files: %w", err) - } - - entries := make([]fileEntry, len(paths)) - for i, p := range paths { - if info, err := os.Stat(p); err == nil { - entries[i] = fileEntry{p, info} - } else { - return nil, err - } - } - - slices.SortStableFunc(entries, func(a, b fileEntry) int { - if delta := b.ModTime().Compare(a.ModTime()); delta != 0 { - return delta - } else { - return strings.Compare(b.Path, a.Path) - } - }) - - return entries, nil -} - -func (w *Writer) prune(archives []fileEntry) error { - var totalSize uint64 - for i, entry := range archives { - totalSize += uint64(entry.Size()) - if w.shouldPrune(i, entry, totalSize) { - if err := entry.Remove(); err != nil { - return fmt.Errorf("could not remove archived logfile: %w", err) - } else { - w.log.Debug("removed archived file", "archive", entry.Path) - } - } - } - return nil -} - -func (w *Writer) shouldPrune(index int, entry fileEntry, totalSize uint64) bool { - if w.pruneMaxCount > 0 && uint(index) >= w.pruneMaxCount { - w.log.Debug("file index exceeds the limit", "index", index, "limit", w.pruneMaxCount, "path", entry.Path) - return true - } - age := w.clock.Now().Sub(entry.ModTime()) - if w.pruneMaxAge > 0 && age > w.pruneMaxAge { - w.log.Debug("file age exceeds the limit", "age", age, "limit", w.pruneMaxAge, "path", entry.Path) - return true - } - if w.pruneMaxSize > 0 && totalSize > w.pruneMaxSize { - w.log.Debug("total size exceeds the limit", "totalSize", totalSize, "limit", w.pruneMaxSize, "path", entry.Path) - return true - } - return false -} - -func (w *Writer) newArchivePath(when time.Time) (string, error) { - ext := path.Ext(w.path) - prefix := w.path[:len(w.path)-len(ext)] - - prefix += w.timeRotation.PathSuffix(when) - if sizeSuffix, err := w.sizeRotation.PathSuffix(prefix, ext); err == nil { - prefix += sizeSuffix - } else { - return "", err - } - - return prefix + ext, nil -} - -func (w *Writer) archiveGlob() string { - ext := path.Ext(w.path) - prefix := w.path[:len(w.path)-len(ext)] - - prefix += w.timeRotation.FileGlob() - prefix += w.sizeRotation.FileGlob() - ext += w.compression.FileGlob() - - return prefix + ext -} - -// ============================== ConfigOption ============================== - -type Option func(c *Writer) - -func WithMaxSize(maxSize uint64) Option { - return func(w *Writer) { - w.sizeRotation = SizeRotation(maxSize) - } -} - -func WithLogger(logger *slog.Logger) Option { - return func(w *Writer) { - w.log = logger - } -} - -func WithTimeRotation(timeRotation TimeRotation) Option { - return func(w *Writer) { - w.timeRotation = timeRotation - } -} - -func WithKeepMaxCount(maxCount uint) Option { - return func(w *Writer) { - w.pruneMaxCount = maxCount - } -} - -func WithKeepMaxAge(maxAge time.Duration) Option { - if maxAge < 0 { - panic("negative maxAge") - } - return func(w *Writer) { - w.pruneMaxAge = maxAge - } -} - -func WithKeepMaxSize(maxSize uint64) Option { - return func(w *Writer) { - w.pruneMaxSize = maxSize - } -} - -func WithGZipCompression(levels ...int) Option { - level := gzip.DefaultCompression - if len(levels) > 0 { - level = levels[0] - } - return func(w *Writer) { - w.compression = gzipCompression(level) - } -} - // ============================== Compression ============================== type Compression interface { @@ -488,21 +167,6 @@ func (n gzipCompression) FileGlob() string { return ".gz" } -// ============================== Clock ============================== - -type clock interface { - Now() time.Time -} - -type sysClock int - -var _ clock = sysClock(0) - -// Now implements Clock. -func (s sysClock) Now() time.Time { - return time.Now() -} - // ============================== fileEntry ============================== type fileEntry struct { diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 32912fa..50d8c29 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -235,7 +235,7 @@ type testClock struct { l sync.Mutex } -var _ clock = (*testClock)(nil) +var _ Clock = (*testClock)(nil) func newTestClock(t *testing.T) *testClock { return &testClock{t: t} @@ -304,8 +304,8 @@ func withDebug() Option { return WithLogger(slog.New(tint.NewHandler(os.Stdout, &tint.Options{Level: slog.LevelDebug, TimeFormat: time.TimeOnly, AddSource: true}))) } -func withClock(c clock) Option { - return func(w *Writer) { +func withClock(c Clock) Option { + return func(w *Config) { w.clock = c } } -- GitLab From 2b6f33eadfa32d61caa382ce75518f4da5732366 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Mon, 24 Mar 2025 19:39:59 +0100 Subject: [PATCH 17/28] refactor: extract compression, rotation and pruning strategies. --- lib/logging/writer/background.go | 47 +++--- lib/logging/writer/cleaner.go | 98 ++++++------ lib/logging/writer/compression.go | 87 +++++++++++ lib/logging/writer/config.go | 69 ++++----- lib/logging/writer/pruning.go | 118 ++++++++++++++ lib/logging/writer/rotation.go | 247 ++++++++++++++++++++++++------ lib/logging/writer/writer.go | 73 --------- lib/logging/writer/writer_test.go | 30 ++-- 8 files changed, 530 insertions(+), 239 deletions(-) create mode 100644 lib/logging/writer/compression.go create mode 100644 lib/logging/writer/pruning.go diff --git a/lib/logging/writer/background.go b/lib/logging/writer/background.go index ab15480..b0c1542 100644 --- a/lib/logging/writer/background.go +++ b/lib/logging/writer/background.go @@ -18,9 +18,8 @@ type BackgroundWriter struct { size uint64 lastModTime time.Time - sizeRotation SizeRotation - timeRotation TimeRotation - archived chan<- string + rotation RotationStrategy + archived chan<- string log *slog.Logger clock Clock @@ -29,14 +28,13 @@ type BackgroundWriter struct { func NewBackgroundWriter(c Config, archived chan<- string) *BackgroundWriter { prefix, ext := c.SplitPath() return &BackgroundWriter{ - path: c.Path, - pathPrefix: prefix, - pathExt: ext, - sizeRotation: c.SizeRotation, - timeRotation: c.TimeRotation, - archived: archived, - log: c.log, - clock: c.clock, + path: c.Path, + pathPrefix: prefix, + pathExt: ext, + rotation: c.Rotation, + archived: archived, + log: c.log, + clock: c.clock, } } @@ -47,7 +45,7 @@ func (w *BackgroundWriter) run(ctx context.Context, reqs <-chan writeRequest) (e for { select { - case <-w.timeRotation.Next(w.clock.Now()): + case <-w.rotation.Next(w.clock.Now()): w.log.Debug("rotation timer expired") if w.shouldRotate(0) { if err := w.rotate(); err != nil { @@ -61,8 +59,12 @@ func (w *BackgroundWriter) run(ctx context.Context, reqs <-chan writeRequest) (e case <-ctx.Done(): for { select { - case req := <-reqs: - req.reply(0, os.ErrClosed) + case req, open := <-reqs: + if open { + req.reply(0, os.ErrClosed) + } else { + return nil + } default: return nil } @@ -145,15 +147,7 @@ func (w *BackgroundWriter) closeFile() error { } func (w *BackgroundWriter) shouldRotate(toWrite uint64) bool { - if w.sizeRotation.ShouldRotate(w.size, w.size+toWrite) { - w.log.Debug("size-based rotation", "size", w.size+toWrite) - return true - } - if now := w.clock.Now(); w.timeRotation.ShouldRotate(w.lastModTime, now) { - w.log.Debug("time-based rotation", "previous", w.lastModTime, "now", now) - return true - } - return false + return w.rotation.ShouldRotate(w.lastModTime, w.clock.Now(), w.size, w.size+toWrite) } func (w *BackgroundWriter) rotate() error { @@ -187,12 +181,9 @@ func (w *BackgroundWriter) rotate() error { } func (w *BackgroundWriter) newArchivePath(when time.Time) (string, error) { - prefix := w.pathPrefix + w.timeRotation.PathSuffix(when) - if sizeSuffix, err := w.sizeRotation.PathSuffix(prefix, w.pathExt); err == nil { - prefix += sizeSuffix + if suffix, err := w.rotation.PathSuffix(w.pathPrefix, w.pathExt, when); err == nil { + return w.pathPrefix + suffix + w.pathExt, nil } else { return "", err } - - return prefix + w.pathExt, nil } diff --git a/lib/logging/writer/cleaner.go b/lib/logging/writer/cleaner.go index 5002017..fca3b16 100644 --- a/lib/logging/writer/cleaner.go +++ b/lib/logging/writer/cleaner.go @@ -11,42 +11,39 @@ import ( "time" ) -type Cleaner struct { +// ============================== Cleaner ============================== + +type cleaner struct { archiveGlob string compression Compression - maxAge time.Duration - maxCount uint - maxSize uint64 + pruning PruningStrategy log *slog.Logger clock Clock } -func NewCleaner(cfg Config) *Cleaner { - return &Cleaner{ - archiveGlob: cfg.archiveGlob(), - compression: cfg.Compression, - maxAge: cfg.MaxAge, - maxCount: cfg.MaxCount, - maxSize: cfg.MaxSize, - log: cfg.log, - clock: cfg.clock, +func NewCleaner(c Config) *cleaner { + return &cleaner{ + archiveGlob: c.archiveGlob(), + compression: c.Compression, + pruning: c.Pruning, + log: c.log, + clock: c.clock, } } -func (c *Cleaner) run(ctx context.Context, archived <-chan string) error { - for { +func (c *cleaner) run(ctx context.Context, archived <-chan string) error { + ever := true + for ever { select { case archive := <-archived: - if c.compression != nil { - if err := c.compression.Compress(archive); err != nil { - return fmt.Errorf("could not compress archived log file: %w", err) - } + if err := c.compression.Compress(archive); err != nil { + return fmt.Errorf("could not compress archived log file: %w", err) } case <-ctx.Done(): - return nil + ever = false } if archives, err := c.listArchives(); err != nil { @@ -58,25 +55,25 @@ func (c *Cleaner) run(ctx context.Context, archived <-chan string) error { } } } + + return nil } -func (c *Cleaner) listArchives() ([]fileEntry, error) { +func (c *cleaner) listArchives() ([]ArchivedFile, error) { paths, err := filepath.Glob(c.archiveGlob) if err != nil { return nil, fmt.Errorf("could not list archived log files: %w", err) } - entries := make([]fileEntry, len(paths)) + entries := make([]ArchivedFile, len(paths)) for i, p := range paths { - if info, err := os.Stat(p); err == nil { - entries[i] = fileEntry{p, info} - } else { + if entries[i], err = newArchivedFile(p, c.clock); err != nil { return nil, err } } - slices.SortStableFunc(entries, func(a, b fileEntry) int { - if delta := b.ModTime().Compare(a.ModTime()); delta != 0 { + slices.SortStableFunc(entries, func(a, b ArchivedFile) int { + if delta := b.ModTime.Compare(a.ModTime); delta != 0 { return delta } else { return strings.Compare(b.Path, a.Path) @@ -86,11 +83,11 @@ func (c *Cleaner) listArchives() ([]fileEntry, error) { return entries, nil } -func (c *Cleaner) prune(archives []fileEntry) error { +func (c *cleaner) prune(archives []ArchivedFile) error { var totalSize uint64 for i, entry := range archives { - totalSize += uint64(entry.Size()) - if c.shouldPrune(i, entry, totalSize) { + totalSize += uint64(entry.Size) + if c.pruning.ShouldPrune(i, entry, totalSize) { if err := entry.Remove(); err != nil { return fmt.Errorf("could not remove archived logfile: %w", err) } else { @@ -101,22 +98,35 @@ func (c *Cleaner) prune(archives []fileEntry) error { return nil } -func (c *Cleaner) shouldPrune(index int, entry fileEntry, totalSize uint64) bool { - if c.maxCount > 0 && uint(index) >= c.maxCount { - c.log.Debug("file index exceeds the limit", "index", index, "limit", c.maxCount, "path", entry.Path) - return true - } +// ============================== ArchivedFile ============================== - age := c.clock.Now().Sub(entry.ModTime()) - if c.maxAge > 0 && age > c.maxAge { - c.log.Debug("file age exceeds the limit", "age", age, "limit", c.maxAge, "path", entry.Path) - return true - } +type ArchivedFile struct { + Path string + Size uint64 + ModTime time.Time + Age time.Duration +} + +var _ fmt.Stringer = ArchivedFile{} - if c.maxSize > 0 && totalSize > c.maxSize { - c.log.Debug("total size exceeds the limit", "totalSize", totalSize, "limit", c.maxSize, "path", entry.Path) - return true +func newArchivedFile(p string, clock Clock) (ArchivedFile, error) { + info, err := os.Stat(p) + if err != nil { + return ArchivedFile{}, err } + return ArchivedFile{ + Path: p, + Size: uint64(info.Size()), + ModTime: info.ModTime(), + Age: clock.Now().Sub(info.ModTime()), + }, nil +} + +func (f ArchivedFile) Remove() error { + return os.Remove(f.Path) +} - return false +// LogValue implements slog.LogValuer. +func (f ArchivedFile) String() string { + return fmt.Sprintf("%s(%d bytes, %s)", f.Path, f.Size, f.ModTime.Format(time.RFC3339)) } diff --git a/lib/logging/writer/compression.go b/lib/logging/writer/compression.go new file mode 100644 index 0000000..aede3ae --- /dev/null +++ b/lib/logging/writer/compression.go @@ -0,0 +1,87 @@ +package writer + +import ( + "compress/gzip" + "fmt" + "io" + "os" +) + +// ============================== Compression ============================== + +type Compression interface { + Compress(string) error + FileGlob() string + IsEnabled() bool +} + +// ============================== noCompression ============================== + +type noCompression int + +var NoCompression Compression = noCompression(0) + +// Compress implements Compression. +func (noCompression) Compress(string) error { + return nil +} + +// FileGlob implements Compression. +func (noCompression) FileGlob() string { + return "" +} + +// FileGlob implements Compression. +func (noCompression) IsEnabled() bool { + return false +} + +// ============================== gzipCompression ============================== + +type GzipCompression int + +var _ Compression = GzipCompression(gzip.DefaultCompression) + +// Compress implements Compression. +func (c GzipCompression) Compress(path string) error { + src, err := os.Open(path) + if err != nil { + return fmt.Errorf("could not open file to compress: %w", err) + } + defer src.Close() + + dest, err := os.OpenFile(path+".gz", os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0o777) + if err != nil { + return fmt.Errorf("could not open compressed file: %w", err) + } + defer dest.Close() + + compressor, err := gzip.NewWriterLevel(dest, int(c)) + if err != nil { + return fmt.Errorf("could not initialize compressor: %w", err) + } + + if _, err = io.Copy(compressor, src); err != nil { + return fmt.Errorf("error while compressing: %w", err) + } + + if err = src.Close(); err != nil { + return fmt.Errorf("error closing compressed file: %w", err) + } + + if err = os.Remove(path); err != nil { + return fmt.Errorf("could not remove the source of the compressed file: %w", err) + } + + return nil +} + +// FileGlob implements Compression. +func (GzipCompression) FileGlob() string { + return ".gz" +} + +// FileGlob implements Compression. +func (GzipCompression) IsEnabled() bool { + return true +} diff --git a/lib/logging/writer/config.go b/lib/logging/writer/config.go index 6506ee5..f3bcbf5 100644 --- a/lib/logging/writer/config.go +++ b/lib/logging/writer/config.go @@ -10,16 +10,10 @@ import ( // ============================== Config ============================== type Config struct { - Path string - - SizeRotation SizeRotation - TimeRotation TimeRotation - + Path string + Rotation RotationStrategy Compression Compression - - MaxAge time.Duration - MaxCount uint - MaxSize uint64 + Pruning PruningStrategy log *slog.Logger clock Clock @@ -27,10 +21,12 @@ type Config struct { func DefaultConfig(path string) Config { return Config{ - Path: path, - TimeRotation: ROTATE_NEVER, - log: DefaultLogger, - clock: DefaultClock, + Path: path, + Rotation: NoRotation, + Compression: NoCompression, + Pruning: NoPruning, + log: DefaultLogger, + clock: DefaultClock, } } @@ -41,7 +37,7 @@ func (c *Config) Apply(options ...Option) { } func (c Config) needCleaner() bool { - return c.Compression != nil || c.MaxAge > 0 || c.MaxCount > 0 || c.MaxSize > 0 + return c.Compression.IsEnabled() || c.Pruning.IsEnabled() } func (c Config) SplitPath() (prefix, ext string) { @@ -51,56 +47,59 @@ func (c Config) SplitPath() (prefix, ext string) { func (c Config) archiveGlob() string { prefix, ext := c.SplitPath() - - prefix += c.TimeRotation.FileGlob() - prefix += c.SizeRotation.FileGlob() - if c.Compression != nil { - ext += c.Compression.FileGlob() - } - - return prefix + ext + return prefix + c.Rotation.FileGlob() + ext + c.Compression.FileGlob() } // ============================== Option ============================== type Option func(c *Config) -func WithMaxSize(maxSize uint64) Option { +func WithLogger(logger *slog.Logger) Option { + if logger == nil { + panic("logger is nil") + } return func(w *Config) { - w.SizeRotation = SizeRotation(maxSize) + w.log = logger } } -func WithLogger(logger *slog.Logger) Option { +func WithRotation(rotation RotationStrategy) Option { return func(w *Config) { - w.log = logger + w.Rotation = ComposeRotationStrategy(w.Rotation, rotation) } } -func WithTimeRotation(timeRotation TimeRotation) Option { - return func(w *Config) { - w.TimeRotation = timeRotation +func WithMaxSize(maxSize uint64) Option { + if maxSize == 0 { + panic("file size limit is zero") } + return WithRotation(SizeRotation(maxSize)) } func WithKeepMaxCount(maxCount uint) Option { + if maxCount == 0 { + panic("max count limit is zero") + } return func(w *Config) { - w.MaxCount = maxCount + w.Pruning = ComposePruningStrategy(w.Pruning, MaxCountPruning(maxCount)) } } func WithKeepMaxAge(maxAge time.Duration) Option { - if maxAge < 0 { - panic("negative maxAge") + if maxAge <= 0 { + panic("max age limit is zero or negative") } return func(w *Config) { - w.MaxAge = maxAge + w.Pruning = ComposePruningStrategy(w.Pruning, MaxAgePruning(maxAge)) } } func WithKeepMaxSize(maxSize uint64) Option { + if maxSize == 0 { + panic("total size limit is zero") + } return func(w *Config) { - w.MaxSize = maxSize + w.Pruning = ComposePruningStrategy(w.Pruning, MaxSizePruning(maxSize)) } } @@ -110,6 +109,6 @@ func WithGZipCompression(levels ...int) Option { level = levels[0] } return func(w *Config) { - w.Compression = gzipCompression(level) + w.Compression = GzipCompression(level) } } diff --git a/lib/logging/writer/pruning.go b/lib/logging/writer/pruning.go new file mode 100644 index 0000000..5db5ccf --- /dev/null +++ b/lib/logging/writer/pruning.go @@ -0,0 +1,118 @@ +package writer + +import ( + "time" +) + +// ============================== Cleaner ============================== + +type PruningStrategy interface { + ShouldPrune(index int, entry ArchivedFile, totalSize uint64) bool + IsEnabled() bool +} + +// ============================== NoPruning ============================== + +type noPruning int + +var NoPruning PruningStrategy = noPruning(0) + +// ShouldPrune implements Pruning. +func (noPruning) ShouldPrune(int, ArchivedFile, uint64) bool { + return false +} + +// ShouldPrune implements Pruning. +func (noPruning) IsEnabled() bool { + return false +} + +// ============================== MaxCountPruning ============================== + +type MaxCountPruning uint + +var _ PruningStrategy = MaxCountPruning(0) + +// ShouldPrune implements Pruning. +func (p MaxCountPruning) ShouldPrune(index int, _ ArchivedFile, _ uint64) bool { + return index >= int(p) +} + +// ShouldPrune implements Pruning. +func (MaxCountPruning) IsEnabled() bool { + return true +} + +// ============================== MaxAgePruning ============================== + +type MaxAgePruning time.Duration + +var _ PruningStrategy = MaxAgePruning(0) + +// ShouldPrune implements Pruning. +func (p MaxAgePruning) ShouldPrune(_ int, entry ArchivedFile, _ uint64) bool { + return entry.Age > time.Duration(p) +} + +// ShouldPrune implements Pruning. +func (MaxAgePruning) IsEnabled() bool { + return true +} + +// ============================== MaxSizePruning ============================== + +type MaxSizePruning uint64 + +var _ PruningStrategy = MaxSizePruning(0) + +// ShouldPrune implements Pruning. +func (p MaxSizePruning) ShouldPrune(_ int, _ ArchivedFile, totalSize uint64) bool { + return totalSize > uint64(p) +} + +// ShouldPrune implements Pruning. +func (MaxSizePruning) IsEnabled() bool { + return true +} + +// ============================== CompoundPruningStrategy ============================== + +type CompoundPruningStrategy []PruningStrategy + +var _ PruningStrategy = CompoundPruningStrategy(nil) + +// ShouldPrune implements Pruning. +func (s CompoundPruningStrategy) ShouldPrune(index int, entry ArchivedFile, totalSize uint64) bool { + for _, sub := range s { + if sub.ShouldPrune(index, entry, totalSize) { + return true + } + } + return false +} + +func ComposePruningStrategy(strategies ...PruningStrategy) PruningStrategy { + s := make([]PruningStrategy, 0, len(strategies)) + for _, sub := range strategies { + if sub != nil && sub.IsEnabled() { + s = append(s, sub) + } + } + if len(s) == 1 { + return s[0] + } else if len(s) > 1 { + return CompoundPruningStrategy(s) + } else { + return NoPruning + } +} + +// ShouldPrune implements Pruning. +func (c CompoundPruningStrategy) IsEnabled() bool { + for _, sub := range c { + if sub.IsEnabled() { + return true + } + } + return false +} diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index bca058e..0845e66 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -1,28 +1,72 @@ package writer import ( + "math" "path/filepath" + "slices" "strconv" + "strings" "time" ) +// ============================== RotationStrategy ============================== + +type RotationStrategy interface { + PathSuffix(prefix, ext string, now time.Time) (string, error) + FileGlob() string + ShouldRotate(previous, now time.Time, prevSize, newSize uint64) bool + Next(previous time.Time) <-chan time.Time + IsEnabled() bool + Priority() int +} + +// ============================== noRotation ============================== + +type noRotation int + +var NoRotation RotationStrategy = noRotation(0) + +// FileGlob implements RotationStrategy. +func (noRotation) FileGlob() string { + return "" +} + +// IsEnabled implements RotationStrategy. +func (noRotation) IsEnabled() bool { + return false +} + +// Next implements RotationStrategy. +func (n noRotation) Next(time.Time) <-chan time.Time { + return nil +} + +// PathSuffix implements RotationStrategy. +func (noRotation) PathSuffix(string, string, time.Time) (string, error) { + return "", nil +} + +// ShouldRotate implements RotationStrategy. +func (noRotation) ShouldRotate(time.Time, time.Time, uint64, uint64) bool { + return false +} + +// Priority implements RotationStrategy. +func (noRotation) Priority() int { + return math.MinInt +} + // ============================== SizeRotation ============================== type SizeRotation uint64 -func (s SizeRotation) ShouldRotate(current, next uint64) bool { - if s > 0 && current > 0 { - return next > uint64(s) - } else { - return false - } -} +var _ RotationStrategy = SizeRotation(0) -func (s SizeRotation) PathSuffix(prefix, ext string) (string, error) { - if s == 0 { - return "", nil - } +func (s SizeRotation) ShouldRotate(_, _ time.Time, current, next uint64) bool { + return current > 0 && next > uint64(s) +} +func (s SizeRotation) PathSuffix(prefix, ext string, _ time.Time) (string, error) { existing, err := filepath.Glob(prefix + s.FileGlob() + ext) if err != nil || len(existing) == 0 { return ".1", err @@ -40,72 +84,177 @@ func (s SizeRotation) PathSuffix(prefix, ext string) (string, error) { } func (s SizeRotation) FileGlob() string { - if s > 0 { - return ".*" - } else { - return "" - } + return ".*" } -// ============================== TimeRotation ============================== +func (SizeRotation) Next(previous time.Time) <-chan time.Time { + return nil +} -type TimeRotation interface { - PathSuffix(now time.Time) string - FileGlob() string - ShouldRotate(previous, now time.Time) bool - Next(previous time.Time) <-chan time.Time +func (s SizeRotation) IsEnabled() bool { + return s > 0 } -// ============================== noTimeRotation ============================== +func (SizeRotation) Priority() int { + return 100 +} -type noTimeRotation int +// ============================== CompoundRotationStrategy ============================== -var ROTATE_NEVER TimeRotation = noTimeRotation(0) +type CompoundRotationStrategy []RotationStrategy -// FileGlob implements TimeRotation. -func (noTimeRotation) FileGlob() string { - return "" +var _ RotationStrategy = CompoundRotationStrategy(nil) + +func ComposeRotationStrategy(strategies ...RotationStrategy) RotationStrategy { + s := make([]RotationStrategy, 0, len(strategies)) + for _, sub := range strategies { + if sub != nil && sub.IsEnabled() { + s = append(s, sub) + } + } + if len(s) == 1 { + return s[0] + } else if len(s) > 1 { + slices.SortFunc(s, func(a, b RotationStrategy) int { + return b.Priority() - a.Priority() + }) + return CompoundRotationStrategy(s) + } else { + return NoRotation + } } -// PathSuffix implements TimeRotation. -func (noTimeRotation) PathSuffix(now time.Time) string { - return "" +// FileGlob implements RotationStrategy. +func (c CompoundRotationStrategy) FileGlob() string { + globs := make([]string, 0, len(c)) + for _, s := range c { + if glob := s.FileGlob(); glob != "" { + globs = append(globs, glob) + } + + } + return strings.Join(globs, ".") } -// ShouldRotate implements TimeRotation. -func (n noTimeRotation) ShouldRotate(previous time.Time, now time.Time) bool { - return false +// IsEnabled implements RotationStrategy. +func (c CompoundRotationStrategy) IsEnabled() bool { + return true } -// Next implements TimeRotation. -func (noTimeRotation) Next(previous time.Time) <-chan time.Time { +// Next implements RotationStrategy. +func (c CompoundRotationStrategy) Next(previous time.Time) <-chan time.Time { + for _, s := range c { + next := s.Next(previous) + if next != nil { + return next + } + } return nil } -// ============================== dailyRotation ============================== - -type dailyRotation int +// PathSuffix implements RotationStrategy. +func (c CompoundRotationStrategy) PathSuffix(prefix string, ext string, now time.Time) (string, error) { + suffixes := make([]string, 0, len(c)) + for _, s := range c { + if suffix, err := s.PathSuffix(prefix, ext, now); err != nil { + return "", err + } else if suffix != "" { + suffixes = append(suffixes, suffix) + } -var ROTATE_DAILY TimeRotation = dailyRotation(0) + } + return strings.Join(suffixes, "."), nil +} -// ShouldRotate implements TimeRotation. -func (dailyRotation) ShouldRotate(previous time.Time, now time.Time) bool { - return previous.YearDay() != now.YearDay() || previous.Year() != now.Year() +// Priority implements RotationStrategy. +func (c CompoundRotationStrategy) Priority() int { + p := 0 + for _, s := range c { + if s.Priority() > p { + p = s.Priority() + } + } + return p } -// PathSuffix implements TimeRotation. -func (dailyRotation) PathSuffix(now time.Time) string { - return now.Format("2006-01-02") +// ShouldRotate implements RotationStrategy. +func (c CompoundRotationStrategy) ShouldRotate(previous time.Time, now time.Time, prevSize uint64, newSize uint64) bool { + for _, s := range c { + if s.ShouldRotate(previous, now, prevSize, newSize) { + return true + } + } + return false } -// FileGlob implements TimeRotation. +// ============================== dailyRotation ============================== + +type dailyRotation int + +var DailyRotation RotationStrategy = dailyRotation(0) + +// FileGlob implements RotationStrategy. func (dailyRotation) FileGlob() string { - return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" + return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" +} + +// IsEnabled implements RotationStrategy. +func (dailyRotation) IsEnabled() bool { + return true } -// Next implements TimeRotation. +// Next implements RotationStrategy. func (dailyRotation) Next(previous time.Time) <-chan time.Time { y, m, d := previous.Date() nextDay := time.Date(y, m, d+1, 0, 0, 0, 0, previous.Location()) return time.After(time.Until(nextDay)) } + +// PathSuffix implements RotationStrategy. +func (dailyRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { + return now.Format("2006-01-02"), nil +} + +// ShouldRotate implements RotationStrategy. +func (dailyRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { + return previous.YearDay() != now.YearDay() || previous.Year() != now.Year() +} + +func (dailyRotation) Priority() int { + return 150 +} + +// ============================== PeriodicRotation ============================== + +type PeriodicRotation time.Duration + +var _ RotationStrategy = PeriodicRotation(time.Second) + +// FileGlob implements RotationStrategy. +func (PeriodicRotation) FileGlob() string { + return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" +} + +// IsEnabled implements RotationStrategy. +func (r PeriodicRotation) IsEnabled() bool { + return r > 0 +} + +// Next implements RotationStrategy. +func (r PeriodicRotation) Next(previous time.Time) <-chan time.Time { + return time.After(time.Until(previous.Add(time.Duration(r)))) +} + +// PathSuffix implements RotationStrategy. +func (PeriodicRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { + return now.Format(".2006-01-02-150405"), nil +} + +// ShouldRotate implements RotationStrategy. +func (r PeriodicRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { + return now.Sub(previous) >= time.Duration(r) +} + +func (PeriodicRotation) Priority() int { + return 150 +} diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 9fd6824..2ad989f 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -1,14 +1,11 @@ package writer import ( - "compress/gzip" "context" - "fmt" "io" "log/slog" "os" "sync" - "time" ) // ============================== Writer ============================== @@ -114,73 +111,3 @@ func (w *Writer) Close() error { } return nil } - -// ============================== Compression ============================== - -type Compression interface { - Compress(string) error - FileGlob() string -} - -type gzipCompression int - -var _ Compression = gzipCompression(gzip.DefaultCompression) - -// Compress implements Compression. -func (c gzipCompression) Compress(path string) error { - src, err := os.Open(path) - if err != nil { - slog.Error("could open source", "path", path, "err", err) - return err - } - defer src.Close() - - dest, err := os.OpenFile(path+".gz", os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0o777) - if err != nil { - slog.Error("could open dest", "path", path+".gz", "err", err) - return err - } - defer dest.Close() - - slog.Info("compressing", "src", src.Name(), "dest", dest.Name()) - - compressor, err := gzip.NewWriterLevel(dest, int(c)) - if err != nil { - slog.Error("could initialize compression", "level", int(c), "err", err) - return err - } - - if _, err = io.Copy(compressor, src); err != nil { - slog.Error("could initialize compression", "level", int(c), "err", err) - return err - } - - if err = src.Close(); err != nil { - return err - } - - return os.Remove(path) -} - -// FileGlob implements Compression. -func (n gzipCompression) FileGlob() string { - return ".gz" -} - -// ============================== fileEntry ============================== - -type fileEntry struct { - Path string - os.FileInfo -} - -var _ fmt.Stringer = fileEntry{} - -func (f fileEntry) Remove() error { - return os.Remove(f.Path) -} - -// LogValue implements slog.LogValuer. -func (f fileEntry) String() string { - return fmt.Sprintf("%s(%d bytes, %s)", f.Path, f.Size(), f.ModTime().Format(time.RFC3339)) -} diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 50d8c29..bb72cb5 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -55,7 +55,7 @@ func TestWriteTimeRotation(t *testing.T) { c := newTestClock(t) dtr := debugTimeRotation{c} - w, err := NewWriter(root+"/logfile.txt", WithTimeRotation(&dtr), withDebug(), withClock(c)) + w, err := NewWriter(root+"/logfile.txt", WithRotation(&dtr), withDebug(), withClock(c)) assert.NoError(err) assert.WriteOk(w, "foobar1\n") @@ -106,7 +106,7 @@ func TestKeepMaxAge(t *testing.T) { c.now = time.Date(2000, 01, 01, 0, 0, 0, 0, time.Local) dtr := debugTimeRotation{c} - w, err := NewWriter(root+"/logfile.txt", WithTimeRotation(&dtr), WithKeepMaxAge(2*time.Second), withDebug(), withClock(c)) + w, err := NewWriter(root+"/logfile.txt", WithRotation(&dtr), WithKeepMaxAge(2*time.Second), withDebug(), withClock(c)) assert.NoError(err) for range 4 { @@ -316,25 +316,35 @@ type debugTimeRotation struct { c *testClock } -var _ TimeRotation = (*debugTimeRotation)(nil) +var _ RotationStrategy = (*debugTimeRotation)(nil) -// FileGlob implements TimeRotation. +// FileGlob implements RotationStrategy. func (d *debugTimeRotation) FileGlob() string { return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]-[0-2][0-9][0-5][0-9][0-5][0-9]" } -// Next implements TimeRotation. +// IsEnabled implements RotationStrategy. +func (d *debugTimeRotation) IsEnabled() bool { + return true +} + +// Next implements RotationStrategy. func (d *debugTimeRotation) Next(previous time.Time) <-chan time.Time { return d.c.Deadline(previous.Add(time.Second)) } -// PathSuffix implements TimeRotation. -func (d *debugTimeRotation) PathSuffix(now time.Time) string { - return now.Format(".2006-01-02-150405") +// PathSuffix implements RotationStrategy. +func (d *debugTimeRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { + return now.Format(".2006-01-02-150405"), nil +} + +// Priority implements RotationStrategy. +func (d *debugTimeRotation) Priority() int { + return 0 } -// ShouldRotate implements TimeRotation. -func (d *debugTimeRotation) ShouldRotate(previous time.Time, now time.Time) bool { +// ShouldRotate implements RotationStrategy. +func (d *debugTimeRotation) ShouldRotate(previous time.Time, now time.Time, prevSize uint64, newSize uint64) bool { return now.Second() != previous.Second() || now.Minute() != previous.Minute() || now.Hour() != previous.Hour() || -- GitLab From b004649641ef25c3d3eba41ac4eb51b46b8e9d44 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 09:13:37 +0100 Subject: [PATCH 18/28] refactor: fixed background task control. --- lib/logging/writer/background.go | 81 +++++++++++++------------ lib/logging/writer/cleaner.go | 38 ++++++------ lib/logging/writer/clock.go | 6 ++ lib/logging/writer/config.go | 16 +++-- lib/logging/writer/rotation.go | 98 +++++++++++++++++++------------ lib/logging/writer/writer.go | 76 +++++++++++++----------- lib/logging/writer/writer_test.go | 6 +- 7 files changed, 183 insertions(+), 138 deletions(-) diff --git a/lib/logging/writer/background.go b/lib/logging/writer/background.go index b0c1542..ed5e22b 100644 --- a/lib/logging/writer/background.go +++ b/lib/logging/writer/background.go @@ -1,7 +1,6 @@ package writer import ( - "context" "errors" "fmt" "log/slog" @@ -26,86 +25,92 @@ type BackgroundWriter struct { } func NewBackgroundWriter(c Config, archived chan<- string) *BackgroundWriter { - prefix, ext := c.SplitPath() + prefix, ext := c.splitPath() return &BackgroundWriter{ path: c.Path, pathPrefix: prefix, pathExt: ext, rotation: c.Rotation, archived: archived, - log: c.log, + log: c.logger(), clock: c.clock, } } -func (w *BackgroundWriter) run(ctx context.Context, reqs <-chan writeRequest) (err error) { +func (w *BackgroundWriter) run(reqs <-chan writeRequest) (err error) { defer func() { + if w.archived != nil { + close(w.archived) + } err = errors.Join(err, w.closeFile()) + w.log.Debug("background writer stopped") }() + triggerR, hasTimer := w.rotation.(RotationStrategyTrigger) + var trigger <-chan time.Time + w.log.Debug("background writer started") + for { + if hasTimer && trigger == nil { + now, next := w.clock.Now(), triggerR.Next(w.lastModTime) + if next.After(now) { + trigger = w.clock.After(next.Sub(now)) + } + } + select { - case <-w.rotation.Next(w.clock.Now()): - w.log.Debug("rotation timer expired") + case <-trigger: + trigger = nil if w.shouldRotate(0) { if err := w.rotate(); err != nil { return err } } - case req := <-reqs: - if err := w.handleRequest(req); err != nil { - return err + case req, open := <-reqs: + if !open { + return nil } - case <-ctx.Done(): - for { - select { - case req, open := <-reqs: - if open { - req.reply(0, os.ErrClosed) - } else { - return nil - } - default: - return nil - } + written, err := w.write([]byte(req.data)) + req.reply(written, err) + w.size += written + w.lastModTime = w.clock.Now() + + if err != nil { + return err } } } } -func (w *BackgroundWriter) handleRequest(req writeRequest) (err error) { - var written uint64 +func (w *BackgroundWriter) write(data []byte) (written uint64, err error) { defer func() { - w.size += written - w.lastModTime = w.clock.Now() if p := recover(); p != nil { err = errors.Join(err, fmt.Errorf("recovered panic: %v", p)) } - req.reply(written, err) }() - toWrite := uint64(len(req.data)) + toWrite := uint64(len(data)) if w.shouldRotate(toWrite) { - if err := w.rotate(); err != nil { - return err + if err = w.rotate(); err != nil { + return 0, err } } if toWrite == 0 { - return nil + return 0, nil } - if err := w.openFile(); err != nil { - return err + if err = w.openFile(); err != nil { + return 0, err } - var n int for err == nil && written < toWrite { - n, err = w.file.Write([]byte(req.data)[written:]) + var n int + n, err = w.file.Write([]byte(data)[written:]) written += uint64(n) } - return nil + return written, nil } func (w *BackgroundWriter) openFile() error { @@ -138,9 +143,9 @@ func (w *BackgroundWriter) closeFile() error { err := w.file.Close() if err != nil { - w.log.Error("error closing file", "err", err) + w.log.Error("error closing file", "path", w.path, "err", err) } else { - w.log.Debug("closed file") + w.log.Debug("closed file", "path", w.path) } w.file = nil return err @@ -165,13 +170,13 @@ func (w *BackgroundWriter) rotate() error { return err } - w.log.Debug("rotating file", "archivePath", archivePath) if err = os.Rename(w.path, archivePath); err != nil { return fmt.Errorf("could not archive log file: %w", err) } if err = os.Chtimes(archivePath, refTime, refTime); err != nil { return fmt.Errorf("could not set archive time: %w", err) } + w.log.Debug("archived file", "archivePath", archivePath) if w.archived != nil { w.archived <- archivePath diff --git a/lib/logging/writer/cleaner.go b/lib/logging/writer/cleaner.go index fca3b16..0fa0b33 100644 --- a/lib/logging/writer/cleaner.go +++ b/lib/logging/writer/cleaner.go @@ -1,7 +1,6 @@ package writer import ( - "context" "fmt" "log/slog" "os" @@ -29,29 +28,32 @@ func NewCleaner(c Config) *cleaner { archiveGlob: c.archiveGlob(), compression: c.Compression, pruning: c.Pruning, - log: c.log, + log: c.logger(), clock: c.clock, } } -func (c *cleaner) run(ctx context.Context, archived <-chan string) error { - ever := true - for ever { - select { - case archive := <-archived: +func (c *cleaner) run(archived <-chan string) error { + defer c.log.Debug("background cleaner stopped") + c.log.Debug("background cleaner started") + + for archive := range archived { + if c.compression.IsEnabled() { if err := c.compression.Compress(archive); err != nil { - return fmt.Errorf("could not compress archived log file: %w", err) + return fmt.Errorf("could not compress archived file: %w", err) + } else { + c.log.Info("compressed archived file") } - case <-ctx.Done(): - ever = false } - if archives, err := c.listArchives(); err != nil { - return err - } else if len(archives) > 0 { - c.log.Debug("found archived files", "archives", archives) - if err := c.prune(archives); err != nil { - return fmt.Errorf("could not prune archived log files: %w", err) + if c.pruning.IsEnabled() { + if archives, err := c.listArchives(); err != nil { + return err + } else if len(archives) > 0 { + c.log.Debug("considering archived files for pruning", "paths", archives) + if err := c.prune(archives); err != nil { + return fmt.Errorf("could not prune archived files: %w", err) + } } } } @@ -62,7 +64,7 @@ func (c *cleaner) run(ctx context.Context, archived <-chan string) error { func (c *cleaner) listArchives() ([]ArchivedFile, error) { paths, err := filepath.Glob(c.archiveGlob) if err != nil { - return nil, fmt.Errorf("could not list archived log files: %w", err) + return nil, fmt.Errorf("could not list archived files: %w", err) } entries := make([]ArchivedFile, len(paths)) @@ -91,7 +93,7 @@ func (c *cleaner) prune(archives []ArchivedFile) error { if err := entry.Remove(); err != nil { return fmt.Errorf("could not remove archived logfile: %w", err) } else { - c.log.Debug("removed archived file", "archive", entry.Path) + c.log.Info("removed archived file", "archive", entry.Path) } } } diff --git a/lib/logging/writer/clock.go b/lib/logging/writer/clock.go index e2d3c73..76d1fb6 100644 --- a/lib/logging/writer/clock.go +++ b/lib/logging/writer/clock.go @@ -6,6 +6,7 @@ import "time" type Clock interface { Now() time.Time + After(time.Duration) <-chan time.Time } type timeClock struct { @@ -18,3 +19,8 @@ var DefaultClock Clock = timeClock{time.Local} func (s timeClock) Now() time.Time { return time.Now().In(s.location) } + +// After implements Clock. +func (s timeClock) After(d time.Duration) <-chan time.Time { + return time.After(d) +} diff --git a/lib/logging/writer/config.go b/lib/logging/writer/config.go index f3bcbf5..f604a44 100644 --- a/lib/logging/writer/config.go +++ b/lib/logging/writer/config.go @@ -19,8 +19,8 @@ type Config struct { clock Clock } -func DefaultConfig(path string) Config { - return Config{ +func DefaultConfig(path string, options ...Option) Config { + c := Config{ Path: path, Rotation: NoRotation, Compression: NoCompression, @@ -28,6 +28,8 @@ func DefaultConfig(path string) Config { log: DefaultLogger, clock: DefaultClock, } + c.Apply(options...) + return c } func (c *Config) Apply(options ...Option) { @@ -40,16 +42,20 @@ func (c Config) needCleaner() bool { return c.Compression.IsEnabled() || c.Pruning.IsEnabled() } -func (c Config) SplitPath() (prefix, ext string) { +func (c Config) splitPath() (prefix, ext string) { ext = path.Ext(c.Path) return c.Path[:len(c.Path)-len(ext)], ext } func (c Config) archiveGlob() string { - prefix, ext := c.SplitPath() + prefix, ext := c.splitPath() return prefix + c.Rotation.FileGlob() + ext + c.Compression.FileGlob() } +func (c Config) logger() *slog.Logger { + return c.log.With("logfile", c.Path) +} + // ============================== Option ============================== type Option func(c *Config) @@ -73,7 +79,7 @@ func WithMaxSize(maxSize uint64) Option { if maxSize == 0 { panic("file size limit is zero") } - return WithRotation(SizeRotation(maxSize)) + return WithRotation(NewSizeRotation(maxSize)) } func WithKeepMaxCount(maxCount uint) Option { diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index 0845e66..5160b21 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -1,6 +1,7 @@ package writer import ( + "fmt" "math" "path/filepath" "slices" @@ -15,11 +16,15 @@ type RotationStrategy interface { PathSuffix(prefix, ext string, now time.Time) (string, error) FileGlob() string ShouldRotate(previous, now time.Time, prevSize, newSize uint64) bool - Next(previous time.Time) <-chan time.Time IsEnabled() bool Priority() int } +type RotationStrategyTrigger interface { + RotationStrategy + Next(previous time.Time) time.Time +} + // ============================== noRotation ============================== type noRotation int @@ -36,11 +41,6 @@ func (noRotation) IsEnabled() bool { return false } -// Next implements RotationStrategy. -func (n noRotation) Next(time.Time) <-chan time.Time { - return nil -} - // PathSuffix implements RotationStrategy. func (noRotation) PathSuffix(string, string, time.Time) (string, error) { return "", nil @@ -58,44 +58,63 @@ func (noRotation) Priority() int { // ============================== SizeRotation ============================== -type SizeRotation uint64 +type SizeRotation struct { + maxSize uint64 + lastIndex int + lastPrefix string +} + +var _ RotationStrategy = (*SizeRotation)(nil) + +func NewSizeRotation(maxSize uint64) *SizeRotation { + if maxSize == 0 { + panic("null maximum size") + } + return &SizeRotation{maxSize: maxSize} +} + +func (s *SizeRotation) ShouldRotate(_, _ time.Time, current, next uint64) bool { + return current > 0 && next > s.maxSize +} -var _ RotationStrategy = SizeRotation(0) +func (s *SizeRotation) PathSuffix(prefix, ext string, _ time.Time) (suffix string, err error) { + if prefix != s.lastPrefix { + if s.lastIndex, err = s.findLastIndex(prefix, ext); err != nil { + return "", err + } + } -func (s SizeRotation) ShouldRotate(_, _ time.Time, current, next uint64) bool { - return current > 0 && next > uint64(s) + s.lastIndex += 1 + return fmt.Sprintf(".%d", s.lastIndex), nil } -func (s SizeRotation) PathSuffix(prefix, ext string, _ time.Time) (string, error) { +func (s *SizeRotation) findLastIndex(prefix, ext string) (last int, err error) { existing, err := filepath.Glob(prefix + s.FileGlob() + ext) if err != nil || len(existing) == 0 { - return ".1", err + return 0, err } - last, start, endOffset := 0, len(prefix)+1, len(ext) + start, endOffset := len(prefix)+1, len(ext) for _, path := range existing { - last, err = strconv.Atoi(path[start : len(path)-endOffset]) - if err != nil { - return "", err + if idx, err := strconv.Atoi(path[start : len(path)-endOffset]); err != nil { + return 0, err + } else if int(idx) > last { + last = int(idx) } } - return "." + strconv.Itoa(last+1), nil + return last, nil } -func (s SizeRotation) FileGlob() string { +func (s *SizeRotation) FileGlob() string { return ".*" } -func (SizeRotation) Next(previous time.Time) <-chan time.Time { - return nil -} - -func (s SizeRotation) IsEnabled() bool { - return s > 0 +func (s *SizeRotation) IsEnabled() bool { + return true } -func (SizeRotation) Priority() int { +func (*SizeRotation) Priority() int { return 100 } @@ -103,7 +122,7 @@ func (SizeRotation) Priority() int { type CompoundRotationStrategy []RotationStrategy -var _ RotationStrategy = CompoundRotationStrategy(nil) +var _ RotationStrategyTrigger = CompoundRotationStrategy(nil) func ComposeRotationStrategy(strategies ...RotationStrategy) RotationStrategy { s := make([]RotationStrategy, 0, len(strategies)) @@ -142,14 +161,16 @@ func (c CompoundRotationStrategy) IsEnabled() bool { } // Next implements RotationStrategy. -func (c CompoundRotationStrategy) Next(previous time.Time) <-chan time.Time { +func (c CompoundRotationStrategy) Next(previous time.Time) time.Time { for _, s := range c { - next := s.Next(previous) - if next != nil { - return next + if s, hasTimer := s.(RotationStrategyTrigger); hasTimer { + next := s.Next(previous) + if !next.IsZero() { + return next + } } } - return nil + return time.Time{} } // PathSuffix implements RotationStrategy. @@ -191,7 +212,7 @@ func (c CompoundRotationStrategy) ShouldRotate(previous time.Time, now time.Time type dailyRotation int -var DailyRotation RotationStrategy = dailyRotation(0) +var DailyRotation RotationStrategyTrigger = dailyRotation(0) // FileGlob implements RotationStrategy. func (dailyRotation) FileGlob() string { @@ -203,11 +224,10 @@ func (dailyRotation) IsEnabled() bool { return true } -// Next implements RotationStrategy. -func (dailyRotation) Next(previous time.Time) <-chan time.Time { +// Next implements RotationStrategyTrigger. +func (dailyRotation) Next(previous time.Time) time.Time { y, m, d := previous.Date() - nextDay := time.Date(y, m, d+1, 0, 0, 0, 0, previous.Location()) - return time.After(time.Until(nextDay)) + return time.Date(y, m, d+1, 0, 0, 0, 0, previous.Location()) } // PathSuffix implements RotationStrategy. @@ -228,7 +248,7 @@ func (dailyRotation) Priority() int { type PeriodicRotation time.Duration -var _ RotationStrategy = PeriodicRotation(time.Second) +var _ RotationStrategyTrigger = PeriodicRotation(time.Second) // FileGlob implements RotationStrategy. func (PeriodicRotation) FileGlob() string { @@ -241,8 +261,8 @@ func (r PeriodicRotation) IsEnabled() bool { } // Next implements RotationStrategy. -func (r PeriodicRotation) Next(previous time.Time) <-chan time.Time { - return time.After(time.Until(previous.Add(time.Duration(r)))) +func (r PeriodicRotation) Next(previous time.Time) time.Time { + return previous.Add(time.Duration(r)) } // PathSuffix implements RotationStrategy. diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 2ad989f..761cfa1 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -1,11 +1,12 @@ package writer import ( - "context" + "fmt" "io" "log/slog" "os" "sync" + "sync/atomic" ) // ============================== Writer ============================== @@ -14,11 +15,10 @@ import ( type Writer struct { path string - reqs chan<- writeRequest - archived chan<- string - ctx context.Context - stop context.CancelCauseFunc - wg sync.WaitGroup + reqs chan<- writeRequest + wg sync.WaitGroup + closed atomic.Bool + err error log *slog.Logger clock Clock @@ -50,51 +50,58 @@ var _ io.WriteCloser = (*Writer)(nil) var DefaultLogger = slog.New(slog.DiscardHandler) func NewWriter(path string, options ...Option) (*Writer, error) { - c := DefaultConfig(path) - c.Apply(options...) + c := DefaultConfig(path, options...) reqs := make(chan writeRequest) - ctx, stop := context.WithCancelCause(context.Background()) - w := &Writer{ reqs: reqs, - ctx: ctx, - log: c.log.With("logfile", path), + log: c.logger(), clock: c.clock, - stop: stop, } var archived chan string if c.needCleaner() { archived = make(chan string, 20) - w.wg.Add(1) - go func() { - defer w.wg.Done() - cleaner := NewCleaner(c) - if err := cleaner.run(ctx, archived); err != nil { - stop(err) - } - }() + w.runBackgroundTask(func() error { + return NewCleaner(c).run(archived) + }) } + w.runBackgroundTask(func() error { + return NewBackgroundWriter(c, archived).run(reqs) + }) + + return w, nil +} + +func (w *Writer) runBackgroundTask(task func() error) { w.wg.Add(1) go func() { - defer w.wg.Done() - b := NewBackgroundWriter(c, archived) - if err := b.run(ctx, reqs); err != nil { - stop(err) - } + defer func() { + if p := recover(); p != nil { + w.close(fmt.Errorf("recovered panic: %v", p)) + } + w.wg.Done() + }() + w.close(task()) }() +} - return w, nil +func (w *Writer) close(cause error) bool { + if w.closed.CompareAndSwap(false, true) { + w.log.Debug("closing") + w.err = cause + close(w.reqs) + return true + } + return false } // Write implements io.WriteCloser. func (w *Writer) Write(p []byte) (n int, err error) { - if err := context.Cause(w.ctx); err == context.Canceled { + if w.closed.Load() { + w.log.Debug("already closed") return 0, os.ErrClosed - } else if err != nil { - return 0, err } req, resp := makeWriteRequest(p) w.reqs <- req @@ -104,10 +111,9 @@ func (w *Writer) Write(p []byte) (n int, err error) { // Close implements io.WriteCloser. func (w *Writer) Close() error { - w.stop(nil) - w.wg.Wait() - if err := context.Cause(w.ctx); err != nil && err != context.Canceled { - return err + if w.close(nil) { + w.log.Debug("waiting for background tasks to end") + w.wg.Wait() } - return nil + return w.err } diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index bb72cb5..8754fd4 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -316,7 +316,7 @@ type debugTimeRotation struct { c *testClock } -var _ RotationStrategy = (*debugTimeRotation)(nil) +var _ RotationStrategyTrigger = (*debugTimeRotation)(nil) // FileGlob implements RotationStrategy. func (d *debugTimeRotation) FileGlob() string { @@ -329,8 +329,8 @@ func (d *debugTimeRotation) IsEnabled() bool { } // Next implements RotationStrategy. -func (d *debugTimeRotation) Next(previous time.Time) <-chan time.Time { - return d.c.Deadline(previous.Add(time.Second)) +func (d *debugTimeRotation) Next(previous time.Time) time.Time { + return previous.Add(time.Second) } // PathSuffix implements RotationStrategy. -- GitLab From 7ee5ed76fd6bd763046bbae1d61c8c2181a18fc2 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 09:30:34 +0100 Subject: [PATCH 19/28] fix: fix sized-based rotation error in suffixes. --- lib/logging/writer/rotatiion_test.go | 60 ++++++++++++++++++++++++++++ lib/logging/writer/rotation.go | 1 + 2 files changed, 61 insertions(+) create mode 100644 lib/logging/writer/rotatiion_test.go diff --git a/lib/logging/writer/rotatiion_test.go b/lib/logging/writer/rotatiion_test.go new file mode 100644 index 0000000..6b05b44 --- /dev/null +++ b/lib/logging/writer/rotatiion_test.go @@ -0,0 +1,60 @@ +package writer + +import ( + "fmt" + "os" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestSizeRotationShouldRotate(t *testing.T) { + t.Parallel() + assert := assert.New(t) + + r := NewSizeRotation(50) + + assert.False(r.ShouldRotate(time.Now(), time.Now(), 1, 2)) + assert.False(r.ShouldRotate(time.Now(), time.Now(), 0, 52)) + assert.True(r.ShouldRotate(time.Now(), time.Now(), 1, 52)) + assert.True(r.ShouldRotate(time.Now(), time.Now(), 52, 102)) +} + +func TestSizeRotationFileSuffix(t *testing.T) { + t.Parallel() + require := require.New(t) + + root := t.TempDir() + r := NewSizeRotation(50) + + for j := range 4 { + prefix := fmt.Sprintf("%s/log-%d", root, j) + for i := range 5 { + s, err := r.PathSuffix(prefix, ".txt", time.Now()) + require.NoError(err) + require.Equal(fmt.Sprintf(".%d", i+1), s) + } + } +} + +func TestSizeRotationFileSuffixExist(t *testing.T) { + t.Parallel() + require := require.New(t) + + root := t.TempDir() + r := NewSizeRotation(50) + + require.NoError(os.WriteFile(root+"/log.52.txt", nil, 0o777)) + + s, err := r.PathSuffix(root+"/log", ".txt", time.Now()) + require.NoError(err) + require.Equal(".53", s) + + require.NoError(os.Remove(root + "/log.52.txt")) + + s, err = r.PathSuffix(root+"/log", ".txt", time.Now()) + require.NoError(err) + require.Equal(".54", s) +} diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index 5160b21..e6b55c7 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -79,6 +79,7 @@ func (s *SizeRotation) ShouldRotate(_, _ time.Time, current, next uint64) bool { func (s *SizeRotation) PathSuffix(prefix, ext string, _ time.Time) (suffix string, err error) { if prefix != s.lastPrefix { + s.lastPrefix = prefix if s.lastIndex, err = s.findLastIndex(prefix, ext); err != nil { return "", err } -- GitLab From 673ed9ced840608ee582546f4615ca6b7f4cd050 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 09:30:53 +0100 Subject: [PATCH 20/28] test: allow parallel execution of writer tests. --- lib/logging/writer/writer_test.go | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 8754fd4..73f712a 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -14,6 +14,7 @@ import ( ) func TestSimpleWrite(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() filePath := root + "/logfile.txt" @@ -30,6 +31,7 @@ func TestSimpleWrite(t *testing.T) { } func TestWriteSizeRotaton(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -49,6 +51,7 @@ func TestWriteSizeRotaton(t *testing.T) { } func TestWriteTimeRotation(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -78,6 +81,7 @@ func TestWriteTimeRotation(t *testing.T) { } func TestKeepMaxCount(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -99,6 +103,7 @@ func TestKeepMaxCount(t *testing.T) { } func TestKeepMaxAge(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -123,6 +128,7 @@ func TestKeepMaxAge(t *testing.T) { } func TestKeepMaxSize(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -142,6 +148,7 @@ func TestKeepMaxSize(t *testing.T) { } func TestWriteCompression(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -160,6 +167,7 @@ func TestWriteCompression(t *testing.T) { } func TestMultiSyncClose(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() @@ -174,6 +182,7 @@ func TestMultiSyncClose(t *testing.T) { } func TestMultiAsyncClose(t *testing.T) { + t.Parallel() assert := NewFileAssert(t) root := t.TempDir() -- GitLab From 9ba3f5d4dc4d4f3e6a6bbe8e55e1d4a7095f9c9b Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 09:50:16 +0100 Subject: [PATCH 21/28] fix: test and fix DailyRotation. --- lib/logging/writer/rotatiion_test.go | 52 ++++++++++++++++++++++++++++ lib/logging/writer/rotation.go | 2 +- 2 files changed, 53 insertions(+), 1 deletion(-) diff --git a/lib/logging/writer/rotatiion_test.go b/lib/logging/writer/rotatiion_test.go index 6b05b44..d4aa405 100644 --- a/lib/logging/writer/rotatiion_test.go +++ b/lib/logging/writer/rotatiion_test.go @@ -58,3 +58,55 @@ func TestSizeRotationFileSuffixExist(t *testing.T) { require.NoError(err) require.Equal(".54", s) } + +func TestDailyRotation(t *testing.T) { + t.Parallel() + require := require.New(t) + + r := DailyRotation + + now := time.Date(2000, 1, 1, 0, 0, 0, 0, time.Local) + + suffix, err := r.PathSuffix("log", ".txt", now) + require.NoError(err) + require.Equal("2000-01-01", suffix) +} + +func TestDailyRotationShouldRotate(t *testing.T) { + t.Parallel() + + r := DailyRotation + now := time.Date(2000, 4, 1, 0, 5, 0, 0, time.UTC) + + positiveCases := []time.Time{ + now.Add(24 * time.Hour), + now.Add(48 * time.Hour), + time.Date(2000, 4, 2, 0, 0, 0, 0, time.UTC), + time.Date(2000, 5, 1, 0, 0, 0, 0, time.UTC), + time.Date(2001, 4, 1, 0, 0, 0, 0, time.UTC), + } + negativeCases := []time.Time{ + now.Add(time.Second), + now.Add(time.Minute), + now.Add(time.Hour), + now.Add(-time.Second), + now.Add(-time.Minute), + now.Add(-time.Hour), + now.Add(-24 * time.Hour), + now.Add(-48 * time.Hour), + time.Date(2000, 4, 1, 0, 0, 0, 0, time.UTC), + time.Date(1999, 4, 1, 0, 5, 0, 0, time.UTC), + time.Date(2000, 3, 1, 0, 5, 0, 0, time.UTC), + } + + for _, date := range positiveCases { + t.Run("allow-"+date.Format(time.RFC3339), func(t *testing.T) { + assert.True(t, r.ShouldRotate(now, date, 0, 0)) + }) + } + for _, date := range negativeCases { + t.Run("deny-"+date.Format(time.RFC3339), func(t *testing.T) { + assert.False(t, r.ShouldRotate(now, date, 0, 0)) + }) + } +} diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index e6b55c7..e21bf06 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -238,7 +238,7 @@ func (dailyRotation) PathSuffix(_ string, _ string, now time.Time) (string, erro // ShouldRotate implements RotationStrategy. func (dailyRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { - return previous.YearDay() != now.YearDay() || previous.Year() != now.Year() + return now.YearDay() > previous.YearDay() || now.Year() > previous.Year() } func (dailyRotation) Priority() int { -- GitLab From 662482465a5cdecbc1066d3bdf8598b20999c37d Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 10:42:46 +0100 Subject: [PATCH 22/28] fix: fixed handling of rotation suffixes. --- lib/logging/writer/background.go | 8 +-- lib/logging/writer/config.go | 8 ++- lib/logging/writer/rotatiion_test.go | 42 ++++++++++++---- lib/logging/writer/rotation.go | 12 ++--- lib/logging/writer/writer_test.go | 74 ++++++++++++++-------------- 5 files changed, 87 insertions(+), 57 deletions(-) diff --git a/lib/logging/writer/background.go b/lib/logging/writer/background.go index ed5e22b..8abe069 100644 --- a/lib/logging/writer/background.go +++ b/lib/logging/writer/background.go @@ -186,9 +186,11 @@ func (w *BackgroundWriter) rotate() error { } func (w *BackgroundWriter) newArchivePath(when time.Time) (string, error) { - if suffix, err := w.rotation.PathSuffix(w.pathPrefix, w.pathExt, when); err == nil { - return w.pathPrefix + suffix + w.pathExt, nil - } else { + if suffix, err := w.rotation.PathSuffix(w.pathPrefix, w.pathExt, when); err != nil { return "", err + } else if suffix != "" { + return w.pathPrefix + "." + suffix + w.pathExt, nil + } else { + return w.pathPrefix + w.pathExt, nil } } diff --git a/lib/logging/writer/config.go b/lib/logging/writer/config.go index f604a44..5fb8086 100644 --- a/lib/logging/writer/config.go +++ b/lib/logging/writer/config.go @@ -49,7 +49,13 @@ func (c Config) splitPath() (prefix, ext string) { func (c Config) archiveGlob() string { prefix, ext := c.splitPath() - return prefix + c.Rotation.FileGlob() + ext + c.Compression.FileGlob() + if glob := c.Rotation.FileGlob(); glob != "" { + prefix += "." + glob + } + if glob := c.Compression.FileGlob(); glob != "" { + ext += glob + } + return prefix + ext } func (c Config) logger() *slog.Logger { diff --git a/lib/logging/writer/rotatiion_test.go b/lib/logging/writer/rotatiion_test.go index d4aa405..fd7666a 100644 --- a/lib/logging/writer/rotatiion_test.go +++ b/lib/logging/writer/rotatiion_test.go @@ -3,6 +3,7 @@ package writer import ( "fmt" "os" + "path/filepath" "testing" "time" @@ -32,9 +33,10 @@ func TestSizeRotationFileSuffix(t *testing.T) { for j := range 4 { prefix := fmt.Sprintf("%s/log-%d", root, j) for i := range 5 { - s, err := r.PathSuffix(prefix, ".txt", time.Now()) + suffix, err := r.PathSuffix(prefix, ".txt", time.Now()) require.NoError(err) - require.Equal(fmt.Sprintf(".%d", i+1), s) + require.True(filepath.Match(r.FileGlob(), suffix)) + require.Equal(fmt.Sprintf("%05d", i+1), suffix) } } } @@ -46,20 +48,20 @@ func TestSizeRotationFileSuffixExist(t *testing.T) { root := t.TempDir() r := NewSizeRotation(50) - require.NoError(os.WriteFile(root+"/log.52.txt", nil, 0o777)) + require.NoError(os.WriteFile(root+"/log.00052.txt", nil, 0o777)) s, err := r.PathSuffix(root+"/log", ".txt", time.Now()) require.NoError(err) - require.Equal(".53", s) + require.Equal("00053", s) - require.NoError(os.Remove(root + "/log.52.txt")) + require.NoError(os.Remove(root + "/log.00052.txt")) s, err = r.PathSuffix(root+"/log", ".txt", time.Now()) require.NoError(err) - require.Equal(".54", s) + require.Equal("00054", s) } -func TestDailyRotation(t *testing.T) { +func TestDailyRotationPathSuffix(t *testing.T) { t.Parallel() require := require.New(t) @@ -69,6 +71,7 @@ func TestDailyRotation(t *testing.T) { suffix, err := r.PathSuffix("log", ".txt", now) require.NoError(err) + require.True(filepath.Match(r.FileGlob(), suffix)) require.Equal("2000-01-01", suffix) } @@ -100,13 +103,34 @@ func TestDailyRotationShouldRotate(t *testing.T) { } for _, date := range positiveCases { - t.Run("allow-"+date.Format(time.RFC3339), func(t *testing.T) { + t.Run("allow/"+date.Sub(now).String(), func(t *testing.T) { assert.True(t, r.ShouldRotate(now, date, 0, 0)) }) } for _, date := range negativeCases { - t.Run("deny-"+date.Format(time.RFC3339), func(t *testing.T) { + t.Run("deny/"+date.Sub(now).String(), func(t *testing.T) { assert.False(t, r.ShouldRotate(now, date, 0, 0)) }) } } + +func TestDailyRotationNext(t *testing.T) { + t.Parallel() + assert := assert.New(t) + + r := DailyRotation + + assert.True(time.Date(2000, 1, 2, 0, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 1, 1, 0, 0, 0, 0, time.UTC)), + )) + assert.True(time.Date(2000, 1, 2, 0, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 1, 1, 23, 59, 59, 0, time.UTC)), + )) + assert.True(time.Date(2000, 1, 2, 0, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 1, 1, 0, 5, 0, 0, time.UTC)), + )) + assert.True(time.Date(2001, 1, 1, 0, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 12, 31, 0, 5, 0, 0, time.UTC)), + )) +} + diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index e21bf06..0a1fd51 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -86,11 +86,11 @@ func (s *SizeRotation) PathSuffix(prefix, ext string, _ time.Time) (suffix strin } s.lastIndex += 1 - return fmt.Sprintf(".%d", s.lastIndex), nil + return fmt.Sprintf("%05d", s.lastIndex), nil } func (s *SizeRotation) findLastIndex(prefix, ext string) (last int, err error) { - existing, err := filepath.Glob(prefix + s.FileGlob() + ext) + existing, err := filepath.Glob(prefix + "." + s.FileGlob() + ext) if err != nil || len(existing) == 0 { return 0, err } @@ -108,7 +108,7 @@ func (s *SizeRotation) findLastIndex(prefix, ext string) (last int, err error) { } func (s *SizeRotation) FileGlob() string { - return ".*" + return "[0-9][0-9][0-9][0-9][0-9]" } func (s *SizeRotation) IsEnabled() bool { @@ -217,7 +217,7 @@ var DailyRotation RotationStrategyTrigger = dailyRotation(0) // FileGlob implements RotationStrategy. func (dailyRotation) FileGlob() string { - return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" + return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" } // IsEnabled implements RotationStrategy. @@ -253,7 +253,7 @@ var _ RotationStrategyTrigger = PeriodicRotation(time.Second) // FileGlob implements RotationStrategy. func (PeriodicRotation) FileGlob() string { - return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" + return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" } // IsEnabled implements RotationStrategy. @@ -268,7 +268,7 @@ func (r PeriodicRotation) Next(previous time.Time) time.Time { // PathSuffix implements RotationStrategy. func (PeriodicRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { - return now.Format(".2006-01-02-150405"), nil + return now.Format("2006-01-02-150405"), nil } // ShouldRotate implements RotationStrategy. diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index 73f712a..b076ab3 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -46,8 +46,8 @@ func TestWriteSizeRotaton(t *testing.T) { assert.NoError(w.Close()) assert.FileContent(root+"/logfile.txt", "foobar3\n") - assert.FileContent(root+"/logfile.1.txt", "foobar1\n") - assert.FileContent(root+"/logfile.2.txt", "foobar2\n") + assert.FileContent(root+"/logfile.00001.txt", "foobar1\n") + assert.FileContent(root+"/logfile.00002.txt", "foobar2\n") } func TestWriteTimeRotation(t *testing.T) { @@ -56,7 +56,7 @@ func TestWriteTimeRotation(t *testing.T) { root := t.TempDir() c := newTestClock(t) - dtr := debugTimeRotation{c} + dtr := debugTimeRotation(0) w, err := NewWriter(root+"/logfile.txt", WithRotation(&dtr), withDebug(), withClock(c)) assert.NoError(err) @@ -74,9 +74,9 @@ func TestWriteTimeRotation(t *testing.T) { assert.NoError(w.Close()) - assert.FileContent(root+"/logfile.0001-01-01-000000.txt", "foobar1\n") - assert.FileContent(root+"/logfile.0001-01-01-000001.txt", "foobar2\n") - assert.FileContent(root+"/logfile.0001-01-01-000003.txt", "foobar3\n") + assert.FileContent(root+"/logfile.0001-01-01.00-00-00.txt", "foobar1\n") + assert.FileContent(root+"/logfile.0001-01-01.00-00-01.txt", "foobar2\n") + assert.FileContent(root+"/logfile.0001-01-01.00-00-03.txt", "foobar3\n") assert.FileContent(root+"/logfile.txt", "foobar4\n") } @@ -95,11 +95,11 @@ func TestKeepMaxCount(t *testing.T) { assert.NoError(w.Close()) assert.FileExists(root + "/logfile.txt") - assert.NoFileExists(root + "/logfile.1.txt") - assert.NoFileExists(root + "/logfile.2.txt") - assert.NoFileExists(root + "/logfile.3.txt") - assert.FileExists(root + "/logfile.4.txt") - assert.FileExists(root + "/logfile.5.txt") + assert.NoFileExists(root + "/logfile.00001.txt") + assert.NoFileExists(root + "/logfile.00002.txt") + assert.NoFileExists(root + "/logfile.00003.txt") + assert.FileExists(root + "/logfile.00004.txt") + assert.FileExists(root + "/logfile.00005.txt") } func TestKeepMaxAge(t *testing.T) { @@ -109,7 +109,7 @@ func TestKeepMaxAge(t *testing.T) { c := newTestClock(t) c.now = time.Date(2000, 01, 01, 0, 0, 0, 0, time.Local) - dtr := debugTimeRotation{c} + dtr := debugTimeRotation(0) w, err := NewWriter(root+"/logfile.txt", WithRotation(&dtr), WithKeepMaxAge(2*time.Second), withDebug(), withClock(c)) assert.NoError(err) @@ -121,10 +121,10 @@ func TestKeepMaxAge(t *testing.T) { assert.NoError(w.Close()) - assert.NoFileExists(root + "/logfile.2000-01-01-000000.txt") - assert.NoFileExists(root + "/logfile.2000-01-01-000001.txt") - assert.FileExists(root + "/logfile.2000-01-01-000002.txt") - assert.FileExists(root + "/logfile.2000-01-01-000003.txt") + assert.NoFileExists(root + "/logfile.2000-01-01.00-00-00.txt") + assert.NoFileExists(root + "/logfile.2000-01-01.00-00-01.txt") + assert.FileExists(root + "/logfile.2000-01-01.00-00-02.txt") + assert.FileExists(root + "/logfile.2000-01-01.00-00-03.txt") } func TestKeepMaxSize(t *testing.T) { @@ -141,9 +141,9 @@ func TestKeepMaxSize(t *testing.T) { assert.NoError(w.Close()) - assert.NoFileExists(root + "/logfile.1.txt") - assert.NoFileExists(root + "/logfile.2.txt") - assert.FileExists(root + "/logfile.3.txt") + assert.NoFileExists(root + "/logfile.00001.txt") + assert.NoFileExists(root + "/logfile.00002.txt") + assert.FileExists(root + "/logfile.00003.txt") assert.FileExists(root + "/logfile.txt") } @@ -162,8 +162,8 @@ func TestWriteCompression(t *testing.T) { assert.NoError(w.Close()) assert.FileContent(root+"/logfile.txt", "foobar3\n") - assert.FileExists(root + "/logfile.1.txt.gz") - assert.FileExists(root + "/logfile.2.txt.gz") + assert.FileExists(root + "/logfile.00001.txt.gz") + assert.FileExists(root + "/logfile.00002.txt.gz") } func TestMultiSyncClose(t *testing.T) { @@ -321,42 +321,40 @@ func withClock(c Clock) Option { // ============================== debugTimeRotation ============================== -type debugTimeRotation struct { - c *testClock -} +type debugTimeRotation int -var _ RotationStrategyTrigger = (*debugTimeRotation)(nil) +var _ RotationStrategyTrigger = debugTimeRotation(0) // FileGlob implements RotationStrategy. -func (d *debugTimeRotation) FileGlob() string { - return ".[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]-[0-2][0-9][0-5][0-9][0-5][0-9]" +func (debugTimeRotation) FileGlob() string { + return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9].[0-2][0-9]-[0-5][0-9]-[0-5][0-9]" } // IsEnabled implements RotationStrategy. -func (d *debugTimeRotation) IsEnabled() bool { +func (debugTimeRotation) IsEnabled() bool { return true } // Next implements RotationStrategy. -func (d *debugTimeRotation) Next(previous time.Time) time.Time { +func (debugTimeRotation) Next(previous time.Time) time.Time { return previous.Add(time.Second) } // PathSuffix implements RotationStrategy. -func (d *debugTimeRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { - return now.Format(".2006-01-02-150405"), nil +func (debugTimeRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { + return now.Format("2006-01-02.15-04-05"), nil } // Priority implements RotationStrategy. -func (d *debugTimeRotation) Priority() int { +func (debugTimeRotation) Priority() int { return 0 } // ShouldRotate implements RotationStrategy. -func (d *debugTimeRotation) ShouldRotate(previous time.Time, now time.Time, prevSize uint64, newSize uint64) bool { - return now.Second() != previous.Second() || - now.Minute() != previous.Minute() || - now.Hour() != previous.Hour() || - now.Month() != previous.Month() || - now.Year() != previous.Year() +func (debugTimeRotation) ShouldRotate(previous time.Time, now time.Time, prevSize uint64, newSize uint64) bool { + return now.Second() > previous.Second() || + now.Minute() > previous.Minute() || + now.Hour() > previous.Hour() || + now.YearDay() > previous.YearDay() || + now.Year() > previous.Year() } -- GitLab From c6da8b8a88611c776816b4be3389504cb172588e Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 10:43:50 +0100 Subject: [PATCH 23/28] feat: add HourlyRotation. --- lib/logging/writer/rotatiion_test.go | 65 ++++++++++++++++++++++++++++ lib/logging/writer/rotation.go | 38 ++++++++++++++++ 2 files changed, 103 insertions(+) diff --git a/lib/logging/writer/rotatiion_test.go b/lib/logging/writer/rotatiion_test.go index fd7666a..7f30b78 100644 --- a/lib/logging/writer/rotatiion_test.go +++ b/lib/logging/writer/rotatiion_test.go @@ -134,3 +134,68 @@ func TestDailyRotationNext(t *testing.T) { )) } +func TestHourlyRotationPathSuffix(t *testing.T) { + t.Parallel() + require := require.New(t) + + r := HourlyRotation + now := time.Date(2000, 1, 1, 0, 0, 0, 0, time.Local) + + suffix, err := r.PathSuffix("log", ".txt", now) + require.NoError(err) + require.True(filepath.Match(r.FileGlob(), suffix)) + require.Equal("2000-01-01.00-00-00", suffix) +} + +func TestHourlyRotationShouldRotate(t *testing.T) { + t.Parallel() + + r := HourlyRotation + now := time.Date(2000, 4, 1, 5, 55, 0, 0, time.UTC) + + positiveCases := []time.Time{ + now.Add(time.Hour), + now.Add(5 * time.Minute), + now.Add(24 * time.Hour), + time.Date(2000, 4, 2, 0, 5, 55, 0, time.UTC), + time.Date(2000, 5, 1, 0, 5, 55, 0, time.UTC), + time.Date(2001, 4, 1, 0, 5, 55, 0, time.UTC), + } + negativeCases := []time.Time{ + now.Add(time.Second), + now.Add(time.Minute), + now.Add(-time.Hour), + now.Add(-time.Second), + } + + for _, date := range positiveCases { + t.Run("allow/"+date.Sub(now).String(), func(t *testing.T) { + assert.True(t, r.ShouldRotate(now, date, 0, 0)) + }) + } + for _, date := range negativeCases { + t.Run("deny/"+date.Sub(now).String(), func(t *testing.T) { + assert.False(t, r.ShouldRotate(now, date, 0, 0)) + }) + } +} + +func TestHourlyRotationNext(t *testing.T) { + t.Parallel() + assert := assert.New(t) + + r := HourlyRotation + + assert.True(time.Date(2000, 1, 1, 1, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 1, 1, 0, 0, 0, 0, time.UTC)), + )) + assert.True(time.Date(2000, 1, 1, 6, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 1, 1, 5, 55, 0, 0, time.UTC)), + )) + assert.True(time.Date(2000, 1, 2, 0, 00, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 1, 1, 23, 20, 0, 0, time.UTC)), + )) + assert.True(time.Date(2001, 1, 1, 0, 0, 0, 0, time.UTC).Equal( + r.Next(time.Date(2000, 12, 31, 23, 0, 0, 0, time.UTC)), + )) +} diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index 0a1fd51..59f33eb 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -245,6 +245,44 @@ func (dailyRotation) Priority() int { return 150 } +// ============================== hourlyRotation ============================== + +type hourlyRotation int + +var HourlyRotation RotationStrategyTrigger = hourlyRotation(0) + +// FileGlob implements RotationStrategy. +func (hourlyRotation) FileGlob() string { + return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9].[0-2][0-9]-[0-5][0-9]-[0-5][0-9]" +} + +// IsEnabled implements RotationStrategy. +func (hourlyRotation) IsEnabled() bool { + return true +} + +// Next implements RotationStrategyTrigger. +func (hourlyRotation) Next(previous time.Time) time.Time { + y, m, d := previous.Date() + return time.Date(y, m, d, previous.Hour()+1, 0, 0, 0, previous.Location()) +} + +// PathSuffix implements RotationStrategy. +func (hourlyRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { + return now.Format("2006-01-02.15-04-05"), nil +} + +// ShouldRotate implements RotationStrategy. +func (hourlyRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { + return now.Hour() > previous.Hour() || + now.YearDay() > previous.YearDay() || + now.Year() > previous.Year() +} + +func (hourlyRotation) Priority() int { + return 150 +} + // ============================== PeriodicRotation ============================== type PeriodicRotation time.Duration -- GitLab From f73e8bfe2571df1868a5ffa8558b6bd718c37a64 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 11:05:51 +0100 Subject: [PATCH 24/28] feat: add weekly, monthly and 15-minute rotation strategies. --- lib/logging/writer/rotatiion_test.go | 4 +- lib/logging/writer/rotation.go | 156 +++++++++++++-------------- 2 files changed, 74 insertions(+), 86 deletions(-) diff --git a/lib/logging/writer/rotatiion_test.go b/lib/logging/writer/rotatiion_test.go index 7f30b78..0fc3154 100644 --- a/lib/logging/writer/rotatiion_test.go +++ b/lib/logging/writer/rotatiion_test.go @@ -104,12 +104,12 @@ func TestDailyRotationShouldRotate(t *testing.T) { for _, date := range positiveCases { t.Run("allow/"+date.Sub(now).String(), func(t *testing.T) { - assert.True(t, r.ShouldRotate(now, date, 0, 0)) + assert.Truef(t, r.ShouldRotate(now, date, 0, 0), "should rotate between %v and %v", now, date) }) } for _, date := range negativeCases { t.Run("deny/"+date.Sub(now).String(), func(t *testing.T) { - assert.False(t, r.ShouldRotate(now, date, 0, 0)) + assert.Falsef(t, r.ShouldRotate(now, date, 0, 0), "should not rotate between %v and %v", now, date) }) } } diff --git a/lib/logging/writer/rotation.go b/lib/logging/writer/rotation.go index 59f33eb..6cb3847 100644 --- a/lib/logging/writer/rotation.go +++ b/lib/logging/writer/rotation.go @@ -209,111 +209,99 @@ func (c CompoundRotationStrategy) ShouldRotate(previous time.Time, now time.Time return false } -// ============================== dailyRotation ============================== +// ============================== startPeriodRotation ============================== -type dailyRotation int - -var DailyRotation RotationStrategyTrigger = dailyRotation(0) - -// FileGlob implements RotationStrategy. -func (dailyRotation) FileGlob() string { - return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" -} - -// IsEnabled implements RotationStrategy. -func (dailyRotation) IsEnabled() bool { - return true -} - -// Next implements RotationStrategyTrigger. -func (dailyRotation) Next(previous time.Time) time.Time { - y, m, d := previous.Date() - return time.Date(y, m, d+1, 0, 0, 0, 0, previous.Location()) -} - -// PathSuffix implements RotationStrategy. -func (dailyRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { - return now.Format("2006-01-02"), nil -} - -// ShouldRotate implements RotationStrategy. -func (dailyRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { - return now.YearDay() > previous.YearDay() || now.Year() > previous.Year() +type periodStartRotation struct { + timeFormat string + glob string + period time.Duration + truncate func(time.Time) time.Time } -func (dailyRotation) Priority() int { - return 150 +func makePeriodStartRotation(period time.Duration, truncate func(time.Time) time.Time) periodStartRotation { + if period == 0 { + panic("null period") + } + timeFormat := "2006-01-02" + glob := "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" + if period < 24*time.Hour { + timeFormat += ".15-04-05" + glob += ".[0-2][0-9]-[0-5][0-9]-[0-5][0-9]" + } + return periodStartRotation{ + timeFormat: timeFormat, + glob: glob, + period: period, + truncate: truncate, + } } -// ============================== hourlyRotation ============================== - -type hourlyRotation int - -var HourlyRotation RotationStrategyTrigger = hourlyRotation(0) +var ( + FifteenMinuteRotation RotationStrategyTrigger = makePeriodStartRotation( + 15*time.Minute, + func(t time.Time) time.Time { + y, m, d := t.Date() + h, mi, _ := t.Clock() + mi -= mi % 15 + return time.Date(y, m, d, h, mi, 0, 0, t.Location()) + }, + ) + DailyRotation RotationStrategyTrigger = makePeriodStartRotation( + 24*time.Hour, + func(t time.Time) time.Time { + y, m, d := t.Date() + return time.Date(y, m, d, 0, 0, 0, 0, t.Location()) + }, + ) + HourlyRotation RotationStrategyTrigger = makePeriodStartRotation( + time.Hour, + func(t time.Time) time.Time { + y, m, d := t.Date() + return time.Date(y, m, d, t.Hour(), 0, 0, 0, t.Location()) + }, + ) + WeeklyRotation RotationStrategyTrigger = makePeriodStartRotation( + 7*24*time.Hour, + func(t time.Time) time.Time { + y, m, d := t.Date() + wk := t.Weekday() + return time.Date(y, m, d-int(wk), 0, 0, 0, 0, t.Location()) + }, + ) + MonthlyRotation RotationStrategyTrigger = makePeriodStartRotation( + 31*24*time.Hour, + func(t time.Time) time.Time { + y, m, _ := t.Date() + return time.Date(y, m, 1, 0, 0, 0, 0, t.Location()) + }, + ) +) // FileGlob implements RotationStrategy. -func (hourlyRotation) FileGlob() string { - return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9].[0-2][0-9]-[0-5][0-9]-[0-5][0-9]" +func (r periodStartRotation) FileGlob() string { + return r.glob } // IsEnabled implements RotationStrategy. -func (hourlyRotation) IsEnabled() bool { +func (r periodStartRotation) IsEnabled() bool { return true } // Next implements RotationStrategyTrigger. -func (hourlyRotation) Next(previous time.Time) time.Time { - y, m, d := previous.Date() - return time.Date(y, m, d, previous.Hour()+1, 0, 0, 0, previous.Location()) -} - -// PathSuffix implements RotationStrategy. -func (hourlyRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { - return now.Format("2006-01-02.15-04-05"), nil -} - -// ShouldRotate implements RotationStrategy. -func (hourlyRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { - return now.Hour() > previous.Hour() || - now.YearDay() > previous.YearDay() || - now.Year() > previous.Year() -} - -func (hourlyRotation) Priority() int { - return 150 -} - -// ============================== PeriodicRotation ============================== - -type PeriodicRotation time.Duration - -var _ RotationStrategyTrigger = PeriodicRotation(time.Second) - -// FileGlob implements RotationStrategy. -func (PeriodicRotation) FileGlob() string { - return "[0-9][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]" -} - -// IsEnabled implements RotationStrategy. -func (r PeriodicRotation) IsEnabled() bool { - return r > 0 -} - -// Next implements RotationStrategy. -func (r PeriodicRotation) Next(previous time.Time) time.Time { - return previous.Add(time.Duration(r)) +func (r periodStartRotation) Next(previous time.Time) time.Time { + return r.truncate(previous.Add(r.period)) } // PathSuffix implements RotationStrategy. -func (PeriodicRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { - return now.Format("2006-01-02-150405"), nil +func (r periodStartRotation) PathSuffix(_ string, _ string, now time.Time) (string, error) { + return now.Format(r.timeFormat), nil } // ShouldRotate implements RotationStrategy. -func (r PeriodicRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { - return now.Sub(previous) >= time.Duration(r) +func (r periodStartRotation) ShouldRotate(previous time.Time, now time.Time, _ uint64, _ uint64) bool { + return !now.Before(r.Next(previous)) } -func (PeriodicRotation) Priority() int { +func (r periodStartRotation) Priority() int { return 150 } -- GitLab From 66128e9995bee8eb4846dc5d90c8ce15cbb4516a Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 11:11:00 +0100 Subject: [PATCH 25/28] refactor: allow to provide custom strategies or compression. --- lib/logging/writer/config.go | 25 +++++++++++++++---------- 1 file changed, 15 insertions(+), 10 deletions(-) diff --git a/lib/logging/writer/config.go b/lib/logging/writer/config.go index 5fb8086..a937124 100644 --- a/lib/logging/writer/config.go +++ b/lib/logging/writer/config.go @@ -88,30 +88,37 @@ func WithMaxSize(maxSize uint64) Option { return WithRotation(NewSizeRotation(maxSize)) } +func WithPruning(p PruningStrategy) Option { + return func(w *Config) { + w.Pruning = ComposePruningStrategy(w.Pruning, p) + } +} + func WithKeepMaxCount(maxCount uint) Option { if maxCount == 0 { panic("max count limit is zero") } - return func(w *Config) { - w.Pruning = ComposePruningStrategy(w.Pruning, MaxCountPruning(maxCount)) - } + return WithPruning(MaxCountPruning(maxCount)) } func WithKeepMaxAge(maxAge time.Duration) Option { if maxAge <= 0 { panic("max age limit is zero or negative") } - return func(w *Config) { - w.Pruning = ComposePruningStrategy(w.Pruning, MaxAgePruning(maxAge)) - } + return WithPruning(MaxAgePruning(maxAge)) } func WithKeepMaxSize(maxSize uint64) Option { if maxSize == 0 { panic("total size limit is zero") } + return WithPruning(MaxSizePruning(maxSize)) + +} + +func WithCompression(c Compression) Option { return func(w *Config) { - w.Pruning = ComposePruningStrategy(w.Pruning, MaxSizePruning(maxSize)) + w.Compression = c } } @@ -120,7 +127,5 @@ func WithGZipCompression(levels ...int) Option { if len(levels) > 0 { level = levels[0] } - return func(w *Config) { - w.Compression = GzipCompression(level) - } + return WithCompression(GzipCompression(level)) } -- GitLab From 970040e4b4f05a2aa875d13958a5793d07e56683 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 11:14:51 +0100 Subject: [PATCH 26/28] fix: remove unused fields. --- lib/logging/writer/writer.go | 63 +++++++++++++++++++----------------- 1 file changed, 33 insertions(+), 30 deletions(-) diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index 761cfa1..c836169 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -13,36 +13,12 @@ import ( // Writer is an asynchronous io.WriteCloser with rotating capabilities type Writer struct { - path string - reqs chan<- writeRequest wg sync.WaitGroup closed atomic.Bool err error - log *slog.Logger - clock Clock -} - -type writeRequest struct { - data string - response chan<- writeResponse -} - -func makeWriteRequest(data []byte) (writeRequest, <-chan writeResponse) { - c := make(chan writeResponse, 1) - w := writeRequest{data: string(data), response: c} - return w, c -} - -func (w *writeRequest) reply(written uint64, err error) { - w.response <- writeResponse{written, err} - close(w.response) -} - -type writeResponse struct { - written uint64 - err error + log *slog.Logger } var _ io.WriteCloser = (*Writer)(nil) @@ -54,9 +30,8 @@ func NewWriter(path string, options ...Option) (*Writer, error) { reqs := make(chan writeRequest) w := &Writer{ - reqs: reqs, - log: c.logger(), - clock: c.clock, + reqs: reqs, + log: c.logger(), } var archived chan string @@ -105,8 +80,7 @@ func (w *Writer) Write(p []byte) (n int, err error) { } req, resp := makeWriteRequest(p) w.reqs <- req - r := <-resp - return int(r.written), r.err + return (<-resp).consume() } // Close implements io.WriteCloser. @@ -117,3 +91,32 @@ func (w *Writer) Close() error { } return w.err } + +// ============================== writeRequest ============================== + +type writeRequest struct { + data string + response chan<- writeResponse +} + +func makeWriteRequest(data []byte) (writeRequest, <-chan writeResponse) { + c := make(chan writeResponse, 1) + w := writeRequest{data: string(data), response: c} + return w, c +} + +func (w *writeRequest) reply(written uint64, err error) { + w.response <- writeResponse{written, err} + close(w.response) +} + +// ============================== writeResponse ============================== + +type writeResponse struct { + written uint64 + err error +} + +func (r writeResponse) consume() (int, error) { + return int(r.written), r.err +} -- GitLab From 12efc65bc0ebd508fc29ed2127281d0be480a995 Mon Sep 17 00:00:00 2001 From: Adirelle Date: Tue, 25 Mar 2025 12:00:20 +0100 Subject: [PATCH 27/28] feet: add some benchmarks and reduce the number of allocations. --- Taskfile.yml | 7 ++++ lib/logging/writer/background.go | 28 +++++++++------- lib/logging/writer/cleaner.go | 3 +- lib/logging/writer/writer.go | 52 ++++++++++++++++++++--------- lib/logging/writer/writer_test.go | 55 +++++++++++++++++++++++++++++++ 5 files changed, 116 insertions(+), 29 deletions(-) diff --git a/Taskfile.yml b/Taskfile.yml index d9edbec..5fdb72b 100644 --- a/Taskfile.yml +++ b/Taskfile.yml @@ -27,6 +27,13 @@ tasks: cmds: - go test {{.CLI_ARGS}} ./lib/... + bench: + deps: [deps] + sources: + - lib/**/* + cmds: + - go test -v -bench=. -run=^# ./lib/... + test-lib: deps: [deps] sources: diff --git a/lib/logging/writer/background.go b/lib/logging/writer/background.go index 8abe069..f0173c2 100644 --- a/lib/logging/writer/background.go +++ b/lib/logging/writer/background.go @@ -3,6 +3,7 @@ package writer import ( "errors" "fmt" + "io" "log/slog" "os" "time" @@ -37,7 +38,7 @@ func NewBackgroundWriter(c Config, archived chan<- string) *BackgroundWriter { } } -func (w *BackgroundWriter) run(reqs <-chan writeRequest) (err error) { +func (w *BackgroundWriter) run(reqs <-chan *writeRequest) (err error) { defer func() { if w.archived != nil { close(w.archived) @@ -70,7 +71,7 @@ func (w *BackgroundWriter) run(reqs <-chan writeRequest) (err error) { if !open { return nil } - written, err := w.write([]byte(req.data)) + written, err := w.write(req.data) req.reply(written, err) w.size += written w.lastModTime = w.clock.Now() @@ -106,7 +107,7 @@ func (w *BackgroundWriter) write(data []byte) (written uint64, err error) { for err == nil && written < toWrite { var n int - n, err = w.file.Write([]byte(data)[written:]) + n, err = w.file.Write(data[written:]) written += uint64(n) } @@ -125,11 +126,11 @@ func (w *BackgroundWriter) openFile() error { return err } - info, err := w.file.Stat() - if err != nil { + if pos, err := w.file.Seek(0, io.SeekCurrent); err == nil { + w.size = uint64(pos) + } else { return err } - w.size = uint64(info.Size()) w.lastModTime = w.clock.Now() w.log.Debug("opened file for writing", "size", w.size, "modTime", w.lastModTime) @@ -141,14 +142,19 @@ func (w *BackgroundWriter) closeFile() error { return nil } - err := w.file.Close() - if err != nil { - w.log.Error("error closing file", "path", w.path, "err", err) + if err := w.file.Sync(); err != nil { + w.log.Warn("error syncing file", "path", w.path, "err", err) + } + + if err := w.file.Close(); err != nil { + w.log.Warn("error closing file", "path", w.path, "err", err) } else { - w.log.Debug("closed file", "path", w.path) + w.log.Debug("closed file", "path", w.path, "size", w.size) } + w.file = nil - return err + w.size = 0 + return nil } func (w *BackgroundWriter) shouldRotate(toWrite uint64) bool { diff --git a/lib/logging/writer/cleaner.go b/lib/logging/writer/cleaner.go index 0fa0b33..f659d5a 100644 --- a/lib/logging/writer/cleaner.go +++ b/lib/logging/writer/cleaner.go @@ -16,8 +16,7 @@ type cleaner struct { archiveGlob string compression Compression - - pruning PruningStrategy + pruning PruningStrategy log *slog.Logger clock Clock diff --git a/lib/logging/writer/writer.go b/lib/logging/writer/writer.go index c836169..901a0d6 100644 --- a/lib/logging/writer/writer.go +++ b/lib/logging/writer/writer.go @@ -13,7 +13,7 @@ import ( // Writer is an asynchronous io.WriteCloser with rotating capabilities type Writer struct { - reqs chan<- writeRequest + reqs chan<- *writeRequest wg sync.WaitGroup closed atomic.Bool err error @@ -28,7 +28,7 @@ var DefaultLogger = slog.New(slog.DiscardHandler) func NewWriter(path string, options ...Option) (*Writer, error) { c := DefaultConfig(path, options...) - reqs := make(chan writeRequest) + reqs := make(chan *writeRequest) w := &Writer{ reqs: reqs, log: c.logger(), @@ -73,14 +73,12 @@ func (w *Writer) close(cause error) bool { } // Write implements io.WriteCloser. -func (w *Writer) Write(p []byte) (n int, err error) { +func (w *Writer) Write(data []byte) (n int, err error) { if w.closed.Load() { w.log.Debug("already closed") return 0, os.ErrClosed } - req, resp := makeWriteRequest(p) - w.reqs <- req - return (<-resp).consume() + return makeWriteRequest(data).send(w.reqs) } // Close implements io.WriteCloser. @@ -95,19 +93,34 @@ func (w *Writer) Close() error { // ============================== writeRequest ============================== type writeRequest struct { - data string - response chan<- writeResponse + data []byte + response chan *writeResponse } -func makeWriteRequest(data []byte) (writeRequest, <-chan writeResponse) { - c := make(chan writeResponse, 1) - w := writeRequest{data: string(data), response: c} - return w, c +var requestPool = sync.Pool{New: func() any { + return &writeRequest{ + data: make([]byte, 0, 256), + response: make(chan *writeResponse, 1), + } +}} + +func makeWriteRequest(data []byte) *writeRequest { + req := requestPool.Get().(*writeRequest) + req.data = append(req.data[:0], data...) + return req +} + +func (w *writeRequest) send(reqs chan<- *writeRequest) (int, error) { + reqs <- w + resp := <-w.response + n, err := int(resp.written), resp.err + responsePool.Put(resp) + requestPool.Put(w) + return n, err } func (w *writeRequest) reply(written uint64, err error) { - w.response <- writeResponse{written, err} - close(w.response) + w.response <- makeWriteResponse(written, err) } // ============================== writeResponse ============================== @@ -117,6 +130,13 @@ type writeResponse struct { err error } -func (r writeResponse) consume() (int, error) { - return int(r.written), r.err +var responsePool = sync.Pool{New: func() any { + return &writeResponse{} +}} + +func makeWriteResponse(written uint64, err error) *writeResponse { + r := responsePool.Get().(*writeResponse) + r.written = written + r.err = err + return r } diff --git a/lib/logging/writer/writer_test.go b/lib/logging/writer/writer_test.go index b076ab3..71e3254 100644 --- a/lib/logging/writer/writer_test.go +++ b/lib/logging/writer/writer_test.go @@ -1,10 +1,12 @@ package writer import ( + "fmt" "io" "log/slog" "os" "runtime" + "strings" "sync" "testing" "time" @@ -206,6 +208,59 @@ func TestMultiAsyncClose(t *testing.T) { close(start) wg.Wait() } +func BenchmarkDefaultWriter(b *testing.B) { + for exp := 0; exp < 10; exp += 1 { + var data = []byte(strings.Repeat("0123456789ABCDEF", 1< Date: Tue, 25 Mar 2025 15:04:12 +0100 Subject: [PATCH 28/28] ci: use latest adirelle/pre-commit-check/check --- .gitlab-ci.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.gitlab-ci.yml b/.gitlab-ci.yml index 54f099a..82d2188 100644 --- a/.gitlab-ci.yml +++ b/.gitlab-ci.yml @@ -16,7 +16,7 @@ stages: - build include: - - component: $CI_SERVER_FQDN/adirelle/pre-commit-check/check@v1.0.0 + - component: $CI_SERVER_FQDN/adirelle/pre-commit-check/check@v1.1.0 inputs: stage: lint -- GitLab