本文的技術(shù)細(xì)節(jié)并不具通用性，但是排查的思路過程值得自己mark下，上次遇到這樣的刺激線上故障已經(jīng)是今年3月了～～～這次排查花了3個小時，還算快啦，也算最近的一個小彩蛋。

昨天在公司coding，測試組的同事突然來找我，告知預(yù)發(fā)環(huán)境的系統(tǒng)掛了，請求都是異常，打開業(yè)務(wù)日志和tomcat的日志排查，滿屏的Too many open files，果然 lsof -p pid 預(yù)發(fā)機(jī)器，已經(jīng)打滿到了65535個，很多都是anon_inode pipe FIFO REG，真的不知道這是什么鬼：

image.png

內(nèi)心一緊，趕緊用lsof -p pid 查看了下線上所有生產(chǎn)機(jī)器的文件描述符個數(shù)，所幸都在正常范圍，這才放下心對預(yù)發(fā)環(huán)境的故障進(jìn)行排查。

首先保存事故現(xiàn)場，用新端口給qa緊急部署了一個新的環(huán)境，nginx轉(zhuǎn)發(fā)到新的端口。

接下來就是jstack對堆棧進(jìn)行檢查。jstack的結(jié)果是有10個左右的線程處于innative的狀態(tài)，其他線程都是處于blocked的狀態(tài)。處于innative狀態(tài)的線程，有一個明顯是tomcat的主線程，有6，7個處于epoll的epoll_wait狀態(tài)，還有一個是我們開啟的內(nèi)部端口監(jiān)聽，也是wait狀態(tài)，剩下的數(shù)百個blocked線程都在tomcat的quene take的wait狀態(tài)。我想了想，又谷歌了下，會不會是epoll_wait的bug呢，記得jdk1.6有一個epoll_wait的bug一直沒解決。于是定位的天平往jdk bug的方向傾斜，應(yīng)該是這樣想會輕松一點吧。

image.png

image.png

轉(zhuǎn)念一想，如果是epoll_wait的bug，不會導(dǎo)致文件描述符被打滿呀。又陷入了焦灼狀態(tài)。。

接下來開始嘗試翻日志，業(yè)務(wù)日志是看不出什么問題了，但是想起來tomcat報錯的時間是下午2點，2點有什么操作么？查看業(yè)務(wù)日志，2點有刷新緩存的操作，看起來有了一條靠譜的線！

快速搭建了一個測試環(huán)境。先lsof一下，大概是400個，刷了一下緩存，變成600個，再刷一下，800個......65535個，問題到這里已經(jīng)能夠復(fù)現(xiàn)了，能復(fù)現(xiàn)就好辦。查到了這里，我給自己泡了一杯普洱茶。
測試了刷新緩存的各個接口，問題基本上已經(jīng)定位到了刷新通訊緩存，我們作為server端采用mina代碼部分的問題，這個時候遠(yuǎn)程debug就派上了用場。基本上是在懷疑的代碼塊附近，每debug一步，我就lsof一下文件描述符的個數(shù)，終于找到一句可疑的話:

acceptor = new NioSocketAcceptor(CommunicationThreadPool.getSeperatorPool(networkConfig),

                new SimpleIoProcessorPool(NioProcessor.class, availableProcessors +1));

調(diào)試的時候發(fā)現(xiàn)，每次執(zhí)行到 new SimpleIoProcessorPool(NioProcessor.class, availableProcessors +1)) ，文件描述符會增加20，在刷新緩存的時候，會有10次這樣的動作，加起來就是180個描述符的增長，基本符合我們觀察到的現(xiàn)象.接著谷歌了一下這個類，果然我們的代碼里面對mina的使用是不正確的，我們在刷新緩存的時候，對上一次的SimpleIoProcessorPool需要進(jìn)行卸載。也即，我們需要將SimpleIoProcessorPool記錄下來，再調(diào)用sessionSimpleIoProcessorPool.dispose();進(jìn)行卸載。

最后的代碼長成這樣：

/**

* 停止監(jiān)聽服務(wù)

*/

    public void dispose() {

if (acceptor !=null) {

acceptor.unbind();

            acceptor.dispose();

            CommunicationConfig networkConfig =configs.get(0);

            LoggerUtil.info(logger, "銷毀channelCode:" + networkConfig.getChannelCode() +"端口:"

                                    + networkConfig.getPort() +"成功！");

        }

if (sessionSimpleIoProcessorPool !=null) {

sessionSimpleIoProcessorPool.dispose();

        }

}

/**

*  啟動服務(wù)端監(jiān)聽

*

    * @param listener

    * @throws IOException

*/

    public void startup()throws IOException {

CommunicationConfig networkConfig =configs.get(0);

        /* 設(shè)置內(nèi)存獲取方式 */

        IoBuffer.allocate(1024, false).setAutoExpand(true);

        int availableProcessors = Runtime.getRuntime().availableProcessors();

        sessionSimpleIoProcessorPool =new SimpleIoProcessorPool(NioProcessor.class, availableProcessors +1);

        acceptor =new NioSocketAcceptor(CommunicationThreadPool.getSeperatorPool(networkConfig),

                sessionSimpleIoProcessorPool);

        // SSL連接屬性設(shè)置,責(zé)任鏈模式，必須在解碼器鏈前面

        initSSLConfig(networkConfig);

        // 初始化Socket接收連接

        initSocketAcceptorConfig(networkConfig);

        acceptor.setReuseAddress(true);

        acceptor.setHandler(TcpServerListenerContext.getListener(ConfigUtil

.getTcpKey(networkConfig)));

        acceptor.bind(new InetSocketAddress(networkConfig.getPort()));

        LoggerUtil.info(logger, "啟動channelCode:" + networkConfig.getChannelCode() +"端口:"

                                + networkConfig.getPort() +"成功！");

    }