Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

net/http: Requests with already canceled context are passed to Handlers #18449

Closed
artyom opened this issue Dec 28, 2016 · 4 comments
Closed

net/http: Requests with already canceled context are passed to Handlers #18449

artyom opened this issue Dec 28, 2016 · 4 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Milestone
Go1.8

Comments

@artyom
Copy link
Member

artyom commented Dec 28, 2016

Please answer these questions before submitting your issue. Thanks!

What did you do?

If possible, provide a recipe for reproducing the error.
A complete runnable program is good.
A link on play.golang.org is best.

Run this server: https://play.golang.org/p/s4dAekw0Tn — it listens 2 sockets and proxies requests from one address to another to ensure final endpoint receives requests via single connection.

This issue likely related to #18447

What did you expect to see?

~ ¶ for i in 1 2 3 ; do curl 'http://localhost:8080/?d=3s' ; done
ok
ok
ok

What did you see instead?

~ ¶ for i in 1 2 3 ; do curl 'http://localhost:8080/?d=3s' ; done
ok
context canceled
context canceled

Does this issue reproduce with the latest release (go1.7.4)?

No

System details

go version go1.8beta2 darwin/amd64
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/tmp/go:/Users/artyom/go"
GORACE=""
GOROOT="/Users/artyom/Library/go"
GOTOOLDIR="/Users/artyom/Library/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/lb/3rk8rqs53czgb4v35w_342xc0000gn/T/go-build942175264=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
GOROOT/bin/go version: go version go1.8beta2 darwin/amd64
GOROOT/bin/go tool compile -V: compile version go1.8beta2 X:framepointer
uname -v: Darwin Kernel Version 16.3.0: Thu Nov 17 20:23:58 PST 2016; root:xnu-3789.31.2~1/RELEASE_X86_64
ProductName:	Mac OS X
ProductVersion:	10.12.2
BuildVersion:	16C67
lldb --version: lldb-360.1.70
@bradfitz
Copy link
Contributor

Is this just a duplicate of #18447, or is this meant to be a bug report about httputil.ReverseProxy?

Please clarify.

@artyom
Copy link
Member Author

artyom commented Dec 28, 2016

It depends on whether #18447 is a regression from 1.7 or it's just a matter of documenting extra cancelation case in Request.Context() docs. If former, this bug is likely a duplicate, if latter, it's probably a separate issue — it seems that Handlers can receive Requests with already canceled context if multiple requests are sent via single http/1.1 keep-alive connection.

I'm able to reproduce this without httputil.ReverseProxy just using netcat against final endpoint (localhost:8081) as well.

@artyom
Copy link
Member Author

artyom commented Dec 28, 2016

Here's a better reproduction: https://play.golang.org/p/Y7MEdQY27J

go 1.7.4:

go1.7.4 ¶ go run repro.go 
2016/12/28 22:54:30 &{{0xc4201000e0}} new
2016/12/28 22:54:30 &{{0xc4201000e0}} active
2016/12/28 22:54:34 ok
2016/12/28 22:54:34 &{{0xc4201000e0}} idle
2016/12/28 22:54:34 &{{0xc4201000e0}} active
2016/12/28 22:54:35 ok
2016/12/28 22:54:35 &{{0xc4201000e0}} idle
2016/12/28 22:54:35 &{{0xc4201000e0}} active
2016/12/28 22:54:36 ok
2016/12/28 22:54:36 &{{0xc4201000e0}} idle

go1.8beta2:

go1.8beta2 ¶ go run repro.go 
2016/12/28 22:56:14 &{{0xc42006a070}} new
2016/12/28 22:56:14 &{{0xc42006a070}} active
2016/12/28 22:56:17 context canceled
2016/12/28 22:56:17 &{{0xc42006a070}} idle
2016/12/28 22:56:17 &{{0xc42006a070}} active
2016/12/28 22:56:17 context canceled
2016/12/28 22:56:17 &{{0xc42006a070}} idle
2016/12/28 22:56:17 &{{0xc42006a070}} active
2016/12/28 22:56:17 context canceled
2016/12/28 22:56:17 &{{0xc42006a070}} idle

@rsc
Copy link
Contributor

rsc commented Jan 4, 2017

Pretty sure #18447 is a behavior bug and those cancellations should not be coming through. In that case, this will be fixed by the same fix. Closing as dup of #18447.

@rsc rsc added this to the Go1.8 milestone Jan 4, 2017
@rsc rsc added the NeedsFix The path to resolution is known, but the work has not been done. label Jan 4, 2017
@rsc rsc closed this as completed Jan 4, 2017
@golang golang locked and limited conversation to collaborators Jan 4, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Milestone
Go1.8
Development

No branches or pull requests
4 participants
@bradfitz @artyom @rsc @gopherbot