记一次go panic问题的解决过程

640



一. Panic问题概述


本周收到客户在bugclose上填写的一个issue:添加一个下发通道后,pushd程序panic并退出了!程序panic时输出的stacktrace信息摘录如下:


 
 
panic: runtime error: invalid memory address or nil pointer dereference[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x8ca449]goroutine 266900 [running]:pkg.tonybai.com/smspush/vendor/github.com/bigwhite/gocmpp.(*Client).Connect(0xc42040c7f0, 0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0x0, 0x0)        /root/.go/src/pkg.tonybai.com/smspush/vendor/github.com/bigwhite/gocmpp/client.go:79 +0x239pkg.tonybai.com/smspush/pkg/pushd/pusher.cmpp2Login(0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0xc4203d29c0, 0x11, 0x73)        /root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/cmpp2_handler.go:25 +0x9apkg.tonybai.com/smspush/pkg/pushd/pusher.newCMPP2Loop(0xc42071f800, 0x4, 0xaaecd8)        /root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/cmpp2_handler.go:65 +0x226pkg.tonybai.com/smspush/pkg/pushd/pusher.(*tchanSession).Run(0xc42071f800, 0xaba7c3, 0x17)        /root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/session.go:52 +0x98pkg.tonybai.com/smspush/pkg/pushd/pusher.(*gateway).addSession.func1(0xc4200881a0, 0xc42071f800, 0xc42040c700)        /root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/gateway.go:61 +0x11ecreated by pkg.tonybai.com/smspush/pkg/pushd/pusher.(*gateway).addSession        /root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/gateway.go:58 +0x350or nil pointer dereference

[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x8ca449]



goroutine 266900 [running]:

pkg.tonybai.com/smspush/vendor/github.com/bigwhite/gocmpp.(*Client).Connect(0xc42040c7f0, 0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0x0, 0x0)

/root/.go/src/pkg.tonybai.com/smspush/vendor/github.com/bigwhite/gocmpp/client.go:79 +0x239

pkg.tonybai.com/smspush/pkg/pushd/pusher.cmpp2Login(0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0xc4203d29c0, 0x11, 0x73)

/root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/cmpp2_handler.go:25 +0x9a

pkg.tonybai.com/smspush/pkg/pushd/pusher.newCMPP2Loop(0xc42071f800, 0x4, 0xaaecd8)

/root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/cmpp2_handler.go:65 +0x226

pkg.tonybai.com/smspush/pkg/pushd/pusher.(*tchanSession).Run(0xc42071f800, 0xaba7c3, 0x17)

/root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/session.go:52 +0x98

pkg.tonybai.com/smspush/pkg/pushd/pusher.(*gateway).addSession.func1(0xc4200881a0, 0xc42071f800, 0xc42040c700)

/root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/gateway.go:61 +0x11e

created by pkg.tonybai.com/smspush/pkg/pushd/pusher.(*gateway).addSession

/root/.go/src/pkg.tonybai.com/smspush/pkg/pushd/pusher/gateway.go:58 +0x350


印象中近大半年用Go写的程序,遇到panic情况不多。上一次是因为原生map变量的并发访问导致的panic,那次panic一眼就看到问题所在了。但这次又是因为啥呢?




二. 分析和debug过程


这个问题在印象中似乎出现过,不过由于当初没有复现,客户环境中又没有panic信息提供,那时没能定位和解决,后来问题并没有出现,显然这个问题是有一定“随机属性”。


对于panic,我们首先检查直接导致panic发生的那一行代码:


        /root/.go/src/pkg.tonybai.com/smspush/vendor/github.com/bigwhite/gocmpp/client.go:79 +0x239


下面是client.go 79行周围的代码片段:


640?wx_fmt=png


也许是疏忽大意,当时瞅了一眼后,就断定这块没有问题(更多从业务协议层面考虑),这也直接导致后面绕了一个大圈子才查到”真凶”。如果您还没看出来问题,那继续往下看。


定式思维让我认为很可能是函数栈中的内存问题,于是我开始调查panic输出的函数调用栈中参数是否正确。


要想知道函数调用栈中参数传递是否有问题,先要知晓panic后输出的栈帧信息都是什么!比如下面panic dump信息中参数中的各种magic number都代表什么!


 
 
gocmpp.(*Client).Connect(0xc42040c7f0, 0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0x0, 0x0)pusher.cmpp2Login(0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0xc4203d29c0, 0x11, 0x73)pusher.newCMPP2Loop(0xc42071f800, 0x4, 0xaaecd8)0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0x0, 0x0)



pusher.cmpp2Login(0xc4203d29c0, 0x11, 0xc420423256, 0x6, 0xc420423260, 0x8, 0x37e11d600, 0xc4203d29c0, 0x11, 0x73)



pusher.newCMPP2Loop(0xc42071f800, 0x4, 0xaaecd8)


在Joe Shaw的《Understanding Go panic output》和William Kennedy的《Stack Traces In Go》中有针对Stack trace输出信息的解析。关于Stack trace输出信息的识别,总体遵循几个要点:


  • stack trace中每个函数/方法后面的“参数数值”个数与函数/方法原型的参数个数不是一一对应的;


  • stack trace中每个函数/方法后面的“参数数值”是按照函数/方法原型参数列表中从左到右的参数类型的内存布局逐一展开的; 每个数值占用一个word(64位平台下面为8字节)


  • 如果是method,则第一个参数是receiver自身。如果reciever是指针类型,则第一个参数数值就是一个指针地址;如果是非指针的实例,则stack trace会按照其内存布局输出;


  • 函数/方法返回值放在stack trace的“参数数值”列表的后面;如果有多个返回值,则同样按从左到右顺序,按照返回值类型的内存布局输出;


  • 指针类型参数:占用stack trace的“参数数值”列表的1个位置;数值表示指针值,也是指针指向的对象的地址;


  • string类型参数:由于string在内存中由两个字(word)表示,第一个字是数据指针,第二个字是string的长度,因此在stack trace的“参数数值”列表中将占用两个位置;


  • slice类型参数:由于slice类型在内存中由三个字表示,第一个word是数据指针,第二个word是len,第三个字是cap,因此在stack trace的“参数数值”列表中将占用三个位置;


  • 内建整型(int,rune,byte):由于按word逐个输出,对于类型长度不足一个Word的参数,会做合并处理;比如:一个函数有5个int16类型的参数,那么在stack trace的信息中,这5个参数将占用stack trace的“参数数值”列表中的两个位置;第一个位置是前4个参数的“合体”,第二个位置则是最后那个int16类型的参数值。


  • struct类型参数: 会按照struct中字段的内存布局顺序在stack trace中展开。


  • interface类型参数:由于interface类型在内存中由两部分组成,一部分是接口类型的参数指针,一部分是接口值的参数指针,因此interface类型参数将用stack trace的“参数数值”列表中的两个位置。


  • stack trace输出的信息是在函数调用过程中的“快照”信息,因此一些输出数值看似不合理,但是由于其并不是最终值,所以问题不一定发生在这些参数身上,比如:返回值参数。


结合上面要点、函数/方法原型以及stack trace的输出,我们来“定位”一下stack trace输出的各个“参数”的含义:


cmpp2Login和Connect的原型以及调用关系如下:


 
 
func cmpp2Login(dstAddr, user, password string, connectTimeout time.Duration) (*cmpp.Client, error)func (cli *Client) Connect(servAddr, user, password string, timeout time.Duration) errorfunc cmpp2Login(dstAddr, user, password string, connectTimeout time.Duration) (*cmpp.Client, error) {    c := cmpp.NewClient(cmpp.V21)    return c, c.Connect(dstAddr, user, password, connectTimeout)}cmpp2Login(dstAddr, user, password string, connectTimeout time.Duration) (*cmpp.Client, error)



func (cli *Client) Connect(servAddr, user, password string, timeout time.Duration) error



func cmpp2Login(dstAddr, user, password string, connectTimeout time.Duration) (*cmpp.Client, error) {

c := cmpp.NewClient(cmpp.V21)

return c, c.Connect(dstAddr, user, password, connectTimeout)

}


对照后,我们得出下面对应关系:


 
 
pusher.cmpp2Login(        0xc4203d29c0,  // dstAddr的data pointer        0x11,                  // dstAddr string的length        0xc420423256,  // user 的data pointer        0x6,                    // user string的length        0xc420423260,  // password的data pointer        0x8,                    // password string的length        0x37e11d600,    // connectTimeout        0xc4203d29c0,  // 返回值:Client的指针        0x11,                 // 返回值:error接口的type pointer        0x73)                 // 返回值:error接口的data pointergocmpp.(*Client).Connect(        0xc42040c7f0,   //cli的指针        0xc4203d29c0,  //servAddr string的data pointer        0x11,                  //servAddr string的 length        0xc420423256,  // user string的data pointer        0x6,                    // user string的length        0xc420423260,  // password的data pointer        0x8,                    // password string的length        0x37e11d600,   // timeout        0x0,                   // 返回值:error接口的type pointer        0x0)                   // 返回值:error接口的data pointer
0xc4203d29c0, // dstAddr的data pointer

0x11, // dstAddr string的length

0xc420423256, // user 的data pointer

0x6, // user string的length

0xc420423260, // password的data pointer

0x8, // password string的length

0x37e11d600, // connectTimeout

0xc4203d29c0, // 返回值:Client的指针

0x11, // 返回值:error接口的type pointer

0x73) // 返回值:error接口的data pointer



gocmpp.(*Client).Connect(

0xc42040c7f0, //cli的指针

0xc4203d29c0, //servAddr string的data pointer

0x11, //servAddr string的 length

0xc420423256, // user string的data pointer

0x6, // user string的length

0xc420423260, // password的data pointer

0x8, // password string的length

0x37e11d600, // timeout

0x0, // 返回值:error接口的type pointer

0x0) // 返回值:error接口的data pointer


在这里,cmpp2Login的dstAddr、user、password、connectTimeout这些输入参数值都非常正常;看起来不正常的两个返回值在栈帧中的值其实意义不大,因为connect没有返回,所以这些值处于“非最终态”;而Connect执行到第79行panic,因此其返回值error的两个值也是处于“中间状态”。


这样一来,似乎没有参数是错误的!




三. 回到起点,捉住“真凶”


在反复查看代码和对比stack trace的参数列表后,依然没有找到蛛丝马迹。遂决定平复心情,从头再来,回到起点!


        

 
 
var ok bool        var status uint8        if cli.typ == V20 || cli.typ == V21 {                var rsp *Cmpp2ConnRspPkt                rsp, ok = p.(*Cmpp2ConnRspPkt)                status = rsp.Status        } else {                var rsp *Cmpp3ConnRspPkt                rsp, ok = p.(*Cmpp3ConnRspPkt)                status = uint8(rsp.Status)   <------ 79行        }        if !ok {                err = ErrRespNotMatch                return err        }bool

var status uint8

if cli.typ == V20 || cli.typ == V21 {

var rsp *Cmpp2ConnRspPkt

rsp, ok = p.(*Cmpp2ConnRspPkt)

status = rsp.Status

} else {

var rsp *Cmpp3ConnRspPkt

rsp, ok = p.(*Cmpp3ConnRspPkt)

status = uint8(rsp.Status) <------ 79

}



if !ok {

err = ErrRespNotMatch

return err

}


又反复看了这段代码!程序正常执行时都是经过这段代码的,都是正常的。为何随机爆出panic呢?79行如果要panic,显然是rsp为nil或其他非法地址。但rsp是由p进行type assertion而来的!难道是type assertion失败了!!!


从正常业务流程来看,这里是不会失败的!这也是当初这里没有立即检查ok这个bool值的原因。但是特殊情况下,也就是当tcp连接建立后,conn包发出后,对方未必返回是conn response包,很可能是其他包回来(比如active test),这样就会导致这块的type assertion失败!这也与这个问题随机发生的情况吻合!


而且当初保留了“ok”,而不是用”_”代替,说明设计思路中是存在返回的包不是conn response包的情况。看来是当初coding时逻辑混乱了:(


这就是问题所在了!教训:type assertion后一定要在检查ok这个bool值之后再决定是否使用assertion之后的变量。




 四. 其他


借着这个问题的解决过程,再多说一句 stacktrace。在Go 1.11及以后版本中,go compiler做了更深入的优化,很多“简单”的函数或方法会被自动inline(内联)了,函数一旦内联化了,那么在stack trace中我们就无法看到栈帧信息了,就会看到如下在栈帧信息中存在省略号的情况:


 

 
 
$go run stacktrace.gopanic: panic in foogoroutine 1 [running]:main.(*Y).foo(...)    /Users/tony/test/go/stacktrace/stacktrace2.go:32main.main()    /Users/tony/test/go/stacktrace/stacktrace.go:51 +0x39exit status 2go

panic: panic in foo



goroutine 1 [running]:

main.(*Y).foo(...)

/Users/tony/test/go/stacktrace/stacktrace2.go:32

main.main()

/Users/tony/test/go/stacktrace/stacktrace.go:51 +0x39

exit status 2

可以使用-gcflags=”-l”来告诉编译器不要inline。至于是否要这么做,就要看debug和性能之间您是如何权衡的了。



我的网课“Kubernetes实战:高可用集群搭建、配置、运维与应用”在慕课网上线了,感谢小伙伴们学习支持!https://coding.imooc.com/class/284.html


我爱发短信:企业级短信平台定制开发专家 https://51smspush.com/

smspush : 可部署在企业内部的定制化短信平台,三网覆盖,不惧大并发接入,可定制扩展; 短信内容你来定,不再受约束, 接口丰富,支持长短信,签名可选。


著名云主机服务厂商DigitalOcean发布最新的主机计划,入门级Droplet配置升级为:1 core CPU、1G内存、25G高速SSD,价格5$/月。有使用DigitalOcean需求的朋友,可以打开这个链接地址:https://m.do.co/c/bff6eed92687 开启你的DO主机之路。


我的联系方式:


微博:https://weibo.com/bigwhite20xx

微信公众号:iamtonybai

博客:tonybai.com

github: https://github.com/bigwhite


商务合作方式:撰稿、出书、培训、在线课程、合伙创业、咨询、广告合作。


© 2019, bigwhite. 版权所有.

640


点击阅读原文查看更多


评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值