tomcat的3个线程栈dump样本分析

"朝花夕拾、不留遗憾。念念不忘,必有回响。"

通过通读tomcat请求任务处理、tomcat线程池、TaskQueue、ReentrantLock以及AQS的源码,以及对它们的功能和原理的了解,我们就可以分析tomcat线程dump里边的蛛丝马迹了。

另外关于样本三,由于没有实验重现问题进而证明推断,请多持怀疑态度。

样本一

这个情况很简单,本地启动tomcat以后jstack就可以看到,没太多好讲的,我们快速过一遍。

"http-nio-8081-exec-27" #42 daemon prio=1 os_prio=-2 tid=0x000000001a549000 nid=0x4a70 waiting on condition [0x000000001dc0f000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000008144aab0> (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:107)
	at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:58)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"http-nio-8081-exec-xx"这样的线程有10个,是线程池coreSize的大小。看上面的几个关键地方,TaskQueue.take这是一个无超时阻塞,从任务队列里出队,线程数少于核心线程Size的时候,用take方法出队。

往上看此时take阻塞在ConditionObject.await其内部是使用的LockSupport.park实现的阻塞。源码里可以看到这个Condition是notEmpty,也就是当前队列是空的,核心线程都等待notEmpty这个条件满足,然后竞争任务队列里的takeLock(ReentrantLock非公平锁,基于AQS排他模式实现),拿到锁之后拿任务出队然后执行。

样本二

这种情况发生在业务高峰过后,正常情况应该会释放部分空闲线程,进入一个平衡点,或者在业务极少的时候比如半夜会进入样本一状态。

"http-nio-8081-exec-162" #177 daemon prio=1 os_prio=-2 tid=0x000000001bbec000 nid=0x2580 waiting on condition [0x00000000272df000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000008144aab0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
	at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
	at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:89)
	at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:1)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:58)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

简单提两句,LinkedBlockingQueue.poll我们知道线程数大于coreSize的时候,任务队列出队会用poll而不是take,接下来ConditionObject.awaitNanos我们去看一下TaskQueue和LinkedBlockingQueue的源码也会知道这还是阻塞在notEmpty条件上、只不过这次是超时阻塞,也就是说线程池设置的keepalive最大空闲时间之内没有被使用的话,该线程最终会走向终结。至于有时候为什么这类线程要经过很久的一个缓慢释放过程,我们在tomcat的worker线程的空闲判定与释放 - 简书 (jianshu.com) 里做了较为详细的分析。

样本三

373个这样处于WAITING的http-nio-8081-exec线程:

"http-nio-8081-exec-385" #459 daemon prio=5 os_prio=0 tid=0x00007f4b6819a800 nid=0x674e waiting on condition [0x00007f4b2e977000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c8ddb088> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2083)
at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
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)

一个处于RUNNABLE的线程:

"http-nio-8081-exec-386" #461 daemon prio=5 os_prio=0 tid=0x00007f4b74511000 nid=0x683f runnable [0x00007f4b2e773000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)

我们这次重点分析一下这个样本三。当时的情形,笔者回忆也是个业务高峰,这个springboot tomcat应该是进程还在、端口也通,但是请求基本不响应了的一个“假死”状态。

样本三和样本二是从awaitNanos之后开始不同的。awaitNanos(long nanosTimeout)这个方法是在LinkedBlockingQueue里边poll(timeout)的时候先拿锁,然后等待在notEmpty这个Condition这个条件上,调用notEmpty.awaitNanos(nanos),notEmpty是队列的ReentrantLock takeLock这个重入锁上的Condition。

LinkedBlockingQueue的poll(timeout)方法:

public E poll(long timeout, TimeUnit unit) throws InterruptedException {
    final E x;
    final int c;
    long nanos = unit.toNanos(timeout);
    final AtomicInteger count = this.count;
    final ReentrantLock takeLock = this.takeLock;
    takeLock.lockInterruptibly();	//先拿锁
    try {
        while (count.get() == 0) { //队列为空
            if (nanos <= 0L)
                return null;  //如果等了timeout时间队列还是空的,就返回null
            nanos = notEmpty.awaitNanos(nanos);	//阻塞等待非空条件、并释放锁
        }
        x = dequeue();  //队列有任务了,出队
        c = count.getAndDecrement();
        if (c > 1)
            notEmpty.signal();	//出队了一个任务之后队列还不是空的,那么唤醒等在notEmpty上的其他线程都去争抢锁并从await继续执行。
    } finally {
        takeLock.unlock();  //释放锁
    }
    if (c == capacity)
        signalNotFull();
    return x;
}

我们接着去awaitNanos里边看看:

public final long awaitNanos(long nanosTimeout)
        throws InterruptedException {
    if (Thread.interrupted())
        throw new InterruptedException();
    // We don't check for nanosTimeout <= 0L here, to allow
    // awaitNanos(0) as a way to "yield the lock".
    final long deadline = System.nanoTime() + nanosTimeout;
    long initialNanos = nanosTimeout;
    Node node = addConditionWaiter();	//new Node(Node.CONDITION)并添加到条件队列队尾
    int savedState = fullyRelease(node);//释放独占锁,unpark唤醒后继节点抢锁
    int interruptMode = 0;
	
	//在while里边说明仍然需要在条件队列里
	//比如假如队列里来任务了,会对notEmpty进行signal,这样Condition队列里的节点会transferForSignal到同步队列去
	//即Condition.await 本质是把自己丢入条件队列,然后等待signal唤醒、如果被唤醒了就再次进入同步队列;同时释放锁、使得同步队列里的后续节点可以抢锁去看条件满足与否。
    while (!isOnSyncQueue(node)) {//node在队列里,并且不是第一个且waitStatus == Node.CONDITION,则返回true; 
        if (nanosTimeout <= 0L) {
            transferAfterCancelledWait(node);
            break;
        }
        if (nanosTimeout > SPIN_FOR_TIMEOUT_THRESHOLD)
            LockSupport.parkNanos(this, nanosTimeout);   //样本二, 还是在条件队列里,等待
        if ((interruptMode = checkInterruptWhileWaiting(node)) != 0)
            break;
        nanosTimeout = deadline - System.nanoTime();
    }
	
	//走到这说明已经(满足条件)在同步队列等待重新获取锁
    if (acquireQueued(node, savedState) && interruptMode != THROW_IE) //样本三
        interruptMode = REINTERRUPT;
    if (node.nextWaiter != null)
        unlinkCancelledWaiters();
    if (interruptMode != 0)
        reportInterruptAfterWait(interruptMode);
    long remaining = deadline - System.nanoTime(); // avoid overflow
    return (remaining <= initialNanos) ? remaining : Long.MIN_VALUE;
}

接下来我们先跳跃一下,去看看任务队列的入队逻辑,从LinkedBlockingQueue的offer方法开始:

public boolean offer(E e) {
    if (e == null) throw new NullPointerException();
    final AtomicInteger count = this.count;
    if (count.get() == capacity)
        return false;	//达到最大队列容量了,返回false
    int c = -1;
    Node<E> node = new Node<E>(e);
    final ReentrantLock putLock = this.putLock;
    putLock.lock();	//先拿锁
    try {
        if (count.get() < capacity) {
            enqueue(node);	//入队
            c = count.getAndIncrement();
            if (c + 1 < capacity)
                notFull.signal(); //队列没满,signal唤醒等待notFull条件的线程
        }
    } finally {
        putLock.unlock();
    }
    if (c == 0)	//c==0说明之前队列是空的,现在入队了,那么就非空了。也只有这时候才需要signal非空、队列本就不为空的话不需要signal非空
        signalNotEmpty(); //队列非空,signal唤醒等待notEmpty条件的线程
    return c >= 0;
}

上面的signalNotEmpty()最终会执行到transferForSignal(Node node)方法里,这个就是把线程(对应的Node)从条件队列转移到同步队列的操作。

分析这2个方法要了解AQS的原理,从poll里边的count.get() == 0线程进来以后,进入了条件队列排队,然后释放了takeLock,就钻到while (!isOnSyncQueue(node))这个循环里了、超时之前不断判断自己有没有在同步队列里,也就是等任务队列有入队了,非空了,条件队列里边的线程都会被移到同步队列里头排队重新获取takeLock然后干活。

样本三的线程栈上可以看出来,线程跳出了while循环,来到了if (acquireQueued(node, savedState) && interruptMode != THROW_IE),也就是说,队列里有入队了而且应该是至少300多个,这些原来等待在条件队列的线程被转移到了同步队列等待获取takeLock干活了!我们继续,进入acquireQueued:

final boolean acquireQueued(final Node node, int arg) {
    boolean interrupted = false;
    try {
        for (;;) {
            final Node p = node.predecessor();
            if (p == head && tryAcquire(arg)) {
                setHead(node);
                p.next = null; // help GC
                return interrupted;
            }
			//要么不是头节点,要么tryAcquire获取锁失败了;
            if (shouldParkAfterFailedAcquire(p, node)) //前边节点状态是SIGNAL则park
                interrupted |= parkAndCheckInterrupt();  //park挂起当前线程,等前边节点unpark; 那400个线程都park在这了!
        } //跳出循环的条件是前置节点为头节点且抢到锁。非公平锁,当前持有锁的线程也会跟后继节点去抢锁。
    } catch (Throwable t) {
        cancelAcquire(node);
        if (interrupted)
            selfInterrupt();
        throw t;
    }
}

到此,我们大致知道了流程:notEmpty条件不满足就先阻塞在takeLock.condition上,满足了以后,由于是非公平锁就先tryAcquire拿一次锁、如果成则去拿队列任务执行,没拿到就进同步队列排队拿锁、除了第一个外其余park等前序唤醒。
从线程栈上看这300+个线程就属于是在AQS同步队列里park等待前序节点唤醒再去拿锁的这种场景。

这是一个线程池饥饿问题吗 ?还是一个性能瓶颈问题?

笔者设想了如下两个可能出现上述情况的场景:

1、非公平锁模式下,300+个线程,某个386号线程由于某种原因,每次都抢到锁。tomcat任务队列是jdk LinkedBlockingQueue的子类,出队锁takeLock就是非公平锁。386号是当前持有锁的线程,poll完之后takeLock.unlock()释放锁并unpark同步队列中自己后继节点了,自己接下来去执行task任务了。然后跟后继节点是可以一起来poll -> tryAcquire来抢锁的。然后又是它抢到了。

杂(jvm线程栈分析、jdkbug引发socketRead0阻塞、jvm调优等) - 肥兔子爱豆畜子 - 博客园 (cnblogs.com)

可能的情况:386线程一直处于RUNNABLE状态,系统将调度优先给这个线程,其他同步队列的线程得不到时间片抢不到锁。然后386线程由于上述jdk bug又执行不完一直处于这个状态。所以整个进程假死。

2、任务队列里任务一下来了非常之多的任务,然后之前条件队列里的线程都满足了notEmpty条件去抢锁然后拿任务,然后也是按照同步队列里的顺序一个接着一个的唤醒去拿锁然后拿任务执行请求业务逻辑。刚好jstack的时候这些在同步队列里的且还没被唤醒的park线程被采集到线程栈了。
请求任务源源不断的的入队(TaskQueue),worker线程就会一直满足notEmpty的Condition而进入到AQS同步队列里、排队、park,这样只要入队的速度大于出队的速度(这里指AQS同步队列),那么就会产生上面300+个线程排队获取TaskQueue的ReentrantLock$NonfairSync锁的现象了。

这就其实是所谓的性能瓶颈了,任务队列里产生了大量积压(所以tomcat新请求来了没响应假死、实际上是进到任务队列排队去了,而且队非常之长),后面的工作线程AQS排队去拿takeLock然后一个个的执行队列里的任务却怎么也执行不完,队列太长了。

如果是2这种情况,那不应该是从awaitNanos进去,后续一直worker线程忙于处理的话,应该是count.get() != 0,然后直接出队,就是park也应该是从takeLock.lockInterruptibly()进去走acquireQueued。

所以从线程栈上来看,是一种线程先空闲从条件队列瞬间移动到同步队列、然后300+大部分没抢到锁的线程进入park,然后抢到锁的386线程一直占用CPU时间片(虽然笔者还不了解更底层的线程调度原理来证明这种线程饥饿的情况),其他线程没机会去抢锁运行这样一个瞬时里发生的事情。

所以,笔者目前倾向是一个jdk bug导致的一个线程长期占用cpu,其他大量线程饥饿park阻塞的情形。

posted on 2021-11-07 18:26  肥兔子爱豆畜子  阅读(979)  评论(0编辑  收藏  举报

导航