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

net/http/fcgi: data race in TestSlowRequest in case of timeout #61271

Closed
gopherbot opened this issue Jul 10, 2023 · 5 comments
Closed

net/http/fcgi: data race in TestSlowRequest in case of timeout #61271

gopherbot opened this issue Jul 10, 2023 · 5 comments
Assignees
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@gopherbot
Copy link

gopherbot commented Jul 10, 2023

#!watchflakes
default <- pkg == "net/http/fcgi" && test == "TestSlowRequest" && `WARNING: DATA RACE`

Issue created automatically to collect these failures.

Example (log):

==================
WARNING: DATA RACE
Read at 0x00c00009fda0 by goroutine 34:
  runtime.mapdelete()
      /data/golang/workdir/go/src/runtime/map.go:696 +0x5ef
  net/http/fcgi.(*child).cleanUp()
      /data/golang/workdir/go/src/net/http/fcgi/child.go:325 +0x7f
  net/http/fcgi.TestSlowRequest.func5()
      /data/golang/workdir/go/src/net/http/fcgi/fcgi_test.go:443 +0x7b
  runtime.deferreturn()
...
  net/http/fcgi.TestSlowRequest()
      /data/golang/workdir/go/src/net/http/fcgi/fcgi_test.go:442 +0x8db
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1595 +0x23d
  testing.(*T).Run.func1()
      /data/golang/workdir/go/src/testing/testing.go:1648 +0x8d
==================
--- FAIL: TestSlowRequest (3.24s)
    fcgi_test.go:452: FastCGI child did not close socket after handling request
    testing.go:1465: race detected during execution of test

watchflakes

@gopherbot gopherbot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jul 10, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "net/http/fcgi" && test == "TestSlowRequest"
2023-07-05 22:05 linux-s390x-ibm-race go@c8dad424 net/http/fcgi.TestSlowRequest (log)
==================
WARNING: DATA RACE
Read at 0x00c00009fda0 by goroutine 34:
  runtime.mapdelete()
      /data/golang/workdir/go/src/runtime/map.go:696 +0x5ef
  net/http/fcgi.(*child).cleanUp()
      /data/golang/workdir/go/src/net/http/fcgi/child.go:325 +0x7f
  net/http/fcgi.TestSlowRequest.func5()
      /data/golang/workdir/go/src/net/http/fcgi/fcgi_test.go:443 +0x7b
  runtime.deferreturn()
...
  net/http/fcgi.TestSlowRequest()
      /data/golang/workdir/go/src/net/http/fcgi/fcgi_test.go:442 +0x8db
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1595 +0x23d
  testing.(*T).Run.func1()
      /data/golang/workdir/go/src/testing/testing.go:1648 +0x8d
==================
--- FAIL: TestSlowRequest (3.24s)
    fcgi_test.go:452: FastCGI child did not close socket after handling request
    testing.go:1465: race detected during execution of test

watchflakes

@bcmills bcmills changed the title net/http/fcgi: TestSlowRequest failures net/http/fcgi: data race in TestSlowRequest in case of timeout Jul 10, 2023
@bcmills bcmills added this to the Backlog milestone Jul 10, 2023
@bcmills bcmills added help wanted NeedsFix The path to resolution is known, but the work has not been done. labels Jul 10, 2023
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jul 10, 2023
@bcmills
Copy link
Contributor

bcmills commented Jul 10, 2023

This is a race in the test on the timeout path:
https://cs.opensource.google/go/go/+/master:src/net/http/fcgi/fcgi_test.go;l=442-453;drc=3e7ffb862f550c38ce0611b970a4dce10a01226e

Probably the fix is to remove the arbitrary 2-second timeout.

@zlasd
Copy link
Contributor

zlasd commented Jul 11, 2023

https://github.com/golang/go/blob/6a063b01b0b0effa787c5aed90b585b409fe4688/src/net/http/fcgi/fcgi_test.go#L435C1-L453C3

In the test code, the handler we pass to newChild close the channel handlerDone, but it still need some time to close rc. Take a sleep after <-handlerDone may fix this.

@bcmills
Copy link
Contributor

bcmills commented Jul 11, 2023

The race cannot be fixed by a sleep. It needs synchronization.

@gopherbot
Copy link
Author

Change https://go.dev/cl/508815 mentions this issue: net/http/fcgi: eliminate goroutine leaks in tests

@bcmills bcmills self-assigned this Jul 11, 2023
@bcmills bcmills modified the milestones: Backlog, Go1.21 Jul 11, 2023
bradfitz pushed a commit to tailscale/go that referenced this issue Jul 15, 2023
Also fix a (minor) double-Close error in Serve that was exposed by the
test fix.

Serve accepts a net.Listener, which produces net.Conn instances.
The documentation for net.Conn requires its methods to be safe for
concurrent use, so most implementations likely allow Close to be
called multiple times as a side effect of making it safe to call
concurrently with other methods. However, the net.Conn interface is a
superset of the io.Closer interface, io.Closer explicitly leaves the
behavior of multiple Close calls undefined, and net.Conn does not
explicitly document a stricter requirement.

Perhaps more importantly, the test for the fcgi package calls
unexported functions that accept an io.ReadWriteCloser (not a
net.Conn), and at least one of the test-helper ReadWriteCloser
implementations expects Close to be called only once.

The goroutine leaks were exposed by a racy arbitrary timeout reported
in golang#61271. Fixing the goroutine leak exposed the double-Close error:
one of the leaked goroutines was blocked on reading from an unclosed
pipe. Closing the pipe (to unblock the goroutine) triggered the second
Close call.

Fixes golang#61271.

Change-Id: I5cfac8870e4bb4f13adeee48910d165dbd4b76fe
Reviewed-on: https://go-review.googlesource.com/c/go/+/508815
Run-TryBot: Bryan Mills <bcmills@google.com>
Reviewed-by: Ian Lance Taylor <iant@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Projects
Status: Done
Development

No branches or pull requests

3 participants