go/go-profiler-notes
1
0
Fork 0
mirror of https://github.com/DataDog/go-profiler-notes.git synced 2025-07-15 23:54:16 +02:00
Code Issues Releases Activity

Note about goroutines

Browse Source
This commit is contained in:
Felix Geisendörfer
2021-01-17 19:21:02 +01:00
parent cd61f90513
commit 6fde1a9f35
19 changed files with 1912 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files

BIN
examples/goroutine/1.net.http.pprof.goroutine.debug0.pb.gz Normal file
View File

Binary file not shown.

77
examples/goroutine/1.net.http.pprof.goroutine.debug1.txt Normal file
View File

@ -0,0 +1,77 @@
goroutine profile: total 10
2 @ 0x103b125 0x106cd1f 0x13ac44a 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac449 main.shortSleepLoop+0x29 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165
1 @ 0x103b125 0x10083ef 0x100802b 0x13ac4ed 0x106fd81
# labels: {"test_label":"test_value"}
# 0x13ac4ec main.chanReceiveForever+0x4c /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10d91c5 0x10d91a3 0x11b8a8f 0x11cb72e 0x12ff937 0x11707c5 0x117092f 0x13005e8 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10d91c4 internal/poll.(*pollDesc).waitRead+0x1a4 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10d91a2 internal/poll.(*FD).Read+0x182 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159
# 0x11b8a8e net.(*netFD).Read+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55
# 0x11cb72d net.(*conn).Read+0x8d /usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182
# 0x12ff936 net/http.(*persistConn).Read+0x76 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887
# 0x11707c4 bufio.(*Reader).fill+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101
# 0x117092e bufio.(*Reader).Peek+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139
# 0x13005e7 net/http.(*persistConn).readLoop+0x1a7 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10dad7c 0x10dad5e 0x11ba005 0x11d4052 0x11d2ee5 0x12e9de6 0x12e9b17 0x13acce6 0x13acc90 0x106fd81
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10dad7b internal/poll.(*pollDesc).waitRead+0x1fb /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10dad5d internal/poll.(*FD).Accept+0x1dd /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394
# 0x11ba004 net.(*netFD).accept+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172
# 0x11d4051 net.(*TCPListener).accept+0x31 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139
# 0x11d2ee4 net.(*TCPListener).Accept+0x64 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261
# 0x12e9de5 net/http.(*Server).Serve+0x265 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937
# 0x12e9b16 net/http.(*Server).ListenAndServe+0xb6 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866
# 0x13acce5 net/http.ListenAndServe+0x125 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
# 0x13acc8f main.main.func1+0xcf /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123
1 @ 0x103b125 0x104afcf 0x130223c 0x106fd81
# labels: {"test_label":"test_value"}
# 0x130223b net/http.(*persistConn).writeLoop+0x11b /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340
1 @ 0x103b125 0x104afcf 0x1302f59 0x12f74a5 0x12dd435 0x129e853 0x129e23f 0x12a025f 0x129fbbe 0x129fbce 0x13abba5 0x13abb8a 0x13acafe 0x13abe67 0x13ac247 0x103ad29 0x106fd81
# labels: {"test_label":"test_value"}
# 0x1302f58 net/http.(*persistConn).roundTrip+0x778 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2565
# 0x12f74a4 net/http.(*Transport).roundTrip+0xa64 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:582
# 0x12dd434 net/http.(*Transport).RoundTrip+0x34 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/roundtrip.go:17
# 0x129e852 net/http.send+0x452 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:252
# 0x129e23e net/http.(*Client).send+0xfe /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:176
# 0x12a025e net/http.(*Client).do+0x45e /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:718
# 0x129fbbd net/http.(*Client).Do+0xbd /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:586
# 0x129fbcd net/http.(*Client).Get+0xcd /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:475
# 0x13abba4 net/http.Get+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:447
# 0x13abb89 main.writeHttpProfile+0xe9 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:92
# 0x13acafd main.glob..func7+0x3d /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:79
# 0x13abe66 main.writeProfiles+0x186 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106
# 0x13ac246 main.main+0x2c6 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:142
# 0x103ad28 runtime.main+0x208 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/proc.go:204
1 @ 0x103b125 0x106cd1f 0x13ac48b 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac48a main.sleepLoop+0x2a /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171
1 @ 0x1069e1d 0x139efc2 0x139ed85 0x139b952 0x13a9865 0x13ab145 0x12e6424 0x12e834d 0x12e9a23 0x12e522d 0x106fd81
# 0x1069e1c runtime/pprof.runtime_goroutineProfileWithLabels+0x5c /usr/local/Cellar/go/1.15.6/libexec/src/runtime/mprof.go:716
# 0x139efc1 runtime/pprof.writeRuntimeProfile+0xe1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:724
# 0x139ed84 runtime/pprof.writeGoroutine+0xa4 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:684
# 0x139b951 runtime/pprof.(*Profile).WriteTo+0x3f1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331
# 0x13a9864 net/http/pprof.handler.ServeHTTP+0x384 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:256
# 0x13ab144 net/http/pprof.Index+0x944 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:367
# 0x12e6423 net/http.HandlerFunc.ServeHTTP+0x43 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2042
# 0x12e834c net/http.(*ServeMux).ServeHTTP+0x1ac /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2417
# 0x12e9a22 net/http.serverHandler.ServeHTTP+0xa2 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2843
# 0x12e522c net/http.(*conn).serve+0x8ac /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1925
1 @ 0x12def61 0x106fd81
# 0x12def60 net/http.(*connReader).backgroundRead+0x0 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:689

153
examples/goroutine/1.net.http.pprof.goroutine.debug2.txt Normal file
View File

@ -0,0 +1,153 @@
goroutine 41 [running]:
runtime/pprof.writeGoroutineStacks(0x14e5f60, 0xc0001d6000, 0xc0001b6270, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:693 +0x9f
runtime/pprof.writeGoroutine(0x14e5f60, 0xc0001d6000, 0x2, 0x1714f40, 0xc0001ba420)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:682 +0x45
runtime/pprof.(*Profile).WriteTo(0x17179e0, 0x14e5f60, 0xc0001d6000, 0x2, 0xc0001d6000, 0xc0003379d8)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331 +0x3f2
net/http/pprof.handler.ServeHTTP(0xc0001ca071, 0x9, 0x14ec9a0, 0xc0001d6000, 0xc000110300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:256 +0x385
net/http/pprof.Index(0x14ec9a0, 0xc0001d6000, 0xc000110300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:367 +0x945
net/http.HandlerFunc.ServeHTTP(0x1486d90, 0x14ec9a0, 0xc0001d6000, 0xc000110300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2042 +0x44
net/http.(*ServeMux).ServeHTTP(0x1725ba0, 0x14ec9a0, 0xc0001d6000, 0xc000110300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2417 +0x1ad
net/http.serverHandler.ServeHTTP(0xc00019c000, 0x14ec9a0, 0xc0001d6000, 0xc000110300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2843 +0xa3
net/http.(*conn).serve(0xc0000c6320, 0x14ed4a0, 0xc000322000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1925 +0x8ad
created by net/http.(*Server).Serve
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2969 +0x36c
goroutine 1 [select]:
net/http.(*persistConn).roundTrip(0xc0000cea20, 0xc0001b40c0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2565 +0x779
net/http.(*Transport).roundTrip(0x171d020, 0xc0001ce000, 0x30, 0x30, 0x180de98)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:582 +0xa65
net/http.(*Transport).RoundTrip(0x171d020, 0xc0001ce000, 0x171d020, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/roundtrip.go:17 +0x35
net/http.send(0xc0001ce000, 0x14e5d80, 0x171d020, 0x0, 0x0, 0x0, 0xc0001c8018, 0x203000, 0x1, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:252 +0x453
net/http.(*Client).send(0x17259e0, 0xc0001ce000, 0x0, 0x0, 0x0, 0xc0001c8018, 0x0, 0x1, 0xf8)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:176 +0xff
net/http.(*Client).do(0x17259e0, 0xc0001ce000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:718 +0x45f
net/http.(*Client).Do(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:586
net/http.(*Client).Get(0x17259e0, 0xc0001cc000, 0x33, 0x2, 0x2, 0xc0001cc000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:475 +0xbe
net/http.Get(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:447
main.writeHttpProfile(0x14e5940, 0xc0001b6090, 0x2, 0x0, 0x0)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:92 +0x105
main.glob..func8(0x14e5940, 0xc0001b6090, 0xc000213eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:85 +0x3e
main.writeProfiles(0x1, 0xc0000c4008, 0x146641d)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:142 +0x2c7
goroutine 22 [sleep]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc00019e000, 0x7d667d63cbbded3e, 0x1789ccbbded3e, 0x100000001)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172 +0x45
net.(*TCPListener).accept(0xc000188060, 0x60006709, 0xc000196da8, 0x109abe6)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000188060, 0xc000196df8, 0x18, 0xc000001200, 0x12e9eec)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261 +0x65
net/http.(*Server).Serve(0xc00019c000, 0x14ec6e0, 0xc000188060, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937 +0x266
net/http.(*Server).ListenAndServe(0xc00019c000, 0xc00019c000, 0x1475536)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866 +0xb7
net/http.ListenAndServe(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
main.main.func1(0xc000032120)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123 +0x126
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:121 +0xc5
goroutine 4 [sleep]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:130 +0x195
goroutine 5 [sleep]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.sleepLoop(0x34630b8a000)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171 +0x2b
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:131 +0x1bc
goroutine 6 [chan receive]:
main.chanReceiveForever()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 +0x4d
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:132 +0x1d4
goroutine 24 [select]:
net/http.(*persistConn).writeLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340 +0x11c
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1709 +0xcdc
goroutine 23 [IO wait]:
internal/poll.runtime_pollWait(0x1e91da0, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00010e198, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x103b1dc, 0xc000199b58, 0x10680e0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000010008, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*persistConn).Read(0xc0000cea20, 0xc000256000, 0x1000, 0x1000, 0xc00009e300, 0xc000199c58, 0x10074b5)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887 +0x77
bufio.(*Reader).fill(0xc0001801e0)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101 +0x105
bufio.(*Reader).Peek(0xc0001801e0, 0x1, 0x0, 0x0, 0x1, 0x0, 0xc000030180)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139 +0x4f
net/http.(*persistConn).readLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040 +0x1a8
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1708 +0xcb7
goroutine 67 [IO wait]:
internal/poll.runtime_pollWait(0x1e91cb8, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e098, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00019e080, 0xc00007c311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00019e080, 0xc00007c311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000186028, 0xc00007c311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*connReader).backgroundRead(0xc00007c300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:690 +0x58
created by net/http.(*connReader).startBackgroundRead
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:686 +0xd5

BIN
examples/goroutine/1.pprof.lookup.goroutine.debug0.pb.gz Normal file
View File

Binary file not shown.

39
examples/goroutine/1.pprof.lookup.goroutine.debug1.txt Normal file
View File

@ -0,0 +1,39 @@
goroutine profile: total 6
2 @ 0x103b125 0x106cd1f 0x13ac44a 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac449 main.shortSleepLoop+0x29 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165
1 @ 0x103b125 0x10083ef 0x100802b 0x13ac4ed 0x106fd81
# labels: {"test_label":"test_value"}
# 0x13ac4ec main.chanReceiveForever+0x4c /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10dad7c 0x10dad5e 0x11ba005 0x11d4052 0x11d2ee5 0x12e9de6 0x12e9b17 0x13acce6 0x13acc90 0x106fd81
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10dad7b internal/poll.(*pollDesc).waitRead+0x1fb /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10dad5d internal/poll.(*FD).Accept+0x1dd /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394
# 0x11ba004 net.(*netFD).accept+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172
# 0x11d4051 net.(*TCPListener).accept+0x31 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139
# 0x11d2ee4 net.(*TCPListener).Accept+0x64 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261
# 0x12e9de5 net/http.(*Server).Serve+0x265 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937
# 0x12e9b16 net/http.(*Server).ListenAndServe+0xb6 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866
# 0x13acce5 net/http.ListenAndServe+0x125 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
# 0x13acc8f main.main.func1+0xcf /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123
1 @ 0x103b125 0x106cd1f 0x13ac48b 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac48a main.sleepLoop+0x2a /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171
1 @ 0x1069e1d 0x139efc2 0x139ed85 0x139b952 0x13ac965 0x13abe67 0x13ac247 0x103ad29 0x106fd81
# labels: {"test_label":"test_value"}
# 0x1069e1c runtime/pprof.runtime_goroutineProfileWithLabels+0x5c /usr/local/Cellar/go/1.15.6/libexec/src/runtime/mprof.go:716
# 0x139efc1 runtime/pprof.writeRuntimeProfile+0xe1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:724
# 0x139ed84 runtime/pprof.writeGoroutine+0xa4 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:684
# 0x139b951 runtime/pprof.(*Profile).WriteTo+0x3f1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331
# 0x13ac964 main.glob..func4+0x64 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:60
# 0x13abe66 main.writeProfiles+0x186 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106
# 0x13ac246 main.main+0x2c6 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:142
# 0x103ad28 runtime.main+0x208 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/proc.go:204

69
examples/goroutine/1.pprof.lookup.goroutine.debug2.txt Normal file
View File

@ -0,0 +1,69 @@
goroutine 1 [running]:
runtime/pprof.writeGoroutineStacks(0x14e5940, 0xc0000abb00, 0x101b8a5, 0xc000213d20)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:693 +0x9f
runtime/pprof.writeGoroutine(0x14e5940, 0xc0000abb00, 0x2, 0xc000213dc0, 0x10ee5c8)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:682 +0x45
runtime/pprof.(*Profile).WriteTo(0x17179e0, 0x14e5940, 0xc0000abb00, 0x2, 0xc00002c210, 0xc0002041a0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331 +0x3f2
main.glob..func5(0x14e5940, 0xc0000abb00, 0xc000213eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:67 +0x65
main.writeProfiles(0x1, 0xc0000c4008, 0x146641d)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:142 +0x2c7
goroutine 22 [sleep]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc00019e000, 0xc0001822d0, 0x1010038, 0xc000088000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172 +0x45
net.(*TCPListener).accept(0xc000188060, 0xc000196da8, 0x1010038, 0x30)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000188060, 0x1436c40, 0xc0001822d0, 0x13f4620, 0x1714f50)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261 +0x65
net/http.(*Server).Serve(0xc00019c000, 0x14ec6e0, 0xc000188060, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937 +0x266
net/http.(*Server).ListenAndServe(0xc00019c000, 0xc00019c000, 0x1475536)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866 +0xb7
net/http.ListenAndServe(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
main.main.func1(0xc000032120)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123 +0x126
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:121 +0xc5
goroutine 4 [sleep]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:130 +0x195
goroutine 5 [sleep]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.sleepLoop(0x34630b8a000)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171 +0x2b
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:131 +0x1bc
goroutine 6 [chan receive]:
main.chanReceiveForever()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 +0x4d
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:132 +0x1d4

218
examples/goroutine/1.runtime.goroutineprofile.json Normal file
View File

@ -0,0 +1,218 @@
[
{
"Stack0": [
20629256,
20629212,
20627047,
20628039,
17018153,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17222943,
20628554,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
16990811,
17211861,
17662341,
17673596,
17673566,
18587653,
18694226,
18689765,
19832294,
19831575,
20630758,
20630672,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17222943,
20628554,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17222943,
20628619,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
16810991,
16810027,
20628717,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
}
]

63
examples/goroutine/1.runtime.stack.txt Normal file
View File

@ -0,0 +1,63 @@
goroutine 1 [running]:
main.glob..func1(0x14e5940, 0xc0000aa7b0, 0xc000064eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:29 +0x6f
main.writeProfiles(0x1, 0xc0000c4008, 0x146641d)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:142 +0x2c7
goroutine 22 [sleep]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc00019e000, 0xc0001822d0, 0x1010038, 0xc000088000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172 +0x45
net.(*TCPListener).accept(0xc000188060, 0xc000196da8, 0x1010038, 0x30)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000188060, 0x1436c40, 0xc0001822d0, 0x13f4620, 0x1714f50)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261 +0x65
net/http.(*Server).Serve(0xc00019c000, 0x14ec6e0, 0xc000188060, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937 +0x266
net/http.(*Server).ListenAndServe(0xc00019c000, 0xc00019c000, 0x1475536)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866 +0xb7
net/http.ListenAndServe(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
main.main.func1(0xc000032120)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123 +0x126
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:121 +0xc5
goroutine 4 [sleep]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:130 +0x195
goroutine 5 [sleep]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.sleepLoop(0x34630b8a000)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171 +0x2b
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:131 +0x1bc
goroutine 6 [chan receive]:
main.chanReceiveForever()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 +0x4d
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:132 +0x1d4

BIN
examples/goroutine/2.net.http.pprof.goroutine.debug0.pb.gz Normal file
View File

Binary file not shown.

77
examples/goroutine/2.net.http.pprof.goroutine.debug1.txt Normal file
View File

@ -0,0 +1,77 @@
goroutine profile: total 10
2 @ 0x103b125 0x106cd1f 0x13ac44a 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac449 main.shortSleepLoop+0x29 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165
1 @ 0x103b125 0x10083ef 0x100802b 0x13ac4ed 0x106fd81
# labels: {"test_label":"test_value"}
# 0x13ac4ec main.chanReceiveForever+0x4c /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10d91c5 0x10d91a3 0x11b8a8f 0x11cb72e 0x12ff937 0x11707c5 0x117092f 0x13005e8 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10d91c4 internal/poll.(*pollDesc).waitRead+0x1a4 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10d91a2 internal/poll.(*FD).Read+0x182 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159
# 0x11b8a8e net.(*netFD).Read+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55
# 0x11cb72d net.(*conn).Read+0x8d /usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182
# 0x12ff936 net/http.(*persistConn).Read+0x76 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887
# 0x11707c4 bufio.(*Reader).fill+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101
# 0x117092e bufio.(*Reader).Peek+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139
# 0x13005e7 net/http.(*persistConn).readLoop+0x1a7 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10dad7c 0x10dad5e 0x11ba005 0x11d4052 0x11d2ee5 0x12e9de6 0x12e9b17 0x13acce6 0x13acc90 0x106fd81
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10dad7b internal/poll.(*pollDesc).waitRead+0x1fb /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10dad5d internal/poll.(*FD).Accept+0x1dd /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394
# 0x11ba004 net.(*netFD).accept+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172
# 0x11d4051 net.(*TCPListener).accept+0x31 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139
# 0x11d2ee4 net.(*TCPListener).Accept+0x64 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261
# 0x12e9de5 net/http.(*Server).Serve+0x265 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937
# 0x12e9b16 net/http.(*Server).ListenAndServe+0xb6 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866
# 0x13acce5 net/http.ListenAndServe+0x125 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
# 0x13acc8f main.main.func1+0xcf /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123
1 @ 0x103b125 0x104afcf 0x130223c 0x106fd81
# labels: {"test_label":"test_value"}
# 0x130223b net/http.(*persistConn).writeLoop+0x11b /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340
1 @ 0x103b125 0x104afcf 0x1302f59 0x12f74a5 0x12dd435 0x129e853 0x129e23f 0x12a025f 0x129fbbe 0x129fbce 0x13abba5 0x13abb8a 0x13acafe 0x13abe67 0x13ac352 0x103ad29 0x106fd81
# labels: {"test_label":"test_value"}
# 0x1302f58 net/http.(*persistConn).roundTrip+0x778 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2565
# 0x12f74a4 net/http.(*Transport).roundTrip+0xa64 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:582
# 0x12dd434 net/http.(*Transport).RoundTrip+0x34 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/roundtrip.go:17
# 0x129e852 net/http.send+0x452 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:252
# 0x129e23e net/http.(*Client).send+0xfe /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:176
# 0x12a025e net/http.(*Client).do+0x45e /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:718
# 0x129fbbd net/http.(*Client).Do+0xbd /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:586
# 0x129fbcd net/http.(*Client).Get+0xcd /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:475
# 0x13abba4 net/http.Get+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:447
# 0x13abb89 main.writeHttpProfile+0xe9 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:92
# 0x13acafd main.glob..func7+0x3d /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:79
# 0x13abe66 main.writeProfiles+0x186 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106
# 0x13ac351 main.main+0x3d1 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:152
# 0x103ad28 runtime.main+0x208 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/proc.go:204
1 @ 0x103b125 0x106cd1f 0x13ac48b 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac48a main.sleepLoop+0x2a /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171
1 @ 0x1069e1d 0x139efc2 0x139ed85 0x139b952 0x13a9865 0x13ab145 0x12e6424 0x12e834d 0x12e9a23 0x12e522d 0x106fd81
# 0x1069e1c runtime/pprof.runtime_goroutineProfileWithLabels+0x5c /usr/local/Cellar/go/1.15.6/libexec/src/runtime/mprof.go:716
# 0x139efc1 runtime/pprof.writeRuntimeProfile+0xe1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:724
# 0x139ed84 runtime/pprof.writeGoroutine+0xa4 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:684
# 0x139b951 runtime/pprof.(*Profile).WriteTo+0x3f1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331
# 0x13a9864 net/http/pprof.handler.ServeHTTP+0x384 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:256
# 0x13ab144 net/http/pprof.Index+0x944 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:367
# 0x12e6423 net/http.HandlerFunc.ServeHTTP+0x43 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2042
# 0x12e834c net/http.(*ServeMux).ServeHTTP+0x1ac /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2417
# 0x12e9a22 net/http.serverHandler.ServeHTTP+0xa2 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2843
# 0x12e522c net/http.(*conn).serve+0x8ac /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1925
1 @ 0x12def61 0x106fd81
# 0x12def60 net/http.(*connReader).backgroundRead+0x0 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:689

153
examples/goroutine/2.net.http.pprof.goroutine.debug2.txt Normal file
View File

@ -0,0 +1,153 @@
goroutine 41 [running]:
runtime/pprof.writeGoroutineStacks(0x14e5f60, 0xc0002ae000, 0xc0002a20c0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:693 +0x9f
runtime/pprof.writeGoroutine(0x14e5f60, 0xc0002ae000, 0x2, 0x1714f40, 0xc0002a4160)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:682 +0x45
runtime/pprof.(*Profile).WriteTo(0x17179e0, 0x14e5f60, 0xc0002ae000, 0x2, 0xc0002ae000, 0xc0003379d8)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331 +0x3f2
net/http/pprof.handler.ServeHTTP(0xc00029e011, 0x9, 0x14ec9a0, 0xc0002ae000, 0xc0001da100)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:256 +0x385
net/http/pprof.Index(0x14ec9a0, 0xc0002ae000, 0xc0001da100)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/pprof/pprof.go:367 +0x945
net/http.HandlerFunc.ServeHTTP(0x1486d90, 0x14ec9a0, 0xc0002ae000, 0xc0001da100)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2042 +0x44
net/http.(*ServeMux).ServeHTTP(0x1725ba0, 0x14ec9a0, 0xc0002ae000, 0xc0001da100)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2417 +0x1ad
net/http.serverHandler.ServeHTTP(0xc00019c000, 0x14ec9a0, 0xc0002ae000, 0xc0001da100)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2843 +0xa3
net/http.(*conn).serve(0xc0000c6320, 0x14ed4a0, 0xc000322000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1925 +0x8ad
created by net/http.(*Server).Serve
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2969 +0x36c
goroutine 1 [select]:
net/http.(*persistConn).roundTrip(0xc0000cea20, 0xc000322240, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2565 +0x779
net/http.(*Transport).roundTrip(0x171d020, 0xc0001da200, 0x30, 0x30, 0x180d7d0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:582 +0xa65
net/http.(*Transport).RoundTrip(0x171d020, 0xc0001da200, 0x171d020, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/roundtrip.go:17 +0x35
net/http.send(0xc0001da200, 0x14e5d80, 0x171d020, 0x0, 0x0, 0x0, 0xc000186040, 0x203000, 0x1, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:252 +0x453
net/http.(*Client).send(0x17259e0, 0xc0001da200, 0x0, 0x0, 0x0, 0xc000186040, 0x0, 0x1, 0xf8)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:176 +0xff
net/http.(*Client).do(0x17259e0, 0xc0001da200, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:718 +0x45f
net/http.(*Client).Do(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:586
net/http.(*Client).Get(0x17259e0, 0xc0001ce080, 0x33, 0x2, 0x2, 0xc0001ce080)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:475 +0xbe
net/http.Get(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/client.go:447
main.writeHttpProfile(0x14e5940, 0xc00007c630, 0x2, 0x0, 0x0)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:92 +0x105
main.glob..func8(0x14e5940, 0xc00007c630, 0xc000333eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:85 +0x3e
main.writeProfiles(0x2, 0xc0000c4008, 0x1466424)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:152 +0x3d2
goroutine 22 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc00019e000, 0x7d667d63cbbded3e, 0x1789ccbbded3e, 0x100000001)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172 +0x45
net.(*TCPListener).accept(0xc000188060, 0x60006709, 0xc000196da8, 0x109abe6)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000188060, 0xc000196df8, 0x18, 0xc000001200, 0x12e9eec)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261 +0x65
net/http.(*Server).Serve(0xc00019c000, 0x14ec6e0, 0xc000188060, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937 +0x266
net/http.(*Server).ListenAndServe(0xc00019c000, 0xc00019c000, 0x1475536)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866 +0xb7
net/http.ListenAndServe(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
main.main.func1(0xc000032120)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123 +0x126
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:121 +0xc5
goroutine 4 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:130 +0x195
goroutine 5 [sleep, 1 minutes]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.sleepLoop(0x34630b8a000)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171 +0x2b
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:131 +0x1bc
goroutine 6 [chan receive, 1 minutes]:
main.chanReceiveForever()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 +0x4d
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:132 +0x1d4
goroutine 24 [select]:
net/http.(*persistConn).writeLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340 +0x11c
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1709 +0xcdc
goroutine 23 [IO wait]:
internal/poll.runtime_pollWait(0x1e91da0, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00010e198, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x103b1dc, 0xc000199b58, 0x10680e0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000010008, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*persistConn).Read(0xc0000cea20, 0xc000256000, 0x1000, 0x1000, 0xc00009e300, 0xc000199c58, 0x10074b5)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887 +0x77
bufio.(*Reader).fill(0xc0001801e0)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101 +0x105
bufio.(*Reader).Peek(0xc0001801e0, 0x1, 0x0, 0x0, 0x1, 0x0, 0xc00009e240)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139 +0x4f
net/http.(*persistConn).readLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040 +0x1a8
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1708 +0xcb7
goroutine 54 [IO wait]:
internal/poll.runtime_pollWait(0x1e91cb8, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e098, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00019e080, 0xc00007c311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00019e080, 0xc00007c311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000186028, 0xc00007c311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*connReader).backgroundRead(0xc00007c300)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:690 +0x58
created by net/http.(*connReader).startBackgroundRead
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:686 +0xd5

BIN
examples/goroutine/2.pprof.lookup.goroutine.debug0.pb.gz Normal file
View File

Binary file not shown.

73
examples/goroutine/2.pprof.lookup.goroutine.debug1.txt Normal file
View File

@ -0,0 +1,73 @@
goroutine profile: total 9
2 @ 0x103b125 0x106cd1f 0x13ac44a 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac449 main.shortSleepLoop+0x29 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165
1 @ 0x103b125 0x10083ef 0x100802b 0x13ac4ed 0x106fd81
# labels: {"test_label":"test_value"}
# 0x13ac4ec main.chanReceiveForever+0x4c /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10d91c5 0x10d91a3 0x11b8a8f 0x11cb72e 0x12df52d 0x11707c5 0x117151d 0x1171754 0x1263c2c 0x12d96ca 0x12d96f9 0x12e09ba 0x12e5085 0x106fd81
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10d91c4 internal/poll.(*pollDesc).waitRead+0x1a4 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10d91a2 internal/poll.(*FD).Read+0x182 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159
# 0x11b8a8e net.(*netFD).Read+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55
# 0x11cb72d net.(*conn).Read+0x8d /usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182
# 0x12df52c net/http.(*connReader).Read+0x1ac /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:798
# 0x11707c4 bufio.(*Reader).fill+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101
# 0x117151c bufio.(*Reader).ReadSlice+0x3c /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:360
# 0x1171753 bufio.(*Reader).ReadLine+0x33 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:389
# 0x1263c2b net/textproto.(*Reader).readLineSlice+0x6b /usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:58
# 0x12d96c9 net/textproto.(*Reader).ReadLine+0xa9 /usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:39
# 0x12d96f8 net/http.readRequest+0xd8 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/request.go:1012
# 0x12e09b9 net/http.(*conn).readRequest+0x199 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:984
# 0x12e5084 net/http.(*conn).serve+0x704 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1851
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10d91c5 0x10d91a3 0x11b8a8f 0x11cb72e 0x12ff937 0x11707c5 0x117092f 0x13005e8 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10d91c4 internal/poll.(*pollDesc).waitRead+0x1a4 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10d91a2 internal/poll.(*FD).Read+0x182 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159
# 0x11b8a8e net.(*netFD).Read+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55
# 0x11cb72d net.(*conn).Read+0x8d /usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182
# 0x12ff936 net/http.(*persistConn).Read+0x76 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887
# 0x11707c4 bufio.(*Reader).fill+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101
# 0x117092e bufio.(*Reader).Peek+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139
# 0x13005e7 net/http.(*persistConn).readLoop+0x1a7 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10dad7c 0x10dad5e 0x11ba005 0x11d4052 0x11d2ee5 0x12e9de6 0x12e9b17 0x13acce6 0x13acc90 0x106fd81
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10dad7b internal/poll.(*pollDesc).waitRead+0x1fb /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10dad5d internal/poll.(*FD).Accept+0x1dd /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394
# 0x11ba004 net.(*netFD).accept+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172
# 0x11d4051 net.(*TCPListener).accept+0x31 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139
# 0x11d2ee4 net.(*TCPListener).Accept+0x64 /usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261
# 0x12e9de5 net/http.(*Server).Serve+0x265 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937
# 0x12e9b16 net/http.(*Server).ListenAndServe+0xb6 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866
# 0x13acce5 net/http.ListenAndServe+0x125 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
# 0x13acc8f main.main.func1+0xcf /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123
1 @ 0x103b125 0x104afcf 0x130223c 0x106fd81
# labels: {"test_label":"test_value"}
# 0x130223b net/http.(*persistConn).writeLoop+0x11b /usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340
1 @ 0x103b125 0x106cd1f 0x13ac48b 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac48a main.sleepLoop+0x2a /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171
1 @ 0x1069e1d 0x139efc2 0x139ed85 0x139b952 0x13ac965 0x13abe67 0x13ac352 0x103ad29 0x106fd81
# labels: {"test_label":"test_value"}
# 0x1069e1c runtime/pprof.runtime_goroutineProfileWithLabels+0x5c /usr/local/Cellar/go/1.15.6/libexec/src/runtime/mprof.go:716
# 0x139efc1 runtime/pprof.writeRuntimeProfile+0xe1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:724
# 0x139ed84 runtime/pprof.writeGoroutine+0xa4 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:684
# 0x139b951 runtime/pprof.(*Profile).WriteTo+0x3f1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331
# 0x13ac964 main.glob..func4+0x64 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:60
# 0x13abe66 main.writeProfiles+0x186 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106
# 0x13ac351 main.main+0x3d1 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:152
# 0x103ad28 runtime.main+0x208 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/proc.go:204

133
examples/goroutine/2.pprof.lookup.goroutine.debug2.txt Normal file
View File

@ -0,0 +1,133 @@
goroutine 1 [running]:
runtime/pprof.writeGoroutineStacks(0x14e5940, 0xc0000abc50, 0x101b8a5, 0xc000333d20)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:693 +0x9f
runtime/pprof.writeGoroutine(0x14e5940, 0xc0000abc50, 0x2, 0xc000333dc0, 0x10ee5c8)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:682 +0x45
runtime/pprof.(*Profile).WriteTo(0x17179e0, 0x14e5940, 0xc0000abc50, 0x2, 0xc00002c210, 0xc0000ac4e0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/pprof/pprof.go:331 +0x3f2
main.glob..func5(0x14e5940, 0xc0000abc50, 0xc000333eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:67 +0x65
main.writeProfiles(0x2, 0xc0000c4008, 0x1466424)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:152 +0x3d2
goroutine 22 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc00019e000, 0x7d667d63cbbded3e, 0x1789ccbbded3e, 0x100000001)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172 +0x45
net.(*TCPListener).accept(0xc000188060, 0x60006709, 0xc000196da8, 0x109abe6)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000188060, 0xc000196df8, 0x18, 0xc000001200, 0x12e9eec)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261 +0x65
net/http.(*Server).Serve(0xc00019c000, 0x14ec6e0, 0xc000188060, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937 +0x266
net/http.(*Server).ListenAndServe(0xc00019c000, 0xc00019c000, 0x1475536)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866 +0xb7
net/http.ListenAndServe(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
main.main.func1(0xc000032120)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123 +0x126
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:121 +0xc5
goroutine 4 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:130 +0x195
goroutine 5 [sleep, 1 minutes]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.sleepLoop(0x34630b8a000)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171 +0x2b
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:131 +0x1bc
goroutine 6 [chan receive, 1 minutes]:
main.chanReceiveForever()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 +0x4d
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:132 +0x1d4
goroutine 24 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340 +0x11c
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1709 +0xcdc
goroutine 23 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91da0, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00010e198, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x103b1dc, 0xc000199b58, 0x10680e0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000010008, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*persistConn).Read(0xc0000cea20, 0xc000256000, 0x1000, 0x1000, 0xc00009e300, 0xc000199c58, 0x10074b5)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887 +0x77
bufio.(*Reader).fill(0xc0001801e0)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101 +0x105
bufio.(*Reader).Peek(0xc0001801e0, 0x1, 0x0, 0x0, 0x1, 0x0, 0xc0001d0060)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139 +0x4f
net/http.(*persistConn).readLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040 +0x1a8
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1708 +0xcb7
goroutine 41 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91cb8, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e098, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00019e080, 0xc000326000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00019e080, 0xc000326000, 0x1000, 0x1000, 0x203000, 0x203000, 0x203000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000186028, 0xc000326000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*connReader).Read(0xc00007c300, 0xc000326000, 0x1000, 0x1000, 0x100000006, 0x10, 0x1819408)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:798 +0x1ad
bufio.(*Reader).fill(0xc000290060)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101 +0x105
bufio.(*Reader).ReadSlice(0xc000290060, 0xa, 0x1819408, 0xc000337988, 0x100f6d0, 0xc000110000, 0x100)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:360 +0x3d
bufio.(*Reader).ReadLine(0xc000290060, 0xc000110000, 0x1079694, 0xc0001a4000, 0x0, 0x1010038, 0x30)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:389 +0x34
net/textproto.(*Reader).readLineSlice(0xc000182300, 0xc000110000, 0x10d7c4d, 0xc00019e080, 0x1068000, 0xc000282900)
/usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:58 +0x6c
net/textproto.(*Reader).ReadLine(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:39
net/http.readRequest(0xc000290060, 0x0, 0xc000110000, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/request.go:1012 +0xaa
net/http.(*conn).readRequest(0xc0000c6320, 0x14ed4a0, 0xc000322000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:984 +0x19a
net/http.(*conn).serve(0xc0000c6320, 0x14ed4a0, 0xc000322000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1851 +0x705
created by net/http.(*Server).Serve
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2969 +0x36c

326
examples/goroutine/2.runtime.goroutineprofile.json Normal file
View File

@ -0,0 +1,326 @@
[
{
"Stack0": [
20629256,
20629212,
20627047,
20628306,
17018153,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17222943,
20628554,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
16990811,
17211861,
17662341,
17673596,
17673566,
18587653,
18694226,
18689765,
19832294,
19831575,
20630758,
20630672,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17222943,
20628554,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17222943,
20628619,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
16810991,
16810027,
20628717,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
17084367,
19931708,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
16990811,
17211861,
17662341,
17666501,
17666467,
18582159,
18659118,
19921207,
18286533,
18286895,
19924456,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
},
{
"Stack0": [
17019173,
16990811,
17211861,
17662341,
17666501,
17666467,
18582159,
18659118,
19789101,
18286533,
18289949,
18290516,
19282988,
19764938,
19764985,
19794362,
19812485,
17235329,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0,
0
]
}
]

127
examples/goroutine/2.runtime.stack.txt Normal file
View File

@ -0,0 +1,127 @@
goroutine 1 [running]:
main.glob..func1(0x14e5940, 0xc0000aa7b0, 0xc000064eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:29 +0x6f
main.writeProfiles(0x2, 0xc0000c4008, 0x1466424)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:152 +0x3d2
goroutine 22 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc00019e000, 0x7d667d63cbbded3e, 0x1789ccbbded3e, 0x100000001)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_unix.go:172 +0x45
net.(*TCPListener).accept(0xc000188060, 0x60006709, 0xc000196da8, 0x109abe6)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000188060, 0xc000196df8, 0x18, 0xc000001200, 0x12e9eec)
/usr/local/Cellar/go/1.15.6/libexec/src/net/tcpsock.go:261 +0x65
net/http.(*Server).Serve(0xc00019c000, 0x14ec6e0, 0xc000188060, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2937 +0x266
net/http.(*Server).ListenAndServe(0xc00019c000, 0xc00019c000, 0x1475536)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2866 +0xb7
net/http.ListenAndServe(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:3120
main.main.func1(0xc000032120)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:123 +0x126
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:121 +0xc5
goroutine 4 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:130 +0x195
goroutine 5 [sleep, 1 minutes]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.sleepLoop(0x34630b8a000)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:171 +0x2b
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:131 +0x1bc
goroutine 6 [chan receive, 1 minutes]:
main.chanReceiveForever()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 +0x4d
created by main.main
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:132 +0x1d4
goroutine 24 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2340 +0x11c
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1709 +0xcdc
goroutine 23 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91da0, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00010e198, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00010e180, 0xc000256000, 0x1000, 0x1000, 0x103b1dc, 0xc000199b58, 0x10680e0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000010008, 0xc000256000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*persistConn).Read(0xc0000cea20, 0xc000256000, 0x1000, 0x1000, 0xc00009e300, 0xc000199c58, 0x10074b5)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1887 +0x77
bufio.(*Reader).fill(0xc0001801e0)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101 +0x105
bufio.(*Reader).Peek(0xc0001801e0, 0x1, 0x0, 0x0, 0x1, 0x0, 0xc0001d0060)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:139 +0x4f
net/http.(*persistConn).readLoop(0xc0000cea20)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:2040 +0x1a8
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/transport.go:1708 +0xcb7
goroutine 41 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91cb8, 0x72, 0x14e6ca0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e098, 0x72, 0x14e6c00, 0x16db878, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00019e080, 0xc000326000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159 +0x1a5
net.(*netFD).Read(0xc00019e080, 0xc000326000, 0x1000, 0x1000, 0x203000, 0x203000, 0x203000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55 +0x4f
net.(*conn).Read(0xc000186028, 0xc000326000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182 +0x8e
net/http.(*connReader).Read(0xc00007c300, 0xc000326000, 0x1000, 0x1000, 0x100000006, 0x10, 0x1819408)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:798 +0x1ad
bufio.(*Reader).fill(0xc000290060)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101 +0x105
bufio.(*Reader).ReadSlice(0xc000290060, 0xa, 0x1819408, 0xc000337988, 0x100f6d0, 0xc000110000, 0x100)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:360 +0x3d
bufio.(*Reader).ReadLine(0xc000290060, 0xc000110000, 0x1079694, 0xc0001a4000, 0x0, 0x1010038, 0x30)
/usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:389 +0x34
net/textproto.(*Reader).readLineSlice(0xc000182300, 0xc000110000, 0x10d7c4d, 0xc00019e080, 0x1068000, 0xc000282900)
/usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:58 +0x6c
net/textproto.(*Reader).ReadLine(...)
/usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:39
net/http.readRequest(0xc000290060, 0x0, 0xc000110000, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/request.go:1012 +0xaa
net/http.(*conn).readRequest(0xc0000c6320, 0x14ed4a0, 0xc000322000, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:984 +0x19a
net/http.(*conn).serve(0xc0000c6320, 0x14ed4a0, 0xc000322000)
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1851 +0x705
created by net/http.(*Server).Serve
/usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:2969 +0x36c

186
examples/goroutine/main.go Normal file
View File

@ -0,0 +1,186 @@
package main
import (
"bytes"
"context"
"encoding/json"
"errors"
"flag"
"fmt"
"io"
"io/ioutil"
"net/http"
_ "net/http/pprof"
"runtime"
"runtime/pprof"
"time"
)
type Profile struct {
Name string
WriteTo func(w io.Writer) error
}
var profiles = []Profile{
{
Name: "runtime.stack.txt",
WriteTo: func(w io.Writer) error {
buf := make([]byte, 1024*1024)
n := runtime.Stack(buf, true)
buf = buf[:n]
_, err := w.Write(buf)
return err
},
},
{
Name: "runtime.goroutineprofile.json",
WriteTo: func(w io.Writer) error {
p := make([]runtime.StackRecord, 1000)
n, ok := runtime.GoroutineProfile(p)
if !ok {
return errors.New("runtime.GoroutineProfile: not ok")
}
p = p[0:n]
e := json.NewEncoder(w)
e.SetIndent("", " ")
return e.Encode(p)
},
},
{
Name: "pprof.lookup.goroutine.debug0.pb.gz",
WriteTo: func(w io.Writer) error {
profile := pprof.Lookup("goroutine")
return profile.WriteTo(w, 0)
},
},
{
Name: "pprof.lookup.goroutine.debug1.txt",
WriteTo: func(w io.Writer) error {
profile := pprof.Lookup("goroutine")
return profile.WriteTo(w, 1)
},
},
{
Name: "pprof.lookup.goroutine.debug2.txt",
WriteTo: func(w io.Writer) error {
profile := pprof.Lookup("goroutine")
return profile.WriteTo(w, 2)
},
},
{
Name: "net.http.pprof.goroutine.debug0.pb.gz",
WriteTo: func(w io.Writer) error {
return writeHttpProfile(w, 0)
},
},
{
Name: "net.http.pprof.goroutine.debug1.txt",
WriteTo: func(w io.Writer) error {
return writeHttpProfile(w, 1)
},
},
{
Name: "net.http.pprof.goroutine.debug2.txt",
WriteTo: func(w io.Writer) error {
return writeHttpProfile(w, 2)
},
},
}
func writeHttpProfile(w io.Writer, debug int) error {
url := fmt.Sprintf("http://%s/debug/pprof/goroutine?debug=%d", listenAddr, debug)
res, err := http.Get(url)
if err != nil {
return err
}
defer res.Body.Close()
_, err = io.Copy(w, res.Body)
return err
}
func writeProfiles(n int) error {
for _, profile := range profiles {
buf := &bytes.Buffer{}
filename := fmt.Sprintf("%d.%s", n, profile.Name)
if err := profile.WriteTo(buf); err != nil {
return err
} else if err := ioutil.WriteFile(filename, buf.Bytes(), 0666); err != nil {
return err
}
}
return nil
}
var listenAddr = "127.0.0.1:8080"
func main() {
flag.Parse()
errCh := make(chan error, 1)
go func() {
fmt.Printf("Listening for pprof requests on %s\n", listenAddr)
errCh <- http.ListenAndServe(listenAddr, nil)
}()
labels := pprof.Labels("test_label", "test_value")
ctx := pprof.WithLabels(context.Background(), labels)
pprof.SetGoroutineLabels(ctx)
go shortSleepLoop()
go sleepLoop(time.Hour)
go chanReceiveForever()
go indirectShortSleepLoop()
sleep := time.Second
fmt.Printf("Sleeping for %s followed by gc\n", sleep)
time.Sleep(time.Second)
runtime.GC()
fmt.Printf("Dump 1\n")
if err := writeProfiles(1); err != nil {
panic(err)
}
sleep = 1*time.Minute + 10*time.Second
fmt.Printf("Sleeping for %s followed by gc\n", sleep)
time.Sleep(sleep)
runtime.GC()
fmt.Printf("Dump 2\n")
if err := writeProfiles(2); err != nil {
panic(err)
}
fmt.Printf("Waiting forever\n")
//fmt.Printf("waiting indefinitely so you can press ctrl+\\ to compare the output\n")
//runtime.GC()
<-errCh
}
func shortSleepLoop() {
for {
time.Sleep(time.Second)
}
}
func sleepLoop(d time.Duration) {
for {
time.Sleep(d)
}
}
func chanReceiveForever() {
forever := make(chan struct{})
<-forever
}
func indirectShortSleepLoop() {
indirectShortSleepLoop2()
}
func indirectShortSleepLoop2() {
go shortSleepLoop()
}

BIN
goroutine-matrix.png Normal file
View File

Binary file not shown.
Side by Side

After

Width:  |  Height:  |  Size: 197 KiB

218
goroutine.md Normal file
View File

@ -0,0 +1,218 @@
This document was last updated for `go1.15.6` but probably still applies to older/newer versions for the most parts.
# Go's Goroutine Profiler
Go has various APIs to provide users with a list of **active** goroutines, their current stack trace, as well as various other properties. Some APIs expose this information as statistical summaries, while other APIs provide information for each individual goroutine.
Despite the differences between the APIs, the [common](https://github.com/golang/go/blob/9b955d2d3fcff6a5bc8bce7bafdc4c634a28e95b/src/runtime/mprof.go#L729) [definition](https://github.com/golang/go/blob/9b955d2d3fcff6a5bc8bce7bafdc4c634a28e95b/src/runtime/traceback.go#L931) of an **active** goroutine seems to be:
- It's not [`dead`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L65-L71) (just exited or is being reinitialized).
- It's not a [system goroutine](https://github.com/golang/go/blob/9b955d2d3fcff6a5bc8bce7bafdc4c634a28e95b/src/runtime/traceback.go#L1013-L1021) nor finalizer goroutine.
In other words, goroutines that are running, waiting on locks, i/o, scheduling, etc. are all considered to be active, even so one might naively not think of them as such.
## Performance Impact
All Goroutine profiling available in Go requires an `O(N)` **stop-the-world** phase where `N` is the number of allocated goroutines. A [naive benchmark](https://github.com/felixge/fgprof/blob/fe01e87ceec08ea5024e8168f88468af8f818b62/fgprof_test.go#L35-L78) [indicates](https://github.com/felixge/fgprof/blob/master/BenchmarkProfilerGoroutines.txt) that the world is stopped for ~1µs per goroutine when using the [runtime.GoroutineProfile()](https://golang.org/pkg/runtime/#GoroutineProfile) API. But this number is likely to fluctuate in response to other factors such as the average stack depth of the program.
As a rule of thumb, applications that are extremely latency sensitive and make use of thousands of active goroutines might want to be a little careful with goroutine profiling in production. That being said, large number of goroutines, and perhaps even Go itself, might not be good idea for such applications to begin with.
Most applications that can tolerate a few ms of ocassional extra latency should have no issues with continous goroutine profiling in production.
## Goroutine Properties
Goroutines have a lot of [properties](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L406-L486) that can help to debug Go applications. The ones below are particulary interesting and exposed via the APIs described later on in this document to varying degrees.
- [`goid`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L428): The unique id of the goroutine, the main goroutine has id `1`.
- [`atomicstatus`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L14-L105): The status of the goroutine, one of the following:
- `idle`: just got allocated
- `runnable`: on a run queue, waiting to be scheduled
- `running`: executing on an OS thread
- `syscall`: blocked on a syscall
- `waiting`: parked by the scheduler, see `g.waitreason`
- `dead`: just exited or being reinitialized
- `copystack`: stack is currently being moved
- `preempted`: just preempted itself
- [`waitreason`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L996-L1024): The reason a goroutine is in `waiting` status, e.g. sleep, channel operations, i/o, gc, etc.
- [`waitsince`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L430): The approximate timestamp a goroutine has entered `waiting` or `syscall` status as determined by the first gc after the wait started.
- [`labels`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L472): A set of key/value [profiler labels](https://rakyll.org/profiler-labels/) that can be attached to goroutines.
- `stack trace`: The function that is currently being executed as well as its callers. This is exposed as either a plain text output of filenames, function names and line numbers or a slice of program counter addresses (pcs). 🚧 *Research more details on this, e.g. can func/file/line text be converted to pcs?*
- [`gopc`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L466): The program counter address (pc) of the `go ...` call that caused this goroutine to be created. Can be converted to the file, function name and line number.
- [`lockedm`](https://github.com/golang/go/blob/go1.15.6/src/runtime/runtime2.go#L460): The thread this goroutine is locked to, if any.
The feature matrix below give you a quick idea on the current availability of these properties through the various APIs. Also available as a [google sheet](https://docs.google.com/spreadsheets/d/1txMRjhDA0NC9eSNRRUMMFI5uWJ3FBnACGVjXYT1gKig/edit?usp=sharing).
![goroutine feature matrix](./goroutine-matrix.png)
## APIs
### [`runtime.Stack()`](https://golang.org/pkg/runtime/#Stack) / [`pprof.Lookup(debug=2)`](https://golang.org/pkg/runtime/pprof/#Lookup)
This returns unstructured text output showing the stack of all active goroutines as well as the properties listed in the feature matrix above.
The `waitsince` property is included as `nanotime() - gp.waitsince()` in minutes, but only if the duration exceeds 1 minute.
`pprof.Lookup(debug=2)` is a simplified alias for how this profile is used. The actual invocation looks like this:
```go
profile := pprof.Lookup("goroutine")
profile.WriteTo(os.Stdout, 2)
```
The profile implementation itself simply invokes `runtime.Stack()`.
Below is a truncated example of the returned output, see [2.runtime.stack.txt](./examples/goroutine/2.runtime.stack.txt) for a full example.
```
goroutine 1 [running]:
main.glob..func1(0x14e5940, 0xc0000aa7b0, 0xc000064eb0, 0x2)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:29 +0x6f
main.writeProfiles(0x2, 0xc0000c4008, 0x1466424)
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:106 +0x187
main.main()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:152 +0x3d2
goroutine 22 [sleep, 1 minutes]:
time.Sleep(0x3b9aca00)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 +0xbf
main.shortSleepLoop()
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 +0x2a
created by main.indirectShortSleepLoop2
/Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:185 +0x35
goroutine 3 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x1e91e88, 0x72, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222 +0x55
internal/poll.(*pollDesc).wait(0xc00019e018, 0x72, 0x0, 0x0, 0x1465786)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00019e000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:394 +0x1fc
...
```
### [`pprof.Lookup(debug=1)`](https://golang.org/pkg/runtime/pprof/#Lookup)
This profiling method is invoked the same way as `pprof.Lookup(debug=2)`, but produces very different data:
- Instead of listing individual goroutines, goroutines with the same stack/labels are listed once along with their count.
- pprof labels are included (`debug=2` does not include them).
- Most other goroutine properties from debug=2 are not included.
- The output format is also text based, but looks very different than `debug=2`.
Below is a truncated example of the returned output, see [2.pprof.lookup.goroutine.debug1.txt](./examples/goroutine/2.pprof.lookup.goroutine.debug1.txt) for a full example.
```
goroutine profile: total 9
2 @ 0x103b125 0x106cd1f 0x13ac44a 0x106fd81
# labels: {"test_label":"test_value"}
# 0x106cd1e time.Sleep+0xbe /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188
# 0x13ac449 main.shortSleepLoop+0x29 /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165
1 @ 0x103b125 0x10083ef 0x100802b 0x13ac4ed 0x106fd81
# labels: {"test_label":"test_value"}
# 0x13ac4ec main.chanReceiveForever+0x4c /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177
1 @ 0x103b125 0x103425b 0x106a1d5 0x10d8185 0x10d91c5 0x10d91a3 0x11b8a8f 0x11cb72e 0x12df52d 0x11707c5 0x117151d 0x1171754 0x1263c2c 0x12d96ca 0x12d96f9 0x12e09ba 0x12e5085 0x106fd81
# 0x106a1d4 internal/poll.runtime_pollWait+0x54 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/netpoll.go:222
# 0x10d8184 internal/poll.(*pollDesc).wait+0x44 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:87
# 0x10d91c4 internal/poll.(*pollDesc).waitRead+0x1a4 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_poll_runtime.go:92
# 0x10d91a2 internal/poll.(*FD).Read+0x182 /usr/local/Cellar/go/1.15.6/libexec/src/internal/poll/fd_unix.go:159
# 0x11b8a8e net.(*netFD).Read+0x4e /usr/local/Cellar/go/1.15.6/libexec/src/net/fd_posix.go:55
# 0x11cb72d net.(*conn).Read+0x8d /usr/local/Cellar/go/1.15.6/libexec/src/net/net.go:182
# 0x12df52c net/http.(*connReader).Read+0x1ac /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:798
# 0x11707c4 bufio.(*Reader).fill+0x104 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:101
# 0x117151c bufio.(*Reader).ReadSlice+0x3c /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:360
# 0x1171753 bufio.(*Reader).ReadLine+0x33 /usr/local/Cellar/go/1.15.6/libexec/src/bufio/bufio.go:389
# 0x1263c2b net/textproto.(*Reader).readLineSlice+0x6b /usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:58
# 0x12d96c9 net/textproto.(*Reader).ReadLine+0xa9 /usr/local/Cellar/go/1.15.6/libexec/src/net/textproto/reader.go:39
# 0x12d96f8 net/http.readRequest+0xd8 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/request.go:1012
# 0x12e09b9 net/http.(*conn).readRequest+0x199 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:984
# 0x12e5084 net/http.(*conn).serve+0x704 /usr/local/Cellar/go/1.15.6/libexec/src/net/http/server.go:1851
...
```
### [`pprof.Lookup(debug=0)`](https://golang.org/pkg/runtime/pprof/#Lookup)
This profiling method is invoked the same way as `pprof.Lookup(debug=1)`, and produces the same data. The only difference is that the data format is the [pprof](./pprof.md) protocol buffer format.
Below is a truncated example of the returned output as reported by `go tool pprof -raw`, see [2.pprof.lookup.goroutine.debug0.pb.gz](./examples/goroutine/2.pprof.lookup.goroutine.debug0.pb.gz) for a full example.
```
PeriodType: goroutine count
Period: 1
Time: 2021-01-14 16:46:23.697667 +0100 CET
Samples:
goroutine/count
2: 1 2 3
test_label:[test_value]
1: 1 4 5 6
test_label:[test_value]
1: 1 7 8 9 10 11 12 13 14 15 16 17 18 19 20
1: 1 7 8 9 10 11 12 21 14 22 23
test_label:[test_value]
1: 1 7 8 9 24 25 26 27 28 29 30
1: 1 31 32
test_label:[test_value]
1: 1 2 33
test_label:[test_value]
1: 34 35 36 37 38 39 40 41
test_label:[test_value]
Locations
1: 0x103b124 M=1 runtime.gopark /usr/local/Cellar/go/1.15.6/libexec/src/runtime/proc.go:306 s=0
2: 0x106cd1e M=1 time.Sleep /usr/local/Cellar/go/1.15.6/libexec/src/runtime/time.go:188 s=0
3: 0x13ac449 M=1 main.shortSleepLoop /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:165 s=0
4: 0x10083ee M=1 runtime.chanrecv /usr/local/Cellar/go/1.15.6/libexec/src/runtime/chan.go:577 s=0
5: 0x100802a M=1 runtime.chanrecv1 /usr/local/Cellar/go/1.15.6/libexec/src/runtime/chan.go:439 s=0
6: 0x13ac4ec M=1 main.chanReceiveForever /Users/felix.geisendoerfer/go/src/github.com/felixge/go-profiler-notes/examples/goroutine/main.go:177 s=0
...
Mappings
1: 0x0/0x0/0x0 [FN]
```
### [`runtime.GoroutineProfile()`](https://golang.org/pkg/runtime/#GoroutineProfile)
This function essentially returns a slice of all active goroutines and their current stack trace. The stack traces are given in the form of program addresses which can be resolved to function names using [`runtime.CallersFrames()`](https://golang.org/pkg/runtime/#CallersFrames).
This method is used by [fgprof](https://github.com/felixge/fgprof) to implement wall clock profiling.
The following features are not available, but might be interesting to propose to the Go project in the future:
- Include goroutine properties outlined above that are not available yet, especially labels.
- Filter by pprof labels, this could reduce stop-the-world, but would require additional book keeping by the runtime.
- Limit the number of returned goroutines to a random subset, could also reduce stop-the-world and might be easier to implement than filtering by label.
Below is a truncated example of the returned output, see [2.runtime.goroutineprofile.json](./examples/goroutine/2.runtime.goroutineprofile.json) for a full example.
```json
[
{
"Stack0": [
20629256,
20629212,
20627047,
20628306,
17018153,
17235329,
// ...
]
},
{
"Stack0": [
17019173,
17222943,
20628554,
17235329,
// ...
]
},
// ...
]
```
### [`net/http/pprof`](https://golang.org/pkg/net/http/pprof/)
This package exposes the [`pprof.Lookup("goroutine")`](https://golang.org/pkg/runtime/pprof/#Lookup) profiles described above via HTTP endpoints. The output is identical.