Go -- 通过GOTRACEBACK生成程序崩溃后core文件的方法(gcore gdb)

Posted 2020-09-16 ⬆️小马哥⬆️

写一个错误的c程序

 

package dlsym

import "testing"

func Test_intercept(t *testing.T) {
    Intercept("gethostbyname\x00")
}

package dlsym

// #cgo CFLAGS: -I.
// #include <stddef.h>
// #include "dlsym_wrapper.h"
import "C"
import "unsafe"

func Intercept(symbol string) {
    ptr := unsafe.Pointer(&([]byte(symbol)[0]))
    C.intercept((*C.char)(ptr), C.size_t(len(symbol)))
}

#include <dlfcn.h>
#include <stddef.h>
#include <stdio.h>

void intercept(char *symbol, size_t symbol_len) {
    symbol = NULL; // will cause SIGSEGV
    printf("%s\n", symbol);
    fflush(stdout);
}

编译测试为可执行文件

go test -c github.com/taowen/go-lib c/dlsym
# will produce executable dlsym.test

这个是用于分析coredump的时候获得符号表使用的。

执行测试，获得coredump

GOTRACEBACK=crash ./dlsym.test
# produced /tmp/core_dlsym.test.29937

如果找不到coredump的位置，执行之前先设置好coredump的写出条件

echo ‘/tmp/core_%e.%p‘ | sudo tee /proc/sys/kernel/core_pattern
ulimit -c unlimited # coredump can be any large

用gdb分析coredump

gdb dlsym.test /tmp/core_dlsym.test /tmp/core_dlsym.test.29937

• 用 bt full 查看所有的frame

• 用 frame <number> 查看指定的frame

• 用 print <symbol> 查看指定的变量的值

 

 

 

通过cgo调用C语言库时会出现程序崩溃的情况，于是就希望能够生成core文件来查看程序崩溃时的堆栈信息。那么Golang程序如何在崩溃后生成core文件呢？答案就是GOTRACEBACK这个环境变量。

 

       关于GOTRACEBACK环境变量的详细说明，可以参考官方文档在runtime一节的链接，这里仅列出文档中较为核心的说明如下（Golang版本为1.6）。根据文档的说明我们可以知道GOTRACEBACK的可选值为：none、single、all、system和crash，其中关于crash的说明就指出了在Unix系统上，程序崩溃会通过SIGABRT信号触发一次core dump。

 

GOTRACEBACK=none omits the goroutine stack traces entirely. 

GOTRACEBACK=single (the default) behaves as described above. 

GOTRACEBACK=all adds stack traces for all user-created goroutines. 

GOTRACEBACK=system is like “all” but adds stack frames for run-time functions and shows goroutines created internally by the run-time. 

GOTRACEBACK=crash is like “system” but crashes in an operating system-specific manner instead of exiting. For example, on Unix systems, the crash raises SIGABRT to trigger a core dump.

 

       另外，虽然官方文档给出了GOTRACEBACK环境变量在不同选值下的行为说明，但看起来实在是有些不知所云，这里我们不妨通过一个简单的程序来验证一下，毕竟程序跑出来的效果才比较真实。以下是验证程序的代码，其功能非常简单，启动两个goroutine，一个正常跑10秒钟，一个睡5秒钟之后自行panic。

 

package main

import (

"fmt"

"time"

)

func saferoutine(c chan bool) {

for i := 0; i < 10; i++ {

fmt.Println("Count:", i)

time.Sleep(1 * time.Second)

}

c <- true

}

func panicgoroutine(c chan bool) {

time.Sleep(5 * time.Second)

panic("Panic, omg ...")

c <- true

}

func main() {

c := make(chan bool, 2)

go saferoutine(c)

go panicgoroutine(c)

for i := 0; i < 2; i++ {

<-c

}

}

 

       编译以上验证程序，然后在GOTRACEBACK取值为none的情况下执行，其结果如下。由此可知在取值为none时，程序仅仅打印出panic消息，之后程序就退出了。

 

# go build testgotraceback.go 

# env GOTRACEBACK=none ./testgotraceback 

Count: 0

Count: 1

Count: 2

Count: 3

Count: 4

panic: Panic, omg ...

 

       以下为GOTRACEBACK取值为single情况下的执行结果，此时还会打印出发生panic的goroutine（也就是main.panicgoroutine）的调用栈信息，而single也是GOTRACEBACK的默认值。

 

# env GOTRACEBACK=single ./testgotraceback

Count: 0

Count: 1

Count: 2

Count: 3

Count: 4

panic: Panic, omg ...

 

goroutine 6 [running]:

panic(0x4b8e00, 0xc82000a310)

/home/ubuntu/repository/oo/go/src/runtime/panic.go:464 +0x3e6

main.panicgoroutine(0xc82004e070)

/home/ubuntu/go/src/testcode/testgotraceback.go:18 +0x78

created by main.main

/home/ubuntu/go/src/testcode/testgotraceback.go:25 +0x79

 

       以下为GOTRACEBACK取值为all情况下的执行结果，此时不仅发生panic的goroutine（也就是main.panicgoroutine）的调用栈信息会被打印出来，主进程（main.main）和正常goroutine（也就是main.saferoutine）的调用栈信息也都被打印出来了。

 

# env GOTRACEBACK=all ./testgotraceback

Count: 0

Count: 1

Count: 2

Count: 3

Count: 4

panic: Panic, omg ...

 

goroutine 6 [running]:

panic(0x4b8e00, 0xc82000a300)

/home/ubuntu/repository/oo/go/src/runtime/panic.go:464 +0x3e6

main.panicgoroutine(0xc82004e070)

/home/ubuntu/go/src/testcode/testgotraceback.go:18 +0x78

created by main.main

/home/ubuntu/go/src/testcode/testgotraceback.go:25 +0x79

 

goroutine 1 [chan receive]:

main.main()

/home/ubuntu/go/src/testcode/testgotraceback.go:27 +0xa9

 

goroutine 5 [sleep]:

time.Sleep(0x3b9aca00)

/home/ubuntu/repository/oo/go/src/runtime/time.go:59 +0xf9

main.saferoutine(0xc82004e070)

/home/ubuntu/go/src/testcode/testgotraceback.go:11 +0x177

created by main.main

/home/ubuntu/go/src/testcode/testgotraceback.go:24 +0x57

 

       以下为GOTRACEBACK取值为system情况下的执行结果，此时除了我们明显知道的三个goroutine的调用栈信息会被打印出来以外，很多隐形存在的系统级goroutine的信息也被打印出来了。因为本博主还不太了解Golang运行期机制，这里就不对这些系统级的goroutine一一做介绍了，但最明显的是有用来做垃圾回收的相关协程。

 

# env GOTRACEBACK=system ./testgotraceback

Count: 0

Count: 1

Count: 2

Count: 3

Count: 4

panic: Panic, omg ...

 

goroutine 6 [running]:

panic(0x4b8e00, 0xc820064090)

/home/ubuntu/repository/oo/go/src/runtime/panic.go:464 +0x3e6 fp=0xc820028778 sp=0xc8200286f8

main.panicgoroutine(0xc820056070)

/home/ubuntu/go/src/testcode/testgotraceback.go:18 +0x78 fp=0xc8200287b8 sp=0xc820028778

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8200287c0 sp=0xc8200287b8

created by main.main

/home/ubuntu/go/src/testcode/testgotraceback.go:25 +0x79

 

goroutine 1 [chan receive]:

runtime.gopark(0x52b150, 0xc8200560c8, 0x5005c0, 0xc, 0x17, 0x3)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:262 +0x163 fp=0xc82003de30 sp=0xc82003de08

runtime.goparkunlock(0xc8200560c8, 0x5005c0, 0xc, 0x17, 0x3)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:268 +0x54 fp=0xc82003de68 sp=0xc82003de30

runtime.chanrecv(0x4b4780, 0xc820056070, 0x0, 0xc82003df01, 0x400000)

/home/ubuntu/repository/oo/go/src/runtime/chan.go:470 +0x49f fp=0xc82003def0 sp=0xc82003de68

runtime.chanrecv1(0x4b4780, 0xc820056070, 0x0)

/home/ubuntu/repository/oo/go/src/runtime/chan.go:355 +0x2b fp=0xc82003df20 sp=0xc82003def0

main.main()

/home/ubuntu/go/src/testcode/testgotraceback.go:27 +0xa9 fp=0xc82003df50 sp=0xc82003df20

runtime.main()

/home/ubuntu/repository/oo/go/src/runtime/proc.go:188 +0x2b0 fp=0xc82003dfa0 sp=0xc82003df50

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc82003dfa8 sp=0xc82003dfa0

 

goroutine 2 [force gc (idle)]:

runtime.gopark(0x52b150, 0x585640, 0x500ce0, 0xf, 0x14, 0x1)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:262 +0x163 fp=0xc820026758 sp=0xc820026730

runtime.goparkunlock(0x585640, 0x500ce0, 0xf, 0xc820000314, 0x1)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:268 +0x54 fp=0xc820026790 sp=0xc820026758

runtime.forcegchelper()

/home/ubuntu/repository/oo/go/src/runtime/proc.go:229 +0xb8 fp=0xc8200267c0 sp=0xc820026790

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8200267c8 sp=0xc8200267c0

created by runtime.init.4

/home/ubuntu/repository/oo/go/src/runtime/proc.go:218 +0x2b

 

goroutine 3 [GC sweep wait]:

runtime.gopark(0x52b150, 0x585760, 0x4ff370, 0xd, 0x41bf14, 0x1)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:262 +0x163 fp=0xc820026f48 sp=0xc820026f20

runtime.goparkunlock(0x585760, 0x4ff370, 0xd, 0x14, 0x1)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:268 +0x54 fp=0xc820026f80 sp=0xc820026f48

runtime.bgsweep(0xc820056000)

/home/ubuntu/repository/oo/go/src/runtime/mgcsweep.go:63 +0xb1 fp=0xc820026fb8 sp=0xc820026f80

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc820026fc0 sp=0xc820026fb8

created by runtime.gcenable

/home/ubuntu/repository/oo/go/src/runtime/mgc.go:191 +0x53

 

goroutine 4 [finalizer wait]:

runtime.gopark(0x52b150, 0x59fc00, 0x500a40, 0xe, 0x14, 0x1)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:262 +0x163 fp=0xc820027718 sp=0xc8200276f0

runtime.goparkunlock(0x59fc00, 0x500a40, 0xe, 0x14, 0x1)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:268 +0x54 fp=0xc820027750 sp=0xc820027718

runtime.runfinq()

/home/ubuntu/repository/oo/go/src/runtime/mfinal.go:158 +0xaa fp=0xc8200277c0 sp=0xc820027750

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8200277c8 sp=0xc8200277c0

created by runtime.createfing

/home/ubuntu/repository/oo/go/src/runtime/mfinal.go:139 +0x60

 

goroutine 5 [sleep]:

runtime.gopark(0x52b150, 0x585780, 0x4fded0, 0x5, 0x643513, 0x2)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:262 +0x163 fp=0xc82003ee80 sp=0xc82003ee58

runtime.goparkunlock(0x585780, 0x4fded0, 0x5, 0x13, 0x2)

/home/ubuntu/repository/oo/go/src/runtime/proc.go:268 +0x54 fp=0xc82003eeb8 sp=0xc82003ee80

time.Sleep(0x3b9aca00)

/home/ubuntu/repository/oo/go/src/runtime/time.go:59 +0xf9 fp=0xc82003ef00 sp=0xc82003eeb8

main.saferoutine(0xc820056070)

/home/ubuntu/go/src/testcode/testgotraceback.go:11 +0x177 fp=0xc82003efa8 sp=0xc82003ef00

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc82003efb0 sp=0xc82003efa8

created by main.main

/home/ubuntu/go/src/testcode/testgotraceback.go:24 +0x57

 

goroutine 7 [syscall]:

runtime.notetsleepg(0x585798, 0x682c29, 0x0)

/home/ubuntu/repository/oo/go/src/runtime/lock_futex.go:205 +0x4e fp=0xc820028f38 sp=0xc820028f10

runtime.timerproc()

/home/ubuntu/repository/oo/go/src/runtime/time.go:209 +0xde fp=0xc820028fc0 sp=0xc820028f38

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc820028fc8 sp=0xc820028fc0

created by runtime.addtimerLocked

/home/ubuntu/repository/oo/go/src/runtime/time.go:116 +0x11f

 

       以下为GOTRACEBACK取值为crash情况下的执行结果，当然在执行之前我们需要修改core文件大小为unlimited，此时打印出来的内容与system的情况下基本一样，除了最后那行代表core dump的提示。另外，在当前目录下，我们想要的core文件出现了！所以在Linux系统下，crash与system的区别就是，前者可以生成core文件。

 

# ulimit -c unlimited

# env GOTRACEBACK=crash ./testgotraceback

...

goroutine 21 [runnable]:

runtime.notetsleepg(0x585798, 0x11b22e, 0x0)

/home/ubuntu/repository/oo/go/src/runtime/lock_futex.go:205 +0x4e fp=0xc820024738 sp=0xc820024710

runtime.timerproc()

/home/ubuntu/repository/oo/go/src/runtime/time.go:209 +0xde fp=0xc8200247c0 sp=0xc820024738

runtime.goexit()

/home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8200247c8 sp=0xc8200247c0

created by runtime.addtimerLocked

/home/ubuntu/repository/oo/go/src/runtime/time.go:116 +0x11f

Aborted (core dumped)

# ls -l

total 5400

-rw------- 1 ubuntu ubuntu 1994752 Apr 20 18:11 core

-rwxrwxr-x 1 ubuntu ubuntu 2295416 Apr 20 17:38 testgotraceback

-rw-rw-r-- 1 ubuntu ubuntu     395 Apr 20 17:38 testgotraceback.go

 

       通过gdb命令，我们可以看到程序发生崩溃时的具体位置，这样即使崩溃点发生在C语言库中，也可以快速定位问题，简直就是so nice！

 

# gdb ./testgotraceback core

(gdb) bt

#0  runtime.raise () at /home/ubuntu/repository/oo/go/src/runtime/sys_linux_amd64.s:110

#1  0x0000000000438588 in runtime.dieFromSignal (sig=6) at /home/ubuntu/repository/oo/go/src/runtime/signal1_unix.go:192

#2  0x00000000004386af in runtime.crash () at /home/ubuntu/repository/oo/go/src/runtime/signal1_unix.go:247

#3  0x000000000042886e in runtime.dopanic_m (gp=0xc820001380, pc=4357542, sp=859530495736)

    at /home/ubuntu/repository/oo/go/src/runtime/panic.go:642

#4  0x000000000044ad72 in runtime.dopanic.func1 () at /home/ubuntu/repository/oo/go/src/runtime/panic.go:517

#5  0x0000000000453569 in runtime.systemstack () at /home/ubuntu/repository/oo/go/src/runtime/asm_amd64.s:291

#6  0x000000000042c6b0 in runtime.startTheWorldWithSema () at /home/ubuntu/repository/oo/go/src/runtime/proc.go:983

#7  0x000000c82001f500 in ?? ()

#8  0x0000000000000000 in ?? ()

 

参考链接：http://dave.cheney.net/2015/11/29/a-whirlwind-tour-of-gos-runtime-environment-variables