夏有清风

最是清風明月知人意,涼爽了整個如詩的夏夜

Open Source, Open Mind,
Open Sight, Open Future!
  menu
7 文章
12547 浏览
0 当前访客
ღゝ◡╹)ノ❤️

服务器进程泄露故障排查

事件起因

2019年06月25日,例常进行服务器检查,发现使用prod账户无法登陆服务器,切换root账户可以登陆。
从服务器多个prod用户下的服务应用日志中观察到,今日凌晨起有间歇性的本地线程无法创建异常。

java.lang.OutOfMemoryError: unable to create new native thread

期间可能有其他线程资源被释放,导致服务勉强可用。
今日10:50左右,服务器prod用户进程数被完全耗尽,最终导致:

  1. prod ssh登录bash进程无法被创建。
  2. 因为文件数未满,HTTP网络请求连接TCP连接可创建,但进程数已满,无法fork进程,所有请求最终会被阻塞,直到超时。
    由上述检测,初步推断为prod账户的创建文件数目达到linux下的配置上限

排查过程

使用 ps h -Led -o user | sort | uniq -c | sort -n 命令查看当前所有用户的进程数,发现prod账户下出现异常。
使用 ps -o nlwp,pid,lwp,args -u prod | sort -n 命令查看prod用户开启进程的分布情况,发现某JAVA服务的进程数出现异常。
进行code review,发现程序中有如下代码:

public void function {
    ExecutorService executor = Executors.newFixedThreadPool(4);
    ...
}

每次该函数被调用,系统会创建1个包含4个线程的线程池。在函数调用结束后,executor对象(线程池)本身会被JVM回收,但是,HotSpot的GC机制针对的是内存管理,并不负责如File、Scoket、Thread之类资源的回收,实际上4个线程在完成各自的任务之后,函数栈被弹出,只留下了比较浅的栈。此时线程一直在后台等待,从而造成了线程泄露。
泄露线程的堆栈信息如下:

"pool-757-thread-4" #74446 prio=5 os_prio=0 tid=0x0000000002b58800 nid=0x31ad waiting on condition [0x00007ff98e964000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000006d69610d0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

该函数每天会被调用几十次,数十天后,后台累积泄露线程数达到了3500+,加上其他服务的进程,达到了linux用户默认的进程数上限值4096。
通过 ps -Tf -p {pid} | wc -l 命令可以统计一个进程的线程数。如果常规的web服务超过100,可能就需要检查一下线程的使用是否合理了。

相关解释

  1. linux一切皆文件,比如socket,文件句柄,进程等都被视作文件,受到用户打开文件数限制。使用 lsof -p {pid} 命令以查看一个进程打开的文件。使用 ulimit -n 命令可以查看当前用户的文件数限制,默认为65535。
  2. linux内核中,线程被实现为一种特殊的进程,因此一般提到进程数,包括线程。可以使用 ps -Tf -u {uid | username} 命令查看用户打开的线程。使用 ulimit -u 命令查看当前用户的进程限制,默认为4096。
  3. Apollo是双向通信机制,Server端向Client端的HTTP请求被阻塞,会持续发送,造成请求堆积,所以会看到Grafna监控图表上,TCP_alloc、TCP_inuse同步线性增长;并且当HTTP超时后,会主动关闭TCP连接,app10作为TCP连接的被动关闭方,TCP连接会处于CLOSE_WAIT状态,这与lsof输出看到的大量CLOSE_WAIT状态连接相符。