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

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 {
@@ -469,15 +476,15 @@ func main() {
 
 	var h http.Handler
 	h = s
+	h = internal.JA4H(h)
 	h = internal.CustomRealIPHeader(*customRealIPHeader, h)
 	h = internal.RemoteXRealIP(*useRemoteAddress, *bindNetwork, h)
 	h = internal.XForwardedForToXRealIP(h)
 	h = internal.XForwardedForUpdate(*xffStripPrivate, h)
-	h = internal.JA4H(h)
 
 	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"
 )

go.mod

@@ -86,6 +86,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
@@ -96,6 +97,7 @@ require (
 	github.com/facebookgo/ensure v0.0.0-20160127193407-b4ab57deab51 // indirect
 	github.com/facebookgo/stack v0.0.0-20160209184415-751773369052 // indirect
 	github.com/facebookgo/subset v0.0.0-20150612182917-8dac2c3c4870 // indirect
+	github.com/fahedouch/go-logrotate v0.3.0 // indirect
 	github.com/fatih/color v1.18.0 // indirect
 	github.com/felixge/httpsnoop v1.0.4 // indirect
 	github.com/fsnotify/fsnotify v1.9.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"),
 	)
 }

internal/ogtags/cache_test.go

@@ -9,7 +9,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 )

internal/ogtags/fetch_test.go

@@ -11,7 +11,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 	"golang.org/x/net/html"
 )

internal/ogtags/integration_test.go

@@ -7,7 +7,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 )
 

internal/ogtags/mem_test.go

@@ -6,7 +6,7 @@ import (
 	"strings"
 	"testing"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 	"golang.org/x/net/html"
 )

internal/ogtags/ogtags.go

@@ -11,7 +11,7 @@ import (
 	"sync"
 	"time"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store"
 )
 

internal/ogtags/ogtags_fuzz_test.go

@@ -7,7 +7,7 @@ import (
 	"testing"
 	"unicode/utf8"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 	"golang.org/x/net/html"
 )

internal/ogtags/ogtags_test.go

@@ -22,7 +22,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 )
 

internal/ogtags/parse_test.go

@@ -6,7 +6,7 @@ import (
 	"testing"
 	"time"
 
-	"github.com/TecharoHQ/anubis/lib/policy/config"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/store/memory"
 	"golang.org/x/net/html"
 )

internal/test/playwright_test.go

@@ -595,7 +595,7 @@ func spawnAnubisWithOptions(t *testing.T, basePrefix string) string {
 		fmt.Fprintf(w, "<html><body><span id=anubis-test>%d</span></body></html>", 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)
 	}

lib/anubis.go

@@ -27,10 +27,10 @@ import (
 	"github.com/TecharoHQ/anubis/internal/dnsbl"
 	"github.com/TecharoHQ/anubis/internal/ogtags"
 	"github.com/TecharoHQ/anubis/lib/challenge"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/localization"
 	"github.com/TecharoHQ/anubis/lib/policy"
 	"github.com/TecharoHQ/anubis/lib/policy/checker"
-	"github.com/TecharoHQ/anubis/lib/policy/config"
 	"github.com/TecharoHQ/anubis/lib/store"
 
 	// challenge implementations

lib/anubis_test.go

@@ -20,8 +20,8 @@ import (
 	"github.com/TecharoHQ/anubis/data"
 	"github.com/TecharoHQ/anubis/internal"
 	"github.com/TecharoHQ/anubis/lib/challenge"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/policy"
-	"github.com/TecharoHQ/anubis/lib/policy/config"
 	"github.com/TecharoHQ/anubis/lib/store"
 	"github.com/TecharoHQ/anubis/lib/thoth/thothmock"
 )
@@ -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)
 			}
 		})

lib/challenge/interface.go

@@ -6,8 +6,8 @@ import (
 	"sort"
 	"sync"
 
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/policy"
-	"github.com/TecharoHQ/anubis/lib/policy/config"
 	"github.com/TecharoHQ/anubis/lib/store"
 	"github.com/a-h/templ"
 )

lib/challenge/proofofwork/proofofwork_test.go

@@ -8,8 +8,8 @@ import (
 	"testing"
 
 	"github.com/TecharoHQ/anubis/lib/challenge"
+	"github.com/TecharoHQ/anubis/lib/config"
 	"github.com/TecharoHQ/anubis/lib/policy"
-	"github.com/TecharoHQ/anubis/lib/policy/config"
 )
 
 func mkRequest(t *testing.T, values map[string]string) *http.Request {