From 05f1743ecda070a9da675c230be2e18658241dfc Mon Sep 17 00:00:00 2001 From: Toby Chui Date: Wed, 2 Apr 2025 20:11:43 +0800 Subject: [PATCH] Fixed #681 - Fixed origin is not populated in log bug --- src/def.go | 5 ++- src/mod/dynamicproxy/Server.go | 19 ++++++---- src/mod/dynamicproxy/access.go | 2 +- src/mod/dynamicproxy/authProviders.go | 16 ++++---- src/mod/dynamicproxy/dynamicproxy.go | 2 +- src/mod/dynamicproxy/proxyRequestHandler.go | 41 ++++++++++----------- src/mod/dynamicproxy/ratelimit.go | 2 +- src/mod/info/logger/trafficlog.go | 8 ++-- 8 files changed, 50 insertions(+), 45 deletions(-) diff --git a/src/def.go b/src/def.go index 6090c35..a5fba8e 100644 --- a/src/def.go +++ b/src/def.go @@ -10,10 +10,11 @@ package main import ( "embed" "flag" - "imuslab.com/zoraxy/mod/auth/sso/authentik" "net/http" "time" + "imuslab.com/zoraxy/mod/auth/sso/authentik" + "imuslab.com/zoraxy/mod/access" "imuslab.com/zoraxy/mod/acme" "imuslab.com/zoraxy/mod/auth" @@ -43,7 +44,7 @@ import ( const ( /* Build Constants */ SYSTEM_NAME = "Zoraxy" - SYSTEM_VERSION = "3.2.0" + SYSTEM_VERSION = "3.2.1" DEVELOPMENT_BUILD = false /* Development: Set to false to use embedded web fs */ /* System Constants */ diff --git a/src/mod/dynamicproxy/Server.go b/src/mod/dynamicproxy/Server.go index 5f942cb..7c195e6 100644 --- a/src/mod/dynamicproxy/Server.go +++ b/src/mod/dynamicproxy/Server.go @@ -48,7 +48,7 @@ func (h *ProxyHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { //Check if this is a redirection url if h.Parent.Option.RedirectRuleTable.IsRedirectable(r) { statusCode := h.Parent.Option.RedirectRuleTable.HandleRedirect(w, r) - h.Parent.logRequest(r, statusCode != 500, statusCode, "redirect", "") + h.Parent.logRequest(r, statusCode != 500, statusCode, "redirect", r.Host, "") return } @@ -79,7 +79,7 @@ func (h *ProxyHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { if sep.RequireRateLimit { err := h.handleRateLimitRouting(w, r, sep) if err != nil { - h.Parent.Option.Logger.LogHTTPRequest(r, "host", 307) + h.Parent.Option.Logger.LogHTTPRequest(r, "host", 307, r.Host, "") return } } @@ -110,7 +110,7 @@ func (h *ProxyHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { if potentialProxtEndpoint != nil && !potentialProxtEndpoint.Disabled { //Missing tailing slash. Redirect to target proxy endpoint http.Redirect(w, r, r.RequestURI+"/", http.StatusTemporaryRedirect) - h.Parent.Option.Logger.LogHTTPRequest(r, "redirect", 307) + h.Parent.Option.Logger.LogHTTPRequest(r, "redirect", 307, r.Host, "") return } } @@ -186,6 +186,9 @@ func (h *ProxyHandler) handleRootRouting(w http.ResponseWriter, r *http.Request) } } + //Do not log default site requests to avoid flooding the logs + //h.Parent.logRequest(r, false, 307, "root", domainOnly, "") + //No vdir match. Route via root router h.hostRequest(w, r, h.Parent.Root) case DefaultSite_Redirect: @@ -208,19 +211,19 @@ func (h *ProxyHandler) handleRootRouting(w http.ResponseWriter, r *http.Request) } hostname := parsedURL.Hostname() if hostname == domainOnly { - h.Parent.logRequest(r, false, 500, "root-redirect", domainOnly) + h.Parent.logRequest(r, false, 500, "root-redirect", domainOnly, "") http.Error(w, "Loopback redirects due to invalid settings", 500) return } - h.Parent.logRequest(r, false, 307, "root-redirect", domainOnly) + h.Parent.logRequest(r, false, 307, "root-redirect", domainOnly, "") http.Redirect(w, r, redirectTarget, http.StatusTemporaryRedirect) case DefaultSite_NotFoundPage: //Serve the not found page, use template if exists h.serve404PageWithTemplate(w, r) case DefaultSite_NoResponse: //No response. Just close the connection - h.Parent.logRequest(r, false, 444, "root-no_resp", domainOnly) + h.Parent.logRequest(r, false, 444, "root-no_resp", domainOnly, "") hijacker, ok := w.(http.Hijacker) if !ok { w.WriteHeader(http.StatusNoContent) @@ -234,11 +237,11 @@ func (h *ProxyHandler) handleRootRouting(w http.ResponseWriter, r *http.Request) conn.Close() case DefaultSite_TeaPot: //I'm a teapot - h.Parent.logRequest(r, false, 418, "root-teapot", domainOnly) + h.Parent.logRequest(r, false, 418, "root-teapot", domainOnly, "") http.Error(w, "I'm a teapot", http.StatusTeapot) default: //Unknown routing option. Send empty response - h.Parent.logRequest(r, false, 544, "root-unknown", domainOnly) + h.Parent.logRequest(r, false, 544, "root-unknown", domainOnly, "") http.Error(w, "544 - No Route Defined", 544) } } diff --git a/src/mod/dynamicproxy/access.go b/src/mod/dynamicproxy/access.go index de8f453..1845612 100644 --- a/src/mod/dynamicproxy/access.go +++ b/src/mod/dynamicproxy/access.go @@ -23,7 +23,7 @@ func (h *ProxyHandler) handleAccessRouting(ruleID string, w http.ResponseWriter, isBlocked, blockedReason := accessRequestBlocked(accessRule, h.Parent.Option.WebDirectory, w, r) if isBlocked { - h.Parent.logRequest(r, false, 403, blockedReason, "") + h.Parent.logRequest(r, false, 403, blockedReason, r.Host, "") } return isBlocked } diff --git a/src/mod/dynamicproxy/authProviders.go b/src/mod/dynamicproxy/authProviders.go index d7e8190..8099b55 100644 --- a/src/mod/dynamicproxy/authProviders.go +++ b/src/mod/dynamicproxy/authProviders.go @@ -31,22 +31,23 @@ and return a boolean indicate if the request is written to http.ResponseWriter - false: the request is not handled (usually means auth ok), continue to the next handler */ func handleAuthProviderRouting(sep *ProxyEndpoint, w http.ResponseWriter, r *http.Request, h *ProxyHandler) bool { + requestHostname := r.Host if sep.AuthenticationProvider.AuthMethod == AuthMethodBasic { err := h.handleBasicAuthRouting(w, r, sep) if err != nil { - h.Parent.Option.Logger.LogHTTPRequest(r, "host", 401) + h.Parent.Option.Logger.LogHTTPRequest(r, "host-http", 401, requestHostname, "") return true } } else if sep.AuthenticationProvider.AuthMethod == AuthMethodAuthelia { err := h.handleAutheliaAuth(w, r) if err != nil { - h.Parent.Option.Logger.LogHTTPRequest(r, "host", 401) + h.Parent.Option.Logger.LogHTTPRequest(r, "host-http", 401, requestHostname, "") return true } } else if sep.AuthenticationProvider.AuthMethod == AuthMethodAuthentik { err := h.handleAuthentikAuth(w, r) if err != nil { - h.Parent.Option.Logger.LogHTTPRequest(r, "host", 401) + h.Parent.Option.Logger.LogHTTPRequest(r, "host-http", 401, requestHostname, "") return true } } @@ -57,11 +58,8 @@ func handleAuthProviderRouting(sep *ProxyEndpoint, w http.ResponseWriter, r *htt /* Basic Auth */ func (h *ProxyHandler) handleBasicAuthRouting(w http.ResponseWriter, r *http.Request, pe *ProxyEndpoint) error { - err := handleBasicAuth(w, r, pe) - if err != nil { - h.Parent.logRequest(r, false, 401, "host", r.URL.Hostname()) - } - return err + //Wrapper for oop style + return handleBasicAuth(w, r, pe) } // Handle basic auth logic @@ -81,6 +79,7 @@ func handleBasicAuth(w http.ResponseWriter, r *http.Request, pe *ProxyEndpoint) if !ok { w.Header().Set("WWW-Authenticate", `Basic realm="Restricted"`) w.WriteHeader(401) + w.Write([]byte("401 - Unauthorized")) return errors.New("unauthorized") } @@ -100,6 +99,7 @@ func handleBasicAuth(w http.ResponseWriter, r *http.Request, pe *ProxyEndpoint) if !matchingFound { w.Header().Set("WWW-Authenticate", `Basic realm="Restricted"`) w.WriteHeader(401) + w.Write([]byte("401 - Unauthorized")) return errors.New("unauthorized") } diff --git a/src/mod/dynamicproxy/dynamicproxy.go b/src/mod/dynamicproxy/dynamicproxy.go index 677881a..f17181e 100644 --- a/src/mod/dynamicproxy/dynamicproxy.go +++ b/src/mod/dynamicproxy/dynamicproxy.go @@ -155,7 +155,7 @@ func (router *Router) StartProxyService() error { if err != nil { http.ServeFile(w, r, "./web/hosterror.html") router.Option.Logger.PrintAndLog("dprouter", "failed to get upstream for hostname", err) - router.logRequest(r, false, 404, "vdir-http", r.Host) + router.logRequest(r, false, 404, "vdir-http", r.Host, "") } endpointProxyRewriteRules := GetDefaultHeaderRewriteRules() diff --git a/src/mod/dynamicproxy/proxyRequestHandler.go b/src/mod/dynamicproxy/proxyRequestHandler.go index f4d8fea..fffc303 100644 --- a/src/mod/dynamicproxy/proxyRequestHandler.go +++ b/src/mod/dynamicproxy/proxyRequestHandler.go @@ -116,13 +116,13 @@ func (router *Router) rewriteURL(rooturl string, requestURL string) string { func (h *ProxyHandler) hostRequest(w http.ResponseWriter, r *http.Request, target *ProxyEndpoint) { r.Header.Set("X-Forwarded-Host", r.Host) r.Header.Set("X-Forwarded-Server", "zoraxy-"+h.Parent.Option.HostUUID) - + reqHostname := r.Host /* Load balancing */ selectedUpstream, err := h.Parent.loadBalancer.GetRequestUpstreamTarget(w, r, target.ActiveOrigins, target.UseStickySession) if err != nil { http.ServeFile(w, r, "./web/rperror.html") h.Parent.Option.Logger.PrintAndLog("proxy", "Failed to assign an upstream for this request", err) - h.Parent.logRequest(r, false, 521, "subdomain-http", r.URL.Hostname()) + h.Parent.logRequest(r, false, 521, "subdomain-http", r.URL.Hostname(), r.Host) return } @@ -144,7 +144,7 @@ func (h *ProxyHandler) hostRequest(w http.ResponseWriter, r *http.Request, targe if selectedUpstream.RequireTLS { u, _ = url.Parse("wss://" + wsRedirectionEndpoint + requestURL) } - h.Parent.logRequest(r, true, 101, "host-websocket", selectedUpstream.OriginIpOrDomain) + h.Parent.logRequest(r, true, 101, "host-websocket", reqHostname, selectedUpstream.OriginIpOrDomain) if target.HeaderRewriteRules == nil { target.HeaderRewriteRules = GetDefaultHeaderRewriteRules() @@ -161,12 +161,11 @@ func (h *ProxyHandler) hostRequest(w http.ResponseWriter, r *http.Request, targe return } - originalHostHeader := r.Host if r.URL != nil { r.Host = r.URL.Host } else { //Fallback when the upstream proxy screw something up in the header - r.URL, _ = url.Parse(originalHostHeader) + r.URL, _ = url.Parse(reqHostname) } //Populate the user-defined headers with the values from the request @@ -188,7 +187,7 @@ func (h *ProxyHandler) hostRequest(w http.ResponseWriter, r *http.Request, targe //Handle the request reverse proxy statusCode, err := selectedUpstream.ServeHTTP(w, r, &dpcore.ResponseRewriteRuleSet{ ProxyDomain: selectedUpstream.OriginIpOrDomain, - OriginalHost: originalHostHeader, + OriginalHost: reqHostname, UseTLS: selectedUpstream.RequireTLS, NoCache: h.Parent.Option.NoCache, PathPrefix: "", @@ -201,28 +200,28 @@ func (h *ProxyHandler) hostRequest(w http.ResponseWriter, r *http.Request, targe //validate the error var dnsError *net.DNSError + upstreamHostname := selectedUpstream.OriginIpOrDomain if err != nil { if errors.As(err, &dnsError) { http.ServeFile(w, r, "./web/hosterror.html") - h.Parent.logRequest(r, false, 404, "host-http", r.URL.Hostname()) + h.Parent.logRequest(r, false, 404, "host-http", reqHostname, upstreamHostname) } else if errors.Is(err, context.Canceled) { //Request canceled by client, usually due to manual refresh before page load http.Error(w, "Request canceled", http.StatusRequestTimeout) - h.Parent.logRequest(r, false, http.StatusRequestTimeout, "host-http", r.URL.Hostname()) + h.Parent.logRequest(r, false, http.StatusRequestTimeout, "host-http", reqHostname, upstreamHostname) } else { http.ServeFile(w, r, "./web/rperror.html") - h.Parent.logRequest(r, false, 521, "host-http", r.URL.Hostname()) + h.Parent.logRequest(r, false, 521, "host-http", reqHostname, upstreamHostname) } } - h.Parent.logRequest(r, true, statusCode, "host-http", r.URL.Hostname()) + h.Parent.logRequest(r, true, statusCode, "host-http", reqHostname, upstreamHostname) } // Handle vdir type request func (h *ProxyHandler) vdirRequest(w http.ResponseWriter, r *http.Request, target *VirtualDirectoryEndpoint) { rewriteURL := h.Parent.rewriteURL(target.MatchingPath, r.RequestURI) r.URL, _ = url.Parse(rewriteURL) - r.Header.Set("X-Forwarded-Host", r.Host) r.Header.Set("X-Forwarded-Server", "zoraxy-"+h.Parent.Option.HostUUID) @@ -242,7 +241,7 @@ func (h *ProxyHandler) vdirRequest(w http.ResponseWriter, r *http.Request, targe target.parent.HeaderRewriteRules = GetDefaultHeaderRewriteRules() } - h.Parent.logRequest(r, true, 101, "vdir-websocket", target.Domain) + h.Parent.logRequest(r, true, 101, "vdir-websocket", r.Host, target.Domain) wspHandler := websocketproxy.NewProxy(u, websocketproxy.Options{ SkipTLSValidation: target.SkipCertValidations, SkipOriginCheck: target.parent.EnableWebsocketCustomHeaders, //You should not use websocket via virtual directory. But keep this to true for compatibility @@ -254,12 +253,12 @@ func (h *ProxyHandler) vdirRequest(w http.ResponseWriter, r *http.Request, targe return } - originalHostHeader := r.Host + reqHostname := r.Host if r.URL != nil { r.Host = r.URL.Host } else { //Fallback when the upstream proxy screw something up in the header - r.URL, _ = url.Parse(originalHostHeader) + r.URL, _ = url.Parse(reqHostname) } //Populate the user-defined headers with the values from the request @@ -282,7 +281,7 @@ func (h *ProxyHandler) vdirRequest(w http.ResponseWriter, r *http.Request, targe //Handle the virtual directory reverse proxy request statusCode, err := target.proxy.ServeHTTP(w, r, &dpcore.ResponseRewriteRuleSet{ ProxyDomain: target.Domain, - OriginalHost: originalHostHeader, + OriginalHost: reqHostname, UseTLS: target.RequireTLS, PathPrefix: target.MatchingPath, UpstreamHeaders: upstreamHeaders, @@ -296,19 +295,19 @@ func (h *ProxyHandler) vdirRequest(w http.ResponseWriter, r *http.Request, targe if errors.As(err, &dnsError) { http.ServeFile(w, r, "./web/hosterror.html") log.Println(err.Error()) - h.Parent.logRequest(r, false, 404, "vdir-http", target.Domain) + h.Parent.logRequest(r, false, 404, "vdir-http", reqHostname, target.Domain) } else { http.ServeFile(w, r, "./web/rperror.html") log.Println(err.Error()) - h.Parent.logRequest(r, false, 521, "vdir-http", target.Domain) + h.Parent.logRequest(r, false, 521, "vdir-http", reqHostname, target.Domain) } } - h.Parent.logRequest(r, true, statusCode, "vdir-http", target.Domain) + h.Parent.logRequest(r, true, statusCode, "vdir-http", reqHostname, target.Domain) } // This logger collect data for the statistical analysis. For log to file logger, check the Logger and LogHTTPRequest handler -func (router *Router) logRequest(r *http.Request, succ bool, statusCode int, forwardType string, target string) { +func (router *Router) logRequest(r *http.Request, succ bool, statusCode int, forwardType string, originalHostname string, upstreamHostname string) { if router.Option.StatisticCollector != nil { go func() { requestInfo := statistic.RequestInfo{ @@ -320,10 +319,10 @@ func (router *Router) logRequest(r *http.Request, succ bool, statusCode int, for Referer: r.Referer(), UserAgent: r.UserAgent(), RequestURL: r.Host + r.RequestURI, - Target: target, + Target: originalHostname, } router.Option.StatisticCollector.RecordRequest(requestInfo) }() } - router.Option.Logger.LogHTTPRequest(r, forwardType, statusCode) + router.Option.Logger.LogHTTPRequest(r, forwardType, statusCode, originalHostname, upstreamHostname) } diff --git a/src/mod/dynamicproxy/ratelimit.go b/src/mod/dynamicproxy/ratelimit.go index 40dbc9b..a809cc9 100644 --- a/src/mod/dynamicproxy/ratelimit.go +++ b/src/mod/dynamicproxy/ratelimit.go @@ -51,7 +51,7 @@ func (t *RequestCountPerIpTable) Clear() { func (h *ProxyHandler) handleRateLimitRouting(w http.ResponseWriter, r *http.Request, pe *ProxyEndpoint) error { err := h.Parent.handleRateLimit(w, r, pe) if err != nil { - h.Parent.logRequest(r, false, 429, "ratelimit", r.URL.Hostname()) + h.Parent.logRequest(r, false, 429, "ratelimit", r.URL.Hostname(), "") } return err } diff --git a/src/mod/info/logger/trafficlog.go b/src/mod/info/logger/trafficlog.go index 640b09a..b5e555f 100644 --- a/src/mod/info/logger/trafficlog.go +++ b/src/mod/info/logger/trafficlog.go @@ -16,7 +16,7 @@ import ( // Log HTTP request. Note that this must run in go routine to prevent any blocking // in reverse proxy router -func (l *Logger) LogHTTPRequest(r *http.Request, reqclass string, statusCode int) { +func (l *Logger) LogHTTPRequest(r *http.Request, reqclass string, statusCode int, downstreamHostname string, upstreamHostname string) { go func() { l.ValidateAndUpdateLogFilepath() if l.logger == nil || l.file == nil { @@ -26,7 +26,9 @@ func (l *Logger) LogHTTPRequest(r *http.Request, reqclass string, statusCode int clientIP := netutils.GetRequesterIP(r) requestURI := r.RequestURI statusCodeString := strconv.Itoa(statusCode) - //fmt.Println("[" + time.Now().Format("2006-01-02 15:04:05.000000") + "] [router:" + reqclass + "] [client " + clientIP + "] " + r.Method + " " + requestURI + " " + statusCodeString) - l.logger.Println("[" + time.Now().Format("2006-01-02 15:04:05.000000") + "] [router:" + reqclass + "] [origin:" + r.URL.Hostname() + "] [client: " + clientIP + "] [useragent: " + r.UserAgent() + "] " + r.Method + " " + requestURI + " " + statusCodeString) + + //Pretty print for debugging + //fmt.Printf("------------\nRequest URL: %s (class: %s) \nUpstream Hostname: %s\nDownstream Hostname: %s\nStatus Code: %s\n", r.URL, reqclass, upstreamHostname, downstreamHostname, statusCodeString) + l.logger.Println("[" + time.Now().Format("2006-01-02 15:04:05.000000") + "] [router:" + reqclass + "] [origin:" + downstreamHostname + "] [client: " + clientIP + "] [useragent: " + r.UserAgent() + "] " + r.Method + " " + requestURI + " " + statusCodeString) }() }