记一次生产redis集群磁盘爆满挂掉故障

一 故障现象

应用无法登陆，登陆报500异常。

二 日志情况

Caused by: io.lettuce.core.RedisCommandExecutionException: MISCONF Errors writing to the AOF file: No space left on device
        at io.lettuce.core.ExceptionFactory.createExecutionException(ExceptionFactory.java:135) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.ExceptionFactory.createExecutionException(ExceptionFactory.java:108) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.AsyncCommand.completeResult(AsyncCommand.java:118) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.AsyncCommand.complete(AsyncCommand.java:109) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.CommandWrapper.complete(CommandWrapper.java:59) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.cluster.ClusterCommand.complete(ClusterCommand.java:66) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.CommandWrapper.complete(CommandWrapper.java:59) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.CommandHandler.complete(CommandHandler.java:680) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:640) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.lettuce.core.protocol.CommandHandler.channelRead(CommandHandler.java:591) ~[lettuce-core-5.3.4.RELEASE.jar!/:5.3.4.RELEASE]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[netty-common-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.52.Final.jar!/:4.1.52.Final]
        ... 1 common frames omitted

从日志简单分析，是磁盘满了无磁盘空间写AOF文件了。

三 检查生产redis集群机器情况

生产机器分布（三主三从，主从错开机器做高可用）

机器	redis节点	说明
redis01	master01 slave03	2核8G
redis02	master02 slave01	2核8G
redis03	master03 slave02	2核8G

查看每台机器的磁盘使用情况

# df -h
文件系统        容量  已用  可用 已用% 挂载点
/dev/vda1        99G   99G     0  100% /
devtmpfs        3.9G     0  3.9G    0% /dev
tmpfs           3.9G     0  3.9G    0% /dev/shm
tmpfs           3.9G   49M  3.8G    2% /run
tmpfs           3.9G     0  3.9G    0% /sys/fs/cgroup
tmpfs           783M     0  783M    0% /run/user/1000

查看内存，剩余1G多可用内存。

四 通过redis日志定位分析

# tail -f -n 20 redis-server.log  
1:M 31 Dec 01:49:02.510 * Starting BGSAVE for SYNC with target: disk
1:M 31 Dec 01:49:02.510 # Can't save in background: fork: Cannot allocate memory
1:M 31 Dec 01:49:02.510 # BGSAVE for replication failed
1:M 31 Dec 01:49:03.638 # Cluster state changed: ok
1:M 31 Dec 01:50:02.621 * Slave 10.0.35.249:6379 asks for synchronization
1:M 31 Dec 01:50:02.621 * Partial resynchronization not accepted: Replication ID mismatch (Slave asked for 'c5cd3405034b3241c343ef7a30f2456214950847', my replication IDs are 'db8bd09b3dcd3a9ffdeb308036d3bd900b43497f' and '0000000000000000000000000000000000000000')
1:M 31 Dec 01:50:02.621 * Starting BGSAVE for SYNC with target: disk
1:M 31 Dec 01:50:02.621 # Can't save in background: fork: Cannot allocate memory
1:M 31 Dec 01:50:02.621 # BGSAVE for replication failed
1:M 31 Dec 01:51:03.733 * Slave 10.0.35.249:6379 asks for synchronization
1:M 31 Dec 01:51:03.733 * Partial resynchronization not accepted: Replication ID mismatch (Slave asked for 'c5cd3405034b3241c343ef7a30f2456214950847', my replication IDs are 'db8bd09b3dcd3a9ffdeb308036d3bd900b43497f' and '0000000000000000000000000000000000000000')
1:M 31 Dec 01:51:03.734 * Starting BGSAVE for SYNC with target: disk
1:M 31 Dec 01:51:03.734 # Can't save in background: fork: Cannot allocate memory
1:M 31 Dec 01:51:03.734 # BGSAVE for replication failed
1:M 31 Dec 01:51:04.477 # Short write while writing to the AOF file: (nwritten=262, expected=776)
1:M 31 Dec 01:51:35.036 # Short write while writing to the AOF file: (nwritten=262, expected=776)
1:signal-handler (1609379510) Received SIGTERM scheduling shutdown...
1:M 31 Dec 01:51:50.545 # User requested shutdown...
1:M 31 Dec 01:51:50.545 * Calling fsync() on the AOF file.
1:M 31 Dec 01:51:50.547 # Redis is now ready to exit, bye bye...

从redis日志”Cannot allocate memory“可以看出，已经没有足够的内存用于异步重写aof文件了。

所以并非表面看到的磁盘满了，导致了磁盘挂了，最根本原因是内存不足了，查看了内存，发现机器内存仅剩余了1G多，确实已经不够aof文件重写所需内存了（aof文件重写后的大小大概是2-3G的样子）。

查看aof文件日志，发现一堆分钟级数据大量写入缓存，根据key团队内询问是谁添加的redis缓存，并且进一步了解添加的场景。原来是为了写入分钟级数据用于算5分钟级数据，再写入mongo，写入后会有定时任务去清理redis缓存，但是清理不一定能清理干净，因为缓存数据太大。仅积累了三四天就已经把redis每台机器的内存增加了4-5G。导致最终机器内存不够用于aof文件重写了。

五 解决方法

• 先让相关同学先把分钟级数据应用赶紧停掉
• 清理redis分钟级数据，腾出足够内存
• 进入每一个redis节点 执行以下命令BGREWRITEAOF
• 如果redis已经挂掉，并且无法再起来，则需要找一下磁盘里哪些日志或文件可以做一些清理，先清理后则能正常起来了，如果还是无法启动，则挂载一个数据盘，把redis的数据迁移到数据盘，指向数据盘再重启（然后再清理redis缓存的分钟级数据）

六 总结

这次生产事故根本原因是研发同学对redis的使用不太规范引起。
另外，我们公司运维这块对生产机器没有告警机制，磁盘爆满都未提前发现。
这次故障，导致生产停了好几个小时。多亏我们的应用目前阶段更多是公司内部在用，还未广泛对外推广使用，否则后果不堪设想。