Change in proxy config not reflected by in-process restart (http2 keep-alive connection not closed)

[tpng]

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

master

2. What are you trying to do?

Reload Caddyfile with new proxy setting with USR1 using in-process restart.

3. What is your entire Caddyfile?

Before:

www.example.com (domain must be served on https, e.g. let's encrypt)

proxy / www.google.com {
        proxy_header Host {host}
        proxy_header X-Real-IP {remote}
        proxy_header X-Forwarded-For {remote}
        proxy_header X-Forwarded-Proto {scheme}
}

After:

www.example.com

proxy / www.yahoo.com {
        proxy_header Host {host}
        proxy_header X-Real-IP {remote}
        proxy_header X-Forwarded-For {remote}
        proxy_header X-Forwarded-Proto {scheme}
}

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

caddy

5. What did you expect to see?

After kill -USR1 on caddy pid, should show error page of Yahoo instead of Google.

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

Still showing error page of Google.

7. How can someone who is starting from scratch reproduce this behavior as minimally as possible?

1. Start caddy with Caddyfile proxying Google
2. Change Caddyfile to proxy Yahoo
3. kill -USR1 CADDY_PID
4. Observe caddy still proxying Google

[tpng]

It seems on the first reload in the browser it will still proxy Google, but if I reload the page again it will proxy Yahoo.

@alexex
Can you please confirm if this is the same behavior you encounter in #806 ?

[alexanderjulo]

For me refreshing did not change anything as far as I remember, I would still encounter a 502, maybe because of the returned status code?

[tpng]

Ah, seems Firefox is caching the result.
With curl the proxy is returning the correct page after Caddy reload.

[tpng]

@alexex
Could you try to use curl in your case and see if the result is different?

[abiosoft]

I've used that signal couple of times and I do not have this issue. I hope its not a browser caching issue. You may want to try curl, multiple browsers and private windows.

[tpng]

It seems it is not a browser caching issue.

In my test case I setup 2 instances of caddy to be proxied, one listening on port 8081 and another on 8082.
If I change the Caddyfile (listening on https with Let's encrypt) to proxy 8082 instead of 8081, there are 2 different behaviors from browser and curl.

curl: the request is sent correctly to 8082 (request in log of 8082)

browser: in the same tab, disabling cache & reloading will still send request to 8081. (request in log of 8081)
Only if I open a new private window in Chrome will the request send correctly to 8082.
Private window in Firefox still send to 8081.

[tpng]

Since the issue only occurs with in-process restart, I guess it has something to do with keep-alive connections.

[mholt]

The reload can take up to 5 seconds (to kill keep-alive connections) -- did you wait 5 seconds before trying again?

(FWIW I cannot reproduce as long as I disable my browser cache.)

[alexanderjulo]

So I do not know why exactly but even after a few minutes while curl reliably returns the new proxy on chrome I still get a 502, even when I have the inspector open and disable caching there. While when I try it in an anonymous windows it seems to work. Something very funky seems to be going on here, but I have no idea what it is.

[tpng]

It seems the issue is only reproducible on http2 enabled servers. (served on https and with browser supporting http2).

[tpng]

With caddy -http2=false, Caddy behaves as @mholt stated, the correct site is proxied after 5 seconds.

[tpng]

Go currently does not provided a Close function for a http2 server to ask browser to stop using the connection.

A workaround seems to be using the Server.ConnState hook to close the idle connection ourselves.
At https://github.com/mholt/caddy/blob/master/server/server.go#L248, change to

func (s *Server) Stop() (err error) {
    s.Server.SetKeepAlivesEnabled(false)
    s.Server.ConnState = func(c net.Conn, cs http.ConnState) {
        if cs == http.StateIdle {
            c.Close()
        }
    }
    // ...
}

Although the browser will fail on the first request when they try to reuse the connection after Caddy restart, the next request will use the updated proxy.

[elcore]

Well done Sherlock, well done 😄 @tpng

[mholt]

Good to know; I'm not sure if this is a "hack" or behavior I want to introduce into Caddy at this time, but thank you for finding it out! Will probably reference this in the future.

[alexanderjulo]

@mholt I would actually still consider this a bug or at least an open question: even after a few hours and deleting the cache and everything my chrome still gives me a bad gateway error while if I open the site in anonymous mode it still works fine. Something very weird is going on.

[alexanderjulo]

So far the only way I found to fix this in chrome is to restart it entirely, after which it will work correctly. Not even closing the tab and re-opening it works. The very same applies to Firefox. @tpng will these browsers keep these connections open indefinitely? Is there any way for these users to get the site working again without completely restarting their browsers?

[tpng]

I think you will have to pass -http2=false to Caddy until the issue is fixed if this concerns you.
The http2 spec requires browser to keep a single persistent connection to the same host:port.
https://http2.github.io/http2-spec/index.html#rfc.section.9.1

[alexanderjulo]

Okay, that's very interesting. I had no idea they would take the persistence so serious as to not close them until I close my browser. Well, that is definitely not a good way to treat my users, as they might be stuck on this connection pretty much forever.

In that case I do think from a usability perspective on caddy's site, there are two options: either (1) caddy has to update the configuration for this connection so that without closing the connection the right proxy is checked or (2) the connection has to be closed by caddy, which according to the specs you linked would be valid behavior:

[...] or until the server closes the connection.

Otherwise some users might be stuck with an invalid connection pretty much forever (how often do you restart your browser?). I will use -http2=false as a workaround but I personally think this is a bug that would warrant some fixing as I do not want to force people who would be able to use http2 to use http1 when they can have all the new/nice stuff that http2 offers. Technically if we restart caddy completely (instead of reload) all these connections would be closed anyways, so I am happy with option 2. :-)

[elcore]

The GODEBUG variables are not covered by Go's API compatibility promise. HTTP/2 support was added in Go 1.6. Please report any issues instead of disabling HTTP/2 support: https://golang.org/s/http2bug

[alexanderjulo]

To be honest I do not really know enough about go, caddy and the eventual interdependencies here to report a bug on GO I think. You guys will probably have to decide where exactly this bug is situated and how it is to be solved, I can unfortunately offer only the usability perspective.

If I can do anything to help this, please let me know and I will try to help out as much as I can!

[tpng]

I hope it will get fixed in Go itself.
Since Go 1.7 is frozen already, it means we will have to wait till Go 1.8 for the fix to go in.
I think we need to consider if there are anything we can do in Caddy until then.

Edit:
Further digging found this issue which seems to provide a IdleTimeout function in stdlib for use with ConnState in Go 1.7.

[mholt]

I believe patches or bug fixes can be released between minor releases, for example 1.7.1. It depends how the Go team classifies this behavior.

The more of these edge case issues pop up the less inclined I am to want to try to maintain hacks/patches/fixes for them in Caddy rather than fix them at the source (realizing, of course, that browsers are part of the problem sometimes). This maintenance burden is prone to create errors and slow down progress on the rest of the project in the long run.

It's hard for me to make a decision on this until I can reproduce it, which I have not yet been able to do with the instructions given. 😞 It seems that others are able to reproduce this, but it's interesting to me that Caddy doesn't force-kill the connection after 5 seconds even with HTTP/2. When you do the reload, does the old Caddy process stay alive indefinitely and leave two running?

[tpng]

The issue is only reproducible with http2 and in-process restart, accessing with http2 enabled browser.
The old instance of server is kept alive due to the http2 connection not closed.
https://github.com/mholt/caddy/blob/master/server/server.go#L254
s.listener.Close() only stop new connections being made, the existing connection will still be used by the browser unless closed explicitly by the server or the browser.

[mholt]

Oh, right, I did remember to use in-process restart in my testing, but forgot about that when writing my comment.

What you say about connections staying open, but not accepting new ones, makes sense. We do, however, call s.Server.SetKeepAlivesEnabled(false) on Stop(), which I suppose does not affect HTTP/2 connections then.

[tpng]

Yes, since s.Server.SetKeepAlivesEnabled(false) only works on new connections made, which will not affect the single opened http2 connection.

[mholt]

I just barely noticed that in the linked issue above. 😄

Now that I understand this better, I'm not sure what to do at this point. We could just chalk it up to a bug in Go. I wonder how difficult it would be to submit a CL for this.

[alexanderjulo]

Well it would be great to fix/workaround this, if not alone to avoid what you can already see above: people disabling http2 because of this using go flags that are not officially supported, but I do not want to annoy anyone, so I will stop lobbying this and just note that I aswell disabled http2 for now, hoping that the flag will not be removed until this is fixed. :-)

[tpng]

-http2=false flag in Caddy is not using the GODEBUG variable, so no worries about that.