diff --git a/cmd/anubis/main.go b/cmd/anubis/main.go index 91223b84..9bd4be4e 100644 --- a/cmd/anubis/main.go +++ b/cmd/anubis/main.go @@ -338,10 +338,14 @@ func main() { ctx = thoth.With(ctx, thothClient) } - policy, err := libanubis.LoadPoliciesOrDefault(ctx, *policyFname, *challengeDifficulty) + lg.Info("loading policy file", "fname", *policyFname) + policy, err := libanubis.LoadPoliciesOrDefault(ctx, *policyFname, *challengeDifficulty, *slogLevel) if err != nil { log.Fatalf("can't parse policy file: %v", err) } + lg = policy.Logger + lg.Debug("swapped to new logger") + slog.SetDefault(lg) // Warn if persistent storage is used without a configured signing key if policy.Store.IsPersistent() { @@ -463,7 +467,7 @@ func main() { CookieSameSite: parseSameSite(*cookieSameSite), PublicUrl: *publicUrl, JWTRestrictionHeader: *jwtRestrictionHeader, - Logger: lg.With("subsystem", "anubis"), + Logger: policy.Logger.With("subsystem", "anubis"), DifficultyInJWT: *difficultyInJWT, }) if err != nil { diff --git a/internal/test/playwright_test.go b/internal/test/playwright_test.go index 0cb72e98..b1cab340 100644 --- a/internal/test/playwright_test.go +++ b/internal/test/playwright_test.go @@ -595,7 +595,7 @@ func spawnAnubisWithOptions(t *testing.T, basePrefix string) string { fmt.Fprintf(w, "%d", time.Now().Unix()) }) - policy, err := libanubis.LoadPoliciesOrDefault(t.Context(), "", anubis.DefaultDifficulty) + policy, err := libanubis.LoadPoliciesOrDefault(t.Context(), "", anubis.DefaultDifficulty, "info") if err != nil { t.Fatal(err) } diff --git a/lib/anubis_test.go b/lib/anubis_test.go index ecafd7d8..78e602df 100644 --- a/lib/anubis_test.go +++ b/lib/anubis_test.go @@ -58,7 +58,7 @@ func loadPolicies(t *testing.T, fname string, difficulty int) *policy.ParsedConf t.Logf("loading policy file: %s", fname) - anubisPolicy, err := LoadPoliciesOrDefault(ctx, fname, difficulty) + anubisPolicy, err := LoadPoliciesOrDefault(ctx, fname, difficulty, "info") if err != nil { t.Fatal(err) } @@ -250,7 +250,7 @@ func TestLoadPolicies(t *testing.T) { } defer fin.Close() - if _, err := policy.ParseConfig(t.Context(), fin, fname, 4); err != nil { + if _, err := policy.ParseConfig(t.Context(), fin, fname, 4, "info"); err != nil { t.Fatal(err) } }) diff --git a/lib/config.go b/lib/config.go index 888bf6d2..2d8ac18b 100644 --- a/lib/config.go +++ b/lib/config.go @@ -48,12 +48,13 @@ type Options struct { CookieSecure bool CookieSameSite http.SameSite Logger *slog.Logger + LogLevel string PublicUrl string JWTRestrictionHeader string DifficultyInJWT bool } -func LoadPoliciesOrDefault(ctx context.Context, fname string, defaultDifficulty int) (*policy.ParsedConfig, error) { +func LoadPoliciesOrDefault(ctx context.Context, fname string, defaultDifficulty int, logLevel string) (*policy.ParsedConfig, error) { var fin io.ReadCloser var err error @@ -77,7 +78,7 @@ func LoadPoliciesOrDefault(ctx context.Context, fname string, defaultDifficulty } }(fin) - anubisPolicy, err := policy.ParseConfig(ctx, fin, fname, defaultDifficulty) + anubisPolicy, err := policy.ParseConfig(ctx, fin, fname, defaultDifficulty, logLevel) if err != nil { return nil, fmt.Errorf("can't parse policy file %s: %w", fname, err) } diff --git a/lib/config/config.go b/lib/config/config.go index 577470a2..3e45b7af 100644 --- a/lib/config/config.go +++ b/lib/config/config.go @@ -332,6 +332,7 @@ type fileConfig struct { Thresholds []Threshold `json:"thresholds"` StatusCodes StatusCodes `json:"status_codes"` DNSBL bool `json:"dnsbl"` + Logging *Logging `json:"logging"` } func (c *fileConfig) Valid() error { @@ -363,6 +364,10 @@ func (c *fileConfig) Valid() error { } } + if err := c.Logging.Valid(); err != nil { + errs = append(errs, err) + } + if c.Store != nil { if err := c.Store.Valid(); err != nil { errs = append(errs, err) @@ -385,6 +390,7 @@ func Load(fin io.Reader, fname string) (*Config, error) { Store: &Store{ Backend: "memory", }, + Logging: (Logging{}).Default(), } if err := yaml.NewYAMLToJSONDecoder(fin).Decode(&c); err != nil { @@ -404,6 +410,7 @@ func Load(fin io.Reader, fname string) (*Config, error) { }, StatusCodes: c.StatusCodes, Store: c.Store, + Logging: c.Logging, } if c.OpenGraph.TimeToLive != "" { @@ -469,6 +476,7 @@ type Config struct { Bots []BotConfig Thresholds []Threshold StatusCodes StatusCodes + Logging *Logging DNSBL bool } diff --git a/lib/config/logging.go b/lib/config/logging.go new file mode 100644 index 00000000..a0308d6f --- /dev/null +++ b/lib/config/logging.go @@ -0,0 +1,133 @@ +package config + +import ( + "errors" + "fmt" + "log/slog" + "time" +) + +var ( + ErrMissingLoggingFileConfig = errors.New("config.Logging: missing value parameters in logging block") + ErrInvalidLoggingSink = errors.New("config.Logging: invalid sink") + ErrInvalidLoggingFileConfig = errors.New("config.LoggingFileConfig: invalid parameters") + ErrInvalidLoggingFileConfigOldTimeFormat = errors.New("config.LoggingFileConfig: invalid old time format") + ErrOutOfRange = errors.New("config: error out of range") +) + +type Logging struct { + Sink string `json:"sink"` // Logging sink, either "stdio" or "file" + Level *slog.Level `json:"level"` // Log level, if set supercedes the level in flags + Parameters *LoggingFileConfig `json:"parameters"` // Logging parameters, to be dynamic in the future +} + +const ( + LogSinkStdio = "stdio" + LogSinkFile = "file" +) + +func (l *Logging) Valid() error { + var errs []error + + switch l.Sink { + case LogSinkStdio: + // no validation needed + case LogSinkFile: + if l.Parameters == nil { + errs = append(errs, ErrMissingLoggingFileConfig) + } + + if err := l.Parameters.Valid(); err != nil { + errs = append(errs, err) + } + default: + errs = append(errs, fmt.Errorf("%w: sink %s is unknown to me", ErrInvalidLoggingSink, l.Sink)) + } + + if len(errs) != 0 { + return errors.Join(errs...) + } + + return nil +} + +func (Logging) Default() *Logging { + return &Logging{ + Sink: "stdio", + } +} + +type LoggingFileConfig struct { + Filename string `json:"file"` + OldFileTimeFormat string `json:"oldFileTimeFormat"` + MaxBackups int `json:"maxBackups"` + MaxBytes int64 `json:"maxBytes"` + MaxAge int `json:"maxAge"` + Compress bool `json:"compress"` + UseLocalTime bool `json:"useLocalTime"` +} + +func (lfc *LoggingFileConfig) Valid() error { + if lfc == nil { + return fmt.Errorf("logging file config is nil, why are you calling this?") + } + + var errs []error + + if lfc.Zero() { + errs = append(errs, ErrMissingValue) + } + + if lfc.Filename == "" { + errs = append(errs, fmt.Errorf("%w: filename", ErrMissingValue)) + } + + if _, err := time.Parse(lfc.OldFileTimeFormat, time.Now().UTC().Format(time.RFC3339)); err != nil { + errs = append(errs, fmt.Errorf("%w: %w", ErrInvalidLoggingFileConfigOldTimeFormat, err)) + } + + if lfc.MaxBackups < 0 { + errs = append(errs, fmt.Errorf("%w: max backup count %d is not greater than or equal to zero", ErrOutOfRange, lfc.MaxBackups)) + } + + if lfc.MaxAge < 0 { + errs = append(errs, fmt.Errorf("%w: max backup count %d is not greater than or equal to zero", ErrOutOfRange, lfc.MaxAge)) + } + + if len(errs) != 0 { + errs = append([]error{ErrInvalidLoggingFileConfig}, errs...) + return errors.Join(errs...) + } + + return nil +} + +func (lfc LoggingFileConfig) Zero() bool { + for _, cond := range []bool{ + lfc.Filename != "", + lfc.OldFileTimeFormat != "", + lfc.MaxBackups != 0, + lfc.MaxBytes != 0, + lfc.MaxAge != 0, + lfc.Compress, + lfc.UseLocalTime, + } { + if cond { + return false + } + } + + return true +} + +func (LoggingFileConfig) Default() *LoggingFileConfig { + return &LoggingFileConfig{ + Filename: "./var/anubis.log", + OldFileTimeFormat: time.RFC3339, + MaxBackups: 3, + MaxBytes: 104857600, // 100 Mi + MaxAge: 7, // 7 days + Compress: true, + UseLocalTime: false, + } +} diff --git a/lib/config/logging_test.go b/lib/config/logging_test.go new file mode 100644 index 00000000..f1135037 --- /dev/null +++ b/lib/config/logging_test.go @@ -0,0 +1,123 @@ +package config + +import ( + "errors" + "testing" + "time" +) + +func TestLoggingValid(t *testing.T) { + for _, tt := range []struct { + name string + input *Logging + want error + }{ + { + name: "simple happy", + input: (Logging{}).Default(), + }, + { + name: "default file config", + input: &Logging{ + Sink: LogSinkFile, + Parameters: (&LoggingFileConfig{}).Default(), + }, + }, + { + name: "invalid sink", + input: &Logging{ + Sink: "taco invalid", + }, + want: ErrInvalidLoggingSink, + }, + { + name: "missing parameters", + input: &Logging{ + Sink: LogSinkFile, + }, + want: ErrMissingLoggingFileConfig, + }, + { + name: "invalid parameters", + input: &Logging{ + Sink: LogSinkFile, + Parameters: &LoggingFileConfig{}, + }, + want: ErrInvalidLoggingFileConfig, + }, + { + name: "file sink with no filename", + input: &Logging{ + Sink: LogSinkFile, + Parameters: &LoggingFileConfig{ + Filename: "", + OldFileTimeFormat: time.RFC3339, + MaxBackups: 3, + MaxBytes: 104857600, // 100 Mi + MaxAge: 7, // 7 days + Compress: true, + UseLocalTime: false, + }, + }, + want: ErrMissingValue, + }, + { + name: "file sink with wrong time format", + input: &Logging{ + Sink: LogSinkFile, + Parameters: &LoggingFileConfig{ + Filename: "./var/anubis.log", + OldFileTimeFormat: "2025-01-01", + MaxBackups: 3, + MaxBytes: 104857600, // 100 Mi + MaxAge: 7, // 7 days + Compress: true, + UseLocalTime: false, + }, + }, + want: ErrInvalidLoggingFileConfigOldTimeFormat, + }, + { + name: "file sink with negative max backups", + input: &Logging{ + Sink: LogSinkFile, + Parameters: &LoggingFileConfig{ + Filename: "./var/anubis.log", + OldFileTimeFormat: time.RFC3339, + MaxBackups: -3, + MaxBytes: 104857600, // 100 Mi + MaxAge: 7, // 7 days + Compress: true, + UseLocalTime: false, + }, + }, + want: ErrOutOfRange, + }, + { + name: "file sink with negative max age", + input: &Logging{ + Sink: LogSinkFile, + Parameters: &LoggingFileConfig{ + Filename: "./var/anubis.log", + OldFileTimeFormat: time.RFC3339, + MaxBackups: 3, + MaxBytes: 104857600, // 100 Mi + MaxAge: -7, // 7 days + Compress: true, + UseLocalTime: false, + }, + }, + want: ErrOutOfRange, + }, + } { + t.Run(tt.name, func(t *testing.T) { + err := tt.input.Valid() + + if !errors.Is(err, tt.want) { + t.Logf("wanted error: %v", tt.want) + t.Logf(" got error: %v", err) + t.Fatal("got wrong error") + } + }) + } +} diff --git a/lib/config/testdata/bad/logging-invalid-sink.yaml b/lib/config/testdata/bad/logging-invalid-sink.yaml new file mode 100644 index 00000000..eadde4c3 --- /dev/null +++ b/lib/config/testdata/bad/logging-invalid-sink.yaml @@ -0,0 +1,2 @@ +logging: + sink: "nope" diff --git a/lib/config/testdata/bad/logging-no-parameters.yaml b/lib/config/testdata/bad/logging-no-parameters.yaml new file mode 100644 index 00000000..0cfea031 --- /dev/null +++ b/lib/config/testdata/bad/logging-no-parameters.yaml @@ -0,0 +1,2 @@ +logging: + sink: "file" diff --git a/lib/config/testdata/good/logging-file.yaml b/lib/config/testdata/good/logging-file.yaml new file mode 100644 index 00000000..c1f09b36 --- /dev/null +++ b/lib/config/testdata/good/logging-file.yaml @@ -0,0 +1,15 @@ +bots: + - name: simple + action: CHALLENGE + user_agent_regex: Mozilla + +logs: + sink: "file" + parameters: + file: "/var/log/botstopper/default.log" + maxBackups: 3 # keep at least 3 old copies + maxBytes: 67108864 # each file can have up to 64 MB of logs + maxAge: 7 # rotate files out every n days + oldFileTimeFormat: 2006-01-02T15-04-05 # RFC 3339-ish + compress: true + useLocalTime: false # timezone for rotated files is UTC diff --git a/lib/config/testdata/good/logging-stdio.yaml b/lib/config/testdata/good/logging-stdio.yaml new file mode 100644 index 00000000..d0fcf54b --- /dev/null +++ b/lib/config/testdata/good/logging-stdio.yaml @@ -0,0 +1,7 @@ +bots: + - name: simple + action: CHALLENGE + user_agent_regex: Mozilla + +logging: + sink: "stdio" diff --git a/lib/config_test.go b/lib/config_test.go index f3dc0a4c..5d392dbb 100644 --- a/lib/config_test.go +++ b/lib/config_test.go @@ -12,7 +12,7 @@ import ( ) func TestInvalidChallengeMethod(t *testing.T) { - if _, err := LoadPoliciesOrDefault(t.Context(), "testdata/invalid-challenge-method.yaml", 4); !errors.Is(err, policy.ErrChallengeRuleHasWrongAlgorithm) { + if _, err := LoadPoliciesOrDefault(t.Context(), "testdata/invalid-challenge-method.yaml", 4, "info"); !errors.Is(err, policy.ErrChallengeRuleHasWrongAlgorithm) { t.Fatalf("wanted error %v but got %v", policy.ErrChallengeRuleHasWrongAlgorithm, err) } } @@ -26,7 +26,7 @@ func TestBadConfigs(t *testing.T) { for _, st := range finfos { st := st t.Run(st.Name(), func(t *testing.T) { - if _, err := LoadPoliciesOrDefault(t.Context(), filepath.Join("config", "testdata", "bad", st.Name()), anubis.DefaultDifficulty); err == nil { + if _, err := LoadPoliciesOrDefault(t.Context(), filepath.Join("config", "testdata", "bad", st.Name()), anubis.DefaultDifficulty, "info"); err == nil { t.Fatal(err) } else { t.Log(err) @@ -46,13 +46,13 @@ func TestGoodConfigs(t *testing.T) { t.Run(st.Name(), func(t *testing.T) { t.Run("with-thoth", func(t *testing.T) { ctx := thothmock.WithMockThoth(t) - if _, err := LoadPoliciesOrDefault(ctx, filepath.Join("config", "testdata", "good", st.Name()), anubis.DefaultDifficulty); err != nil { + if _, err := LoadPoliciesOrDefault(ctx, filepath.Join("config", "testdata", "good", st.Name()), anubis.DefaultDifficulty, "info"); err != nil { t.Fatal(err) } }) t.Run("without-thoth", func(t *testing.T) { - if _, err := LoadPoliciesOrDefault(t.Context(), filepath.Join("config", "testdata", "good", st.Name()), anubis.DefaultDifficulty); err != nil { + if _, err := LoadPoliciesOrDefault(t.Context(), filepath.Join("config", "testdata", "good", st.Name()), anubis.DefaultDifficulty, "info"); err != nil { t.Fatal(err) } }) diff --git a/lib/policy/policy.go b/lib/policy/policy.go index 665f4c08..aa17c3c1 100644 --- a/lib/policy/policy.go +++ b/lib/policy/policy.go @@ -6,12 +6,15 @@ import ( "fmt" "io" "log/slog" + "os" "sync/atomic" + "github.com/TecharoHQ/anubis/internal" "github.com/TecharoHQ/anubis/lib/config" "github.com/TecharoHQ/anubis/lib/policy/checker" "github.com/TecharoHQ/anubis/lib/store" "github.com/TecharoHQ/anubis/lib/thoth" + "github.com/fahedouch/go-logrotate" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promauto" @@ -38,6 +41,7 @@ type ParsedConfig struct { StatusCodes config.StatusCodes DefaultDifficulty int DNSBL bool + Logger *slog.Logger } func newParsedConfig(orig *config.Config) *ParsedConfig { @@ -48,7 +52,7 @@ func newParsedConfig(orig *config.Config) *ParsedConfig { } } -func ParseConfig(ctx context.Context, fin io.Reader, fname string, defaultDifficulty int) (*ParsedConfig, error) { +func ParseConfig(ctx context.Context, fin io.Reader, fname string, defaultDifficulty int, logLevel string) (*ParsedConfig, error) { c, err := config.Load(fin, fname) if err != nil { return nil, err @@ -202,6 +206,27 @@ func ParseConfig(ctx context.Context, fin io.Reader, fname string, defaultDiffic validationErrs = append(validationErrs, config.ErrUnknownStoreBackend) } + if c.Logging.Level != nil { + logLevel = c.Logging.Level.String() + } + + switch c.Logging.Sink { + case config.LogSinkStdio: + result.Logger = internal.InitSlog(logLevel, os.Stderr) + case config.LogSinkFile: + out := &logrotate.Logger{ + Filename: c.Logging.Parameters.Filename, + FilenameTimeFormat: c.Logging.Parameters.OldFileTimeFormat, + MaxBytes: c.Logging.Parameters.MaxBytes, + MaxAge: c.Logging.Parameters.MaxAge, + MaxBackups: c.Logging.Parameters.MaxBackups, + LocalTime: c.Logging.Parameters.UseLocalTime, + Compress: c.Logging.Parameters.Compress, + } + + result.Logger = internal.InitSlog(logLevel, out) + } + if len(validationErrs) > 0 { return nil, fmt.Errorf("errors validating policy config JSON %s: %w", fname, errors.Join(validationErrs...)) } diff --git a/lib/policy/policy_test.go b/lib/policy/policy_test.go index b5228574..56ce3731 100644 --- a/lib/policy/policy_test.go +++ b/lib/policy/policy_test.go @@ -19,7 +19,7 @@ func TestDefaultPolicyMustParse(t *testing.T) { } defer fin.Close() - if _, err := ParseConfig(ctx, fin, "botPolicies.yaml", anubis.DefaultDifficulty); err != nil { + if _, err := ParseConfig(ctx, fin, "botPolicies.yaml", anubis.DefaultDifficulty, "info"); err != nil { t.Fatalf("can't parse config: %v", err) } } @@ -42,7 +42,7 @@ func TestGoodConfigs(t *testing.T) { defer fin.Close() ctx := thothmock.WithMockThoth(t) - if _, err := ParseConfig(ctx, fin, fin.Name(), anubis.DefaultDifficulty); err != nil { + if _, err := ParseConfig(ctx, fin, fin.Name(), anubis.DefaultDifficulty, "info"); err != nil { t.Fatal(err) } }) @@ -54,7 +54,7 @@ func TestGoodConfigs(t *testing.T) { } defer fin.Close() - if _, err := ParseConfig(t.Context(), fin, fin.Name(), anubis.DefaultDifficulty); err != nil { + if _, err := ParseConfig(t.Context(), fin, fin.Name(), anubis.DefaultDifficulty, "info"); err != nil { t.Fatal(err) } }) @@ -79,7 +79,7 @@ func TestBadConfigs(t *testing.T) { } defer fin.Close() - if _, err := ParseConfig(ctx, fin, fin.Name(), anubis.DefaultDifficulty); err == nil { + if _, err := ParseConfig(ctx, fin, fin.Name(), anubis.DefaultDifficulty, "info"); err == nil { t.Fatal(err) } else { t.Log(err)