Dubbo项目线上案例解析

Posted 2021-04-06 技术琐话

本节介绍笔者在工作和实践中遇到的两起事故案例，可通过这两个案例了解到解决问题的方法。对于更多的线上事故解决方法和步骤，可以参考《分布式服务架构：原理、设计与实战》第6章的内容。

线上问题的通用解决方案

1．发现问题

发现问题通常通过自动化的监控和报警系统来实现，线上游戏服搭建了一个完善、有效的日志中心、监控和报警系统，通常我们会从系统层面、应用层面和数据库层面进行监控。

对系统层面的监控包括对系统的CPU利用率、系统负载、内存使用情况、网络I/O负载、磁盘负载、I/O等待、交换区的使用、线程数及打开的文件句柄数等进行的监控，一旦超出阈值，就需要报警。

对应用层面的监控包括对服务接口的响应时间、吞吐量、调用频次、接口成功率及接口的波动率等进行的监控。

对资源层的监控包括对数据库、缓存和消息队列的监控。我们通常会对数据库的负载、慢SQL、连接数等进行监控；对缓存的连接数、占用内存、吞吐量、响应时间等进行监控；并对消息队列的响应时间、吞吐量、负载、积压情况等进行监控。

2．定位问题

定位问题时，首先要根据经验来分析，如果应急团队中有人对相应的问题有经验，并确定能够通过某种手段进行恢复，则应该第一时间恢复，同时保留现场，然后定位问题。

应急人员在定位过程中需要与业务负责人、技术负责人、核心技术开发人员、技术专家、架构师、运营人员和运维人员一起，对产生问题的原因进行快速分析。在分析的过程中要先考虑系统最近的变化，考虑如下问题。

• 问题系统最近是否进行了上线？

• 依赖的基础平台和资源是否进行了上线或者升级？

• 依赖的系统最近是否进行了上线？

• 运营人员是否在系统里做过运营变更？

• 网络是否有波动？

• 最近的业务是否上量？

•  服务的使用方是否有促销活动？

3．解决问题

解决问题的阶段有时处于应急处理中，有时处于应急处理后。在理想情况下，每个系统都会对各种严重情况设计止损和降级开关，因此在发生严重问题时先使用止损策略，在恢复问题后再定位和解决问题。解决问题要以定位问题为基础，必须清晰地定位问题产生的根本原因，再提出解决问题的有效方案，切记在没有明确原因之前，不要使用各种可能的方法来尝试修复问题，这样可能导致还没有解决这个问题又引出另一个问题。

4．消除影响

在解决问题时，某个问题可能还没被解决就已恢复，在任何情况下都需要消除问题带来的影响。

• 技术人员在应急过程中对系统做的临时性改变，若在后面证明是无效的，则要尝试恢复到原来的状态。

• 技术人员在应急过程中对系统进行的降级开关操作，在事后需要恢复。

• 运营人员在应急过程中对系统做的特殊设置如某些流量路由的开关，在事后需要恢复。

• 对使用方或者用户造成的问题，尽量采取补偿的策略进行修复，在极端情况下需要一一核实。

• l对外由专门的客服团队整理话术，统一对外宣布发生故障的原因并安抚用户，话术要贴近客观事实，并从用户的角度出发。

在详细了解如何发现问题、定位问题、解决问题和消除造成的影响后，接下来让我们看看在实际情况下如何应用。

首先，找运维看日志。如果在日志监控系统中有报错，则能很好地定位问题，我们只需根据日志报错的堆栈信息来解决问题即可。如果在日志监控系统中没有任何异常信息，就得保存现场了。

其次，保存现场并恢复服务。在日志系统中找不到任何线索的情况下，我们需要赶紧保存现场快照，并尽快恢复服务，以达到最大程度止损的目的。在JVM中保存现场快照通常包括保存当前运行线程的快照和保存JVM内存堆栈快照。如下所述。

（1）保存当前运行线程的快照，可以使用jstack [pid]命令实现，在通常情况下需要保存三份不同时刻的线程快照，时间间隔为1～2分钟。

（2）保存JVM内存堆栈快照，可以使用jmap –heap、jmap –histo、jmap -dump:format=b、file=xxx.hprof等命令实现。

快速恢复服务的常用方法如下：

（1）隔离出现问题的服务，使其退出线上服务，便于后续的分析处理。

（2）尝试快速重启服务，第一时间恢复系统，而不是彻底解决问题。

（3）对服务降级处理，只使用少量的请求来重现问题，以便我们全程跟踪观察，因为之前可能没太注意这个问题是如何发生的。

通过上面的一系列操作后，要分析日志并定位问题。这一步很关键，也需要有很多实战经验，需要先查看服务器的“当前症状”，才能进一步对症下药。下面提供从服务器的CPU、内存和I/O三方面查看症状的基本方法。

查看CPU或内存情况的命令如下：

l   top：查看服务器的负载状况。

l   top+1：在top视图中按键盘数字“1”查看每个逻辑CPU的使用情况。

l   jstat –gcutil pid：查看堆中各内存区域的变化及GC的工作状态。

l   top+H：查看线程的使用情况。

l   ps -mp pid -o THREAD,tid,time | sort -rn：查看指定进程中各个线程占用CPU的状态，选出耗时最多、最繁忙的线程id。

l   jstack pid：打印进程中的线程堆栈信息。

判断内存溢出（OOM）方法如下。

l   堆外内存溢出：由JNI的调用或NIO中的DirectByteBuffer等使用不当造成。

l   堆内内存溢出：容易由程序中创建的大对象、全局集合、缓存、ClassLoader加载的类或大量的线程消耗等造成。

l   使用jmap –heap命令、jmap –histo命令或者jmap-dump:format=b,file=xxx.hprof等命令查看JVM内存的使用情况。

分析I/O读写问题的方法如下。

l   文件I/O：使用命令vmstat、lsof –c -ppid等。

l   网络I/O：使用命令netstat –anp、tcpdump -i eth0 ‘dst host 239.33.24.212’ -w raw.pcap和wireshark工具等。

l   mysql数据库：查看慢查询日志、数据库的磁盘空间、排查索引是否缺失，或使用show processlist检查具体的SQL语句情况。

最后，在Hotfix后继续观察情况。在测试环境或预生产环境修改测试后，如果问题不能再复现了，就可以根据公司的Hotfix流程进行线上的Bug更新，并继续观察。如果一切都正常，就需要消除之前可能造成的影响。

耗时服务耗尽了线程池的案例

有一次，我们线上的某个Web服务访问报HTTP 500错误，在查看log日志时报异常，异常的关键信息如下：

Caused by:java.util.concurrent.RejectedExecutionException: Thread pool is EXHAUSTED!Thread Name: DubboServerHandler-172.31.24.215:20880, Pool Size: 200 (active:200, core: 200, max: 200, largest: 200), Task: 3622292 (completed: 3622092),Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), indubbo://172.31.24.215:20880!

我们并没有手动设置过服务端线程池的大小，默认使用200，从报错日志来看，明显是服务端的线程池被用光了。

接下来使用jstack pid打印进程中的线程堆栈信息，确实有200个Dubbo线程在不断地执行，Dubbo线程的命名格式为：DubboServerHandler-192.168.168.101:20880-thread-num。

为什么突然有这么多线程不断执行呢？是用户量突然增大了，还是有爬虫攻击？带着这些问题，笔者查看了网络流量监控，并未发现有明显的流量突增。

我们通过日志和监控暂时没有发现问题的成因，就添加了些日志，添加了请求时长打印，也增加了服务端的线程数。问题依然存在，不过可以排除服务端的线程数设置的问题了。

最后，通过新添加的日志打印发现，服务的请求时间普遍很长，这引起了我们的注意，顺着该线索找下去，才发现是服务调用数据库的时间太长，所以最后定位为数据库的问题。

在定位为是数据库执行慢导致很多线程占用不释放后，我们开始查看MySQL慢查询日志。由于之前慢查询的阀值时间被设置为1秒，所以在慢查询日志中没有任何记录；然后使用show processlist查看SQL的执行情况，发现有一条SQL语句占用的时间较长；最后，修改慢查询的时间为500毫秒，并记录下相关的慢查询SQL语句。

我们采取的解决方法为：为慢查询语句添加索引并修改逻辑代码，恢复之前的修改。通过查看codereview相关的代码，我们发现有部分业务逻辑在for循环中多次查询数据库，便将其修改为一次查询多条数据，然后在for循环中使用。

-----------------------------------------------------------------------------------

如对分布式缓存有进一步阅读欲望，推荐本号作者总策划和合著的新书。

《深入分布式缓存》

购书请点击查看原文。

推广活动：评论区点赞多的前三名可获得《可伸缩服务架构：框架与中间件》,如果文章阅读量超过5000，还有神秘奖项--挑选评论最走心者送出作者签名版《深入分布式缓存》。

声明：

封面图片由张逸大师提供，公子张子瞻拍摄于动物园。