net/http: context cancellation race condition between http.Server, httputil.ReverseProxy and http.Transport

[labkode]

This is a new issue to re-open #20617

The problem is still there, and apt-get is still suffering from it.

What version of Go are you using (go version)?

go version go1.10.3 linux/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/root/go"
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build994157374=/tmp/go-build -gno-record-gcc-switches"
[root@cbox-redirector-02 cboxredirectd]#

What did you do?

Please read #20617 for the root of the problem.

apt-get install <pkg>
...

Need to get 7941 kB/54.5 MB of archives.
After this operation, 331 MB of additional disk space will be used.
Err:1 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5core5a 5.6.2-14+6.17
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:2 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5network5 5.6.2-14+6.17
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:3 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5gui5 5.6.2-14+6.17
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:4 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5widgets5 5.6.2-14+6.17
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:5 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5sql5 5.6.2-14+6.17
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:6 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-qtsvg5 5.6.2-1
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:7 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5keychain1 0.7.0-1+1.16
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:8 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  libcernboxsync0 2.4.1+oc-2352
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:9 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5xml5 5.6.2-14+6.17
  502  Bad Gateway [IP: 137.138.13.160 443]
Err:10 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  cernbox-client-l10n 2.4.1+oc-2352
  502  Bad Gateway [IP: 137.138.13.160 443]
Get:11 https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04  ocqt562+240-libqt5sql5-sqlite 5.6.2-14+6.17 [69.0 kB]
Fetched 69.0 kB in 0s (485 kB/s)
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5core5a_5.6.2-14+6.17_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5network5_5.6.2-14+6.17_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5gui5_5.6.2-14+6.17_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5widgets5_5.6.2-14+6.17_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5sql5_5.6.2-14+6.17_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-qtsvg5_5.6.2-1_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5keychain1_0.7.0-1+1.16_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/libcernboxsync0_2.4.1+oc-2352_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/amd64/ocqt562+240-libqt5xml5_5.6.2-14+6.17_amd64.deb  502  Bad Gateway [IP: 137.138.13.160 443]
E: Failed to fetch https://example.org/cernbox/doc/Linux/repo/Ubuntu_18.04/all/cernbox-client-l10n_2.4.1+oc-2352_all.deb  502  Bad Gateway [IP: 137.138.13.160 443]

result in

Jul 17 10:27:36 cbox-redirector-02 cboxredirectd: 2018/07/17 10:27:36 http: proxy error: context canceled
Jul 17 10:27:36 cbox-redirector-02 cboxredirectd: 2018/07/17 10:27:36 http: proxy error: context canceled
Jul 17 10:27:36 cbox-redirector-02 cboxredirectd: 2018/07/17 10:27:36 http: proxy error: context canceled
Jul 17 10:28:51 cbox-redirector-02 cboxredirectd: 2018/07/17 10:28:51 http: proxy error: context canceled
Jul 17 10:28:51 cbox-redirector-02 cboxredirectd: 2018/07/17 10:28:51 http: proxy error: context canceled
Jul 17 10:28:51 cbox-redirector-02 cboxredirectd: 2018/07/17 10:28:51 http: proxy error: context canceled
Jul 17 10:28:51 cbox-redirector-02 cboxredirectd: 2018/07/17 10:28:51 http: proxy error: context canceled

There are three workarounds for this issue:

Add a custom director: Thanks to @rgeronimi

// See https://github.com/golang/go/issues/26414
func director(req *http.Request) {
        // apply hack only to GET requests, as we have only seen these type of reqs from apt-get.
        if req.Method == "GET" {
                quietReq := req.WithContext(context.Background())
                *req = *quietReq
        }
}

Disable keep-alives on the server

server.SetKeepAlivesEnabled(false)

Disable closeNotify method if method is GET for HTTP pipelining: Thanks to @juliens

@juliens disabled the closeNotify logic for the traefik proxy here: traefik/traefik#3108

@bradfitz What do you think about disabling the closeNotify mechanism for pipelined GET requests?

        // If the protocol is HTTP/1.1 and CloseNotify is called while
        // processing an idempotent request (such a GET) while
        // HTTP/1.1 pipelining is in use, the arrival of a subsequent
        // pipelined request may cause a value to be sent on the
        // returned channel. In practice HTTP/1.1 pipelining is not
        // enabled in browsers and not seen often in the wild. If this
        // is a problem, use HTTP/2 or only use CloseNotify on methods
        // such as POST.

From my point of view I would consider apt-get as an important client.

Thanks

[juliens]

This is already fixed in master ( #23921 ).

[davecheney]

Duplicate of #23921.