来源：https://zhenbianshu.github.io/前段时间，我们的服务遇到了性能瓶颈。由于前期需求比较急，所以没有关注这方面的优化。到了偿还技术债务的时候，非常痛苦。在极低的QPS压力下，服务器负载可达10-20，CPU使用率超过60%，每次流量高峰时，界面都会报大量错误。虽然使用了服务熔断框架Hystrix，但是熔断后服务延迟无法恢复。每一次变更上线，我就更加担心，担心它会成为压死骆驼的最后一根稻草，导致服务雪崩。在需求终于放缓之后，领导给我们定下目标，要在两周内彻底解决服务性能问题。在近两周的排查整理中，发现并解决了多个性能瓶颈，修改了系统熔断方案，将服务可处理的QPS提升了一倍，使服务在超高QPS（3-4倍）压力下正常熔断，并且降压后能迅速恢复正常，以下是部分问题的排查及解决过程。服务器高CPU、高负载首先要解决的问题是服务导致服务器整体负载高、CPU高的问题。我们整个服务可以概括为从某个存储或者远程调用获取一批数据，然后对这批数据进行各种花式变换，最后返回。由于数据转换过程长，操作多，系统CPU高一些是正常的，但正常情况下CPUus在50%以上，还是有点夸张。我们都知道在服务器上可以使用top命令查询系统中各个进程的CPU和内存使用情况。但是JVM是Java应用程序的领域。应该用什么工具查看JVM中各个线程的资源使用情况？jmc是可以的，但是使用起来比较麻烦，需要一系列的设置。我们还有一个选择，就是使用jtop，jtop只是一个jar包，它的项目地址在yujikiriki/jtop，我们可以很方便的把它拷贝到服务器上，得到java应用的pid后，使用java-jarjtop.jar[options]可以输出JVM内部统计信息。jtop会使用默认参数-stackn打印出5个最耗CPU的线程堆栈。形式如：HeapMemory:INIT=134217728USED=230791968COMMITED=450363392MAX=1908932608NonHeapMemory:INIT=2555904USED=24834632COMMITED=26411008MAX=-1GCPSScavengeVALID[PSEdenSpace,PSGC=SurvivorSpace]GCT440GCPSMarkSweepVALID[PSEdenSpace,PSSurvivorSpace,PSOldGen]GC=2GCT=532ClassLoadingLOADED=3118TOTAL_LOADED=3118UNLOADED=0线程总数：608CPU=2454(106.88%)USER=2142(93.30%)NEW=0RUNNABLE=6BLOCKED=0WAITING=2TIMED_WAITING=600TERMINATED=0mainTID=1STATE=RUNNABLECPU_TIME=2039(88.79%)USER_TIME=1970(85.79%)分配：640318696com.google.common.util.concurrent。RateLimiter.tryAcquire(RateLimiter.java:337)io.zhenbianshu.TestFuturePool.main(TestFuturePool.java:23)RMITCP连接(2)-127.0.0.1TID=2555STATE=RUNNABLECPU_TIME=89(3.89%)USER_TIME=85(3.70%)已分配：7943616sun.management.ThreadImpl.dumpThreads0（本地方法）sun.management.ThreadImpl.dumpAllThreads（ThreadImpl.java:454)me.hatter.tools.jtop.rmi.RmiServer.listThreadInfos(RmiServer.java:59)me.hatter.tools.jtop.management.JTopImpl.listThreadInfos(JTopImpl.java:48)sun.reflect。NativeMethodAccessorImpl.invoke0(NativeMethod)......通过观察线程栈，我们可以找到需要优化的代码点。在我们的代码中，发现了很多json序列化反序列化和Bean拷贝的消耗CPU的点。之后通过代码优化，通过提高Bean的复用率，使用PB代替json等方式，大大降低了CPU压力。Fuse框架优化服务Fuse框架，我们选择了Hystrix。虽然已经宣布不再维护，但是还是推荐使用resilience4j和阿里开源的sentinel。不过，由于本部门的技术栈是Hystrix，而且没有明显的缺点，所以就用了。先介绍一下基本情况。我们在控制器接口的最外层和内部RPC调用处添加了Hystrix注解。隔离方式为线程池方式。接口超时设置为1000ms，最大线程数为2000超时设置为200ms，最大线程数为500界面。观察接口的访问日志，可以发现接口有请求耗时1200ms，有的甚至达到2000ms以上。由于线程池模式，Hystrix会使用一个异步线程来执行真正的业务逻辑，而主线程一直在等待。一旦等待超时，主线程可以立即返回。所以接口超过超时时间，问题很可能出现在Hystrix框架层，Spring框架层，或者系统层。推荐一个SpringBoot基础教程和实例：https://github.com/javastacks...这时候可以分析运行时线程栈。我使用jstack打印出线程堆栈，并将多次打印的结果制作成Flamegraph（参见ApplicationDebuggingTools-FlameGraph）进行观察。如上图所示，可以看到很多线程都停在了LockSupport.park(LockSupport.java:175)处，这些线程都被锁住了。往下看源码，就是HystrixTimer.addTimerListener(HystrixTimer.java:106)，然后到下面就是我们的业务代码了。Hystrix注释说明这些TimerListener是HystrixCommand用来处理异步线程超时的，当调用超时时会执行，并返回超时结果。当调用次数较多时，设置这些TimerListener会因为锁而阻塞，导致接口设置的超时时间不生效。然后查看为什么调用了这么多TimerListener。由于服务在多个地方依赖同一个RPC返回值，平均一次接口响应会得到相同的值3-5次，所以接口在本次RPC的返回值中加入了LocalCache。查看代码发现在LocalCache的get方法中添加了HystrixCommand，所以当单机QPS为1000时，会通过Hystrix调用该方法3000-5000次，从而产生大量的HystrixTimerListener。代码类似于：@HystrixCommand(fallbackMethod="fallBackGetXXXConfig",commandProperties={@HystrixProperty(name="execution.isolation.thread.timeoutInMilliseconds",value="200"),@HystrixProperty(name="circuitBreaker.errorThresholdPercentage",value="50")},threadPoolProperties={@HystrixProperty(name="coreSize",value="200"),@HystrixProperty(name="maximumSize",value="500"),@HystrixProperty(name="allowMaximumSizeToDivergeFromCoreSize",value="true")})publicXXXConfiggetXXXConfig(Longuid){try{returnXXXConfigCache.get(uid);}catch（异常e）{返回EMPTY_XXX_CONFIG；}}修改代码，将HystrixCommand修改为localCache的load方法来解决这个问题。另外，为了进一步降低Hystrix框架对性能的影响，将Hystrix隔离策略改为信号量模式，进而稳定接口的最大耗时。并且由于方法都在主线程上执行，没有了Hystrix线程池的维护和主线程与Hystrix线程的上下文切换，进一步降低了系统的CPU占用率。但是在使用信号量隔离模式时也要注意一个问题：信号量只能限制方法是否可以进入执行，方法返回后判断接口是否超时并处理超时，而不能干预已经在执行的方法。这可能会导致请求超时时，一个信号量一直被占用，但框架无法处理。服务隔离和降级另一个问题是服务不能以预期的方式降级和断开。我们认为当流量很大的时候，应该继续断线，但是Hystrix却显示偶尔断线。一开始在调试Hystrixfuse参数的时候，我们采用了日志观察的方式。由于日志设置为异步，我们看不到实时日志，而且有很多错误信息干扰，处理效率低，不准确。引入Hystrix的可视化界面后，提高了调试效率。Hystrix可视化模式分为服务端和客户端。服务器就是我们要观察的服务。我们需要在服务中引入hystrix-metrics-event-stream包并添加一个输出Metrics信息的接口，然后启动hystrix-dashboard客户端并填写服务器地址即可。通过类似上图的可视化界面，非常清晰的展示了Hystrix的整体状态。由于上述优化，接口的最大响应时间完全可控，并且可以通过严格限制接口方法的并发来修改接口的熔断策略。假设我们能容忍的最大接口平均响应时间是50ms，服务能接受的最大QPS是2000，那么合适的信号量限制可以通过2000*50/1000=100得到。如果拒绝的错误太多，可以添加一些冗余。这样，当流量突然变化时，可以通过拒绝部分请求来控制接口接受的请求总数，并严格限制这些请求总数中的最大耗时。如果错误过多，也可以通过熔断降级，多种策略同时进行，可以保证接口的平均响应时间。熔断时的高负载使其无法恢复。接下来解决接口熔断时，服务负载持续上升，QPS压力降低后服务无法恢复的问题。当服务器负载特别高的时候，用各种工具观察服务内部状态是不靠谱的，因为观察一般采用点采集的方式，在观察服务的同时服务发生了变化。比如在高负载下使用jtop查看CPU最密集的线程时，得到的结果总是JVMTI相关的栈。但是观察服务外部，我们可以发现此时会有大量的错误日志输出，往往是在服务稳定了很久之后，还有之前的错误日志在打印，而延迟的单位甚至以分钟为单位。大量的错误日志不仅会造成I/O压力，线程栈的获取和日志内存的分配也会增加服务器的压力。而且由于日志量大，服务改为异步日志，使得通过I/O阻塞线程的障碍消失了。之后修改服务中的日志记录点，打印日志时不再打印异常堆栈，然后重写Spring框架的ExceptionHandler，彻底减少日志量的输出。结果符合预期。当错误量特别大的时候，日志的输出也控制在正常范围内，这样在熔断之后，日志就不会再增加服务的压力了。一旦QPS压降，熔断开关关闭，服务很快就可以使用了。恢复正常。Springdatabindingexception另外，在查看jstack输出的线程栈时，也无意中发现了一个奇怪的栈。在java.lang.Throwable.fillInStackTrace(NativeMethod)在java.lang.Throwable.fillInStackTrace(Throwable.java:783)-锁定<0x00000006a697a0b8>（一个org.springframework.beans.NotWritablePropertyException）...org.springframework.beans.AbstractNestablePropertyAccessor.processLocalProperty（AbstractNestablePropertyAccessor.java:426）在org.springframework.beans.AbstractNestablePropertyAccessor.setPropertyValue（AbstractNestablePropertyAccessor.java:278）...在org.springframework.validation.DataBinder.doBinjad:DataBinder.doBinder:DataBinder..springframework.web.bind.WebDataBinder.doBind（WebDataBinder.java:197）在org.springframework.web.bind.ServletRequestDataBinder.bind（ServletRequestDataBinder.java:107）在org.springframework.web.method.support.InvocableHandlerMethod.getMethodArgumentValues(InvocableHandlerMethod.java:161)...atorg.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991)jstack的一次输出中，可以看到多个线程的栈顶都停在Spring的异常处理，但是此时没有日志输出，业务也没有异常。我跟进了代码并查看了它。Spring其实是偷偷捕获了异常，并没有做任何事情。List
