一次并发Bug

最近碰到一个bug, 约7天发生一次,历时3周才找到问题并修复。

在找到bug并修复后,我仔细反思了一下。

我发现不仅这个bug是并发bug的一个典型,修复bug的过程也是直击我的弱点。

下面记录一下整个过程。

最近突然想对我的网络框架做一次RPC浸泡测试。

写了一段代码,开了6000个客户端,去并发RPC请求,服务端收到RPC之后会随机10~2500ms 延时之后再返回。丢到我的VPS上之后,也没在意,过了两天就忘记这回事了。

过了大概一周,我突然想起来我还有一个浸泡测试在跑着呢,就上去看了一下log.

令我意外的是,网络和rpc没有出现bug,定时器出现Bug了。

就这样一边加log等重现,一边看代码,在历时3周后终于靠看代码修掉了。

定时器相关代码大概如下:

--core.lua(run in thread1)

function core.timeout(ms, func) local co = cocreate(func)

--silly_timeout 等价于 silly_timer_timeout local session = silly_timeout(ms)

sleep_session_co[session] = co sleep_co_session[co] = session

return session

end

local MSG = {}

function MSG.expire(session, _, _) local co = sleep_session_co[session] assert(sleep_co_session[co] == session) sleep_session_co[session] = nil sleep_co_session[co] = nil wakeup_co_queue[#wakeup_co_queue + 1] = co

end

//silly_timer.c

uint32_t silly_timer_timeout(uint32_t expire){ struct node *n = newnode(); if (unlikely(n == NULL)) { silly_log("silly timer alloc node failed\n"); return -1; } lock(T); n->expire = expire / TIMER_RESOLUTION + T->ticktime; assert((int32_t)(n->expire - T->expire) >= 0); add_node(T, n); unlock(T); return n->session;

}

// run thread2

void silly_timer_update()

{

//检查所有struct node, 是否超时

//如果超时,则向Lua层抛出expire消息

//然后将node结点Free掉

//在Lua层收到expire消息后,会调用MSG.expire函数

}

发现bug时,是发现在MSG.expire函数的第二行assert失败了。

这时我就告诉自己,柯南君的名言“排除一切不可能,剩下的再不可能也是真相”。

即然assert失败了,那只有三种可能。

A1. co 为 nil, 这时sleep_co_session[co]为nil A2. co 不为nil 且sleep_co_session[co] 为nil A3. co 不为nil 且 sleep_co_session[co]不等于session

我检查了一下代码,发现sleep_session_co 和sleep_co_session都是一起操作的,因此我将A2排除了。

为了进一步排除A1和A3, 我在MSG.expire加了点log,当assert失败时,打印一下session和co的值。

过了几天后确定是A1.

而导致A1产生的可能情况有以下几种可能:

B1. silly_timer_timeout返回了两个相同的session B2. silly_timer_update 对同一个session返回了2次 B3. silly_timer_update 返回了一个陌生的session

我查了一下rpc client端的log,我发现在相同的时间确实有一次rpc请求失败了,排除了B2.

如果是情况3, 那就代表silly_timer_update时返回的是脏数据,我查看了silly_timer.c中的代码,发现node->session只有在newnode时被赋值,其他情况并没有被改动过。因此我将B3排除了。

现在就剩下B1,出现B1 有两种可能。

C1. session回绕了 C2. 在++session时有并发问题出现了某种竞争

于是,我在session回绕和session每增加1000时,分别打印了一行log。以期望可以在下次重现时,获得一些有用的信息。

再次出现之后,我发现session并没有回绕,而session每增加1000打印的log似乎对我并没有什么帮助。

我开始把矛头对准C2分析。但是我反复检查,以我现有的知识来讲,session都不可能存在并发问题。

线突然断了,我知道一定是我哪里弄错了,但是我思维已经造成了定式。反复思考也没看到哪里有问题。

之后,每天打开电脑第一件事,就是去看一遍之前发生过的log和代码,以便突然有点灵感。

在过了大约7天之后,我突然发现,session每增加1000时的log L1和assert失败时的log L2发生在同一秒,而出错的session比L1中打印出来的session要小。

本文分享自微信公众号 - 重归混沌(findstrx),作者:重归混沌

原文出处及转载信息见文内详细说明,如有侵权,请联系 yunjia_community@tencent.com 删除。

原始发表时间:2020-06-14

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

我来说两句

0 条评论
登录 后参与评论

相关文章

  • 谈谈Unity的资源管理

    在Unity最佳实践明确指出, 要使用AssetBundle而不是Resources目录来管理资源。

    重归混沌
  • 地形渲染之爬过的坑

    目前我们采用TiledMap的菱形模式来编辑地形,然后再导入到Unity, 将TiledMap的每一个菱形以Unity中的Quad为单位来拼出来。

    重归混沌
  • DC3算法

    最近做了一个差量更新工具, 实质就是一个Diff工具。这个Diff工具在本地生成一个patch文件。客户端通过网络下载到本地后,根据本地文件和patch文件来生...

    重归混沌
  • Flink时间系列:如何在两个DataStream上进行Join操作

    批处理经常要解决的问题是将两个数据源做关联Join操作。比如,很多手机APP都有一个用户数据源User,同时APP会记录用户的行为,我们称之为Behavior,...

    PP鲁
  • Python入门经典案例一

    py3study
  • Android热更新方案Robust开源,新增自动化补丁工具

    我们在之前的博客文章中介绍了高兼容性、高稳定性的实时热更新解决方案Robust之后,业内反响强烈,不断有读者咨询我们什么时候开源。今天我们非常高兴地宣布,Rob...

    美团技术团队
  • YOLOv3 提升 5.91 mAP,IoU在目标检测中的正确打开方式

    论文:Distance-IoU Loss: Faster and Better Learning for Bounding Box Regression

    CV君
  • scala时间和时间戳互转

    机器学习和大数据挖掘
  • 马斯克不满特朗普NASA预算案,吐槽没有实质性的帮助

    镁客网
  • 怎么才能学好嵌入式?

    嵌入式学习太广泛,要学习的东西忒多。根据自己的选择,你要干硬件,还是软件等等。我们就从基础说起吧! 软件基础: 一、编程基础 C/C++语言学习书籍,谭浩强C语...

    程序员互动联盟

扫码关注云+社区

领取腾讯云代金券