Spring Web容器响应异常排查_Poller线程异常退出

问题一_系统响应异常

问题现象

04-11 18点左右客户反馈系统很慢；18点多，反馈pda登录异常；

19:20左右，本地网页登录，某些请求超时；某些正常； 短时间定位后无头绪，保留了stack和dump信息后重启服务，系统恢复正常；

排查思路

• 基于请求链路，排除了nginx的原因；是后端服务的问题；当时出现问题的时候，直接对后端接口进行请求，多数也卡住了。事后查看后台的日志，部分请求有打印，部分无；说明请求尚未到达业务层；于是怀疑http接入有问题；

• 基于nio处理流程，重点分析涉及请求缓存的地方，他们是可能的阻塞点，有两个地方

  • Poller类里面的events队列
  • 业务线程池的queue
    
    

分析过程

stack trace分析

• 业务线程很多是waiting状态，故非业务线程忙碌；而Acceptor和Poller的线程状态也正常；

"http-nio-9999-exec-743" #181220 daemon prio=5 os_prio=0 tid=0x00007f785c00f000 nid=0x5758 waiting on condition [0x00007f763e6f0000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000005c6786808> (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 org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:103)
    at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:31)
    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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"http-nio-9999-Acceptor-0" #216 daemon prio=5 os_prio=0 tid=0x00007f78aee2b000 nid=0xfc runnable [0x00007f76699ab000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
    - locked <0x00000005c67867c0> (a java.lang.Object)
    at org.apache.tomcat.util.net.NioEndpoint.serverSocketAccept(NioEndpoint.java:448)
    at org.apache.tomcat.util.net.NioEndpoint.serverSocketAccept(NioEndpoint.java:70)
    at org.apache.tomcat.util.net.Acceptor.run(Acceptor.java:95)
    at java.lang.Thread.run(Thread.java:748)

"http-nio-9999-ClientPoller-0" #214 daemon prio=5 os_prio=0 tid=0x00007f78af23e000 nid=0xfa runnable [0x00007f7669bad000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x00000005c690fc48> (a sun.nio.ch.Util$3)
    - locked <0x00000005c690fc38> (a java.util.Collections$UnmodifiableSet)
    - locked <0x00000005c690fc58> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:744)
    at java.lang.Thread.run(Thread.java:748)

dump文件分析

• PollerEvent有2k+实例，比较可疑
  

• NioEndpoint里面的poller对象分析

  • 为什么是一个数组，有两个实例
  • events分布极不均匀，pollers[0]里面的events数量只有58个；pollers[1]里面的events数量有2014个；
    

源码分析

• 查看现象的版本为tomcat-embed-core-9.0.13.jar，切到对应版本的源码，发现构造了Poller数组，启动了多个线程；
  

• 查看当时的stack trace，只有一个Poller线程；
  

• 查看线上运行正常应用的stack trace，有两个Poller线程
  

问题原因

有一个Poller线程挂掉了，导致有些请求一直没有处理；表现为有的请求正常，有的不正常；
为什么挂掉了，见下面的继续分析

问题二_Poller线程挂掉

问题现象

见上一个问题的原因。jstack trace里面，有一个Poller线程挂掉了

可疑信息

• 查看当天的日志，看到一个内存溢出；这个是可疑点；从这次内存溢出到上一个问题出现，中间未重启服务
  

分析

• 内存溢出打印的是业务线程，且后面通过jstack查看线程快照，该线程是正常的；可能原因：
  • 线程异常处理机制，往上抛出影响到入口线程（Poller）
  • 内存不够，其他线程业务执行被影响导致异常结束了
• 本地demo复现内存溢出场景，限制jvm内存 （基于tomcat-embed-core:9.0.73版本压测）
  • 场景1：单个请求；内存溢出，报错，但线程运行正常；下一个请求正常受理；
    • 见后面的线程异常处理机制简介，线程未捕获异常，向上抛出，和其他线程隔离，不影响；异常处理后不影响线程的下一次调度
  • 场景2：压测；大量内存溢出错误，线程异常（本次Acceptor和Poller线程均异常退出），无法接受新的请求；查看线程快照，无Acceptor和Poller线程线程
    
    

原因

内存溢出，导致Poller线程异常退出；

相关知识点

spring http请求处理大概过程

tomcat-embed-core-9.0.13.jar

• acceptor处理

  • thread name：http-nio-8080-Acceptor (8080是端口号）
  • 职能：接收新的tcp请求，并将socket连接注册到poller
  • 代码流程（Acceptor#run）
    • 获取socket连接。NioEndPoint.serverSocketAccept()
      • 从serverSock.accept取socket连接
    • 向poller注册socket连接，NioEndpoint.setSocketOptions
      • poller.register
        • 将事件添加到队列（Poller#events）

• poller处理

  • thread name：http-nio-8080-Poller
  • 职能：poller接收acceptor注册的socket连接，对其注册监听事件，读取到信息后，提交给容器的线程池处理
  • 代码流程（Poller#run)
    • 调用events()方法，对队列中所有原始socket去注册事件
    • 调用selector.selectNow()和selector.select()方法监听是否有事件发生（上一步注册的事件）
    • 如果selector检测到有事件发生，调用poller#processKey处理
      • processSocket
        • sc = processorCache.pop();
        • if sc == null , sc = new …;
        • 提交到容器的IO线程池处理（executor.execute(sc))
    • 调用timeout方法，做超时处理如果有

• http 线程池处理

  • thread name: http-nio-8080-x
  • 职能：实际的业务处理，最终会提交到Http11Processor#service，然后分发给Controller层处理

线程异常处理机制简介

说明

Thread出现未捕获的异常时，JVM会调用线程对象的dispatchUncaughtException方法；
未指定exceptionHandler的情况下，会通过threadGroup来处理（直至system group），最终通过控制台输出；

相关代码

Thread#dispatchUncaughtException

线程异常时，会

/**
 * Dispatch an uncaught exception to the handler. This method is
 * intended to be called only by the JVM.
 */
private void dispatchUncaughtException(Throwable e) {
    getUncaughtExceptionHandler().uncaughtException(this, e);
}

/**
 * Returns the handler invoked when this thread abruptly terminates
 * due to an uncaught exception. If this thread has not had an
 * uncaught exception handler explicitly set then this thread's
 * <tt>ThreadGroup</tt> object is returned, unless this thread
 * has terminated, in which case <tt>null</tt> is returned.
 * @since 1.5
 * @return the uncaught exception handler for this thread
 */
public UncaughtExceptionHandler getUncaughtExceptionHandler() {
    return uncaughtExceptionHandler != null ? uncaughtExceptionHandler : group;
}

ThreadGroup#uncaughtException

public void uncaughtException(Thread t, Throwable e) {
if (parent != null) {
parent.uncaughtException(t, e);
} else {
Thread.UncaughtExceptionHandler ueh =
Thread.getDefaultUncaughtExceptionHandler();
if (ueh != null) {
ueh.uncaughtException(t, e);
} else if (!(e instanceof ThreadDeath)) {
System.err.print("Exception in thread “”
+ t.getName() + “” ");
e.printStackTrace(System.err);
}
}
}

参考资料

• tomcat nio：https://cloud.tencent.com/developer/inventory/1620