我们知道在golang社区里多数web框架自带了panic后的recovery功能。go的recovery可以当成一个保护方案,避免因为各种错误导致进程挂掉,业务受到影响。golang echo 这个框架也有 recovery 的功能,但他的默认方法着实坑人,该坑会引起我们标题中的所描述的高延迟和阻塞问题。
下面是官方给的例子,像其他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的问题,那么都会走上面的加锁的过程,而且还并发操作,那么势必会造成阻塞和高时延的问题。
追了下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的锁 😅。锁会造成各种的性能问题,通常表现为吞吐性能不足,指标为高延迟及阻塞。