故事背景

嘀~嘀~嘀~，生產事故，內存泄漏！

昨天下午，突然收到運維的消息，分部某系統生產環境內存泄漏了，幫忙排查一下。

排查過程如下：

第一步，要日志

分部給到的異常日志大概是這樣（鑒于公司規定禁止截圖禁止拍照禁止外傳任何信息，下面是我網上找到一張類似的報錯）：

LEAK: ByteBuf.release() was not called before it's garbage-collected. See http://netty.io/wiki/reference-counted-objects.html for more information.Recent access records: #1: io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:273)io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253)io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:646)io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:581)io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:498)io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:460)io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)java.lang.Thread.run(Thread.java:748)

這一看，不得了了，ByteBuf沒有釋放，導致內存泄漏了。

第二步，看內存指標

既然知道了是內存泄漏，趕緊讓運維看下內存使用情況，特別是堆外內存使用情況（因為用了Netty），根據運維反饋，堆內內存使用正常，堆外內存居高不下。

OK，到這里已經可以很明確地斷言：堆外內存泄漏了。

此時，分兩步走，一步是把gateway換成zuul壓測觀察，一步是內存泄漏問題排查。

第三步，要代碼

讓分部這個項目的負責人把代碼給到我，我打開一看，傻眼了，就一個簡單的Spring Cloud Gateway項目，里面還包含了兩個類，一個是AuthFilter用來做權限校驗的，一個是XssFilter用來防攻擊的。

Spring Cloud Gateway使用的是Netty，zuul 1.x使用的是Tomcat，本文來源于工縱耗彤哥讀源碼。

第四步，初步懷疑

快速掃一下各個類的代碼，在XssFilter里面看到了跟ByteBuf相關的代碼，但是，沒有明顯地ByteBuf沒有釋放的信息，很簡單，先把這個類屏蔽掉，看看還有沒有內存泄漏。

但是，怎么檢測有沒有內存泄漏呢？總不能把這個類刪掉，在生產上跑吧。

第五步，參數及監控改造

其實，很簡單，看過Netty源碼的同學，應該比較清楚，Netty默認使用的是池化的直接內存實現的ByteBuf，即PooledDirectByteBuf，所以，為了調試，首先，要把池化這個功能關閉。

直接內存，即堆外內存。

為什么要關閉池化功能？

因為池化是對內存的一種緩存，它一次分配16M內存且不會立即釋放，開啟池化后不便觀察，除非慢慢調試。

那么，怎么關閉池化功能呢？

在Netty中，所有的ByteBuf都是通過一個叫作ByteBufAllocator來創建的，在接口ByteBufAllocator中有一個默認的分配器，找到這個默認的分配器，再找到它創建的地方，就可以看到相關的代碼了。

public interface ByteBufAllocator {ByteBufAllocator DEFAULT = ByteBufUtil.DEFAULT_ALLOCATOR; } public final class ByteBufUtil {static final ByteBufAllocator DEFAULT_ALLOCATOR;static {// 本文來源于工縱耗彤哥讀源碼String allocType = SystemPropertyUtil.get("io.netty.allocator.type", PlatformDependent.isAndroid() ? "unpooled" : "pooled");allocType = allocType.toLowerCase(Locale.US).trim();ByteBufAllocator alloc;if ("unpooled".equals(allocType)) {alloc = UnpooledByteBufAllocator.DEFAULT;logger.debug("-Dio.netty.allocator.type: {}", allocType);} else if ("pooled".equals(allocType)) {alloc = PooledByteBufAllocator.DEFAULT;logger.debug("-Dio.netty.allocator.type: {}", allocType);} else {alloc = PooledByteBufAllocator.DEFAULT;logger.debug("-Dio.netty.allocator.type: pooled (unknown: {})", allocType);}DEFAULT_ALLOCATOR = alloc;}}

可以看到，是通過io.netty.allocator.type這個參數控制的。

OK，在JVM啟動參數中添加上這個參數，并把它賦值為unpooled。

關閉了池化功能之后，還要能夠實時地觀測到內存是不是真的有泄漏，這要怎么做呢？

其實，這個也很簡單，Netty的PlatformDependent這個類會統計所有直接內存的使用。

最近一直在研究Netty的源碼，所以，我對Netty的各種細節了解地很清楚，本文來源于工縱耗彤哥讀源碼，最近還在準備，等后面弄完了，開始Netty專欄的創作。

所以，我們只需要寫一個定時器，定時地把這個統計信息打印出來就可以了，這里，我就直接給出代碼了：

@Component public class Metrics {@PostConstructpublic void init() {ScheduledExecutorService scheduledExecutorService = Executors.newSingleThreadScheduledExecutor();scheduledExecutorService.scheduleAtFixedRate(()->{System.out.println("used direct memory: " + PlatformDependent.usedDirectMemory());}, 1, 1, TimeUnit.SECONDS);} }

把它扔到跟啟動類同級或下級的目錄就可以了。

到這里，池化及監控都弄好了，下面就是調試了。

第六步，初步調試

直接運行啟動類，觀察日志。

used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0

一開始，直接內存都很正常，一直是0。

隨便發送一個請求，報404了，而且觀察直接內存并沒有變化，還是0，說明，隨便模擬一個請求還不行，這直接被spring給攔截了，還沒到Netty。

第七步，修改配置

隨便一個請求不行， 那只能模擬正常的請求轉發了，我快速啟動了一個SpringBoot項目，并在里面定義了一個請求，修改gateway的配置，讓它可以轉發過去：

spring:cloud:gateway:routes:- id: testuri: http://localhost:8899/testpredicates:- Path=/test

第八步，再次調試

修改完配置，同時啟動兩個項目，一個gateway，一個springboot，請求發送，觀察直接內存的使用情況：

used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 1031 used direct memory: 1031 used direct memory: 1031

果然，內存沒有釋放。

第九步，刪除XssFilter

為了驗證前面初步懷疑的XssFilter，把它刪掉，再次啟動項目，發送請求，觀察直接內存的使用。

used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 1031 used direct memory: 1031 used direct memory: 1031

問題依然存在，而且，還是跟前面泄漏的一樣大小。

這個是這樣的，Netty是靠猜（guess）來決定每次內存分配的大小的，這個猜的初始值是1024。

@Override public ByteBuf allocate(ByteBufAllocator alloc) {return alloc.ioBuffer(guess()); }

是不是沒想到Netty還有這么可愛的一面^^，咳咳，跑題了，強行拉回！

然后，這里還有個7B存儲的是換行符回車符啥的，這7B是不會釋放的，加到一起就是1031。

private static final byte[] ZERO_CRLF_CRLF = { '0', CR, LF, CR, LF }; // 2B private static final ByteBuf CRLF_BUF = unreleasableBuffer(directBuffer(2).writeByte(CR).writeByte(LF)); // 5B private static final ByteBuf ZERO_CRLF_CRLF_BUF = unreleasableBuffer(directBuffer(ZERO_CRLF_CRLF.length).writeBytes(ZERO_CRLF_CRLF));

嗯，有點意思，既然不是XssFilter的問題，那么，會不會是AuthFilter的問題呢？

第十步，干掉AuthFilter

說干就干，干掉AuthFiler，重啟項目，發送請求，觀察直接內存：

used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 1031 used direct memory: 1031 used direct memory: 1031

問題還是存在，還是熟悉的內存大小。

此時，我的思路已經不順暢了，下面是跑偏之路。

第十一步，思考

在把XssFilter和AuthFilter相繼刪除之后，已經只剩下一個啟動類了，當然，還有一個新加的監控類。

難道是Spring Cloud Gateway本身有問題，咦，我好像發現了新大陸，這要是發現Spring Cloud Gateway有問題，以后又能吹噓一番了（內心YY）。

既然，內存分配沒有釋放，那我們就找到內存分配的地方，打個斷點。

通過前面的分析，我們已經知道使用的內存分配器是UnpooledByteBufAllocator了，那就在它的newDirectBuffer()方法中打一個斷點，因為我們這里是直接內存泄漏了。

第十二步，一步一步調試

按照第十一步的思路，在UnpooledByteBufAllocator的newDirectBuffer()方法中打一個斷點，一步一步調試，最后，來到了這個方法：

// io.netty.handler.codec.ByteToMessageDecoder.channelRead @Override public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {if (msg instanceof ByteBuf) {CodecOutputList out = CodecOutputList.newInstance();try {first = cumulation == null;// 1. 返回的是msg本身，msg是一個ByteBufcumulation = cumulator.cumulate(ctx.alloc(),first ? Unpooled.EMPTY_BUFFER : cumulation, (ByteBuf) msg);// 2. 解碼，本文來源于工縱耗彤哥讀源碼callDecode(ctx, cumulation, out);} catch (DecoderException e) {throw e;} catch (Exception e) {throw new DecoderException(e);} finally {if (cumulation != null && !cumulation.isReadable()) {numReads = 0;// 3. 釋放內存cumulation.release();cumulation = null;} else if (++ numReads >= discardAfterReads) {// We did enough reads already try to discard some bytes so we not risk to see a OOME.// See https://github.com/netty/netty/issues/4275numReads = 0;discardSomeReadBytes();}int size = out.size();firedChannelRead |= out.insertSinceRecycled();// 4. 讀取完out中剩余的值fireChannelRead(ctx, out, size);// 5. 回收outout.recycle();}} else {ctx.fireChannelRead(msg);} }

這中間花了好幾個小時，特別是ChannelPipeLine里面一不小心就跳過去了，又得重新來過，真的是只能一步一步來。

這個方法主要是用來把ByteBuf轉換成Message，Message就是消息，可以理解為簡單的Java對象，主要邏輯在上面的代碼中都標示出來了。

可以看到，這里有個cumulation.release();，它就是釋放內存的地方，但是，并沒有釋放掉，在調用這行代碼之前，msg(=cumulation)的引用計數是4，釋放之后是2，所以，還有計數，無法回收。

走完下面的4、5兩步，out都回收了，msg還是沒有被回收，問題肯定是出在這一塊。

一直在這里糾結，包括decode里面的代碼都反反復復看了好多遍，這里沒有釋放的msg里面的內容轉換之后的對象是DefaultHttpContent，它表示的是Http請求的body，不過這里是Http請求返回值的body。

這也是讓我很迷惑的一點，我試了，Http請求的body好像沒有走到這塊邏輯，又反反復復地找Http請求的Body，搞了好久，一直沒有進展。

到晚上9點多的時候，辦公室已經沒什么人了，燈也關了（疫情期間，每個部門每天只能去幾個人），我也收拾下回家了。

第十三步，打車回家

在車上的時候，一直在想這個問題，回憶整個過程，會不會是我的方向錯了呢？

Spring Cloud Gateway出來也挺久了，沒聽說有內存泄漏的問題啊，此時，我開始自我懷疑了。

不行，我回家得自己寫一個項目，使用Spring Cloud Gateway跑一下試試。

第十四步，寫一個使用Spring Cloud Gateway的項目

到家了，趕緊打開電腦，動手寫了一個使用Spring Cloud Gateway的項目和一個SpringBoot的項目，把監控打開，把池化功能去掉，啟動項目，發送請求，觀察直接內存。

used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0

納尼，阿西巴，到這里，已經很明確了，不是Spring Cloud Gateway的問題，那是什么問題呢？

肯定是使用的姿勢不對，不過公司那個項目，也沒有別的什么東西了，類都被我刪完了，只剩下啟動類了。

哎不對，pom文件。

打開跳板機，登錄到公司電腦，查看pom.xml，發現里面都是SpringBoot或者SpringCloud本身的一些引用。

嗯，不對，有個common包，分部自己寫的common包，點進去，里面引用了三個jar包，其中，有一個特別扎眼，tomcat！！！！

哎喲我次奧，此時，我真的想罵娘，這都什么事兒~~

其實，我在刪除AuthFilter的時候就應該想到pom的問題的，當時，只顧著YY Spring Cloud Gateway 可能有bug的問題了，一頭就扎進去了。

我們知道，Spring Cloud Gateway使用的是Netty做為服務端接收請求，然后再轉發給下游系統，這里引用tomcat會怎樣呢？還真是一件有趣的事呢。

第十五步，干掉tomcat

在pom文件中，把tomcat的jar包排除掉，重啟項目，發送請求，觀察直接內存：

used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0 used direct memory: 0

哦了，沒有問題了，就是tomcat搗的鬼。

那么，tomcat是怎么搗鬼的呢？加了tomcat也能正常的響應請求，請求也能正常的轉發，返回給客戶端，而且，更可怕的是，內部也確實是使用了Netty進行請求的讀寫響應，真的有點神奇。

第十六步，發現新大陸

為了驗證這個問題，我們還是先退出跳板機，回到我自己的電腦，在pom中加入tomcat，啟動項目，咦，確實能起得來，好好玩兒~~

難道是tomcat和Netty同時監聽了同一個端口，兩者都起來了？

觀察一下項目啟動日志：

Connected to the target VM, address: '127.0.0.1:52162', transport: 'socket'. ____ _ __ _ _/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \\\/ ___)| |_)| | | | | || (_| | ) ) ) )' |____| .__|_| |_|_| |_\__, | / / / /=========|_|==============|___/=/_/_/_/:: Spring Boot :: (v2.2.6.RELEASE)2020-05-19 08:50:04.448 INFO 7896 --- [ main] com.alan.test.Application : No active profile set, falling back to default profiles: default 2020-05-19 08:50:04.829 INFO 7896 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=082e67ca-d4c7-3a8c-b051-e806722fd225 2020-05-19 08:50:04.998 INFO 7896 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http) 2020-05-19 08:50:05.006 INFO 7896 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2020-05-19 08:50:05.006 INFO 7896 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.33] 2020-05-19 08:50:05.859 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [After] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Before] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Between] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Cookie] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Header] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Host] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Method] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Path] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [Query] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [ReadBodyPredicateFactory] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [RemoteAddr] 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : 本文來源于工縱耗彤哥讀源碼 2020-05-19 08:50:05.860 INFO 7896 --- [ main] o.s.c.g.r.RouteDefinitionRouteLocator : Loaded RoutePredicateFactory [CloudFoundryRouteService] 2020-05-19 08:50:06.731 INFO 7896 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2020-05-19 08:50:07.304 INFO 7896 --- [ main] com.alan.test.Application : Started Application in 4.271 seconds (JVM running for 5.0)

發現確實只啟動了tomcat，那它是怎么把請求移交給Netty來處理的呢？

第十七步，tomcat -> Netty

學習過NIO相關知識的同學應該知道，NIO將SocketChannel分成了兩種，一種是ServerSocketChannel，一種是SocketChannel，其中，ServerSocketChannel是服務啟動的時候創建的，用來監聽客戶端連接的到來，而SocketChannel就表示客戶端與服務端之間的連接。

看過NIO源碼的同學又知道，SocketChannel是通過ServerSocketChannel創建出來的。

看過Netty源碼的同學又知道，Netty根據不同的協議又把這些Channel分成了NioXxxChannel、EpollXxxChannel等等，針對每一種協議的Channel同樣分成NioServerSocketChannel、NioSocketChannel等。

而在Windows平臺下，默認使用的是NioXxxChannel，而從上可知，NioSocketChannel應該是通過NioServerSocketChannel創建出來的，如果是正常使用Netty，也確實是這樣的。

下圖是正常使用Netty時NioSocketChannel創建時的線程棧：

?

不過，我們現在的場景是 tomcat + Netty，那又是怎樣的呢？

此時，在NioSocketChannel的構造方法中打一個斷點，發送一個請求，發現斷點到了NioSocketChannel的構造方法中，觀察線程棧的情況（從下往上看）：

?

?

可以看到，經過tomcat->spring->reactor->reactor-netty->netty，千轉百回之后，終于創建了NioSocketChannel。

這里的情況就有點復雜了，后面有時間，我們再詳細分析。

第十八步，內存泄漏

從上面可以看出，Tomcat最終把請求的處理交給了Netty，但是為什么會內存泄漏呢？這依然是個問題。

經過我的對比檢測，問題還是出在第十二步的代碼那里，在使用正常的Netty請求時，在fireChannelRead()的里面會往NioEventLoop中添加一個任務，叫作MonoSendMany.SendManyInner.AsyncFlush:

final class AsyncFlush implements Runnable {@Overridepublic void run() {if (pending != 0) {ctx.flush();}} }

這是用來把寫緩沖區的數據真正寫出去的（讀完了寫出去），同時，也會把寫緩沖區的數據清理掉，也就是調用了這個方法客戶端才能收到響應的結果，而使用 tomcat + Netty 的時候，并沒有執行這個任務，數據就發送給了客戶端（猜測可能是通過tomcat的連接而不NioSocketChannel本身發送出去的），這是一個遺留問題，等后面再研究下了，現在腦子有點凌亂。

總結

這次生產事件，雖然整個代碼比較簡單，但是還是搞了挺久的，現總結幾個點：

不要輕易懷疑開源框架，特別是像Spring這種用的人比較多的，懷疑它容易把自己帶偏，但也不是不要懷疑哈；

當無法找到問題的原因的時候，可以考慮休息一下、放松一下，換個思路；

Spring Cloud Gateway中為什么能tomcat和Netty可以并存，這是一個問題，應該給官方提一個issue，當檢測到兩者同時存在時，直接讓程序起不來不是更好嘛；

目前在準備Netty專欄，老鐵們等著我。

作者：彤哥讀源碼

鏈接：https://juejin.im/post/5ec358f0f265da498e6f007b

來源：掘金

總結

以上是生活随笔為你收集整理的当Tomcat遇上Netty，我这一系列神操作，同事看了拍手叫绝的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。