记一次 Lindorm 查询超时问题

负责的一个 IOT 平台，在一天早上突然发现 MQ 堆积严重（1小时堆积上涨百万左右）。之前也遇到过这种问题，基本都是因为依赖的 OSS 变慢导致，有时因为其他业务把 OSS 带宽打满，有时因为 OSS 本身在并发量大的情况下会做限流措施。

问题排查处理

到公司之后先查看了相关的日志（由于 Lindorm 超时严重已经有很多 ERROR 告警），根据告警日志发现是数据库（Lindorm）的连接池满了（使用的 durid），错误堆栈基本都是下面这样。

org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException: 
### Error updating database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 30000, active 20, maxActive 20, runningSqlCount 2 : select  ts
                ,metric
                ,val
        from    monitor_metric
        where   app_bind_rel_id = ?
        and     metric in
         (  
            ?
         ) 
        and     ts >= ? and ts <= ?
        order by app_bind_rel_id, metric, ts
runningSqlCount 1 : SELECT  app_bind_rel_id,oss_key,lng,angle,gmt_create,speed,lat,ts  FROM data_track_point 
 
 WHERE (app_bind_rel_id = ? AND ts > ? AND ts < ?)
runningSqlCount 6 : SELECT ts AS id, concat(?, CAST(lng AS varchar), ?, CAST(lat AS varchar), ?) AS coord, ts
FROM data_track_point
WHERE app_bind...

从错误上也很容易看出来问题，数据库连接池已经被用满，无法获取到 JDBC 连接。连接池被用满的情况，巨大多数情况都是因为慢 SQL！于是根据之前预埋的日志查看了下 Lindom 相关 SQL 的执行时间，果然跟猜测一致，查询耗时 4-5W ms，写入耗时 2-3W ms，平时查询、写入基本都是 10 ms 以内。这么慢连接池不满才怪。

首先想到的是 Lindorm 的问题（这里应该打自己一个嘴巴，毕竟是阿里云的成熟服务，出问题的几率比自己服务出问题的几率要小很多，在这里浪费了不少时间），于是找 Lindorm 的同学咨询 Lindorm 集群是否有问题。因为当时为了测试建了个临时表，里面只有一条数据，查询起来也要很久。

Lindorm 的同学介入后，发现有慢 SQL 让业务自查。但是我们最近也没有发版，所以一时的确也找不到问题所在。Lindorm 同学通过监控平台发现对 data_track_point 表的读取量有大幅的增加，让看下是否查询方式有变更或者输入参数有较大变化。

查询量变更

排查了半天实在还是没有头绪，查看了这个表所有的相关读取，都没看到有啥问题（主要服务的确没有做过变更）。

于是咨询 Lindorm 的同学是否有 dbservice 那种 SQL 限流能力，没有给答复（应该暂时不具备）。后来说可以尝试把问题表隔离出去，从而不影响整个集群的服务。于是先执行了这个表的隔离操作，但是隔离完发现没啥效果，或者说有效果有限吧，响应变得忽快忽慢。拉群之后答复应该是因为使用了轻客户端（SQL）的方式，导致隔离策略没有生效，Lindorm 在这种使用方式下对请求的路由是随机选择节点下发，下发到有问题表的节点上就很慢，到其他节点上就很快。

处理恢复

于是业务侧考虑开始限流，对于端上来的 HTTP 请求处理很简单。由于接入了 sentinel，在 sentinel 里配置下限流规则就立马生效了。这里必须吹一波 sentinel，强烈建议有线上业务的一定要接入，救命的法宝。如果没有 sentinel 只能改代码发版，现实是发版都不一定解决，因为 Lindorm 响应极慢，在应用启动时候获取连接特别慢。

但是除了这里还有 Spring Event 分发做触发的（其实这里的请求没啥问题），好在这里通过一个曲折的配置也可以禁用掉。

所有流量限掉后， Lindorm 集群开始恢复。

问题定位

业务恢复后开始想办法找到真正的原因，开始一直怀疑是 Lindorm 的某个节点有问题，导致了慢查询，从而把集群拖挂。因为除了最开始的慢 SQL，后面所有请求的 SQL 都是慢 SQL 了，的确不好区分到底是谁的问题。也考虑过是否因为数据量变大之后导致的查询雪崩，但其实这种一般都是线性的或者是有预兆的变慢，而我们这个就是突然完全崩掉，应该也不是这个问题。

最后在看消息的时候，发现昨晚端上有过设备的全量 OTA 升级。进而怀疑是否可能是这个导致，而且发版时间点跟 Lindrom 的读取量暴涨可以对应上。于是仔细的排查了上面被限流接口的输入参数。发现开始时间有输入为 0 的情况，而这个接口会使用开始时间对 data_track_point 做范围查询，到这里基本就可以定位问题了。

咨询端上同学为啥开始时间会传 0 ？告知是因为 OTA 之后设备的系统时间会被重置为 0 。但之前也有过很多次 OTA，为啥只有这次又问题呢？主要因为之前这个数据用 MySql 存储了 1 个月，切换 Lindorm 之后存储了 3 个月（且使用了冷存储特性），Lindorm 相比 MySql 查询不是他的强项。而且查询这么大范围的数据，对所有数据库都是噩梦。

血泪教训

. 对端上的输入一定要有校验
. 涉及到对大表的范围查询一定要谨慎、谨慎再谨慎
. 对线上业务一定要做好限流、降级能力建设，遇到此类问题先做限流、降级，保证业务大面不受影响
. 对各个模块尽量做好隔离，在定位问题的时候比较方便，想要限流也比较容易