From 9d0ac0382c1455c5174b5edc548974058d7b8a1c Mon Sep 17 00:00:00 2001 From: Frank Schroeder Date: Thu, 30 Mar 2017 22:10:36 +0200 Subject: [PATCH] Issue #80: bugfixes * Add integration test * Fix upstream_uri and upstream_url values * Fix request_url value --- logger/logger.go | 3 +- logger/pattern.go | 20 ++++-- proxy/http_handler.go | 28 ++++++-- proxy/http_headers.go | 25 ++++--- proxy/http_integration_test.go | 126 +++++++++++++++++++++++++++++++-- proxy/http_proxy.go | 54 +++++++++++--- 6 files changed, 220 insertions(+), 36 deletions(-) diff --git a/logger/logger.go b/logger/logger.go index 80187edaf..80df4c07d 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -57,6 +57,7 @@ type Event struct { Start, End time.Time Req *http.Request Resp *http.Response + RequestURL *url.URL UpstreamAddr string UpstreamURL *url.URL } @@ -66,7 +67,7 @@ type HTTPLogger interface { } func New(w io.Writer, format string) (HTTPLogger, error) { - p, err := parse(format, fields) + p, err := parse(format, Fields) if err != nil { return nil, err } diff --git a/logger/pattern.go b/logger/pattern.go index 68fb3c77e..1168105b6 100644 --- a/logger/pattern.go +++ b/logger/pattern.go @@ -89,7 +89,7 @@ var shortMonthNames = []string{ "Dec", } -var fields = map[string]field{ +var Fields = map[string]field{ "$remote_addr": func(b *bytes.Buffer, e *Event) { b.WriteString(e.Req.RemoteAddr) }, @@ -109,7 +109,11 @@ var fields = map[string]field{ b.WriteString(e.Req.Proto) }, "$request_args": func(b *bytes.Buffer, e *Event) { - b.WriteString(e.Req.URL.RawQuery) + // cannot use e.Req.URL since it may have been modified + if e.RequestURL == nil { + return + } + b.WriteString(e.RequestURL.RawQuery) }, "$request_host": func(b *bytes.Buffer, e *Event) { b.WriteString(e.Req.Host) @@ -118,13 +122,21 @@ var fields = map[string]field{ b.WriteString(e.Req.Method) }, "$request_scheme": func(b *bytes.Buffer, e *Event) { - b.WriteString(e.Req.URL.Scheme) + // cannot use e.Req.URL since it may have been modified + if e.RequestURL == nil { + return + } + b.WriteString(e.RequestURL.Scheme) }, "$request_uri": func(b *bytes.Buffer, e *Event) { b.WriteString(e.Req.RequestURI) }, "$request_url": func(b *bytes.Buffer, e *Event) { - b.WriteString(e.Req.URL.String()) + // cannot use e.Req.URL since it may have been modified + if e.RequestURL == nil { + return + } + b.WriteString(e.RequestURL.String()) }, "$request_proto": func(b *bytes.Buffer, e *Event) { b.WriteString(e.Req.Proto) diff --git a/proxy/http_handler.go b/proxy/http_handler.go index d11d491c0..72c5705fa 100644 --- a/proxy/http_handler.go +++ b/proxy/http_handler.go @@ -7,16 +7,30 @@ import ( "time" ) -func newHTTPProxy(t *url.URL, tr http.RoundTripper, flush time.Duration) http.Handler { - rp := httputil.NewSingleHostReverseProxy(t) - rp.Transport = tr - rp.FlushInterval = flush - rp.Transport = &transport{tr, nil} +func newHTTPProxy(target *url.URL, tr http.RoundTripper, flush time.Duration) http.Handler { + rp := &httputil.ReverseProxy{ + // this is a simplified director function based on the + // httputil.NewSingleHostReverseProxy() which does not + // mangle the request and target URL since the target + // URL is already in the correct format. + Director: func(req *http.Request) { + req.URL.Scheme = target.Scheme + req.URL.Host = target.Host + req.URL.Path = target.Path + req.URL.RawQuery = target.RawQuery + if _, ok := req.Header["User-Agent"]; !ok { + // explicitly disable User-Agent so it's not set to default value + req.Header.Set("User-Agent", "") + } + }, + FlushInterval: flush, + Transport: &transport{tr, nil}, + } return &httpHandler{rp} } -// responser exposes the response from an HTTP request. -type responser interface { +// responseKeeper exposes the response from an HTTP request. +type responseKeeper interface { response() *http.Response } diff --git a/proxy/http_headers.go b/proxy/http_headers.go index 7d0d70c7c..8a97ee257 100644 --- a/proxy/http_headers.go +++ b/proxy/http_headers.go @@ -45,16 +45,7 @@ func addHeaders(r *http.Request, cfg config.Proxy) error { } if r.Header.Get("X-Forwarded-Proto") == "" { - switch { - case ws && r.TLS != nil: - r.Header.Set("X-Forwarded-Proto", "wss") - case ws && r.TLS == nil: - r.Header.Set("X-Forwarded-Proto", "ws") - case r.TLS != nil: - r.Header.Set("X-Forwarded-Proto", "https") - default: - r.Header.Set("X-Forwarded-Proto", "http") - } + r.Header.Set("X-Forwarded-Proto", scheme(r)) } if r.Header.Get("X-Forwarded-Port") == "" { @@ -91,6 +82,20 @@ func addHeaders(r *http.Request, cfg config.Proxy) error { return nil } +func scheme(r *http.Request) string { + ws := r.Header.Get("Upgrade") == "websocket" + switch { + case ws && r.TLS != nil: + return "wss" + case ws && r.TLS == nil: + return "ws" + case r.TLS != nil: + return "https" + default: + return "http" + } +} + func localPort(r *http.Request) string { if r == nil { return "" diff --git a/proxy/http_integration_test.go b/proxy/http_integration_test.go index c27d38ff5..133fc81bd 100644 --- a/proxy/http_integration_test.go +++ b/proxy/http_integration_test.go @@ -3,16 +3,22 @@ package proxy import ( "bytes" "compress/gzip" + "fmt" + "net" "net/http" "net/http/httptest" "net/url" "os" "regexp" + "sort" + "strings" "testing" + "time" "github.com/eBay/fabio/config" "github.com/eBay/fabio/logger" "github.com/eBay/fabio/route" + "github.com/pascaldekloe/goe/verify" ) func TestProxyProducesCorrectXffHeader(t *testing.T) { @@ -26,8 +32,7 @@ func TestProxyProducesCorrectXffHeader(t *testing.T) { Config: config.Proxy{LocalIP: "1.1.1.1", ClientIPHeader: "X-Forwarded-For"}, Transport: http.DefaultTransport, Lookup: func(r *http.Request) *route.Target { - tbl, _ := route.NewTable("route add srv / " + server.URL) - return tbl.Lookup(r, "", route.Picker["rr"], route.Matcher["prefix"]) + return &route.Target{URL: mustParse(server.URL)} }, } req := makeReq("/") @@ -84,6 +89,111 @@ func TestProxyStripsPath(t *testing.T) { } } +func TestProxyLogOutput(t *testing.T) { + // build a format string from all log fields and one header field + fields := []string{"header.X-Foo:$header.X-Foo"} + for k := range logger.Fields { + fields = append(fields, k[1:]+":"+k) + } + sort.Strings(fields) + format := strings.Join(fields, ";") + + // create a logger + var b bytes.Buffer + l, err := logger.New(&b, format) + if err != nil { + t.Fatal("logger.New: ", err) + } + + // create an upstream server + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + fmt.Fprint(w, "foo") + })) + defer server.Close() + + // create a proxy handler with mocked time + tm := time.Date(2016, 1, 1, 0, 0, 0, 12345678, time.UTC) + proxy := &HTTPProxy{ + Time: func() time.Time { + defer func() { tm = tm.Add(1111111111 * time.Nanosecond) }() + return tm + }, + Transport: http.DefaultTransport, + Lookup: func(r *http.Request) *route.Target { + return &route.Target{URL: mustParse(server.URL)} + }, + Logger: l, + } + + // start an http server with the proxy handler + // which captures some parameters from the request + var remoteAddr string + proxyServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + remoteAddr = r.RemoteAddr + proxy.ServeHTTP(w, r) + })) + defer proxyServer.Close() + + // create the request + rawurl := proxyServer.URL + "/foo?x=y" + req, _ := http.NewRequest("GET", rawurl, nil) + req.Host = "example.com" + req.Header.Set("X-Foo", "bar") + + // execute the request + resp, err := http.DefaultClient.Do(req) + if err != nil { + t.Fatal("http.Get: ", err) + } + if resp.StatusCode != 200 { + t.Fatal("http.Get: want 200 got ", resp.StatusCode) + } + + upstreamURL, _ := url.Parse(server.URL) + upstreamHost, upstreamPort, _ := net.SplitHostPort(upstreamURL.Host) + remoteHost, remotePort, _ := net.SplitHostPort(remoteAddr) + want := []string{ + "header.X-Foo:bar", + "remote_addr:" + remoteAddr, + "remote_host:" + remoteHost, + "remote_port:" + remotePort, + "request:GET /foo?x=y HTTP/1.1", + "request_args:x=y", + "request_host:example.com", + "request_method:GET", + "request_proto:HTTP/1.1", + "request_scheme:http", + "request_uri:/foo?x=y", + "request_url:http://example.com/foo?x=y", + "response_body_size:3", + "response_status:200", + "response_time_ms:1.111", + "response_time_ns:1.111111111", + "response_time_us:1.111111", + "time_common:01/Jan/2016:00:00:01 +0000", + "time_rfc3339:2016-01-01T00:00:01Z", + "time_rfc3339_ms:2016-01-01T00:00:01.123Z", + "time_rfc3339_ns:2016-01-01T00:00:01.123456789Z", + "time_rfc3339_us:2016-01-01T00:00:01.123456Z", + "time_unix_ms:1451606401123", + "time_unix_ns:1451606401123456789", + "time_unix_us:1451606401123456", + "upstream_addr:" + upstreamURL.Host, + "upstream_host:" + upstreamHost, + "upstream_port:" + upstreamPort, + "upstream_request_scheme:" + upstreamURL.Scheme, + "upstream_request_uri:/foo?x=y", + "upstream_request_url:" + upstreamURL.String() + "/foo?x=y", + } + + data := string(b.Bytes()) + data = data[:len(data)-1] // strip \n + got := strings.Split(data, ";") + sort.Strings(got) + + verify.Values(t, "", got, want) +} + func TestProxyGzipHandler(t *testing.T) { tests := []struct { desc string @@ -148,8 +258,7 @@ func TestProxyGzipHandler(t *testing.T) { }, Transport: http.DefaultTransport, Lookup: func(r *http.Request) *route.Target { - tbl, _ := route.NewTable("route add srv / " + server.URL) - return tbl.Lookup(r, "", route.Picker["rr"], route.Matcher["prefix"]) + return &route.Target{URL: mustParse(server.URL)} }, } req := makeReq("/") @@ -188,8 +297,17 @@ func gzipHandler(contentType string) http.HandlerFunc { } } +func mustParse(rawurl string) *url.URL { + u, err := url.Parse(rawurl) + if err != nil { + panic(err) + } + return u +} + func makeReq(path string) *http.Request { return &http.Request{ + Method: "GET", RemoteAddr: "2.2.2.2:666", Header: http.Header{}, RequestURI: path, diff --git a/proxy/http_proxy.go b/proxy/http_proxy.go index 0de522c65..4288bccea 100644 --- a/proxy/http_proxy.go +++ b/proxy/http_proxy.go @@ -2,6 +2,7 @@ package proxy import ( "net/http" + "net/url" "strconv" "strings" "time" @@ -18,6 +19,10 @@ type HTTPProxy struct { // Config is the proxy configuration as provided during startup. Config config.Proxy + // Time returns the current time as the number of seconds since the epoch. + // If Time is nil, HTTPProxy uses time.Now. + Time func() time.Time + // Transport is the http connection pool configured with timeouts. // The proxy will panic if this value is nil. Transport http.RoundTripper @@ -53,12 +58,33 @@ func (p *HTTPProxy) ServeHTTP(w http.ResponseWriter, r *http.Request) { return } + // build the request url since r.URL will get modified + // by the reverse proxy and contains only the RequestURI anyway + requestURL := &url.URL{ + Scheme: scheme(r), + Host: r.Host, + Path: r.URL.Path, + RawQuery: r.URL.RawQuery, + } + + // build the real target url that is passed to the proxy + targetURL := &url.URL{ + Scheme: t.URL.Scheme, + Host: t.URL.Host, + Path: r.URL.Path, + } + if t.URL.RawQuery == "" || r.URL.RawQuery == "" { + targetURL.RawQuery = t.URL.RawQuery + r.URL.RawQuery + } else { + targetURL.RawQuery = t.URL.RawQuery + "&" + r.URL.RawQuery + } + // TODO(fs): The HasPrefix check seems redundant since the lookup function should // TODO(fs): have found the target based on the prefix but there may be other // TODO(fs): matchers which may have different rules. I'll keep this for // TODO(fs): a defensive approach. if t.StripPath != "" && strings.HasPrefix(r.URL.Path, t.StripPath) { - r.URL.Path = r.URL.Path[len(t.StripPath):] + targetURL.Path = targetURL.Path[len(t.StripPath):] } upgrade, accept := r.Header.Get("Upgrade"), r.Header.Get("Accept") @@ -66,40 +92,48 @@ func (p *HTTPProxy) ServeHTTP(w http.ResponseWriter, r *http.Request) { var h http.Handler switch { case upgrade == "websocket" || upgrade == "Websocket": - h = newRawProxy(t.URL) + h = newRawProxy(targetURL) case accept == "text/event-stream": // use the flush interval for SSE (server-sent events) // must be > 0s to be effective - h = newHTTPProxy(t.URL, p.Transport, p.Config.FlushInterval) + h = newHTTPProxy(targetURL, p.Transport, p.Config.FlushInterval) default: - h = newHTTPProxy(t.URL, p.Transport, time.Duration(0)) + h = newHTTPProxy(targetURL, p.Transport, time.Duration(0)) } if p.Config.GZIPContentTypes != nil { h = gzip.NewGzipHandler(h, p.Config.GZIPContentTypes) } - start := time.Now() + timeNow := p.Time + if timeNow == nil { + timeNow = time.Now + } + + start := timeNow() h.ServeHTTP(w, r) if p.Requests != nil { p.Requests.UpdateSince(start) } - t.Timer.UpdateSince(start) + if t.Timer != nil { + t.Timer.UpdateSince(start) + } - if hr, ok := h.(responser); ok { + if hr, ok := h.(responseKeeper); ok { if resp := hr.response(); resp != nil { name := key(resp.StatusCode) metrics.DefaultRegistry.GetTimer(name).UpdateSince(start) if p.Logger != nil { p.Logger.Log(&logger.Event{ Start: start, - End: time.Now(), + End: timeNow(), Req: r, Resp: resp, - UpstreamAddr: t.URL.Host, - UpstreamURL: t.URL, + RequestURL: requestURL, + UpstreamAddr: targetURL.Host, + UpstreamURL: targetURL, }) } }