Service Thread Count Spikes: Tracing It to Repeated Thread Pool Creation

Posted on Views: Word count in article: 3.5k Reading time ≈ 3 mins.
A postmortem of a service whose thread count spiked from repeated thread pool creation: monitoring alert, thread dump and heap analysis, root cause, and four fixes.

Monitoring showed a service’s thread count spiking; troubleshooting revealed that the thread pools were being used incorrectly. This post records the full investigation and the fix, to help clarify how thread pools are supposed to be used.

Background

Monitoring flagged an abnormally high thread count in one of our services:

线程数

CPU, memory, and network connections were all normal at the same time.

Investigation

The first reaction was to look at the thread dumps:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
"pool-2493-thread-3" #3718833 prio=5 os_prio=0 tid=0x00007f1610041000 nid=0x38bff6 waiting on condition [0x00007f18ba29e000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007a044cce0> (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)

"pool-2493-thread-2" #3718832 prio=5 os_prio=0 tid=0x00007f161003f800 nid=0x38bff5 waiting on condition [0x00007f18bd502000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007a044cce0> (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)

"pool-2493-thread-1" #3718823 prio=5 os_prio=0 tid=0x00007f161003e000 nid=0x38bff3 waiting on condition [0x00007f18c2725000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007a044cce0> (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)

I wanted to find where the threads were created from the thread dumps, but all they showed was that the threads were created by a ThreadPoolExecutor — only runtime state.

What about the heap?

Item Value
Object/Stack Frame java.lang.Thread @ 0x7a044af30
Name pool-2493-thread-3
Shallow Heap 120
Retained Heap 1,728
Max. Locals’ Retained Heap
Context Class Loader org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader @ 0x71d665028
Is Daemon false
State [alive, parked, waiting, waiting indefinitely]
State value 0x291

The heap gave me nothing useful beyond one extra field versus the thread dump: the Context Class Loader.

Going back over the thread dumps, a pattern emerged: in [pool-2493-thread-1], the number after pool keeps increasing, while the number after thread is almost always 1, 2, or 3.

From Naming Executor Service Threads and Thread Pool in Java, I inferred that somewhere in the code a thread pool was being initialized with 3 core threads. A quick search of the codebase turned up exactly such a snippet:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
// import cn.hutool.core.thread.ThreadUtil;

    @GetMapping(value = "/jiankunkingTransfer")
    public Map<String, Object> jiankunkingTransfer(String date) {
        Executor executor = ThreadUtil.newExecutor(3, 6, 30000);
        // todo: run some business logic
        for (Object c : json.getJSONArray("data")) {
            executor.execute(() -> {
               // todo: run some business logic
            });
        }
		// note: no CountDownLatch await() here
		// and no shutdown() either
    }

At first I assumed the locally created threads would be reclaimed by the GC, so I forced a GC through Arthas vmtool — and the thread count did not drop.

Why weren’t they reclaimed?

=>
Does an ExecutorService get garbage collected when out of scope?

=> That question mentions shutdown() on the pool, but I had not focused on it yet.
=> This led me to believe the unreclaimed threads belonged to some global variable, and a round of investigation found no large global thread pool anywhere.
=> Searching again eventually turned up the answer:
https://docs.oracle.com/javase/8/docs/api/java/util/concurrent/ThreadPoolExecutor.html

The JDK official documentation says:

1
2
3
4
5
Finalization
 A pool that is no longer referenced in a program AND has no remaining threads will be shutdown automatically.
 If you would like to ensure that unreferenced pools are reclaimed even if users forget to call shutdown(), 
 then you must arrange that unused threads eventually die, by setting appropriate keep-alive times, using a 
 lower bound of zero core threads and/or setting allowCoreThreadTimeOut(boolean).

=>
A pool that is no longer referenced in the program AND has no remaining threads will be shut down automatically. If you want to ensure that unreferenced pools are reclaimed even when users forget to call shutdown(), you must arrange for unused threads to eventually die — by setting appropriate keep-alive times, using a lower bound of zero core threads, and/or setting allowCoreThreadTimeOut(boolean).

But why don’t the threads get reclaimed once the pool goes out of scope?
=>
https://stackoverflow.com/questions/7728102/why-doesnt-this-thread-pool-get-garbage-collected

Conclusions

The official documentation shows there are several ways to fix this:

  1. Make the thread pool a member variable (recommended)
  2. Shut the pool down with threadPoolExecutor.shutdown(); (this waits for in-flight tasks to finish)
  3. Enable core thread timeouts with allowCoreThreadTimeOut(true);
  4. Set the core thread count to 0 — but this causes other headaches in practice (omitted)

The fix is clear now. Next, a look at shutdown() and the default thread pool naming rule.

Extras

How shutdown() works

shutdown() sets the pool state to SHUTDOWN, interrupts all idle threads (idle meaning blocked on the queue), and finally sets the pool state to TERMINATED.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
/**
 * Initiates an orderly shutdown in which previously submitted
 * tasks are executed, but no new tasks will be accepted.
 * Invocation has no additional effect if already shut down.
 *
 * <p>This method does not wait for previously submitted tasks to
 * complete execution.  Use {@link #awaitTermination awaitTermination}
 * to do that.
 *
 * @throws SecurityException {@inheritDoc}
 */
public void shutdown() {
    
    final ReentrantLock mainLock = this.mainLock;
    // acquire the (global) lock
    mainLock.lock();
    try {
        // permission check, security-policy related
        checkShutdownAccess();
        // set the pool state to SHUTDOWN
        advanceRunState(SHUTDOWN);
        // interrupt all idle worker threads
        interruptIdleWorkers();
        // empty method, left for subclasses to implement
        onShutdown(); // hook for ScheduledThreadPoolExecutor
    } finally {
        // release the lock
        mainLock.unlock();
    }
    tryTerminate();
}

https://docs.oracle.com/javase/8/docs/api/java/util/concurrent/ThreadPoolExecutor.html#shutdown--

Default thread pool naming rule

java.util.concurrent.DefaultThreadFactory

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
static class DefaultThreadFactory implements ThreadFactory {
        private static final AtomicInteger poolNumber = new AtomicInteger(1);
        private final ThreadGroup group;
        private final AtomicInteger threadNumber = new AtomicInteger(1);
        private final String namePrefix;

        DefaultThreadFactory() {
            SecurityManager s = System.getSecurityManager();
            group = (s != null) ? s.getThreadGroup() :
                                  Thread.currentThread().getThreadGroup();
            namePrefix = "pool-" +
                          poolNumber.getAndIncrement() +
                         "-thread-";
        }

        public Thread newThread(Runnable r) {
            Thread t = new Thread(group, r,
                                  namePrefix + threadNumber.getAndIncrement(),
                                  0);
            if (t.isDaemon())
                t.setDaemon(false);
            if (t.getPriority() != Thread.NORM_PRIORITY)
                t.setPriority(Thread.NORM_PRIORITY);
            return t;
        }
    }

As the code shows, the default thread name follows => pool-<pool number, auto-incremented from 1>-thread-<thread number within the pool, auto-incremented from 1>

For custom thread naming, see:
https://stackoverflow.com/questions/6113746/naming-threads-and-thread-pools-of-executorservice

This article is the English edition of a post originally published in Chinese.