今天,考试系统出现生产问题。
1.老师反馈,无法创建考试、发布考试。
2.学员反馈,无法打开"我的考试"列表,无法参加考试、提交考试后成绩无法显示,一直处于"成绩正在计算中"页面。
开发人员自测,发现整个系统感觉变慢,响应时间变长;
日志部分报错Dubbo连接超时;
Kafka队列不减少,Kafka消费者端时有时无;
运维人员反馈,redis压力变大,cpu100%,对某些key频繁操作;不过redis无错误日志;
数据库压力正常;
尝试重启各种Java后台项目,仍没有解决系统变慢的问题。
尝试把kafka收发代码修改为rabbitmq收发代码;
可能由于晚上用户变少的缘故,发现系统变快,然后于凌晨3时下班。
上午,还是有用户反馈之前的问题,整个系统还是很慢。
下午,采取了限流措施,让用户分批考试。
晚上,有专家组来支援,尝试在代码中增加时间日志,分析程序运行时间;
尝试查看nginx日志,发现大量500错误是用户身份认证接口超时报错;
尝试查看Java堆栈dump文件;
尝试重启项目;
尝试重启Kafka,调整Kafka主从配置;
尝试删除生产数据库部分错误数据;
尝试重启Redis(之前一直因为生产担心丢数据,未重启redis;直到上级领导同意重启,对于丢失考试成绩的考生,允许其重新考试)
使用Jmeter压测高并发接口,压测通过;决定到此为止,等下一天用户量多时看看怎么样。
此时凌晨4点结束整个解决问题流程。(本人在本公司的首次通宵)
今日,考试系统运行正常,不再有大量用户反馈系统慢、无法使用。
分析之前出问题的日志,主要是Dubbo报错多、请求响应超时多,只能说明当时Java程序确实很卡,没有分析到主要原因。
整个修复过程中,最终没有修改程序代码,只是进行了全部重启的操作,重启Java程序,重启Kafka,重启redis,删除数据库错误数据等。
redis压力变大过,但是没有错误日志,还能正常使用;
数据库压力一直正常;
网络应该也没有问题;
Kafka出现队列只增不减的情况,是因为消费者消费Kafka时报错,因此kafka消息队列没有减少(有配置,只有成功消费才会让消息队列减少)
从kafka消费者报错线排查,也只能排查到Dubbo超时,程序确实响应慢到超时,还是无法得知核心原因。
整个项目以前经受过用户多、高并发的考验,因此这次出问题,也不是架构问题。
总之就是不知道什么问题,当时系统变慢,导致大批用户反馈考试系统无法使用了。
今天,开发完其它需求后,暂时有空继续排查当时的问题。
1.经过多日排查,感觉系统主要是重启redis后才恢复正常。
2.代码中有很多地方用到了redis锁,推测可能是等待锁的线程过多(如果获取不到锁,就sleep,直到获取到锁),导致系统变慢。(但是有finally释放redis锁,正常情况下不应该有太多等锁的线程)
3.推测,由于数据库数据一直在增多,因此有些教师端操作会耗费大量时间与内存等资源(修改试卷关联标签等),此时会导致整个程序变慢;
正常情况下重启Java后台可以中断这种操作,让程序恢复正常(不过可能产生数据库错误数据);
但是如果有高并发用户访问Java后台、处于等待redis锁的状态、如果此时重启项目,会让占用redis锁的线程无法执行finally方法(由于处理耗时,一直占用锁,还没有处理完,再加上程序突然关闭),就会无法释放redis锁;
如果重启项目时,占用redis锁的线程有很多(大量用户),就会有大量无法释放的redis锁留在redis中;
进而导致重启项目后,用户量不变,系统刚开始较快,之后还是会变慢(又出现了大量等待redis锁的线程)。
4.总之,就是redis中如果存在大量redis锁的话,只重启Java项目就不能让程序恢复正常,只有重启redis后,程序才能恢复正常。
5.本地测试,如果出现大量等待redis锁的线程会怎么样
6.本地测试发现,确实会出现白页面等问题,很像当时出现的问题。
7.因此本人怀疑,当时系统变慢,起因是教师端的耗时操作导致系统变慢;之后由于重启Java后台项目,导致大量redis锁残留在redis中,导致系统一直都慢。(如果不做干预,等教师端耗时操作结束,系统也能恢复正常,但是干预后导致问题加重。)
8.目前仍在推测阶段,没有证据能证明核心原因。
(各处都没有明显错误日志;数据库等压力都正常,redis压力也在可以接受的范围,没有压崩;本身就是高并发,dump中有线程报错也很正常;代码中有大量redis锁,有些还不太确定作用,逐一排查也很难;确实不好找证据)
1.重启Java项目,可能导致finally方法无法执行,可能导致redis锁无法释放。
2.想解决上述系统变慢、影响大批用户使用的问题,一方面,可以排查下哪些是耗时操作,先禁止用户使用耗时操作,然后再慢慢优化。(真实情况是代码庞大,功能繁多,一时半会真不知道哪些是耗时操作)
3.怀疑是redis锁导致系统变慢,因此可以整理下所有涉及到的redis锁,写一个清空所有redis锁的逻辑。(但是清空redis锁后,又会导致数据库出现大量错误数据,还得整理出相关的处理方法……感觉还是从第2点想办法吧)
4.最后,重启redis确实能释放redis锁(那些锁的key设置的都是1天,如果没有释放,就得等1天才自己消失),但是会丢失数据,后果也很严重。(丢失考试成绩,学员就得重新考试……)