Caddy: upstream placeholder didn't work

[Barbers]

Hello,

I traced down a little issue of the combination from header, log and proxy.
When using header the upstream placeholder changes to - .
More details are figured out with the help of Whitestrake in the community under caddy.community

1. What version of Caddy are you using (caddy -version)?

0,11,0 and 0,11,3

2. What are you trying to do?

Syslog my api gateway.

3. What is your entire Caddyfile?

:2015 {
proxy / localhost:2016
header / Access-Control-Allow-Origin *
log / stdout “{common} /// {upstream}”
}
:2016 {
status 200 /
}

4. How did you run Caddy (give the full command and describe the execution environment)?

./caddy

5. Please paste any relevant HTTP request(s) here.

curl -I localhost:2015

6. What did you expect to see?

::1 - - [11/Feb/2019:11:25:01 +1000] "HEAD / HTTP/1.1" 200 0 /// http://localhost:2016

7. What did you see instead (give full error messages and/or log)?

::1 - - [11/Feb/2019:11:25:01 +1000] "HEAD / HTTP/1.1" 200 0 /// -

8. How can someone who is starting from scratch reproduce the bug as minimally as possible?

write the config example to the Caddyfile, start caddy and make the request.

[whitestrake]

Looking at the code...

The log directive goes first, attaches a Replacer to the ResponseRecorder that each successive directive can add placeholders to (such as proxy adding {upstream}): https://github.com/mholt/caddy/blob/1867ded14c82cd2ab296df8d783bbc880360d37d/caddyhttp/log/log.go#L47-L50

It sends the ResponseRecorder on as the ResponseWriter for subsequent middleware.

At a glance, I'd thought that header was actually wrapping the ResponseRecorder in a ResponseWriterWrapper with its own new Replacer: https://github.com/mholt/caddy/blob/1867ded14c82cd2ab296df8d783bbc880360d37d/caddyhttp/header/header.go#L37-L40

But I don't think that's actually the case, the wrapper doesn't actually hold anything but a ResponseWriter and a couple of functions. The new Replacer is only used to add a few headers to the ResponseWriter as far as I can tell.

So, later down the chain, the proxy code adds the replacement here: https://github.com/mholt/caddy/blob/1867ded14c82cd2ab296df8d783bbc880360d37d/caddyhttp/proxy/proxy.go#L189-L191

Is the issue here that the check is failing because w is not a (*httpserver.ResponseRecorder) type, but instead a (*httpserver.ResponseWriterWrapper)?

[francislavoie]

Is #2449 related?

[whitestrake]

I don't _think_ so. The crux of this issue is the interaction of proxy's addition to the Replacer provided by the log directive, and specifically only seems to be triggered by the presence of the header directive, which wraps the ResponseWriter between log and proxy in the middleware chain.

2449 doesn't seem to have header interacting with the issue and they're hardcoding the hostname in the header_upstream subdirective; no Replacer issues to worry about.

[whitestrake]

I've got a fix in code, but it's awful, in my opinion.

What header is doing is wrapping the http.ResponseWriter it gets in a httpserver.ResponseWriterWrapper, and wrapping _that_ in a header.responseWriterWrapper.

It wouldn't be an issue if I could assert w to be either of the latter types (because then I could have the proxy their wrapped ResponseWriter directly and assert it to be a ResponseRecorder).

But it's not a httpserver.ResponseWriterWrapper, and I can't assert an unexported type (i.e. header.responseWriterWrapper)

So at the moment, the fix is to export header.ResponseWriterWrapper, then in the proxy code, assert it to be as such, check its ResponseWriter for the ResponseRecorder type, and continue as normal.

[mholt]

What if we invert how header wraps the response writer?

So instead of:

rww := &responseWriterWrapper{
    ResponseWriterWrapper: &httpserver.ResponseWriterWrapper{ResponseWriter: w},
}

do:

rww := responseWriterWrapper{w}
httpserverRww := &httpserver.ResponseWriterWrapper{ResponseWriter: rww}

Will that majorly break anything?

[whitestrake]

I gave it a shot and came across a bevvy of errors. To put w in one directly, the responseWriterWrapper would need to embed a http.ResponseWriter instead of a http.ResponseWriterWrapper and therefore fails the httpserver.HTTPInterfaces guards. It seems like a rabbit hole to me.

[akawhy]

I come across this problem too and solve it by change the code

//if rr, ok := w.(*httpserver.ResponseRecorder); ok && rr.Replacer != nil {
//            rr.Replacer.Set("upstream", host.Name)
//}
replacer.Set("upstream", host.Name)

In this case, I think setting a custom upstream placeholder by a new replacer or the one in w is just the same.

[mwl]

Just want to chime in on this issue as well. We are seeing exactly the same behaviour, that the {upstream} is missing from the logs. And in addition that the {user} placeholder has been missing for quite some time too. Our complete log

  log / /var/log/caddy/status.humio.com.http.log "{remote} - {user} [{when}] \"{method} {uri} {proto}\" {status} {size} \"{>Referer}\" \"{>User-Agent}\" {latency_ms} {>Content-Length} \"{upstream}\" \"{<Server}\" \"{>Humio-Query-Session}\""
 {
    rotate_size 100
    rotate_age  7
    rotate_keep 100
  }

To be completely honest I don't know what we changed on our end, but I do know that it went away on 2010-02-19 on version 0.11.2. This morning I tried 0.11.1, 0.11.2 and 0.11.4, which all seem to behave the same in respect to missing {upstream} and {user}

[tobya]

@mwi

Would you be able to provide your full caddyfile block for this domain?

[mwl]

Sure, https://gist.github.com/mwl/1ad563fcfe2b6979deafcfe87b98cf7e

[tobya]

@mwl {user} is generally (and possibly exclusively) attached to basicauth which none of your domains are using. Do you know what was setting it before?

The upstream issue seems to be in progress.

[mwl]

In regards to {user}, I'm aware it's basic auth only. Our users only ship the username part of it though. So no passwords in the header.

We have the same configuration deployed across two load balancers where one is serving ops.humio.com and the other cloud.humio.com. Both of them have stopped replacing the {upstream} placeholder with other than -.

[mholt]

I'm pretty sure this is fixed in Caddy 2. (Logging has yet to be implemented but the placeholders should be working.) Give it a try! (see the v2 branch for now)