From 898002a38e44e2d5f6f2f46adcc4b4f6b6e16614 Mon Sep 17 00:00:00 2001 From: yusing Date: Sun, 15 Feb 2026 17:20:54 +0800 Subject: [PATCH] feat(acl): add reason field to ACL logging for decision tracking Add a reason parameter throughout the ACL system to track and log why each IP was allowed or denied. This provides better visibility into ACL decisions by recording specific reasons such as "allowed by allow_local rule", "blocked by deny rule: [rule]", or "deny by default". Changes include: - Add reason field to checkCache and ipLog structs - Update LogACL interface and implementations to accept reason - Generate descriptive reasons for all ACL decision paths - Include reason in console log output --- internal/acl/config.go | 42 +++++++++++-------- internal/logging/accesslog/console_logger.go | 4 +- .../logging/accesslog/file_access_logger.go | 2 +- internal/logging/accesslog/formatter.go | 6 ++- .../logging/accesslog/multi_access_logger.go | 4 +- .../accesslog/multi_access_logger_test.go | 4 +- internal/logging/accesslog/types.go | 6 +-- 7 files changed, 40 insertions(+), 28 deletions(-) diff --git a/internal/acl/config.go b/internal/acl/config.go index b25ab083..100edb63 100644 --- a/internal/acl/config.go +++ b/internal/acl/config.go @@ -67,13 +67,14 @@ type config struct { type checkCache struct { *maxmind.IPInfo allow bool + reason string created time.Time } type ipLog struct { - info *maxmind.IPInfo - allowed bool - blockedRule string + info *maxmind.IPInfo + allowed bool + reason string } const cacheTTL = 1 * time.Minute @@ -170,13 +171,14 @@ func (c *Config) Start(parent task.Parent) error { return nil } -func (c *Config) cacheRecord(info *maxmind.IPInfo, allow bool) { +func (c *Config) cacheRecord(info *maxmind.IPInfo, allow bool, reason string) { if common.ForceResolveCountry && info.City == nil { maxmind.LookupCity(info) } c.ipCache.Store(info.Str, &checkCache{ IPInfo: info, allow: allow, + reason: reason, created: time.Now(), }) } @@ -216,7 +218,7 @@ func (c *Config) logNotifyLoop(parent task.Parent) { case req := <-c.logNotifyCh: if c.logger != nil { if !req.allowed || c.logAllowed { - c.logger.LogACL(req.info, !req.allowed) + c.logger.LogACL(req.info, !req.allowed, req.reason) } } if c.needNotify() { @@ -231,7 +233,7 @@ func (c *Config) logNotifyLoop(parent task.Parent) { } } if !req.allowed { - aclevents.Blocked(req.info.Str, req.blockedRule) + aclevents.Blocked(req.info.Str, req.reason) } case <-c.notifyTicker.C: // will never tick when notify is disabled total := len(c.allowedCount) + len(c.blockedCount) @@ -264,9 +266,9 @@ func (c *Config) logNotifyLoop(parent task.Parent) { } // log and notify if needed -func (c *Config) logAndNotify(info *maxmind.IPInfo, allowed bool, blockedRule string) { +func (c *Config) logAndNotify(info *maxmind.IPInfo, allowed bool, reason string) { if c.logNotifyCh != nil { - c.logNotifyCh <- ipLog{info: info, allowed: allowed, blockedRule: blockedRule} + c.logNotifyCh <- ipLog{info: info, allowed: allowed, reason: reason} } } @@ -281,30 +283,36 @@ func (c *Config) IPAllowed(ip net.IP) bool { } if c.allowLocal && ip.IsPrivate() { - c.logAndNotify(&maxmind.IPInfo{IP: ip, Str: ip.String()}, true, "") + c.logAndNotify(&maxmind.IPInfo{IP: ip, Str: ip.String()}, true, "allowed by allow_local rule") return true } ipStr := ip.String() record, ok := c.ipCache.Load(ipStr) if ok && !record.Expired() { - c.logAndNotify(record.IPInfo, record.allow, "") + c.logAndNotify(record.IPInfo, record.allow, record.reason) return record.allow } ipAndStr := &maxmind.IPInfo{IP: ip, Str: ipStr} if index := c.Deny.MatchedIndex(ipAndStr); index != -1 { - c.logAndNotify(ipAndStr, false, c.Deny[index].raw) - c.cacheRecord(ipAndStr, false) + reason := "blocked by deny rule: " + c.Deny[index].raw + c.logAndNotify(ipAndStr, false, reason) + c.cacheRecord(ipAndStr, false, reason) return false } - if c.Allow.Match(ipAndStr) { - c.logAndNotify(ipAndStr, true, "") - c.cacheRecord(ipAndStr, true) + if index := c.Allow.MatchedIndex(ipAndStr); index != -1 { + reason := "allowed by allow rule: " + c.Allow[index].raw + c.logAndNotify(ipAndStr, true, reason) + c.cacheRecord(ipAndStr, true, reason) return true } - c.logAndNotify(ipAndStr, c.defaultAllow, "deny by default") - c.cacheRecord(ipAndStr, c.defaultAllow) + reason := "deny by default" + if c.defaultAllow { + reason = "allow by default" + } + c.logAndNotify(ipAndStr, c.defaultAllow, reason) + c.cacheRecord(ipAndStr, c.defaultAllow, reason) return c.defaultAllow } diff --git a/internal/logging/accesslog/console_logger.go b/internal/logging/accesslog/console_logger.go index 70d61bc9..7651dceb 100644 --- a/internal/logging/accesslog/console_logger.go +++ b/internal/logging/accesslog/console_logger.go @@ -59,8 +59,8 @@ func (l *ConsoleLogger) LogError(req *http.Request, err error) { l.formatter.LogRequestZeroLog(&log, req, internalErrorResponse) } -func (l *ConsoleLogger) LogACL(info *maxmind.IPInfo, blocked bool) { - ConsoleACLFormatter{}.LogACLZeroLog(stdoutLogger, info, blocked) +func (l *ConsoleLogger) LogACL(info *maxmind.IPInfo, blocked bool, reason string) { + ConsoleACLFormatter{}.LogACLZeroLog(stdoutLogger, info, blocked, reason) } func (l *ConsoleLogger) Flush() { diff --git a/internal/logging/accesslog/file_access_logger.go b/internal/logging/accesslog/file_access_logger.go index 5f07e05b..17b45c9a 100644 --- a/internal/logging/accesslog/file_access_logger.go +++ b/internal/logging/accesslog/file_access_logger.go @@ -131,7 +131,7 @@ func (l *fileAccessLogger) LogError(req *http.Request, err error) { l.LogRequest(req, internalErrorResponse) } -func (l *fileAccessLogger) LogACL(info *maxmind.IPInfo, blocked bool) { +func (l *fileAccessLogger) LogACL(info *maxmind.IPInfo, blocked bool, reason string) { line := bytesPool.GetBuffer() defer bytesPool.PutBuffer(line) l.AppendACLLog(line, info, blocked) diff --git a/internal/logging/accesslog/formatter.go b/internal/logging/accesslog/formatter.go index 8be1fdcc..68fbf42a 100644 --- a/internal/logging/accesslog/formatter.go +++ b/internal/logging/accesslog/formatter.go @@ -171,7 +171,7 @@ func (f ACLLogFormatter) LogACLZeroLog(logger *zerolog.Logger, info *maxmind.IPI event.Send() } -func (f ConsoleACLFormatter) LogACLZeroLog(logger *zerolog.Logger, info *maxmind.IPInfo, blocked bool) { +func (f ConsoleACLFormatter) LogACLZeroLog(logger *zerolog.Logger, info *maxmind.IPInfo, blocked bool, reason string) { event := logger.Info() if info.City != nil { if isoCode := info.City.Country.IsoCode; isoCode != "" { @@ -186,6 +186,10 @@ func (f ConsoleACLFormatter) LogACLZeroLog(logger *zerolog.Logger, info *maxmind action = "denied" } + if reason != "" { + event.Str("reason", reason) + } + // NOTE: zerolog will append a newline to the buffer event.Msgf("request %s from %s", action, info.Str) } diff --git a/internal/logging/accesslog/multi_access_logger.go b/internal/logging/accesslog/multi_access_logger.go index bb694178..d34c887d 100644 --- a/internal/logging/accesslog/multi_access_logger.go +++ b/internal/logging/accesslog/multi_access_logger.go @@ -50,9 +50,9 @@ func (m *MultiAccessLogger) LogError(req *http.Request, err error) { } } -func (m *MultiAccessLogger) LogACL(info *maxmind.IPInfo, blocked bool) { +func (m *MultiAccessLogger) LogACL(info *maxmind.IPInfo, blocked bool, reason string) { for _, accessLogger := range m.accessLoggers { - accessLogger.LogACL(info, blocked) + accessLogger.LogACL(info, blocked, reason) } } diff --git a/internal/logging/accesslog/multi_access_logger_test.go b/internal/logging/accesslog/multi_access_logger_test.go index ce54c93c..2fbcf6df 100644 --- a/internal/logging/accesslog/multi_access_logger_test.go +++ b/internal/logging/accesslog/multi_access_logger_test.go @@ -116,7 +116,7 @@ func TestMultiAccessLoggerLogACL(t *testing.T) { Str: "192.168.1.1", } - logger.LogACL(info, false) + logger.LogACL(info, false, "test reason") logger.Flush() expect.Equal(t, writer1.NumLines(), 1) @@ -252,7 +252,7 @@ func TestMultiAccessLoggerMixedOperations(t *testing.T) { cfg2 := DefaultACLLoggerConfig() cfg2.LogAllowed = true aclLogger := NewMultiAccessLogger(testTask, cfg2, writers) - aclLogger.LogACL(info, false) + aclLogger.LogACL(info, false, "test reason") logger.Flush() diff --git a/internal/logging/accesslog/types.go b/internal/logging/accesslog/types.go index 8017ef67..7d293c17 100644 --- a/internal/logging/accesslog/types.go +++ b/internal/logging/accesslog/types.go @@ -13,7 +13,7 @@ type ( AccessLogger interface { LogRequest(req *http.Request, res *http.Response) LogError(req *http.Request, err error) - LogACL(info *maxmind.IPInfo, blocked bool) + LogACL(info *maxmind.IPInfo, blocked bool, reason string) Config() *Config @@ -35,9 +35,9 @@ type ( } ACLFormatter interface { // AppendACLLog appends a log line to line with or without a trailing newline - AppendACLLog(line *bytes.Buffer, info *maxmind.IPInfo, blocked bool) + AppendACLLog(line *bytes.Buffer, info *maxmind.IPInfo, blocked bool, reason string) // LogACLZeroLog logs an ACL log to the logger - LogACLZeroLog(logger *zerolog.Logger, info *maxmind.IPInfo, blocked bool) + LogACLZeroLog(logger *zerolog.Logger, info *maxmind.IPInfo, blocked bool, reason string) } )