crypto/tls: handshake cause goroutine blocking In some cases?

[aaaaa123ad]

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

$ go version
go version go1.13.3 linux/amd64

Does this issue reproduce with the latest release?

yes

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="direct"
GOROOT="/usr/lib/golang"
GOSUMDB="off"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/golang/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build531877332=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I make a https server using golang。Server waited a long time in tls handshake phase,becouse
many clients didn't send hello to server。One day later, my server goroutine count Increase to a huge number（hundreds thousand level）。

I try different frameworks or library(net/http,fasthttp,gin) and set the readtimeout,but didn't solve this problem.

goroutine 627 [IO wait, 36 minutes]:
internal/poll.runtime_pollWait(0x7f6d0fc44728, 0x72, 0xffffffffffffffff)
C:/Go1.13/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc000223898, 0x72, 0x200, 0x205, 0xffffffffffffffff)
C:/Go1.13/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
C:/Go1.13/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000223880, 0xc000334480, 0x205, 0x205, 0x0, 0x0, 0x0)
C:/Go1.13/src/internal/poll/fd_unix.go:169 +0x1cf
net.(*netFD).Read(0xc000223880, 0xc000334480, 0x205, 0x205, 0x203000, 0x42e7c1, 0xb98f38)
C:/Go1.13/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e898, 0xc000334480, 0x205, 0x205, 0x0, 0x0, 0x0)
C:/Go1.13/src/net/net.go:184 +0x68
crypto/tls.(*atLeastReader).Read(0xc0002a9ce0, 0xc000334480, 0x205, 0x205, 0xc000334480, 0x0, 0xc000551450)
C:/Go1.13/src/crypto/tls/conn.go:782 +0x60
bytes.(*Buffer).ReadFrom(0xc000508958, 0xc60fc0, 0xc0002a9ce0, 0x40a1d5, 0xab40a0, 0xb3daa0)
C:/Go1.13/src/bytes/buffer.go:204 +0xb4
crypto/tls.(*Conn).readFromUntil(0xc000508700, 0xc61e80, 0xc00000e898, 0x5, 0xc00000e898, 0x0)
C:/Go1.13/src/crypto/tls/conn.go:804 +0xec
crypto/tls.(*Conn).readRecordOrCCS(0xc000508700, 0x100, 0xc61180, 0xc00001e050)
C:/Go1.13/src/crypto/tls/conn.go:609 +0x17c
crypto/tls.(*Conn).readRecord(...)
C:/Go1.13/src/crypto/tls/conn.go:577
crypto/tls.(*Conn).readHandshake(0xc000508700, 0x0, 0x0, 0xc61180, 0xc00001e050)
C:/Go1.13/src/crypto/tls/conn.go:995 +0x6d
crypto/tls.(*Conn).readClientHello(0xc000508700, 0x0, 0xc61180, 0xc00001e050)
C:/Go1.13/src/crypto/tls/handshake_server.go:135 +0x40
crypto/tls.(*Conn).serverHandshake(0xc000508700, 0x0, 0x0)
C:/Go1.13/src/crypto/tls/handshake_server.go:43 +0x70
crypto/tls.(*Conn).Handshake(0xc000508700, 0x0, 0x0)
C:/Go1.13/src/crypto/tls/conn.go:1366 +0x23a
github.com/valyala/fasthttp.(*Server).getNextProto(0xc000180e00, 0xc76040, 0xc000508700, 0x0, 0x0, 0xc61180, 0xc00001e050)
C:/Users/Administrator/go/src/github.com/valyala/fasthttp/server.go:1338 +0xbf
github.com/valyala/fasthttp.(*Server).serveConn(0xc000180e00, 0xc76040, 0xc000508700, 0x0, 0x0)
C:/Users/Administrator/go/src/github.com/valyala/fasthttp/server.go:1843 +0xbf
github.com/valyala/fasthttp.(*workerPool).workerFunc(0xc0001df180, 0xc0002a8780)
C:/Users/Administrator/go/src/github.com/valyala/fasthttp/workerpool.go:223 +0xc0
github.com/valyala/fasthttp.(*workerPool).getCh.func1(0xc0001df180, 0xc0002a8780, 0xa511a0, 0xc0002a8780)
C:/Users/Administrator/go/src/github.com/valyala/fasthttp/workerpool.go:195 +0x35
created by github.com/valyala/fasthttp.(*workerPool).getCh
C:/Users/Administrator/go/src/github.com/valyala/fasthttp/workerpool.go:194 +0x101

What did you expect to see?

I hope the handshake timeout could be add in crypto/tls。

[networkimprov]

Maybe you're running into this? #31224

If not, could you provide a small, complete program which reproduces your problem, and tell us how you built and ran it?

[aaaaa123ad]

Maybe you're running into this? #31224

If not, could you provide a small, complete program which reproduces your problem, and tell us how you built and ran it?

The client written by others uses mbedtls to connect to the server.But I can use golang to write a simple server and client to simulate

Server:

package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof"
)

func main() {
	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		fmt.Fprint(w,"hello")
	})
	go func() {
		http.ListenAndServe("0.0.0.0:8787", nil)
	}()
	http.ListenAndServeTLS(":12121","server.pem","server.key",nil)

}

Client:

package main

import (
	"crypto/tls"
	"log"
	"net"
)

func ClientTest()  {
	rawConn, err := net.Dial("tcp", "127.0.0.1:12121")
	if err != nil {
		log.Println("error :",err.Error())
		return
	}
	conn:=tls.Client(rawConn,&tls.Config{})

        //handshake  didn't work for some reason or client bug
	select {

	}
	//handshake
	conn.Handshake()
	//.....other operation
}
func main()  {
	for i:=0;i<500;i++{
		go ClientTest()
	}
	select {

	}
}

http://127.0.0.1:8787/debug/pprof：

/debug/pprof/



Types of profiles available:

Count
Profile

	
2
allocs
	

	

	
0
block
	

	

	
0
cmdline
	

	

	
505
goroutine
	

	

	
2
heap
	

	

	
0
mutex
	

	

	
0
profile
	

	

	
7
threadcreate
	

	

	
0
trace
	


full goroutine stack dump

http://127.0.0.1:8787/debug/pprof/goroutine?debug=2：

///....................some fragment.........  server is  under the environment of Windows
goroutine 501 [IO wait]:
internal/poll.runtime_pollWait(0x330ee354, 0x72, 0x7db7d0)
	C:/Go1.13/src/runtime/netpoll.go:184 +0x4b
internal/poll.(*pollDesc).wait(0x131c785c, 0x72, 0x9c4100, 0x0, 0x0)
	C:/Go1.13/src/internal/poll/fd_poll_runtime.go:87 +0x37
internal/poll.(*ioSrv).ExecIO(0xa015f8, 0x131c7774, 0x77a430, 0x0, 0x0, 0x0)
	C:/Go1.13/src/internal/poll/fd_windows.go:228 +0xef
internal/poll.(*FD).Read(0x131c7760, 0x13201b00, 0x205, 0x205, 0x0, 0x0, 0x0)
	C:/Go1.13/src/internal/poll/fd_windows.go:527 +0x10a
net.(*netFD).Read(0x131c7760, 0x13201b00, 0x205, 0x205, 0x0, 0x281fcf5, 0x76)
	C:/Go1.13/src/net/fd_windows.go:152 +0x3f
net.(*conn).Read(0x12c41d28, 0x13201b00, 0x205, 0x205, 0x0, 0x0, 0x0)
	C:/Go1.13/src/net/net.go:184 +0x56
crypto/tls.(*atLeastReader).Read(0x130f4750, 0x13201b00, 0x205, 0x205, 0x0, 0x13201b00, 0x0)
	C:/Go1.13/src/crypto/tls/conn.go:782 +0x61
bytes.(*Buffer).ReadFrom(0x13212d60, 0x7da7f0, 0x130f4750, 0x0, 0x4088c9, 0x70e760, 0x74dc80)
	C:/Go1.13/src/bytes/buffer.go:204 +0x95
crypto/tls.(*Conn).readFromUntil(0x13212c00, 0x32f21008, 0x12c41d28, 0x5, 0x12c41d28, 0x0)
	C:/Go1.13/src/crypto/tls/conn.go:804 +0xcb
crypto/tls.(*Conn).readRecordOrCCS(0x13212c00, 0x0, 0x0, 0x27e8a38)
	C:/Go1.13/src/crypto/tls/conn.go:609 +0x114
crypto/tls.(*Conn).readRecord(...)
	C:/Go1.13/src/crypto/tls/conn.go:577
crypto/tls.(*Conn).readHandshake(0x13212c00, 0x23ba98, 0x20, 0x0, 0x200)
	C:/Go1.13/src/crypto/tls/conn.go:995 +0x4b
crypto/tls.(*Conn).readClientHello(0x13212c00, 0x12cbec80, 0x84, 0xffffffff)
	C:/Go1.13/src/crypto/tls/handshake_server.go:135 +0x25
crypto/tls.(*Conn).serverHandshake(0x13212c00, 0x0, 0x330ea480)
	C:/Go1.13/src/crypto/tls/handshake_server.go:43 +0x6f
crypto/tls.(*Conn).Handshake(0x13212c00, 0x0, 0x0)
	C:/Go1.13/src/crypto/tls/conn.go:1366 +0x1d7
net/http.(*conn).serve(0x12fc7500, 0x7de740, 0x12c38800)
	C:/Go1.13/src/net/http/server.go:1783 +0x1a2
created by net/http.(*Server).Serve
	C:/Go1.13/src/net/http/server.go:2928 +0x30d

//.....................hidden.........

[toothrot]

@aaaaa123ad Are you checking the error that got returned from the handshake? In this scenario, I'd expect an error similar to:

tls: either ServerName or InsecureSkipVerify must be specified in the tls.Config

Also, I am not quite sure I understand what the point of the empty select {} is in ClientTest. It seems like you're opening a connection and blocking indefinitely before doing a handshake, which could be why you have so many goroutines blocking on your server.

[gopherbot]

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.)