关于java:搞了-2-周性能优化QPS-终于翻倍了

32次阅读

共计 7237 个字符,预计需要花费 19 分钟才能阅读完成。

起源:https://zhenbianshu.github.io/

前段时间咱们的服务遇到了性能瓶颈,因为后期需要太急没有留神这方面的优化,到了要还技术债的时候就十分苦楚了。

在很低的 QPS 压力下服务器 load 就能达到 10-20,CPU 使用率 60% 以上,而且在每次流量峰值时接口都会大量报错,尽管应用了服务熔断框架 Hystrix,但熔断后服务却迟迟不能复原。每次变更上线更是胆战心惊,放心会成为压死骆驼的最初一根稻草,导致服务雪崩。

在需要终于缓下来后,leader 给咱们定下指标,限咱们在两周内把服务性能问题彻底解决。近两周的排查和梳理中,发现并解决了多个性能瓶颈,批改了零碎熔断计划,最终实现了服务能解决的 QPS 翻倍,能实现在极高 QPS(3- 4 倍)压力下服务失常熔断,且能在压力升高后迅速恢复正常,以下是局部问题的排查和解决过程。

服务器高 CPU、高负载

首先要解决的问题就是服务导致服务器整体负载高、CPU 高的问题。

咱们的服务整体能够演绎为从某个存储或近程调用获取到一批数据,而后就对这批数据进行各种花式变换,最初返回。因为数据变换的流程长、操作多,零碎 CPU 高一些会失常,但平时状况下就 CPU us 50% 以上,还是有些夸大了。

咱们都晓得,能够应用 top 命令在服务器上查问零碎内各个过程的 CPU 和内存占用状况。可是 JVM 是 Java 利用的领地,想查看 JVM 里各个线程的资源占用状况该用什么工具呢?

jmc 是能够的,但应用它比拟麻烦,要进行一系列设置。咱们还有另一种抉择,就是应用 jtop,jtop 只是一个 jar 包,它的我的项目地址在 yujikiriki/jtop,咱们能够很不便地把它复制到服务器上,获取到 java 利用的 pid 后,应用 java -jar jtop.jar [options] 即可输入 JVM 外部统计信息。

jtop 会应用默认参数 -stack n 打印出最耗 CPU 的 5 种线程栈。

形如:

Heap Memory: INIT=134217728  USED=230791968  COMMITED=450363392  MAX=1908932608
NonHeap Memory: INIT=2555904  USED=24834632  COMMITED=26411008  MAX=-1
GC PS Scavenge  VALID  [PS Eden Space, PS Survivor Space]  GC=161  GCT=440
GC PS MarkSweep  VALID  [PS Eden Space, PS Survivor Space, PS Old Gen]  GC=2  GCT=532
ClassLoading LOADED=3118  TOTAL_LOADED=3118  UNLOADED=0
Total threads: 608  CPU=2454 (106.88%)  USER=2142 (93.30%)
NEW=0  RUNNABLE=6  BLOCKED=0  WAITING=2  TIMED_WAITING=600  TERMINATED=0

main  TID=1  STATE=RUNNABLE  CPU_TIME=2039 (88.79%)  USER_TIME=1970 (85.79%) Allocted: 640318696
    com.google.common.util.concurrent.RateLimiter.tryAcquire(RateLimiter.java:337)
    io.zhenbianshu.TestFuturePool.main(TestFuturePool.java:23)

RMI TCP Connection(2)-127.0.0.1  TID=2555  STATE=RUNNABLE  CPU_TIME=89 (3.89%)  USER_TIME=85 (3.70%) Allocted: 7943616
    sun.management.ThreadImpl.dumpThreads0(Native Method)
    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(Native Method)

    ... ...

通过观察线程栈,咱们能够找到要优化的代码点。

在咱们的代码里,发现了很多 json 序列化和反序列化和 Bean 复制耗 CPU 的点,之后通过代码优化,通过晋升 Bean 的复用率,应用 PB 代替 json 等形式,大大降低了 CPU 压力。

熔断框架优化

服务熔断框架上,咱们选用了 Hystrix,尽管它曾经发表不再保护,更举荐应用 resilience4j 和阿里开源的 sentinel,但因为部门内技术栈是 Hystrix,而且它也没有显著的短板,就接着用上来了。

先介绍一下根本状况,咱们在控制器接口最外层和内层 RPC 调用处增加了 Hystrix 注解,隔离形式都是线程池模式,接口处超时工夫设置为 1000ms,最大线程数是 2000,外部 RPC 调用的超时工夫设置为 200ms,最大线程数是 500。

响应工夫不失常

要解决的第一个问题是接口的响应工夫不失常。在察看接口的 access 日志时,能够发现接口有耗时为 1200ms 的申请,有些甚至达到了 2000ms 以上。因为线程池模式下,Hystrix 会应用一个异步线程去执行真正的业务逻辑,而主线程则始终在期待,一旦期待超时,主线程是能够立即返回的。所以接口耗时超过超时工夫,问题很可能产生在 Hystrix 框架层、Spring 框架层或零碎层。

举荐一个 Spring Boot 基础教程及实战示例:
https://github.com/javastacks…

这时候能够对运行时线程栈来剖析,我应用 jstack 打印出线程栈,并将屡次打印的后果制作成火焰图(参见 利用调试工具 - 火焰图)来察看。

如上图,能够看到很多线程都停在 LockSupport.park(LockSupport.java:175) 处,这些线程都被锁住了,向下看起源发现是 HystrixTimer.addTimerListener(HystrixTimer.java:106), 再向下就是咱们的业务代码了。

Hystrix 正文里解释这些 TimerListener 是 HystrixCommand 用来解决异步线程超时的,它们会在调用超时时执行,将超时后果返回。而在调用量大时,设置这些 TimerListener 就会因为锁而阻塞,进而导致接口设置的超时工夫不失效。

接着排查调用量为什么 TimerListener 特地多。

因为服务在多个中央依赖同一个 RPC 返回值,均匀一次接口响应会获取同样的值 3-5 次,所以接口内对这个 RPC 的返回值增加了 LocalCache。排查代码发现 HystrixCommand 被增加在了 LocalCache 的 get 办法上,所以单机 QPS 1000 时,会通过 Hystrix 调用办法 3000-5000 次,进而产生大量的 Hystrix TimerListener。

代码相似于:

@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")})
public XXXConfig getXXXConfig(Long uid) {
    try {return XXXConfigCache.get(uid);
    } catch (Exception e) {return EMPTY_XXX_CONFIG;}
}

批改代码,将 HystrixCommand 批改到 localCache 的 load 办法上来解决这个问题。此外为了进一步升高 Hystrix 框架对性能的影响,将 Hystrix 的隔离策略改为了信号量模式,之后接口的最大耗时就稳固了。而且因为办法都在主线程执行,少了 Hystrix 线程池保护和主线程与 Hystrix 线程的上下文切换,零碎 CPU 使用率又有进一步降落。

但应用信号量隔离模式也要留神一个问题:信号量只能限度办法是否可能进入执行,在办法返回后再判断接口是否超时并对超时进行解决,而无奈干涉曾经在执行的办法,这可能会导致有申请超时时,始终占用一个信号量,但框架却无奈解决。

服务隔离和降级

另一个问题是服务不能依照预期的形式进行服务降级和熔断,咱们认为流量在十分大的状况下应该会继续熔断时,而 Hystrix 却体现为偶然熔断。

最开始调试 Hystrix 熔断参数时,咱们采纳日志观察法,因为日志被设置成异步,看不到实时日志,而且有大量的报错信息烦扰,过程低效而不精确。起初引入 Hystrix 的可视化界面后,才晋升了调试效率。

Hystrix 可视化模式分为服务端和客户端,服务端是咱们要察看的服务,须要在服务内引入 hystrix-metrics-event-stream 包并增加一个接口来输入 Metrics 信息,再启动 hystrix-dashboard 客户端并填入服务端地址即可。

通过相似上图的可视化界面,Hystrix 的整体状态就展现得十分分明了。

因为上文中的优化,接口的最大响应工夫曾经齐全可控,能够通过严格限度接口办法的并发量来批改接口的熔断策略了。假如咱们能容忍的最大接口均匀响应工夫为 50ms,而服务能承受的最大 QPS 为 2000,那么能够通过 2000*50/1000=100 失去适宜的信号量限度,如果被回绝的谬误数过多,能够再增加一些冗余。

这样,在流量渐变时,就能够通过回绝一部分申请来管制接口承受的总申请数,而在这些总申请里,又严格限度了最大耗时,如果谬误数过多,还能够通过熔断来进行降级,多种策略同时进行,就能保障接口的均匀响应时长了。

熔断时高负载导致无奈复原

接下来就要解决接口熔断时,服务负载继续升高,但在 QPS 压力升高后服务迟迟无奈复原的问题。

在服务器负载特地高时,应用各种工具来观测服务外部状态,后果都是不靠谱的,因为观测个别都采纳打点收集的形式,在察看服务的同时曾经扭转了服务。例如应用 jtop 在高负载时查看占用 CPU 最高的线程时,获取到的后果总是 JVM TI 相干的栈。

不过,察看服务内部能够发现,这个时候会有大量的谬误日志输入,往往在服务曾经稳固良久了,还有之前的谬误日志在打印,延时的单位甚至以分钟计。大量的谬误日志不仅造成 I/O 压力,而且线程栈的获取、日志内存的调配都会减少服务器压力。而且服务早因为日志量大改为了异步日志,这使得通过 I/O 阻塞线程的屏障也隐没了。

之后批改服务内的日志记录点,在打印日志时不再打印异样栈,再重写 Spring 框架的 ExceptionHandler,彻底缩小日志量的输入。后果合乎预期,在谬误量极大时,日志输入也被管制在失常范畴,这样熔断后,就不会再因为日志给服务减少压力,一旦 QPS 压力降落,熔断开关被敞开,服务很快就能恢复正常状态。

Spring 数据绑定异样

另外,在查看 jstack 输入的线程栈时,还偶尔发现了一种奇怪的栈。

at java.lang.Throwable.fillInStackTrace(Native Method)
at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
  - locked <0x00000006a697a0b8> (a org.springframework.beans.NotWritablePropertyException)
  ...
org.springframework.beans.AbstractNestablePropertyAccessor.processLocalProperty(AbstractNestablePropertyAccessor.java:426)
at org.springframework.beans.AbstractNestablePropertyAccessor.setPropertyValue(AbstractNestablePropertyAccessor.java:278)
  ...
at org.springframework.validation.DataBinder.doBind(DataBinder.java:735)
at org.springframework.web.bind.WebDataBinder.doBind(WebDataBinder.java:197)
at org.springframework.web.bind.ServletRequestDataBinder.bind(ServletRequestDataBinder.java:107)
at org.springframework.web.method.support.InvocableHandlerMethod.getMethodArgumentValues(InvocableHandlerMethod.java:161)
 ...
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991)

jstack 的一次输入中,能够看到多个线程的栈顶都停留在 Spring 的异样解决,但这时候也没有日志输入,业务也没有异样,跟进代码看了一下,Spring 居然偷偷捕捉了异样且不做任何解决。

List<PropertyAccessException> propertyAccessExceptions = null;
List<PropertyValue> propertyValues = (pvs instanceof MutablePropertyValues ?
  ((MutablePropertyValues) pvs).getPropertyValueList() : Arrays.asList(pvs.getPropertyValues()));
for (PropertyValue pv : propertyValues) {
try {
  // This method may throw any BeansException, which won't be caught
  // here, if there is a critical failure such as no matching field.
  // We can attempt to deal only with less serious exceptions.
  setPropertyValue(pv);
}
catch (NotWritablePropertyException ex) {if (!ignoreUnknown) {throw ex;}
  // Otherwise, just ignore it and continue...
}
... ...
}

联合代码上下文再看,原来 Spring 在解决咱们的控制器数据绑定,要解决的数据是咱们的一个参数类 ApiContext。

控制器代码相似于:

@RequestMapping("test.json")
public Map testApi(@RequestParam(name = "id") String id, ApiContext apiContext) {}

依照失常的套路,咱们应该为这个 ApiContext 类增加一个参数解析器 (HandlerMethodArgumentResolver),这样 Spring 会在解析这个参数时会调用这个参数解析器为办法生成一个对应类型的参数。可是如果没有这么一个参数解析器,Spring 会怎么解决呢?

答案就是会应用下面的那段”奇怪”代码,先创立一个空的 ApiContext 类,并将所有的传入参数顺次尝试 set 进这个类,如果 set 失败了,就 catch 住异样继续执行,而 set 胜利后,就实现了 ApiContext 类内一个属性的参数绑定。

而可怜的是,咱们的接口下层会为咱们对立传过来三四十个参数,所以每次都会进行大量的”尝试绑定”,造成的异样和异样解决就会导致大量的性能损失,在应用参数解析器解决这个问题后,接口性能居然有近十分之一的晋升。

小结

性能优化不是久而久之的事,把技术债都堆到最初一块解决绝不是什么好的抉择。平时多留神一些代码写法,在应用黑科技时留神一下其实现有没有什么暗藏的坑才是正解,还能够进行定期的性能测试,及时发现并解决代码里近期引入的不安宁因素。

近期热文举荐:

1.1,000+ 道 Java 面试题及答案整顿 (2021 最新版)

2. 别在再满屏的 if/ else 了,试试策略模式,真香!!

3. 卧槽!Java 中的 xx ≠ null 是什么新语法?

4.Spring Boot 2.6 正式公布,一大波新个性。。

5.《Java 开发手册(嵩山版)》最新公布,速速下载!

感觉不错,别忘了顺手点赞 + 转发哦!

正文完
 0