博客详细记录了Redis3.2.3服务因信号11崩溃的排查过程。问题出现在执行bgsave、bgrewriteaof等操作时，发现是由于在位字段（bitfield）命令中，一次命令执行多次set操作，且后续offset小于先前offset，导致sds字符串长度错误，可能引发内存问题。通过版本对比，发现在3.2.6版本修复了相关bug，升级到该版本后问题不再出现。排查过程中，考虑了编码问题、内存溢出、rehash影响等因素，最终确定是位字段命令导致的崩溃。
Redis 3.2.3 crashed by signal: 11 服务宕机问题排查
现象
Redis执行bgsave 、bgrewriteaof、全量scan等操作都会出现崩溃
=== REDIS BUG REPORT START: Cut & paste starting from here ===
4664:C 13 Jul 13:44:19.092 # Redis 3.2.3 crashed by signal: 11
4664:C 13 Jul 13:44:19.092 # Crashed running the instuction at: 0x4234c0
4664:C 13 Jul 13:44:19.092 # Accessing address: (nil)
4664:C 13 Jul 13:44:19.092 # Failed assertion: <no assertion failed> (<no file>:0)
------ STACK TRACE ------
EIP:
redis-rdb-bgsave 0.0.0.0:7000 [cluster](dictNext+0x70)[0x4234c0]
Backtrace:
redis-rdb-bgsave 0.0.0.0:7000 [cluster](logStackTrace+0x29)[0x45d3d9]
redis-rdb-bgsave 0.0.0.0:7000 [cluster](sigsegvHandler+0xaa)[0x45d8ca]
/lib64/libpthread.so.0(+0xf630)[0x7f82f8e7d630]
------ CURRENT CLIENT INFO ------
id=89347820 addr=127.0.0.1:63314 fd=104 name= age=35 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=bgsave
argv[0]: 'BGSAVE'
32912:C 13 Jul 14:28:16.596 # ------------------------------------------------
32912:C 13 Jul 14:28:16.596 # !!! Software Failure. Press left mouse button to continue
32912:C 13 Jul 14:28:16.596 # Guru Meditation: "Unknown encoding type" #object.c:456
32912:C 13 Jul 14:28:16.596 # (forcing SIGSEGV in order to print the stack trace)
32912:C 13 Jul 14:28:16.596 # ------------------------------------------------
10430:M 13 Jul 14:28:16.672 # Background saving terminated by signal 11
=== REDIS BUG REPORT START: Cut & paste starting from here ===
10430:M 13 Jul 15:01:55.933 # Redis 3.2.3 crashed by signal: 11
10430:M 13 Jul 15:01:55.933 # Crashed running the instuction at: 0x438ea0
10430:M 13 Jul 15:01:55.933 # Accessing address: (nil)
10430:M 13 Jul 15:01:55.933 # Failed assertion: <no assertion failed> (<no file>:0)
------ STACK TRACE ------
EIP:
/opt/cachecloud/redis/src/redis-server 0.0.0.0:7000 [cluster](scanCallback+0xb0)[0x438ea0]
Backtrace:
/opt/cachecloud/redis/src/redis-server 0.0.0.0:7000 [cluster](logStackTrace+0x29)[0x45d3d9]
/opt/cachecloud/redis/src/redis-server 0.0.0.0:7000 [cluster](sigsegvHandler+0xaa)[0x45d8ca]
/lib64/libpthread.so.0(+0xf630)[0x7f82f8e7d630]
/opt/cachecloud/redis/src/redis-server 0.0.0.0:7000 [cluster](scanCallback+0xb0)[0x438ea0]
/opt/cachecloud/redis/src/redis-server 0.0.0.0:7000 [cluster](dictScan+0x198)[0x423a28]
=== REDIS BUG REPORT START: Cut & paste starting from here ===
24773:S 15 Jul 17:29:29.787 # Redis 3.2.3 crashed by signal: 11
24773:S 15 Jul 17:29:29.787 # Crashed running the instuction at: 0x4231ea
24773:S 15 Jul 17:29:29.787 # Accessing address: (nil)
24773:S 15 Jul 17:29:29.787 # Failed assertion: <no assertion failed> (<no file>:0)
------ STACK TRACE ------
EIP:
/opt/cachecloud/redis/src/redis-server 0.0.0.0:7000 [cluster](dictFind+0x8a)[0x4231ea]
排查
最开始生产的该实例已经是单点了，从节点虽然启动了，但是主节点无法生成dump文件进行主从同步，无法bgsave的操作，也无法进行数据传输的操作。正当我和同事讨论要不要开启aof备份时，这个主节点挂了，只能立即启动，但是数据丢了一半。这里有个教训，这种情况应该首先在实例开启AOF，这样在崩溃时才有还原的数据以及排查的数据。
重新启动以后，我们立刻开启了aof备份，可以正常备份数据。当时如果开启了aof备份就好了，起码数据不会丢很多，开启aof备份以后，会立即进行全量的备份，将内存中的已有数据都写入aof备份文件。但是此时，造成崩溃的数据已经丢了，现在进行bgsave等操作等正常了。这时领导说要不升级下版本试试（这点要考），我们目前不能复现所以无法确定问题所在，所以没有同意进行升级。使用这个集群的项目组最近新上了功能，使用了bitmap的bitfield命令，但是没法定位问题，所以不能确定是否是这个原因（这点要考）。
因为想起mysql也有因为编码问题无法存储表情包只能使用utf8_mb4的情况，所以第二天特意找到很多表情码中文码进行读写测试，都没有出现崩溃的情况。可以正常进行数据读写。
第二天无事发生，到了第三天，又出现了类似的情况。首先是一个从节点挂掉，然后一个主节点成了单点，从节点重新启动不停向主节点请求数据同步，但主节点生成rdb始终是失败的。没过一会，主节点也失败了，这次有了aof的备份数据，直接启动节点就可以了，而且有了aof的节点数据。但是问题并没有解决。领导说要不升级到高版本试试，因为目前使用的版本是3.2.3，所以现在反正也无法定位到问题，不如死马当活马医，升级下版本试试。那就试试，于是在本地的虚拟机中搭建了3.2.12版本的实例，然后拿生产的aof备份文件进行导入启动，然后进行 scan 、bgsave等测试，确定是能够正常进行没有崩溃以后，便和业务约好一定时间进行维护，将该应用使用的集群的所有实例全部升级到了3.2.13版本。
生产稳定以后，就开始想办法复现问题定位原因了。改问题可以通过几种方式进行复现：
- 使用该数据文件进行启动，然后执行
save、bgsave、bgrewriteaof - 使用改数据文件进行启动，然后进行
save，使用less命令查看崩溃后生成的临时rdb文件temp-xxx.xxx.rdb的最后一个key，使用这个key在全局使用一个非常大的count进行scan，可以偶现崩溃情况。 - 使用该数据文件进行启动，然后执行全量scan可以偶现。
为了找到问题的key，我尝试使用几种排查的方法，
- 二分法：将aof备份文件给切分成等大小的10份、5份、2份，将每份数据的截断的命令进行删除后，非别启动实例导入每份数据，然后分别在每个实例上面执行bgsave命令，都能够正常的执行。没有出现崩溃的情况，因为对同一个key的操作是可能会分布到多个文件中，所以这个方法没法复现。
- 全局scan方式：启动实例并引入aof备份文件以后，使用java程序执行全局scan命令，
scan 0 match * count 600直到全部数据执行完毕。看是否触发崩溃。经过多次试验，并不是每次都能够复现崩溃情况（有可能存在数据超时的情况），崩溃时记录下崩溃的时候执行的key，然后拿到这个key，将其所有的操作从aof文件中导出，在一个空实例中执行，再执行bgsave命令，没有复现崩溃的情况。每次崩溃时的key也不一样。 - 修改源码，在执行bgsave中崩溃的代码以及scanCallback崩溃时的代码中对key进行输出。但这种方式只能定位到出现崩溃时的前一个key，每次的也不一样。
从以上的几次测试，可以看出，并不是特定的key数据导致的崩溃。
- 使用gdb打断点的方式，进行按步调试，但是崩溃发生的地方是循环中，因为key太多，也无法正常调试。
使用个各种方式都没法定位到问题，后来想到，既然升级了版本以后，没有再出现崩溃的问题，那么应该是某个版本对bug进行了修复，然后就从3.2.3以后的版本往后逐个创建新虚拟机进行编译->启动->导入数据->bgsave，到3.2.6版本就没有出现这个问题了。然后就查看3.2.6这个版本的修改记录，https://github.com/redis/redis/blob/3.2.6/00-RELEASENOTES
Upgrade urgency MODERATE: GEORADIUS, BITFIELD and Redis Cluster minor fixes.
This release mainly fixes three bugs:
1. A bug with BITFIELD that may cause the bitmap corruption when setting offsets
larger than the current string size.
2. A GEORADIUS bug that may happen when using very large radius lengths, in
the range of 10000km or alike, due to wrong bounding box calculation.
3. A bug with Redis Cluster which crashes when reading a nodes configuration
file with zero bytes at the end, which sometimes happens with certain ext4
configurations after a system crash.
前面不是提到了吗，使用这个集群的应用最近上了个新功能，使用了bitmap，3.2.6这个版本正好修复了bitfield命令的一个bug，使用aof文件解析工具waoffle，将aof文件解析为redis命令后，将所有的bitfield命令导出。最开始没有对bug修复描述的A bug with BITFIELD that may cause the bitmap corruption when setting offsets larger than the current string size正确理解，只能通过根据bug修复的代码进行反推。
在源码处增加对执行命令、key及参数进行输出，将符合修复代码部分的命令进行输出，源码修改如下：
bitops.c
958 if (opcode != BITFIELDOP_GET) {
959 readonly = 0;
960 if(higest_write_offset!=0 && higest_write_offset < (bitoffset + bits - 1)){
961 serverLog(LL_WARNING,"key=>%s,higest:%d,sum:%d,bitoffset:%d,bits:%d",c->argv[1]->ptr,higest_write_offset,( bitoffset + bits - 1),bitoffset,bits);
962 }
963 higest_write_offset = bitoffset + bits - 
最低0.47元/天 解锁文章
扫一扫
2万+
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
