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.

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: data race in closing and reading from expectContinueReader () #26253

Closed
Ewg-sha opened this issue Jul 6, 2018 · 6 comments
Closed

net/http: data race in closing and reading from expectContinueReader () #26253

Ewg-sha opened this issue Jul 6, 2018 · 6 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone
Go1.12

Comments

@Ewg-sha
Copy link

Ewg-sha commented Jul 6, 2018 •
edited

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

Go version: 1.10.3

Does this issue reproduce with the latest release?

yes

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

GOARCH="amd64"
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"

What did you do?

I need to cancel receiving of request body in http server's handle. I use background go routine which blocks on context's channel and closes request body once the channel is closed: request.Body.Close() (go/src/net/http/server.go:878 +0x40)

What did you expect to see?

Receiving of the request stops, no race.

What did you see instead?

==================
WARNING: DATA RACE
Write at 0x00c42000c1d8 by goroutine 53:
  net/http.(*expectContinueReader).Close()
      /local/home/bond/tools/go/src/net/http/server.go:878 +0x40
  prj/test/transfer.(*httpTransfer).Receive.func1()
    /wks/bond/prj/test/src/prj/test/transfer/server.go:193 +0x61
  prj/test/transfer.(*pendingRequest).CancelReceive()
    /wks/bond/prj/test/src/prj/test/transfer/server.go:372 +0x8d
  prj/test/transfer.(*serverTestSuite).TestReceiveAndCancel.func3()
    /wks/bond/prj/test/src/prj/test/transfer/transfer_test.go:232 +0x46
  github.com/stretchr/testify/assert.didPanic.func1()
      /home/bond/build/gopath/src/github.com/stretchr/testify/assert/assertions.go:791 +0x68
  github.com/stretchr/testify/assert.didPanic()
      /home/bond/build/gopath/src/github.com/stretchr/testify/assert/assertions.go:793 +0x5d
  github.com/stretchr/testify/assert.NotPanics()
      /home/bond/build/gopath/src/github.com/stretchr/testify/assert/assertions.go:833 +0x45
  prj/test/transfer.(*serverTestSuite).TestReceiveAndCancel()
    /wks/bond/prj/test/src/prj/test/transfer/transfer_test.go:232 +0x531
  runtime.call32()
      /local/home/bond/tools/go/src/runtime/asm_amd64.s:573 +0x3a
  reflect.Value.Call()
      /local/home/bond/tools/go/src/reflect/value.go:308 +0xc0
  github.com/stretchr/testify/suite.Run.func2()
      /home/bond/build/gopath/src/github.com/stretchr/testify/suite/suite.go:102 +0x2ff
  testing.tRunner()
      /local/home/bond/tools/go/src/testing/testing.go:777 +0x16d

Previous read at 0x00c42000c1d8 by goroutine 76:
  net/http.(*expectContinueReader).Read()
      /local/home/bond/tools/go/src/net/http/server.go:862 +0x40
  mime/multipart.(*stickyErrorReader).Read()
      /local/home/bond/tools/go/src/mime/multipart/multipart.go:124 +0x97
  bufio.(*Reader).fill()
      /local/home/bond/tools/go/src/bufio/bufio.go:100 +0x19f
  bufio.(*Reader).Peek()
      /local/home/bond/tools/go/src/bufio/bufio.go:132 +0x50
  mime/multipart.partReader.Read()
      /local/home/bond/tools/go/src/mime/multipart/multipart.go:177 +0x358
  mime/multipart.(*Part).Read()
      /local/home/bond/tools/go/src/mime/multipart/multipart.go:157 +0x75
  io.copyBuffer()
      /local/home/bond/tools/go/src/io/io.go:400 +0x172
  io.Copy()
      /local/home/bond/tools/go/src/io/io.go:362 +0x74
  prj/test/transfer.(*pendingRequest).Receive.func1()
    /wks/bond/prj/test/src/prj/test/transfer/server.go:350 +0x93
==================
@meirf
Copy link
Contributor

meirf commented Jul 7, 2018

I'm going to try to come up with code that matches your description, but it would really speed things up if you can submit standalone runnable code.

A complete runnable program is good.
A link on play.golang.org is best.

thanks!

@odeke-em odeke-em added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Jul 7, 2018
@Ewg-sha
Copy link
Author

Ewg-sha commented Jul 10, 2018

expectContinueReader struct has a race between methods Close and Read when accessing unprotected boolean "closed"

func (ecr *expectContinueReader) Close() error {
	ecr.closed = true
	return ecr.readCloser.Close()
}

and

func (ecr *expectContinueReader) Read(p []byte) (n int, err error) {
	if ecr.closed {
		return 0, ErrBodyReadAfterClose
	}
        ...
}

Is this race expected? Is there any safe way to abort http transfer on server side in net/http package?

@meirf
Copy link
Contributor

meirf commented Jul 11, 2018 •
edited

Thanks for the code. (I now see how obvious this was from your first comment.)

Can easily recreate this race by inserting

go func() {
    r.Body.Close()
}()

into TestServerExpect's httptest.NewServer (in server_test.go) and then running go test -race -run=TestServerExpect

I suppose an obvious band aid is to use a mutex. If sync.Mutex locking without contention implementation is fast (e.g. futex) then sync.Mutex should be fine.

I use background go routine which blocks on context's channel and closes request body once the channel is closed

Can you elaborate more on what this context is? Is it per request or supposed to live as long as the server?

Is there any safe way to abort http transfer on server side in net/http package?

I assume you've seen Server.ReadTimeout, Server.ReadHeaderTimeout and Server.Close(), but these aren't enough. Hopefully your answer to the question above will give us a better understanding.

@ianlancetaylor ianlancetaylor added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jul 11, 2018
@ianlancetaylor ianlancetaylor added this to the Go1.12 milestone Jul 11, 2018
@thinxer
Copy link

thinxer commented Dec 17, 2018 •
edited

I believe this issue is similar to #6995 (which is ancient). In
https://golang.org/cl/46570043 the fix was to add locking to http.body. http.expectContinueReader is, however, not protected yet.

If there are future implementations of http.Request.Body in addition to http.body and http.expectContinueReader, they should be goroutine-safe, too.

@agnivade agnivade added WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. and removed WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. labels Jan 7, 2019
@gopherbot
Copy link

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

@johnrengelman
Copy link

johnrengelman commented May 14, 2019 •
edited

We are seeing this in a reverse proxy under load on Go 1.12.4. Is there even a way to patch around this locally without fixing it in the core http package?

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x54640f]
goroutine 42721892 [running]:
bufio.(*Writer).Available(...)
/usr/local/Cellar/go/1.12.4/libexec/src/bufio/bufio.go:607
bufio.(*Writer).WriteString(0x0, 0xc002c3, 0x19, 0x0, 0x1, 0x2)
/usr/local/Cellar/go/1.12.4/libexec/src/bufio/bufio.go:688 +0x7f
net/http.(*expectContinueReader).Read(0xc292208b80, 0xc1b3b76000, 0x12c, 0x1000, 0x408c6c, 0xc00036c000, 0xb1f320)
/usr/local/Cellar/go/1.12.4/libexec/src/net/http/server.go:890 +0x13b
net/http.transferBodyReader.Read(0xc0ffdacaa0, 0xc1b3b76000, 0x12c, 0x1000, 0xb40040, 0xc014425d01, 0x0)
/usr/local/Cellar/go/1.12.4/libexec/src/net/http/transfer.go:62 +0x56
io.(*LimitedReader).Read(0xc2c1f0d560, 0xc1b3b76000, 0x1000, 0x1000, 0x0, 0x40bc00, 0xc2c1f0d560)
/usr/local/Cellar/go/1.12.4/libexec/src/io/io.go:448 +0x63
bufio.(*Writer).ReadFrom(0xc1884d4e40, 0xce7da0, 0xc2c1f0d560, 0x7f69df12f4e0, 0xc1884d4e40, 0x1201a01)
/usr/local/Cellar/go/1.12.4/libexec/src/bufio/bufio.go:722 +0xe5
io.copyBuffer(0xce6e00, 0xc1884d4e40, 0xce7da0, 0xc2c1f0d560, 0x0, 0x0, 0x0, 0x3, 0x1, 0xc050e1ad01)
/usr/local/Cellar/go/1.12.4/libexec/src/io/io.go:388 +0x2fc
io.Copy(...)
/usr/local/Cellar/go/1.12.4/libexec/src/io/io.go:364
net/http.(*transferWriter).writeBody(0xc0ffdacaa0, 0xce6e00, 0xc1884d4e40, 0x2, 0x2)
/usr/local/Cellar/go/1.12.4/libexec/src/net/http/transfer.go:369 +0x715
net/http.(*Request).write(0xc10994b600, 0xce6e00, 0xc1884d4e40, 0x0, 0xc0676a9d70, 0xc292208be0, 0x0, 0x0)
/usr/local/Cellar/go/1.12.4/libexec/src/net/http/request.go:655 +0x721
net/http.(*persistConn).writeLoop(0xc178578c60)
/usr/local/Cellar/go/1.12.4/libexec/src/net/http/transport.go:1961 +0x1b8
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.12.4/libexec/src/net/http/transport.go:1358 +0xb0d

@rosenhouse rosenhouse mentioned this issue Sep 11, 2019
Open
@mike1808 mike1808 mentioned this issue Oct 14, 2019
Closed
@golang golang locked and limited conversation to collaborators May 14, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Milestone
Go1.12
Development

No branches or pull requests
8 participants
@thinxer @johnrengelman @agnivade @meirf @ianlancetaylor @odeke-em @gopherbot @Ewg-sha