From 3db5b4a60afffbffc1329ec0d0c931f7294ddf57 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andri=20=C3=93skarsson?= Date: Sat, 28 Feb 2026 14:25:22 +0100 Subject: [PATCH] Normalize client IPs and add session debug logging MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit IPv4-mapped IPv6 addresses (::ffff:192.168.1.x) are now unwrapped to plain IPv4 so the session map key from portal auth matches the proxy lookup key. All RemoteAddr extraction points go through normalizeIP(). Debug logging on sessionMap Set/Get/Delete traces the exact IP being stored vs looked up — visible with --log-level=debug. Also includes: logElementHidden now logs which CSS selectors were applied, and mergeElementHidingCSS returns the selector list. --- DECISIONS.md | 1 + connect.go | 2 +- elemhide_inject.go | 14 ++++---- http.go | 22 ++++++++++-- http_test.go | 83 ++++++++++++++++++++++++++++++++++++++++++++++ log.go | 3 +- log_test.go | 7 ++-- session_map.go | 9 ++++- transparent.go | 3 +- 9 files changed, 130 insertions(+), 14 deletions(-) create mode 100644 http_test.go diff --git a/DECISIONS.md b/DECISIONS.md index a8c03bc..5a1e53d 100644 --- a/DECISIONS.md +++ b/DECISIONS.md @@ -82,3 +82,4 @@ - 2026-02-28 m+git@andri.dk — Added zstd decompression for CSS injection and resource stripping. All major browsers now negotiate zstd via `Accept-Encoding`, and CDNs are increasingly serving zstd-compressed HTML. Added `github.com/klauspost/compress/zstd` (pure Go, zero transitive runtime deps) alongside the existing brotli and gzip support. Without this, zstd-encoded HTML passed through without element hiding or script injection. - 2026-02-28 m+git@andri.dk — Cert cache now evicts expired certificates. `GetCert` checks the cached cert's expiry time before returning it; expired entries are regenerated on demand. Previously, certs were cached indefinitely — after 24h of uptime, cached certs would be stale and clients would get TLS errors. The cache stores `expiresAt` alongside each cert. No background goroutine; expiry is checked lazily on access. - 2026-02-28 m+git@andri.dk — Structured logging with `log/slog` (stdlib, zero new dependencies). Replaced all `fmt.Fprintf(os.Stderr)` calls with `slog` at appropriate levels. Added `--log-level` flag (env: `UBLPROXY_LOG_LEVEL`, default: `info`). Every log line includes `ip` (client source IP) and `user` (first 8 chars of credential ID, or `anon`). Per-request traffic logging and passthrough tunnels are Debug level — only visible with `--log-level=debug`. Blocked requests, startup, and errors are Info/Error level and always visible. Blocklist loading failures are Warn level. Output is `slog.TextHandler` (structured key=value pairs to stderr). +- 2026-02-28 m+git@andri.dk — Normalize client IP addresses via `normalizeIP()` to unwrap IPv4-mapped IPv6 (e.g. `::ffff:192.168.1.5` → `192.168.1.5`). Go's `net` package can represent the same IPv4 address differently depending on whether the connection arrived via IPv4 or IPv6. Without normalization, the session map key from portal auth could differ from the proxy lookup key, causing `user=anon` despite an active session. All `RemoteAddr` extraction points now go through normalization. Debug logging added to `sessionMap.Set()`, `Get()`, and `Delete()` for diagnosing session lookup issues. diff --git a/connect.go b/connect.go index 2b3dc94..2621209 100644 --- a/connect.go +++ b/connect.go @@ -17,7 +17,7 @@ func (p *proxyHandler) handleConnect(w http.ResponseWriter, r *http.Request) { host = r.Host port = "443" } - clientIP, _, _ := net.SplitHostPort(r.RemoteAddr) + clientIP := clientIPFromRequest(r) credID := p.credentialForIP(clientIP) if p.shouldBlockHost(clientIP, host) { p.logActivity(ActivityBlocked, host, "", "||"+host+"^", clientIP, credID) diff --git a/elemhide_inject.go b/elemhide_inject.go index 7d5648c..1e90b2f 100644 --- a/elemhide_inject.go +++ b/elemhide_inject.go @@ -146,13 +146,14 @@ func (p *proxyHandler) applyElementHiding(resp *http.Response, host, clientIP st modified := stripBlockedResources(body, sc) // Merge baseline + user element hiding CSS, applying user #@# exceptions - css := mergeElementHidingCSS(baselineEH, userEH, userRS, host) + css, selectors := mergeElementHidingCSS(baselineEH, userEH, userRS, host) if css != "" { safeCSS := styleCloseRe.ReplaceAllString(css, `<\/style`) styleTag := []byte("") modified = injectStyleTag(modified, styleTag) - p.logActivity(ActivityElementHidden, host, "", "", clientIP, credID) - logElementHidden(host, clientIP, credID) + rule := strings.Join(selectors, ", ") + p.logActivity(ActivityElementHidden, host, "", rule, clientIP, credID) + logElementHidden(host, rule, clientIP, credID) } // Inject the bootstrap script for the element picker @@ -170,7 +171,7 @@ func (p *proxyHandler) applyElementHiding(resp *http.Response, host, clientIP st // mergeElementHidingCSS combines element hiding selectors from baseline and // user RuleSets for a specific domain. User #@# exception rules suppress // matching baseline ## selectors. Returns empty string if no CSS to inject. -func mergeElementHidingCSS(baseline, user *blocklist.ElementHiding, userRS *blocklist.RuleSet, domain string) string { +func mergeElementHidingCSS(baseline, user *blocklist.ElementHiding, userRS *blocklist.RuleSet, domain string) (string, []string) { var selectors []string // Add baseline selectors, filtering out any excepted by user #@# rules @@ -189,10 +190,11 @@ func mergeElementHidingCSS(baseline, user *blocklist.ElementHiding, userRS *bloc } if len(selectors) == 0 { - return "" + return "", nil } - return strings.Join(selectors, ",\n") + " {\n display: none !important;\n}\n" + css := strings.Join(selectors, ",\n") + " {\n display: none !important;\n}\n" + return css, selectors } // injectBeforeClose inserts content before the first found closing tag, diff --git a/http.go b/http.go index 3bd4792..59e7181 100644 --- a/http.go +++ b/http.go @@ -11,12 +11,30 @@ import ( ) // clientIPFromRequest extracts the IP address from the request's RemoteAddr. +// The result is normalized so that IPv4-mapped IPv6 addresses (e.g. +// "::ffff:192.168.1.5") are returned as plain IPv4 ("192.168.1.5"). +// Without this, session lookups can fail when the portal auth request +// arrives on a different address family than the proxy CONNECT request. func clientIPFromRequest(r *http.Request) string { host, _, err := net.SplitHostPort(r.RemoteAddr) if err != nil { - return r.RemoteAddr + return normalizeIP(r.RemoteAddr) } - return host + return normalizeIP(host) +} + +// normalizeIP parses an IP string and returns its canonical form. +// IPv4-mapped IPv6 addresses are unwrapped to plain IPv4. +func normalizeIP(raw string) string { + ip := net.ParseIP(raw) + if ip == nil { + return raw + } + // Unmap IPv4-mapped IPv6 (e.g. ::ffff:192.168.1.5 -> 192.168.1.5) + if v4 := ip.To4(); v4 != nil { + return v4.String() + } + return ip.String() } // Headers that must not be forwarded between hops. diff --git a/http_test.go b/http_test.go new file mode 100644 index 0000000..1960803 --- /dev/null +++ b/http_test.go @@ -0,0 +1,83 @@ +package main + +import ( + "net/http" + "testing" +) + +func TestNormalizeIP(t *testing.T) { + tests := []struct { + input string + want string + }{ + {"192.168.1.5", "192.168.1.5"}, + {"::ffff:192.168.1.5", "192.168.1.5"}, + {"::ffff:10.0.0.1", "10.0.0.1"}, + {"::1", "::1"}, + {"fe80::1", "fe80::1"}, + {"2001:db8::1", "2001:db8::1"}, + // Unparseable strings are returned as-is + {"not-an-ip", "not-an-ip"}, + {"", ""}, + } + for _, tt := range tests { + got := normalizeIP(tt.input) + if got != tt.want { + t.Errorf("normalizeIP(%q) = %q, want %q", tt.input, got, tt.want) + } + } +} + +func TestClientIPFromRequest(t *testing.T) { + tests := []struct { + name string + remoteAddr string + want string + }{ + {"ipv4 with port", "192.168.1.5:12345", "192.168.1.5"}, + {"ipv6 mapped with port", "[::ffff:192.168.1.5]:12345", "192.168.1.5"}, + {"ipv6 with port", "[::1]:12345", "::1"}, + {"ipv4 no port", "192.168.1.5", "192.168.1.5"}, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + r := &http.Request{RemoteAddr: tt.remoteAddr} + got := clientIPFromRequest(r) + if got != tt.want { + t.Errorf("clientIPFromRequest(RemoteAddr=%q) = %q, want %q", tt.remoteAddr, got, tt.want) + } + }) + } +} + +func TestSessionLookupWithNormalizedIP(t *testing.T) { + sm := newSessionMap() + + // Store session with plain IPv4 + sm.Set("192.168.1.5", sessionEntry{ + Token: "tok-abc", + CredentialID: "cred-xyz-12345678", + }) + + // Lookup with same IPv4 should hit + entry := sm.Get("192.168.1.5") + if entry == nil { + t.Fatal("expected session for 192.168.1.5, got nil") + } + if entry.CredentialID != "cred-xyz-12345678" { + t.Errorf("got credID %q, want %q", entry.CredentialID, "cred-xyz-12345678") + } + + // Lookup with different IP should miss + entry = sm.Get("192.168.1.6") + if entry != nil { + t.Errorf("expected nil for 192.168.1.6, got %+v", entry) + } + + // Delete and verify + sm.Delete("192.168.1.5") + entry = sm.Get("192.168.1.5") + if entry != nil { + t.Errorf("expected nil after delete, got %+v", entry) + } +} diff --git a/log.go b/log.go index 0841b69..cb328f9 100644 --- a/log.go +++ b/log.go @@ -83,9 +83,10 @@ func logBlocked(host, url, rule, clientIP, credentialID string) { } // logElementHidden logs a CSS element hiding injection at Debug level. -func logElementHidden(host, clientIP, credentialID string) { +func logElementHidden(host, rule, clientIP, credentialID string) { slog.Debug("element-hidden", "host", host, + "rule", rule, "ip", clientIP, "user", shortUserID(credentialID), ) diff --git a/log_test.go b/log_test.go index a6c75fe..d039bf5 100644 --- a/log_test.go +++ b/log_test.go @@ -110,7 +110,7 @@ func TestLogPassthroughIsDebugLevel(t *testing.T) { func TestLogElementHiddenIsDebugLevel(t *testing.T) { // At info level, logElementHidden should produce no output output := withLogCapture(slog.LevelInfo, func() { - logElementHidden("example.com", "192.168.1.5", "CredABCD1234") + logElementHidden("example.com", ".ad-banner, #sidebar-ad", "192.168.1.5", "CredABCD1234") }) if output != "" { t.Errorf("logElementHidden at info level should produce no output, got: %s", output) @@ -118,7 +118,7 @@ func TestLogElementHiddenIsDebugLevel(t *testing.T) { // At debug level, logElementHidden should produce output output = withLogCapture(slog.LevelDebug, func() { - logElementHidden("example.com", "192.168.1.5", "CredABCD1234") + logElementHidden("example.com", ".ad-banner, #sidebar-ad", "192.168.1.5", "CredABCD1234") }) if !strings.Contains(output, "level=DEBUG") { t.Errorf("expected level=DEBUG, got: %s", output) @@ -129,6 +129,9 @@ func TestLogElementHiddenIsDebugLevel(t *testing.T) { if !strings.Contains(output, "host=example.com") { t.Errorf("expected host=example.com, got: %s", output) } + if !strings.Contains(output, ".ad-banner") { + t.Errorf("expected rule to contain .ad-banner, got: %s", output) + } } func TestLogErrorIsErrorLevel(t *testing.T) { diff --git a/session_map.go b/session_map.go index d37ee0d..e00bfb5 100644 --- a/session_map.go +++ b/session_map.go @@ -1,6 +1,9 @@ package main -import "sync" +import ( + "log/slog" + "sync" +) // sessionEntry holds the session token and credential ID for an // authenticated client. The credential ID identifies the user (passkey) @@ -28,6 +31,7 @@ func (m *sessionMap) Set(clientIP string, entry sessionEntry) { m.mu.Lock() m.entries[clientIP] = entry m.mu.Unlock() + slog.Debug("session stored", "ip", clientIP, "user", shortUserID(entry.CredentialID)) } // Get returns the session entry for a client IP, or nil if none. @@ -36,8 +40,10 @@ func (m *sessionMap) Get(clientIP string) *sessionEntry { entry, ok := m.entries[clientIP] m.mu.RUnlock() if !ok { + slog.Debug("session lookup miss", "ip", clientIP) return nil } + slog.Debug("session lookup hit", "ip", clientIP, "user", shortUserID(entry.CredentialID)) return &entry } @@ -46,4 +52,5 @@ func (m *sessionMap) Delete(clientIP string) { m.mu.Lock() delete(m.entries, clientIP) m.mu.Unlock() + slog.Debug("session deleted", "ip", clientIP) } diff --git a/transparent.go b/transparent.go index aafbbc3..46ad08f 100644 --- a/transparent.go +++ b/transparent.go @@ -439,7 +439,8 @@ func handleTransparentTLSConn(conn net.Conn, proxy *proxyHandler, certs *ca.Cach conn.SetDeadline(time.Now().Add(10 * time.Second)) - clientIP, _, _ := net.SplitHostPort(conn.RemoteAddr().String()) + clientIPRaw, _, _ := net.SplitHostPort(conn.RemoteAddr().String()) + clientIP := normalizeIP(clientIPRaw) br := bufio.NewReader(conn) sni, err := extractSNI(br) -- 2.51.2