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

x/net/http2: data race in Transport.newClientConn() when connection idle timeout is too low #66763

Open
cinchurge opened this issue Apr 10, 2024 · 1 comment
Open

x/net/http2: data race in Transport.newClientConn() when connection idle timeout is too low #66763

cinchurge opened this issue Apr 10, 2024 · 1 comment
Assignees
@panjf2000
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Milestone
Go1.23

Comments

@cinchurge
Copy link

cinchurge commented Apr 10, 2024 •
edited

Go version

1.22.2

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='arm64'
GOBIN=''
GOCACHE='/Users/echung/Library/Caches/go-build'
GOENV='/Users/echung/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='arm64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMODCACHE='/Users/echung/go-code/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='darwin'
GOPATH='/Users/echung/go-code'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/homebrew/Cellar/go/1.22.2/libexec'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/homebrew/Cellar/go/1.22.2/libexec/pkg/tool/darwin_arm64'
GOVCS=''
GOVERSION='go1.22.2'
GCCGO='gccgo'
AR='ar'
CC='cc'
CXX='c++'
CGO_ENABLED='1'
GOMOD='/Users/echung/go-code/http2idleconntest/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -arch arm64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/f6/d0y5wpkn14gb644rbckvn_dr0000gn/T/go-build46174965=/tmp/go-build -gno-record-gcc-switches -fno-common'

What did you do?

Test code:

package idleconn_test

import (
	"context"
	"crypto/tls"
	"net"
	"net/http"
	"net/http/httptest"
	"testing"
	"time"

	"golang.org/x/net/http2"
	"golang.org/x/net/http2/h2c"
)

func TestHTTP2IdleConnTimeout(t *testing.T) {
	server := httptest.NewServer(
		h2c.NewHandler(
			http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}),
			&http2.Server{},
		),
	)
	defer server.Close()

	client := http.Client{
		Transport: &http2.Transport{
			AllowHTTP: true,
			DialTLSContext: func(ctx context.Context, network, addr string, cfg *tls.Config) (net.Conn, error) {
				var d net.Dialer
				return d.DialContext(ctx, network, addr)
			},
			IdleConnTimeout: time.Millisecond,
		},
	}

	for range 1000 {
		go func() {
			_, _ = client.Get(server.URL)
		}()
	}
}

Run it via

go test . -race -count 10000 -v -failfast

What did you see happen?

The above trips the race detector due to ClientConn.idleTimer firing while the client connection is still being constructed. The race happens in ClientConn.closeIfIdle() when it tries to read from ClientConn.nextStreamID while it's being updated in

	if t.AllowHTTP {
		cc.nextStreamID = 3
	}

Output of the test with race detection enabled:

 $ go test . -race -count 10000 -v -failfast
=== RUN   TestHTTP2IdleConnTimeout
==================
WARNING: DATA RACE
Read at 0x00c0002c69b0 by goroutine 760:
  golang.org/x/net/http2.(*ClientConn).closeIfIdle()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/transport.go:1108 +0xc4
  golang.org/x/net/http2.(*ClientConn).onIdleTimeout()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/transport.go:1080 +0x34
  golang.org/x/net/http2.(*ClientConn).onIdleTimeout-fm()
      <autogenerated>:1 +0x20

Previous write at 0x00c0002c69b0 by goroutine 508:
  golang.org/x/net/http2.(*Transport).newClientConn()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/transport.go:864 +0x1048
  golang.org/x/net/http2.(*Transport).dialClientConn()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/transport.go:739 +0xdc
  golang.org/x/net/http2.(*dialCall).dial()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/client_conn_pool.go:141 +0x7c
  golang.org/x/net/http2.(*clientConnPool).getStartDialLocked.gowrap1()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/client_conn_pool.go:134 +0x64

Goroutine 760 (running) created at:
  time.goFunc()
      /opt/homebrew/Cellar/go/1.22.2/libexec/src/time/sleep.go:177 +0x40

Goroutine 508 (running) created at:
  golang.org/x/net/http2.(*clientConnPool).getStartDialLocked()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/client_conn_pool.go:134 +0x34c
  golang.org/x/net/http2.(*clientConnPool).getClientConn()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/client_conn_pool.go:95 +0x200
  golang.org/x/net/http2.(*clientConnPool).GetClientConn()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/client_conn_pool.go:55 +0x44
  golang.org/x/net/http2.(*Transport).RoundTripOpt()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/transport.go:610 +0x620
  golang.org/x/net/http2.(*Transport).RoundTrip()
      /Users/echung/go-code/pkg/mod/golang.org/x/net@v0.24.0/http2/transport.go:575 +0x34
  net/http.send()
      /opt/homebrew/Cellar/go/1.22.2/libexec/src/net/http/client.go:259 +0x6ec
  net/http.(*Client).send()
      /opt/homebrew/Cellar/go/1.22.2/libexec/src/net/http/client.go:180 +0x100
  net/http.(*Client).do()
      /opt/homebrew/Cellar/go/1.22.2/libexec/src/net/http/client.go:724 +0xc60
  net/http.(*Client).Do()
      /opt/homebrew/Cellar/go/1.22.2/libexec/src/net/http/client.go:590 +0x90
  net/http.(*Client).Get()
      /opt/homebrew/Cellar/go/1.22.2/libexec/src/net/http/client.go:487 +0xa0
  http2idleconntest_test.TestHTTP2IdleConnTimeout.func3()
      /Users/echung/go-code/http2idleconntest/idleconn_test.go:38 +0x58
==================
    testing.go:1398: race detected during execution of test
--- FAIL: TestHTTP2IdleConnTimeout (0.01s)
FAIL
FAIL	http2idleconntest	0.427s
FAIL

What did you expect to see?

No race detected.
@cinchurge cinchurge changed the title golang.org/x/net/http2: data race in Transport.newClientConn() when connection idle timeout is too low x/net/http2: data race in Transport.newClientConn() when connection idle timeout is too low Apr 10, 2024
@panjf2000 panjf2000 added the NeedsFix The path to resolution is known, but the work has not been done. label Apr 11, 2024
@panjf2000 panjf2000 added this to the Go1.23 milestone Apr 11, 2024
@gopherbot
Copy link

Change https://go.dev/cl/578115 mentions this issue: http2: set up the handler of closing idle connection after its initialization

@panjf2000 panjf2000 self-assigned this Apr 11, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@panjf2000 panjf2000

Labels
NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Milestone
Go1.23
Development

No branches or pull requests
3 participants
@cinchurge @panjf2000 @gopherbot