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) } )