0%

记一次查找 lua-resty-mysql 库 insert_id 的 bug

背景

我们公司平时业务开发使用 OpenResty,也一直使用 lua-resty-mysql 库连接 Mysql。

有一个业务场景,MySQL 中表的主键是自增 id,业务需要在 insert 语句之后需要拿到此次插入的自增 id 值。
我们一直使用 lua-resty-mysql 库(Openresty 组件中的一个)中执行 insert 语句返回的 res.insert_id 作为这个值(这样可以一次请求就拿到这个值)。

但是最近开始这个值变成负数,导致业务出现很多错误,于是便开始排查为什么 res.insert_id 会返回负数。

基本猜测

首先确定 res.insert_id 这个值是负数之后,第一反应想到的是会不会 MySQL 的主键超出类型范围,导致自增 id 变成负数,但是想到我们用的类型时 bigint,不太可能会超出范围,

而且查到自增 id 达到范围上限后,会出现插入报错,并不会出现负数,所以排除这种可能性。

之后便是去确认这个值是 MySQL 返回的还是我们用到的 lua-resty-mysql 库基于自己的规则生成的

  1. 如果是 MySQL 返回,必然是哪里存在 bug,不是 MySQL 的 bug 导致某些行为返回的这个值是负数,就是 lua-resty-mysql 库解析 MySQL 返回值时出现问题。
  2. 如果是用到的 lua-resty-mysql 库基于自己的规则生成的,那就是我们使用的方式不对,毕竟 lua-resty-mysql 库的官方说明并没有提供这样的用法

排查过程

随后开始查看 lua-resty-mysql 库的源码,看到了 res.insert_id 来源这里

因为之前对这份源码不太熟悉,所以第一反应是这个值是 lua-resty-mysql 基于自己的规则生成的(也就是上面的猜测 2),我们不能这样使用。

通过网上搜索我们这种业务场景,也发现别人都是建议使用 MySQL 自带的函数 LAST_INSERT_ID() 来获取这个值(这种方式和 MySQL 交互两次),
所以我想当然的以为是我们的使用方法错了(后来发现这种想法是错误的,并且网上很少有人提到 MySQL 在 insert 之后已经返回插入的自增 id 值了)。

后来仔细想想,如果是 lua-resty-mysql 基于自己的规则生成的这个值,那么为什么之前这个值都是正确的呢,lua-resty-mysql 又是怎么实现的呢?

基于这个想法,我又打开了源码,发现一开始的理解错了,这个值是基于 MySQL 的响应值解析而来的,上图中 _from_length_coded_bin(packet, pos) 这个函数的作用其实就是解析 MySQL 的二进制响应。

确定了这个问题之后,可以排除上面的猜测 2。
回到了猜测 1,但是这里面还漏掉一个原因。

MySQL 返回 insert_id 的这个值是不是代表我们需要的值?
或者说,如果 MySQL 官方没有明确说明这个值的含义,只是一个代表其他含义的值,那也不能说是哪里存在 bug,还是我们的使用方法错误,之前的正确只是巧合。

于是开始查阅 MySQL 关于插入后网络响应的官方说明 ,很快就找到了这个值。

图里明确说明 last_insert_id(也就是我们上面提到的 insert_id)是最后的插入 id 值。

到此,基本可以确定猜测 1 是对的,MySQL 或者 lua-resty-mysql 库一定哪里存在 bug,导致没有按说明正确返回

基于对 MySQL 的信任(毕竟用的人这么多,出错的概率很小,就算有错误一定有人提到过),先假设 lua-resty-mysql 存在问题。

于是我便开始查看 MySQL 的网络协议,需要如何正确解析,以及 lua-resty-mysql 库是否解析正确。

注意这里需要一个背景知识,客户端在向 MySQL Server 发送 insert 语句后(相当于发送请求),MySQL Server 会返回 OK 的包(相当于服务器响应),里面会带有上图中的值

可以看到 MySQL 的官方文档里面提到返回的 last_insert_id 是一个 int 类型。
lenenc 在 MySQL 里代表变长,需要根据不同的情况分别解析。

对照 lua-resty-mysql 库的源码,发现解析的规则并没有错。

排查到这里就陷入困难了,毕竟 lua-resty-mysql 库对网络协议的解析并没有错,难道是 MySQL 出现 bug 了?如果真是这样,排查起来就困难了,毕竟 MySQL 源码要复杂很多。

其实这里可以用 tcpdump 等工具获取 MySQL 的响应值,分析网络协议中的这个值,来确定是到底是不是 MySQL 的问题,但是因为权限等原因太繁琐,所以不到万不得已就没有这样排查

只能先去查一下 MySQL 官方的 bug 平台,发现并没有这样的 bug。

本着最后一丝希望,我在 lua-resty-mysql 库的 issue 列表 里搜索 insert_id,

终于发现有人遇到了同样的问题 https://github.com/openresty/lua-resty-mysql/pull/26(其实这一步应该最先进行,后面反思里会提到)。

里面提到因为 LuaJIT(可以理解为 lua-resty-mysql 库使用的语言) 位操作只支持 32 位有符号整数,所以 MySQL 的包并没有被正确解析,可以看到在当时还是 Open 的状态。

这也是为什么我查看源码并没有问题,但还是返回了负数的原因,因为我默认位运算没有 32 位整数的限制(毕竟还有这个限制的很少)。

下面章亦春大大(lua-resty-mysql 库,还有 Openresty 作者)回复,会在 5 月中旬假期回来查看,但那已经是 2015 了,到现在 2021 年 2 月末,过了将近 6 年,还是没有处理~~~

为了查看是否是这个原因,我也去查阅了 luajit 关于位运算的相关文档

果然文档上写明 luajit 位运算会返回 32 位有符号整数范围的数字,OpenResty 使用的 luajit 虽然是自己的维护 luajit 分支,但是大部分都和原作者的相同,在这一点上也没有改动

后来我自己手动模拟了一遍,发现确实当 Mysql 中自增 id 的值超过 32 位有符号整数上限的时候,这个问题是稳定复现的。

最终结果

因为之前有一次线上分享加到了章亦春大大的微信,所以干脆直接在微信上联系了章亦春大大。

说明了我的问题和排查到的结果之后,很快得到了回复,并且很快这个 issue 就得到了处理,不得不说,处理的速度还是很快的~

至此,这个 bug 完美排查到并且解决了!

事后反思

虽然最后这个事情最终结束了,但是还是有一些值得思考的地方。

  1. 首先,得到的最大的感触是不要重复造轮子,在遇到问题之后,最先确定是否是自己的原因(在这个例子中就是首先确定是否是使用方法错误),
    下一步骤应该就是查找涉及的 issue 列表,而不是自己再从头排查,我在这个过程也花费了很多时间
    (当然在这个例子里如果不知道背景知识,比如 MySQL 的 OK 响应包,直接查看 issue 列表也很难发现);
  2. 当然排查的过程中收获也很多,比如对 lua-resty-mysql 库的源码掌握更清晰,对 client 和 MySQL server 之间的网络协议更加了解等等;
  3. 最后,对问题应该有刨根问底的精神,而不是网上简单的查不到就跳过,这种做事的方法也是很大的收获。