March 16, 2019
以常见的one-gouroutine-per-connection模式来介绍pprof的用法
10000个connection时测试数据
10000个connection的测试数据
# server.go
func main() {
ln, err := net.Listen("tcp", ":8972")
if err != nil {
panic(err)
}
go func() {
if err := http.ListenAndServe(":6060", nil); err != nil {
log.Fatalf("pprof failed: %v", err)
}
}()
var connections []net.Conn
defer func() {
for _, conn := range connections {
conn.Close()
}
}()
for {
conn, e := ln.Accept()
if e != nil {
if ne, ok := e.(net.Error); ok && ne.Temporary() {
log.Printf("accept temp err: %v", ne)
continue
}
log.Printf("accept err: %v", e)
return
}
go handleConn(conn)
connections = append(connections, conn)
if len(connections)%100 == 0 {
log.Printf("total number of connections: %v", len(connections))
}
}
}
func handleConn(conn net.Conn) {
io.Copy(ioutil.Discard, conn)
}
# client.go
var (
ip = flag.String("ip", "127.0.0.1", "server IP")
connections = flag.Int("conn", 1, "number of tcp connections")
)
func main() {
flag.Parse()
rand.Seed(time.Now().UnixNano())
addr := *ip + ":8972"
var conns []net.Conn
for i := 0; i < *connections; i++ {
c, err := net.DialTimeout("tcp", addr, 10*time.Second)
if err != nil {
fmt.Println("failed to connect", i, err)
i--
continue
}
conns = append(conns, c)
time.Sleep(time.Millisecond)
}
defer func() {
for _, c := range conns {
c.Close()
}
}()
log.Printf("完成初始化 %d 连接", len(conns))
wg := sync.WaitGroup{}
for i := 0; i < len(conns); i++ {
wg.Add(1)
go func(conn net.Conn) {
defer wg.Done()
for {
time.Sleep(time.Duration(rand.Int31n(1000)) * time.Millisecond)
conn.Write([]byte("hello world\r\n"))
}
}(conns[i])
}
wg.Wait()
}
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=60
(pprof) top
Showing nodes accounting for 2350ms, 70.57% of 3330ms total
Dropped 34 nodes (cum <= 16.65ms)
Showing top 10 nodes out of 79
flat flat% sum% cum cum%
560ms 16.82% 16.82% 560ms 16.82% runtime.epollwait /usr/local/go/src/runtime/sys_linux_amd64.s
560ms 16.82% 33.63% 790ms 23.72% syscall.Syscall /usr/local/go/src/syscall/asm_linux_amd64.s
310ms 9.31% 42.94% 310ms 9.31% runtime.futex /usr/local/go/src/runtime/sys_linux_amd64.s
210ms 6.31% 49.25% 210ms 6.31% runtime.usleep /usr/local/go/src/runtime/sys_linux_amd64.s
170ms 5.11% 54.35% 1490ms 44.74% io/ioutil.devNull.ReadFrom /usr/local/go/src/io/ioutil/ioutil.go
120ms 3.60% 57.96% 1210ms 36.34% internal/poll.(*FD).Read /usr/local/go/src/internal/poll/fd_unix.go
110ms 3.30% 61.26% 110ms 3.30% runtime.deferreturn /usr/local/go/src/runtime/panic.go
110ms 3.30% 64.56% 220ms 6.61% runtime.netpollready /usr/local/go/src/runtime/netpoll.go
110ms 3.30% 67.87% 110ms 3.30% runtime.netpollunblock /usr/local/go/src/runtime/netpoll.go
90ms 2.70% 70.57% 870ms 26.13% runtime.netpoll /usr/local/go/src/runtime/netpoll_epoll.go
go tool pprof http://localhost:6060/debug/pprof/heap
(pprof) top
Showing nodes accounting for 19080.60kB, 100% of 19080.60kB total
Showing top 10 nodes out of 22
flat flat% sum% cum cum%
17544.35kB 91.95% 91.95% 17544.35kB 91.95% io/ioutil.glob..func1 /usr/local/go/src/io/ioutil/ioutil.go
1024.06kB 5.37% 97.32% 1024.06kB 5.37% syscall.anyToSockaddr /usr/local/go/src/syscall/syscall_linux.go
512.19kB 2.68% 100% 512.19kB 2.68% runtime.malg /usr/local/go/src/runtime/proc.go
0 0% 100% 512.03kB 2.68% internal/poll.(*FD).Accept /usr/local/go/src/internal/poll/fd_unix.go
0 0% 100% 512.03kB 2.68% internal/poll.accept /usr/local/go/src/internal/poll/sock_cloexec.go
0 0% 100% 17544.35kB 91.95% io.Copy /usr/local/go/src/io/io.go
0 0% 100% 17544.35kB 91.95% io.copyBuffer /usr/local/go/src/io/io.go
0 0% 100% 17544.35kB 91.95% io/ioutil.(*devNull).ReadFrom <autogenerated>
0 0% 100% 17544.35kB 91.95% io/ioutil.devNull.ReadFrom /usr/local/go/src/io/ioutil/ioutil.go
0 0% 100% 17544.35kB 91.95% main.handleConn /home/gelco/code/go/src/gelco/1m-go-tcp-connection/goroutine-per-conn/server.go
#Block profiling
go tool pprof http://localhost:6060/debug/pprof/block
#Mutex profiling
go tool pprof http://localhost:6060/debug/pprof/mutex