An interactive tool to analyze Golang goroutine dump.
go get github.com/shippomx/goins
$GOPATH/bin/goinsWorkspace is the place to hold imported goroutine dumps. Instructions are provided to maintain these dumps.
In the interactive shell, two kinds of instructions can be issued: commands and statements.
At present, the following commands are supported.
| command | function |
|---|---|
| cd | Change current working directory. |
| clear | Clear the workspace. |
| exit | Exit the interactive shell. |
| help | Show help. |
| ls | Show files in current directory. |
| pwd | Show present working directory. |
| quit | Quit the interactive shell. |
| whos | Show all varaibles in workspace. |
Load the dump and assign to a variable:
>> original = load("pprof-goroutines-20170510-170245.dump")
>> whos
originalSimply type the variable name:
>> original
# of goroutines: 2217
running: 1
IO wait: 533
syscall: 2
chan receive: 50
select: 1504
runnable: 38
semacquire: 85
chan send: 4
To copy the whole dump, simply assign it to a different var:
>> copy1 = original
>> whos
copy originalIt's equivalent to using a copy() function:
>> copy2 = original.copy()
>> whos
copy copy1 copy2 originalThe copy() function allows passing a conditional so that only those meeting the cariteria will be copied:
>> copy3 = original.copy("id>900 && id<2000")Function delete() accepts a conditional to delete goroutine items in a dump var. Function keep() do the reversed conditional.
>> copy
# of goroutines: 2217
running: 1
IO wait: 533
syscall: 2
chan receive: 50
select: 1504
runnable: 38
semacquire: 85
chan send: 4
>> copy.delete("id>100 && id<1000")
Deleted 118 goroutines, kept 2099.
>> copy.keep("id>200")
Deleted 12 goroutines, kept 2087.
>> copy
# of goroutines: 2087
running: 1
select: 1411
IO wait: 500
semacquire: 85
runnable: 37
chan receive: 49
chan send: 4
Function show() displays goroutine dump items with optional offset and limit. The default offset is 0, and default limit is 10.
>> original.show() # offset 0, limit 10
goroutine 1803 [select, 10 minutes]:
google.golang.org/grpc/transport.(*http2Server).keepalive(0xc420e59ce0)
google.golang.org/grpc/transport/http2_server.go:919 +0x488
created by google.golang.org/grpc/transport.newHTTP2Server
google.golang.org/grpc/transport/http2_server.go:226 +0x97c
...
...
>> original.show(15) # offset 15, limit 10
goroutine 6455709 [running]:
runtime/pprof.writeGoroutineStacks(0xe9a080, 0xc4216f0088, 0x1d, 0x40)
go1.8.1.linux-amd64/src/runtime/pprof/pprof.go:603 +0x79
runtime/pprof.writeGoroutine(0xe9a080, 0xc4216f0088, 0x2, 0x1d, 0xc4217cede0)
go1.8.1.linux-amd64/src/runtime/pprof/pprof.go:592 +0x44
runtime/pprof.(*Profile).WriteTo(0xed3780, 0xe9a080, 0xc4216f0088, 0x2, 0xc4217cef80, 0x1)
go1.8.1.linux-amd64/src/runtime/pprof/pprof.go:302 +0x3b5
www.test.com/bagel/runtime.dumpToFile(0xed0f0ba5e, 0xae05027, 0xee1780, 0xc425bd2060, 0x5, 0x5)
www.test.com/bagel/runtime/dump.go:58 +0x3f3
created by www.test.com/bagel/runtime.EnableGoroutineDump.func1
www.test.com/bagel/runtime/dump.go:30 +0x2d6
...
...
>> original.show(15, 1) # offset 15, limit 1
goroutine 6455709 [running]:
runtime/pprof.writeGoroutineStacks(0xe9a080, 0xc4216f0088, 0x1d, 0x40)
go1.8.1.linux-amd64/src/runtime/pprof/pprof.go:603 +0x79
runtime/pprof.writeGoroutine(0xe9a080, 0xc4216f0088, 0x2, 0x1d, 0xc4217cede0)
go1.8.1.linux-amd64/src/runtime/pprof/pprof.go:592 +0x44
runtime/pprof.(*Profile).WriteTo(0xed3780, 0xe9a080, 0xc4216f0088, 0x2, 0xc4217cef80, 0x1)
go1.8.1.linux-amd64/src/runtime/pprof/pprof.go:302 +0x3b5
www.test.com/bagel/runtime.dumpToFile(0xed0f0ba5e, 0xae05027, 0xee1780, 0xc425bd2060, 0x5, 0x5)
www.test.com/bagel/runtime/dump.go:58 +0x3f3
created by www.test.com/bagel/runtime.EnableGoroutineDump.func1
www.test.com/bagel/runtime/dump.go:30 +0x2d6Similar to show(), but with a conditional to only show items meeting certain criteria:
>> original.search("id < 2000", 15, 1) # offset 15, limit 1
goroutine 6455896 [select]:
net.(*netFD).connect.func2(0xea1980, 0xc424bca540, 0xc422c1af50, 0xc424bca600, 0xc424bca5a0)
go1.8.1.linux-amd64/src/net/fd_unix.go:133 +0x1d5
created by net.(*netFD).connect
go1.8.1.linux-amd64/src/net/fd_unix.go:144 +0x239One useful ability is to filter goroutines by running time:
>> original.search("duration > 10") # duration larger than 10 minutes
goroutine 72 [select, 25 minutes]: 119 times: [72, 54755, 76757, 299, 201, 286, 283, 296, 204, 302,
207, 305, 338, 356, 359, 362, 365, 372, 375, 368, 378, 328, 331, 387, 381
, 390, 384, 403, 393, 334, 406, 396, 399, 337, 418, 341, 436, 344, 439, 421, 424, 409, 427, 452, 430, 433, 442, 455, 445, 458, 448, 461, 464, 468, 483, 471, 499, 486, 502, 5
05, 489, 76462, 76773, 54530, 54572, 55194, 54824, 54481, 42719, 54691, 54859, 55023, 75593, 76750, 55202, 54885, 79006, 54468, 55212, 54473, 54462, 54931, 54864, 55133, 550
97, 54882, 54901, 55209, 54499, 55114, 54564, 76653, 54416, 54527, 75588, 55034, 54868, 54791, 54813, 54698, 54579, 55111, 54443, 54486, 76467, 54654, 54537, 54456, 55126, 5
5117, 54622, 55199, 54556, 54477, 54871, 79498, 76601, 76735, 76996]
google.golang.org/grpc/transport.(*http2Server).keepalive(0xc4202f0420)
google.golang.org/grpc/transport/http2_server.go:919 +0x488
created by google.golang.org/grpc/transport.newHTTP2Server
google.golang.org/grpc/transport/http2_server.go:226 +0x97cNote that the above is after a dedup operation, so it shows the same stack trace existing 119 times. See the "Dedup goroutines" section.
>> l, c, r = x.diff(y)
>> l
# of goroutines: 574
IO wait: 147
chan receive: 1
runnable: 3
select: 421
syscall: 2
>> c
# of goroutines: 651
IO wait: 157
runnable: 4
select: 489
semacquire: 1
>> r
# of goroutines: 992
IO wait: 229
chan receive: 49
chan send: 4
runnable: 31
running: 1
select: 594
semacquire: 84It returns three values: the dump var containing goroutines only appear in x (the left side), the dump var containing goroutines appear in both x and y, the dump var containing goroutines only appear in y (the right side).
Normally goroutine dump files contain thousands of goroutine entries, but there are many duplicated traces. Function dedup() helps to identify these duplicated traces by comparing the trace lines, and only keep one copy of them. It greatly reduces the information explosion and make developers much easier to focus on their problems.
>> a
# of goroutines: 2217
IO wait: 533
chan receive: 50
chan send: 4
runnable: 38
running: 1
select: 1504
semacquire: 85
syscall: 2
>> a.dedup()
Dedupped 2217, kept 46
>>
>> a
# of goroutines: 46
IO wait: 6
chan receive: 2
chan send: 2
runnable: 18
running: 1
select: 12
semacquire: 3
syscall: 2To show goroutines with 5+ duplicates:
>> a.search("dups >= 5")
...Check goroutine entries have surspicous goroutine deaklock.
>> a.check()
Dedupped 1453, kept 39
================= WARNING DEAD LOCK =================
goroutine 67777 has surspicous DEAD LOCK with goroutine 66926
LockHolders of goroutine 67777: [*Mutex *RWMutex *memoryStore *Daemon]
LockHolders of goroutine 66926: [*Mutex *State *Daemon *memoryStore *Daemon]After a dump var is modified, it can be saved to a file:
>> a.save("pprof-deduped.log")Each dump item has 5 properties which can be used in conditionals:
| property | type | meaning |
|---|---|---|
| id | integer | The goroutine ID. |
| dups | integer | The number of duplicate traces. |
| duration | integer | The waiting duration (in minutes) of a goroutine. |
| lines | integer | The number of lines of the goroutine's stack trace. |
| state | string | The running state of the goroutine. |
| trace | string | The concatenated text of the goroutine stack trace. |
The following functions can be used in defining conditionals:
| function | args | return value | meaning |
|---|---|---|---|
| contains | string, string | bool | Returns true if the first arg contains the second arg |
| lower | string | string | Returns the lowercased string of the input. |
| upper | string | string | Returns the uppercased string of the input. |
Example:
>> original.search("contains(lower(trace), 'handlestream')")