Chris, I now know why this is happening.
In ServeHTTP in reverseproxy in the httputil package[1] we make a copy of
the incoming request for the outgoing request[2]. We then check[3] if the
incoming request have any "Hop-by-hop"[4] headers are set.
If they are set we assign the outgoing requests headers to a new Header
object[5], deep copy all the headers into it from the incoming request and
delete the Hop-by-hop headers.
After this we update the X-Forwarded-For header[6].
This effectively means that if the incoming request doesn't container any
of the hop-by-hop headers we will in step [6] update the incoming requests
X-Forwarded-For header as outrec.Header is a reference to rec.Header. But
in the case we do have a hop-by-hop header the inrec.Headers,
outrec.Headers will not be a reference and thus we get different logs when
we enter the defer in gorouter/proxy/proxy.go[7]
I have emailed Brad Fitzpatrick who was involved in writing the reverse
proxy to see if this is expected behaviour, to me it seems like a bug?
[1]
https://github.com/golang/go/blob/release-branch.go1.4/src/net/http/httputil/reverseproxy.go[2]
https://github.com/golang/go/blob/release-branch.go1.4/src/net/http/httputil/reverseproxy.go#L110[3]
https://github.com/golang/go/blob/release-branch.go1.4/src/net/http/httputil/reverseproxy.go#L125[4]
https://github.com/golang/go/blob/release-branch.go1.4/src/net/http/httputil/reverseproxy.go#L92[5]
https://github.com/golang/go/blob/release-branch.go1.4/src/net/http/httputil/reverseproxy.go#L127[6]
https://github.com/golang/go/blob/release-branch.go1.4/src/net/http/httputil/reverseproxy.go#L142[7]
https://github.com/cloudfoundry/gorouter/blob/master/proxy/proxy.go#L149On Thu, Aug 20, 2015 at 6:05 PM, Christopher Piraino <cpiraino(a)pivotal.io>
wrote:
Simon,
That is very interesting, nice investigation. I would have to do a little
digging to try and see what exactly is going on, but the fact that the
GoRouter is not setting the "X-Forwarded-For" header when keep-alive is
enabled sounds suspiciously similar to an issue with HaProxy
<http://comments.gmane.org/gmane.comp.web.haproxy/5419> where it was only
adding the x-forwarded-proto on the first request for a connection. Not
sure if this is actually similar though.
I took a quick look through golang's reverseproxy code and nothing jumped
out at me, I added a story in our backlog
<https://www.pivotaltracker.com/story/show/101692478> to investigate
further.
- Chris Piraino
On Thu, Aug 20, 2015 at 7:20 AM, Simon Johansson <simon(a)simonjohansson.com
wrote:
Disregarding F5/HAProxy comletely and going directly(10.230.18.134) to a
Gorouter also yields different results depending on the client.
$ curl -H "host:cf-env.domain.com" 10.230.18.134
$ wget --header=host:cf-env.domain.com -qO- 10.230.18.134
Results in the following gorouter logs
cf-env.domain.com - [20/08/2015:13:32:57 +0000] "GET / HTTP/1.1" 200 0
5576 "-" "curl/7.43.0" 172.21.27.221:41193
x_forwarded_for:"172.21.27.221" ...
cf-env.domain.com - [20/08/2015:13:35:47 +0000] "GET / HTTP/1.1" 200 0
5655 "-" "Wget/1.16.3 (linux-gnu)" 172.21.27.221:41218
x_forwarded_for:"-" ....
I.e when using curl the x_forwarded_for header is set, but when using
wget its not.
Doing a tcpdump on the gorouter we get these headers for the incoming
request.
GET / HTTP/1.1
host:cf-env.domain.com
User-Agent: curl/7.43.0
Accept: */*
GET / HTTP/1.1
User-Agent: Wget/1.16.3 (linux-gnu)
Accept: */*
Accept-Encoding: identity
host: cf-env.domain.com
Connection: Keep-Alive
As we can see there is two(well, three if you cound User-Agent) differing
headers, the wget request have the Accept-Encoding and Connection headers
whereas the curl request does not.
So, when going directly to a gorouter with curl(that previously set the
x_forwarded_for header) and setting the Connection header to Keep-Alive we
get this
$ curl -H "host:cf-env.domain.com" -H "Connection: Keep-Alive"
10.230.18.134
GET / HTTP/1.1
host:cf-env.domain.com
User-Agent: curl/7.43.0
Accept: */*
Connection: Keep-Alive
cf-env.domain.com - [20/08/2015:13:46:25 +0000] "GET /curl-keep-alive
HTTP/1.1" 404 0 18 "-" "curl/7.43.0" 172.21.27.221:41313
x_forwarded_for:"-" ...
So, Keep-Alive seems to be the difference between getting x_forwarded_for
set or not in this case.
Interestingly, when hitting an app with either wget or curl via
HAProxy(that both logs x_forwarded_for: sourceIP, HAProxyIP) we can see the
headers for the requests on the Gorouter have Connection unset.
$ # On my machine
$ curl -H "host:cf-env.domain.com" 10.230.18.68/curl
$ curl -H "host:cf-env.domain.com" -H "Connection: Keep-Alive"
10.230.18.68/curl-keep-alive-set
$ wget --header=host:cf-env.domain.com -qO- 10.230.18.68/wget
$ # Tcpdump on HAProxy
GET /curl HTTP/1.1
host: cf-env.domain.com
User-Agent: curl/7.43.0
Accept: */*
GET /curl-keep-alive-set HTTP/1.1
host: cf-env.domain.com
User-Agent: curl/7.43.0
Accept: */*
Connection: Keep-Alive
GET /wget HTTP/1.1
User-Agent: Wget/1.16.3 (linux-gnu)
Accept: */*
Accept-Encoding: identity
host: cf-env.domain.com
Connection: Keep-Alive
$ # Tcpdump on Gorouter
GET /curl HTTP/1.1
User-Agent: curl/7.43.0
Accept: */*
host: cf-env.domain.com
X-Forwarded-Proto: http
X-Forwarded-For: 172.21.27.221
GET /curl-keep-alive-set HTTP/1.1
User-Agent: curl/7.43.0
Accept: */*
host: cf-env.domain.com
X-Forwarded-Proto: http
X-Forwarded-For: 172.21.27.221
GET /wget HTTP/1.1
User-Agent: Wget/1.16.3 (linux-gnu)
Accept: */*
Accept-Encoding: identity
host: cf-env.domain.com
X-Forwarded-Proto: http
X-Forwarded-For: 172.21.27.221
$ cf logs cf-env
cf-env.domain.com - [20/08/2015:14:10:12 +0000] "GET /curl HTTP/1.1" 404
0 18 "-" "curl/7.43.0" 10.230.18.68:60573
x_forwarded_for:"172.21.27.221, 10.230.18.68" ...
cf-env.domain.com - [20/08/2015:14:10:17 +0000] "GET
/curl-keep-alive-set HTTP/1.1" 404 0 18 "-" "curl/7.43.0"
10.230.18.68:60594 x_forwarded_for:"172.21.27.221, 10.230.18.68" ...
cf-env.domain.com - [20/08/2015:14:10:22 +0000] "GET /wget HTTP/1.1" 404
0 18 "-" "Wget/1.16.3 (linux-gnu)" 10.230.18.68:60615
x_forwarded_for:"172.21.27.221, 10.230.18.68" ...
So it seems HAProxy is stripping the Connection header before forwarding
it to a Gorouter and that is why we dont get different x_forwarded_for ips
depending on client whereas we get different when using F5 as it doesnt
strip the Connection header.
