net: mass tcp dial timeout with the concurrency more than 10000

[Anteoy]

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

$ go version
go version go1.12.1 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
GOARCH="amd64"
GOBIN="/home/zhoudazhuang/gobin/"
GOCACHE="/home/zhoudazhuang/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/zhoudazhuang/db11/jm/pro"
GOPROXY=""
GORACE=""
GOROOT="/home/zhoudazhuang/usr/local/go1.12.1/go"
GOTMPDIR=""
GOTOOLDIR="/home/zhoudazhuang/usr/local/go1.12.1/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
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-build631445118=/tmp/go-build -gno-record-gcc-switches"

What did you do?

My tested code:
Server:

func main() {
	l, err := net.Listen("tcp", ":8888")
	if err != nil {
		log.Println("listen error:", err)
		return
	}

	for {
		c, err := l.Accept()
		if err != nil {
			log.Println("accept error:", err)
			break
		}
		go c.Close()
		// start a new goroutine to handle
		// the new connection.
		//log.Println("accept a new connection")
		//go handleConn(c)
	}
}

Client:

package main

import (
	"fmt"
	"github.com/jessevdk/go-flags"
	"net"
	"os"
	"sync"
	"time"
)

var args struct {
	Addr string `short:"a"  required:"yes" description:"服务端地址"`
	Concurrence int `short:"c"  required:"yes" description:"并发请求数"`
	Count int `short:"t" required:"yes" description:"测试次数"`
}

func main() {
	argParser := flags.NewNamedParser("tcp_test", flags.PassDoubleDash)
	argParser.AddGroup("Mock parameters", "", &args)
	_, err := argParser.Parse()
	if err != nil {
		fmt.Println(err)
		argParser.WriteHelp(os.Stdout)
		os.Exit(1)
	}
	fmt.Printf("测试参数: %+v\n",args)
	wg := sync.WaitGroup{}
	for j:=0; j<args.Count;j++ {
		for i:=0; i<args.Concurrence;i++{
			wg.Add(1)
			go func() {
				defer wg.Done()
				time.Sleep(time.Second*5)
				conn, err := net.DialTimeout("tcp", args.Addr, time.Second*3)
				if err != nil {
					fmt.Printf("dialog err: %+v i为%d:\n",err,j)
					return
				}
				time.Sleep(time.Millisecond*10)
				conn.Close()
			}()
		}
	}
	fmt.Println("start wait")
	wg.Wait()
	fmt.Println("ok")
}

The cmd: ./Test -a 127.0.0.1:8888 -c 10000 -t 3
╰─># cat /proc/sys/net/ipv4/ip_local_port_range
4096 65535
╰─># ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 386849
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 10000000
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 10240
cpu time (seconds, -t) unlimited
max user processes (-u) 1000000
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

╰─># free -h
total used free shared buffers cached
Mem: 94G 85G 9.3G 2.0M 54M 42G
-/+ buffers/cache: 42G 51G
Swap: 0B 0B 0B

╰─># lscpu
Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 32
On-line CPU(s) list: 0-31
Thread(s) per core: 2
Core(s) per socket: 8
Socket(s): 2
NUMA node(s): 2
Vendor ID: GenuineIntel
CPU family: 6
Model: 79
Model name: Intel(R) Xeon(R) CPU E5-26xx v4
Stepping: 1
CPU MHz: 3192.606
BogoMIPS: 6385.21
Hypervisor vendor: KVM
Virtualization type: full
L1d cache: 32K
L1i cache: 32K
L2 cache: 4096K
NUMA node0 CPU(s): 0-15
NUMA node1 CPU(s): 16-31

What did you expect to see?

no tcp dial timeout.

What did you see instead?

dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:
dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:
dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:
dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:

[Anteoy]

|># cat /proc/sys/net/ipv4/tcp_max_syn_backlog
65536
|># cat /proc/sys/net/core/somaxconn
16384

[av86743]

Does this also happen with go 1.11? For server part, presumably.

[Anteoy]

@av86743 I don't have go 1.11, You can try it.
I am suspicious of the performance bottleneck.

[av86743]

You must test your code with latest version of go 1.11 and provide results, in order to to make your request meaningful and yourself helpful to Go community.

[Anteoy]

@av86743 The lastest version is 1.12.6, not 1.11.

[Anteoy]

I also tested it at go 1.10.8. It got the same result. I don't think it's related to the version, It seems to be related to performance bottlenecks.

[av86743]

Provided server source won't even compile.
Server output is not provided.

[Anteoy]

I put the Server output at "What did you see instead?"

dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:
dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:
dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:
dialog err: dial tcp 127.0.0.1:8888: i/o timeout i为3:

"Provided server source won't even compile."
You mean my server code can not compile correctly?

func main() {
	l, err := net.Listen("tcp", ":8888")
	if err != nil {
		log.Println("listen error:", err)
		return
	}

	for {
		c, err := l.Accept()
		if err != nil {
			log.Println("accept error:", err)
			break
		}
		go c.Close()
		// start a new goroutine to handle
		// the new connection.
		//log.Println("accept a new connection")
		//go handleConn(c)
	}
}

[andybons]

@bradfitz @mikioh

[AlexanderYastrebov]

Looks somewhat similar to #35407