分享一次排查CLOSE_WAIT过多的经验 - 踩刀诗人 - 博客园

标签: | 发表时间:2021-04-08 11:34 | 作者:
出处:https://www.cnblogs.com

关键词:TCP、CLOSE_WAIT

 

问题背景

某日下午有测试人员急匆匆的跑来跟我反馈:“有客户反馈供应商附件预览不了,流程阻塞,需要紧急处理”,我立马精神起来,毕竟都是付费客户 目前做B端业务,客户都是付费用户,不像C端,出了问题发个道歉声明也就过去了)

 

等她说完,我第一时间用测试账号登上去验证,浏览器一直在转圈,差不多一分钟以后出了nginx的504错误页。

 

 

 

初步排查

也许有人对504这个错误码不熟悉,这里借用百度百科的内容简单介绍下这个错误码。

 

504 Gateway Timeout

作为网关或者代理工作的服务器尝试执行请求时,未能及时从上游服务器(URI标识出的服务器,例如HTTP、FTP、LDAP)或者辅助服务器(例如DNS)收到响应。

                                                                                                             ( 内容来源于百度百科)

 

看到这个错误码第一反应就是下游服务太慢,导致nginx请求超时了,这里的下游服务是自研的附件预览服务,采用SpringBoot开发,整体的请求链路如下图所示:

 

 

在线预览的处理流程如下:

1.用户在业务方站点发起预览请求;

2.业务方拼接相关参数重定向到预览服务;

3.预览服务通过业务方传递的附件链接调用业务方接口下载附件到本地;

4.预览服务将下载的附件转换成html供用户在线预览;

 

结合上面的处理流程和请求链路,初步得到以下两点猜测:

1.预览服务调用业务方下载接口过慢;

2.预览服务本身处理过慢;

 

带着这两点猜测我立马去查看日志,结果却大跌眼镜,从昨天14点以后就没有日志输出了。

请求进不来了?假死?挂了?

我首先确认进程是否存在,进程跑的好好的,为什么会没有请求呢,我第一反应是业务代码有问题,导致线程被hang占满了tomcat的线程池,所以立即使用jstack查看线程情况,意外的是一切正常,线程数不多,更没有发现死锁、socket read0等可能导致线程hang住的情况。

 

自身没问题,难道是被其他任务影响了,我继续使用top查看系统负载、cpu占用等情况

 

 显而易见,负载、cpu占用都不高,似乎陷入了僵局。

 

 我猜测可能不是业务代码的问题,需要跳出业务代码去查问题,既然没有请求,那就先从网络开始查起。

 

渐入佳境

先确认下服务端监听端口是不是正常。

第一步:netstat 查看网络状态

netstat -aonp
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name     Timer
tcp       81      0 0.0.0.0:8080            0.0.0.0:*               LISTEN      1/java               off (0.00/0/0)
tcp        0      0 127.0.0.1:8100          0.0.0.0:*               LISTEN      24/soffice.bin       off (0.00/0/0)
tcp      936      0 172.20.4.203:8080       172.20.5.59:40576       CLOSE_WAIT  -                    off (0.00/0/0)
tcp      867      0 172.20.4.203:8080       172.20.4.172:57166      CLOSE_WAIT  -                    off (0.00/0/0)
tcp      964      0 172.20.4.203:8080       172.20.5.59:50106       CLOSE_WAIT  -                    off (0.00/0/0)
tcp     1701      0 172.20.4.203:8080       172.20.4.172:45428      CLOSE_WAIT  -                    off (0.00/0/0)
tcp     1169      0 172.20.4.203:8080       172.20.4.172:61582      CLOSE_WAIT  -                    off (0.00/0/0)
tcp      963      0 172.20.4.203:8080       172.20.4.172:64474      CLOSE_WAIT  -                    off (0.00/0/0)
tcp     1058      0 172.20.4.203:8080       172.20.5.59:44564       CLOSE_WAIT  -                    off (0.00/0/0)
tcp      962      0 172.20.4.203:8080       172.20.4.172:64160      CLOSE_WAIT  -                    off (0.00/0/0)
tcp     1733      0 172.20.4.203:8080       172.20.4.172:46810      CLOSE_WAIT  -                    off (0.00/0/0)
tcp     1587      0 172.20.4.203:8080       172.20.5.59:40032       CLOSE_WAIT  -                    off (0.00/0/0)
tcp      994      0 172.20.4.203:8080       172.20.4.172:47474      CLOSE_WAIT  -                    off (0.00/0/0)
tcp      867      0 172.20.4.203:8080       172.20.5.59:47134       CLOSE_WAIT  -                    off (0.00/0/0)
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
CLOSE_WAIT 103
ESTABLISHED 2

  

从输出结果中可以确认预览服务的监听端口(8080)虽然是存活的,但有大量的CLOSE_WAIT出现,这显然是不正常的,难道是CLOSE_WAIT过多导致超过了文件描述符的限制,但是我在日志中没有找到“Too manay open files”,这个猜想随之破灭,有没有可能是tcp队列溢出了?

  linux中一切皆文件,ServerSocket每次accept一个socket意味着需要开启一个文件描述符,这个数量并不是无限的,系统中有限制,如果超过限制了就会报Too manay open files。

第二步:查看tcp队列是否溢出

netstat -s | egrep "listen|LISTEN" 
    243 times the listen queue of a socket overflowed
    243 SYNs to LISTEN sockets dropped

  

上面看到的 243 times ,表示全连接队列溢出的次数,隔一阵刷新一下,发现这个数字还在涨。

既然tcp队列有溢出,自然是有部分请求到不了预览服务了,在tcp层就被扔了,但是从昨天14点到现在一点日志也没有,难道都被扔了,继续确认当前tcp队列的情况。

关于tcp队列的知识,这里推荐去阅读淘宝技术团队写的一篇文章,通俗易懂。 http://jm.taobao.org/2017/05/25/525-1/

 

第三步:查看tcp队列当前情况

ss -lnt
State       Recv-Q Send-Q                                                                                           Local Address:Port                                                                                                          Peer Address:Port              
LISTEN      101    100

  

Recv-Q代表当前全连接队列的大小,也就是三次握手完成,目前在全连接队列中等待被应用程序accept的socket个数。

Send-Q代表全连接队列的最大值,应用程序可以在创建ServerSocket的时候指定,tomcat默认为100,但是这个值不能超过系统的/proc/sys/net/core/somaxconn,看看jdk中关于这个值的解释,专业名词叫backlog。

The maximum queue length for incoming connection indications (a
   request to connect) is set to the {@code backlog} parameter. If
   a connection indication arrives when the queue is full, the
     connection is refused.
 
 public ServerSocket(int port, int backlog) throws IOException {
        this(port, backlog, null);
 }

  

从上面的输出可以发现Recv-Q已经大于Send-Q,而且这个数量长时间不变,可以得出两个结论:

1.部分socket一直堆积在队列中没有被accept;

2.由于tcp全连接队列已满,所以新的socket自然是进不来了。

至此可以初步解释为什么从昨天14点开始就一直没有请求进来了。

 

深入分析

截止现在可以确定是由于tcp队列满导致一直没有请求进来,但tcp队列怎么能从昨天14点一直满到现在呢,jstack查看当前线程并没有什么异常、top查看系统负载、cpu都不高,是什么让tomcat不去tcp队列中accept新的socket呢?

 

另一方面,通过tcp队列满这个现象也可以分析出为什么那么多的CLOSE_WAIT,因为socket在tcp的队列中一直堆积着,还没等到应用程序处理呢,就达到了nginx的超时时间,nginx主动关闭了连接,这里贴一张经典的四次握手的图。

 

 左边的Initiator(发起者)就是nginx,右边的Receiver(接受者)就是tomcat,nginx和tomcat通过三次握手已经建立了tcp连接,此时连接暂存在全连接队列中,等待着tomcat去accept,但是tomcat迟迟不accept,一分钟过后,nginx等不住了,主动发起了FIN开始关闭连接,此时tomcat侧的tcp连接就处在CLOSE_WAIT状态,理论上来讲,tomcat收到nginx的FIN接着就应该close socket,CLOSE_WAIT状态不会持续太久,难道是tomcat出bug了,没有响应?

 

截止现在有两个疑问:

1.为什么tomcat不去tcp队列中accept新的socket呢?

2.为什么tomcat不响应nginx的关闭socket请求呢?

 

我们先看第一个疑问 “为什么tomcat不去tcp队列中accept新的socket呢?”

要揭开这个疑问我们先看一张图来感受下TCP握手过程中建连接的流程和队列

 

 ( 图片来源于https://tech.ebayinc.com/engineering/a-vip-connection-timeout-issue-caused-by-snat-and-tcp-tw-recycle/)

 

接下来的任务就是搞清楚tomcat是如何处理上图中的accept逻辑的,我之前看过一部分tomcat源码,所以这里直接抛个答案出来吧,就不延伸了,tomcat是通过一个单独的Acceptor线程去accept socket的,accept之后扔给IO多路复用模块进行后续的业务处理,在这里只需要关注处理accept那段逻辑就好,贴一下源码:

protected class Acceptor extends AbstractEndpoint.Acceptor {

        @Override
        public void run() {

            int errorDelay = 0;

            // Loop until we receive a shutdown command
            while (running) {

                // Loop if endpoint is paused
                while (paused && running) {
                    state = AcceptorState.PAUSED;
                    try {
                        Thread.sleep(50);
                    } catch (InterruptedException e) {
                        // Ignore
                    }
                }

                if (!running) {
                    break;
                }
                state = AcceptorState.RUNNING;

                try {
                    //if we have reached max connections, wait
                    countUpOrAwaitConnection();

                    SocketChannel socket = null;
                    try {
                        // Accept the next incoming connection from the server
                        // socket
                        socket = serverSock.accept();
                    } catch (IOException ioe) {
                        // We didn't get a socket
                        countDownConnection();
                        if (running) {
                            // Introduce delay if necessary
                            errorDelay = handleExceptionWithDelay(errorDelay);
                            // re-throw
                            throw ioe;
                        } else {
                            break;
                        }
                    }
                    // Successful accept, reset the error delay
                    errorDelay = 0;
                    // Configure the socket
                    if (running && !paused) {
                        // setSocketOptions() will hand the socket off to
                        // an appropriate processor if successful
                        if (!setSocketOptions(socket)) {
                            closeSocket(socket);
                        }
                    } else {
                        closeSocket(socket);
                    }
                } catch (Throwable t) {
                    ExceptionUtils.handleThrowable(t);
                    log.error(sm.getString("endpoint.accept.fail"), t);
                }
            }
            state = AcceptorState.ENDED;
        }

  

逻辑比较简单,就是一直从ServerSocket中accept socket然后扔给IO多路复用模块,重点关注下60行, ExceptionUtils.handleThrowable(t)。

如果accept过程中抛了一个异常会怎样?接着看下ExceptionUtils.handleThrowable(t)的处理逻辑:

/**
     * Checks whether the supplied Throwable is one that needs to be
     * rethrown and swallows all others.
     * @param t the Throwable to check
     */
    public static void handleThrowable(Throwable t) {
        if (t instanceof ThreadDeath) {
            throw (ThreadDeath) t;
        }
        if (t instanceof StackOverflowError) {
            // Swallow silently - it should be recoverable
            return;
        }
        if (t instanceof VirtualMachineError) {
            throw (VirtualMachineError) t;
        }
        // All other instances of Throwable will be silently swallowed
    }

  

如果是ThreadDeath和VirtualMachineError这两类异常就继续往上抛了,抛出去意味着什么呢?

 思考三秒钟

 

 

 如果继续往上抛说明Acceptor线程意外退出运行,自然就不会去tcp队列中accept连接,队列不堆积才怪呢,想到这儿我立马去翻一下预览服务的日志,看会不会有什么发现,其中有一条日志引起了我的关注。

Exception in thread "http-nio-8080-Acceptor" java.lang.OutOfMemoryError: Java heap space

  

"http-nio-8080-Acceptor" 正是Acceptor线程的名字,说明Acceptor抛了一个OutOfMemoryError。

OutOfMemoryError和Acceptor退出有什么关系呢,想想前面提到的handleThrowable逻辑 “如果是ThreadDeath和VirtualMachineError这两类异常就继续抛出”,这里的OutOfMemoryError正是VirtualMachineError的一个子类。

public class OutOfMemoryError extends VirtualMachineError

到这里可以说真相大白,是因为内存不足导致Acceptor线程在accept的时候抛了OutOfMemoryError,线程直接退出,所以导致大量连接堆积在tcp队列中。

 

其实到这儿第二个疑问“ 为什么tomcat不响应nginx的关闭socket请求呢?”也就很好解释了,因为Acceptor的退出,堆积在tcp队列中的连接tomcat消费不到,自然没有机会去响应nginx的关闭socket请求了,这里留个思考题,如果Acceptor不意外退出,那tomcat在拿到一个处于CLOSE_WAIT状态的连接会怎么处理? 

写在最后

通过一系列的分析最终得出是由于内存不足导致tomct的Acceptor线程异常退出,进而导致连接堆积在tcp队列中无法消费,最终引发了两个问题:

1.新请求一直进不去;

2.大量CLOSE_WAIT状态的连接存在,而且不会消失。

 

也许有人会问究竟是什么导致了内存不足呢,这里简单提一下,之前在提到在线预览处理流程的时候说过,预览服务会将附件转化为html提供给用户在线预览,转化这一步是比较耗内存的,有些客户的附件会达到百兆以上。

 

文中提到了一些非常有用的命令,比如jstack,top,netstat,ss等,之所以没有花太多篇幅去详细解释,一是我对命令的使用经验有限,二是网络上不乏铺天盖地的说明,讲的已经很好。

 

通过这篇文章,只是想分享一种排查此类问题的思路,希望你在遇到相似问题的时候带来些许帮助。

 

推荐阅读

关于TCP 半连接队列和全连接队列 

服务端close-wait或者time-wait状态过多会导致什么样的后果?

PHP升级导致系统负载过高问题分析

浅谈CLOSE_WAIT

 

 

 

相关 [分享 close wait] 推荐:

单条日志过长引发的 CLOSE-WAIT 问题

- - DockOne.io
部分租户称他们的某个业务部署在 Kubernetes 容器平台后经常会重启,部分租户称另一个业务在运行一段时间时会产生大量的 CLOSE-WAIT,还有的就是业务跑着就会 hang 住. 其实这三个问题,经过我们排查后,都是同一个问题引起,这也是我今天要分享的主题内容. 大家都知道,重启我们不好查,因为原因太多了,比如:容器分配的内存不够会重启,运行中程序内存泄漏到将内存耗尽会重启;在 Kubernetes 中配置了容器运行时健康检查时,如果条件未达到会重启等等;总之不好排查.

wait、sleep、yield区别

- - CSDN博客推荐文章
1、属于Object的本地方法. 2、暂停当前线程,并释放锁. 3、调用notify()或notifyAll()方法唤醒线程. 1、Thread类的静态方法. 2、当前线程休眠,但不释放锁. 3、其他线程可以继续执行,无论该线程优先级高与否. 4、休眠一段时间后,自动执行. 1、Thread类的静态方法.

Java多线程之wait()和notify()

- - CSDN博客推荐文章
直接看测试代码吧,细节之处,详见注释.  * Java多线程之wait()和notify()的妙用 .  * @see 问题:同时启动两个线程和同时启动四个线程,控制台打印结果是不同的 .  * @see      同时启动两个线程时,控制台会很规律的输出1010101010101010 .  * @see      同时启动四个线程时,控制台起初会规律的输出10101010,一旦某一刻输出一个负数,那么后面的输出就会"一错再错" .

java多线程设计wait/notify机制

- - CSDN博客推荐文章
  当线程A获得了obj锁后,发现条件condition不满足,无法继续下一处理,于是线程A就wait() , 放弃对象锁..   之后在另一线程B中,如果B更改了某些条件,使得线程A的condition条件满足了,就可以唤醒线程A:.   # 调用obj的wait(), notify()方法前,必须获得obj锁,也就是必须写在synchronized(obj) {…} 代码段内.

Java多线程之wait和notify

- - ITeye博客
最近在看Java特种兵,看到多线程部分,对wait和notify不是很理解,于是写了代码来帮助理解.              wait方法通过参数可以指定等待的时长. 如果没有指定参数,默认一直等待直到被通知. notify方法是通知某个正在等待这个对象的控制权的线程可以继续运行. 调用wait方法时候,必须加上synchronized同步块,不然会抛出java.lang.IllegalMonitorStateException异常.

Java Sleep() 与 Wait()的机制原理与区别

- - CSDN博客推荐文章
Java中的多线程是一种抢占式的机制而不是分时机制. 线程主要有以下几种状态:可运行,运行,阻塞,死亡. 抢占式机制指的是有多个线程处于可运行状态,但是只有一个线程在运行.        当有多个线程访问共享数据的时候,就需要对线程进行同步.        Thread类的方法:sleep(),yield()等.

[转载]java之yield(),sleep(),wait()区别详解

- - 移动开发 - ITeye博客
使当前线程(即调用该方法的线程)暂停执行一段时间,让其他线程有机会继续执行,但它并不释放对象锁. 也就是说如果有synchronized同步快,其他线程仍然不能访问共享数据. 例如有两个线程同时执行(没有synchronized)一个线程优先级为MAX_PRIORITY,另一个为MIN_PRIORITY,如果没有Sleep()方法,只有高优先级的线程执行完毕后,低优先级的线程才能够执行;但是高优先级的线程sleep(500)后,低优先级就有机会执行了.

最简实例说明wait、notify、notifyAll的使用方法

- - Java - 编程语言 - ITeye博客
wait()、notify()、notifyAll()是三个定义在Object类里的方法,可以用来控制线程的状态. 这三个方法最终调用的都是jvm级的native方法. 随着jvm运行平台的不同可能有些许差异. •如果对象调用了wait方法就会使持有该对象的线程把该对象的控制权交出去,然后处于等待状态.

分享图片

- 糖果 - 变态辣椒的时政漫画

40套MiniIcon分享

- Newton - Booto'Blog
很精美的40套迷你MiniIcon,可能这类型的Icon更多的是运用在App设计和移动客户端上面吧,简约而不简单.