improved tracing for debug

internal/net/http/header_utils.go

@@ -2,7 +2,6 @@ package http
 
 import (
 	"net/http"
-	"slices"
 )
 
 func RemoveHop(h http.Header) {
@@ -25,18 +24,30 @@ func CopyHeader(dst, src http.Header) {
 	}
 }
 
-func FilterHeaders(h http.Header, allowed []string) {
+func FilterHeaders(h http.Header, allowed []string) http.Header {
-	if allowed == nil {
+	if len(allowed) == 0 {
-		return
+		return h
 	}
 
-	for i := range allowed {
+	filtered := make(http.Header)
-		allowed[i] = http.CanonicalHeaderKey(allowed[i])
+
+	for i, header := range allowed {
+		values := h.Values(header)
+		if len(values) == 0 {
+			continue
+		}
+		filtered[http.CanonicalHeaderKey(allowed[i])] = append([]string(nil), values...)
 	}
 
-	for key := range h {
+	return filtered
-		if !slices.Contains(allowed, key) {
+}
-			h.Del(key)
+
+func HeaderToMap(h http.Header) map[string]string {
+	result := make(map[string]string)
+	for k, v := range h {
+		if len(v) > 0 {
+			result[k] = v[0] // Take the first value
 		}
 	}
+	return result
 }

internal/net/http/middleware/forward_auth.go

@@ -54,7 +54,7 @@ func NewForwardAuthfunc(optsRaw OptionsRaw) (*Middleware, E.NestedError) {
 	}
 
 	// TODO: use tr from reverse proxy
-	tr, ok := fa.forwardAuthOpts.transport.(*http.Transport)
+	tr, ok := fa.transport.(*http.Transport)
 	if ok {
 		tr = tr.Clone()
 	} else {
@@ -81,7 +81,7 @@ func (fa *forwardAuth) forward(next http.HandlerFunc, w ResponseWriter, req *Req
 		nil,
 	)
 	if err != nil {
-		fa.m.AddTracef("new request err to %s", fa.Address).With("error", err)
+		fa.m.AddTracef("new request err to %s", fa.Address).WithError(err)
 		w.WriteHeader(http.StatusInternalServerError)
 		return
 	}
@@ -89,12 +89,13 @@ func (fa *forwardAuth) forward(next http.HandlerFunc, w ResponseWriter, req *Req
 	gpHTTP.CopyHeader(faReq.Header, req.Header)
 	gpHTTP.RemoveHop(faReq.Header)
 
-	gpHTTP.FilterHeaders(faReq.Header, fa.AuthResponseHeaders)
+	faReq.Header = gpHTTP.FilterHeaders(faReq.Header, fa.AuthResponseHeaders)
 	fa.setAuthHeaders(req, faReq)
+	fa.m.AddTraceRequest("forward auth request", faReq)
 
 	faResp, err := fa.client.Do(faReq)
 	if err != nil {
-		fa.m.AddTracef("failed to call %s", fa.Address).With("error", err)
+		fa.m.AddTracef("failed to call %s", fa.Address).WithError(err)
 		w.WriteHeader(http.StatusInternalServerError)
 		return
 	}
@@ -102,19 +103,19 @@ func (fa *forwardAuth) forward(next http.HandlerFunc, w ResponseWriter, req *Req
 
 	body, err := io.ReadAll(faResp.Body)
 	if err != nil {
-		fa.m.AddTracef("failed to read response body from %s", fa.Address).With("error", err)
+		fa.m.AddTracef("failed to read response body from %s", fa.Address).WithError(err)
 		w.WriteHeader(http.StatusInternalServerError)
 		return
 	}
 
 	if faResp.StatusCode < http.StatusOK || faResp.StatusCode >= http.StatusMultipleChoices {
-		fa.m.AddTracef("status %d", faResp.StatusCode)
+		fa.m.AddTraceResponse("forward auth response", faResp)
 		gpHTTP.CopyHeader(w.Header(), faResp.Header)
 		gpHTTP.RemoveHop(w.Header())
 
 		redirectURL, err := faResp.Location()
 		if err != nil {
-			fa.m.AddTracef("failed to get location from %s", fa.Address).With("error", err)
+			fa.m.AddTracef("failed to get location from %s", fa.Address).WithError(err)
 			w.WriteHeader(http.StatusInternalServerError)
 			return
 		} else if redirectURL.String() != "" {
@@ -125,7 +126,7 @@ func (fa *forwardAuth) forward(next http.HandlerFunc, w ResponseWriter, req *Req
 		w.WriteHeader(faResp.StatusCode)
 
 		if _, err = w.Write(body); err != nil {
-			fa.m.AddTracef("failed to write response body from %s", fa.Address).With("error", err)
+			fa.m.AddTracef("failed to write response body from %s", fa.Address).WithError(err)
 		}
 		return
 	}

internal/net/http/middleware/trace.go

@@ -2,22 +2,22 @@ package middleware
 
 import (
 	"fmt"
-	"net/http"
 	"sync"
 	"time"
 
+	gpHTTP "github.com/yusing/go-proxy/internal/net/http"
 	U "github.com/yusing/go-proxy/internal/utils"
 )
 
 type Trace struct {
-	Time        string         `json:"time,omitempty"`
+	Time        string            `json:"time,omitempty"`
-	Caller      string         `json:"caller,omitempty"`
+	Caller      string            `json:"caller,omitempty"`
-	URL         string         `json:"url,omitempty"`
+	URL         string            `json:"url,omitempty"`
-	Message     string         `json:"msg"`
+	Message     string            `json:"msg"`
-	ReqHeaders  http.Header    `json:"req_headers,omitempty"`
+	ReqHeaders  map[string]string `json:"req_headers,omitempty"`
-	RespHeaders http.Header    `json:"resp_headers,omitempty"`
+	RespHeaders map[string]string `json:"resp_headers,omitempty"`
-	RespStatus  int            `json:"resp_status,omitempty"`
+	RespStatus  int               `json:"resp_status,omitempty"`
-	Additional  map[string]any `json:"additional,omitempty"`
+	Additional  map[string]any    `json:"additional,omitempty"`
 }
 
 type Traces []*Trace
@@ -25,7 +25,7 @@ type Traces []*Trace
 var traces = Traces{}
 var tracesMu sync.Mutex
 
-const MaxTraceNum = 1000
+const MaxTraceNum = 100
 
 func GetAllTrace() []*Trace {
 	return traces
@@ -36,7 +36,7 @@ func (tr *Trace) WithRequest(req *Request) *Trace {
 		return nil
 	}
 	tr.URL = req.RequestURI
-	tr.ReqHeaders = req.Header.Clone()
+	tr.ReqHeaders = gpHTTP.HeaderToMap(req.Header)
 	return tr
 }
 
@@ -45,8 +45,8 @@ func (tr *Trace) WithResponse(resp *Response) *Trace {
 		return nil
 	}
 	tr.URL = resp.Request.RequestURI
-	tr.ReqHeaders = resp.Request.Header.Clone()
+	tr.ReqHeaders = gpHTTP.HeaderToMap(resp.Request.Header)
-	tr.RespHeaders = resp.Header.Clone()
+	tr.RespHeaders = gpHTTP.HeaderToMap(resp.Header)
 	tr.RespStatus = resp.StatusCode
 	return tr
 }
@@ -63,6 +63,18 @@ func (tr *Trace) With(what string, additional any) *Trace {
 	return tr
 }
 
+func (tr *Trace) WithError(err error) *Trace {
+	if tr == nil {
+		return nil
+	}
+
+	if tr.Additional == nil {
+		tr.Additional = map[string]any{}
+	}
+	tr.Additional["error"] = err.Error()
+	return tr
+}
+
 func (m *Middleware) EnableTrace() {
 	m.trace = true
 	for _, child := range m.children {

mtrace.json

@@ -0,0 +1,95 @@
+[
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "authentik-server",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "authentik",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "testMRInner",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "testMR",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "gp-test",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "immich-shared",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "immich",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "authentik",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "whoami",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:16",
+    "caller": "it-tools",
+    "msg": "middleware created"
+  },
+  {
+    "time": "2024-10-06 05:53:21",
+    "caller": "whoami.authentik.authentik[0]",
+    "msg": "forward auth request",
+    "req_headers": {
+      "X-Forwarded-For": "10.0.1.2",
+      "X-Forwarded-Host": "whoami.i.sh",
+      "X-Forwarded-Method": "GET",
+      "X-Forwarded-Proto": "https",
+      "X-Forwarded-Uri": "/"
+    }
+  },
+  {
+    "time": "2024-10-06 05:53:21",
+    "caller": "whoami.authentik.authentik[0]",
+    "msg": "forward auth response",
+    "req_headers": {
+      "X-Forwarded-For": "10.0.1.2",
+      "X-Forwarded-Host": "whoami.i.sh",
+      "X-Forwarded-Method": "GET",
+      "X-Forwarded-Proto": "https",
+      "X-Forwarded-Uri": "/"
+    },
+    "resp_headers": {
+      "Content-Type": "text/html; charset=utf-8",
+      "Date": "Sat, 05 Oct 2024 21:53:21 GMT",
+      "Referrer-Policy": "same-origin",
+      "Vary": "Accept-Encoding",
+      "X-Authentik-Id": "22e0c95971dc4c1b8033725c6988abc9",
+      "X-Content-Type-Options": "nosniff",
+      "X-Frame-Options": "DENY",
+      "X-Powered-By": "authentik"
+    },
+    "resp_status": 404
+  },
+  {
+    "time": "2024-10-06 05:53:21",
+    "caller": "whoami.authentik.authentik[0]",
+    "msg": "failed to get location from https://authentik.i.sh/outpost.goauthentik.io/auth/traefik",
+    "additional": {
+      "error": "http: no Location header in response"
+    }
+  }
+]