布景
前段时刻咱们的服务遇到了功能瓶颈,由于前期需求太急没有留意这方面的优化,到了要还技能债的时分就十分痛苦了。
在很低的 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 结构层或体系层。
这时分能够对运行时线程栈来分析,我运用 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 类内一个属性的参数绑定。
而不幸的是,咱们的接口上层会为咱们一致传过来三四十个参数,所以每次都会进行很多的”测验绑定”,形成的反常和反常处理就会导致很多的功能丢失,在运用参数解析器处理这个问题后,接口功能居然有近十分之一的提升。
小结
功能优化不是一朝一夕的事,把技能债都堆到最后一块处理绝不是什么好的挑选。平常多留意一些代码写法,在运用黑科技时留意一下其实现有没有什么躲藏的坑才是正解,还能够进行定期的功能测验,及时发现并处理代码里近期引进的不安定因素。