當Tomcat遇上Netty

故事背景

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

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

排查過程

第一步，要日誌

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

LEAK: ByteBuf.release() was not called before it&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壓測觀察，一步是內存洩漏問題排查。

第三步，要代碼

讓分部這個項目的負責人把代碼給到我，我打開一看，傻眼了，就一個簡單的 SpringCloudGateway項目，裡面還包含了兩個類，一個是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( &34;, PlatformDependent.isAndroid() ? &34; : &34;); allocType = allocType.toLowerCase(Locale.US).trim(); ByteBufAllocator alloc; if (&34;.equals(allocType)) { alloc = UnpooledByteBufAllocator.DEFAULT; logger.debug(&34;, allocType); } else if (&34;.equals(allocType)) { alloc = PooledByteBufAllocator.DEFAULT; logger.debug(&34;, allocType); } else { alloc = PooledByteBufAllocator.DEFAULT; logger.debug(&34;, allocType); } DEFAULT_ALLOCATOR = alloc; }}

https://gitee.com/coolcodingonline/sourcecode/raw/master/%E7%94%9F%E4%BA%A7%E9%97%AE%E9%A2%98/resources/jvmunpooled.png 可以看到，是通過 io.netty.allocator.type這個參數控制的。

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

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

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

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

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

@Componentpublic class Metrics { @PostConstruct public void init() { ScheduledExecutorService scheduledExecutorService = Executors.newSingleThreadScheduledExecutor(); scheduledExecutorService.scheduleAtFixedRate(()->{ System.out.println(&34; + PlatformDependent.usedDirectMemory()); }, 1, 1, TimeUnit.SECONDS); }}

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

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

第六步，初步調試

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

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

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

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

第七步，修改配置

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

spring: cloud: gateway: routes: - id: test uri: http://localhost:8899/test predicates: - Path=/test

第八步，再次調試

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

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

果然，內存沒有釋放。

第九步，刪除XssFilter

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

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

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

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

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

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

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

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

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

第十步，幹掉AuthFilter

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

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

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

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

第十一步，思考

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

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

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

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

第十二步，一步一步調試

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

// io.netty.handler.codec.ByteToMessageDecoder.channelRead@Overridepublic void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception { if (msg instanceof ByteBuf) { CodecOutputList out = CodecOutputList.newInstance(); try { first = cumulation == null; // 1. 返回的是msg本身，msg是一個ByteBuf cumulation = 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/4275 numReads = 0; discardSomeReadBytes(); } int size = out.size(); firedChannelRead |= out.insertSinceRecycled(); // 4. 讀取完out中剩餘的值 fireChannelRead(ctx, out, size); // 5. 回收out out.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: 0used direct memory: 0used direct memory: 0used direct memory: 0used direct memory: 0used 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: 0used direct memory: 0used direct memory: 0used direct memory: 0used direct memory: 0used direct memory: 0

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

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

第十六步，發現新大陸

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

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

觀察一下項目啟動日誌：

Connected to the target VM, address: &39;, transport: &39; . ____ _ __ _ _ /\\ / ___&39;_ | &39;_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) &39;'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 { @Override public void run() { if (pending != 0) { ctx.flush(); } }}

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

總結

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

1. 不要輕易懷疑開源框架，特別是像Spring這種用的人比較多的，懷疑它容易把自己帶偏，但也不是不要懷疑哈；
2. 當無法找到問題的原因的時候，可以考慮休息一下、放鬆一下，換個思路；
3. Spring Cloud Gateway中為什麼能tomcat和Netty可以並存，這是一個問題，應該給官方提一個issue，當檢測到兩者同時存在時，直接讓程序起不來不是更好嘛；

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