Skip to content

x/net/http2: data race in TestTransportReusesConns #49850

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
Closed
bcmills opened this issue Nov 29, 2021 · 6 comments
Closed

x/net/http2: data race in TestTransportReusesConns #49850

bcmills opened this issue Nov 29, 2021 · 6 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
Backlog

Comments

@bcmills
Copy link
Contributor

bcmills commented Nov 29, 2021 

==================
WARNING: DATA RACE
Read at 0x00c00035e943 by goroutine 153:
  testing.(*common).logDepth()
      /workdir/go/src/testing/testing.go:759 +0x164
  testing.(*common).log()
      /workdir/go/src/testing/testing.go:746 +0x8f
  testing.(*common).Logf()
      /workdir/go/src/testing/testing.go:792 +0x21
  golang.org/x/net/http2.testTransportReusesConns.func2()
      /workdir/gopath/src/golang.org/x/net/http2/transport_test.go:197 +0x133
  net/http/httptest.(*Server).wrap.func1()
      /workdir/go/src/net/http/httptest/server.go:357 +0x123
  net/http.(*conn).setState()
      /workdir/go/src/net/http/server.go:1750 +0x158
  net/http.(*conn).serve.func1()
      /workdir/go/src/net/http/server.go:1809 +0x119
  net/http.(*conn).serve()
      /workdir/go/src/net/http/server.go:1843 +0x1f9f

Previous write at 0x00c00035e943 by goroutine 176:
  testing.tRunner.func1()
      /workdir/go/src/testing/testing.go:1180 +0x52c
  testing.tRunner()
      /workdir/go/src/testing/testing.go:1197 +0x22a

Goroutine 153 (running) created at:
  net/http.(*Server).Serve()
      /workdir/go/src/net/http/server.go:2993 +0x644
  net/http/httptest.(*Server).goServe.func1()
      /workdir/go/src/net/http/httptest/server.go:308 +0xd8

Goroutine 176 (finished) created at:
  testing.(*T).Run()
      /workdir/go/src/testing/testing.go:1238 +0x5d7
  golang.org/x/net/http2.TestTransportReusesConns()
      /workdir/gopath/src/golang.org/x/net/http2/transport_test.go:258 +0x24b
  testing.tRunner()
      /workdir/go/src/testing/testing.go:1193 +0x202
==================
--- FAIL: TestTransportReusesConns (0.13s)
    transport_test.go:197: conn 127.0.0.1:34812 is now state closed
    --- FAIL: TestTransportReusesConns/RequestClose (0.05s)
        --- FAIL: TestTransportReusesConns/RequestClose/Transport (0.02s)
            transport_test.go:197: conn 127.0.0.1:53822 is now state new
            transport_test.go:197: conn 127.0.0.1:53822 is now state active
            transport_test.go:197: conn 127.0.0.1:53822 is now state idle
            transport_test.go:197: conn 127.0.0.1:53822 is now state active
            transport_test.go:197: conn 127.0.0.1:53822 is now state idle
            transport_test.go:197: conn 127.0.0.1:53822 is now state closed
            transport_test.go:197: conn 127.0.0.1:53824 is now state new
            transport_test.go:197: conn 127.0.0.1:53824 is now state active
            transport_test.go:197: conn 127.0.0.1:53824 is now state idle
            transport_test.go:197: conn 127.0.0.1:53824 is now state active
            transport_test.go:197: conn 127.0.0.1:53824 is now state idle
            transport_test.go:197: conn 127.0.0.1:53824 is now state closed
            testing.go:1092: race detected during execution of test
        testing.go:1092: race detected during execution of test
    testing.go:1092: race detected during execution of test
FAIL
FAIL	golang.org/x/net/http2	32.680s

greplogs --dashboard -md -l -e '^WARNING: DATA RACE\n(?:.*\n)*--- FAIL: TestTransportReusesConns'

2021-11-29T02:12:23-d83791d-f6103e9/linux-amd64-race

(CC @neild)
@bcmills bcmills added Testing An issue that has been verified to require only test changes, not just a test failure. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Nov 29, 2021
@bcmills
Copy link
Contributor Author

bcmills commented Nov 29, 2021

The racing call to Logf is here:
https://cs.opensource.google/go/x/net/+/master:http2/transport_test.go;l=197;drc=69e39bad7dc2bbb411fa35755c46020969029fa7

That callback is set as the httptest.Handler's Config.ConnState callback:
https://cs.opensource.google/go/x/net/+/master:http2/server_test.go;l=142;drc=d418f374d30933c6c7db22cf349625c295a5afaa

The serverTester's Close method is deferred here:
https://cs.opensource.google/go/x/net/+/master:http2/transport_test.go;l=199;drc=69e39bad7dc2bbb411fa35755c46020969029fa7

So this seems to imply that the serverTester is firing connection state callbacks after it has been closed.

@bcmills
Copy link
Contributor Author

bcmills commented Nov 29, 2021

Given the above, this could be a duplicate of #38370.

@bcmills bcmills added this to the Backlog milestone Nov 29, 2021
@bcmills
Copy link
Contributor Author

bcmills commented Nov 29, 2021

(Note that the above log record is from a commit on release-branch.go1.16.)

@bcmills
Copy link
Contributor Author

bcmills commented Nov 29, 2021

This may be closely related to #45237.

greplogs --dashboard -md -l -e '^WARNING: DATA RACE\n.+ by goroutine \d+:\n(?: .+\n \s+.+\n)* net/http/httptest' --since=2021-03-26

2021-11-29T02:12:23-d83791d-f6103e9/linux-amd64-race
2021-04-12T21:25:46-afb366f-f12cf76/windows-amd64-race
2021-03-31T16:59:18-cb1fcc7-887c0d8/freebsd-amd64-race

This was referenced Nov 29, 2021
Open
Closed
@gopherbot gopherbot mentioned this issue Nov 29, 2021
Closed
@bcmills
Copy link
Contributor Author

bcmills commented Nov 29, 2021

Duplicate of #49851

@bcmills bcmills marked this as a duplicate of #49851 Nov 29, 2021
@bcmills bcmills closed this as completed Nov 29, 2021
@gopherbot
Copy link
Contributor

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

@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
Backlog
Development

No branches or pull requests
2 participants
@bcmills @gopherbot