Issue #80: bugfixes

* Add integration test
* Fix upstream_uri and upstream_url values
* Fix request_url value

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
 	}

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)

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
 }
 

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 ""

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,