前言:

我们知道在golang社区里多数web框架自带了panic后的recovery功能。go的recovery可以当成一个保护方案，避免因为各种错误导致进程挂掉，业务受到影响，继而影响kpi，最后钱少了，媳妇就不乐意了，不让你进家门…

golang echo这个框架也有recovery的功能，但他的默认方法着实坑人，该坑会引起我们标题中的所描述的高延迟和阻塞问题。 感谢前同事发现的问题 @趣头条架构师徐鹏

该文章后续仍在不断的更新修改中， 请移步到原文地址 http://xiaorui.cc/?p=6294

源码解读：

下面是官方给的例子，像其他web框架一样，把recovery做到了中间件里面。

// xiaorui.cc

package main

import (
  "net/http"
  "github.com/labstack/echo/v4"
  "github.com/labstack/echo/v4/middleware"
)

func main() {
  // Echo instance
  e := echo.New()

  // Middleware
  e.Use(middleware.Recover())
 ...

默认的config.DisableStackAll为false，下面使用了 ! 符号，负负得正。简单说，默认是打印所有的协程栈，当然最后的打印依赖stackSize，buf值为4KB大小。

// xiaorui.cc

				if r := recover(); r != nil {
					err, ok := r.(error)
					if !ok {
						err = fmt.Errorf("%v", r)
					}
					stack := make([]byte, config.StackSize)
					length := runtime.Stack(stack, !config.DisableStackAll)
					if !config.DisablePrintStack {
						c.Logger().Printf("[PANIC RECOVER] %v %s\n", err, stack[:length])
					}
					c.Error(err)
				}

当all=false时，只会获取当前协程的函数调用栈信息，无需加锁。但all=true时，意味着要获取所有协程的栈信息，在go runtime的pmg调度模型下，为了保证并发操作安全，自然就需要在stack方法里加了锁，且锁的粒度还不小，直接调用stopTheWorld用来阻塞GC的操作。

goroutineheader方法用来获取协程的状态信息，比如等待锁，scan，已等待时间等。allgs是runtime保存的所有已创建协程的容器，当然不会去追踪已经消亡的协程。另外，为了保护allgs切片的安全，还会对allglock加锁，在allgadd()创建goroutine和checkdead()检测死锁里会产生锁竞争。

// xiaorui.cc

func Stack(buf []byte, all bool) int {
	if all {
		stopTheWorld("stack trace")
	}

	n := 0
	if len(buf) > 0 {
		gp := getg()
		sp := getcallersp()
		pc := getcallerpc()
		systemstack(func() {
			g0 := getg()
			g0.m.traceback = 1
			g0.writebuf = buf[0:0:len(buf)]
			goroutineheader(gp)
			traceback(pc, sp, 0, gp)
			if all {
				tracebackothers(gp)
			}
			g0.m.traceback = 0
			n = len(g0.writebuf)
			g0.writebuf = nil
		})
	}

	if all {
		startTheWorld()
	}
	return n
}

func tracebackothers(me *g) {
	g := getg()
	gp := g.m.curg
	if gp != nil && gp != me {
		print("\n")
		goroutineheader(gp)
		traceback(^uintptr(0), ^uintptr(0), 0, gp)
	}

	lock(&allglock)
	for _, gp := range allgs {
		if gp == me || gp == g.m.curg || readgstatus(gp) == _Gdead || isSystemGoroutine(gp, false) && level < 2 {
			continue
		}
		print("\n")
		goroutineheader(gp)
		if gp.m != g.m && readgstatus(gp)&^_Gscan == _Grunning {
			print("\tgoroutine running on other thread; stack unavailable\n")
			printcreatedby(gp)
		} else {
			traceback(^uintptr(0), ^uintptr(0), 0, gp)
		}
	}
	unlock(&allglock)
}

func goroutineheader(gp *g) {
	// approx time the G is blocked, in minutes
	var waitfor int64
	if (gpstatus == _Gwaiting || gpstatus == _Gsyscall) && gp.waitsince != 0 {
		waitfor = (nanotime() - gp.waitsince) / 60e9
	}
	print("goroutine ", gp.goid, " [", status)
	if isScan {
		print(" (scan)")
	}
	if waitfor >= 1 {
		print(", ", waitfor, " minutes")
	}
...

我们可以设想一下，在echo里某个接口并发的出现了recovery的问题，那么都会走上面的加锁的过程，而且还并发操作，那么势必会造成阻塞和高时延的问题。

其他web框架的recovery源码：

追了下gin和iris的recovery源码实现，都只传递需要打印的栈层数，然后调用runtime.Caller获取栈的信息。https://github.com/gin-gonic/gin/blob/master/recovery.go

// xiaorui.cc

func stack(skip int) []byte {
	buf := new(bytes.Buffer) // the returned data
	// As we loop, we open files and read them. These variables record the currently
	// loaded file.
	var lines [][]byte
	var lastFile string
	for i := skip; ; i++ { // Skip the expected number of frames
		pc, file, line, ok := runtime.Caller(i)
		if !ok {
			break
		}
		// Print this much at least.  If we can't find the source, it won't show.
		fmt.Fprintf(buf, "%s:%d (0x%x)\n", file, line, pc)
		if file != lastFile {
			data, err := ioutil.ReadFile(file)
			if err != nil {
				continue
			}
			lines = bytes.Split(data, []byte{'\n'})
			lastFile = file
		}
		fmt.Fprintf(buf, "\t%s: %s\n", function(pc), source(lines, line))
	}
	return buf.Bytes()
}

其他打印协程的方法？

debug.PrintStack可打印当前协程的栈信息，相比上面runtime.Stack和runtime.Caller，该方法只能输出到标准错误输出的fd上。为了能完整输出栈信息，还精细的做了buf的扩充重试。😅 另外，pprof也提供了栈的打印，pprof.Lookup(“goroutine”)就可以拿到。

// xiaorui.cc

func PrintStack() {
	os.Stderr.Write(Stack())
}

func Stack() []byte {
	buf := make([]byte, 1024)
	for {
		n := runtime.Stack(buf, false)
		if n < len(buf) {
			return buf[:n]
		}
		buf = make([]byte, 2*len(buf))
	}
}

解决方法：

修改默认值，让recovery只打印当前协程栈信息，这样就避免了加锁的各种操作了。更推荐的方法是自定义中间件来实现recovery，runtime.Caller的性能要优于runtime.Stack。

总结：

以前文章就多次讲过，要小心golang的锁 😅。锁会造成各种的性能问题，通常表现为吞吐性能不足，指标为高延迟及阻塞。

话说这算不算是个坑？不太理解echo默认的recovery居然是打印所有协程栈。按照常规排错的理解，通常只需要关注哪里崩了就可以了。不理解...