记一次tomcat报错Too many open files的排查历程

版权声明:本文为博主原创文章,遵循 CC 4.0 by-sa 版权协议,转载请附上原文出处链接和本声明。
本文链接:https://blog.csdn.net/xxxxxx91116/article/details/79011972

本文的技术细节并不具通用性,但是排查的思路过程值得自己mark下,上次遇到这样的刺激线上故障已经是去年3月了~~~这次排查花了3个小时,还算快啦,也算最近的一个小彩蛋。

昨天在公司coding,测试组的同事突然来找我,告知预发环境的系统挂了,请求都是异常,打开业务日志和tomcat的日志排查,满屏的Too many open files,果然 lsof -p pid 预发机器,已经打满到了65535个,很多都是anon_inode pipe FIFO REG,真的不知道这是什么鬼:
image.png
内心一紧,赶紧用lsof -p pid 查看了下线上所有生产机器的文件描述符个数,所幸都在正常范围,这才放下心对预发环境的故障进行排查。

首先保存事故现场,用新端口给qa紧急部署了一个新的环境,nginx转发到新的端口。

接下来就是jstack对堆栈进行检查。jstack的结果是有10个左右的线程处于innative的状态,其他线程都是处于blocked的状态。处于innative状态的线程,有一个明显是tomcat的主线程,有6,7个处于epoll的epoll_wait状态,还有一个是我们开启的内部端口监听,也是wait状态,剩下的数百个blocked线程都在tomcat的quene take的wait状态。我想了想,又谷歌了下,会不会是epoll_wait的bug呢,记得jdk1.6有一个epoll_wait的bug一直没解决。于是定位的天平往jdk bug的方向倾斜,应该是这样想会轻松一点吧。
image.png
image.png

转念一想,如果是epoll_wait的bug,不会导致文件描述符被打满呀。又陷入了焦灼状态。。

接下来开始尝试翻日志,业务日志是看不出什么问题了,但是想起来tomcat报错的时间是下午2点,2点有什么操作么?查看业务日志,2点有刷新缓存的操作,看起来有了一条靠谱的线!

快速搭建了一个测试环境。先lsof一下,大概是400个,刷了一下缓存,变成600个,再刷一下,800个……65535个,问题到这里已经能够复现了,能复现就好办。查到了这里,我给自己泡了一杯普洱茶。
测试了刷新缓存的各个接口,问题基本上已经定位到了刷新通讯缓存,我们作为server端采用mina代码部分的问题,这个时候远程debug就派上了用场。基本上是在怀疑的代码块附近,每debug一步,我就lsof一下文件描述符的个数,终于找到一句可疑的话:

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

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

调试的时候发现,每次执行到 new SimpleIoProcessorPool(NioProcessor.class, availableProcessors +1)) ,文件描述符会增加20,在刷新缓存的时候,会有10次这样的动作,加起来就是180个描述符的增长,基本符合我们观察到的现象.接着谷歌了一下这个类,果然我们的代码里面对mina的使用是不正确的,我们在刷新缓存的时候,对上一次的SimpleIoProcessorPool需要进行卸载。也即,我们需要将SimpleIoProcessorPool记录下来,再调用sessionSimpleIoProcessorPool.dispose();进行卸载。

最后的代码长成这样:

/**

* 停止监听服务

*/

    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();

        }

}

/**

*  启动服务端监听

*

    * @param listener

    * @throws IOException

*/

    public void startup()throws IOException {

CommunicationConfig networkConfig =configs.get(0);

        /* 设置内存获取方式 */

        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连接属性设置,责任链模式,必须在解码器链前面

        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() +"成功!");

    }

所以总结一下,排查线上bug的几个关键点:
1. 尽量保存线上事故现场,不挂掉故障机器,使用nginx等转发到好的机器
2. 仔细查看日志
3. 使用jstack,jmap等打印出堆栈信息
4. 复现故障,通过1-3和代码,逐步剥茧抽丝,找到谜底

jstack\jmap
/proc/pid/目录:
https://www.cnblogs.com/GoodGoodWorkDayDayUp/archive/2011/05/27/2059685.html

展开阅读全文

没有更多推荐了,返回首页