刚分析完的线上问题,想骂娘!原创
你好,我是yes。
接上篇的事情,看到报警群有个报错,赶忙的去处理了。
作为一名老油条,我内心慌得一批,但是表面稳如老狗,装的不急不忙地打开了日志平台:
咳咳,报错很直观,在利用 mybatis-plus selectOne 查询时,实际符合条件的结果不止一条,于是抛了 TooManyResultsException
的错。
根据堆栈,我直接定位到了抛错的查询,朴实无华的一条查询:
User user = userMapper.selectOne(Wrappers.lambdaQuery(new User())
.eq(StrUtil.isNotEmpty(userDTO.getUserId()), User::getUserId, userDTO.getUserId()));
我心想,难道还有用户的 userId 是重复的?
不可能,这可是数据库唯一键。
因为我们 feign 接口出入参有统一打印,所以我找了下日志发现了入参:
userId=%5B%5D
,什么玩意?我开始兴奋了起来,凭借我敏锐的嗅觉,直接一个 URLdecode:
上游传了 []
过来?被莫名转成了 %5B%5D
然后触发了 mybatis 奇怪查询?还是说 SQL 自己的问题?
于是乎我更兴奋了!
不过我先得搞清楚,为啥上游会传个 []
,因为上游的那个应用也是我负责的...
兜兜转转一堆查询,我发现上游传的其实是空字符串:
这又是啥操作?空串变成了%5B%5D
??? 这中间到底发生了啥?
因为这是 feign 接口,底层最终用 RequestTemplate 构建请求发送的,于是乎我一步步 debug,发现了啥?
发现一切正常。。。。
于是乎我开始疑神疑鬼。
发送方是 ok 的,难道是接收方解析时候出了问题?中间出现了我所不知道的py交易?
但是反过来又感觉不可能,传个空串能变%5B%5D
?
如果会出现这种问题应该很多地方都爆了!
所以此时应该怀疑啥?此时陷入了僵局。
但身为一个身经百战的老油条,我是不会放弃的,我将怀疑的目光转向了日志。
emmm....就是实际参数是对的,日志打印从中作梗!很有可是序列化啥的抽风了?
于是我仔细看通用包下日志切面的代码,发现了华点!
日志中 PARAMETER_MAP_PARAMS
对应的就是这个字段,它塞的值是从 request 的 parameterMap 取的,然后我发现这个 map 的 value 是 String 数组类型!
已经破案了啊!因为 userId 没有值,所以这里的数组被默认塞了空数组。
那为啥会被 urlencode 呢?
我又点开了 HttpUtil.toParams ,注释清晰写明了此方法会自动 url 编码 key 和 value,所以 []
就变成了 %5B%5D
咱们就直接复现一下:
好了,明明传空字符串在日志上却显示 %5B%5D
的案子破了。
也因此不需要分析啥接收方的源码了,拿到的肯定是空串,不可能是 %5B%5D
,因此也不可能是因为 %5B%5D
触发了 mybatis 的奇怪查询。
唉,这时候竟然有一点点失落,还想着重拾一波 mybatis 源码的呢。
那再次把目光专向那条朴实无华的查询语句:
User user = userMapper.selectOne(Wrappers.lambdaQuery(new User())
.eq(StrUtil.isNotEmpty(userDTO.getUserId()), User::getUserId, userDTO.getUserId()));
这时候一眼就看出来了。。因为传的是空串,所以 eq 的条件没命中,等于查询都没 where 了,直接全表扫描了,因此查出了多条数据。
还好这个是内部用户,数量少,这要是 C 端用户,全表扫描就要 G 了!
解决方式很简单,接口入参做限制 userId 不允许为空,且不允许为空串,isNotBlank。
然后上游预先判断,如果 userId 没值就别查了,没值还查,查什么查!
三下五除二改完,自测结束直接偷偷上线。
咳咳,我负责的服务,没有bug。
不过话说回来,就是这个鬼日志导致了我的错误判断,疑神疑鬼一头扎入源码中,差点溺亡,白瞎我一早上的时间。
果然大部分的 bug 排查起来可能惊心动魄。。但最终找到的原因大部分都有点无脑...不太“高级”
我是yes,从一点点我亿点点,我们下篇见~