diff --git a/DECISIONS.md b/DECISIONS.md index 440741a..3f31dcb 100644 --- a/DECISIONS.md +++ b/DECISIONS.md @@ -84,3 +84,5 @@ - 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. - 2026-02-28 m+git@andri.dk — Lazy session restore in `authenticate()`. The in-memory `sessionMap` (IP → credential) is lost on server restart. Now, when a valid Bearer token is validated against SQLite, `authenticate()` also populates the `sessionMap` for that client IP. The proxy knows the user as soon as their browser makes any authenticated API call (e.g. `GET /api/whoami` on portal page load). No schema change needed. +- 2026-02-28 m+git@andri.dk — `X-Ublproxy-Stats` response header on modified HTML responses. Reports `hidden=N; stripped=N` — the number of CSS element-hiding selectors injected and HTML elements (script/iframe/object/embed) stripped. Present only when the proxy modified the response. Zero performance overhead: counts are byproducts of work already being done. Useful for debugging filtering issues across browsers. +- 2026-02-28 m+git@andri.dk — Warn-level logging when HTML filtering is skipped due to unsupported `Content-Encoding`, decompression init failure, or decompression read failure. Previously these were silent `return nil, false` paths — filtering was silently bypassed with no diagnostic output. diff --git a/connect.go b/connect.go index 2621209..5548a5f 100644 --- a/connect.go +++ b/connect.go @@ -189,11 +189,12 @@ func (p *proxyHandler) proxyTLSRequests(clientTLS *tls.Conn, host, port, clientI // Replace ad elements in HTML responses (skip HEAD — no body to modify) if req.Method != http.MethodHead { - if modified, ok := p.applyElementHiding(resp, host, clientIP, insecure); ok { + if modified, stats := p.applyElementHiding(resp, host, clientIP, insecure); stats.Modified { resp.Body.Close() resp.Body = io.NopCloser(bytes.NewReader(modified)) resp.ContentLength = int64(len(modified)) resp.Header.Del("Content-Length") + resp.Header.Set(statsHeaderName, stats.header()) } } diff --git a/elemhide_inject.go b/elemhide_inject.go index 611ad04..9a0c1da 100644 --- a/elemhide_inject.go +++ b/elemhide_inject.go @@ -3,8 +3,10 @@ package main import ( "bytes" "compress/gzip" + "fmt" htmlpkg "html" "io" + "log/slog" "net/http" "regexp" "strings" @@ -16,6 +18,22 @@ import ( "ublproxy/internal/blocklist" ) +// statsHeaderName is the response header the proxy adds to every proxied +// response, reporting how many filtering operations were applied. +const statsHeaderName = "X-Ublproxy-Stats" + +// elementHidingStats reports what the proxy did to an HTML response. +type elementHidingStats struct { + Modified bool // true if the response body was changed + Hidden int // CSS element-hiding selectors injected + Stripped int // HTML elements (script/iframe/object/embed) removed +} + +// header returns the stats formatted for the X-Ublproxy-Stats response header. +func (s elementHidingStats) header() string { + return fmt.Sprintf("hidden=%d; stripped=%d", s.Hidden, s.Stripped) +} + // styleCloseRe matches tag. var styleCloseRe = regexp.MustCompile(`(?i)" + safeCSS + "") modified = injectStyleTag(modified, styleTag) + stats.Hidden = len(selectors) rule := truncateRule(strings.Join(selectors, ", "), 80) p.logActivity(ActivityElementHidden, host, "", rule, clientIP, credID) logElementHidden(host, rule, clientIP, credID) @@ -165,7 +192,7 @@ func (p *proxyHandler) applyElementHiding(resp *http.Response, host, clientIP st // The proxy-to-client hop is typically localhost so this is fine. resp.Header.Del("Content-Encoding") - return modified, true + return modified, stats } // mergeElementHidingCSS combines element hiding selectors from baseline and @@ -212,15 +239,16 @@ func injectBeforeClose(htmlDoc, content []byte, tags ...[]byte) []byte { // strip elements (script, iframe, object, embed) whose external resource URL // resolves to a blocked address. Other elements are passed through unchanged — // element hiding for those is handled by CSS injection only. -func stripBlockedResources(src []byte, sc srcBlockContext) []byte { +func stripBlockedResources(src []byte, sc srcBlockContext) ([]byte, int) { if sc.proxy == nil { - return src + return src, 0 } var buf bytes.Buffer buf.Grow(len(src)) tokenizer := html.NewTokenizer(bytes.NewReader(src)) + stripped := 0 for { tt := tokenizer.Next() @@ -228,10 +256,10 @@ func stripBlockedResources(src []byte, sc srcBlockContext) []byte { switch tt { case html.ErrorToken: if tokenizer.Err() == io.EOF { - return buf.Bytes() + return buf.Bytes(), stripped } buf.Write(tokenizer.Raw()) - return buf.Bytes() + return buf.Bytes(), stripped case html.StartTagToken: tn, hasAttr := tokenizer.TagName() @@ -265,6 +293,7 @@ func stripBlockedResources(src []byte, sc srcBlockContext) []byte { // HTML-encode the URL to prevent breaking out of the comment replacement := "" buf.WriteString(replacement) + stripped++ if !voidElements[tagNameLower] { skipUntilClose(tokenizer, tagNameLower) } diff --git a/http.go b/http.go index 59e7181..5a5c907 100644 --- a/http.go +++ b/http.go @@ -92,10 +92,11 @@ func (p *proxyHandler) handleHTTP(w http.ResponseWriter, r *http.Request) { // bootstrap script injection to avoid leaking the session token. insecure := r.TLS == nil if r.Method != http.MethodHead { - if modified, ok := p.applyElementHiding(resp, r.URL.Hostname(), clientIP, insecure); ok { + if modified, stats := p.applyElementHiding(resp, r.URL.Hostname(), clientIP, insecure); stats.Modified { copyHeaders(w.Header(), resp.Header) removeHopByHopHeaders(w.Header()) w.Header().Del("Content-Length") + w.Header().Set(statsHeaderName, stats.header()) w.WriteHeader(resp.StatusCode) w.Write(modified) logRequest(r.Method, r.URL.String(), resp.StatusCode, time.Since(start), clientIP, credID) diff --git a/inject_test.go b/inject_test.go index 2c805f5..fec4380 100644 --- a/inject_test.go +++ b/inject_test.go @@ -77,8 +77,8 @@ func TestScriptInjectionInHTML(t *testing.T) { Body: io.NopCloser(strings.NewReader(htmlBody)), } - modified, ok := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) - if !ok { + modified, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if !stats.Modified { t.Fatal("expected modification") } @@ -116,8 +116,8 @@ func TestNoScriptInjectionWithoutSession(t *testing.T) { } // No rules and no session -> no modification - _, ok := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) - if ok { + _, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if stats.Modified { t.Error("should not modify HTML when there's no session and no rules") } } @@ -146,8 +146,8 @@ func TestScriptInjectionWithGzip(t *testing.T) { Body: io.NopCloser(&buf), } - modified, ok := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) - if !ok { + modified, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if !stats.Modified { t.Fatal("expected modification for gzipped HTML") } @@ -177,8 +177,8 @@ func TestScriptInjectionWithRules(t *testing.T) { Body: io.NopCloser(strings.NewReader(htmlBody)), } - modified, ok := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) - if !ok { + modified, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if !stats.Modified { t.Fatal("expected modification") } @@ -261,8 +261,8 @@ func TestScriptInjectionWithZstd(t *testing.T) { Body: io.NopCloser(bytes.NewReader(compressed)), } - modified, ok := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) - if !ok { + modified, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if !stats.Modified { t.Fatal("expected modification for zstd-compressed HTML") } @@ -274,3 +274,115 @@ func TestScriptInjectionWithZstd(t *testing.T) { t.Error("should contain the original HTML content") } } + +func TestElementHidingStatsCountsSelectors(t *testing.T) { + rs := blocklist.NewRuleSet() + rs.AddLine("##.ad-banner") + rs.AddLine("##.tracking-pixel") + rs.AddLine("##.sponsored") + + p := &proxyHandler{sessions: newSessionMap()} + p.baselineRules.Store(rs) + + htmlBody := `

Content

` + resp := &http.Response{ + StatusCode: 200, + Header: http.Header{"Content-Type": []string{"text/html"}}, + Body: io.NopCloser(strings.NewReader(htmlBody)), + } + + _, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if !stats.Modified { + t.Fatal("expected modification") + } + if stats.Hidden != 3 { + t.Errorf("Hidden = %d, want 3", stats.Hidden) + } + if stats.Stripped != 0 { + t.Errorf("Stripped = %d, want 0", stats.Stripped) + } +} + +func TestElementHidingStatsCountsStripped(t *testing.T) { + rs := blocklist.NewRuleSet() + rs.AddLine("||ads.example.com^") + rs.AddLine("||tracker.example.com^") + + p := &proxyHandler{sessions: newSessionMap()} + p.baselineRules.Store(rs) + + htmlBody := `` + + `` + + `` + + `` + + `

Content

` + + `` + resp := &http.Response{ + StatusCode: 200, + Header: http.Header{"Content-Type": []string{"text/html"}}, + Body: io.NopCloser(strings.NewReader(htmlBody)), + } + + _, stats := p.applyElementHiding(resp, "page.example.com", "127.0.0.1", false) + if !stats.Modified { + t.Fatal("expected modification") + } + if stats.Stripped != 2 { + t.Errorf("Stripped = %d, want 2", stats.Stripped) + } +} + +func TestElementHidingStatsCombined(t *testing.T) { + rs := blocklist.NewRuleSet() + rs.AddLine("##.ad-banner") + rs.AddLine("||ads.example.com^") + + p := &proxyHandler{sessions: newSessionMap()} + p.baselineRules.Store(rs) + + htmlBody := `` + + `` + + `` + + `
Ad
` + + `

Content

` + + `` + resp := &http.Response{ + StatusCode: 200, + Header: http.Header{"Content-Type": []string{"text/html"}}, + Body: io.NopCloser(strings.NewReader(htmlBody)), + } + + _, stats := p.applyElementHiding(resp, "page.example.com", "127.0.0.1", false) + if !stats.Modified { + t.Fatal("expected modification") + } + if stats.Hidden != 1 { + t.Errorf("Hidden = %d, want 1", stats.Hidden) + } + if stats.Stripped != 1 { + t.Errorf("Stripped = %d, want 1", stats.Stripped) + } + + want := "hidden=1; stripped=1" + if got := stats.header(); got != want { + t.Errorf("header() = %q, want %q", got, want) + } +} + +func TestElementHidingStatsNoModification(t *testing.T) { + p := &proxyHandler{sessions: newSessionMap()} + + resp := &http.Response{ + StatusCode: 200, + Header: http.Header{"Content-Type": []string{"application/json"}}, + Body: io.NopCloser(strings.NewReader(`{"ok":true}`)), + } + + _, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", false) + if stats.Modified { + t.Error("should not modify non-HTML response") + } + if stats.Hidden != 0 || stats.Stripped != 0 { + t.Errorf("stats should be zero for unmodified response, got hidden=%d stripped=%d", stats.Hidden, stats.Stripped) + } +} diff --git a/proxy_test.go b/proxy_test.go index 5969a24..a9d0974 100644 --- a/proxy_test.go +++ b/proxy_test.go @@ -2234,6 +2234,99 @@ func TestHTTPPortConnect(t *testing.T) { } } +func TestStatsHeaderOnModifiedHTML(t *testing.T) { + rs := blocklist.NewRuleSet() + rs.AddLine("##.ad-banner") + rs.AddLine("##.tracking") + rs.AddLine("||ads.tracker.com^") + + upstream := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "text/html; charset=utf-8") + w.WriteHeader(http.StatusOK) + w.Write([]byte(`` + + `` + + `` + + `
Ad
` + + `

Content

` + + ``)) + }) + + env := startTestEnv(t, upstream, rs) + client := env.httpClient(t) + + // HTTP proxy path + resp, err := client.Get(env.httpURL + "/page.html") + if err != nil { + t.Fatalf("GET: %v", err) + } + defer resp.Body.Close() + io.ReadAll(resp.Body) + + got := resp.Header.Get(statsHeaderName) + if got == "" { + t.Fatal("X-Ublproxy-Stats header missing on modified HTML response") + } + // 2 CSS selectors hidden, 1 script stripped + want := "hidden=2; stripped=1" + if got != want { + t.Errorf("X-Ublproxy-Stats = %q, want %q", got, want) + } +} + +func TestStatsHeaderOnHTTPSModifiedHTML(t *testing.T) { + rs := blocklist.NewRuleSet() + rs.AddLine("##.ad-banner") + + upstream := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "text/html; charset=utf-8") + w.WriteHeader(http.StatusOK) + w.Write([]byte(`
Ad
`)) + }) + + env := startTestEnv(t, upstream, rs) + client := env.httpClient(t) + + // HTTPS proxy path (through CONNECT tunnel) + resp, err := client.Get(env.httpsURL + "/page.html") + if err != nil { + t.Fatalf("GET: %v", err) + } + defer resp.Body.Close() + io.ReadAll(resp.Body) + + got := resp.Header.Get(statsHeaderName) + if got == "" { + t.Fatal("X-Ublproxy-Stats header missing on HTTPS modified HTML response") + } + want := "hidden=1; stripped=0" + if got != want { + t.Errorf("X-Ublproxy-Stats = %q, want %q", got, want) + } +} + +func TestStatsHeaderAbsentOnUnmodifiedResponse(t *testing.T) { + upstream := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(http.StatusOK) + w.Write([]byte(`{"ok":true}`)) + }) + + env := startTestEnv(t, upstream, nil) + client := env.httpClient(t) + + resp, err := client.Get(env.httpURL + "/api/data") + if err != nil { + t.Fatalf("GET: %v", err) + } + defer resp.Body.Close() + io.ReadAll(resp.Body) + + // No rules, no modification, no header + if got := resp.Header.Get(statsHeaderName); got != "" { + t.Errorf("X-Ublproxy-Stats should be absent on unmodified response, got %q", got) + } +} + func TestNoBootstrapInjectionOnInsecureProxy(t *testing.T) { sm := newSessionMap() sm.Set("127.0.0.1", sessionEntry{Token: "secret-token", CredentialID: "cred-1"}) @@ -2251,8 +2344,8 @@ func TestNoBootstrapInjectionOnInsecureProxy(t *testing.T) { } // With insecure=true (plain HTTP proxy), bootstrap script should NOT be injected - modified, ok := p.applyElementHiding(resp, "example.com", "127.0.0.1", true) - if ok { + modified, stats := p.applyElementHiding(resp, "example.com", "127.0.0.1", true) + if stats.Modified { body := string(modified) if strings.Contains(body, "secret-token") { t.Error("session token must not be injected on insecure connections") @@ -2268,8 +2361,8 @@ func TestNoBootstrapInjectionOnInsecureProxy(t *testing.T) { Header: http.Header{"Content-Type": []string{"text/html; charset=utf-8"}}, Body: io.NopCloser(strings.NewReader(htmlBody)), } - modified2, ok2 := p.applyElementHiding(resp2, "example.com", "127.0.0.1", false) - if !ok2 { + modified2, stats2 := p.applyElementHiding(resp2, "example.com", "127.0.0.1", false) + if !stats2.Modified { t.Fatal("expected modification on secure connection") } body2 := string(modified2) diff --git a/transparent.go b/transparent.go index 46ad08f..9854446 100644 --- a/transparent.go +++ b/transparent.go @@ -329,10 +329,11 @@ func (h *transparentHTTPHandler) forwardHTTP(w http.ResponseWriter, r *http.Requ insecure := true // transparent HTTP is always insecure if r.Method != http.MethodHead { - if modified, ok := h.proxy.applyElementHiding(resp, host, clientIP, insecure); ok { + if modified, stats := h.proxy.applyElementHiding(resp, host, clientIP, insecure); stats.Modified { copyHeaders(w.Header(), resp.Header) removeHopByHopHeaders(w.Header()) w.Header().Del("Content-Length") + w.Header().Set(statsHeaderName, stats.header()) w.WriteHeader(resp.StatusCode) w.Write(modified) logRequest(r.Method, targetURL, resp.StatusCode, time.Since(start), clientIP, credID)