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

x/net/http2: data race in onSameConn test helper #37505

Closed
bcmills opened this issue Feb 27, 2020 · 4 comments
Closed

x/net/http2: data race in onSameConn test helper #37505

bcmills opened this issue Feb 27, 2020 · 4 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone
Unreleased

Comments

@bcmills
Copy link
Contributor

bcmills commented Feb 27, 2020 •
edited

https://build.golang.org/log/0d66aaa201ea31f6aa29c94ff8d6b76f67789071

==================
WARNING: DATA RACE
Read at 0x00c00015c163 by goroutine 315:
  testing.(*common).logDepth()
      /tmp/workdir/go/src/testing/testing.go:669 +0xa1
  testing.(*common).log()
      /tmp/workdir/go/src/testing/testing.go:662 +0x8f
  testing.(*common).Logf()
      /tmp/workdir/go/src/testing/testing.go:701 +0x21
  golang.org/x/net/http2.onSameConn.func2()
      /tmp/workdir/gopath/src/golang.org/x/net/http2/transport_test.go:196 +0x101
  net/http/httptest.(*Server).wrap.func1()
      /tmp/workdir/go/src/net/http/httptest/server.go:357 +0x121
  net/http.(*conn).setState()
      /tmp/workdir/go/src/net/http/server.go:1725 +0x155
  net/http.(*conn).serve.func1()
      /tmp/workdir/go/src/net/http/server.go:1777 +0xf8
  net/http.(*conn).serve()
      /tmp/workdir/go/src/net/http/server.go:1807 +0x1c10

Previous write at 0x00c00015c163 by goroutine 195:
  testing.tRunner.func1()
      /tmp/workdir/go/src/testing/testing.go:978 +0x467
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:996 +0x20d

Goroutine 315 (running) created at:
  net/http.(*Server).Serve()
      /tmp/workdir/go/src/net/http/server.go:2933 +0x5b6
  net/http/httptest.(*Server).goServe.func1()
      /tmp/workdir/go/src/net/http/httptest/server.go:308 +0xd3

Goroutine 195 (running) created at:
  testing.(*T).Run()
      /tmp/workdir/go/src/testing/testing.go:1043 +0x660
  testing.runTests.func1()
      /tmp/workdir/go/src/testing/testing.go:1300 +0xa6
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:992 +0x1eb
  testing.runTests()
      /tmp/workdir/go/src/testing/testing.go:1298 +0x57f
  testing.(*M).Run()
      /tmp/workdir/go/src/testing/testing.go:1210 +0x353
  main.main()
      _testmain.go:668 +0x223
==================
FAIL
FAIL	golang.org/x/net/http2	17.754s

The racing write is here:

go/src/testing/testing.go

Lines 976 to 978 in 7bb3317

// Do not lock t.done to allow race detector to detect race in case
// the user does not appropriately synchronizes a goroutine.
t.done = true

That comment suggests that the bug lies in the test itself:
https://github.com/golang/net/blob/0de0cce0169b09b364e001f108dc0399ea8630b3/http2/transport_test.go#L193-L198

	st := newServerTester(t, func(w http.ResponseWriter, r *http.Request) {
		io.WriteString(w, r.RemoteAddr)
	}, optOnlyServer, func(c net.Conn, st http.ConnState) {
		t.Logf("conn %v is now state %v", c.RemoteAddr(), st)
	})
	defer st.Close()

That, in turn, suggests that the serverTester is continuing to execute one of its callbacks after its Close method has already returned.

The callback is registered via the httptest.Server's Config.ConnState field:
https://github.com/golang/net/blob/0de0cce0169b09b364e001f108dc0399ea8630b3/http2/server_test.go#L118-L119

The (*serverTester).Close method explicitly closes its httptest.Server and its net.Conn.
https://github.com/golang/net/blob/0de0cce0169b09b364e001f108dc0399ea8630b3/http2/server_test.go#L256-L259

The documentation for (*httptest.Server).Close says that it “blocks until all outstanding requests on this server have completed.” However, it does not specify whether it blocks until the corresponding connections have been closed.

I would argue that (*httptest.Server).Close should block until the outstanding connections are completely closed, including any ConnState callbacks. However, there may be a shorter-term workaround we can apply in the x/net/http2 test in the interim. (I will file a separate issue for httptest.Server.)

CC @bradfitz @rsc @tombergan
@bcmills bcmills added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Testing An issue that has been verified to require only test changes, not just a test failure. labels Feb 27, 2020
@bcmills bcmills mentioned this issue Feb 27, 2020
Closed
@bcmills bcmills added this to the Unreleased milestone Feb 27, 2020
@rsc rsc mentioned this issue May 22, 2020
Open
@bcmills
Copy link
Contributor Author

bcmills commented Oct 19, 2020

2020-10-16T16:51:38-7b1cca2/windows-amd64-race
2020-09-27T03:25:02-5d4f700/freebsd-amd64-race
2020-09-27T03:25:02-5d4f700/windows-amd64-race
2020-08-13T13:45:08-3edf25e/freebsd-amd64-race
2020-07-07T03:43:11-ab34263/freebsd-amd64-race
2020-05-28T22:51:25-3c3fba1/windows-amd64-race
2020-05-20T18:23:14-0ba52f6/windows-amd64-race
2020-05-13T18:57:01-a91f071/windows-amd64-race
2020-04-25T23:01:54-ff2c4b7/freebsd-amd64-race
2020-03-24T14:37:07-d3edc99/freebsd-amd64-race
2020-03-19T23:41:17-63522db/freebsd-amd64-race
2020-02-22T12:55:58-5a598a2/windows-amd64-race
2020-02-19T18:36:55-4628272/freebsd-amd64-race
2020-01-14T15:54:13-6afb519/freebsd-amd64-race
2019-12-09T16:08:50-c0dbc17/windows-amd64-race

@bcmills
Copy link
Contributor Author

bcmills commented Dec 22, 2020

2020-12-16T05:46:12-986b41b/freebsd-amd64-race
2020-10-26T09:15:29-146b70c/freebsd-amd64-race

@gopherbot
Copy link

Change https://golang.org/cl/304829 mentions this issue: net/http/httptest: wait for user ConnState hooks

@gopherbot
Copy link

Change https://golang.org/cl/367516 mentions this issue: [release-branch.go1.16] net/http/httptest: wait for user ConnState hooks

gopherbot pushed a commit that referenced this issue Dec 1, 2021
@neild @mknyszek
[release-branch.go1.16] net/http/httptest: wait for user ConnState hooks
0f9838e 
Ensure that user ConnState callbacks have completed before returning
from (*httptest.Server).Close.

Fixes: #49851
Updates: #37510
Updates: #37505
Updates: #45237

Change-Id: I8fe7baa089fbe4f3836bf6ae9767c7b1270d1331
Reviewed-on: https://go-review.googlesource.com/c/go/+/304829
Trust: Damien Neil <dneil@google.com>
Run-TryBot: Damien Neil <dneil@google.com>
Reviewed-by: Bryan C. Mills <bcmills@google.com>
(cherry picked from commit 5cec8b8)
Reviewed-on: https://go-review.googlesource.com/c/go/+/367516
Trust: Bryan C. Mills <bcmills@google.com>
Run-TryBot: Bryan C. Mills <bcmills@google.com>
TryBot-Result: Go Bot <gobot@golang.org>
Reviewed-by: Damien Neil <dneil@google.com>
@golang golang locked and limited conversation to collaborators Nov 29, 2022
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. Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
None yet
Milestone
Unreleased
Development

No branches or pull requests
2 participants
@bcmills @gopherbot