refactor: address simplify review findings for access log feature
- Replace local loopbackNets/isLoopback with existing localhostNets/IsTrustedProxy from cidr.go - Extract HealthCheckUserAgentPrefix constant to domain/labels.go; use in both accesslog middleware and httpprober - Fix double time.Now(): capture end once, derive both duration and Entry.Time from it - Store journald vars map once in struct instead of allocating per-request - Remove redundant MaxSize fallback default in fileSink (config defaults own this) - Add richer context to access-log write-failure warning (request_id, method, path, status, client_ip)
- commit
- be4bda72daf82ba0e5fef7ba0845f8fb50aa414c
- author
- brice · · 2026-04-03 15:42 UTC
- parent
- 9e9308c
- signature
- GPG Verified
CD88F9E564E0102646FB6077A1A07C7C7C3E349D· arch-gpg Verified for the committer email
5 files · +35 -32
M internal/adapters/in/http/middleware/accesslog.go +19 -18
| @@ -9,20 +9,9 @@ import ( | |||
| 9 | 9 | "github.com/bnema/zerowrap" | |
| 10 | 10 | ||
| 11 | 11 | "github.com/bnema/gordon/internal/adapters/out/accesslog" | |
| 12 | + | "github.com/bnema/gordon/internal/domain" | |
| 12 | 13 | ) | |
| 13 | 14 | ||
| 14 | - | // loopbackNets contains the loopback ranges used for health-check exclusion. | |
| 15 | - | var loopbackNets = func() []*net.IPNet { | |
| 16 | - | _, ipv4Loopback, _ := net.ParseCIDR("127.0.0.0/8") | |
| 17 | - | _, ipv6Loopback, _ := net.ParseCIDR("::1/128") | |
| 18 | - | return []*net.IPNet{ipv4Loopback, ipv6Loopback} | |
| 19 | - | }() | |
| 20 | - | ||
| 21 | - | // isLoopback reports whether ip is a loopback address. | |
| 22 | - | func isLoopback(ip string) bool { | |
| 23 | - | return IsTrustedProxy(ip, loopbackNets) | |
| 24 | - | } | |
| 25 | - | ||
| 26 | 15 | // AccessLogWriter is the interface the middleware needs from the output adapter. | |
| 27 | 16 | // *accesslog.Writer satisfies this interface. | |
| 28 | 17 | type AccessLogWriter interface { | |
| @@ -33,7 +22,7 @@ type AccessLogWriter interface { | |||
| 33 | 22 | // to the provided writer. It runs alongside (not instead of) RequestLogger. | |
| 34 | 23 | // | |
| 35 | 24 | // When excludeHealthChecks is true, requests from the Gordon health prober | |
| 36 | - | // (UA prefix "Gordon-HealthCheck/") or from loopback IPs are not logged. | |
| 25 | + | // (UA prefix domain.HealthCheckUserAgentPrefix) or from loopback IPs are not logged. | |
| 37 | 26 | // | |
| 38 | 27 | // Write failures are reported as warnings through the application logger and | |
| 39 | 28 | // never fail the HTTP response. | |
| @@ -60,18 +49,25 @@ func AccessLogger(writer AccessLogWriter, excludeHealthChecks bool, log zerowrap | |||
| 60 | 49 | ||
| 61 | 50 | next.ServeHTTP(rw, r) | |
| 62 | 51 | ||
| 63 | - | // Apply health-check exclusion after the response so we always allow | |
| 64 | - | // the request to complete, we just don't log it. | |
| 52 | + | // Apply health-check exclusion after the response so the request | |
| 53 | + | // always completes — we just skip writing the log entry. | |
| 54 | + | // UA check uses the shared domain constant so the prober and this | |
| 55 | + | // filter can never drift. Loopback check reuses localhostNets from | |
| 56 | + | // cidr.go (same package) — no separate loopback definition needed. | |
| 65 | 57 | if excludeHealthChecks { | |
| 66 | - | if strings.HasPrefix(r.UserAgent(), "Gordon-HealthCheck/") || isLoopback(clientIP) { | |
| 58 | + | if strings.HasPrefix(r.UserAgent(), domain.HealthCheckUserAgentPrefix) || | |
| 59 | + | IsTrustedProxy(clientIP, localhostNets) { | |
| 67 | 60 | return | |
| 68 | 61 | } | |
| 69 | 62 | } | |
| 70 | 63 | ||
| 71 | - | durationMS := float64(time.Since(start).Microseconds()) / 1000.0 | |
| 64 | + | // Capture end time once; use it for both duration and entry timestamp | |
| 65 | + | // so the two values are derived from the same instant. | |
| 66 | + | end := time.Now() | |
| 67 | + | durationMS := float64(end.Sub(start).Microseconds()) / 1000.0 | |
| 72 | 68 | ||
| 73 | 69 | entry := accesslog.Entry{ | |
| 74 | - | Time: time.Now().UTC(), | |
| 70 | + | Time: end.UTC(), | |
| 75 | 71 | ClientIP: clientIP, | |
| 76 | 72 | Method: r.Method, | |
| 77 | 73 | Host: r.Host, | |
| @@ -90,6 +86,11 @@ func AccessLogger(writer AccessLogWriter, excludeHealthChecks bool, log zerowrap | |||
| 90 | 86 | log.Warn(). | |
| 91 | 87 | Str(zerowrap.FieldLayer, "adapter"). | |
| 92 | 88 | Str(zerowrap.FieldAdapter, "http"). | |
| 89 | + | Str(zerowrap.FieldRequestID, requestID). | |
| 90 | + | Str(zerowrap.FieldMethod, r.Method). | |
| 91 | + | Str(zerowrap.FieldPath, r.URL.Path). | |
| 92 | + | Int(zerowrap.FieldStatus, rw.StatusCode()). | |
| 93 | + | Str(zerowrap.FieldClientIP, clientIP). | |
| 93 | 94 | Err(err). | |
| 94 | 95 | Msg("access log write failed") | |
| 95 | 96 | } | |
| @@ -9,20 +9,9 @@ import ( | |||||
| 9 | "github.com/bnema/zerowrap" | 9 | "github.com/bnema/zerowrap" | ||
| 10 | 10 | ||||
| 11 | "github.com/bnema/gordon/internal/adapters/out/accesslog" | 11 | "github.com/bnema/gordon/internal/adapters/out/accesslog" | ||
| 12 | + | "github.com/bnema/gordon/internal/domain" | |||
| 12 | ) | 13 | ) | ||
| 13 | 14 | ||||
| 14 | - | // loopbackNets contains the loopback ranges used for health-check exclusion. | |||
| 15 | - | var loopbackNets = func() []*net.IPNet { | |||
| 16 | - | _, ipv4Loopback, _ := net.ParseCIDR("127.0.0.0/8") | |||
| 17 | - | _, ipv6Loopback, _ := net.ParseCIDR("::1/128") | |||
| 18 | - | return []*net.IPNet{ipv4Loopback, ipv6Loopback} | |||
| 19 | - | }() | |||
| 20 | - | ||||
| 21 | - | // isLoopback reports whether ip is a loopback address. | |||
| 22 | - | func isLoopback(ip string) bool { | |||
| 23 | - | return IsTrustedProxy(ip, loopbackNets) | |||
| 24 | - | } | |||
| 25 | - | ||||
| 26 | // AccessLogWriter is the interface the middleware needs from the output adapter. | 15 | // AccessLogWriter is the interface the middleware needs from the output adapter. | ||
| 27 | // *accesslog.Writer satisfies this interface. | 16 | // *accesslog.Writer satisfies this interface. | ||
| 28 | type AccessLogWriter interface { | 17 | type AccessLogWriter interface { | ||
| @@ -33,7 +22,7 @@ type AccessLogWriter interface { | |||||
| 33 | // to the provided writer. It runs alongside (not instead of) RequestLogger. | 22 | // to the provided writer. It runs alongside (not instead of) RequestLogger. | ||
| 34 | // | 23 | // | ||
| 35 | // When excludeHealthChecks is true, requests from the Gordon health prober | 24 | // When excludeHealthChecks is true, requests from the Gordon health prober | ||
| 36 | - | // (UA prefix "Gordon-HealthCheck/") or from loopback IPs are not logged. | 25 | + | // (UA prefix domain.HealthCheckUserAgentPrefix) or from loopback IPs are not logged. |
| 37 | // | 26 | // | ||
| 38 | // Write failures are reported as warnings through the application logger and | 27 | // Write failures are reported as warnings through the application logger and | ||
| 39 | // never fail the HTTP response. | 28 | // never fail the HTTP response. | ||
| @@ -60,18 +49,25 @@ func AccessLogger(writer AccessLogWriter, excludeHealthChecks bool, log zerowrap | |||||
| 60 | 49 | ||||
| 61 | next.ServeHTTP(rw, r) | 50 | next.ServeHTTP(rw, r) | ||
| 62 | 51 | ||||
| 63 | - | // Apply health-check exclusion after the response so we always allow | 52 | + | // Apply health-check exclusion after the response so the request |
| 64 | - | // the request to complete, we just don't log it. | 53 | + | // always completes — we just skip writing the log entry. |
| 54 | + | // UA check uses the shared domain constant so the prober and this | |||
| 55 | + | // filter can never drift. Loopback check reuses localhostNets from | |||
| 56 | + | // cidr.go (same package) — no separate loopback definition needed. | |||
| 65 | if excludeHealthChecks { | 57 | if excludeHealthChecks { | ||
| 66 | - | if strings.HasPrefix(r.UserAgent(), "Gordon-HealthCheck/") || isLoopback(clientIP) { | 58 | + | if strings.HasPrefix(r.UserAgent(), domain.HealthCheckUserAgentPrefix) || |
| 59 | + | IsTrustedProxy(clientIP, localhostNets) { | |||
| 67 | return | 60 | return | ||
| 68 | } | 61 | } | ||
| 69 | } | 62 | } | ||
| 70 | 63 | ||||
| 71 | - | durationMS := float64(time.Since(start).Microseconds()) / 1000.0 | 64 | + | // Capture end time once; use it for both duration and entry timestamp |
| 65 | + | // so the two values are derived from the same instant. | |||
| 66 | + | end := time.Now() | |||
| 67 | + | durationMS := float64(end.Sub(start).Microseconds()) / 1000.0 | |||
| 72 | 68 | ||||
| 73 | entry := accesslog.Entry{ | 69 | entry := accesslog.Entry{ | ||
| 74 | - | Time: time.Now().UTC(), | 70 | + | Time: end.UTC(), |
| 75 | ClientIP: clientIP, | 71 | ClientIP: clientIP, | ||
| 76 | Method: r.Method, | 72 | Method: r.Method, | ||
| 77 | Host: r.Host, | 73 | Host: r.Host, | ||
| @@ -90,6 +86,11 @@ func AccessLogger(writer AccessLogWriter, excludeHealthChecks bool, log zerowrap | |||||
| 90 | log.Warn(). | 86 | log.Warn(). | ||
| 91 | Str(zerowrap.FieldLayer, "adapter"). | 87 | Str(zerowrap.FieldLayer, "adapter"). | ||
| 92 | Str(zerowrap.FieldAdapter, "http"). | 88 | Str(zerowrap.FieldAdapter, "http"). | ||
| 89 | + | Str(zerowrap.FieldRequestID, requestID). | |||
| 90 | + | Str(zerowrap.FieldMethod, r.Method). | |||
| 91 | + | Str(zerowrap.FieldPath, r.URL.Path). | |||
| 92 | + | Int(zerowrap.FieldStatus, rw.StatusCode()). | |||
| 93 | + | Str(zerowrap.FieldClientIP, clientIP). | |||
| 93 | Err(err). | 94 | Err(err). | ||
| 94 | Msg("access log write failed") | 95 | Msg("access log write failed") | ||
| 95 | } | 96 | } | ||
M internal/adapters/out/accesslog/journald.go +7 -6
| @@ -20,7 +20,9 @@ var ( | |||
| 20 | 20 | // distinct SYSLOG_IDENTIFIER so security tools (CrowdSec, fail2ban) can filter | |
| 21 | 21 | // on the identity without catching application logs. | |
| 22 | 22 | type journaldSink struct { | |
| 23 | - | syslogID string | |
| 23 | + | // vars is built once at construction and reused on every write to avoid a | |
| 24 | + | // per-request map allocation. | |
| 25 | + | vars map[string]string | |
| 24 | 26 | } | |
| 25 | 27 | ||
| 26 | 28 | func newJournaldSink(cfg Config) (*journaldSink, error) { | |
| @@ -31,14 +33,13 @@ func newJournaldSink(cfg Config) (*journaldSink, error) { | |||
| 31 | 33 | if !journalEnabledFunc() { | |
| 32 | 34 | return nil, fmt.Errorf("accesslog: journald output requested but journald is not available on this system") | |
| 33 | 35 | } | |
| 34 | - | return &journaldSink{syslogID: id}, nil | |
| 36 | + | return &journaldSink{ | |
| 37 | + | vars: map[string]string{"SYSLOG_IDENTIFIER": id}, | |
| 38 | + | }, nil | |
| 35 | 39 | } | |
| 36 | 40 | ||
| 37 | 41 | func (s *journaldSink) WriteLine(line string) error { | |
| 38 | - | err := journalSendFunc(line, journal.PriInfo, map[string]string{ | |
| 39 | - | "SYSLOG_IDENTIFIER": s.syslogID, | |
| 40 | - | }) | |
| 41 | - | if err != nil { | |
| 42 | + | if err := journalSendFunc(line, journal.PriInfo, s.vars); err != nil { | |
| 42 | 43 | return fmt.Errorf("accesslog: journald write: %w", err) | |
| 43 | 44 | } | |
| 44 | 45 | return nil | |
| @@ -20,7 +20,9 @@ var ( | |||||
| 20 | // distinct SYSLOG_IDENTIFIER so security tools (CrowdSec, fail2ban) can filter | 20 | // distinct SYSLOG_IDENTIFIER so security tools (CrowdSec, fail2ban) can filter | ||
| 21 | // on the identity without catching application logs. | 21 | // on the identity without catching application logs. | ||
| 22 | type journaldSink struct { | 22 | type journaldSink struct { | ||
| 23 | - | syslogID string | 23 | + | // vars is built once at construction and reused on every write to avoid a |
| 24 | + | // per-request map allocation. | |||
| 25 | + | vars map[string]string | |||
| 24 | } | 26 | } | ||
| 25 | 27 | ||||
| 26 | func newJournaldSink(cfg Config) (*journaldSink, error) { | 28 | func newJournaldSink(cfg Config) (*journaldSink, error) { | ||
| @@ -31,14 +33,13 @@ func newJournaldSink(cfg Config) (*journaldSink, error) { | |||||
| 31 | if !journalEnabledFunc() { | 33 | if !journalEnabledFunc() { | ||
| 32 | return nil, fmt.Errorf("accesslog: journald output requested but journald is not available on this system") | 34 | return nil, fmt.Errorf("accesslog: journald output requested but journald is not available on this system") | ||
| 33 | } | 35 | } | ||
| 34 | - | return &journaldSink{syslogID: id}, nil | 36 | + | return &journaldSink{ |
| 37 | + | vars: map[string]string{"SYSLOG_IDENTIFIER": id}, | |||
| 38 | + | }, nil | |||
| 35 | } | 39 | } | ||
| 36 | 40 | ||||
| 37 | func (s *journaldSink) WriteLine(line string) error { | 41 | func (s *journaldSink) WriteLine(line string) error { | ||
| 38 | - | err := journalSendFunc(line, journal.PriInfo, map[string]string{ | 42 | + | if err := journalSendFunc(line, journal.PriInfo, s.vars); err != nil { |
| 39 | - | "SYSLOG_IDENTIFIER": s.syslogID, | |||
| 40 | - | }) | |||
| 41 | - | if err != nil { | |||
| 42 | return fmt.Errorf("accesslog: journald write: %w", err) | 43 | return fmt.Errorf("accesslog: journald write: %w", err) | ||
| 43 | } | 44 | } | ||
| 44 | return nil | 45 | return nil | ||
M internal/adapters/out/accesslog/writer.go +1 -6
| @@ -160,15 +160,10 @@ func newFileSink(cfg Config) (*fileSink, error) { | |||
| 160 | 160 | return nil, fmt.Errorf("accesslog: create log directory: %w", err) | |
| 161 | 161 | } | |
| 162 | 162 | ||
| 163 | - | maxSize := cfg.MaxSize | |
| 164 | - | if maxSize <= 0 { | |
| 165 | - | maxSize = 100 | |
| 166 | - | } | |
| 167 | - | ||
| 168 | 163 | return &fileSink{ | |
| 169 | 164 | logger: &lumberjack.Logger{ | |
| 170 | 165 | Filename: cfg.FilePath, | |
| 171 | - | MaxSize: maxSize, | |
| 166 | + | MaxSize: cfg.MaxSize, | |
| 172 | 167 | MaxBackups: cfg.MaxBackups, | |
| 173 | 168 | MaxAge: cfg.MaxAge, | |
| 174 | 169 | Compress: true, | |
| @@ -160,15 +160,10 @@ func newFileSink(cfg Config) (*fileSink, error) { | |||||
| 160 | return nil, fmt.Errorf("accesslog: create log directory: %w", err) | 160 | return nil, fmt.Errorf("accesslog: create log directory: %w", err) | ||
| 161 | } | 161 | } | ||
| 162 | 162 | ||||
| 163 | - | maxSize := cfg.MaxSize | |||
| 164 | - | if maxSize <= 0 { | |||
| 165 | - | maxSize = 100 | |||
| 166 | - | } | |||
| 167 | - | ||||
| 168 | return &fileSink{ | 163 | return &fileSink{ | ||
| 169 | logger: &lumberjack.Logger{ | 164 | logger: &lumberjack.Logger{ | ||
| 170 | Filename: cfg.FilePath, | 165 | Filename: cfg.FilePath, | ||
| 171 | - | MaxSize: maxSize, | 166 | + | MaxSize: cfg.MaxSize, |
| 172 | MaxBackups: cfg.MaxBackups, | 167 | MaxBackups: cfg.MaxBackups, | ||
| 173 | MaxAge: cfg.MaxAge, | 168 | MaxAge: cfg.MaxAge, | ||
| 174 | Compress: true, | 169 | Compress: true, | ||
M internal/adapters/out/httpprober/prober.go +4 -2
| @@ -7,6 +7,8 @@ import ( | |||
| 7 | 7 | "fmt" | |
| 8 | 8 | "net/http" | |
| 9 | 9 | "time" | |
| 10 | + | ||
| 11 | + | "github.com/bnema/gordon/internal/domain" | |
| 10 | 12 | ) | |
| 11 | 13 | ||
| 12 | 14 | // DefaultTimeout is the default timeout for HTTP probes. | |
| @@ -76,8 +78,8 @@ func (p *Prober) Probe(ctx context.Context, url string) (int, int64, error) { | |||
| 76 | 78 | return 0, 0, fmt.Errorf("failed to create request: %w", err) | |
| 77 | 79 | } | |
| 78 | 80 | ||
| 79 | - | // Set a reasonable user agent | |
| 80 | - | req.Header.Set("User-Agent", "Gordon-HealthCheck/1.0") | |
| 81 | + | // Set a recognisable user agent so access-log filters can exclude probe traffic. | |
| 82 | + | req.Header.Set("User-Agent", domain.HealthCheckUserAgentPrefix+"1.0") | |
| 81 | 83 | ||
| 82 | 84 | resp, err := p.client.Do(req) | |
| 83 | 85 | if err != nil { | |
| @@ -7,6 +7,8 @@ import ( | |||||
| 7 | "fmt" | 7 | "fmt" | ||
| 8 | "net/http" | 8 | "net/http" | ||
| 9 | "time" | 9 | "time" | ||
| 10 | + | ||||
| 11 | + | "github.com/bnema/gordon/internal/domain" | |||
| 10 | ) | 12 | ) | ||
| 11 | 13 | ||||
| 12 | // DefaultTimeout is the default timeout for HTTP probes. | 14 | // DefaultTimeout is the default timeout for HTTP probes. | ||
| @@ -76,8 +78,8 @@ func (p *Prober) Probe(ctx context.Context, url string) (int, int64, error) { | |||||
| 76 | return 0, 0, fmt.Errorf("failed to create request: %w", err) | 78 | return 0, 0, fmt.Errorf("failed to create request: %w", err) | ||
| 77 | } | 79 | } | ||
| 78 | 80 | ||||
| 79 | - | // Set a reasonable user agent | 81 | + | // Set a recognisable user agent so access-log filters can exclude probe traffic. |
| 80 | - | req.Header.Set("User-Agent", "Gordon-HealthCheck/1.0") | 82 | + | req.Header.Set("User-Agent", domain.HealthCheckUserAgentPrefix+"1.0") |
| 81 | 83 | ||||
| 82 | resp, err := p.client.Do(req) | 84 | resp, err := p.client.Do(req) | ||
| 83 | if err != nil { | 85 | if err != nil { | ||
M internal/domain/labels.go +4 -0
| @@ -1,5 +1,9 @@ | |||
| 1 | 1 | package domain | |
| 2 | 2 | ||
| 3 | + | // HealthCheckUserAgentPrefix is the User-Agent prefix set by Gordon's internal | |
| 4 | + | // health-check prober. Shared so access-log filtering and the prober stay in sync. | |
| 5 | + | const HealthCheckUserAgentPrefix = "Gordon-HealthCheck/" | |
| 6 | + | ||
| 3 | 7 | // Label keys used by Gordon for container and image metadata. | |
| 4 | 8 | const ( | |
| 5 | 9 | // Container labels | |
| @@ -1,5 +1,9 @@ | |||||
| 1 | package domain | 1 | package domain | ||
| 2 | 2 | ||||
| 3 | + | // HealthCheckUserAgentPrefix is the User-Agent prefix set by Gordon's internal | |||
| 4 | + | // health-check prober. Shared so access-log filtering and the prober stay in sync. | |||
| 5 | + | const HealthCheckUserAgentPrefix = "Gordon-HealthCheck/" | |||
| 6 | + | ||||
| 3 | // Label keys used by Gordon for container and image metadata. | 7 | // Label keys used by Gordon for container and image metadata. | ||
| 4 | const ( | 8 | const ( | ||
| 5 | // Container labels | 9 | // Container labels | ||