一台机器,CPU100%,如何找到相关服务,如何定位问题代码,今天简单分享下思路。
简要步骤如下:
- 找到最耗CPU的进程;
- 找到最耗CPU的线程;
- 查看堆栈,定位线程在干嘛,定位对应代码;
步骤一、找到最耗CPU的进程
工具:top 方法:
- 执行top -c ,显示进程运行信息列表
- 键入P (大写p),进程按照CPU使用率排序 图示:
如上图,最耗CPU的进程PID为10765。
步骤二:找到最耗CPU的线程
工具:top 方法:
- top -Hp 10765 ,显示一个进程的线程运行信息列表
- 键入P (大写p),线程按照CPU使用率排序 图示:
如上图,进程10765内,最耗CPU的线程PID为10804。
步骤三:查看堆栈,定位线程在干嘛,定位对应代码
首先,将线程PID转化为16进制。 工具:printf 方法:printf "%x\n" 10804
如上图,10804对应的16进制是0x2a34,当然,这一步可以用计算器。
之所以要转化为16进制,是因为堆栈里,线程id是用16进制表示的。
jave 查看方式
接着,查看堆栈,找到线程在干嘛。 工具:jstack 方法:jstack 10765 | grep '0x2a34' -C5 --color 打印进程堆栈 通过线程id,过滤得到线程堆栈 图示:
如上图,找到了耗CPU高的线程对应的线程名称“AsyncLogger-1”,以及看到了该线程正在执行代码的堆栈。
go的查看方式
目前pstack对于go进程根本不管用 目前我了解的唯一办法就是给进程发送SIGQUIT信号:
kill -SIGQUIT <pid>
go进程在收到SIGQUIT信号后,会往标准错误(stderr)打印出所有goroutine的stack信息。
但是遗憾的是,此时go进程也就退出了。
package main
import (
"runtime/debug"
"time"
)
func main() {
go a()
m1()
}
func m1() {
m2()
}
func m2() {
m3()
}
func m3() {
debug.PrintStack()
time.Sleep(time.Hour)
}
func a() {
time.Sleep(time.Hour)
}
打印出所有goroutine的 stacktrace
可以通过pprof.Lookup("goroutine").WriteTo将所有的goroutine的stack trace都打印出来,如下面的程序:
package main
import (
"os"
"runtime/pprof"
"time"
)
func main() {
go a()
m1()
}
func m1() {
m2()
}
func m2() {
m3()
}
func m3() {
pprof.Lookup("goroutine").WriteTo(os.Stdout, 1)
time.Sleep(time.Hour)
}
func a() {
time.Sleep(time.Hour)
}
较完美的输出 stacktrace
你可以使用runtime.Stack得到所有的goroutine的stack trace信息,事实上前面debug.PrintStack()也是通过这个方法获得的。
为了更方便的随时的得到应用所有的goroutine的stack trace信息,我们可以监听SIGUSER1信号,当收到这个信号的时候就将stack trace打印出来。发送信号也很简单,通过kill -SIGUSER1 就可以,不必担心kill会将程序杀死,它只是发了一个信号而已。
package main
import (
"fmt"
"os"
"os/signal"
"runtime"
"syscall"
"time"
)
func main() {
setupSigusr1Trap()
go a()
m1()
}
func m1() {
m2()
}
func m2() {
m3()
}
func m3() {
time.Sleep(time.Hour)
}
func a() {
time.Sleep(time.Hour)
}
func setupSigusr1Trap() {
c := make(chan os.Signal, 1)
signal.Notify(c, syscall.SIGUSR1)
go func() {
for range c {
DumpStacks()
}
}()
}
func DumpStacks() {
buf := make([]byte, 16384)
buf = buf[:runtime.Stack(buf, true)]
fmt.Printf("=== BEGIN goroutine stack dump ===\n%s\n=== END goroutine stack dump ===", buf)
}
=== BEGIN goroutine stack dump ===
goroutine 36 [running]:
main.DumpStacks()
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:47 +0x77
main.setupSigusr1Trap.func1(0xc420070060)
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:40 +0x73
created by main.setupSigusr1Trap
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:42 +0xec
goroutine 1 [sleep]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/time.go:59 +0xe1
main.m3()
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:28 +0x30
main.m2()
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:24 +0x14
main.m1()
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:20 +0x14
main.main()
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:16 +0x3f
goroutine 34 [syscall]:
os/signal.signal_recv(0xff280)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/sigqueue.go:116 +0x157
os/signal.loop()
/usr/local/Cellar/go/1.7.4/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.1
/usr/local/Cellar/go/1.7.4/libexec/src/os/signal/signal_unix.go:28 +0x41
goroutine 35 [select, locked to thread]:
runtime.gopark(0xb5cc8, 0x0, 0xab3ef, 0x6, 0x18, 0x2)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/proc.go:259 +0x13a
runtime.selectgoImpl(0xc42008d730, 0x0, 0x18)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/select.go:423 +0x11d9
runtime.selectgo(0xc42008d730)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/select.go:238 +0x1c
runtime.ensureSigM.func1()
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/signal1_unix.go:304 +0x2d1
runtime.goexit()
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/asm_amd64.s:2086 +0x1
goroutine 37 [sleep]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/time.go:59 +0xe1
main.a()
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:32 +0x30
created by main.main
/Users/yuepan/go/src/github.com/smallnest/dump/d3.go:15 +0x3a
=== END goroutine stack dump ===