Golang panic&recover 详解

前言

近期在编写并发 goroutine 以及超时控制时，出现了意料之外的没有 handle 住的 panic ，导致程序直接退出

具体场景大致如下：

func main() {
	defer myRecover()

	ctx, canceller := context.WithTimeout(context.Background(), 1*time.Minute)
	defer canceller()

	startTime := time.Now()
	done := make(chan struct{}, 1)
	// do task
	go func() {
		defer close(done)
		panic("some panic")
    done <- struct{}{}
	}()

	select {
	case <-ctx.Done():
		if ctx.Err() != nil {
			zaplog.Logger.Error("ctx.Done closed", zaplog.Error(ctx.Err()), zaplog.Any("timeCost", time.Since(startTime)))
		} else {
			zaplog.Logger.Error("ctx.Done closed, no error, get sys message to quit")
		}
		return
	case msg, ok := <-done:
		if !ok {
			panic(fmt.Sprintf("done closed without sending any message"))
		}
		zaplog.Logger.Info("done closed, get message", zaplog.Any("msg", msg), zaplog.Any("timeCost", time.Since(startTime)))
		return
	}
  ticker := time.NewTicker(1 * time.Second)
	count := 0
	for range ticker.C {
		count++
		zaplog.Logger.Info("main loop...", zaplog.Int("count", count))
	}
}

func myRecover() {
	if err := recover(); err != nil {
		errMsg := fmt.Sprintf("======== Panic ========\nPanic: %v\nTraceBack:\n%s\n======== Panic ========", err, string(debug.Stack()))
		zaplog.Logger.DPanic(errMsg)
	}
}

实际运行情况是 main 中没有打印出done closed, get message的日志，直接退出了程序

值得注意的是，我们在 main 中是有进行 panic 的统一异常处理的，但是很明显的是 Goroutine 的外层的 defer 并没有 cover 住这个异常

需要了解的词

Goroutine
Goroutine 是Go语言中并发的执行单位，可以认为 Go 协程是轻量级的线程，由 Go 运行时来管理
panic
能够改变程序的控制流，调用 panic 后会立刻停止执行当前函数的剩余代码，并在当前 Goroutine 中递归执行调用方的 defer
recover
可以中止 panic 造成的程序崩溃。它是一个只能在 defer 中发挥作用的函数，在其他作用域中调用不会发挥作用

原因分析

首先我们要知道panic和recover的特性：

panic 只会触发当前 Goroutine 的 defer
recover 只有在 defer 中调用才会生效
panic 允许在 defer 中嵌套多次调用

golang-panic-and-defers

多个 Goroutine 之间没有太多的关联，自然一个 Goroutine 在 panic 时也不应该执行其他 Goroutine 的延迟函数；具体到实现来说，之所以 panic 只会对当前 Goroutine 的 defer 有效是因为在 newdefer 分配 _defer 结构体对象的时，会把分配到的对象链入当前 Goroutine 的 _defer 链表的表头中（如下图所示）

实际上 panic的数据结构为：

type _panic struct {
	argp      unsafe.Pointer // pointer to arguments of deferred call run during panic; cannot move - known to liblink
	arg       interface{}    // argument to panic
	link      *_panic        // link to earlier panic
	pc        uintptr        // where to return to in runtime if this panic is bypassed
	sp        unsafe.Pointer // where to return to in runtime if this panic is bypassed
	recovered bool           // whether this panic is over
	aborted   bool           // the panic was aborted
	goexit    bool
}

argp 是指向 defer 调用时参数的指针
arg 是我们调用 panic 时传入的参数
link 指向的是更早调用 runtime._panic 结构，也就是说 painc 可以被连续调用，他们之间形成链表
recovered 表示当前 runtime._panic 是否被 recover 恢复
aborted 表示当前的 panic 是否被强行终止

从数据结构中的 link 字段我们就可以推测出以下的结论：panic 函数可以被连续多次调用，它们之间通过 link 可以组成链表

结构体中的 pc、sp 和 goexit 三个字段都是为了修复 runtime.Goexit 带来的问题引入的1。runtime.Goexit 能够只结束调用该函数的 Goroutine 而不影响其他的 Goroutine，但是该函数会被 defer 中的 panic 和 recover 取消2，引入这三个字段就是为了保证该函数的一定会生效

所以实际的 panic 流程是这样的：

实际修复与测试

再看回我们的实际场景

外层的 select 会阻塞住主进程，panic 是在内层的 goroutine 中触发的，所以会先执行 goroutine 中的 defer，即：

func() { done <- struct{}{} }()
close(done)

当 close(done)后，正常情况下外层 select case 中的 case msg, ok := <-done:解除阻塞，但这时内层 goroutine 的 defer 已经执行完了，没有被 recover ，直接导致程序退出，外层的 recover 并不能保证程序的继续运行

在内层 goroutine task 中加入 defer myRecover()后，外层仍可正常运行main loop

func main() {
	defer myRecover()

	ctx, canceller := context.WithTimeout(context.Background(), 1*time.Minute)
	defer canceller()

	startTime := time.Now()
	done := make(chan struct{}, 1)
	// do task
	go func() {
		defer myRecover()
		defer func() {
			ticker := time.NewTicker(time.Second)
			defer ticker.Stop()
			count := 0
			for range ticker.C {
				count++
				zaplog.Logger.Info("waiting for recover...", zaplog.Int("count", count))
				if count >= 5 {
					zaplog.Logger.Info("no recover, panic...")
					return
				}
			}
		}()
		defer close(done)
		defer func() { done <- struct{}{} }()
		panic("some panic")
	}()

	select {
	case <-ctx.Done():
		if ctx.Err() != nil {
			zaplog.Logger.Error("ctx.Done closed", zaplog.Error(ctx.Err()), zaplog.Any("timeCost", time.Since(startTime)))
		} else {
			zaplog.Logger.Error("ctx.Done closed, no error, get sys message to quit")
		}
		return
	case msg, ok := <-done:
		if !ok {
			panic(fmt.Sprintf("done closed without sending any message"))
		}
		zaplog.Logger.Info("done closed, get message", zaplog.Any("msg", msg), zaplog.Any("timeCost", time.Since(startTime)))
	}
	ticker := time.NewTicker(1 * time.Second)
	count := 0
	for range ticker.C {
		count++
		zaplog.Logger.Info("main loop...", zaplog.Int("count", count))
	}
}

func myRecover() {
	if err := recover(); err != nil {
		errMsg := fmt.Sprintf("======== Panic ========\nPanic: %v\nTraceBack:\n%s\n======== Panic ========", err, string(debug.Stack()))
		zaplog.Logger.DPanic(errMsg)
	}
}