问题一_系统响应异常
问题现象
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线程线程
- 场景1：单个请求；内存溢出，报错，但线程运行正常；下一个请求正常受理；
原因
内存溢出，导致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.register
- 获取socket连接。NioEndPoint.serverSocketAccept()
-
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))
- processSocket
- 调用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
