feat: writing logs to the filesystem with rotation support

.github/actions/spelling/expect.txt

@@ -106,6 +106,7 @@ externalfetcher
 extldflags
 facebookgo
 Factset
+fahedouch
 fastcgi
 fediverse
 ffprobe
@@ -194,6 +195,7 @@ lcj
 ldflags
 letsencrypt
 Lexentale
+lfc
 lgbt
 licend
 licstart

.github/workflows/smoke-tests.yml

@@ -22,6 +22,7 @@ jobs:
           - git-push
           - healthcheck
           - i18n
+          - log-file
           - palemoon/amd64
           #- palemoon/i386
           - robots_txt

cmd/anubis/main.go

@@ -31,8 +31,8 @@ import (
 	"github.com/TecharoHQ/anubis/data"
 	"github.com/TecharoHQ/anubis/internal"
 	libanubis "github.com/TecharoHQ/anubis/lib"
+	"github.com/TecharoHQ/anubis/lib/config"
 	botPolicy "github.com/TecharoHQ/anubis/lib/policy"
-	"github.com/TecharoHQ/anubis/lib/policy/config"
 	"github.com/TecharoHQ/anubis/lib/thoth"
 	"github.com/TecharoHQ/anubis/web"
 	"github.com/facebookgo/flagenv"
@@ -273,9 +273,11 @@ func main() {
 		return
 	}
 
-	internal.InitSlog(*slogLevel)
 	internal.SetHealth("anubis", healthv1.HealthCheckResponse_NOT_SERVING)
 
+	lg := internal.InitSlog(*slogLevel, os.Stderr)
+	lg.Info("starting up Anubis")
+
 	if *healthcheck {
 		log.Println("running healthcheck")
 		if err := doHealthCheck(); err != nil {
@@ -303,7 +305,7 @@ func main() {
 
 	if *metricsBind != "" {
 		wg.Add(1)
-		go metricsServer(ctx, wg.Done)
+		go metricsServer(ctx, *lg.With("subsystem", "metrics"), wg.Done)
 	}
 
 	var rp http.Handler
@@ -323,11 +325,11 @@ func main() {
 	// Thoth configuration
 	switch {
 	case *thothURL != "" && *thothToken == "":
-		slog.Warn("THOTH_URL is set but no THOTH_TOKEN is set")
+		lg.Warn("THOTH_URL is set but no THOTH_TOKEN is set")
 	case *thothURL == "" && *thothToken != "":
-		slog.Warn("THOTH_TOKEN is set but no THOTH_URL is set")
+		lg.Warn("THOTH_TOKEN is set but no THOTH_URL is set")
 	case *thothURL != "" && *thothToken != "":
-		slog.Debug("connecting to Thoth")
+		lg.Debug("connecting to Thoth")
 		thothClient, err := thoth.New(ctx, *thothURL, *thothToken, *thothInsecure)
 		if err != nil {
 			log.Fatalf("can't dial thoth at %s: %v", *thothURL, err)
@@ -336,15 +338,19 @@ 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() {
 		if *hs512Secret == "" && *ed25519PrivateKeyHex == "" && *ed25519PrivateKeyHexFile == "" {
-			slog.Warn("[misconfiguration] persistent storage backend is configured, but no private key is set. " +
+			lg.Warn("[misconfiguration] persistent storage backend is configured, but no private key is set. " +
 				"Challenges will be invalidated when Anubis restarts. " +
 				"Set HS512_SECRET, ED25519_PRIVATE_KEY_HEX, or ED25519_PRIVATE_KEY_HEX_FILE to ensure challenges survive service restarts. " +
 				"See: https://anubis.techaro.lol/docs/admin/installation#key-generation")
@@ -407,7 +413,7 @@ func main() {
 			log.Fatalf("failed to generate ed25519 key: %v", err)
 		}
 
-		slog.Warn("generating random key, Anubis will have strange behavior when multiple instances are behind the same load balancer target, for more information: see https://anubis.techaro.lol/docs/admin/installation#key-generation")
+		lg.Warn("generating random key, Anubis will have strange behavior when multiple instances are behind the same load balancer target, for more information: see https://anubis.techaro.lol/docs/admin/installation#key-generation")
 	}
 
 	var redirectDomainsList []string
@@ -421,7 +427,7 @@ func main() {
 			redirectDomainsList = append(redirectDomainsList, strings.TrimSpace(domain))
 		}
 	} else {
-		slog.Warn("REDIRECT_DOMAINS is not set, Anubis will only redirect to the same domain a request is coming from, see https://anubis.techaro.lol/docs/admin/configuration/redirect-domains")
+		lg.Warn("REDIRECT_DOMAINS is not set, Anubis will only redirect to the same domain a request is coming from, see https://anubis.techaro.lol/docs/admin/configuration/redirect-domains")
 	}
 
 	anubis.CookieName = *cookiePrefix + "-auth"
@@ -461,6 +467,7 @@ func main() {
 		CookieSameSite:           parseSameSite(*cookieSameSite),
 		PublicUrl:                *publicUrl,
 		JWTRestrictionHeader:     *jwtRestrictionHeader,
+		Logger:                   policy.Logger.With("subsystem", "anubis"),
 		DifficultyInJWT:          *difficultyInJWT,
 	})
 	if err != nil {
@@ -477,7 +484,7 @@ func main() {
 
 	srv := http.Server{Handler: h, ErrorLog: internal.GetFilteredHTTPLogger()}
 	listener, listenerUrl := setupListener(*bindNetwork, *bind)
-	slog.Info(
+	lg.Info(
 		"listening",
 		"url", listenerUrl,
 		"difficulty", *challengeDifficulty,
@@ -511,7 +518,7 @@ func main() {
 	wg.Wait()
 }
 
-func metricsServer(ctx context.Context, done func()) {
+func metricsServer(ctx context.Context, lg slog.Logger, done func()) {
 	defer done()
 
 	mux := http.NewServeMux()
@@ -537,7 +544,7 @@ func metricsServer(ctx context.Context, done func()) {
 
 	srv := http.Server{Handler: mux, ErrorLog: internal.GetFilteredHTTPLogger()}
 	listener, metricsUrl := setupListener(*metricsBindNetwork, *metricsBind)
-	slog.Debug("listening for metrics", "url", metricsUrl)
+	lg.Debug("listening for metrics", "url", metricsUrl)
 
 	go func() {
 		<-ctx.Done()

cmd/containerbuild/main.go

@@ -28,7 +28,7 @@ func main() {
 	flagenv.Parse()
 	flag.Parse()
 
-	internal.InitSlog(*slogLevel)
+	slog.SetDefault(internal.InitSlog(*slogLevel, os.Stderr))
 
 	koDockerRepo := strings.TrimSuffix(*dockerRepo, "/"+filepath.Base(*dockerRepo))
 

cmd/robots2policy/main.go

@@ -12,7 +12,7 @@ import (
 	"regexp"
 	"strings"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 
 	"sigs.k8s.io/yaml"
 )

docs/docs/CHANGELOG.md

@@ -21,9 +21,29 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - Allow Renovate as an OCI registry client.
 - Properly handle 4in6 addresses so that IP matching works with those addresses.
 - Add support to simple Valkey/Redis cluster mode
-- Open Graph passthrough now reuses the configured target Host/SNI/TLS settings, so metadata fetches succeed when the upstream certificate differs from the public domain. ([1283](https://github.com/TecharoHQ/anubis/pull/1283)) 
+- Open Graph passthrough now reuses the configured target Host/SNI/TLS settings, so metadata fetches succeed when the upstream certificate differs from the public domain. ([1283](https://github.com/TecharoHQ/anubis/pull/1283))
 - Stabilize the CVE-2025-24369 regression test by always submitting an invalid proof instead of relying on random POW failures.
 
+### Logging customization
+
+Anubis now supports the ability to log to multiple backends ("sinks"). This allows you to have Anubis [log to a file](./admin/policies.mdx#file-sink) instead of just logging to standard out. You can also customize the [logging level](./admin/policies.mdx#log-levels) in the policy file:
+
+```yaml
+logging:
+  level: "warn" # much less verbose logging
+  sink: file # log to a file
+  parameters:
+    file: "./var/anubis.log"
+    maxBackups: 3 # keep at least 3 old copies
+    maxBytes: 67108864 # each file can have up to 64 Mi of logs
+    maxAge: 7 # rotate files out every n days
+    oldFileTimeFormat: 2006-01-02T15-04-05 # RFC 3339-ish
+    compress: true # gzip-compress old log files
+    useLocalTime: false # timezone for rotated files is UTC
+```
+
+Additionally, information about [how Anubis uses each logging level](./admin/policies.mdx#log-levels) has been added to the documentation.
+
 ## v1.23.1: Lyse Hext - Echo 1
 
 - Fix `SERVE_ROBOTS_TXT` setting after the double slash fix broke it.

docs/docs/admin/policies.mdx

@@ -328,6 +328,84 @@ If you are using [Redis™ Sentinel](https://redis.io/docs/latest/operate/oss_an
 | `username`   | string                   | `azurediamond`        | The username used to authenticate against the Redis™ Sentinel and Redis™ servers.                                                                         |
 | `password`   | string                   | `hunter2`             | The password used to authenticate against the Redis™ Sentinel and Redis™ servers.                                                                         |
 
+## Logging management
+
+Anubis has very verbose logging out of the box. This is intentional and allows administrators to be sure that it is working merely by watching it work in real time. Some administrators may not appreciate this level of logging out of the box. As such, Anubis lets you customize details about how it logs data.
+
+Anubis uses a practice called [structured logging](https://stackify.com/what-is-structured-logging-and-why-developers-need-it/) to emit log messages with key-value pair context. In order to make analyzing large amounts of log messages easier, Anubis encodes all logs in JSON. This allows you to use any tool that can parse JSON to perform analytics or monitor for issues.
+
+Anubis exposes the following logging settings in the policy file:
+
+| Name         | Type                     | Example         | Description                                                                                                                              |
+| :----------- | :----------------------- | :-------------- | :--------------------------------------------------------------------------------------------------------------------------------------- |
+| `level`      | [log level](#log-levels) | `info`          | The logging level threshold. Any logs that are at or above this threshold will be drained to the sink. Any other logs will be discarded. |
+| `sink`       | string                   | `stdio`, `file` | The sink where the logs drain to as they are being recorded in Anubis.                                                                   |
+| `parameters` | object                   |                 | Parameters for the given logging sink. This will vary based on the logging sink of choice. See below for more information.               |
+
+Anubis supports the following logging sinks:
+
+1. `file`: logs are emitted to a file that is rotated based on size and age. Old log files are compressed with gzip to save space. This allows for better integration with users that decide to use legacy service managers (OpenRC, FreeBSD's init, etc).
+2. `stdio`: logs are emitted to the standard error stream of the Anubis process. This allows runtimes such as Docker, Podman, Systemd, and Kubernetes to capture logs with their native logging subsystems without any additional configuration.
+
+### Log levels
+
+Anubis uses Go's [standard library `log/slog` package](https://pkg.go.dev/log/slog) to emit structured logs. By default, Anubis logs at the [Info level](https://pkg.go.dev/log/slog#Level), which is fairly verbose out of the box. Here are the possible logging levels in Anubis:
+
+| Log level | Use in Anubis                                                                                                                                             |
+| :-------- | :-------------------------------------------------------------------------------------------------------------------------------------------------------- |
+| `DEBUG`   | The raw unfiltered torrent of doom. Only use this if you are actively working on Anubis or have very good reasons to use it.                              |
+| `INFO`    | The default logging level, fairly verbose in order to make it easier for automation to parse.                                                             |
+| `WARN`    | A "more silent" logging level. Much less verbose. Some things that are now at the `info` level need to be moved up to the `warn` level in future patches. |
+| `ERROR`   | Only log error messages.                                                                                                                                  |
+
+Additionally, you can set a "slightly higher" log level if you need to, such as:
+
+```yaml
+logging:
+  sink: stdio
+  level: "INFO+1"
+```
+
+This isn't currently used by Anubis, but will be in the future for "slightly important" information.
+
+### `file` sink
+
+The `file` sink makes Anubis write its logs to the filesystem and rotate them out when the log file meets certain thresholds. This logging sink takes the following parameters:
+
+| Name           | Type            | Example               | Description                                                                                                                                                                                                                    |
+| :------------- | :-------------- | :-------------------- | :----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
+| `file`         | string          | `/var/log/anubis.log` | The file where Anubis logs should be written to. Make sure the user Anubis is running as has write and file creation permissions to this directory.                                                                            |
+| `maxBackups`   | number          | `3`                   | The number of old log files that should be maintained when log files are rotated out.                                                                                                                                          |
+| `maxBytes`     | number of bytes | `67108864` (64Mi)     | The maximum size of each log file before it is rotated out.                                                                                                                                                                    |
+| `maxAge`       | number of days  | `7`                   | If a log file is more than this many days old, rotate it out.                                                                                                                                                                  |
+| `compress`     | boolean         | `true`                | If true, compress old log files with gzip. This should be set to `true` and is only exposed as an option for dealing with legacy workflows where there is magical thinking about log files at play.                            |
+| `useLocalTime` | boolean         | `false`               | If true, use the system local time zone to create log filenames instead of UTC. This should almost always be set to `false` and is only exposed for legacy workflows where there is magical thinking about time zones at play. |
+
+```yaml
+logging:
+  sink: file
+  parameters:
+    file: "./var/anubis.log"
+    maxBackups: 3 # keep at least 3 old copies
+    maxBytes: 67108864 # each file can have up to 64 Mi of logs
+    maxAge: 7 # rotate files out every n days
+    compress: true # gzip-compress old log files
+    useLocalTime: false # timezone for rotated files is UTC
+```
+
+When files are rotated out, the old files will be named after the rotation timestamp in [RFC 3339 format](https://www.rfc-editor.org/rfc/rfc3339).
+
+### `stdio` sink
+
+By default, Anubis logs everything to the standard error stream of its process. This requires no configuration:
+
+```yaml
+logging:
+  sink: stdio
+```
+
+If you use a service orchestration platform that does not capture the standard error stream of processes, you need to use a different logging sink.
+
 ## Risk calculation for downstream services
 
 In case your service needs it for risk calculation reasons, Anubis exposes information about the rules that any requests match using a few headers:

go.mod

@@ -10,6 +10,7 @@ require (
 	github.com/aws/aws-sdk-go-v2/service/s3 v1.90.2
 	github.com/cespare/xxhash/v2 v2.3.0
 	github.com/facebookgo/flagenv v0.0.0-20160425205200-fcd59fca7456
+	github.com/fahedouch/go-logrotate v0.3.0
 	github.com/gaissmai/bart v0.26.0
 	github.com/golang-jwt/jwt/v5 v5.3.0
 	github.com/google/cel-go v0.26.1
@@ -86,6 +87,7 @@ require (
 	github.com/deckarep/golang-set/v2 v2.8.0 // indirect
 	github.com/dgryski/go-rendezvous v0.0.0-20200823014737-9f7001d12a5f // indirect
 	github.com/distribution/reference v0.6.0 // indirect
+	github.com/djherbis/times v1.6.0 // indirect
 	github.com/dlclark/regexp2 v1.11.5 // indirect
 	github.com/docker/docker v28.5.1+incompatible // indirect
 	github.com/docker/go-connections v0.6.0 // indirect

go.sum

@@ -139,6 +139,8 @@ github.com/dgryski/go-rendezvous v0.0.0-20200823014737-9f7001d12a5f h1:lO4WD4F/r
 github.com/dgryski/go-rendezvous v0.0.0-20200823014737-9f7001d12a5f/go.mod h1:cuUVRXasLTGF7a8hSLbxyZXjz+1KgoB3wDUb6vlszIc=
 github.com/distribution/reference v0.6.0 h1:0IXCQ5g4/QMHHkarYzh5l+u8T3t73zM5QvfrDyIgxBk=
 github.com/distribution/reference v0.6.0/go.mod h1:BbU0aIcezP1/5jX/8MP0YiH4SdvB5Y4f/wlDRiLyi3E=
+github.com/djherbis/times v1.6.0 h1:w2ctJ92J8fBvWPxugmXIv7Nz7Q3iDMKNx9v5ocVH20c=
+github.com/djherbis/times v1.6.0/go.mod h1:gOHeRAz2h+VJNZ5Gmc/o7iD9k4wW7NMVqieYCY99oc0=
 github.com/dlclark/regexp2 v1.11.5 h1:Q/sSnsKerHeCkc/jSTNq1oCm7KiVgUMZRDUoRu0JQZQ=
 github.com/dlclark/regexp2 v1.11.5/go.mod h1:DHkYz0B9wPfa6wondMfaivmHpzrQ3v9q8cnmRbL6yW8=
 github.com/docker/docker v28.5.1+incompatible h1:Bm8DchhSD2J6PsFzxC35TZo4TLGR2PdW/E69rU45NhM=
@@ -163,6 +165,8 @@ github.com/facebookgo/stack v0.0.0-20160209184415-751773369052 h1:JWuenKqqX8nojt
 github.com/facebookgo/stack v0.0.0-20160209184415-751773369052/go.mod h1:UbMTZqLaRiH3MsBH8va0n7s1pQYcu3uTb8G4tygF4Zg=
 github.com/facebookgo/subset v0.0.0-20150612182917-8dac2c3c4870 h1:E2s37DuLxFhQDg5gKsWoLBOB0n+ZW8s599zru8FJ2/Y=
 github.com/facebookgo/subset v0.0.0-20150612182917-8dac2c3c4870/go.mod h1:5tD+neXqOorC30/tWg0LCSkrqj/AR6gu8yY8/fpw1q0=
+github.com/fahedouch/go-logrotate v0.3.0 h1:XP+dHIDgWZ1ckz43mG6gl5ASer3PZDVr755SVMyzaUQ=
+github.com/fahedouch/go-logrotate v0.3.0/go.mod h1:X49m0bvPLkk71MHNCQ1yEfVEw8W/u+qvHa/hOnhCYf4=
 github.com/fatih/color v1.18.0 h1:S8gINlzdQ840/4pfAwic/ZE0djQEH3wM94VfqLTZcOM=
 github.com/fatih/color v1.18.0/go.mod h1:4FelSpRwEGDpQ12mAdzqdOukCy4u8WUtOY6lkT/6HfU=
 github.com/felixge/httpsnoop v1.0.4 h1:NFTV2Zj1bL4mc9sqWACXbQFVBBg2W3GPvqp8/ESS2Wg=
@@ -479,6 +483,7 @@ golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7w
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220520151302-bc2c85ada10a/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.0.0-20220615213510-4f61da869c0c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.1.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=

internal/log.go

@@ -2,14 +2,15 @@ package internal
 
 import (
 	"fmt"
+	"io"
 	"log"
 	"log/slog"
 	"net/http"
 	"os"
 	"strings"
 )
 
-func InitSlog(level string) {
+func InitSlog(level string, sink io.Writer) *slog.Logger {
 	var programLevel slog.Level
 	if err := (&programLevel).UnmarshalText([]byte(level)); err != nil {
 		fmt.Fprintf(os.Stderr, "invalid log level %s: %v, using info\n", level, err)
@@ -19,11 +20,12 @@ func InitSlog(level string) {
 	leveler := &slog.LevelVar{}
 	leveler.Set(programLevel)
 
-	h := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
+	h := slog.NewJSONHandler(sink, &slog.HandlerOptions{
 		AddSource: true,
 		Level:     leveler,
 	})
-	slog.SetDefault(slog.New(h))
+	result := slog.New(h)
+	return result
 }
 
 func GetRequestLogger(base *slog.Logger, r *http.Request) *slog.Logger {
@@ -39,8 +41,7 @@ func GetRequestLogger(base *slog.Logger, r *http.Request) *slog.Logger {
 		"user_agent", r.UserAgent(),
 		"accept_language", r.Header.Get("Accept-Language"),
 		"priority", r.Header.Get("Priority"),
-		"x-forwarded-for",
-		r.Header.Get("X-Forwarded-For"),
+		"x-forwarded-for", r.Header.Get("X-Forwarded-For"),
 		"x-real-ip", r.Header.Get("X-Real-Ip"),
 	)
 }