perf(log): migrate logging from logrus to slog

Replace logrus and logrus-prefixed-formatter with the standard library
log/slog across the whole module. The main driver is performance: the
DNS hot path uses lazy slog.LogValuer fields (QuestionLogValuer /
AnswerLogValuer) so the expensive question/answer formatting is skipped
entirely when the log level is disabled.

- slog default logger (slog.Default/SetDefault) with tint (text) and JSON
  handlers; slog.LevelVar for lock-free runtime level changes
- contextHandler injects request-scoped attrs (req_id, client_ip, ...)
  after the level check, preserving LogValuer laziness
- resolvers use construction-time prefixed, ctx-bound loggers
- request-path call sites use the context-aware slog methods
  (InfoContext/DebugContext/...), enforced by a sloglint `context: scope`
  rule so a missing ctx fails lint wherever a context is in scope
- Recorder + CaptureGlobal/ConfigureForTest test helpers
- no dedicated trace level: folds into debug; "trace" remains a legacy
  config alias that maps to debug
- Silence uses slog.DiscardHandler

Drops logrus and logrus-prefixed-formatter as direct dependencies.
This commit is contained in:
Dimitri Herzog
2026-06-23 22:34:31 +02:00
parent afea4524d4
commit f92bb4535f
179 changed files with 2738 additions and 1612 deletions
+4
View File
@@ -89,6 +89,10 @@ linters:
- recvcheck
- wrapcheck
settings:
goconst:
ignore-tests: true
sloglint:
context: scope
ginkgolinter:
forbid-focus-container: true
mnd:
+13 -13
View File
@@ -5,6 +5,7 @@ import (
"encoding/json"
"errors"
"fmt"
"log/slog"
"strings"
"time"
@@ -15,7 +16,6 @@ import (
"github.com/google/uuid"
"github.com/prometheus/client_golang/prometheus"
"github.com/prometheus/client_golang/prometheus/promauto"
"github.com/sirupsen/logrus"
)
const (
@@ -86,7 +86,7 @@ type RedisExpiringCache[T any] struct {
opts RedisOptions[T]
instanceID string
sendBuf chan sendBufferEntry[T]
logger *logrus.Entry
logger *slog.Logger
}
// NewRedisExpiringByteCache creates a RedisExpiringCache for []byte values,
@@ -155,7 +155,7 @@ func NewRedisExpiringCache[T any](
// Blocking startup load.
if err := c.loadFromRedis(ctx); err != nil {
c.logger.WithError(err).Warn("startup Redis scan failed – starting with empty local cache")
c.logger.WarnContext(ctx, "startup Redis scan failed – starting with empty local cache", log.AttrError(err))
}
go c.runSubscriber(ctx)
@@ -225,7 +225,7 @@ func (c *RedisExpiringCache[T]) Clear() {
return c.client.Del(ctx, keys...).Err()
})
if err != nil {
c.logger.WithError(err).Warn("Redis Clear failed")
c.logger.Warn("Redis Clear failed", log.AttrError(err))
}
}
@@ -269,7 +269,7 @@ func (c *RedisExpiringCache[T]) scanKeys(
func (c *RedisExpiringCache[T]) loadFromRedis(ctx context.Context) error {
return c.scanKeys(ctx, func(ctx context.Context, keys []string) error {
if err := c.loadKeysViaPipeline(ctx, keys); err != nil {
c.logger.WithError(err).Warn("pipeline load failed for SCAN page")
c.logger.WarnContext(ctx, "pipeline load failed for SCAN page", log.AttrError(err))
}
return nil
@@ -305,7 +305,7 @@ func (c *RedisExpiringCache[T]) loadKeysViaPipeline(ctx context.Context, keys []
val, err := c.opts.Decode(data)
if err != nil {
c.logger.WithError(err).Warn("failed to decode Redis entry on startup")
c.logger.WarnContext(ctx, "failed to decode Redis entry on startup", log.AttrError(err))
continue
}
@@ -380,7 +380,7 @@ func (c *RedisExpiringCache[T]) flushBatch(ctx context.Context, batch []sendBuff
for _, e := range batch {
data, err := c.opts.Encode(e.val)
if err != nil {
c.logger.WithError(err).Warn("failed to encode cache entry for Redis")
c.logger.WarnContext(ctx, "failed to encode cache entry for Redis", log.AttrError(err))
continue
}
@@ -394,7 +394,7 @@ func (c *RedisExpiringCache[T]) flushBatch(ctx context.Context, batch []sendBuff
}
if _, err := pipe.Exec(ctx); err != nil && ctx.Err() == nil {
c.logger.WithError(err).Warn("Redis pipeline exec failed")
c.logger.WarnContext(ctx, "Redis pipeline exec failed", log.AttrError(err))
}
if len(syncEntries) == 0 || c.opts.Channel == "" {
@@ -408,13 +408,13 @@ func (c *RedisExpiringCache[T]) flushBatch(ctx context.Context, batch []sendBuff
payload, err := json.Marshal(msg)
if err != nil {
c.logger.WithError(err).Warn("failed to marshal sync message")
c.logger.WarnContext(ctx, "failed to marshal sync message", log.AttrError(err))
return
}
if err := c.client.Publish(ctx, c.opts.Channel, payload).Err(); err != nil && ctx.Err() == nil {
c.logger.WithError(err).Warn("Redis PUBLISH failed")
c.logger.WarnContext(ctx, "Redis PUBLISH failed", log.AttrError(err))
}
}
@@ -443,7 +443,7 @@ func (c *RedisExpiringCache[T]) runSubscriber(ctx context.Context) {
func (c *RedisExpiringCache[T]) handleSyncMessage(ctx context.Context, payload []byte) {
var msg redisSyncMessage
if err := json.Unmarshal(payload, &msg); err != nil {
c.logger.WithError(err).Warn("failed to decode sync message")
c.logger.WarnContext(ctx, "failed to decode sync message", log.AttrError(err))
return
}
@@ -460,7 +460,7 @@ func (c *RedisExpiringCache[T]) handleSyncMessage(ctx context.Context, payload [
}
if _, err := pipe.Exec(ctx); err != nil {
c.logger.WithError(err).Warn("failed to fetch TTLs for sync entries")
c.logger.WarnContext(ctx, "failed to fetch TTLs for sync entries", log.AttrError(err))
return
}
@@ -473,7 +473,7 @@ func (c *RedisExpiringCache[T]) handleSyncMessage(ctx context.Context, payload [
val, err := c.opts.Decode(e.Data)
if err != nil {
c.logger.WithError(err).Warn("failed to decode sync entry")
c.logger.WarnContext(ctx, "failed to decode sync entry", log.AttrError(err))
continue
}
+3 -3
View File
@@ -9,9 +9,9 @@ import (
. "github.com/onsi/gomega"
)
func init() {
log.Silence()
}
var _ = BeforeSuite(func() {
log.ConfigureForTest(GinkgoWriter)
})
func TestCache(t *testing.T) {
RegisterFailHandler(Fail)
+17 -8
View File
@@ -1,6 +1,8 @@
package stringcache
import (
"fmt"
"log/slog"
"regexp"
"slices"
"sort"
@@ -55,7 +57,9 @@ func (cache stringMap) findMatch(searchString string) (string, bool) {
if idx < searchBucketLen {
blockRule := cache[searchLen][idx*searchLen : idx*searchLen+searchLen]
if blockRule == normalized {
log.PrefixedLog("string_map").Debugf("block rule '%s' matched with '%s'", blockRule, searchString)
log.PrefixedLog("string_map").Debug("block rule matched",
slog.String("rule", blockRule),
slog.String("search", searchString))
return blockRule, true
}
@@ -131,7 +135,9 @@ func (cache regexCache) elementCount() int {
func (cache regexCache) findMatch(searchString string) (string, bool) {
for _, regex := range cache {
if regex.MatchString(searchString) {
log.PrefixedLog("regex_cache").Debugf("regex '%s' matched with '%s'", regex, searchString)
log.PrefixedLog("regex_cache").Debug("block rule matched",
slog.String("rule", regex.String()),
slog.String("search", searchString))
// re-wrap in the '/.../' delimiters that addEntry strips on insertion
// so the reported rule matches the entry as configured by the user.
@@ -156,7 +162,7 @@ func (r *regexCacheFactory) addEntry(entry string) bool {
compile, err := regexp.Compile(entry)
if err != nil {
log.Log().Warnf("invalid regex '%s'", entry)
log.Log().Warn(fmt.Sprintf("invalid regex '%s'", entry))
return true // invalid but handled
}
@@ -185,8 +191,9 @@ func newRegexCacheFactory() cacheFactory {
}
type wildcardCache struct {
trie trie.Trie
cnt int
trie trie.Trie
cnt int
logger *slog.Logger
}
func (cache wildcardCache) elementCount() int {
@@ -206,7 +213,9 @@ func (cache wildcardCache) findMatch(domain string) (string, bool) {
// concern rather than being hard-coded here.
rule := "*." + trie.JoinTLD(labels)
log.PrefixedLog("wildcard_cache").Debugf("wildcard block rule '%s' matched with '%s'", rule, domain)
cache.logger.Debug("block rule matched",
slog.String("rule", rule),
slog.String("search", domain))
return rule, true
}
@@ -229,7 +238,7 @@ func (r *wildcardCacheFactory) addEntry(entry string) bool {
}
if !strings.HasPrefix(entry, "*.") || globCount > 1 {
log.Log().Warnf("unsupported wildcard '%s': must start with '*.' and contain no other '*'", entry)
log.Log().Warn(fmt.Sprintf("unsupported wildcard '%s': must start with '*.' and contain no other '*'", entry))
return true // invalid but handled
}
@@ -252,7 +261,7 @@ func (r *wildcardCacheFactory) create() stringCache {
return nil
}
return wildcardCache{*r.trie, r.cnt}
return wildcardCache{*r.trie, r.cnt, log.PrefixedLog("wildcard_cache")}
}
func normalizeWildcard(domain string) string {
+1 -1
View File
@@ -276,7 +276,7 @@ func loadTestdata(path string) (res []string) {
p := parsers.AllowErrors(parsers.Hosts(f), parsers.NoErrorLimit)
p.OnErr(func(err error) {
log.Log().Warnf("could not parse line in %s: %s", path, err)
log.Log().Warn(fmt.Sprintf("could not parse line in %s: %s", path, err))
})
err = parsers.ForEach[*parsers.HostsIterator](context.Background(), p, func(hosts *parsers.HostsIterator) error {
+5 -5
View File
@@ -2,11 +2,11 @@ package cmd
import (
"fmt"
"log/slog"
"net/http"
"strings"
"github.com/0xERR0R/blocky/api"
"github.com/0xERR0R/blocky/log"
"github.com/spf13/cobra"
)
@@ -103,7 +103,7 @@ func statusBlocking(cmd *cobra.Command, _ []string) error {
}
if resp.JSON200.Enabled {
log.Log().Info("blocking enabled")
slog.Info("blocking enabled")
} else {
var groupNames string
if resp.JSON200.DisabledGroups != nil {
@@ -111,10 +111,10 @@ func statusBlocking(cmd *cobra.Command, _ []string) error {
}
if resp.JSON200.AutoEnableInSec == nil || *resp.JSON200.AutoEnableInSec == 0 {
log.Log().Infof("blocking disabled for groups: %s", groupNames)
slog.Info("blocking disabled for groups: " + groupNames)
} else {
log.Log().Infof("blocking disabled for groups: '%s', for %d seconds",
groupNames, *resp.JSON200.AutoEnableInSec)
slog.Info(fmt.Sprintf("blocking disabled for groups: '%s', for %d seconds",
groupNames, *resp.JSON200.AutoEnableInSec))
}
}
+11 -15
View File
@@ -7,8 +7,6 @@ import (
"net/url"
"strconv"
"github.com/sirupsen/logrus/hooks/test"
"github.com/0xERR0R/blocky/api"
"github.com/0xERR0R/blocky/log"
@@ -18,9 +16,9 @@ import (
var _ = Describe("Blocking command", func() {
var (
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
loggerHook *test.Hook
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
rec *log.Recorder
)
JustBeforeEach(func() {
ts = testHTTPAPIServer(mockFn)
@@ -30,17 +28,15 @@ var _ = Describe("Blocking command", func() {
})
BeforeEach(func() {
mockFn = func(w http.ResponseWriter, _ *http.Request) {}
loggerHook = test.NewGlobal()
log.Log().AddHook(loggerHook)
})
AfterEach(func() {
loggerHook.Reset()
var restore func()
rec, restore = log.CaptureGlobal()
DeferCleanup(restore)
})
Describe("enable blocking", func() {
When("Enable blocking is called via REST", func() {
It("should enable the blocking status", func() {
Expect(disableBlocking(withContext(newBlockingCommand()), []string{})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(Equal("OK"))
Expect(rec.LastMessage()).Should(Equal("OK"))
})
})
When("Wrong url is used", func() {
@@ -68,7 +64,7 @@ var _ = Describe("Blocking command", func() {
When("disable blocking is called via REST", func() {
It("should enable the blocking status", func() {
Expect(disableBlocking(withContext(newBlockingCommand()), []string{})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(Equal("OK"))
Expect(rec.LastMessage()).Should(Equal("OK"))
})
})
When("Wrong url is used", func() {
@@ -110,7 +106,7 @@ var _ = Describe("Blocking command", func() {
})
It("should query the blocking status", func() {
Expect(statusBlocking(withContext(newBlockingCommand()), []string{})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(Equal("blocking enabled"))
Expect(rec.LastMessage()).Should(Equal("blocking enabled"))
})
})
When("status blocking is called via REST and blocking is disabled", func() {
@@ -133,12 +129,12 @@ var _ = Describe("Blocking command", func() {
It("should show the blocking status with time", func() {
autoEnable = 5
Expect(statusBlocking(withContext(newBlockingCommand()), []string{})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(Equal("blocking disabled for groups: 'abc', for 5 seconds"))
Expect(rec.LastMessage()).Should(Equal("blocking disabled for groups: 'abc', for 5 seconds"))
})
It("should show the blocking status", func() {
autoEnable = 0
Expect(statusBlocking(withContext(newBlockingCommand()), []string{})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(Equal("blocking disabled for groups: abc"))
Expect(rec.LastMessage()).Should(Equal("blocking disabled for groups: abc"))
})
})
When("Wrong url is used", func() {
+7 -11
View File
@@ -4,8 +4,6 @@ import (
"net/http"
"net/http/httptest"
"github.com/sirupsen/logrus/hooks/test"
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
@@ -14,9 +12,9 @@ import (
var _ = Describe("Cache command", func() {
var (
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
loggerHook *test.Hook
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
rec *log.Recorder
)
JustBeforeEach(func() {
ts = testHTTPAPIServer(mockFn)
@@ -26,17 +24,15 @@ var _ = Describe("Cache command", func() {
})
BeforeEach(func() {
mockFn = func(w http.ResponseWriter, _ *http.Request) {}
loggerHook = test.NewGlobal()
log.Log().AddHook(loggerHook)
})
AfterEach(func() {
loggerHook.Reset()
var restore func()
rec, restore = log.CaptureGlobal()
DeferCleanup(restore)
})
Describe("flush cache", func() {
When("flush cache is called via REST", func() {
It("should flush caches", func() {
Expect(flushCache(withContext(newCacheCommand()), []string{})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(Equal("OK"))
Expect(rec.LastMessage()).Should(Equal("OK"))
})
})
When("Wrong url is used", func() {
+13 -15
View File
@@ -6,27 +6,25 @@ import (
"github.com/0xERR0R/blocky/config"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus/hooks/test"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
)
var _ = Describe("warnMissingPrivilegedPortCapability", func() {
var (
loggerHook *test.Hook
origRaise func() (bool, error)
rec *log.Recorder
origRaise func() (bool, error)
)
BeforeEach(func() {
origRaise = raiseNetBindService
loggerHook = test.NewGlobal()
log.Log().AddHook(loggerHook)
var restore func()
rec, restore = log.CaptureGlobal()
DeferCleanup(restore)
})
AfterEach(func() {
raiseNetBindService = origRaise
loggerHook.Reset()
})
When("the capability is effective", func() {
@@ -36,7 +34,7 @@ var _ = Describe("warnMissingPrivilegedPortCapability", func() {
It("does not warn even with a privileged port", func() {
warnMissingPrivilegedPortCapability(config.Ports{DNS: config.ListenConfig{":53"}})
Expect(loggerHook.AllEntries()).Should(BeEmpty())
Expect(rec.Records()).Should(BeEmpty())
})
})
@@ -47,7 +45,7 @@ var _ = Describe("warnMissingPrivilegedPortCapability", func() {
It("warns when a privileged port is configured", func() {
warnMissingPrivilegedPortCapability(config.Ports{DNS: config.ListenConfig{":53"}})
Expect(loggerHook.LastEntry().Message).Should(ContainSubstring("CAP_NET_BIND_SERVICE"))
Expect(rec.LastMessage()).Should(ContainSubstring("CAP_NET_BIND_SERVICE"))
})
It("does not warn when only unprivileged ports are configured", func() {
@@ -55,7 +53,7 @@ var _ = Describe("warnMissingPrivilegedPortCapability", func() {
DNS: config.ListenConfig{":1053"},
HTTP: config.ListenConfig{":4000"},
})
Expect(loggerHook.AllEntries()).Should(BeEmpty())
Expect(rec.Records()).Should(BeEmpty())
})
})
@@ -66,8 +64,8 @@ var _ = Describe("warnMissingPrivilegedPortCapability", func() {
It("logs one combined warning naming the error and the capability", func() {
warnMissingPrivilegedPortCapability(config.Ports{DNS: config.ListenConfig{":53"}})
Expect(loggerHook.AllEntries()).Should(HaveLen(1))
Expect(loggerHook.LastEntry().Message).Should(SatisfyAll(
Expect(rec.Records()).Should(HaveLen(1))
Expect(rec.LastMessage()).Should(SatisfyAll(
ContainSubstring("could not adjust process capabilities"),
ContainSubstring("CAP_NET_BIND_SERVICE"),
))
@@ -75,9 +73,9 @@ var _ = Describe("warnMissingPrivilegedPortCapability", func() {
It("logs only the error when no privileged port is configured", func() {
warnMissingPrivilegedPortCapability(config.Ports{DNS: config.ListenConfig{":1053"}})
Expect(loggerHook.AllEntries()).Should(HaveLen(1))
Expect(loggerHook.LastEntry().Message).Should(ContainSubstring("could not adjust process capabilities"))
Expect(loggerHook.LastEntry().Message).ShouldNot(ContainSubstring("CAP_NET_BIND_SERVICE"))
Expect(rec.Records()).Should(HaveLen(1))
Expect(rec.LastMessage()).Should(ContainSubstring("could not adjust process capabilities"))
Expect(rec.LastMessage()).ShouldNot(ContainSubstring("CAP_NET_BIND_SERVICE"))
})
})
})
+3 -3
View File
@@ -11,9 +11,9 @@ import (
. "github.com/onsi/gomega"
)
func init() {
log.Silence()
}
var _ = BeforeSuite(func() {
log.ConfigureForTest(GinkgoWriter)
})
func TestCmd(t *testing.T) {
RegisterFailHandler(Fail)
+10 -17
View File
@@ -5,7 +5,6 @@ import (
"net/http/httptest"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus/hooks/test"
"github.com/spf13/cobra"
. "github.com/onsi/ginkgo/v2"
@@ -14,11 +13,11 @@ import (
var _ = Describe("Lists command", func() {
var (
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
loggerHook *test.Hook
c *cobra.Command
err error
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
rec *log.Recorder
c *cobra.Command
err error
)
JustBeforeEach(func() {
ts = testHTTPAPIServer(mockFn)
@@ -28,23 +27,17 @@ var _ = Describe("Lists command", func() {
})
BeforeEach(func() {
mockFn = func(w http.ResponseWriter, _ *http.Request) {}
loggerHook = test.NewGlobal()
log.Log().AddHook(loggerHook)
})
AfterEach(func() {
loggerHook.Reset()
var restore func()
rec, restore = log.CaptureGlobal()
DeferCleanup(restore)
})
Describe("Call list refresh command", func() {
When("list refresh is executed", func() {
BeforeEach(func() {
c = NewListsCommand()
c.SetArgs([]string{"refresh"})
})
It("should print result", func() {
err = c.Execute()
err = refreshList(withContext(newRefreshCommand()), nil)
Expect(err).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(ContainSubstring("OK"))
Expect(rec.LastMessage()).Should(ContainSubstring("OK"))
})
})
When("Server returns 500", func() {
+6 -6
View File
@@ -2,10 +2,10 @@ package cmd
import (
"fmt"
"log/slog"
"net/http"
"github.com/0xERR0R/blocky/api"
"github.com/0xERR0R/blocky/log"
"github.com/miekg/dns"
"github.com/spf13/cobra"
)
@@ -52,11 +52,11 @@ func query(cmd *cobra.Command, args []string) error {
return fmt.Errorf("response NOK, %s %s", resp.Status(), string(resp.Body))
}
log.Log().Infof("Query result for '%s' (%s):", req.Query, req.Type)
log.Log().Infof("\treason: %20s", resp.JSON200.Reason)
log.Log().Infof("\tresponse type: %20s", resp.JSON200.ResponseType)
log.Log().Infof("\tresponse: %20s", resp.JSON200.Response)
log.Log().Infof("\treturn code: %20s", resp.JSON200.ReturnCode)
slog.Info(fmt.Sprintf("Query result for '%s' (%s):", req.Query, req.Type))
slog.Info(fmt.Sprintf("\treason: %20s", resp.JSON200.Reason))
slog.Info(fmt.Sprintf("\tresponse type: %20s", resp.JSON200.ResponseType))
slog.Info(fmt.Sprintf("\tresponse: %20s", resp.JSON200.Response))
slog.Info(fmt.Sprintf("\treturn code: %20s", resp.JSON200.ReturnCode))
return nil
}
+7 -10
View File
@@ -6,7 +6,6 @@ import (
"net/http/httptest"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus/hooks/test"
"github.com/0xERR0R/blocky/api"
@@ -16,9 +15,9 @@ import (
var _ = Describe("Blocking command", func() {
var (
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
loggerHook *test.Hook
ts *httptest.Server
mockFn func(w http.ResponseWriter, _ *http.Request)
rec *log.Recorder
)
JustBeforeEach(func() {
ts = testHTTPAPIServer(mockFn)
@@ -28,11 +27,9 @@ var _ = Describe("Blocking command", func() {
})
BeforeEach(func() {
mockFn = func(w http.ResponseWriter, _ *http.Request) {}
loggerHook = test.NewGlobal()
log.Log().AddHook(loggerHook)
})
AfterEach(func() {
loggerHook.Reset()
var restore func()
rec, restore = log.CaptureGlobal()
DeferCleanup(restore)
})
Describe("Call query command", func() {
BeforeEach(func() {
@@ -67,7 +64,7 @@ var _ = Describe("Blocking command", func() {
})
It("should print result", func() {
Expect(query(withContext(NewQueryCommand()), []string{"google.de"})).Should(Succeed())
Expect(loggerHook.LastEntry().Message).Should(ContainSubstring("NOERROR"))
Expect(rec.LastMessage()).Should(ContainSubstring("NOERROR"))
})
})
When("Server returns 500", func() {
+2 -1
View File
@@ -2,6 +2,7 @@ package cmd
import (
"fmt"
"log/slog"
"net"
"net/http"
"os"
@@ -132,7 +133,7 @@ type codeWithStatus interface {
func printOkOrError(resp codeWithStatus, body string) error {
if resp.StatusCode() == http.StatusOK {
log.Log().Info("OK")
slog.Info("OK")
} else {
return fmt.Errorf("response NOK, %s %s", resp.Status(), body)
}
-3
View File
@@ -5,8 +5,6 @@ import (
"net/http"
"os"
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
@@ -29,7 +27,6 @@ func (m mockResponse) Status() string {
var _ = Describe("root command", func() {
When("Version command is called", func() {
log.Log().ExitFunc = nil
It("should execute without error", func() {
c := NewRootCommand()
c.SetOut(io.Discard)
+23 -22
View File
@@ -3,6 +3,7 @@ package cmd
import (
"context"
"fmt"
"log/slog"
"os"
"os/signal"
"strings"
@@ -55,14 +56,14 @@ func warnMissingPrivilegedPortCapability(ports config.Ports) {
effective, err := raiseNetBindService()
if err != nil {
if privileged := ports.PrivilegedPorts(); len(privileged) > 0 {
log.Log().Warnf("could not adjust process capabilities (%v); binding "+
slog.Warn(fmt.Sprintf("could not adjust process capabilities (%v); binding "+
"privileged port(s) %s may fail — %s",
err, strings.Join(privileged, ", "), privilegedPortCapHint)
err, strings.Join(privileged, ", "), privilegedPortCapHint))
return
}
log.Log().Warnf("could not adjust process capabilities: %v", err)
slog.Warn(fmt.Sprintf("could not adjust process capabilities: %v", err))
return
}
@@ -72,8 +73,8 @@ func warnMissingPrivilegedPortCapability(ports config.Ports) {
}
if privileged := ports.PrivilegedPorts(); len(privileged) > 0 {
log.Log().Warnf("configured to listen on privileged port(s) %s without "+
"CAP_NET_BIND_SERVICE; %s", strings.Join(privileged, ", "), privilegedPortCapHint)
slog.Warn(fmt.Sprintf("configured to listen on privileged port(s) %s without "+
"CAP_NET_BIND_SERVICE; %s", strings.Join(privileged, ", "), privilegedPortCapHint))
}
}
@@ -109,7 +110,7 @@ func startServer(_ *cobra.Command, _ []string) error {
go func() {
select {
case <-signals:
log.Log().Infof("Terminating...")
slog.Info("Terminating...")
// Cancel background operations (periodic refresh, etc.)
cancelFn()
@@ -122,7 +123,7 @@ func startServer(_ *cobra.Command, _ []string) error {
done <- true
case err := <-errChan:
log.Log().Error("server start failed: ", err)
slog.Error("server start failed", log.AttrError(err))
terminationErr = err
done <- true
}
@@ -135,19 +136,19 @@ func startServer(_ *cobra.Command, _ []string) error {
}
func printBanner() {
log.Log().Info("_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/")
log.Log().Info("_/ _/")
log.Log().Info("_/ _/")
log.Log().Info("_/ _/ _/ _/ _/")
log.Log().Info("_/ _/_/_/ _/ _/_/ _/_/_/ _/ _/ _/ _/ _/")
log.Log().Info("_/ _/ _/ _/ _/ _/ _/ _/_/ _/ _/ _/")
log.Log().Info("_/ _/ _/ _/ _/ _/ _/ _/ _/ _/ _/ _/")
log.Log().Info("_/ _/_/_/ _/ _/_/ _/_/_/ _/ _/ _/_/_/ _/")
log.Log().Info("_/ _/ _/")
log.Log().Info("_/ _/_/ _/")
log.Log().Info("_/ _/")
log.Log().Info("_/ _/")
log.Log().Infof("_/ Version: %-18s Build time: %-18s _/", util.Version, util.BuildTime)
log.Log().Info("_/ _/")
log.Log().Info("_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/")
slog.Info("_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/")
slog.Info("_/ _/")
slog.Info("_/ _/")
slog.Info("_/ _/ _/ _/ _/")
slog.Info("_/ _/_/_/ _/ _/_/ _/_/_/ _/ _/ _/ _/ _/")
slog.Info("_/ _/ _/ _/ _/ _/ _/ _/_/ _/ _/ _/")
slog.Info("_/ _/ _/ _/ _/ _/ _/ _/ _/ _/ _/ _/")
slog.Info("_/ _/_/_/ _/ _/_/ _/_/_/ _/ _/ _/_/_/ _/")
slog.Info("_/ _/ _/")
slog.Info("_/ _/_/ _/")
slog.Info("_/ _/")
slog.Info("_/ _/")
slog.Info(fmt.Sprintf("_/ Version: %-18s Build time: %-18s _/", util.Version, util.BuildTime))
slog.Info("_/ _/")
slog.Info("_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/_/")
}
+3 -4
View File
@@ -2,10 +2,9 @@ package cmd
import (
"errors"
"log/slog"
"os"
"github.com/0xERR0R/blocky/log"
"github.com/spf13/cobra"
)
@@ -22,7 +21,7 @@ func NewValidateCommand() *cobra.Command {
}
func validateConfiguration(_ *cobra.Command, _ []string) error {
log.Log().Infof("Validating configuration file: %s", configPath)
slog.Info("Validating configuration file: " + configPath)
_, err := os.Stat(configPath)
if err != nil && errors.Is(err, os.ErrNotExist) {
@@ -34,7 +33,7 @@ func validateConfiguration(_ *cobra.Command, _ []string) error {
return err
}
log.Log().Info("Configuration is valid")
slog.Info("Configuration is valid")
return nil
}
+14 -14
View File
@@ -2,13 +2,13 @@ package config
import (
"fmt"
"log/slog"
"maps"
"slices"
"strings"
. "github.com/0xERR0R/blocky/config/migration"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus"
)
// Blocking configuration for query blocking
@@ -45,7 +45,7 @@ type Blocking struct {
} `yaml:",inline"`
}
func (c *Blocking) migrate(logger *logrus.Entry) bool {
func (c *Blocking) migrate(logger *slog.Logger) bool {
return Migrate(logger, "blocking", c.Deprecated, map[string]Migrator{
"blackLists": Move(To("denylists", c)),
"whiteLists": Move(To("allowlists", c)),
@@ -70,11 +70,11 @@ func (c *Blocking) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *Blocking) LogConfig(logger *logrus.Entry) {
func (c *Blocking) LogConfig(logger *slog.Logger) {
logger.Info("clientGroupsBlock:")
for key, val := range c.ClientGroupsBlock {
logger.Infof(" %s = %v", key, val)
logger.Info(fmt.Sprintf(" %s = %v", key, val))
}
if len(c.Schedules) > 0 {
@@ -82,9 +82,9 @@ func (c *Blocking) LogConfig(logger *logrus.Entry) {
for name, sched := range c.Schedules {
if sched.Start == "" && sched.End == "" {
logger.Infof(" %s: all day (weekdays: %v)", name, sched.Weekdays)
logger.Info(fmt.Sprintf(" %s: all day (weekdays: %v)", name, sched.Weekdays))
} else {
logger.Infof(" %s: %s - %s (weekdays: %v)", name, sched.Start, sched.End, sched.Weekdays)
logger.Info(fmt.Sprintf(" %s: %s - %s (weekdays: %v)", name, sched.Start, sched.End, sched.Weekdays))
}
}
}
@@ -93,33 +93,33 @@ func (c *Blocking) LogConfig(logger *logrus.Entry) {
logger.Info("listSchedules:")
for list, scheds := range c.ListSchedules {
logger.Infof(" %s = %v", list, scheds)
logger.Info(fmt.Sprintf(" %s = %v", list, scheds))
}
}
logger.Infof("blockType = %s", c.BlockType)
logger.Infof("blockTTL = %s", c.BlockTTL)
logger.Info("blockType = " + c.BlockType)
logger.Info(fmt.Sprintf("blockTTL = %s", c.BlockTTL))
logger.Info("loading:")
log.WithIndent(logger, " ", c.Loading.LogConfig)
logger.Info("denylists:")
log.WithIndent(logger, " ", func(logger *logrus.Entry) {
log.WithIndent(logger, " ", func(logger *slog.Logger) {
c.logListGroups(logger, c.Denylists)
})
logger.Info("allowlists:")
log.WithIndent(logger, " ", func(logger *logrus.Entry) {
log.WithIndent(logger, " ", func(logger *slog.Logger) {
c.logListGroups(logger, c.Allowlists)
})
}
func (c *Blocking) logListGroups(logger *logrus.Entry, listGroups map[string][]BytesSource) {
func (c *Blocking) logListGroups(logger *slog.Logger, listGroups map[string][]BytesSource) {
for group, sources := range listGroups {
logger.Infof("%s:", group)
logger.Info(group + ":")
for _, source := range sources {
logger.Infof(" - %s", source)
logger.Info(fmt.Sprintf(" - %s", source))
}
}
}
+11 -11
View File
@@ -55,9 +55,9 @@ var _ = Describe("BlockingConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages[0]).Should(Equal("clientGroupsBlock:"))
Expect(hook.Messages).Should(ContainElement(Equal("blockType = ZEROIP")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()[0]).Should(Equal("clientGroupsBlock:"))
Expect(rec.Messages()).Should(ContainElement(Equal("blockType = ZEROIP")))
})
It("should log time-range schedules", func() {
@@ -66,8 +66,8 @@ var _ = Describe("BlockingConfig", func() {
}
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(Equal("schedules:")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("night: 22:00 - 07:00")))
Expect(rec.Messages()).Should(ContainElement(Equal("schedules:")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("night: 22:00 - 07:00")))
})
It("should log full-day schedules", func() {
@@ -76,8 +76,8 @@ var _ = Describe("BlockingConfig", func() {
}
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(Equal("schedules:")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("weekend: all day")))
Expect(rec.Messages()).Should(ContainElement(Equal("schedules:")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("weekend: all day")))
})
It("should log listSchedules", func() {
@@ -86,8 +86,8 @@ var _ = Describe("BlockingConfig", func() {
}
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(Equal("listSchedules:")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("gr1 = [night]")))
Expect(rec.Messages()).Should(ContainElement(Equal("listSchedules:")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("gr1 = [night]")))
})
})
@@ -106,8 +106,8 @@ var _ = Describe("BlockingConfig", func() {
migrated := cfg.migrate(logger)
Expect(migrated).Should(BeTrue())
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("blocking.allowlists"),
ContainSubstring("blocking.denylists"),
))
+12 -12
View File
@@ -1,9 +1,9 @@
package config
import (
"fmt"
"log/slog"
"time"
"github.com/sirupsen/logrus"
)
// Caching configuration for domain caching
@@ -34,20 +34,20 @@ func (c *Caching) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *Caching) LogConfig(logger *logrus.Entry) {
logger.Infof("minTime = %s", c.MinCachingTime)
logger.Infof("maxTime = %s", c.MaxCachingTime)
logger.Infof("cacheTimeNegative = %s", c.CacheTimeNegative)
logger.Infof("exclude:")
func (c *Caching) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("minTime = %s", c.MinCachingTime))
logger.Info(fmt.Sprintf("maxTime = %s", c.MaxCachingTime))
logger.Info(fmt.Sprintf("cacheTimeNegative = %s", c.CacheTimeNegative))
logger.Info("exclude:")
for _, val := range c.Exclude {
logger.Infof("- %v", val)
logger.Info(fmt.Sprintf("- %v", val))
}
if c.Prefetching {
logger.Infof("prefetching:")
logger.Infof(" expires = %s", c.PrefetchExpires)
logger.Infof(" threshold = %d", c.PrefetchThreshold)
logger.Infof(" maxItems = %d", c.PrefetchMaxItemsCount)
logger.Info("prefetching:")
logger.Info(fmt.Sprintf(" expires = %s", c.PrefetchExpires))
logger.Info(fmt.Sprintf(" threshold = %d", c.PrefetchThreshold))
logger.Info(fmt.Sprintf(" maxItems = %d", c.PrefetchMaxItemsCount))
} else {
logger.Debug("prefetching: disabled")
}
+7 -7
View File
@@ -66,8 +66,8 @@ var _ = Describe("CachingConfig", func() {
It("should return configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("prefetching:")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("prefetching:")))
})
})
When("has any settings", func() {
@@ -77,8 +77,8 @@ var _ = Describe("CachingConfig", func() {
It("should return Exclude", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("exclude:")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("exclude:")))
})
})
When("Exclude any settings", func() {
@@ -88,9 +88,9 @@ var _ = Describe("CachingConfig", func() {
It("should return Exclude and a list with values in it", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("exclude:")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("- local")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("exclude:")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("- local")))
})
})
})
+7 -7
View File
@@ -1,9 +1,9 @@
package config
import (
"fmt"
"log/slog"
"net"
"github.com/sirupsen/logrus"
)
// ClientLookup configuration for the client lookup
@@ -22,18 +22,18 @@ func (c *ClientLookup) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *ClientLookup) LogConfig(logger *logrus.Entry) {
func (c *ClientLookup) LogConfig(logger *slog.Logger) {
if !c.Upstream.IsDefault() {
logger.Infof("upstream = %s", c.Upstream)
logger.Info(fmt.Sprintf("upstream = %s", c.Upstream))
}
logger.Infof("singleNameOrder = %v", c.SingleNameOrder)
logger.Info(fmt.Sprintf("singleNameOrder = %v", c.SingleNameOrder))
if len(c.ClientnameIPMapping) > 0 {
logger.Infof("client IP mapping:")
logger.Info("client IP mapping:")
for k, v := range c.ClientnameIPMapping {
logger.Infof(" %s = %s", k, v)
logger.Info(fmt.Sprintf(" %s = %s", k, v))
}
}
}
+2 -2
View File
@@ -59,8 +59,8 @@ var _ = Describe("ClientLookupConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("client IP mapping:")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("client IP mapping:")))
})
})
})
+3 -4
View File
@@ -2,9 +2,8 @@ package config
import (
"fmt"
"log/slog"
"strings"
"github.com/sirupsen/logrus"
)
// ConditionalUpstream conditional upstream configuration
@@ -26,9 +25,9 @@ func (c *ConditionalUpstream) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *ConditionalUpstream) LogConfig(logger *logrus.Entry) {
func (c *ConditionalUpstream) LogConfig(logger *slog.Logger) {
for key, val := range c.Mapping.Upstreams {
logger.Infof("%s = %v", key, val)
logger.Info(fmt.Sprintf("%s = %v", key, val))
}
}
+2 -2
View File
@@ -54,8 +54,8 @@ var _ = Describe("ConditionalUpstreamConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("fritz.box = ")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("fritz.box = ")))
})
})
+46 -44
View File
@@ -7,6 +7,7 @@ import (
"crypto/tls"
"errors"
"fmt"
"log/slog"
"net"
"os"
"path/filepath"
@@ -16,7 +17,6 @@ import (
"time"
"github.com/miekg/dns"
"github.com/sirupsen/logrus"
. "github.com/0xERR0R/blocky/config/migration"
"github.com/0xERR0R/blocky/config/schema"
@@ -42,7 +42,7 @@ type Configurable interface {
// LogConfig logs the receiver's configuration.
//
// The behavior of this method is undefined when `IsEnabled` returns false.
LogConfig(logger *logrus.Entry)
LogConfig(logger *slog.Logger)
}
// NetProtocol resolver protocol ENUM(
@@ -84,14 +84,14 @@ func (ipv IPVersion) QTypes() []dns.Type {
// )
type TLSVersion int // values MUST match `tls.VersionTLS*`
func (v *TLSVersion) validate(logger *logrus.Entry) {
func (v *TLSVersion) validate(logger *slog.Logger) {
// So we get a linting error if it is considered insecure in the future
minAllowed := tls.Config{MinVersion: tls.VersionTLS12}.MinVersion
if *v < TLSVersion(minAllowed) {
def := mustDefault[Config]().MinTLSServeVer
logger.Warnf("TLS version %s is insecure, using %s instead", v, def)
logger.Warn(fmt.Sprintf("TLS version %s is insecure, using %s instead", v, def))
*v = def
}
}
@@ -325,7 +325,7 @@ type Config struct {
Upstream *UpstreamGroups `yaml:"upstream"`
UpstreamTimeout *Duration `yaml:"upstreamTimeout"`
DisableIPv6 *bool `yaml:"disableIPv6"`
LogLevel *logrus.Level `yaml:"logLevel"`
LogLevel *log.Level `yaml:"logLevel"`
LogFormat *log.FormatType `yaml:"logFormat"`
LogPrivacy *bool `yaml:"logPrivacy"`
LogTimestamp *bool `yaml:"logTimestamp"`
@@ -367,14 +367,14 @@ func (p ProxyProtocolListeners) Has(t ProxyProtocolType) bool {
return slices.Contains(p, t)
}
func (c *Ports) LogConfig(logger *logrus.Entry) {
logger.Infof("DNS = %s", c.DNS)
logger.Infof("TLS = %s", c.TLS)
logger.Infof("HTTP = %s", c.HTTP)
logger.Infof("HTTPS = %s", c.HTTPS)
logger.Infof("DOHPath = %s", c.DOHPath)
logger.Infof("FreeBind = %t", c.FreeBind)
logger.Infof("PROXY protocol = %s", c.ProxyProtocol)
func (c *Ports) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("DNS = %s", c.DNS))
logger.Info(fmt.Sprintf("TLS = %s", c.TLS))
logger.Info(fmt.Sprintf("HTTP = %s", c.HTTP))
logger.Info(fmt.Sprintf("HTTPS = %s", c.HTTPS))
logger.Info("DOHPath = " + c.DOHPath)
logger.Info(fmt.Sprintf("FreeBind = %t", c.FreeBind))
logger.Info(fmt.Sprintf("PROXY protocol = %s", c.ProxyProtocol))
}
func (c *Ports) validate() error {
@@ -482,7 +482,7 @@ func (b *BootstrapDNS) IsEnabled() bool {
return len(*b) != 0
}
func (b *BootstrapDNS) LogConfig(*logrus.Entry) {
func (b *BootstrapDNS) LogConfig(*slog.Logger) {
// This should not be called, at least for now:
// The Boostrap resolver is not in the chain and thus its config is not logged
panic("not implemented")
@@ -514,7 +514,7 @@ func (c *toEnable) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *toEnable) LogConfig(logger *logrus.Entry) {
func (c *toEnable) LogConfig(logger *slog.Logger) {
logger.Info("enabled")
}
@@ -523,8 +523,8 @@ type Init struct {
Strategy InitStrategy `default:"blocking" yaml:"strategy"`
}
func (c *Init) LogConfig(logger *logrus.Entry) {
logger.Debugf("strategy = %s", c.Strategy)
func (c *Init) LogConfig(logger *slog.Logger) {
logger.Debug(fmt.Sprintf("strategy = %s", c.Strategy))
}
type SourceLoading struct {
@@ -540,13 +540,13 @@ type SourceLoading struct {
Downloads Downloader `yaml:"downloads"`
}
func (c *SourceLoading) LogConfig(logger *logrus.Entry) {
func (c *SourceLoading) LogConfig(logger *slog.Logger) {
c.Init.LogConfig(logger)
logger.Infof("concurrency = %d", c.Concurrency)
logger.Debugf("maxErrorsPerSource = %d", c.MaxErrorsPerSource)
logger.Info(fmt.Sprintf("concurrency = %d", c.Concurrency))
logger.Debug(fmt.Sprintf("maxErrorsPerSource = %d", c.MaxErrorsPerSource))
if c.RefreshPeriod.IsAboveZero() {
logger.Infof("refresh = every %s", c.RefreshPeriod)
logger.Info(fmt.Sprintf("refresh = every %s", c.RefreshPeriod))
} else {
logger.Debug("refresh = disabled")
}
@@ -626,13 +626,13 @@ type Downloader struct {
CachePath string `yaml:"cachePath"`
}
func (c *Downloader) LogConfig(logger *logrus.Entry) {
logger.Infof("timeout = %s", c.Timeout)
logger.Infof("attempts = %d", c.Attempts)
logger.Debugf("cooldown = %s", c.Cooldown)
func (c *Downloader) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("timeout = %s", c.Timeout))
logger.Info(fmt.Sprintf("attempts = %d", c.Attempts))
logger.Debug(fmt.Sprintf("cooldown = %s", c.Cooldown))
if c.CachePath != "" {
logger.Infof("cachePath = %s", c.CachePath)
logger.Info("cachePath = " + c.CachePath)
} else {
logger.Debug("cachePath = (disabled, stateless downloads)")
}
@@ -651,7 +651,7 @@ func WithDefaults[T any]() (T, error) {
func mustDefault[T any]() T {
cfg, err := WithDefaults[T]()
if err != nil {
util.FatalOnError("broken defaults", err)
panic(fmt.Sprintf("broken defaults: %v", err))
}
return cfg
@@ -659,12 +659,10 @@ func mustDefault[T any]() T {
// LoadConfig creates new config from YAML file or a directory containing YAML files
func LoadConfig(path string, mandatory bool) (rCfg *Config, rerr error) {
logger := logrus.NewEntry(log.Log())
return loadConfig(logger, path, mandatory)
return loadConfig(log.Log(), path, mandatory)
}
func loadConfig(logger *logrus.Entry, path string, mandatory bool) (rCfg *Config, rerr error) {
func loadConfig(logger *slog.Logger, path string, mandatory bool) (rCfg *Config, rerr error) {
cfg, err := WithDefaults[Config]()
if err != nil {
return nil, fmt.Errorf("failed to apply default configuration: %w", err)
@@ -700,7 +698,7 @@ func loadConfig(logger *logrus.Entry, path string, mandatory bool) (rCfg *Config
}
if err := cfg.Ports.validate(); err != nil {
logger.Fatal(err)
return nil, fmt.Errorf("invalid ports config: %w", err)
}
// Normalize rewrite keys to lowercase after unmarshaling
@@ -716,7 +714,7 @@ func loadConfig(logger *logrus.Entry, path string, mandatory bool) (rCfg *Config
// merges and returns the per-file sources for post-merge error attribution.
// prettyPath is the user-facing path used in error messages.
func readConfigSource(
logger *logrus.Entry, path string, fs os.FileInfo,
logger *slog.Logger, path string, fs os.FileInfo,
) (data []byte, sources []configFile, prettyPath string, err error) {
if fs.IsDir() {
prettyPath = filepath.Join(path, "*")
@@ -798,7 +796,7 @@ func readFromDir(path string) ([]configFile, error) {
// logConfigSources logs the merge order so users can tell which file wins a
// conflict.
func logConfigSources(logger *logrus.Entry, files []configFile) {
func logConfigSources(logger *slog.Logger, files []configFile) {
if len(files) == 0 {
return
}
@@ -808,7 +806,7 @@ func logConfigSources(logger *logrus.Entry, files []configFile) {
paths = append(paths, f.path)
}
logger.Infof("loading config files in merge order (later files win conflicts): %s", strings.Join(paths, ", "))
logger.Info("loading config files in merge order", slog.String("files", strings.Join(paths, ", ")))
}
// isRegularFile follows symlinks, so the result is `true` for a symlink to a regular file.
@@ -826,7 +824,7 @@ func isRegularFile(path string) (bool, error) {
// unmarshalConfig decodes data into cfg. sources, when non-empty, are the
// individual files that were merged to produce data; they are used to attribute
// schema findings to specific source files on the error path.
func unmarshalConfig(logger *logrus.Entry, data []byte, cfg *Config, sources []configFile) error {
func unmarshalConfig(logger *slog.Logger, data []byte, cfg *Config, sources []configFile) error {
err := yaml.UnmarshalStrict(data, cfg)
if err != nil {
// Enrich the already-failing path with field-path schema errors,
@@ -847,7 +845,7 @@ func unmarshalConfig(logger *logrus.Entry, data []byte, cfg *Config, sources []c
// schema, never a config error. Warn, never fail.
if schemaErrs, sErr := schema.ValidateYAML(data); sErr == nil && len(schemaErrs) > 0 {
for _, e := range schemaErrs {
logger.Warnf("config does not match schema (possible schema gap, please report): %s", e)
logger.Warn(fmt.Sprintf("config does not match schema (possible schema gap, please report): %s", e))
}
}
@@ -856,7 +854,9 @@ func unmarshalConfig(logger *logrus.Entry, data []byte, cfg *Config, sources []c
logger.Error("configuration uses deprecated options, see warning logs for details")
}
cfg.validate(logger)
if err := cfg.validate(logger); err != nil {
return err
}
return nil
}
@@ -925,7 +925,7 @@ func reconcileSchemaErrors(data []byte, sources []configFile) []string {
return lines
}
func (cfg *Config) migrate(logger *logrus.Entry) bool {
func (cfg *Config) migrate(logger *slog.Logger) bool {
usesDepredOpts := Migrate(logger, "", cfg.Deprecated, map[string]Migrator{
"upstream": Move(To("upstreams.groups", &cfg.Upstreams)),
"upstreamTimeout": Move(To("upstreams.timeout", &cfg.Upstreams)),
@@ -958,27 +958,29 @@ func (cfg *Config) migrate(logger *logrus.Entry) bool {
return usesDepredOpts
}
func (cfg *Config) validate(logger *logrus.Entry) {
func (cfg *Config) validate(logger *slog.Logger) error {
cfg.MinTLSServeVer.validate(logger)
cfg.Upstreams.validate(logger)
// Blocking validation
if err := cfg.Blocking.validate(); err != nil {
logger.Warn(err)
logger.Warn(err.Error())
}
// DNS64 validation
if err := cfg.DNS64.validate(logger, &cfg.Filtering, &cfg.Caching); err != nil {
logger.Fatal(err)
return fmt.Errorf("DNS64 config invalid: %w", err)
}
if err := cfg.RateLimit.validate(); err != nil {
logger.Fatal(err)
return fmt.Errorf("rate limit config invalid: %w", err)
}
if err := cfg.RebindingProtection.validate(); err != nil {
logger.Fatal(err)
return err
}
return nil
}
// ConvertPort converts string representation into a valid port (0 - 65535)
+4 -4
View File
@@ -26,7 +26,7 @@ var _ = Describe("schema-enriched config loading", func() {
err := unmarshalConfig(logger, data, &Config{}, nil)
Expect(err).Should(Succeed())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("does not match schema")))
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("does not match schema")))
})
It("accepts PROXY protocol listener families", func() {
@@ -44,7 +44,7 @@ ports:
err := unmarshalConfig(logger, data, &Config{}, nil)
Expect(err).Should(Succeed())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("does not match schema")))
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("does not match schema")))
})
})
@@ -72,7 +72,7 @@ ports:
err := unmarshalConfig(logger, data, &Config{}, nil)
Expect(err).Should(Succeed())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("does not match schema")))
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("does not match schema")))
})
})
@@ -89,7 +89,7 @@ ports:
err = unmarshalConfig(logger, data, &Config{}, nil)
Expect(err).Should(Succeed())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("does not match schema")),
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("does not match schema")),
"every form in testdata/superset_config.yml must validate against the schema too")
})
})
+7 -7
View File
@@ -1,22 +1,22 @@
package config
import (
"log/slog"
"testing"
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/sirupsen/logrus"
)
var (
logger *logrus.Entry
hook *log.MockLoggerHook
logger *slog.Logger
rec *log.Recorder
)
func init() {
log.Silence()
}
var _ = BeforeSuite(func() {
log.ConfigureForTest(GinkgoWriter)
})
func TestConfig(t *testing.T) {
RegisterFailHandler(Fail)
@@ -25,6 +25,6 @@ func TestConfig(t *testing.T) {
func suiteBeforeEach() {
BeforeEach(func() {
logger, hook = log.NewMockEntry()
logger, rec = log.NewRecorder()
})
}
+49 -46
View File
@@ -1,9 +1,11 @@
package config
import (
"bytes"
"context"
"crypto/tls"
"errors"
"log/slog"
"net"
"strings"
"sync/atomic"
@@ -11,7 +13,6 @@ import (
"github.com/creasty/defaults"
"github.com/miekg/dns"
"github.com/sirupsen/logrus"
"github.com/0xERR0R/blocky/helpertest"
"github.com/0xERR0R/blocky/log"
@@ -44,7 +45,7 @@ var _ = Describe("Config", func() {
It("should add 'AAAA' to filter.queryTypes", func() {
c.Deprecated.DisableIPv6 = ptrOf(true) //nolint:modernize // ptrOf sets a non-zero value, new(T) would give zero-value pointer
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("disableIPv6")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("disableIPv6")))
Expect(c.Filtering.QueryTypes).Should(HaveKey(QType(dns.TypeAAAA)))
Expect(c.Filtering.QueryTypes.Contains(dns.Type(dns.TypeAAAA))).Should(BeTrue())
})
@@ -57,23 +58,23 @@ var _ = Describe("Config", func() {
It("should change loading.strategy blocking to failOnError", func() {
c.Blocking.Loading.Strategy = InitStrategyBlocking
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("blocking.loading.strategy")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("blocking.loading.strategy")))
Expect(c.Blocking.Loading.Strategy).Should(Equal(InitStrategyFailOnError))
})
It("shouldn't change loading.strategy if set to fast", func() {
c.Blocking.Loading.Strategy = InitStrategyFast
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("blocking.loading.strategy")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("blocking.loading.strategy")))
Expect(c.Blocking.Loading.Strategy).Should(Equal(InitStrategyFast))
})
})
When("parameter 'logLevel' is set", func() {
It("should convert to log.level", func() {
c.Deprecated.LogLevel = ptrOf(logrus.DebugLevel)
c.Deprecated.LogLevel = ptrOf(log.Level(slog.LevelDebug))
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("log.level")))
Expect(c.Log.Level).Should(Equal(logrus.DebugLevel))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("log.level")))
Expect(c.Log.Level).Should(Equal(log.Level(slog.LevelDebug)))
})
})
@@ -81,7 +82,7 @@ var _ = Describe("Config", func() {
It("should convert to log.format", func() {
c.Deprecated.LogFormat = ptrOf(log.FormatTypeJson)
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("log.format")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("log.format")))
Expect(c.Log.Format).Should(Equal(log.FormatTypeJson))
})
})
@@ -90,7 +91,7 @@ var _ = Describe("Config", func() {
It("should convert to log.privacy", func() {
c.Deprecated.LogPrivacy = ptrOf(true) //nolint:modernize // ptrOf sets a non-zero value, new(T) would give zero-value pointer
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("log.privacy")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("log.privacy")))
Expect(c.Log.Privacy).Should(BeTrue())
})
})
@@ -99,7 +100,7 @@ var _ = Describe("Config", func() {
It("should convert to log.timestamp", func() {
c.Deprecated.LogTimestamp = new(bool)
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("log.timestamp")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("log.timestamp")))
Expect(c.Log.Timestamp).Should(BeFalse())
})
})
@@ -109,7 +110,7 @@ var _ = Describe("Config", func() {
ports := ListenConfig([]string{"5333"})
c.Deprecated.DNSPorts = ptrOf(ports) //nolint:modernize // ptrOf(var) is not equivalent to new(T)
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("ports.dns")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("ports.dns")))
Expect(c.Ports.DNS).Should(Equal(ports))
})
})
@@ -119,7 +120,7 @@ var _ = Describe("Config", func() {
ports := ListenConfig([]string{"5333"})
c.Deprecated.HTTPPorts = ptrOf(ports) //nolint:modernize // ptrOf(var) is not equivalent to new(T)
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("ports.http")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("ports.http")))
Expect(c.Ports.HTTP).Should(Equal(ports))
})
})
@@ -129,7 +130,7 @@ var _ = Describe("Config", func() {
ports := ListenConfig([]string{"5333"})
c.Deprecated.HTTPSPorts = ptrOf(ports) //nolint:modernize // ptrOf(var) is not equivalent to new(T)
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("ports.https")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("ports.https")))
Expect(c.Ports.HTTPS).Should(Equal(ports))
})
})
@@ -139,7 +140,7 @@ var _ = Describe("Config", func() {
ports := ListenConfig([]string{"5333"})
c.Deprecated.TLSPorts = ptrOf(ports) //nolint:modernize // ptrOf(var) is not equivalent to new(T)
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("ports.tls")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("ports.tls")))
Expect(c.Ports.TLS).Should(Equal(ports))
})
})
@@ -148,7 +149,7 @@ var _ = Describe("Config", func() {
It("should convert to upstreams.init.strategy", func() {
c.Deprecated.StartVerifyUpstream = ptrOf(true) //nolint:modernize // ptrOf(true) != new(bool) which gives false
c.migrate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("startVerifyUpstream")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("startVerifyUpstream")))
Expect(c.Upstreams.Init.Strategy).Should(Equal(InitStrategyFailOnError))
})
})
@@ -330,7 +331,7 @@ var _ = Describe("Config", func() {
c, err := LoadConfig(tmpDir.Path, true)
Expect(err).Should(Succeed())
Expect(c.Upstreams.Groups["default"]).Should(HaveLen(1))
Expect(c.Log.Level).Should(Equal(logrus.DebugLevel))
Expect(c.Log.Level).Should(Equal(log.Level(slog.LevelDebug)))
})
It("still rejects duplicate keys within one file, naming the file", func() {
@@ -363,7 +364,7 @@ var _ = Describe("Config", func() {
c, err := LoadConfig(tmpDir.Path, true)
Expect(err).Should(Succeed())
Expect(c.Log.Level).Should(Equal(logrus.DebugLevel))
Expect(c.Log.Level).Should(Equal(log.Level(slog.LevelDebug)))
})
It("merges multi-document files in document order", func() {
@@ -377,7 +378,7 @@ var _ = Describe("Config", func() {
c, err := LoadConfig(tmpDir.Path, true)
Expect(err).Should(Succeed())
Expect(c.Log.Level).Should(Equal(logrus.DebugLevel))
Expect(c.Log.Level).Should(Equal(log.Level(slog.LevelDebug)))
})
It("preserves scalar literals so minTlsServeVersion: 1.0 still loads (issue #1827)", func() {
@@ -625,7 +626,7 @@ bootstrapDns:
c, err = LoadConfig(tmpDir.JoinPath("config.yml"), false)
Expect(err).Should(Succeed())
Expect(c.Log.Level).Should(Equal(logrus.InfoLevel))
Expect(c.Log.Level).Should(Equal(log.Level(slog.LevelInfo)))
})
})
})
@@ -850,8 +851,8 @@ bootstrapDns:
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("concurrency = 12"),
ContainSubstring("refresh = every 1 hour"),
))
@@ -862,19 +863,19 @@ bootstrapDns:
})
It("should reflect that", func() {
logger.Logger.Level = logrus.InfoLevel
var buf bytes.Buffer
cfg.LogConfig(logger)
// At info level, "refresh = disabled" (logged at Debug) should NOT appear
cfg.LogConfig(slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})))
Expect(buf.String()).ShouldNot(BeEmpty())
Expect(buf.String()).ShouldNot(ContainSubstring("refresh = disabled"))
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("refresh = disabled")))
buf.Reset()
logger.Logger.Level = logrus.TraceLevel
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("refresh = disabled")))
// At debug level, "refresh = disabled" SHOULD appear
cfg.LogConfig(slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
Expect(buf.String()).ShouldNot(BeEmpty())
Expect(buf.String()).Should(ContainSubstring("refresh = disabled"))
})
})
})
@@ -893,22 +894,24 @@ bootstrapDns:
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("cachePath = /var/cache/blocky/lists")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("cachePath = /var/cache/blocky/lists")))
})
It("logs disabled only at debug level when cachePath is empty", func() {
cfg, err := WithDefaults[Downloader]()
Expect(err).Should(Succeed())
var buf bytes.Buffer
// At the default info level the disabled note is suppressed (it is a debug line)...
logger.Logger.Level = logrus.InfoLevel
cfg.LogConfig(logger)
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("disabled")))
cfg.LogConfig(slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})))
Expect(buf.String()).ShouldNot(ContainSubstring("disabled"))
buf.Reset()
// ...and only appears once debug/trace logging is enabled.
logger.Logger.Level = logrus.TraceLevel
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("disabled")))
cfg.LogConfig(slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
Expect(buf.String()).Should(ContainSubstring("disabled"))
})
})
})
@@ -1172,11 +1175,11 @@ bootstrapDns:
Describe("Documentation config", func() {
It("should not use deprecated options", func() {
logger, hook := log.NewMockEntry()
lgr, lrec := log.NewRecorder()
_, err := loadConfig(logger, "../docs/config.yml", true)
_, err := loadConfig(lgr, "../docs/config.yml", true)
Expect(err).Should(Succeed())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("deprecated")))
Expect(lrec.Messages()).ShouldNot(ContainElement(ContainSubstring("deprecated")))
})
})
@@ -1570,8 +1573,8 @@ var _ = Describe("Ports", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("DNS"),
ContainSubstring("HTTP"),
ContainSubstring("HTTPS"),
@@ -1640,8 +1643,8 @@ var _ = Describe("toEnable", func() {
cfg := toEnable{Enable: true}
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("enabled")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("enabled")))
})
})
})
@@ -1735,7 +1738,7 @@ var _ = Describe("TLSVersion", func() {
v.validate(logger)
Expect(v).Should(BeNumerically(">=", TLSVersion(tls.VersionTLS12)))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("insecure")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("insecure")))
})
It("should not change valid TLS version", func() {
+5 -5
View File
@@ -2,11 +2,11 @@ package config
import (
"fmt"
"log/slog"
"net"
"strings"
"github.com/miekg/dns"
"github.com/sirupsen/logrus"
)
// CustomDNS custom DNS configuration
@@ -99,14 +99,14 @@ func (c *CustomDNS) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *CustomDNS) LogConfig(logger *logrus.Entry) {
logger.Debugf("TTL = %s", c.CustomTTL)
logger.Debugf("filterUnmappedTypes = %t", c.FilterUnmappedTypes)
func (c *CustomDNS) LogConfig(logger *slog.Logger) {
logger.Debug(fmt.Sprintf("TTL = %s", c.CustomTTL))
logger.Debug(fmt.Sprintf("filterUnmappedTypes = %t", c.FilterUnmappedTypes))
logger.Info("mapping:")
for key, val := range c.Mapping {
logger.Infof(" %s = %s", key, val)
logger.Info(fmt.Sprintf(" %s = %s", key, val))
}
}
+2 -2
View File
@@ -58,8 +58,8 @@ var _ = Describe("CustomDNSConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("custom.domain = "),
ContainSubstring("ip6.domain = "),
ContainSubstring("multiple.ips = "),
+5 -5
View File
@@ -3,10 +3,10 @@ package config
import (
"errors"
"fmt"
"log/slog"
"net/netip"
"github.com/miekg/dns"
"github.com/sirupsen/logrus"
)
// DNS64 is the configuration for DNS64 resolver
@@ -25,13 +25,13 @@ func (c *DNS64) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *DNS64) LogConfig(logger *logrus.Entry) {
func (c *DNS64) LogConfig(logger *slog.Logger) {
if len(c.Prefixes) == 0 {
logger.Info("prefixes: [64:ff9b::/96] (default)")
} else {
logger.Info("prefixes:")
for _, prefix := range c.Prefixes {
logger.Infof(" - %s", prefix.String())
logger.Info(" - " + prefix.String())
}
}
@@ -40,13 +40,13 @@ func (c *DNS64) LogConfig(logger *logrus.Entry) {
} else {
logger.Info("exclusionSet (custom):")
for _, prefix := range c.ExclusionSet {
logger.Infof(" - %s", prefix.String())
logger.Info(" - " + prefix.String())
}
}
}
// validate checks DNS64 configuration for conflicts and validity
func (c *DNS64) validate(logger *logrus.Entry, filtering *Filtering, caching *Caching) error {
func (c *DNS64) validate(logger *slog.Logger, filtering *Filtering, caching *Caching) error {
if !c.Enable {
return nil
}
+16 -16
View File
@@ -38,9 +38,9 @@ var _ = Describe("DNS64Config", func() {
Describe("LogConfig", func() {
It("should log default prefixes when empty", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("64:ff9b::/96")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("default")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("64:ff9b::/96")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("default")))
})
It("should log custom prefixes when configured", func() {
@@ -49,16 +49,16 @@ var _ = Describe("DNS64Config", func() {
netip.MustParsePrefix("2001:db9::/96"),
}
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("2001:db8::/32")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("2001:db9::/96")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("2001:db8::/32")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("2001:db9::/96")))
})
It("should log default exclusionSet when empty", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("::ffff:0:0/96")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("default, plus configured prefixes")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("::ffff:0:0/96")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("default, plus configured prefixes")))
})
It("should log custom exclusionSet when configured", func() {
@@ -66,9 +66,9 @@ var _ = Describe("DNS64Config", func() {
netip.MustParsePrefix("2001:db8::/64"),
}
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("exclusionSet (custom)")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("2001:db8::/64")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("exclusionSet (custom)")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("2001:db8::/64")))
})
})
@@ -178,9 +178,9 @@ var _ = Describe("DNS64Config", func() {
It("should log warning", func() {
caching.MaxCachingTime = Duration(-1)
_ = cfg.validate(logger, filtering, caching)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("DNS64 is enabled but caching is disabled")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("reduced performance")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("DNS64 is enabled but caching is disabled")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("reduced performance")))
})
})
@@ -189,7 +189,7 @@ var _ = Describe("DNS64Config", func() {
caching.MaxCachingTime = Duration(5 * time.Minute)
_ = cfg.validate(logger, filtering, caching)
// Check no warning about caching was logged
for _, msg := range hook.Messages {
for _, msg := range rec.Messages() {
if msg == "DNS64 is enabled but caching is disabled" {
Fail("Should not log caching disabled warning when caching is enabled")
}
+10 -9
View File
@@ -1,7 +1,8 @@
package config
import (
"github.com/sirupsen/logrus"
"fmt"
"log/slog"
)
// DNSSEC is the configuration for DNSSEC validation
@@ -30,19 +31,19 @@ func (c *DNSSEC) IsEnabled() bool {
}
// LogConfig logs the DNSSEC configuration
func (c *DNSSEC) LogConfig(logger *logrus.Entry) {
logger.Infof("Validation = %t", c.Validate)
func (c *DNSSEC) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("Validation = %t", c.Validate))
if c.Validate {
if len(c.TrustAnchors) > 0 {
logger.Infof("Custom trust anchors = %d", len(c.TrustAnchors))
logger.Info(fmt.Sprintf("Custom trust anchors = %d", len(c.TrustAnchors)))
} else {
logger.Info("Using default root trust anchors")
}
logger.Infof("Max chain depth = %d", c.MaxChainDepth)
logger.Infof("Cache expiration = %d hour(s)", c.CacheExpirationHours)
logger.Infof("Max NSEC3 iterations = %d", c.MaxNSEC3Iterations)
logger.Infof("Max upstream queries per validation = %d", c.MaxUpstreamQueries)
logger.Infof("Clock skew tolerance = %d second(s)", c.ClockSkewToleranceSec)
logger.Info(fmt.Sprintf("Max chain depth = %d", c.MaxChainDepth))
logger.Info(fmt.Sprintf("Cache expiration = %d hour(s)", c.CacheExpirationHours))
logger.Info(fmt.Sprintf("Max NSEC3 iterations = %d", c.MaxNSEC3Iterations))
logger.Info(fmt.Sprintf("Max upstream queries per validation = %d", c.MaxUpstreamQueries))
logger.Info(fmt.Sprintf("Clock skew tolerance = %d second(s)", c.ClockSkewToleranceSec))
}
}
+17 -20
View File
@@ -2,10 +2,10 @@ package config
import (
"bytes"
"log/slog"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/sirupsen/logrus"
)
var _ = Describe("DNSSEC config", func() {
@@ -35,16 +35,13 @@ var _ = Describe("DNSSEC config", func() {
Describe("LogConfig", func() {
var (
logger *logrus.Entry
buf *bytes.Buffer
lgr *slog.Logger
buf *bytes.Buffer
)
BeforeEach(func() {
buf = new(bytes.Buffer)
logInstance := logrus.New()
logInstance.Out = buf
logInstance.SetLevel(logrus.InfoLevel)
logger = logrus.NewEntry(logInstance)
lgr = slog.New(slog.NewTextHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug}))
})
It("should log validation status when disabled", func() {
@@ -52,7 +49,7 @@ var _ = Describe("DNSSEC config", func() {
Validate: false,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Validation = false"))
@@ -68,7 +65,7 @@ var _ = Describe("DNSSEC config", func() {
ClockSkewToleranceSec: 3600,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Validation = true"))
@@ -85,7 +82,7 @@ var _ = Describe("DNSSEC config", func() {
TrustAnchors: []string{},
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Using default root trust anchors"))
@@ -101,7 +98,7 @@ var _ = Describe("DNSSEC config", func() {
},
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Custom trust anchors = 3"))
@@ -117,7 +114,7 @@ var _ = Describe("DNSSEC config", func() {
ClockSkewToleranceSec: 3600,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Validation = false"))
@@ -132,7 +129,7 @@ var _ = Describe("DNSSEC config", func() {
CacheExpirationHours: 24,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Cache expiration = 24 hour(s)"))
@@ -144,7 +141,7 @@ var _ = Describe("DNSSEC config", func() {
MaxChainDepth: 20,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Max chain depth = 20"))
@@ -156,7 +153,7 @@ var _ = Describe("DNSSEC config", func() {
MaxNSEC3Iterations: 500,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Max NSEC3 iterations = 500"))
@@ -168,7 +165,7 @@ var _ = Describe("DNSSEC config", func() {
MaxUpstreamQueries: 50,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Max upstream queries per validation = 50"))
@@ -180,7 +177,7 @@ var _ = Describe("DNSSEC config", func() {
ClockSkewToleranceSec: 7200,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Clock skew tolerance = 7200 second(s)"))
@@ -196,7 +193,7 @@ var _ = Describe("DNSSEC config", func() {
ClockSkewToleranceSec: 0,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Max chain depth = 0"))
@@ -214,7 +211,7 @@ var _ = Describe("DNSSEC config", func() {
},
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Custom trust anchors = 1"))
@@ -226,7 +223,7 @@ var _ = Describe("DNSSEC config", func() {
TrustAnchors: nil,
}
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
output := buf.String()
Expect(output).Should(ContainSubstring("Using default root trust anchors"))
+2 -2
View File
@@ -2,10 +2,10 @@ package config
import (
"fmt"
"log/slog"
"strconv"
"time"
"github.com/0xERR0R/blocky/log"
"github.com/hako/durafmt"
)
@@ -50,7 +50,7 @@ func (c *Duration) UnmarshalText(data []byte) error {
// number without unit: use minutes to ensure back compatibility
*c = Duration(time.Duration(minutes) * time.Minute)
log.Log().Warnf("Setting a duration without a unit is deprecated. Please use '%s min' instead.", input)
slog.Warn(fmt.Sprintf("Setting a duration without a unit is deprecated. Please use '%s min' instead.", input))
return nil
}
+6 -7
View File
@@ -2,9 +2,8 @@ package config
import (
"fmt"
"log/slog"
"strconv"
"github.com/sirupsen/logrus"
)
const (
@@ -60,11 +59,11 @@ func (c *ECS) IsEnabled() bool {
}
// LogConfig logs the configuration
func (c *ECS) LogConfig(logger *logrus.Entry) {
logger.Infof("Use as client = %t", c.UseAsClient)
logger.Infof("Forward = %t", c.Forward)
logger.Infof("IPv4 netmask = %d", c.IPv4Mask)
logger.Infof("IPv6 netmask = %d", c.IPv6Mask)
func (c *ECS) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("Use as client = %t", c.UseAsClient))
logger.Info(fmt.Sprintf("Forward = %t", c.Forward))
logger.Info(fmt.Sprintf("IPv4 netmask = %d", c.IPv4Mask))
logger.Info(fmt.Sprintf("IPv6 netmask = %d", c.IPv6Mask))
}
// unmarshalInternal unmarshals the subnet mask from the given text and checks if the value is valid
+3 -3
View File
@@ -69,14 +69,14 @@ var _ = Describe("ECS", func() {
Describe("LogConfig", func() {
BeforeEach(func() {
logger, hook = log.NewMockEntry()
logger, rec = log.NewRecorder()
})
It("should log configuration", func() {
c.LogConfig(logger)
Expect(hook.Calls).Should(HaveLen(4))
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).Should(HaveLen(4))
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("Use as client"),
ContainSubstring("Forward"),
ContainSubstring("IPv4 netmask"),
+4 -3
View File
@@ -1,7 +1,8 @@
package config
import (
"github.com/sirupsen/logrus"
"fmt"
"log/slog"
)
type Filtering struct {
@@ -15,10 +16,10 @@ func (c *Filtering) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *Filtering) LogConfig(logger *logrus.Entry) {
func (c *Filtering) LogConfig(logger *slog.Logger) {
logger.Info("query types:")
for qType := range c.QueryTypes {
logger.Infof(" - %s", qType)
logger.Info(fmt.Sprintf(" - %s", qType))
}
}
+2 -2
View File
@@ -46,8 +46,8 @@ var _ = Describe("FilteringConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).Should(HaveLen(3))
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).Should(HaveLen(3))
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("query types:"),
ContainSubstring(" - AAAA"),
ContainSubstring(" - MX"),
+8 -6
View File
@@ -1,9 +1,11 @@
package config
import (
"fmt"
"log/slog"
. "github.com/0xERR0R/blocky/config/migration"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus"
)
type HostsFile struct {
@@ -23,7 +25,7 @@ type HostsFile struct {
} `yaml:",inline"`
}
func (c *HostsFile) migrate(logger *logrus.Entry) bool {
func (c *HostsFile) migrate(logger *slog.Logger) bool {
return Migrate(logger, "hostsFile", c.Deprecated, map[string]Migrator{
"refreshPeriod": Move(To("loading.refreshPeriod", &c.Loading)),
"filePath": Apply(To("sources", c), func(value BytesSource) {
@@ -38,9 +40,9 @@ func (c *HostsFile) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *HostsFile) LogConfig(logger *logrus.Entry) {
logger.Infof("TTL: %s", c.HostsTTL)
logger.Infof("filter loopback addresses: %t", c.FilterLoopback)
func (c *HostsFile) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("TTL: %s", c.HostsTTL))
logger.Info(fmt.Sprintf("filter loopback addresses: %t", c.FilterLoopback))
logger.Info("loading:")
log.WithIndent(logger, " ", c.Loading.LogConfig)
@@ -48,6 +50,6 @@ func (c *HostsFile) LogConfig(logger *logrus.Entry) {
logger.Info("sources:")
for _, source := range c.Sources {
logger.Infof(" - %s", source)
logger.Info(fmt.Sprintf(" - %s", source))
}
}
+4 -4
View File
@@ -52,8 +52,8 @@ var _ = Describe("HostsFileConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("- file:///a/file/path"),
ContainSubstring("- 127.0.0.1 lo..."),
))
@@ -71,8 +71,8 @@ var _ = Describe("HostsFileConfig", func() {
migrated := cfg.migrate(logger)
Expect(migrated).Should(BeTrue())
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("hostsFile.loading.refreshPeriod"),
ContainSubstring("hostsFile.sources"),
))
+2 -2
View File
@@ -1,6 +1,6 @@
package config
import "github.com/sirupsen/logrus"
import "log/slog"
// HTTP3 holds DNS-over-HTTPS over HTTP/3 (DoH3) server settings.
type HTTP3 struct {
@@ -14,6 +14,6 @@ func (c *HTTP3) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *HTTP3) LogConfig(logger *logrus.Entry) {
func (c *HTTP3) LogConfig(logger *slog.Logger) {
logger.Info("enabled")
}
+2 -2
View File
@@ -37,8 +37,8 @@ var _ = Describe("HTTP3Config", func() {
cfg := HTTP3{Enable: true}
cfg.LogConfig(logger)
Expect(hook.Calls).Should(HaveLen(1))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("enabled")))
Expect(rec.Records()).Should(HaveLen(1))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("enabled")))
})
})
+5 -3
View File
@@ -1,6 +1,8 @@
package config
import "github.com/sirupsen/logrus"
import (
"log/slog"
)
// Metrics contains the config values for prometheus
type Metrics struct {
@@ -16,6 +18,6 @@ func (c *Metrics) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *Metrics) LogConfig(logger *logrus.Entry) {
logger.Infof("url path: %s", c.Path)
func (c *Metrics) LogConfig(logger *slog.Logger) {
logger.Info("url path: " + c.Path)
}
+2 -2
View File
@@ -45,8 +45,8 @@ var _ = Describe("MetricsConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).Should(HaveLen(1))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("url path: /custom/path")))
Expect(rec.Records()).Should(HaveLen(1))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("url path: /custom/path")))
})
})
})
+9 -10
View File
@@ -5,18 +5,18 @@ package migration
import (
"fmt"
"log/slog"
"maps"
"reflect"
"strings"
"github.com/creasty/defaults"
"github.com/sirupsen/logrus"
)
// Migrate checks each field of `deprecated` to see if a migration can and should be run.
//
// Each field must be a pointer: this allows knowing if the user has set a value in the config.
func Migrate(logger *logrus.Entry, optPrefix string, deprecated any, newOptions map[string]Migrator) bool {
func Migrate(logger *slog.Logger, optPrefix string, deprecated any, newOptions map[string]Migrator) bool {
deprecatedVal := reflect.ValueOf(deprecated)
deprecatedTyp := deprecatedVal.Type()
@@ -54,20 +54,19 @@ func Migrate(logger *logrus.Entry, optPrefix string, deprecated any, newOptions
val = val.Elem() // deref the pointer
if !migrator.dest.IsDefault() {
logger.
WithFields(logrus.Fields{
migrator.dest.Name(): migrator.dest.Value.Interface(),
oldName: val.Interface(),
}).
Errorf(
logger.Error(
fmt.Sprintf(
"config options %q (new) and %q (deprecated) are both set, ignoring the deprecated one",
migrator.dest, oldName,
)
),
slog.Any(migrator.dest.Name(), migrator.dest.Value.Interface()),
slog.Any(oldName, val.Interface()),
)
continue
}
logger.Warnf("config option %q is deprecated, please use %q instead", oldName, migrator.dest)
logger.Warn(fmt.Sprintf("config option %q is deprecated, please use %q instead", oldName, migrator.dest))
migrator.apply(oldName, val)
}
+6 -6
View File
@@ -1,12 +1,12 @@
package migration
import (
"log/slog"
"testing"
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/sirupsen/logrus"
)
func TestMigration(t *testing.T) {
@@ -28,12 +28,12 @@ type testNew struct {
var _ = Describe("Migration", func() {
var (
logger *logrus.Entry
hook *log.MockLoggerHook
logger *slog.Logger
rec *log.Recorder
)
BeforeEach(func() {
logger, hook = log.NewMockEntry()
logger, rec = log.NewRecorder()
})
Describe("Migrate", func() {
@@ -63,7 +63,7 @@ var _ = Describe("Migration", func() {
Expect(result).Should(BeTrue())
Expect(newCfg.NewName).Should(Equal("migrated-value"))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("deprecated")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("deprecated")))
})
It("should not override new option if already set", func() {
@@ -94,7 +94,7 @@ var _ = Describe("Migration", func() {
Expect(result).Should(BeTrue())
Expect(newCfg.NewName).Should(Equal("val"))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("section.oldName")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("section.oldName")))
})
})
+16 -15
View File
@@ -1,11 +1,12 @@
package config
import (
"fmt"
"log/slog"
"net/url"
"strings"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus"
)
// QueryLog configuration for the query logging
@@ -50,28 +51,28 @@ func (c *QueryLog) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *QueryLog) LogConfig(logger *logrus.Entry) {
logger.Infof("type: %s", c.Type)
func (c *QueryLog) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("type: %s", c.Type))
if c.Target != "" {
logger.Infof("target: %s", c.censoredTarget())
logger.Info("target: " + c.censoredTarget())
}
logger.Infof("logRetentionDays: %d", c.LogRetentionDays)
logger.Debugf("creationAttempts: %d", c.CreationAttempts)
logger.Debugf("creationCooldown: %s", c.CreationCooldown)
logger.Infof("flushInterval: %s", c.FlushInterval)
logger.Infof("fields: %s", c.Fields)
logger.Info(fmt.Sprintf("logRetentionDays: %d", c.LogRetentionDays))
logger.Debug(fmt.Sprintf("creationAttempts: %d", c.CreationAttempts))
logger.Debug(fmt.Sprintf("creationCooldown: %s", c.CreationCooldown))
logger.Info(fmt.Sprintf("flushInterval: %s", c.FlushInterval))
logger.Info(fmt.Sprintf("fields: %s", c.Fields))
logger.Infof("ignore:")
log.WithIndent(logger, " ", func(e *logrus.Entry) {
e.Infof("sudn: %t", c.Ignore.SUDN)
logger.Info("ignore:")
log.WithIndent(logger, " ", func(e *slog.Logger) {
e.Info(fmt.Sprintf("sudn: %t", c.Ignore.SUDN))
if len(c.Ignore.Domains) > 0 {
e.Infof("domains (%d):", len(c.Ignore.Domains))
log.WithIndent(e, " ", func(e *logrus.Entry) {
e.Info(fmt.Sprintf("domains (%d):", len(c.Ignore.Domains)))
log.WithIndent(e, " ", func(e *slog.Logger) {
for _, d := range c.Ignore.Domains {
e.Debugf("- %s", d)
e.Debug("- " + d)
}
})
}
+6 -6
View File
@@ -55,9 +55,9 @@ var _ = Describe("QueryLogConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("logRetentionDays:")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("sudn:")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("logRetentionDays:")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("sudn:")))
})
It("should log the ignored domains", func() {
@@ -65,7 +65,7 @@ var _ = Describe("QueryLogConfig", func() {
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("domains (3):")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("domains (3):")))
})
DescribeTable("secret censoring", func(target string) {
@@ -74,8 +74,8 @@ var _ = Describe("QueryLogConfig", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("password")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("password")))
},
Entry("without scheme", "user:password@localhost"),
Entry("with scheme", "scheme://user:password@localhost"),
+7 -8
View File
@@ -3,9 +3,8 @@ package config
import (
"errors"
"fmt"
"log/slog"
"net"
"github.com/sirupsen/logrus"
)
const (
@@ -35,12 +34,12 @@ type RateLimit struct {
func (c *RateLimit) IsEnabled() bool { return c.Enable }
// LogConfig implements `config.Configurable`.
func (c *RateLimit) LogConfig(logger *logrus.Entry) {
logger.Infof("rate = %d qps", c.Rate)
logger.Infof("burst = %d", c.Burst)
logger.Infof("ipv4 prefix = /%d", c.IPv4Prefix)
logger.Infof("ipv6 prefix = /%d", c.IPv6Prefix)
logger.Infof("allowlist = %v", c.Allowlist)
func (c *RateLimit) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("rate = %d qps", c.Rate))
logger.Info(fmt.Sprintf("burst = %d", c.Burst))
logger.Info(fmt.Sprintf("ipv4 prefix = /%d", c.IPv4Prefix))
logger.Info(fmt.Sprintf("ipv6 prefix = /%d", c.IPv6Prefix))
logger.Info(fmt.Sprintf("allowlist = %v", c.Allowlist))
}
func (c *RateLimit) validate() error {
+1 -1
View File
@@ -67,7 +67,7 @@ var _ = Describe("RateLimit config", func() {
Allowlist: []string{"10.0.0.0/8"},
}
c.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(rec.Records()).ShouldNot(BeEmpty())
})
})
+4 -5
View File
@@ -2,12 +2,11 @@ package config
import (
"fmt"
"log/slog"
"strings"
"unicode"
"github.com/0xERR0R/blocky/util"
"github.com/sirupsen/logrus"
)
// RebindingProtection drops answers from the general upstream resolvers that contain
@@ -27,11 +26,11 @@ func (c *RebindingProtection) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *RebindingProtection) LogConfig(logger *logrus.Entry) {
logger.Infof("allowed domains (%d):", len(c.AllowedDomains))
func (c *RebindingProtection) LogConfig(logger *slog.Logger) {
logger.Info("allowed domains", slog.Int("count", len(c.AllowedDomains)))
for _, domain := range c.AllowedDomains {
logger.Infof(" - %s", domain)
logger.Info(" - " + domain)
}
}
+3 -3
View File
@@ -31,11 +31,11 @@ var _ = Describe("RebindingProtection", func() {
Describe("LogConfig", func() {
It("should log something", func() {
logger, hook := log.NewMockEntry()
lgr, rec := log.NewRecorder()
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(rec.Records()).ShouldNot(BeEmpty())
})
})
+14 -13
View File
@@ -1,7 +1,8 @@
package config
import (
"github.com/sirupsen/logrus"
"fmt"
"log/slog"
)
// Redis configuration for the redis connection
@@ -35,27 +36,27 @@ func (c *Redis) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`
func (c *Redis) LogConfig(logger *logrus.Entry) {
func (c *Redis) LogConfig(logger *slog.Logger) {
if len(c.SentinelAddresses) == 0 {
logger.Info("address: ", c.Address)
logger.Info("address: " + c.Address)
}
logger.Info("username: ", c.Username)
logger.Info("password: ", secretObfuscator)
logger.Info("database: ", c.Database)
logger.Info("required: ", c.Required)
logger.Info("connectionAttempts: ", c.ConnectionAttempts)
logger.Info("connectionCooldown: ", c.ConnectionCooldown)
logger.Info("username: " + c.Username)
logger.Info("password: " + secretObfuscator)
logger.Info(fmt.Sprintf("database: %d", c.Database))
logger.Info(fmt.Sprintf("required: %t", c.Required))
logger.Info(fmt.Sprintf("connectionAttempts: %d", c.ConnectionAttempts))
logger.Info(fmt.Sprintf("connectionCooldown: %s", c.ConnectionCooldown))
if len(c.SentinelAddresses) > 0 {
logger.Info("sentinel:")
logger.Info(" master: ", c.Address)
logger.Info(" username: ", c.SentinelUsername)
logger.Info(" password: ", secretObfuscator)
logger.Info(" master: " + c.Address)
logger.Info(" username: " + c.SentinelUsername)
logger.Info(" password: " + secretObfuscator)
logger.Info(" addresses:")
for _, addr := range c.SentinelAddresses {
logger.Info(" - ", addr)
logger.Info(" - " + addr)
}
}
}
+11 -11
View File
@@ -44,14 +44,14 @@ var _ = Describe("Redis", func() {
Describe("LogConfig", func() {
BeforeEach(func() {
logger, hook = log.NewMockEntry()
logger, rec = log.NewRecorder()
})
When("all fields are default", func() {
It("should log default values", func() {
c.LogConfig(logger)
Expect(hook.Messages).Should(
Expect(rec.Messages()).Should(
SatisfyAll(ContainElement(ContainSubstring("address: ")),
ContainElement(ContainSubstring("username: ")),
ContainElement(ContainSubstring("password: ")),
@@ -70,7 +70,7 @@ var _ = Describe("Redis", func() {
It("should log address", func() {
c.LogConfig(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("address: localhost:6379")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("address: localhost:6379")))
})
})
@@ -82,7 +82,7 @@ var _ = Describe("Redis", func() {
It("should log sentinel addresses", func() {
c.LogConfig(logger)
Expect(hook.Messages).Should(
Expect(rec.Messages()).Should(
SatisfyAll(
ContainElement(ContainSubstring("sentinel:")),
ContainElement(ContainSubstring(" addresses:")),
@@ -97,16 +97,16 @@ var _ = Describe("Redis", func() {
c.Password = secretValue
c.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring(secretValue)))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring(secretValue)))
})
It("should not log the sentinel password", func() {
c.SentinelPassword = secretValue
c.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring(secretValue)))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring(secretValue)))
})
})
@@ -134,7 +134,7 @@ var _ = Describe("Redis", func() {
})
It("still obfuscates a file-loaded password in LogConfig", func() {
logger, hook = log.NewMockEntry()
logger, rec = log.NewRecorder()
dir := GinkgoT().TempDir()
pwPath := filepath.Join(dir, "pw")
@@ -147,8 +147,8 @@ var _ = Describe("Redis", func() {
redisCfg.LogConfig(logger)
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("redispass")))
Expect(hook.Messages).Should(ContainElement(ContainSubstring(secretObfuscator)))
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("redispass")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring(secretObfuscator)))
})
})
})
+5 -5
View File
@@ -1,9 +1,9 @@
package config
import (
"fmt"
"log/slog"
"strings"
"github.com/sirupsen/logrus"
)
// RewriterConfig custom DNS configuration
@@ -31,12 +31,12 @@ func (c *RewriterConfig) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *RewriterConfig) LogConfig(logger *logrus.Entry) {
logger.Infof("fallbackUpstream = %t", c.FallbackUpstream)
func (c *RewriterConfig) LogConfig(logger *slog.Logger) {
logger.Info(fmt.Sprintf("fallbackUpstream = %t", c.FallbackUpstream))
logger.Info("rules:")
for key, val := range c.Rewrite {
logger.Infof(" %s = %s", key, val)
logger.Info(fmt.Sprintf(" %s = %s", key, val))
}
}
+2 -2
View File
@@ -47,8 +47,8 @@ var _ = Describe("RewriterConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("rules:"),
ContainSubstring("original2 ="),
))
+2 -3
View File
@@ -3,10 +3,9 @@ package config
import (
"errors"
"fmt"
"log/slog"
"strings"
"time"
"github.com/0xERR0R/blocky/log"
)
const (
@@ -100,7 +99,7 @@ func (s *Schedule) validate() error {
for _, wd := range s.Weekdays {
if seen[wd] {
log.Log().Warnf("schedule contains duplicate weekday '%s', possible typo?", wd)
slog.Warn(fmt.Sprintf("schedule contains duplicate weekday '%s', possible typo?", wd))
}
seen[wd] = true
+5 -12
View File
@@ -7,8 +7,6 @@ import (
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
)
var _ = Describe("Schedule", func() {
@@ -143,13 +141,8 @@ var _ = Describe("Schedule", func() {
})
It("should warn about duplicate weekdays", func() {
testHook := &test.Hook{}
log.Log().AddHook(testHook)
log.Log().SetLevel(logrus.WarnLevel)
defer func() {
testHook.Reset()
}()
rec, restore := log.CaptureGlobal()
DeferCleanup(restore)
s := Schedule{
Start: "09:00",
@@ -157,9 +150,9 @@ var _ = Describe("Schedule", func() {
Weekdays: []Weekday{Weekday(time.Monday), Weekday(time.Monday), Weekday(time.Monday)},
}
Expect(s.validate()).Should(Succeed())
Expect(testHook.Entries).Should(HaveLen(2))
Expect(testHook.Entries[0].Message).Should(ContainSubstring("duplicate weekday"))
Expect(testHook.Entries[0].Message).Should(ContainSubstring("Monday"))
Expect(rec.Records()).Should(HaveLen(2))
Expect(rec.Messages()[0]).Should(ContainSubstring("duplicate weekday"))
Expect(rec.Messages()[0]).Should(ContainSubstring("Monday"))
})
})
+3 -3
View File
@@ -1,6 +1,6 @@
package config
import "github.com/sirupsen/logrus"
import "log/slog"
// Statistics contains the config for the in-memory statistics subsystem.
type Statistics struct {
@@ -14,6 +14,6 @@ func (c *Statistics) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *Statistics) LogConfig(logger *logrus.Entry) {
logger.Infof("enable = %t", c.Enable)
func (c *Statistics) LogConfig(logger *slog.Logger) {
logger.Info("enable", slog.Bool("enable", c.Enable))
}
+3 -3
View File
@@ -26,11 +26,11 @@ var _ = Describe("StatisticsConfig", func() {
Describe("LogConfig", func() {
It("logs the enabled state", func() {
logger, hook := log.NewMockEntry()
lgr, rec := log.NewRecorder()
cfg.LogConfig(logger)
cfg.LogConfig(lgr)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(rec.Records()).ShouldNot(BeEmpty())
})
})
})
+4 -3
View File
@@ -1,7 +1,8 @@
package config
import (
"github.com/sirupsen/logrus"
"fmt"
"log/slog"
)
// SUDN configuration for Special Use Domain Names
@@ -21,6 +22,6 @@ func (c *SUDN) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *SUDN) LogConfig(logger *logrus.Entry) {
logger.Debugf("rfc6762-appendixG = %v", c.RFC6762AppendixG)
func (c *SUDN) LogConfig(logger *slog.Logger) {
logger.Debug(fmt.Sprintf("rfc6762-appendixG = %v", c.RFC6762AppendixG))
}
+2 -2
View File
@@ -45,8 +45,8 @@ var _ = Describe("SUDNConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("rfc6762-appendixG = true")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("rfc6762-appendixG = true")))
})
})
})
+17 -15
View File
@@ -1,8 +1,10 @@
package config
import (
"fmt"
"log/slog"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus"
)
const UpstreamDefaultCfgName = "default"
@@ -45,22 +47,22 @@ func (c *Upstreams) hasQuicUpstream() bool {
return false
}
func (c *Upstreams) validate(logger *logrus.Entry) {
func (c *Upstreams) validate(logger *slog.Logger) {
defaults := mustDefault[Upstreams]()
if !c.Timeout.IsAboveZero() {
logger.Warnf("upstreams.timeout <= 0, setting to %s", defaults.Timeout)
logger.Warn(fmt.Sprintf("upstreams.timeout <= 0, setting to %s", defaults.Timeout))
c.Timeout = defaults.Timeout
}
if c.hasQuicUpstream() {
if !c.QUIC.MaxIdleTimeout.IsAboveZero() {
logger.Warnf("upstreams.quic.maxIdleTimeout <= 0, setting to %s", defaults.QUIC.MaxIdleTimeout)
logger.Warn(fmt.Sprintf("upstreams.quic.maxIdleTimeout <= 0, setting to %s", defaults.QUIC.MaxIdleTimeout))
c.QUIC.MaxIdleTimeout = defaults.QUIC.MaxIdleTimeout
}
if !c.QUIC.KeepAlivePeriod.IsAboveZero() {
logger.Warnf("upstreams.quic.keepAlivePeriod <= 0, setting to %s", defaults.QUIC.KeepAlivePeriod)
logger.Warn(fmt.Sprintf("upstreams.quic.keepAlivePeriod <= 0, setting to %s", defaults.QUIC.KeepAlivePeriod))
c.QUIC.KeepAlivePeriod = defaults.QUIC.KeepAlivePeriod
}
@@ -76,26 +78,26 @@ func (c *Upstreams) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *Upstreams) LogConfig(logger *logrus.Entry) {
func (c *Upstreams) LogConfig(logger *slog.Logger) {
logger.Info("init:")
log.WithIndent(logger, " ", c.Init.LogConfig)
logger.Info("timeout: ", c.Timeout)
logger.Info("strategy: ", c.Strategy)
logger.Info(fmt.Sprintf("timeout: %s", c.Timeout))
logger.Info(fmt.Sprintf("strategy: %s", c.Strategy))
logger.Info("groups:")
for name, upstreams := range c.Groups {
logger.Infof(" %s:", name)
logger.Info(fmt.Sprintf(" %s:", name))
for _, upstream := range upstreams {
logger.Infof(" - %s", upstream)
logger.Info(fmt.Sprintf(" - %s", upstream))
}
}
if c.hasQuicUpstream() {
logger.Info("quic:")
logger.Info(" maxIdleTimeout: ", c.QUIC.MaxIdleTimeout)
logger.Info(" keepAlivePeriod: ", c.QUIC.KeepAlivePeriod)
logger.Info(fmt.Sprintf(" maxIdleTimeout: %s", c.QUIC.MaxIdleTimeout))
logger.Info(fmt.Sprintf(" keepAlivePeriod: %s", c.QUIC.KeepAlivePeriod))
}
}
@@ -130,11 +132,11 @@ func (c *UpstreamGroup) IsEnabled() bool {
}
// LogConfig implements `config.Configurable`.
func (c *UpstreamGroup) LogConfig(logger *logrus.Entry) {
logger.Info("group: ", c.Name)
func (c *UpstreamGroup) LogConfig(logger *slog.Logger) {
logger.Info("group: " + c.Name)
logger.Info("upstreams:")
for _, upstream := range c.GroupUpstreams() {
logger.Infof(" - %s", upstream)
logger.Info(fmt.Sprintf(" - %s", upstream))
}
}
+11 -11
View File
@@ -53,8 +53,8 @@ var _ = Describe("ParallelBestConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("timeout:"),
ContainSubstring("groups:"),
ContainSubstring(":host2:"),
@@ -75,7 +75,7 @@ var _ = Describe("ParallelBestConfig", func() {
cfg.LogConfig(logger)
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("quic:"),
ContainSubstring("maxIdleTimeout:"),
ContainSubstring("keepAlivePeriod:"),
@@ -92,14 +92,14 @@ var _ = Describe("ParallelBestConfig", func() {
Expect(cfg.Timeout).Should(BeNumerically(">", 0))
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElement(ContainSubstring("timeout")))
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("timeout")))
})
It("should not override valid user values", func() {
cfg.validate(logger)
Expect(hook.Messages).ShouldNot(ContainElement(ContainSubstring("timeout")))
Expect(rec.Messages()).ShouldNot(ContainElement(ContainSubstring("timeout")))
})
When("QUIC upstream is configured", func() {
@@ -118,7 +118,7 @@ var _ = Describe("ParallelBestConfig", func() {
cfg.validate(logger)
Expect(cfg.QUIC.MaxIdleTimeout).Should(BeNumerically(">", 0))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("maxIdleTimeout")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("maxIdleTimeout")))
})
It("should warn when QUIC keepAlivePeriod is not above zero", func() {
@@ -128,7 +128,7 @@ var _ = Describe("ParallelBestConfig", func() {
cfg.validate(logger)
Expect(cfg.QUIC.KeepAlivePeriod).Should(BeNumerically(">", 0))
Expect(hook.Messages).Should(ContainElement(ContainSubstring("keepAlivePeriod")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("keepAlivePeriod")))
})
It("should warn when keepAlivePeriod >= maxIdleTimeout", func() {
@@ -137,7 +137,7 @@ var _ = Describe("ParallelBestConfig", func() {
cfg.validate(logger)
Expect(hook.Messages).Should(ContainElement(ContainSubstring("keep-alive won't prevent idle timeout")))
Expect(rec.Messages()).Should(ContainElement(ContainSubstring("keep-alive won't prevent idle timeout")))
})
})
})
@@ -183,8 +183,8 @@ var _ = Describe("ParallelBestConfig", func() {
It("should log configuration", func() {
cfg.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("group: test"),
ContainSubstring("upstreams:"),
ContainSubstring(":host1:"),
+1 -1
View File
@@ -452,7 +452,7 @@ http3:
# optional: logging configuration
log:
# optional: Log level (one from trace, debug, info, warn, error). Default: info
# optional: Log level (one from debug, info, warn, error). Default: info
level: info
# optional: Log format (text or json). Default: text
format: text
+7 -3
View File
@@ -128,7 +128,7 @@ All logging options are optional.
| Parameter | Type | Default value | Description |
| ------------- | -------------------------------------- | ------------- | ------------------------------------------------------------------------------------------------------------------------------------------------- |
| log.level | enum (trace, debug, info, warn, error) | info | Log level |
| log.level | enum (debug, info, warn, error) | info | Log level |
| log.format | enum (text, json) | text | Log format (text or json). |
| log.timestamp | bool | true | Log timestamps (true or false). |
| log.privacy | bool | false | Obfuscate log output (replace all alphanumeric characters with \*) for user sensitive data like request domains or responses to increase privacy. |
@@ -501,11 +501,15 @@ Pick `burst == rate` for a strict steady-state limiter with no spike tolerance.
```ini
[Definition]
failregex = ^.*rate-limiting: dropped query.*client_ip=<HOST>.*$
failregex = ^.*dropped query.*client_ip=<HOST>.*$
ignoreregex =
```
This filter assumes `logFormat: text` (the default); with `logFormat: json` the field becomes `"client_ip":"<HOST>"` and the regex must be adjusted accordingly.
This filter assumes `logFormat: text` (the default), where the line looks like
`2024-01-01 12:00:00 WRN dropped query prefix=rate-limiting client_ip=<HOST>`
(the rate-limiting prefix is a structured `prefix=rate-limiting` field). With
`logFormat: json` the field becomes `"client_ip":"<HOST>"` and the regex must be
adjusted accordingly.
### Metrics
+6 -2
View File
@@ -64,8 +64,12 @@ var _ = Describe("Domain blocking functionality", func() {
HaveTTL(BeNumerically("==", 123)),
))
// Verify warning in logs
Expect(getContainerLogs(ctx, blocky)).Should(ContainElement(ContainSubstring("cannot open source: ")))
// Verify warning in logs. The failing source URL is now a structured
// `source=` attribute rather than inline in the message text.
Expect(getContainerLogs(ctx, blocky)).Should(ContainElement(SatisfyAll(
ContainSubstring("cannot open source"),
ContainSubstring("source=http://wrong.domain.url/list.txt"),
)))
})
})
+3 -4
View File
@@ -4,6 +4,7 @@ import (
"context"
"fmt"
"io"
"log/slog"
"net"
"net/http"
"os"
@@ -12,8 +13,6 @@ import (
"strings"
"time"
log "github.com/sirupsen/logrus"
"github.com/0xERR0R/blocky/config"
"github.com/0xERR0R/blocky/util"
"github.com/avast/retry-go/v4"
@@ -430,7 +429,7 @@ func checkBlockyReadiness(ctx context.Context, cfg *config.Config, container tes
return nil
},
retry.OnRetry(func(n uint, err error) {
log.Infof("Performing retry DNS request #%d: %s\n", n, err)
slog.InfoContext(ctx, fmt.Sprintf("Performing retry DNS request #%d: %s", n, err))
}),
retry.Attempts(retryAttempts),
retry.DelayType(retry.BackOffDelay),
@@ -448,7 +447,7 @@ func checkBlockyReadiness(ctx context.Context, cfg *config.Config, container tes
return doHTTPRequest(ctx, container, port)
},
retry.OnRetry(func(n uint, err error) {
log.Infof("Performing retry HTTP request #%d: %s\n", n, err)
slog.InfoContext(ctx, fmt.Sprintf("Performing retry HTTP request #%d: %s", n, err))
}),
retry.Attempts(retryAttempts),
retry.DelayType(retry.BackOffDelay),
+4 -1
View File
@@ -102,7 +102,10 @@ var _ = Describe("Per-client rate limiting", func() {
return false
}
for _, line := range lines {
if strings.Contains(line, "rate-limiting:") &&
// tint renders the logger prefix as a structured
// `prefix=rate-limiting` attribute (not a `rate-limiting:` message
// prefix), matching the documented fail2ban failregex.
if strings.Contains(line, "prefix=rate-limiting") &&
strings.Contains(line, "dropped query") &&
strings.Contains(line, "client_ip=") {
return true
+3 -4
View File
@@ -20,7 +20,9 @@ require (
github.com/hashicorp/go-multierror v1.1.1
github.com/invopop/jsonschema v0.14.0
github.com/jedisct1/go-dnsstamps v0.0.0-20260518121737-6579dc73e4a2
github.com/lmittmann/tint v1.1.3
github.com/mattn/go-colorable v0.1.15
github.com/mattn/go-isatty v0.0.20
github.com/miekg/dns v1.1.72
github.com/moby/moby/api v1.55.0
github.com/mroth/weightedrand/v2 v2.1.0
@@ -33,14 +35,12 @@ require (
github.com/ramr/go-reaper v0.3.1
github.com/rs/cors v1.11.1
github.com/santhosh-tekuri/jsonschema/v6 v6.0.2
github.com/sirupsen/logrus v1.9.4
github.com/spf13/cobra v1.10.2
github.com/stretchr/testify v1.11.1
github.com/testcontainers/testcontainers-go v0.43.0
github.com/testcontainers/testcontainers-go/modules/mariadb v0.43.0
github.com/testcontainers/testcontainers-go/modules/postgres v0.43.0
github.com/testcontainers/testcontainers-go/modules/redis v0.43.0
github.com/x-cray/logrus-prefixed-formatter v0.5.2
golang.org/x/net v0.56.0
golang.org/x/sys v0.46.0
golang.org/x/time v0.15.0
@@ -121,11 +121,9 @@ require (
github.com/lufia/plan9stats v0.0.0-20211012122336-39d0f177ccd0 // indirect
github.com/magiconair/properties v1.8.10 // indirect
github.com/mailru/easyjson v0.9.1 // indirect
github.com/mattn/go-isatty v0.0.20 // indirect
github.com/mattn/go-runewidth v0.0.16 // indirect
github.com/mattn/goveralls v0.0.12 // indirect
github.com/mdelapenya/tlscert v0.2.0 // indirect
github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d // indirect
github.com/mitchellh/copystructure v1.2.0 // indirect
github.com/mitchellh/reflectwalk v1.0.2 // indirect
github.com/moby/docker-image-spec v1.3.1 // indirect
@@ -157,6 +155,7 @@ require (
github.com/russross/blackfriday/v2 v2.1.0 // indirect
github.com/shirou/gopsutil/v4 v4.26.5 // indirect
github.com/shopspring/decimal v1.4.0 // indirect
github.com/sirupsen/logrus v1.9.4 // indirect
github.com/speakeasy-api/jsonpath v0.6.2 // indirect
github.com/speakeasy-api/openapi-overlay v0.10.3 // indirect
github.com/spf13/cast v1.10.0 // indirect
+2 -4
View File
@@ -232,6 +232,8 @@ github.com/labstack/gommon v0.4.2 h1:F8qTUNXgG1+6WQmqoUWnz8WiEU60mXVVw0P4ht1WRA0
github.com/labstack/gommon v0.4.2/go.mod h1:QlUFxVM+SNXhDL/Z7YhocGIBYOiwB0mXm1+1bAPHPyU=
github.com/lib/pq v1.10.9 h1:YXG7RB+JIjhP29X+OtkiDnYaXQwpS4JEWq7dtCCRUEw=
github.com/lib/pq v1.10.9/go.mod h1:AlVN5x4E4T544tWzH6hKfbfQvm3HdbOxrmggDNAPY9o=
github.com/lmittmann/tint v1.1.3 h1:Hv4EaHWXQr+GTFnOU4VKf8UvAtZgn0VuKT+G0wFlO3I=
github.com/lmittmann/tint v1.1.3/go.mod h1:HIS3gSy7qNwGCj+5oRjAutErFBl4BzdQP6cJZ0NfMwE=
github.com/lufia/plan9stats v0.0.0-20211012122336-39d0f177ccd0 h1:6E+4a0GO5zZEnZ81pIr0yLvtUWk2if982qA3F3QD6H4=
github.com/lufia/plan9stats v0.0.0-20211012122336-39d0f177ccd0/go.mod h1:zJYVVT2jmtg6P3p1VtQj7WsuWi/y4VnjVBn7F8KPB3I=
github.com/magiconair/properties v1.8.10 h1:s31yESBquKXCV9a/ScB3ESkOjUYYv+X0rg8SYxI99mE=
@@ -255,8 +257,6 @@ github.com/mdelapenya/tlscert v0.2.0 h1:7H81W6Z/4weDvZBNOfQte5GpIMo0lGYEeWbkGp5L
github.com/mdelapenya/tlscert v0.2.0/go.mod h1:O4njj3ELLnJjGdkN7M/vIVCpZ+Cf0L6muqOG4tLSl8o=
github.com/mfridman/tparse v0.18.0 h1:wh6dzOKaIwkUGyKgOntDW4liXSo37qg5AXbIhkMV3vE=
github.com/mfridman/tparse v0.18.0/go.mod h1:gEvqZTuCgEhPbYk/2lS3Kcxg1GmTxxU7kTC8DvP0i/A=
github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d h1:5PJl274Y63IEHC+7izoQE9x6ikvDFZS2mDVS3drnohI=
github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d/go.mod h1:01TrycV0kFyexm33Z7vhZRXopbI8J3TDReVlkTgMUxE=
github.com/miekg/dns v1.1.72 h1:vhmr+TF2A3tuoGNkLDFK9zi36F2LS+hKTRW0Uf8kbzI=
github.com/miekg/dns v1.1.72/go.mod h1:+EuEPhdHOsfk6Wk5TT2CzssZdqkmFhf8r+aVyDEToIs=
github.com/mitchellh/copystructure v1.2.0 h1:vpKXTN4ewci03Vljg/q9QvCGUDttBOGBIa15WveJJGw=
@@ -426,8 +426,6 @@ github.com/vmware-labs/yaml-jsonpath v0.3.2 h1:/5QKeCBGdsInyDCyVNLbXyilb61MXGi9N
github.com/vmware-labs/yaml-jsonpath v0.3.2/go.mod h1:U6whw1z03QyqgWdgXxvVnQ90zN1BWz5V+51Ewf8k+rQ=
github.com/woodsbury/decimal128 v1.4.0 h1:xJATj7lLu4f2oObouMt2tgGiElE5gO6mSWUjQsBgUlc=
github.com/woodsbury/decimal128 v1.4.0/go.mod h1:BP46FUrVjVhdTbKT+XuQh2xfQaGki9LMIRJSFuh6THU=
github.com/x-cray/logrus-prefixed-formatter v0.5.2 h1:00txxvfBM9muc0jiLIEAkAcIMJzfthRT6usrui8uGmg=
github.com/x-cray/logrus-prefixed-formatter v0.5.2/go.mod h1:2duySbKsL6M18s5GU7VPsoEPHyzalCE06qoARUCeBBE=
github.com/xeipuuv/gojsonpointer v0.0.0-20180127040702-4e3ac2762d5f h1:J9EGpcZtP0E/raorCMxlFGSTBrsSlaDGf3jU/qvAE2c=
github.com/xeipuuv/gojsonpointer v0.0.0-20180127040702-4e3ac2762d5f/go.mod h1:N2zxlSyiKSe5eX1tZViRH5QA0qijqEDrYZiPEAiq3wU=
github.com/xeipuuv/gojsonreference v0.0.0-20180127040603-bd5ef7bd5415 h1:EzJWgHovont7NscjpAxXsDA8S8BMYve8Y5+7cuRE7R0=
+3 -4
View File
@@ -12,7 +12,6 @@ import (
"strconv"
"strings"
"github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/model"
"github.com/miekg/dns"
@@ -59,12 +58,12 @@ func GetHostPort(host string, port int) string {
func TempFile(data string) *os.File {
f, err := os.CreateTemp("", "prefix")
if err != nil {
log.Log().Fatal(err)
panic(err)
}
_, err = f.WriteString(data)
if err != nil {
log.Log().Fatal(err)
panic(err)
}
return f
@@ -75,7 +74,7 @@ func TestServer(data string) *httptest.Server {
srv := httptest.NewServer(http.HandlerFunc(func(rw http.ResponseWriter, req *http.Request) {
_, err := rw.Write([]byte(data))
if err != nil {
log.Log().Fatal("can't write to buffer:", err)
panic(fmt.Sprintf("can't write to buffer: %v", err))
}
}))
+8 -5
View File
@@ -7,10 +7,13 @@ import (
"errors"
"fmt"
"io"
"log/slog"
"net/http"
"os"
"path/filepath"
"sync"
"github.com/0xERR0R/blocky/log"
)
// cacheFilePath returns the on-disk path for a source URL: <dir>/<sha256hex(url)>.
@@ -92,7 +95,7 @@ func (c *cachingDownloader) DownloadFile(ctx context.Context, link string) (io.R
var statusErr *httpStatusError
if !errors.As(err, &statusErr) {
if cached, openErr := openCached(c.dir, link); openErr == nil {
logger().WithField("link", link).WithError(err).Warn("download failed, using cached copy")
logger().WarnContext(ctx, "download failed, using cached copy", slog.String("link", link), log.AttrError(err))
return cached, nil
}
@@ -104,7 +107,7 @@ func (c *cachingDownloader) DownloadFile(ctx context.Context, link string) (io.R
if resp.statusCode == http.StatusNotModified {
cached, openErr := openCached(c.dir, link)
if openErr == nil {
logger().WithField("link", link).Debug("source not modified, using cached copy")
logger().DebugContext(ctx, "source not modified, using cached copy", slog.String("link", link))
return cached, nil
}
@@ -129,7 +132,7 @@ func (c *cachingDownloader) DownloadFile(ctx context.Context, link string) (io.R
func (c *cachingDownloader) serveAndStore(link string, resp *downloadResponse) (io.ReadCloser, error) {
tmp, err := os.CreateTemp(c.dir, "dl-*.tmp")
if err != nil {
logger().WithError(err).Warnf("cannot create temp cache file in %s, serving without caching", c.dir)
logger().Warn(fmt.Sprintf("cannot create temp cache file in %s, serving without caching", c.dir), log.AttrError(err))
return resp.body, nil
}
@@ -160,7 +163,7 @@ func (c *cachingDownloader) serveAndStore(link string, resp *downloadResponse) (
_ = tmp.Close()
if err := os.Rename(tmp.Name(), finalPath); err != nil {
logger().WithError(err).Warnf("cannot finalize cache file %s", finalPath)
logger().Warn("cannot finalize cache file "+finalPath, log.AttrError(err))
_ = os.Remove(tmp.Name())
return
@@ -191,7 +194,7 @@ func (w *tolerantFileWriter) Write(p []byte) (int, error) {
if _, err := w.w.Write(p); err != nil {
w.failed = true
logger().WithError(err).Warn("cache write failed, abandoning on-disk copy")
logger().Warn("cache write failed, abandoning on-disk copy", log.AttrError(err))
}
return len(p), nil
+12 -8
View File
@@ -5,12 +5,14 @@ import (
"errors"
"fmt"
"io"
"log/slog"
"net"
"net/http"
"os"
"github.com/0xERR0R/blocky/config"
"github.com/0xERR0R/blocky/evt"
"github.com/0xERR0R/blocky/log"
"github.com/avast/retry-go/v4"
)
@@ -62,8 +64,9 @@ func NewDownloader(cfg config.Downloader, transport http.RoundTripper) FileDownl
}
if err := os.MkdirAll(cfg.CachePath, cacheDirPermission); err != nil {
logger().WithError(err).Warnf(
"cannot create download cache dir %s, continuing without on-disk cache", cfg.CachePath)
logger().Warn(
fmt.Sprintf("cannot create download cache dir %s, continuing without on-disk cache", cfg.CachePath),
log.AttrError(err))
return inner
}
@@ -172,17 +175,18 @@ func (d *httpDownloader) logRetry(link string) func(n uint, err error) {
var dnsErr *net.DNSError
logger := logger().
WithField("link", link).
WithField("attempt", fmt.Sprintf("%d/%d", n+1, d.cfg.Attempts))
l := logger().With(
slog.String("link", link),
slog.String("attempt", fmt.Sprintf("%d/%d", n+1, d.cfg.Attempts)),
)
switch {
case errors.As(err, &transientErr):
logger.Warnf("Temporary network err / Timeout occurred: %s", transientErr)
l.Warn(fmt.Sprintf("Temporary network err / Timeout occurred: %s", transientErr))
case errors.As(err, &dnsErr):
logger.Warnf("Name resolution err: %s", dnsErr.Err)
l.Warn("Name resolution err: " + dnsErr.Err)
default:
logger.Warnf("Can't download file: %s", err)
l.Warn(fmt.Sprintf("Can't download file: %s", err))
}
onDownloadError(link)
+7 -8
View File
@@ -17,7 +17,6 @@ import (
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/sirupsen/logrus/hooks/test"
)
var _ = Describe("Downloader", func() {
@@ -25,7 +24,7 @@ var _ = Describe("Downloader", func() {
sutConfig config.Downloader
sut *httpDownloader
failedDownloadCountEvtChannel chan string
loggerHook *test.Hook
rec *log.Recorder
)
BeforeEach(func() {
var err error
@@ -43,9 +42,9 @@ var _ = Describe("Downloader", func() {
Expect(Bus().Unsubscribe(CachingFailedDownloadChanged, fn)).Should(Succeed())
})
loggerHook = test.NewGlobal()
log.Log().AddHook(loggerHook)
DeferCleanup(loggerHook.Reset)
var restore func()
rec, restore = log.CaptureGlobal()
DeferCleanup(restore)
})
JustBeforeEach(func() {
@@ -118,7 +117,7 @@ var _ = Describe("Downloader", func() {
_, err := sut.DownloadFile(ctx, "somewrongurl")
Expect(err).Should(HaveOccurred())
Expect(loggerHook.LastEntry().Message).Should(ContainSubstring("Can't download file: "))
Expect(rec.LastMessage()).Should(ContainSubstring("Can't download file: "))
// failed download event was emitted only once
Expect(failedDownloadCountEvtChannel).Should(HaveLen(1))
Expect(failedDownloadCountEvtChannel).Should(Receive(Equal("somewrongurl")))
@@ -161,7 +160,7 @@ var _ = Describe("Downloader", func() {
// failed download event was emitted only once
Expect(failedDownloadCountEvtChannel).Should(HaveLen(1))
Expect(failedDownloadCountEvtChannel).Should(Receive(Equal(server.URL)))
Expect(loggerHook.LastEntry().Message).Should(ContainSubstring("Temporary network err / Timeout occurred: "))
Expect(rec.LastMessage()).Should(ContainSubstring("Temporary network err / Timeout occurred: "))
})
})
When("If timeout occurs on all request", func() {
@@ -220,7 +219,7 @@ var _ = Describe("Downloader", func() {
Expect(failedDownloadCountEvtChannel).Should(Receive(Equal("http://xyz.example.com")))
// Use Or() to combine matchers instead of the | operator
Expect(loggerHook.LastEntry().Message).Should(Or(
Expect(rec.LastMessage()).Should(Or(
ContainSubstring("Can't download file:"),
ContainSubstring("Name resolution err:")))
})
+36 -36
View File
@@ -5,12 +5,11 @@ import (
"context"
"errors"
"fmt"
"log/slog"
"net"
"os"
"sync/atomic"
"github.com/sirupsen/logrus"
"github.com/0xERR0R/blocky/cache/stringcache"
"github.com/0xERR0R/blocky/config"
"github.com/0xERR0R/blocky/evt"
@@ -54,25 +53,25 @@ type ListCache struct {
}
// LogConfig implements `config.Configurable`.
func (b *ListCache) LogConfig(logger *logrus.Entry) {
func (b *ListCache) LogConfig(logger *slog.Logger) {
total := 0
regexes := 0
for group := range b.groupSources {
count := b.groupedCache.ElementCount(group)
logger.Infof("%s: %d entries", group, count)
logger.Info(fmt.Sprintf("%s: %d entries", group, count))
total += count
regexes += b.regexCache.ElementCount(group)
}
if regexes > regexWarningThreshold {
logger.Warnf(
logger.Warn(fmt.Sprintf(
"REGEXES: %d !! High use of regexes is not recommended: they use a lot of memory and are very slow to search",
regexes,
)
))
}
logger.Infof("TOTAL: %d entries", total)
logger.Info(fmt.Sprintf("TOTAL: %d entries", total))
}
// NewListCache creates new list instance
@@ -101,7 +100,7 @@ func NewListCache(ctx context.Context,
}
err := cfg.StartPeriodicRefresh(ctx, c.refresh, func(err error) {
logger().WithError(err).Errorf("could not init %s", t)
logger().ErrorContext(ctx, fmt.Sprintf("could not init %s", t), log.AttrError(err))
})
if err != nil {
return nil, fmt.Errorf("failed to start periodic refresh for %s: %w", t, err)
@@ -110,7 +109,7 @@ func NewListCache(ctx context.Context,
return c, nil
}
func logger() *logrus.Entry {
func logger() *slog.Logger {
return log.PrefixedLog("list_cache")
}
@@ -150,15 +149,15 @@ func (b *ListCache) refresh(ctx context.Context) error {
if err != nil {
count := b.groupedCache.ElementCount(group)
logger := logger().WithFields(logrus.Fields{
logFieldGroup: group,
logFieldTotalCount: count,
})
l := logger().With(
slog.String(logFieldGroup, group),
slog.Int(logFieldTotalCount, count),
)
if count == 0 {
logger.Warn("Populating of group cache failed, cache will be empty until refresh succeeds")
l.WarnContext(ctx, "Populating of group cache failed, cache will be empty until refresh succeeds")
} else {
logger.Warn("Populating of group cache failed, using existing cache, if any")
l.WarnContext(ctx, "Populating of group cache failed, using existing cache, if any")
}
return fmt.Errorf("failed to create cache for group %s: %w", group, err)
@@ -168,10 +167,10 @@ func (b *ListCache) refresh(ctx context.Context) error {
evt.Bus().Publish(evt.BlockingCacheGroupChanged, b.listType, group, count)
logger().WithFields(logrus.Fields{
logFieldGroup: group,
logFieldTotalCount: count,
}).Info("group import finished")
logger().With(
slog.String(logFieldGroup, group),
slog.Int(logFieldTotalCount, count),
).InfoContext(ctx, "group import finished")
return nil
})
@@ -212,7 +211,7 @@ func (b *ListCache) createCacheForGroup(
if groupFactory.AddEntry(host) {
hasEntries.Store(true)
} else {
logger().WithField("host", host).Warn("no list cache was able to use host")
logger().With(slog.String("host", host)).WarnContext(ctx, "no list cache was able to use host")
}
}
@@ -258,15 +257,16 @@ func (b *ListCache) seedFromDisk(ctx context.Context) {
for group, sources := range localSources {
unlimitedGrp.Go(func(ctx context.Context) error {
if err := b.createCacheForGroup(producersGrp, unlimitedGrp, group, sources); err != nil {
logger().WithError(err).WithField(logFieldGroup, group).Debug("disk seed: skipping group with no usable local data")
logger().With(log.AttrError(err), slog.String(logFieldGroup, group)).
DebugContext(ctx, "disk seed: skipping group with no usable local data")
return nil // best-effort: never fail startup on a seed error
}
logger().WithFields(logrus.Fields{
logFieldGroup: group,
logFieldTotalCount: b.groupedCache.ElementCount(group),
}).Debug("seeded group cache from disk")
logger().With(
slog.String(logFieldGroup, group),
slog.Int(logFieldTotalCount, b.groupedCache.ElementCount(group)),
).DebugContext(ctx, "seeded group cache from disk")
return nil
})
@@ -295,7 +295,7 @@ func (b *ListCache) localSeedSources(dir string) map[string][]config.BytesSource
path := cacheFilePath(dir, source.From)
if _, err := os.Stat(path); err != nil {
if !errors.Is(err, os.ErrNotExist) {
logger().WithError(err).WithField("path", path).Debug("disk seed: cannot stat cache file")
logger().With(log.AttrError(err), slog.String("path", path)).Debug("disk seed: cannot stat cache file")
}
continue // no cached copy yet
@@ -316,18 +316,18 @@ func (b *ListCache) localSeedSources(dir string) map[string][]config.BytesSource
func (b *ListCache) parseFile(ctx context.Context, opener SourceOpener, resultCh chan<- string) error {
count := 0
logger := func() *logrus.Entry {
return logger().WithFields(logrus.Fields{
"source": opener.String(),
"count": count,
})
logger := func() *slog.Logger {
return logger().With(
slog.String("source", opener.String()),
slog.Int("count", count),
)
}
logger().Debug("starting processing of source")
logger().DebugContext(ctx, "starting processing of source")
r, err := opener.Open(ctx)
if err != nil {
logger().Error("cannot open source: ", err)
logger().ErrorContext(ctx, "cannot open source", log.AttrError(err))
return fmt.Errorf("failed to open list source %s: %w", opener, err)
}
@@ -335,7 +335,7 @@ func (b *ListCache) parseFile(ctx context.Context, opener SourceOpener, resultCh
p := parsers.AllowErrors(parsers.Hosts(r), b.cfg.MaxErrorsPerSource)
p.OnErr(func(err error) {
logger().Warnf("parse error: %s, trying to continue", err)
logger().WarnContext(ctx, fmt.Sprintf("parse error: %s, trying to continue", err))
})
err = parsers.ForEach[*parsers.HostsIterator](ctx, p, func(hosts *parsers.HostsIterator) error {
@@ -360,7 +360,7 @@ func (b *ListCache) parseFile(ctx context.Context, opener SourceOpener, resultCh
if err != nil {
// Don't log cancelation: it was caused by another goroutine failing
if !errors.Is(err, context.Canceled) {
logger().Error("parse error: ", err)
logger().ErrorContext(ctx, "parse error", log.AttrError(err))
}
// Only propagate the error if no entries were parsed
@@ -373,7 +373,7 @@ func (b *ListCache) parseFile(ctx context.Context, opener SourceOpener, resultCh
return nil
}
logger().Info("import succeeded")
logger().InfoContext(ctx, "import succeeded")
return nil
}
+7 -7
View File
@@ -6,6 +6,7 @@ import (
"errors"
"fmt"
"io"
"log/slog"
"net/http/httptest"
"os"
"path/filepath"
@@ -17,7 +18,6 @@ import (
"github.com/0xERR0R/blocky/lists/parsers"
"github.com/0xERR0R/blocky/log"
"github.com/google/uuid"
"github.com/sirupsen/logrus"
"github.com/stretchr/testify/mock"
. "github.com/0xERR0R/blocky/helpertest"
@@ -408,12 +408,12 @@ var _ = Describe("ListCache", func() {
})
Describe("LogConfig", func() {
var (
logger *logrus.Entry
hook *log.MockLoggerHook
logger *slog.Logger
rec *log.Recorder
)
BeforeEach(func() {
logger, hook = log.NewMockEntry()
logger, rec = log.NewRecorder()
lists = map[string][]config.BytesSource{
"gr1": config.NewBytesSources(server1.URL, server2.URL),
@@ -426,8 +426,8 @@ var _ = Describe("ListCache", func() {
Expect(err).Should(Succeed())
sut.LogConfig(logger)
Expect(hook.Calls).ShouldNot(BeEmpty())
Expect(hook.Messages).Should(ContainElements(
Expect(rec.Records()).ShouldNot(BeEmpty())
Expect(rec.Messages()).Should(ContainElements(
ContainSubstring("gr1:"),
ContainSubstring("gr2:"),
ContainSubstring("TOTAL:"),
@@ -595,7 +595,7 @@ func mockListSource() config.BytesSource {
func createTestListFile(dir string, totalLines int) (string, int) {
file, err := os.CreateTemp(dir, "blocky")
if err != nil {
log.Log().Fatal(err)
Fail(fmt.Sprintf("failed to create temp file: %v", err))
}
w := bufio.NewWriter(file)
+3 -3
View File
@@ -9,9 +9,9 @@ import (
. "github.com/onsi/gomega"
)
func init() {
log.Silence()
}
var _ = BeforeSuite(func() {
log.ConfigureForTest(GinkgoWriter)
})
func TestLists(t *testing.T) {
RegisterFailHandler(Fail)
+53 -25
View File
@@ -2,45 +2,73 @@ package log
import (
"context"
"github.com/sirupsen/logrus"
"log/slog"
)
type ctxKey struct{}
type attrsKey struct{}
func NewCtx(ctx context.Context, logger *logrus.Entry) (context.Context, *logrus.Entry) {
ctx = context.WithValue(ctx, ctxKey{}, logger)
// ctxWithAttrs appends request-scoped attrs to the context. They are injected
// into every record emitted with this context by the contextHandler.
func ctxWithAttrs(ctx context.Context, attrs ...slog.Attr) context.Context {
existing := attrsFromCtx(ctx)
return ctx, entryWithCtx(ctx, logger)
merged := make([]slog.Attr, 0, len(existing)+len(attrs))
merged = append(merged, existing...)
merged = append(merged, attrs...)
return context.WithValue(ctx, attrsKey{}, merged)
}
func FromCtx(ctx context.Context) *logrus.Entry {
logger, ok := ctx.Value(ctxKey{}).(*logrus.Entry)
if !ok {
// Fallback to the global logger
return logrus.NewEntry(Log())
func attrsFromCtx(ctx context.Context) []slog.Attr {
if ctx == nil {
return nil
}
// Ensure `logger.Context == ctx`, not always the case since `ctx` could be a child of `logger.Context`
return entryWithCtx(ctx, logger)
attrs, _ := ctx.Value(attrsKey{}).([]slog.Attr)
return attrs
}
func entryWithCtx(ctx context.Context, logger *logrus.Entry) *logrus.Entry {
loggerCopy := *logger
loggerCopy.Context = ctx
// WithContext binds ctx's request-scoped attrs to l so they are emitted on
// every record, even when the caller uses the non-Context methods
// (logger.Debug/Info/...) which slog dispatches with context.Background().
//
// slog.LogValuer attrs stay unresolved until a record is actually emitted, so
// this is safe to call on the hot path. When ctx carries no attrs, l is
// returned unchanged (no allocation).
func WithContext(ctx context.Context, l *slog.Logger) *slog.Logger {
if len(attrsFromCtx(ctx)) == 0 {
return l
}
return &loggerCopy
return slog.New(boundContextHandler(ctx, l.Handler()))
}
func WrapCtx(ctx context.Context, wrap func(*logrus.Entry) *logrus.Entry) (context.Context, *logrus.Entry) {
logger := FromCtx(ctx)
logger = wrap(logger)
// WithContextFields binds ctx's request-scoped attrs to l and attaches attrs, in a
// single handler chain — avoiding the throwaway logger that WithContext(...).With(...)
// would allocate. attrs are consumed as []slog.Attr directly (no any-boxing).
func WithContextFields(ctx context.Context, l *slog.Logger, attrs ...slog.Attr) *slog.Logger {
h := l.Handler()
if len(attrsFromCtx(ctx)) > 0 {
h = boundContextHandler(ctx, h)
}
return NewCtx(ctx, logger)
return slog.New(h.WithAttrs(attrs))
}
func CtxWithFields(ctx context.Context, fields logrus.Fields) (context.Context, *logrus.Entry) {
return WrapCtx(ctx, func(e *logrus.Entry) *logrus.Entry {
return e.WithFields(fields)
})
// FromCtx returns the global logger bound to ctx's request-scoped attrs.
func FromCtx(ctx context.Context) *slog.Logger { return WithContext(ctx, Log()) }
// CtxWithFields appends attrs to ctx and returns the ctx together with a logger
// that emits them. The attrs are injected by the contextHandler at emit time.
func CtxWithFields(ctx context.Context, attrs ...slog.Attr) (context.Context, *slog.Logger) {
ctx = ctxWithAttrs(ctx, attrs...)
return ctx, FromCtx(ctx)
}
// WithIndent calls fn with a logger that prepends indent to every message.
// Nesting accumulates indents.
func WithIndent(l *slog.Logger, indent string, fn func(*slog.Logger)) {
fn(slog.New(&indentHandler{indent: indent, next: l.Handler()}))
}
+58
View File
@@ -0,0 +1,58 @@
package log
import (
"bytes"
"context"
"log/slog"
"strings"
"testing"
)
func TestCtxWithFieldsAndFromCtx(t *testing.T) {
var buf bytes.Buffer
configureTo(&buf, &Config{Level: Level(slog.LevelInfo), Format: FormatTypeJson, Timestamp: true})
ctx, l := CtxWithFields(context.Background(), slog.String("req_id", "r1"))
l.InfoContext(ctx, "first")
// A logger from the same ctx must also carry the field.
FromCtx(ctx).InfoContext(ctx, "second")
out := buf.String()
if strings.Count(out, `"req_id":"r1"`) != 2 {
t.Errorf("expected req_id on both lines, got: %s", out)
}
}
// A ctx-bound logger must carry the request attrs even on the NON-Context emit
// methods (logger.Info/Debug/...), which slog dispatches with a background
// context. This is the regression that dropped req_id/client_ip from resolver
// logs after the slog migration.
func TestWithContextNonContextEmit(t *testing.T) {
var buf bytes.Buffer
configureTo(&buf, &Config{Level: Level(slog.LevelInfo), Format: FormatTypeJson, Timestamp: false})
ctx, _ := CtxWithFields(context.Background(), slog.String("req_id", "r1"))
// Plain Info (no *Context), exactly like the resolver call sites.
WithContext(ctx, Log()).Info("plain")
if out := buf.String(); strings.Count(out, `"req_id":"r1"`) != 1 {
t.Errorf("expected req_id on the plain (non-context) line exactly once, got: %s", out)
}
}
// Binding must not double-inject when the caller then uses a Context method
// (the bound handler replaces, not stacks on, the global contextHandler).
func TestWithContextNoDoubleInject(t *testing.T) {
var buf bytes.Buffer
configureTo(&buf, &Config{Level: Level(slog.LevelInfo), Format: FormatTypeJson, Timestamp: false})
ctx, _ := CtxWithFields(context.Background(), slog.String("req_id", "r1"))
WithContext(ctx, Log()).InfoContext(ctx, "ctx-method")
if out := buf.String(); strings.Count(out, `"req_id":"r1"`) != 1 {
t.Errorf("expected req_id exactly once (no double inject), got: %s", out)
}
}
+108
View File
@@ -0,0 +1,108 @@
package log
import (
"context"
"log/slog"
)
// contextHandler injects request-scoped attrs stored in the context into each
// emitted record. Because injection happens in Handle (after the level check),
// any slog.LogValuer attrs are resolved only when a record is actually emitted.
//
// If bound is non-nil, attrs are read from it instead of the per-call context.
// This lets WithContext return a logger that injects request fields even when
// the caller uses the non-Context emit methods (logger.Debug/Info/...), which
// slog dispatches with context.Background(). A bound handler replaces (rather
// than wraps) the unbound contextHandler so attrs are never injected twice.
//
// NOTE: WithGroup nests subsequently-added attrs, including the ctx attrs
// injected here, under the group. Do not call WithGroup on a context-aware
// logger if the request fields must stay top-level; none of blocky's hot paths
// do (the only WithGroup users are the handler chain itself).
type contextHandler struct {
next slog.Handler
//nolint:containedctx // intentional: holds the request ctx so non-Context emit methods still inject request attrs
bound context.Context
}
func (h *contextHandler) attrCtx(ctx context.Context) context.Context {
// A bound handler injects its bound ctx's attrs so the non-Context emit
// methods (which slog dispatches with context.Background()) still carry the
// request fields. But when the caller passes a context that itself carries
// attrs, honor it — never let a stale bound ctx shadow a live request ctx.
if h.bound != nil && len(attrsFromCtx(ctx)) == 0 {
return h.bound
}
return ctx
}
func (h *contextHandler) Enabled(ctx context.Context, level slog.Level) bool {
return h.next.Enabled(h.attrCtx(ctx), level)
}
func (h *contextHandler) Handle(ctx context.Context, r slog.Record) error {
ctx = h.attrCtx(ctx)
if attrs := attrsFromCtx(ctx); len(attrs) > 0 {
r.AddAttrs(attrs...)
}
return h.next.Handle(ctx, r)
}
func (h *contextHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return &contextHandler{next: h.next.WithAttrs(attrs), bound: h.bound}
}
func (h *contextHandler) WithGroup(name string) slog.Handler {
return &contextHandler{next: h.next.WithGroup(name), bound: h.bound}
}
// boundContextHandler returns a contextHandler that injects ctx's attrs, layered
// over h with any pre-existing contextHandler removed so the same attrs are never
// injected twice. It looks through an indentHandler wrapper (the only handler that
// can sit above a contextHandler), so the strip is robust to handler-chain order
// rather than assuming the contextHandler is outermost.
func boundContextHandler(ctx context.Context, h slog.Handler) slog.Handler {
return &contextHandler{next: stripContextHandler(h), bound: ctx}
}
// stripContextHandler removes a contextHandler from the chain (recursing through a
// single indentHandler), returning the chain without its per-call ctx injection so
// a freshly-bound contextHandler placed above it cannot double-inject.
func stripContextHandler(h slog.Handler) slog.Handler {
switch v := h.(type) {
case *contextHandler:
return v.next
case *indentHandler:
return &indentHandler{indent: v.indent, next: stripContextHandler(v.next)}
default:
return h
}
}
// indentHandler prepends a fixed indent string to every record message. Used
// for the startup config dump; not on the hot path.
type indentHandler struct {
indent string
next slog.Handler
}
func (h *indentHandler) Enabled(ctx context.Context, level slog.Level) bool {
return h.next.Enabled(ctx, level)
}
func (h *indentHandler) Handle(ctx context.Context, r slog.Record) error {
r.Message = h.indent + r.Message
return h.next.Handle(ctx, r)
}
func (h *indentHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return &indentHandler{indent: h.indent, next: h.next.WithAttrs(attrs)}
}
func (h *indentHandler) WithGroup(name string) slog.Handler {
return &indentHandler{indent: h.indent, next: h.next.WithGroup(name)}
}
+52
View File
@@ -0,0 +1,52 @@
package log
import (
"bytes"
"context"
"log/slog"
"strings"
"testing"
)
func TestContextHandlerInjectsCtxAttrs(t *testing.T) {
var buf bytes.Buffer
base := slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})
logger := slog.New(&contextHandler{next: base})
ctx := ctxWithAttrs(context.Background(), slog.String("req_id", "abc"))
logger.InfoContext(ctx, "hello")
out := buf.String()
if !strings.Contains(out, "req_id=abc") {
t.Errorf("expected req_id in output, got: %s", out)
}
if !strings.Contains(out, "hello") {
t.Errorf("expected message in output, got: %s", out)
}
}
func TestContextHandlerLazyOnDisabledLevel(t *testing.T) {
var resolved int
valuer := slog.AnyValue(logValuerFunc(func() slog.Value {
resolved++
return slog.StringValue("expensive")
}))
var buf bytes.Buffer
base := slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})
logger := slog.New(&contextHandler{next: base})
ctx := ctxWithAttrs(context.Background(), slog.Attr{Key: "q", Value: valuer})
logger.DebugContext(ctx, "should not emit") // Debug < Info => disabled
if resolved != 0 {
t.Errorf("LogValuer resolved %d times on disabled level, want 0", resolved)
}
}
type logValuerFunc func() slog.Value
func (f logValuerFunc) LogValue() slog.Value { return f() }
+22
View File
@@ -0,0 +1,22 @@
package log
import (
"bytes"
"context"
"log/slog"
"strings"
"testing"
)
func TestWithIndentPrefixesMessages(t *testing.T) {
var buf bytes.Buffer
configureTo(&buf, &Config{Level: Level(slog.LevelInfo), Format: FormatTypeText, Timestamp: false})
WithIndent(Log(), " ", func(l *slog.Logger) {
l.InfoContext(context.Background(), "indented line")
})
if !strings.Contains(buf.String(), " indented line") {
t.Errorf("expected indented message, got: %q", buf.String())
}
}
+54
View File
@@ -0,0 +1,54 @@
package log
import (
"fmt"
"log/slog"
"strings"
)
// Level is blocky's log level. It wraps slog.Level but parses the historical
// (logrus) level strings from YAML so existing configs keep working.
type Level slog.Level
// ToSlogLevel returns the underlying slog.Level.
func (l Level) ToSlogLevel() slog.Level { return slog.Level(l) }
//nolint:gochecknoglobals
var levelByName = map[string]slog.Level{
"trace": slog.LevelDebug, // legacy alias: the dedicated trace level was removed; folds into debug
"debug": slog.LevelDebug,
"info": slog.LevelInfo,
"warn": slog.LevelWarn,
"warning": slog.LevelWarn,
"error": slog.LevelError,
"fatal": slog.LevelError, // legacy: no code emits at fatal anymore
"panic": slog.LevelError, // legacy
}
// String returns the canonical lower-case level name. slog.Level.String()
// already yields "DEBUG"/"INFO"/"WARN"/"ERROR" (with "+N"/"-N" offsets for
// non-canonical levels), so lower-casing it gives blocky's canonical names that
// UnmarshalText round-trips, without a parallel name table to keep in sync.
func (l Level) String() string {
return strings.ToLower(slog.Level(l).String())
}
// UnmarshalText implements encoding.TextUnmarshaler (used by the YAML loader,
// the same mechanism FormatType relies on).
func (l *Level) UnmarshalText(text []byte) error {
name := strings.ToLower(strings.TrimSpace(string(text)))
lvl, ok := levelByName[name]
if !ok {
return fmt.Errorf("invalid log level %q", string(text))
}
*l = Level(lvl)
return nil
}
// MarshalText implements encoding.TextMarshaler.
func (l Level) MarshalText() ([]byte, error) {
return []byte(l.String()), nil
}
+46
View File
@@ -0,0 +1,46 @@
package log
import (
"log/slog"
"testing"
)
func TestLevelUnmarshalText(t *testing.T) {
cases := map[string]slog.Level{
"trace": slog.LevelDebug, // legacy alias folds into debug
"debug": slog.LevelDebug,
"info": slog.LevelInfo,
"warn": slog.LevelWarn,
"warning": slog.LevelWarn,
"error": slog.LevelError,
"fatal": slog.LevelError,
"panic": slog.LevelError,
"INFO": slog.LevelInfo, // case-insensitive
}
for in, want := range cases {
var l Level
if err := l.UnmarshalText([]byte(in)); err != nil {
t.Fatalf("UnmarshalText(%q) error: %v", in, err)
}
if l.ToSlogLevel() != want {
t.Errorf("UnmarshalText(%q) = %v, want %v", in, l.ToSlogLevel(), want)
}
}
var bad Level
if err := bad.UnmarshalText([]byte("nonsense")); err == nil {
t.Error("expected error for invalid level, got nil")
}
}
func TestLevelStringRoundTrip(t *testing.T) {
for _, name := range []string{"debug", "info", "warn", "error"} {
var l Level
if err := l.UnmarshalText([]byte(name)); err != nil {
t.Fatal(err)
}
if l.String() != name {
t.Errorf("String() = %q, want %q", l.String(), name)
}
}
}
+108 -147
View File
@@ -3,28 +3,20 @@ package log
//go:generate go tool go-enum -f=$GOFILE --marshal --names --template ../tools/schemagen/templates/enum_description.tmpl
import (
"fmt"
"io"
"maps"
"log/slog"
"os"
"strings"
"sync"
"sync/atomic"
"github.com/creasty/defaults"
"github.com/lmittmann/tint"
"github.com/mattn/go-colorable"
"github.com/sirupsen/logrus"
prefixed "github.com/x-cray/logrus-prefixed-formatter"
"github.com/mattn/go-isatty"
)
const prefixField = "prefix"
// Logger is the global logging instance
//
//nolint:gochecknoglobals
var (
logger *logrus.Logger
initDone atomic.Bool
const (
prefixKey = "prefix"
textTimeLayout = "2006-01-02 15:04:05"
)
// FormatType format for logging ENUM(
@@ -33,167 +25,136 @@ var (
// )
type FormatType int
// Config defines all logging configurations
// Config defines all logging configuration.
type Config struct {
Level logrus.Level `default:"info" yaml:"level"`
Format FormatType `default:"text" yaml:"format"`
Privacy bool `default:"false" yaml:"privacy"`
Timestamp bool `default:"true" yaml:"timestamp"`
Level Level `default:"info" yaml:"level"`
Format FormatType `default:"text" yaml:"format"`
Privacy bool `default:"false" yaml:"privacy"`
Timestamp bool `default:"true" yaml:"timestamp"`
}
// DefaultConfig returns a new Config initialized with default values.
// DefaultConfig returns a Config initialized with default values.
func DefaultConfig() *Config {
cfg := new(Config)
defaults.MustSet(cfg)
return cfg
}
//nolint:gochecknoglobals
var levelVar = new(slog.LevelVar)
//nolint:gochecknoinits
func init() {
if !initDone.CompareAndSwap(false, true) {
return
}
newLogger := logrus.New()
ConfigureLogger(newLogger, DefaultConfig())
logger = newLogger
setLogger(newLogger(os.Stdout, DefaultConfig()))
}
// Log returns the global logger
func Log() *logrus.Logger {
return logger
// setLogger installs l as the slog default. Readers (Log/PrefixedLog/FromCtx)
// read slog.Default(), which slog updates atomically, so a hot-path reader
// never races with a Configure/Silence/CaptureGlobal swap.
func setLogger(l *slog.Logger) {
slog.SetDefault(l)
}
// PrefixedLog return the global logger with prefix
func PrefixedLog(prefix string) *logrus.Entry {
return logger.WithField(prefixField, prefix)
// Log returns the global logger.
func Log() *slog.Logger { return slog.Default() }
// SetLevel changes the active log level at runtime.
func SetLevel(l slog.Level) { levelVar.Set(l) }
// Configure applies cfg to the global logger (writing to os.Stdout).
func Configure(cfg *Config) { configureTo(os.Stdout, cfg) }
// configureTo is the test seam: it builds the global logger writing to w.
func configureTo(w io.Writer, cfg *Config) {
levelVar.Set(cfg.Level.ToSlogLevel())
setLogger(newLogger(w, cfg))
}
// WithPrefix adds the given prefix to the logger.
func WithPrefix(logger *logrus.Entry, prefix string) *logrus.Entry {
if existingPrefix, ok := logger.Data[prefixField]; ok {
prefix = fmt.Sprintf("%s.%s", existingPrefix, prefix)
}
return logger.WithField(prefixField, prefix)
}
// EscapeInput removes line breaks from input
func EscapeInput(input string) string {
result := strings.ReplaceAll(input, "\n", "")
result = strings.ReplaceAll(result, "\r", "")
return result
}
// Configure applies configuration to the global logger.
func Configure(cfg *Config) {
ConfigureLogger(logger, cfg)
}
// Configure applies configuration to the given logger.
func ConfigureLogger(logger *logrus.Logger, cfg *Config) {
logger.SetLevel(cfg.Level)
// newLogger builds a slog logger for cfg writing to w, wrapped in the
// contextHandler so request-scoped attrs are injected lazily.
func newLogger(w io.Writer, cfg *Config) *slog.Logger {
var base slog.Handler
switch cfg.Format {
case FormatTypeText:
// Respect NO_COLOR env var (https://no-color.org/)
noColor := os.Getenv("NO_COLOR") != ""
logFormatter := &prefixed.TextFormatter{
TimestampFormat: "2006-01-02 15:04:05",
FullTimestamp: true,
ForceFormatting: true,
ForceColors: false,
QuoteEmptyFields: true,
DisableTimestamp: !cfg.Timestamp,
DisableColors: noColor,
}
logFormatter.SetColorScheme(&prefixed.ColorScheme{
PrefixStyle: "blue+b",
TimestampStyle: "white+h",
})
logger.SetFormatter(logFormatter)
if noColor {
logger.SetOutput(os.Stdout)
} else {
// Windows does not support ANSI colors
logger.SetOutput(colorable.NewColorableStdout())
}
case FormatTypeJson:
logger.SetFormatter(&logrus.JSONFormatter{})
}
}
// Silence disables the logger output
func Silence() {
initDone.Store(true)
logger = logrus.New()
logger.SetFormatter(nopFormatter{}) // skip expensive formatting
// not actually needed but doesn't hurt
logger.SetOutput(io.Discard)
}
type nopFormatter struct{}
func (f nopFormatter) Format(*logrus.Entry) ([]byte, error) {
return nil, nil
}
func WithIndent(log *logrus.Entry, prefix string, callback func(*logrus.Entry)) {
undo := indentMessages(prefix, log.Logger)
defer undo()
callback(log)
}
// indentMessages modifies a logger and adds `prefix` to all messages.
//
// The returned function must be called to remove the prefix.
func indentMessages(prefix string, logger *logrus.Logger) func() {
if _, ok := logger.Formatter.(*prefixed.TextFormatter); !ok {
// log is not plaintext, do nothing
return func() {}
}
oldHooks := maps.Clone(logger.Hooks)
logger.AddHook(prefixMsgHook{
prefix: prefix,
})
var once sync.Once
return func() {
once.Do(func() {
logger.ReplaceHooks(oldHooks)
base = slog.NewJSONHandler(w, &slog.HandlerOptions{
Level: levelVar,
ReplaceAttr: replaceAttr(cfg),
})
case FormatTypeText:
fallthrough
default:
base = tint.NewHandler(textWriter(w), &tint.Options{
Level: levelVar,
TimeFormat: textTimeLayout,
NoColor: noColor(w),
ReplaceAttr: replaceAttr(cfg),
})
}
return slog.New(&contextHandler{next: base})
}
type prefixMsgHook struct {
prefix string
// textWriter wraps os.Stdout with go-colorable for Windows ANSI support; other
// writers (tests, files) are returned unchanged.
func textWriter(w io.Writer) io.Writer {
if w == os.Stdout {
return colorable.NewColorableStdout()
}
return w
}
// Levels implements `logrus.Hook`.
func (h prefixMsgHook) Levels() []logrus.Level {
return logrus.AllLevels
// noColor preserves blocky's historical behavior: disable color when NO_COLOR
// is set OR stdout is not a TTY. tint does not check NO_COLOR itself.
func noColor(w io.Writer) bool {
if os.Getenv("NO_COLOR") != "" {
return true
}
if f, ok := w.(*os.File); ok {
return !isatty.IsTerminal(f.Fd())
}
return true // non-file writer (tests, pipes) => no color
}
// Fire implements `logrus.Hook`.
func (h prefixMsgHook) Fire(entry *logrus.Entry) error {
entry.Message = h.prefix + entry.Message
// replaceAttr drops the time attr when timestamps are disabled.
func replaceAttr(cfg *Config) func([]string, slog.Attr) slog.Attr {
noTimestamp := !cfg.Timestamp
return nil
return func(groups []string, a slog.Attr) slog.Attr {
if len(groups) != 0 {
return a
}
if a.Key == slog.TimeKey && noTimestamp {
return slog.Attr{}
}
return a
}
}
// PrefixedLog returns the global logger tagged with a prefix attr.
func PrefixedLog(prefix string) *slog.Logger {
return slog.Default().With(slog.String(prefixKey, prefix))
}
//nolint:gochecknoglobals
var inputEscaper = strings.NewReplacer("\n", "", "\r", "")
// EscapeInput removes line breaks from input (log-injection hardening).
func EscapeInput(input string) string {
return inputEscaper.Replace(input)
}
// Silence discards all log output. Prefer ConfigureForTest(GinkgoWriter) in
// Ginkgo suites; Silence remains for non-Ginkgo callers.
func Silence() {
setLogger(slog.New(slog.DiscardHandler))
}
// AttrError returns a standard attr for an error value.
func AttrError(err error) slog.Attr { return slog.Any("error", err) }
+71
View File
@@ -0,0 +1,71 @@
package log
import (
"context"
"io"
"log/slog"
"testing"
)
func benchSetup(b *testing.B, level slog.Level) {
b.Helper()
configureTo(io.Discard, &Config{Level: Level(level), Format: FormatTypeText, Timestamp: true})
b.ReportAllocs()
}
func requestAttrs() []slog.Attr {
return []slog.Attr{
slog.String("req_id", "b8f4c1e2-0000-1111-2222-333344445555"),
slog.String("question", "A example.com."),
slog.String("client_ip", "192.168.178.1"),
}
}
func BenchmarkCtxWithFields(b *testing.B) {
benchSetup(b, slog.LevelInfo)
ctx := context.Background()
for b.Loop() {
_, _ = CtxWithFields(ctx, requestAttrs()...)
}
}
func BenchmarkFromCtx(b *testing.B) {
ctx, _ := CtxWithFields(context.Background(), requestAttrs()...)
benchSetup(b, slog.LevelInfo)
for b.Loop() {
_ = FromCtx(ctx)
}
}
func BenchmarkFromCtxWithPrefix(b *testing.B) {
ctx, _ := CtxWithFields(context.Background(), requestAttrs()...)
benchSetup(b, slog.LevelInfo)
for b.Loop() {
_ = FromCtx(ctx).With(slog.String(prefixKey, "blocking"))
}
}
var chainPrefixes = []string{
"client_names", "query_logging", "metrics", "blocking", "caching",
"conditional", "custom_dns", "hosts_file", "dns64", "upstream",
}
func benchmarkRequestChain(b *testing.B, level slog.Level) {
b.Helper()
benchSetup(b, level)
base := context.Background()
for b.Loop() {
ctx, _ := CtxWithFields(base, requestAttrs()...)
for _, prefix := range chainPrefixes {
logger := FromCtx(ctx).With(slog.String(prefixKey, prefix))
logger.DebugContext(ctx, "resolving in "+prefix)
}
}
}
func BenchmarkRequestChain_InfoLevel(b *testing.B) { benchmarkRequestChain(b, slog.LevelInfo) }
func BenchmarkRequestChain_DebugLevel(b *testing.B) { benchmarkRequestChain(b, slog.LevelDebug) }
+54
View File
@@ -0,0 +1,54 @@
package log
import (
"bytes"
"context"
"log/slog"
"strings"
"testing"
)
func TestConfigureJSONEmitsKeys(t *testing.T) {
var buf bytes.Buffer
cfg := &Config{Level: Level(slog.LevelInfo), Format: FormatTypeJson, Timestamp: true}
configureTo(&buf, cfg) // test seam (Step 3)
ctx := ctxWithAttrs(context.Background(), slog.String("req_id", "xyz"))
Log().InfoContext(ctx, "msg", slog.String("prefix", "blocking"))
out := buf.String()
for _, want := range []string{`"req_id":"xyz"`, `"prefix":"blocking"`, `"msg":"msg"`} {
if !strings.Contains(out, want) {
t.Errorf("JSON output missing %s; got: %s", want, out)
}
}
}
func TestConfigureTimestampDisabled(t *testing.T) {
var buf bytes.Buffer
cfg := &Config{Level: Level(slog.LevelInfo), Format: FormatTypeJson, Timestamp: false}
configureTo(&buf, cfg)
Log().Info("msg")
if strings.Contains(buf.String(), `"time"`) {
t.Errorf("expected no time key when Timestamp=false; got: %s", buf.String())
}
}
func TestSetLevelDynamic(t *testing.T) {
var buf bytes.Buffer
cfg := &Config{Level: Level(slog.LevelInfo), Format: FormatTypeJson, Timestamp: true}
configureTo(&buf, cfg)
Log().Debug("hidden") // below info
if strings.Contains(buf.String(), "hidden") {
t.Fatal("debug should be hidden at info level")
}
SetLevel(slog.LevelDebug)
Log().Debug("nowvisible")
if !strings.Contains(buf.String(), "nowvisible") {
t.Error("debug should be visible after SetLevel(Debug)")
}
}
-57
View File
@@ -1,57 +0,0 @@
package log
import (
"sync"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
"github.com/stretchr/testify/mock"
)
func NewMockEntry() (*logrus.Entry, *MockLoggerHook) {
logger, _ := test.NewNullLogger()
logger.Level = logrus.TraceLevel
entry := logrus.Entry{Logger: logger}
hook := MockLoggerHook{}
entry.Logger.AddHook(&hook)
hook.On("Fire", mock.Anything).Return(nil)
return &entry, &hook
}
type MockLoggerHook struct {
mock.Mock
Messages []string
mu sync.Mutex
}
// Levels implements `logrus.Hook`.
func (h *MockLoggerHook) Levels() []logrus.Level {
return logrus.AllLevels
}
// Fire implements `logrus.Hook`.
func (h *MockLoggerHook) Fire(entry *logrus.Entry) error {
_ = h.Called()
h.mu.Lock()
defer h.mu.Unlock()
h.Messages = append(h.Messages, entry.Message)
return nil
}
// Reset clears the Messages slice, removing all logged messages.
// It is safe to call concurrently with other methods on MockLoggerHook,
// as all access to Messages is protected by a mutex.
func (h *MockLoggerHook) Reset() {
h.mu.Lock()
defer h.mu.Unlock()
h.Messages = nil
}
+231
View File
@@ -0,0 +1,231 @@
package log
import (
"context"
"io"
"log/slog"
"slices"
"sync"
)
// recorderStore is the shared backing storage for a Recorder and any
// WithAttrs-derived recorders, so the original handle sees all records.
type recorderStore struct {
mu sync.Mutex
records []slog.Record
}
// Recorder is a slog.Handler that records emitted records for test assertions.
// It replaces the old logrus MockLoggerHook / test.NewGlobal patterns.
//
// Enabled always returns true: the Recorder captures records at every level so
// tests can assert on debug/trace output regardless of the active level. Test
// level-gating itself through the real handlers (which honor levelVar), not the
// Recorder.
type Recorder struct {
store *recorderStore
base []slog.Attr // attrs pre-attached via WithAttrs (already group-nested)
groups []string // currently-open groups (from WithGroup)
}
// NewRecorder returns a logger writing into a fresh Recorder (captures all levels).
func NewRecorder() (*slog.Logger, *Recorder) {
rec := &Recorder{store: &recorderStore{}}
return slog.New(rec), rec
}
func (r *Recorder) Enabled(context.Context, slog.Level) bool { return true }
func (r *Recorder) Handle(_ context.Context, rec slog.Record) error {
stored := slog.NewRecord(rec.Time, rec.Level, rec.Message, rec.PC)
recAttrs := make([]slog.Attr, 0, rec.NumAttrs())
rec.Attrs(func(a slog.Attr) bool {
recAttrs = append(recAttrs, a)
return true
})
// base attrs (attached via WithAttrs) precede the record's own attrs,
// matching the ordering of the real text/JSON handlers. resolveAttrs
// resolves slog.LogValuer values (so captured question/answer fields are
// obfuscated exactly as production emits them), and mergeGroupAttrs folds
// attrs sharing a WithGroup group into a single group like the real handlers.
all := append(slices.Clone(r.base), nestGroups(r.groups, recAttrs)...)
stored.AddAttrs(mergeGroupAttrs(resolveAttrs(all))...)
r.store.mu.Lock()
defer r.store.mu.Unlock()
r.store.records = append(r.store.records, stored)
return nil
}
// resolveAttrs resolves any slog.LogValuer values (recursing into groups) so the
// Recorder stores the concrete values the real text/JSON handlers would emit,
// including privacy-obfuscated question/answer fields, rather than unresolved
// valuers.
func resolveAttrs(attrs []slog.Attr) []slog.Attr {
out := make([]slog.Attr, len(attrs))
for i, a := range attrs {
v := a.Value.Resolve()
if v.Kind() == slog.KindGroup {
v = slog.GroupValue(resolveAttrs(v.Group())...)
}
out[i] = slog.Attr{Key: a.Key, Value: v}
}
return out
}
// mergeGroupAttrs merges attrs that represent the same WithGroup group (same key
// holding a group value) into one group, recursively — matching slog, which
// emits a single nested group rather than one per WithAttrs call. Plain
// (non-group) attrs are left untouched, including same-key duplicates, which
// slog itself does not deduplicate.
func mergeGroupAttrs(attrs []slog.Attr) []slog.Attr {
out := make([]slog.Attr, 0, len(attrs))
groupPos := make(map[string]int)
for _, a := range attrs {
if a.Value.Kind() != slog.KindGroup {
out = append(out, a)
continue
}
if pos, ok := groupPos[a.Key]; ok {
combined := append(slices.Clone(out[pos].Value.Group()), a.Value.Group()...)
out[pos] = slog.Attr{Key: a.Key, Value: slog.GroupValue(mergeGroupAttrs(combined)...)}
continue
}
groupPos[a.Key] = len(out)
out = append(out, slog.Attr{Key: a.Key, Value: slog.GroupValue(mergeGroupAttrs(a.Value.Group())...)})
}
return out
}
func (r *Recorder) WithAttrs(attrs []slog.Attr) slog.Handler {
// attrs added now sit at the current group depth, like the real handlers.
grouped := nestGroups(r.groups, attrs)
merged := make([]slog.Attr, 0, len(r.base)+len(grouped))
merged = append(merged, r.base...)
merged = append(merged, grouped...)
return &Recorder{store: r.store, base: merged, groups: r.groups}
}
func (r *Recorder) WithGroup(name string) slog.Handler {
if name == "" {
return r
}
return &Recorder{store: r.store, base: r.base, groups: append(slices.Clone(r.groups), name)}
}
// nestGroups wraps attrs in the given group chain (outermost first), so
// groups=["a","b"] turns attr into a.b.attr, matching slog grouping semantics.
func nestGroups(groups []string, attrs []slog.Attr) []slog.Attr {
for _, g := range slices.Backward(groups) {
attrs = []slog.Attr{{Key: g, Value: slog.GroupValue(attrs...)}}
}
return attrs
}
// Records returns a copy of the recorded records.
func (r *Recorder) Records() []slog.Record {
r.store.mu.Lock()
defer r.store.mu.Unlock()
return append([]slog.Record(nil), r.store.records...)
}
// Messages returns the recorded messages in order.
func (r *Recorder) Messages() []string {
r.store.mu.Lock()
defer r.store.mu.Unlock()
msgs := make([]string, len(r.store.records))
for i, rec := range r.store.records {
msgs[i] = rec.Message
}
return msgs
}
// LastMessage returns the most recent message, or "" if none.
func (r *Recorder) LastMessage() string {
r.store.mu.Lock()
defer r.store.mu.Unlock()
if len(r.store.records) == 0 {
return ""
}
return r.store.records[len(r.store.records)-1].Message
}
// Attr looks up an attr by key on the most recent record.
func (r *Recorder) Attr(key string) (slog.Value, bool) {
r.store.mu.Lock()
defer r.store.mu.Unlock()
if len(r.store.records) == 0 {
return slog.Value{}, false
}
var found slog.Value
var ok bool
r.store.records[len(r.store.records)-1].Attrs(func(a slog.Attr) bool {
if a.Key == key {
found, ok = a.Value, true
return false
}
return true
})
return found, ok
}
// Reset clears recorded records.
func (r *Recorder) Reset() {
r.store.mu.Lock()
defer r.store.mu.Unlock()
r.store.records = nil
}
// CaptureGlobal swaps the global logger for a Recorder (wrapped in a
// contextHandler so context-stored attrs are captured) and returns a restore
// func (call via DeferCleanup). Ginkgo runs specs serially per process, so this
// is safe within a spec.
func CaptureGlobal() (*Recorder, func()) {
prev := slog.Default()
rec := &Recorder{store: &recorderStore{}}
setLogger(slog.New(&contextHandler{next: rec}))
return rec, func() {
setLogger(prev)
}
}
// ConfigureForTest routes the global logger to w (typically GinkgoWriter):
// quiet on passing specs, full diagnostics on failure. No color, debug level.
func ConfigureForTest(w io.Writer) {
levelVar.Set(slog.LevelDebug)
setLogger(slog.New(&contextHandler{next: slog.NewTextHandler(w, &slog.HandlerOptions{
Level: levelVar,
ReplaceAttr: replaceAttr(DefaultConfig()),
})}))
}
+166
View File
@@ -0,0 +1,166 @@
package log
import (
"context"
"log/slog"
"testing"
)
func TestRecorderCapturesMessages(t *testing.T) {
logger, rec := NewRecorder()
logger.Info("first")
logger.Warn("second", slog.String("k", "v"))
if got := rec.Messages(); len(got) != 2 || got[0] != "first" || got[1] != "second" {
t.Fatalf("Messages() = %v", got)
}
if rec.LastMessage() != "second" {
t.Errorf("LastMessage() = %q", rec.LastMessage())
}
rec.Reset()
if len(rec.Messages()) != 0 {
t.Error("Reset did not clear messages")
}
}
func TestRecorderWithAttrsVisible(t *testing.T) {
logger, rec := NewRecorder()
logger.With(slog.String("prefix", "blk")).Info("m")
if got := rec.LastMessage(); got != "m" {
t.Fatalf("LastMessage() = %q, want %q", got, "m")
}
val, ok := rec.Attr("prefix")
if !ok {
t.Fatal("Attr(\"prefix\") not found")
}
if got := val.String(); got != "blk" {
t.Errorf("Attr(\"prefix\") = %q, want %q", got, "blk")
}
}
func TestRecorderWithGroupNests(t *testing.T) {
logger, rec := NewRecorder()
logger.WithGroup("dns").Info("m", slog.String("rcode", "NXDOMAIN"))
// The grouped attr must be nested, mirroring the real handlers, so the
// top-level "rcode" key is absent and "dns" holds a group.
if _, ok := rec.Attr("rcode"); ok {
t.Error("expected rcode to be nested under the group, not top-level")
}
val, ok := rec.Attr("dns")
if !ok {
t.Fatal("Attr(\"dns\") group not found")
}
if val.Kind() != slog.KindGroup {
t.Fatalf("expected dns to be a group, got %v", val.Kind())
}
}
func TestRecorderWithGroupMergesAttrs(t *testing.T) {
logger, rec := NewRecorder()
// A WithAttrs attr and a per-call attr under the same group must land in a
// SINGLE merged group, like the real text/JSON handlers (not two "g" attrs).
logger.WithGroup("g").With(slog.Int("a", 1)).Info("m", slog.Int("b", 2))
val, ok := rec.Attr("g")
if !ok {
t.Fatal("Attr(\"g\") group not found")
}
if val.Kind() != slog.KindGroup {
t.Fatalf("expected g to be a group, got %v", val.Kind())
}
got := map[string]int64{}
for _, a := range val.Group() {
got[a.Key] = a.Value.Int64()
}
if len(got) != 2 || got["a"] != 1 || got["b"] != 2 {
t.Errorf("group g = %v, want a=1 b=2 in one merged group", got)
}
}
func TestRecorderResolvesLogValuer(t *testing.T) {
logger, rec := NewRecorder()
logger.Info("m", slog.Any("q", logValuerFunc(func() slog.Value {
return slog.StringValue("resolved")
})))
val, ok := rec.Attr("q")
if !ok {
t.Fatal("Attr(\"q\") not found")
}
if val.Kind() != slog.KindString || val.String() != "resolved" {
t.Errorf("q = %v (kind %v), want resolved string", val.String(), val.Kind())
}
}
func TestRecorderBaseAttrsPrecedeRecordAttrs(t *testing.T) {
logger, rec := NewRecorder()
// WithAttrs ("base") must come before the per-call attr, like real handlers.
logger.With(slog.String("k", "base")).Info("m", slog.String("k", "call"))
rec.store.mu.Lock()
defer rec.store.mu.Unlock()
var order []string
rec.store.records[0].Attrs(func(a slog.Attr) bool {
if a.Key == "k" {
order = append(order, a.Value.String())
}
return true
})
if len(order) != 2 || order[0] != "base" || order[1] != "call" {
t.Errorf("attr order = %v, want [base call]", order)
}
}
func TestCaptureGlobalRestores(t *testing.T) {
before := Log()
rec, restore := CaptureGlobal()
Log().InfoContext(context.Background(), "captured")
if rec.LastMessage() != "captured" {
t.Errorf("expected captured message, got %q", rec.LastMessage())
}
restore()
if Log() != before {
t.Error("CaptureGlobal restore did not reinstate the previous logger")
}
}
func TestCaptureGlobalContextAttrs(t *testing.T) {
rec, restore := CaptureGlobal()
defer restore()
ctx := context.Background()
ctx, _ = CtxWithFields(ctx, slog.String("req_id", "r1"))
Log().InfoContext(ctx, "with-ctx")
val, ok := rec.Attr("req_id")
if !ok {
t.Fatal("Attr(\"req_id\") not found")
}
if got := val.String(); got != "r1" {
t.Errorf("Attr(\"req_id\") = %q, want %q", got, "r1")
}
}
+3 -2
View File
@@ -6,7 +6,6 @@ import (
"github.com/0xERR0R/blocky/evt"
"github.com/0xERR0R/blocky/lists"
"github.com/0xERR0R/blocky/util"
"github.com/prometheus/client_golang/prometheus"
)
@@ -192,5 +191,7 @@ func prefetchDomainCacheCount() prometheus.Gauge {
}
func subscribe(topic string, fn any) {
util.FatalOnError(fmt.Sprintf("can't subscribe topic '%s'", topic), evt.Bus().Subscribe(topic, fn))
if err := evt.Bus().Subscribe(topic, fn); err != nil {
panic(fmt.Sprintf("can't subscribe topic '%s': %v", topic, err))
}
}
+2 -2
View File
@@ -2,6 +2,7 @@ package metrics_test
import (
"context"
"log/slog"
"net"
"slices"
"strings"
@@ -19,7 +20,6 @@ import (
"github.com/go-chi/chi/v5"
"github.com/miekg/dns"
"github.com/prometheus/client_golang/prometheus"
"github.com/sirupsen/logrus"
)
func init() {
@@ -104,7 +104,7 @@ func (m *MockResolver) IsEnabled() bool {
return true
}
func (m *MockResolver) LogConfig(*logrus.Entry) {
func (m *MockResolver) LogConfig(*slog.Logger) {
// no-op for testing
}
+13 -3
View File
@@ -3,6 +3,7 @@ package querylog
import (
"context"
"fmt"
"log/slog"
"reflect"
"strconv"
"strings"
@@ -23,6 +24,15 @@ import (
"gorm.io/gorm"
)
// slogPrintf wraps a *slog.Logger to satisfy gorm's logger.Writer interface.
type slogPrintf struct {
l *slog.Logger
}
func (s slogPrintf) Printf(msg string, args ...any) {
s.l.Info(fmt.Sprintf(msg, args...))
}
type logEntry struct {
RequestTS time.Time `gorm:"not null;index"`
ClientIP string
@@ -71,7 +81,7 @@ func newDatabaseWriter(ctx context.Context, target gorm.Dialector, logRetentionD
) (*DatabaseWriter, error) {
db, err := gorm.Open(target, &gorm.Config{
Logger: logger.New(
log.Log(),
slogPrintf{log.PrefixedLog("database_writer")},
logger.Config{
SlowThreshold: time.Minute,
LogLevel: logger.Warn,
@@ -215,7 +225,7 @@ func (d *DatabaseWriter) Write(entry *LogEntry) {
func (d *DatabaseWriter) CleanUp() {
deletionDate := time.Now().AddDate(0, 0, int(-d.logRetentionDays)) //nolint:gosec // G115: correct via two's complement
log.PrefixedLog("database_writer").Debugf("deleting log entries with request_ts < %s", deletionDate)
log.PrefixedLog("database_writer").Debug(fmt.Sprintf("deleting log entries with request_ts < %s", deletionDate))
d.db.Where("request_ts < ?", deletionDate).Delete(&logEntry{})
}
@@ -226,7 +236,7 @@ func (d *DatabaseWriter) doDBWrite() error {
var err *multierror.Error
if len(d.pendingEntries) > 0 {
log.Log().Tracef("%d entries to write", len(d.pendingEntries))
log.Log().Debug("entries to write", slog.Int("count", len(d.pendingEntries)))
const bulkSize = 100
+10 -11
View File
@@ -4,6 +4,7 @@ import (
"encoding/csv"
"fmt"
"io"
"log/slog"
"os"
"path/filepath"
"regexp"
@@ -13,7 +14,6 @@ import (
"github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/util"
"github.com/sirupsen/logrus"
)
const (
@@ -57,7 +57,7 @@ func (d *FileWriter) Write(entry *LogEntry) {
file, err := os.OpenFile(writePath, os.O_APPEND|os.O_CREATE|os.O_RDWR, filePermission)
util.LogOnErrorWithEntry(log.PrefixedLog(loggerPrefixFileWriter).WithField("file_name", writePath),
util.LogOnErrorWithEntry(log.PrefixedLog(loggerPrefixFileWriter).With("file_name", writePath),
"can't create/open file", err)
if err == nil {
@@ -65,7 +65,7 @@ func (d *FileWriter) Write(entry *LogEntry) {
writer := createCsvWriter(file)
err := writer.Write(createQueryLogRow(entry))
util.LogOnErrorWithEntry(log.PrefixedLog(loggerPrefixFileWriter).WithField("file_name", writePath),
util.LogOnErrorWithEntry(log.PrefixedLog(loggerPrefixFileWriter).With("file_name", writePath),
"can't write to file", err)
writer.Flush()
}
@@ -77,11 +77,11 @@ func (d *FileWriter) CleanUp() {
logger := log.PrefixedLog(loggerPrefixFileWriter)
logger.Trace("starting clean up")
logger.Debug("starting clean up")
files, err := os.ReadDir(d.target)
util.LogOnErrorWithEntry(logger.WithField("target", d.target), "can't list log directory: ", err)
util.LogOnErrorWithEntry(logger.With("target", d.target), "can't list log directory: ", err)
// search for log files, which names starts with date
for _, f := range files {
@@ -90,14 +90,13 @@ func (d *FileWriter) CleanUp() {
if err == nil {
differenceDays := uint64(time.Since(t).Hours() / hoursPerDay)
if d.logRetentionDays > 0 && differenceDays > d.logRetentionDays {
logger.WithFields(logrus.Fields{
"file": f.Name(),
"ageInDays": differenceDays,
"logRetentionDays": d.logRetentionDays,
}).Info("existing log file is older than retention time and will be deleted")
logger.Info("existing log file is older than retention time and will be deleted",
slog.String("file", f.Name()),
slog.Uint64("ageInDays", differenceDays),
slog.Uint64("logRetentionDays", d.logRetentionDays))
err := os.Remove(filepath.Join(d.target, f.Name()))
util.LogOnErrorWithEntry(logger.WithField("file", f.Name()), "can't remove file: ", err)
util.LogOnErrorWithEntry(logger.With("file", f.Name()), "can't remove file: ", err)
}
}
}
+1 -2
View File
@@ -10,7 +10,6 @@ import (
"time"
"github.com/0xERR0R/blocky/helpertest"
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
@@ -143,7 +142,7 @@ func readCsv(file string) [][]string {
if errors.Is(err, io.EOF) {
break
} else if err != nil {
log.Log().Fatal("can't read line", err)
Expect(err).Should(Succeed(), "can't read line")
}
result = append(result, line)
+47 -24
View File
@@ -1,17 +1,17 @@
package querylog
import (
"reflect"
"context"
"log/slog"
"strings"
"github.com/0xERR0R/blocky/log"
"github.com/sirupsen/logrus"
)
const loggerPrefixLoggerWriter = "queryLog"
type LoggerWriter struct {
logger *logrus.Entry
logger *slog.Logger
}
func NewLoggerWriter() *LoggerWriter {
@@ -19,36 +19,59 @@ func NewLoggerWriter() *LoggerWriter {
}
func (d *LoggerWriter) Write(entry *LogEntry) {
fields := LogEntryFields(entry)
d.logger.WithFields(fields).Infof("query resolved")
d.logger.LogAttrs(context.Background(), slog.LevelInfo, "query resolved", LogEntryFields(entry)...)
}
func (d *LoggerWriter) CleanUp() {
// Nothing to do
}
func LogEntryFields(entry *LogEntry) logrus.Fields {
return withoutZeroes(logrus.Fields{
"client_ip": entry.ClientIP,
"client_names": strings.Join(entry.ClientNames, "; "),
"response_reason": entry.ResponseReason,
"response_type": entry.ResponseType,
"response_code": entry.ResponseCode,
"question_name": entry.QuestionName,
"question_type": entry.QuestionType,
"answer": entry.Answer,
"duration_ms": entry.DurationMs,
"instance": entry.BlockyInstance,
})
// LogEntryFields returns the entry as flat, snake_case slog attrs, omitting
// zero-valued fields (matching the historical logrus WithFields output).
func LogEntryFields(entry *LogEntry) []slog.Attr {
return withoutZeroes(
slog.String("client_ip", entry.ClientIP),
slog.String("client_names", strings.Join(entry.ClientNames, "; ")),
slog.String("response_reason", entry.ResponseReason),
slog.String("response_type", entry.ResponseType),
slog.String("response_code", entry.ResponseCode),
slog.String("question_name", entry.QuestionName),
slog.String("question_type", entry.QuestionType),
slog.String("answer", entry.Answer),
slog.Int64("duration_ms", entry.DurationMs),
slog.String("instance", entry.BlockyInstance),
)
}
func withoutZeroes(fields logrus.Fields) logrus.Fields {
for k, v := range fields {
if reflect.ValueOf(v).IsZero() {
delete(fields, k)
func withoutZeroes(attrs ...slog.Attr) []slog.Attr {
result := attrs[:0]
for _, a := range attrs {
if !isZeroValue(a.Value) {
result = append(result, a)
}
}
return fields
return result
}
// isZeroValue reports whether v holds the zero value for its kind. It switches
// on slog.Kind rather than using reflection so the per-query query-log path
// stays allocation-free and never panics on a nil interface value.
func isZeroValue(v slog.Value) bool {
//nolint:exhaustive // the default branch intentionally treats every other kind as non-zero
switch v.Kind() {
case slog.KindString:
return v.String() == ""
case slog.KindInt64:
return v.Int64() == 0
case slog.KindUint64:
return v.Uint64() == 0
case slog.KindFloat64:
return v.Float64() == 0
case slog.KindBool:
return !v.Bool()
default:
return false
}
}
+55 -18
View File
@@ -1,31 +1,55 @@
package querylog
import (
"log/slog"
"time"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
"github.com/0xERR0R/blocky/log"
. "github.com/onsi/gomega"
. "github.com/onsi/ginkgo/v2"
)
// attrValue returns the value of the first attr with the given key.
func attrValue(attrs []slog.Attr, key string) (slog.Value, bool) {
for _, a := range attrs {
if a.Key == key {
return a.Value, true
}
}
return slog.Value{}, false
}
var _ = Describe("LoggerWriter", func() {
Describe("logger query log", func() {
When("New log entry was created", func() {
It("should be logged", func() {
writer := NewLoggerWriter()
logger, hook := test.NewNullLogger()
writer.logger = logger.WithField("k", "v")
logger, rec := log.NewRecorder()
writer.logger = logger
writer.Write(&LogEntry{
Start: time.Now(),
ClientIP: "192.168.1.5",
DurationMs: 20,
})
Expect(hook.Entries).Should(HaveLen(1))
Expect(hook.LastEntry().Message).Should(Equal("query resolved"))
Expect(rec.Records()).Should(HaveLen(1))
Expect(rec.LastMessage()).Should(Equal("query resolved"))
// Fields must be flat and snake_case, not nested under "entry".
_, hasEntry := rec.Attr("entry")
Expect(hasEntry).Should(BeFalse())
clientIP, ok := rec.Attr("client_ip")
Expect(ok).Should(BeTrue())
Expect(clientIP.String()).Should(Equal("192.168.1.5"))
durationMs, ok := rec.Attr("duration_ms")
Expect(ok).Should(BeTrue())
Expect(durationMs.Int64()).Should(Equal(int64(20)))
})
})
When("Cleanup is called", func() {
@@ -47,19 +71,32 @@ var _ = Describe("LoggerWriter", func() {
fields := LogEntryFields(&entry)
Expect(fields).Should(HaveKeyWithValue("client_ip", entry.ClientIP))
Expect(fields).Should(HaveKeyWithValue("duration_ms", entry.DurationMs))
Expect(fields).Should(HaveKeyWithValue("question_type", entry.QuestionType))
Expect(fields).Should(HaveKeyWithValue("response_code", entry.ResponseCode))
clientIP, ok := attrValue(fields, "client_ip")
Expect(ok).Should(BeTrue())
Expect(clientIP.String()).Should(Equal(entry.ClientIP))
Expect(fields).ShouldNot(HaveKey("client_names"))
Expect(fields).ShouldNot(HaveKey("question_name"))
durationMs, ok := attrValue(fields, "duration_ms")
Expect(ok).Should(BeTrue())
Expect(durationMs.Int64()).Should(Equal(entry.DurationMs))
questionType, ok := attrValue(fields, "question_type")
Expect(ok).Should(BeTrue())
Expect(questionType.String()).Should(Equal(entry.QuestionType))
_, ok = attrValue(fields, "response_code")
Expect(ok).Should(BeTrue())
// zero-valued fields are omitted
_, ok = attrValue(fields, "client_names")
Expect(ok).Should(BeFalse())
_, ok = attrValue(fields, "question_name")
Expect(ok).Should(BeFalse())
})
})
DescribeTable("withoutZeroes",
func(value any, isZero bool) {
fields := withoutZeroes(logrus.Fields{"a": value})
func(attr slog.Attr, isZero bool) {
fields := withoutZeroes(attr)
if isZero {
Expect(fields).Should(BeEmpty())
@@ -68,16 +105,16 @@ var _ = Describe("LoggerWriter", func() {
}
},
Entry("empty string",
"",
slog.String("a", ""),
true),
Entry("non-empty string",
"something",
slog.String("a", "something"),
false),
Entry("zero int",
0,
slog.Int("a", 0),
true),
Entry("non-zero int",
1,
slog.Int("a", 1),
false),
)
})

Some files were not shown because too many files have changed in this diff Show More