【.com原稿】作者所在公司有一款DAU（DailyLive）大的休闲游戏。这款游戏的后端架构非常简单，可以简单理解为通信-逻辑-存储的三层结构。其中，存储层大量使用Redis和MySQL。图片来自Pexels。随着现有用户的增加，Redis时不时会出现问题。所以笔者打算将项目中遇到的一系列问题和实践整理记录下来。每天14点，项目组都会遇到惊心动魄的时刻。一连串的警告短信把工程师从午睡中拉回现实，然后问题就神秘消失了。PM叫你去上班吗？还是服务员在取笑你？且看工程师是如何一步步找出真凶并解决问题的。1.原因某日下午，后台组监控系统报警，服务器响应时间变长，超过阈值。片刻后系统自动恢复，告警解除。第二天差不多同一时间，监控系统又发出了同样的警报，几分钟后又恢复了。所以我们决定调查这个问题。2.背景首先介绍一下应用架构，这是一个非常简单的三层Web服务。从外到内看起来是这样的：负载均衡：对外提供访问，对内实现负载均衡。Nginx：放在LB后面，实现流量控制等功能。AppService：逻辑服务，多机多进程。存储：由MySQL和Redis组成的存储层。我们的服务部署在AWS云上，架构中使用了很多AWS的服务，比如ELB、EC2、RDS等。3.肤浅排查的第一步是收集信息。从监控和日志系统中提取大量相关信息，然后分析和解决问题。我们收集到的信息大概是这样的，每天14:00：QPS激增。P99指标增加。Appserver集群CPU和内存增加，TCP连接数暴增，网络流量下降。MySQLWriteIOPS增加，写入延迟增加，数据库连接数增加。几分钟后，这些指标全部恢复正常。4.先从代码上查看这个时间点是否有定时任务。事实证明它没有。那么就有了第一个嫌疑人，MySQL。使用mysqlbinlog命令统计每个时间点的binlog条数：我们在第二天观察这个时间点的场景，使用showprocesslist命令抓取当时的MySQL连接状态，发现连接数从Appserverwereallsleep大约20秒，没有任何反应。初步推断根据以上数据，我们可以还原出当时的场景：AppserverSockets数量激增。应用服务器不再进行逻辑处理（待确认）。应用服务器不再做任何数据库操作。App服务器恢复读写数据库。大量积压的网络请求导致游戏服务器CPU增加。大量写请求涌入数据库，导致数据库各项指标上升。那么问题来了：Sockets的热潮从何而来？或者他们与谁联系？为什么App服务器20秒没有数据库操作？App服务器真的挂了吗？带着疑惑开始进一步调查。5.深入排查先解决第一个问题：多余的Socket是从哪里来的？AppService在14:00之前选择一个App服务器，并抓取它的TCP连接：#!/bin/bashwhile[true];docurrentHour=$(date+%H)currentMin=$(date+%M)filename=$(date+%y%m%d%H%M%S).txtif[$currentHour-eq05]&&[$currentMin-gt58];thenss-t-a>>$filename#/bin/date>>$filenameelif[$currentHour-eq06]&&[$currentMin-lt05];thens-t-a>>$filename#/bin/date>>$filenameelif[$currentHour-ge06]&&[$currentMin-gt05];thenexit;fi/bin/sleep1done对比大文件差异，并发现额外的连接来自Nginx。Nginx只是一个代理，所以检查它的上游负载均衡。LoadBalanceLoadBalance我们使用经典的AWS产品ELB。ELB日志很大，主要是分析这段时间有没有流量异常。经过对比分析，13:55-14:00和14:00-14:05这两个时间段的请求没有明显差异。基本上，它由以下请求组成：https://xxxxxx.xxxx.xxx:443/timehttps://xxxxx.xxxx.xxx:443/gateway/v1但是从14:00:53开始，带有网关的请求大部分返回504，有时间的请求正常返回。504表示网关超时，即App响应超时。根据这些信息，可以推断出一些情况：AppService还在正常提供服务，否则时间请求不会正常返回。应用服务写入数据库的所有操作都处于等待状态。Nginx与AppService的连接无法及时处理，所以长时间没有断开连接，导致Nginx与AppService之间的Socket连接快速增长。综合以上，基本可以排除是ELB和Nginx导致的问题。那么就只剩下一个问题了，什么数据库不能长期写？而且是每天固定的时间。MySQL问题返回到数据库。首先想到的是备份，但是我们的备份时间不在问题发生的时间段内。我们使用的是AWS的RDS服务，查看了RDS的备份文档。只有备份了数据库，写I/O才会挂掉，导致数据库不可写。而默认的备份时间窗口是这样的：这个开始时间也刚好是我们出问题的时间，简直太巧合了。下一步是确认问题。是偷偷帮我们做备份，还是实例所在物理机上的其他实例在干扰我们？在某个MySQL实例上新建一个数据库test，新建一个表test：CREATETABLE`test`(`id`int(10)unsignedNOTNULLAUTO_INCREMENT,`curdate`varchar(100)NOTNULL,PRIMARYKEY(`id`))ENGINE=InnoDBAUTO_INCREMENT=2DEFAULTCHARSET=utf8;每一秒向这个表写入一条数据，数据的内容是当前时间，这样可以看出数据库在哪个时间段是不可写的。同时每秒读取这个表的最大值，记录结果和当前时间，这样可以看出数据库在哪个时间段不可读。测试的脚本如下：#!/bin/bashhost=xxxx.xxx.xxxport=3306user=xxxxxpassword=xxxxxmysql="mysql-u$user-p$password-h$host-P$port--default-character-set=utf8-A-N"fetchsql="showprocesslist;"selectsql="selectmax(id),now(3)fromtest.test;"insertsql="insertintotest.test(curdate)value(now(3));"functionrun(){filename_prefix=$1mysqlcmd="$($mysql-e"$fetchsql")"echo$mysqlcmd>>$filename_prefix.procs.txtmysqlcmd="$($mysql-e"$selectsql")"echo$mysqlcmd>>$filename_prefix。select.txtmysqlcmd="$($mysql-e"$insertsql")"}while[true];docurrentHour=$(date+%H)currentMin=$(date+%M)filename_prefix=./checksql/$(date+%y%m%d%H%M%S)$(run$filename_prefix)if[$currentHour-eq05]&&[$currentMin-gt59];then$(run$filename_prefix);elif[$currentHour-eq06]&&[$currentMin-lt02];然后$(run$filename_prefix);elif[$currentHour-ge06]&&[$currentMin-gt02];thenexit;fi/bin/sleep1done脚本还每秒扫描每个MySQL客户端的工作状态。最后得出的结论是，出问题的时候数据库是可以读写的。问题好像卡住了。疑惑一一被证明是正确的。导线也断了。只能回到起点，继续从代码开始，看哪里会导致单点，哪里出问题会导致所有游戏服务器集体卡死，或者数据库操作卡死。Redis终于找到了罪魁祸首。最可疑的有两点：数据库分片方案依赖Redis。每个用户的数据库片段id存储在Redis中，用于查找其数据的位置。用户的设备和逻辑id的映射关系也存储在Redis中。几乎每个API请求都会查找此映射。以上两点几乎就是一个API请求的开始。如果这两点出现问题，后面的操作就会卡住。经OPS确认，这两个Redis的备份时间窗口确实在6:00-7:00utc之间。而且备份都是在从库上进行的，我们程序中的读操作也是在从库上进行的。通过Redis的info命令，查询到Redis最新的备份时间，刚好是北京时间14:01左右。进一步证实怀疑：更改两个Redis的备份时间。Redis1更改为3:00-4:00utc，Redis2更改为7:00-8:00utc。北京时间11:00左右，Redis1备份正常，但问题没有重现；北京时间14:00左右，问题没有再出现；北京时间15:00左右，Redis2备份正常，问题再次出现。之后查看了Redis1和Redis2的数据量。Redis2大约是Redis1的5倍。Redis1占用内存1.3G左右，Redis2占用内存6.0G左右。Redis1的备份过程几乎瞬间完成，对App影响不明显。六、结论问题的大致过程如下：北京时间14:00左右，Redis2从数据库进行了备份。备份的时候，整个Reids从库的读操作都被阻塞了。这进一步导致用户的API请求被阻止。期间没有进行任何数据库操作。逐渐积累的API请求在备份完成后的短时间内对Nginx、AppService、Redis、RDS带来了不小的冲击。于是就出现了上面描述的现象。7、事后，问题的根源还是出在Redis的备份上。再说说Redis的备份。Redis的持久化分为两种方案：全量方式RDB增量方式AOF详细可以参考官方中文翻译：http://www.redis.cn/topics/persistence.htmlRDB根据格式备份文件，这是一个完整的备份。它进一步分为两种不同的形式。涉及到的Redis命令有SAVE/BGSAVE：SAVE：众所周知，Redis服务是单线程的。SAVE和其他常用命令一样，也在主进程中运行。可以想象，如果SAVE很慢，其他命令将不得不等待它完成。BGSAVE：BGSAVE命令也可以触发全量备份，但Redis会为其fork一个子进程。BGSAVE命令运行在子进程中，不会影响Redis主进程执行其他命令。它唯一的作用可能是在操作系统层面与Redis主进程竞争资源（CPU、RAM等）。AOF增量备份方式有点像MySQL的binlog机制。它将更改数据的命令附加到备份文件。该方法是Redis服务的行为，不对外提供命令。两种方式优缺点对比：RDB文件小，自定义格式有优势。AOF文件很大。Redis虽然会合并一些指令，但是流水账还是会很大。RDB备份时间长，无法做到细粒度备份。AOF的每条指令都有备份，可以细粒度。两者可以结合使用。AmazonElastiCacheforRedis我们使用AWS托管服务，他们如何备份？具体可以参考官方文档：https://docs.aws.amazon.com/zh_cn/AmazonElastiCache/latest/red-ug/backups.html#backups-performanceRedis2.8.22之前：使用BGSAVE命令，如果预留内存不足，备份可能会失败。Redis2.8.22及更高版本：如果内存不足，请使用SAVE命令。如果内存足够，请使用BGSAVE命令。应该保留多少内存？AWS官方推荐25%的内存。很明显，我们实例的预留内存是不够这个数的，才会出现问题。我认为AWS可以做更好的备份。【原创稿件，合作网站转载请注明原作者和出处为.com】
