goframe框架 一个简单bug,排查过程分享

18393910396 · 2020-06-17 16:44:15 · 3375 次点击 · 大约8小时之前 开始浏览    置顶
这是一个创建于 2020-06-17 16:44:15 的主题,其中的信息可能已经有所发展或是发生改变。

[TOC]

1: 问题描述

一次不小心复制使用了相同的pattern (如下图:blackListOpt),发现程序一运行就退出,没有报错信息。最后是pattern重复了,但按理说,handler map会报错,所以就在空闲时间做了分析梳理

    s.Use(MiddlewareCORS, JWTAuth)
    user := new(api.AccountController)
    s.BindHandler("POST:/user/login", user.Login)
    s.BindHandler("GET:/user/userInfo", user.GetUserInfo)
    s.BindHandler("POST:/user/blackListOpt", user.BlackListOpt)
    s.BindHandler("POST:/user/blackListOpt", user.Report)

2: 先看handler注册

发现setHandler方法里面有重复路由检测,并会进行log.Fatal

思考:为什么glog.fatal没有输出打印信息呢?

猜测: 没有来得及打印日志就退出了。极大可能是异步日志。

验证: 添加fmt.Println,发现可以正常打印,在源码设置sleep之后也可以正常输出,基本上100%确定是异步日志

// handler会注册到这个切片中
var (
    preBindItems = make([]preBindItem, 0, 64)
)

// handler注册具体实现
func (g *RouterGroup) preBind(bindType string, pattern string, object interface{}, params ...interface{}) *RouterGroup {
    preBindItems = append(preBindItems, preBindItem{
        group:    g,
        bindType: bindType,
        pattern:  pattern,
        object:   object,
        params:   params,
    })
    return g
}

// 在server.Start()中,会遍历preBindItems ,并作检测
func (s *Server) handlePreBindItems() {
    for k, item := range preBindItems {
        // Handle the items of current server.
        if item.group.server != nil && item.group.server != s {
            continue
        }
        if item.group.domain != nil && item.group.domain.s != s {
            continue
        }
        item.group.doBind(item.bindType, item.pattern, item.object, item.params...)
    }
}

//   --------------注意-------------- 路由注册处理方法。
// 非叶节点为哈希表检索节点,按照URI注册的层级进行高效检索,直至到叶子链表节点;
// 叶子节点是链表,按照优先级进行排序,优先级高的排前面,按照遍历检索,按照哈希表层级检索后的叶子链表数据量不会很大,所以效率比较高;

//  发现框架有处理--注册地址记录及重复注册判断
func (s *Server) setHandler(pattern string, handler *handlerItem) {
    handler.itemId = handlerIdGenerator.Add(1)
    domain, method, uri, err := s.parsePattern(pattern)
    if err != nil {
        glog.Fatal("invalid pattern:", pattern, err)
        return
    }
    if len(uri) == 0 || uri[0] != '/' {
        glog.Fatal("invalid pattern:", pattern, "URI should lead with '/'")
        return
    }
    // 注册地址记录及重复注册判断
    regKey := s.handlerKey(handler.hookName, method, uri, domain)
    if !s.config.RouteOverWrite {
        switch handler.itemType {
        case gHANDLER_TYPE_HANDLER, gHANDLER_TYPE_OBJECT, gHANDLER_TYPE_CONTROLLER:
            if item, ok := s.routesMap[regKey]; ok {
                fmt.Printf(`1 duplicated route registry "%s", already registered at %s`, pattern, item[0].file)
                glog.Fatalf(`2 duplicated route registry "%s", already registered at %s`, pattern, item[0].file)
                return
            }
        }
    }

3: 继续深入源码glog.Fatalf()

终于找见了,把printToWriter放到grpool ,异步执行。os.Exit()先执行了,导致错误日志不打印

// glog.Fatalf方法
func (l *Logger) Fatalf(format string, v ...interface{}) {
    l.printErr("[FATA]", l.format(format, v...))
    //time.Sleep(time.Second*1)
    os.Exit(1)
}

//printErr 方法
func (l *Logger) printErr(lead string, value ...interface{}) {
    if l.config.StStatus == 1 {
        if s := l.GetStack(); s != "" {
            value = append(value, "\nStack:\n"+s)
        }
    }
    // In matter of sequence, do not use stderr here, but use the same stdout.
    l.print(os.Stdout, lead, value...)
}
//print方法

// 发现了关键字ASYNC, 哈哈,离真相越来越近了

    if l.config.Flags&F_ASYNC > 0 {
        err := asyncPool.Add(func() {
            l.printToWriter(std, buffer)
        })
        if err != nil {
            intlog.Error(err)
        }
    } else {
        l.printToWriter(std, buffer)
    }

// 这难道就是真相?
    F_ASYNC      = 1 << iota // Print logging content asynchronously。 日志异步打印

// 是的,把printToWriter放到grpool ,异步执行
// Add pushes a new job to the pool.
// The job will be executed asynchronously.
func (p *Pool) Add(f func()) error {
    for p.closed.Val() {
        return errors.New("pool closed")
    }
    p.list.PushFront(f)
    // Check whether fork new goroutine or not.
    var n int
    for {
        n = p.count.Val()
        if p.limit != -1 && n >= p.limit {
            // No need fork new goroutine.
            return nil
        }
        if p.count.Cas(n, n+1) {
            // Use CAS to guarantee atomicity.
            break
        }
    }
    p.fork()
    return nil
}

4:反思

还是写代码要多细心,尽量减少低级 Bug 的出现。要多学习,向各位相互学习交流


有疑问加站长微信联系(非本文作者)

入群交流(和以上内容无关):加入Go大咖交流群,或添加微信:liuxiaoyan-s 备注:入群;或加QQ群:692541889

3375 次点击  ∙  1 赞  
加入收藏 微博
暂无回复
添加一条新回复 (您需要 登录 后才能回复 没有账号 ?)
  • 请尽量让自己的回复能够对别人有帮助
  • 支持 Markdown 格式, **粗体**、~~删除线~~、`单行代码`
  • 支持 @ 本站用户;支持表情(输入 : 提示),见 Emoji cheat sheet
  • 图片支持拖拽、截图粘贴等方式上传