spring-cloud-gateway是spring出品的微服務(wù)網(wǎng)關(guān)，我們公司基于此進(jìn)行了二次開發(fā)并承載公司所有web流量锌仅，之前我們一直用的是spring-cloud?Finchley.SR2版本對應(yīng)的gateway摄凡，最近我們嘗試升級到spring-cloud?Greenwich.RELEASE版本時發(fā)現(xiàn)GC惡化了不少蝎宇，于是排查之旅就此開始徽龟。

先在兩臺升級前后的機(jī)器上執(zhí)行jstat命令贤旷，這個命令可以查看GC概況广料，在排查GC問題時非常有用，如下兩圖分別是升級前后的GC概況：

圖1. 升級前GC概況

圖2. 升級后GC概況

從這兩張圖中我們可以得到如下結(jié)論：

young gc頻率差不多幼驶，都是大約4秒一次艾杏，但是每次young gc后，圖2中survivor區(qū)占用內(nèi)存明顯比圖1高很多盅藻，圖2中每次晉升到old區(qū)的內(nèi)存量也明顯比圖1高购桑；這說明升級后存活對象數(shù)增加了很多，導(dǎo)致gc惡化氏淑。圖中也可以看出升級后FGCT（筆者用的是CMS垃圾回收算法）明顯比升級前多了很多勃蜘。

那么到底是哪些存活對象變多了導(dǎo)致GC惡化了呢？樓主在分析問題的時候用了一款瑞士軍刀：https://github.com/DarLiner/vjtools/tree/master/vjmap

在升級前后的機(jī)器上分別執(zhí)行命令：./vjmap.sh -sur PID > histo-sur.log假残，這個命令可以輸出survivor區(qū)的對象統(tǒng)計(jì)信息（這個命令會STW元旬，執(zhí)行前別忘了先切斷流量），兩臺機(jī)器執(zhí)行結(jié)果分別如下：

圖3. 升級前survivor區(qū)對象統(tǒng)計(jì)信息

圖4. 升級后survivor區(qū)對象統(tǒng)計(jì)信息

從圖中可以看出升級后java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask這個類的對象占用了8.7M內(nèi)存守问，而升級前這個類的對象非常少匀归，看來李鬼就在這里了。

那么這些對象到底是哪里來的呢耗帕，從以上概況已經(jīng)看不出更多信息了穆端，這個時候就該用jmap命令dump內(nèi)存看看了，balabala仿便，十幾分鐘過后体啰，樓主打開新鮮出爐的內(nèi)存dump文件，經(jīng)過一番分析嗽仪，發(fā)現(xiàn)了如下關(guān)鍵信息：

內(nèi)存dump分析

如上圖所示荒勇，可以看到大量java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask對象存在ScheduledThreadPoolExecutor的工作隊(duì)列中，看源碼可以知道ScheduledThreadPoolExecutor會把所有提交的任務(wù)包裝成ScheduledFutureTask放入queue中闻坚，并在執(zhí)行完成后刪除沽翔，從這里也能看出ScheduledThreadPoolExecutor的threadFactory使用了reactor.core.schedule.ReactorThreadFactory, 看起來是有地方在使用reactor-java提交大量延時任務(wù)導(dǎo)致的。

目前使用上述手段也已經(jīng)無法獲得更多信息窿凤，繼續(xù)從其他地方著手繼續(xù)排查仅偎。樓主發(fā)現(xiàn)在斷開流量后，過五六分鐘去重新執(zhí)行命令查看survivor區(qū)對象雳殊，ScheduledFutureTask對象實(shí)例幾乎沒有了橘沥，這說明ScheduledFutureTask這個對象的創(chuàng)建基本是由流量觸發(fā)的。于是我打開本地代碼夯秃，在ScheduledThreadPoolExecutor類中所有提交任務(wù)的代碼中加入斷點(diǎn)座咆，并加入斷點(diǎn)條件：this.getThreadFactory().getClass().getSimpleName().equals("ReactorThreadFactory")

Idea增加條件斷點(diǎn)

然后通過瀏覽器打開頁面痢艺，果然觸發(fā)了斷點(diǎn)。斷點(diǎn)所在堆棧很長介陶，樓主截取了關(guān)鍵信息如下：

"reactor-http-kqueue-4" #340 daemon prio=5 os_prio=31 tid=0x00007fe61cb62800 nid=0x15207 at breakpoint[0x000070000fa71000] java.lang.Thread.State: RUNNABLE at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:544) at reactor.core.scheduler.Schedulers.directSchedule(Schedulers.java:838) at reactor.core.scheduler.ParallelScheduler.schedule(ParallelScheduler.java:158) at reactor.core.scheduler.Schedulers$CachedScheduler.schedule(Schedulers.java:767) at reactor.core.publisher.MonoDelay.subscribe(MonoDelay.java:58) at reactor.core.publisher.MonoOnErrorResume.subscribe(MonoOnErrorResume.java:44) at reactor.core.publisher.Mono.subscribe(Mono.java:3710) at reactor.core.publisher.FluxTimeout.subscribe(FluxTimeout.java:89) at reactor.core.publisher.FluxOnErrorResume.subscribe(FluxOnErrorResume.java:47) at reactor.core.publisher.Flux.subscribe(Flux.java:7793)
?......
?......
?at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) at reactor.core.publisher.Mono.subscribe(Mono.java:3710) at rx.RxReactiveStreams$1.call(RxReactiveStreams.java:60) at rx.RxReactiveStreams$1.call(RxReactiveStreams.java:57)
?......
?......
at rx.Observable.subscribe(Observable.java:10095) at org.springframework.cloud.gateway.filter.factory.HystrixGatewayFilterFactory.lambda$null$0(HystrixGatewayFilterFactory.java:102) at org.springframework.cloud.gateway.filter.factory.HystrixGatewayFilterFactory$$Lambda$948/2078441774.accept(Unknown Source) at reactor.core.publisher.MonoCreate.subscribe(MonoCreate.java:57) at reactor.core.publisher.MonoOnErrorResume.subscribe(MonoOnErrorResume.java:44) at reactor.core.publisher.Mono.subscribe(Mono.java:3710) at reactor.core.publisher.MonoIgnorePublisher.subscribe(MonoIgnorePublisher.java:41)
?......
?......
at reactor.netty.http.server.HttpServerHandle.onStateChange(HttpServerHandle.java:64) at reactor.netty.tcp.TcpServerBind$ChildObserver.onStateChange(TcpServerBind.java:234) at reactor.netty.http.server.HttpServerOperations.onInboundNext(HttpServerOperations.java:436) at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:141) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) at reactor.netty.http.server.HttpTrafficHandler.channelRead(HttpTrafficHandler.java:162) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
?......
?......
?at java.lang.Thread.run(Thread.java:745)

注意其中的粗體部分腹备，F(xiàn)luxTimeout，從這個類可以看出調(diào)用來自Flux.timeout方法斤蔓，類似reactor的框架素來就對調(diào)試非常不友好植酥，從這個堆棧完全看不出是哪里調(diào)用了Flux.timeout, 經(jīng)過一番查找和調(diào)試，筆者發(fā)現(xiàn)Flux.timeout來自源碼org.springframework.cloud.gateway.filter.NettyRoutingFilter：

spring源碼

spring在這里設(shè)置了超時時間弦牡，如果從上游的響應(yīng)超過了超時時間友驮，則拋出異常。筆者這里的超時時間設(shè)置了59秒驾锰。

結(jié)合以上分析卸留，答案自然浮出了水面：spring-cloud-gateway每次處理一個http請求時都會調(diào)用Flux.timeout往ScheduledThreadPoolExecutor中提交一個延時任務(wù)（在這個例子中是延遲59秒后執(zhí)行）并生成一個ScheduledFutureTask放入工作隊(duì)列中，大部分情況下上游的響應(yīng)都會在十幾ms內(nèi)響應(yīng)椭豫，reactor-java會調(diào)用ScheduledFutureTask.cancel來取消這個延時任務(wù)的觸發(fā)耻瑟，然而這個ScheduledFutureTask對象仍然會存在于工作隊(duì)列中，直到59秒后才會被從隊(duì)列中剔除赏酥。

由于大量ScheduledFutureTask對象都會存活59秒喳整，這些對象很容易就熬過了幾次young gc，并最終晉升到老年代裸扶，這樣不僅導(dǎo)致了young gc時間變長框都，還導(dǎo)致CMS GC頻次的大幅增加。

那么怎么解決這個問題呢呵晨？筆者在閱讀ScheduledThreadPoolExecutor源碼時發(fā)現(xiàn)其中一個有意思的方法：

ScheduledThreadPoolExecutor源碼

從注釋可以看出魏保，如果把removeOnCancel屬性設(shè)置為true，那么調(diào)用ScheduledFutureTask.cancel方法的同時也會把ScheduledFutureTask從工作隊(duì)列中移除摸屠，從而可以盡快被gc回收掉（removeOnCancel屬性默認(rèn)為false）谓罗。

那么有什么辦法修改reactor-java內(nèi)部創(chuàng)建的ScheduledThreadPoolExecutor的屬性呢？reactor-java已經(jīng)提供了hook給我們季二，只要在適當(dāng)?shù)牡胤剑ū热鐒倖訒r）調(diào)用如下代碼就可以了：

Schedulers.addExecutorServiceDecorator("setRemoveOnCancel", (scheduler, scheduledExecutorService) -> {
?if (scheduledExecutorService instanceof ScheduledThreadPoolExecutor) {? ? ? ? ? ? ? ? ????((ScheduledThreadPoolExecutor)scheduledExecutorService) ????????.setRemoveOnCancelPolicy(true); }
?return scheduledExecutorService;
});

最后拋出個問題留給讀者自己思考：為什么升級前不會有這個問題呢檩咱？讀者可自行閱讀源碼研究一下。

后續(xù)：筆者順便看了下另一款框架RxJava的實(shí)現(xiàn)戒傻，其內(nèi)部創(chuàng)建的ScheduledThreadPoolExecutor默認(rèn)都是把removeOnCancel設(shè)置為true的税手，筆者個人覺得這算是一個問題蜂筹，故給reactor-java提交了一個PR：https://github.com/reactor/reactor-core/pull/1674