Deadlock when the application context is closed and System.exit(int) is then called during application context refresh

[wilkinsona]

Via this question on Stack Overflow, a deadlock occurs if System.exit(int) is called during context refresh. This minimal app will reproduce the problem:

package com.example.demo;

import javax.annotation.PostConstruct;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class So68099330Application {
	
	@PostConstruct
	void shutdown() {
		System.exit(0);
	}

	public static void main(String[] args) {
		SpringApplication.run(So68099330Application.class, args);
	}

}

A workaround is to set spring.main.register-shutdown-hook to false.

The deadlock looks like this:

Full thread dump OpenJDK 64-Bit Server VM (11.0.10+9 mixed mode):

Threads class SMR info:
_java_thread_list=0x00007f8d0e260f20, length=14, elements={
0x00007f8d0f809800, 0x00007f8d0d817000, 0x00007f8cdd01b000, 0x00007f8cfd01e800,
0x00007f8d0e993800, 0x00007f8cdd01c000, 0x00007f8d0e994000, 0x00007f8d0e995000,
0x00007f8d0e9ee000, 0x00007f8d0f037800, 0x00007f8d0ea22800, 0x00007f8d0f944000,
0x00007f8d0eaa3000, 0x00007f8d0ea86800
}

"main" #1 prio=5 os_prio=31 cpu=933.21ms elapsed=9.94s tid=0x00007f8d0f809800 nid=0x2703 in Object.wait()  [0x0000700004e3a000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.10/Native Method)
	- waiting on <0x000000061dcc4a38> (a java.lang.Thread)
	at java.lang.Thread.join(java.base@11.0.10/Thread.java:1305)
	- waiting to re-lock in wait() <0x000000061dcc4a38> (a java.lang.Thread)
	at java.lang.Thread.join(java.base@11.0.10/Thread.java:1380)
	at java.lang.ApplicationShutdownHooks.runHooks(java.base@11.0.10/ApplicationShutdownHooks.java:107)
	at java.lang.ApplicationShutdownHooks$1.run(java.base@11.0.10/ApplicationShutdownHooks.java:46)
	at java.lang.Shutdown.runHooks(java.base@11.0.10/Shutdown.java:130)
	at java.lang.Shutdown.exit(java.base@11.0.10/Shutdown.java:174)
	- locked <0x000000061dcc3c68> (a java.lang.Class for java.lang.Shutdown)
	at java.lang.Runtime.exit(java.base@11.0.10/Runtime.java:116)
	at java.lang.System.exit(java.base@11.0.10/System.java:1752)
	at com.example.demo.So68099330Application.shutdown(So68099330Application.java:13)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.10/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.10/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.10/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@11.0.10/Method.java:566)
	at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389)
	at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333)
	at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:422)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1778)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:602)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:524)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)
	at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$206/0x0000000800201040.getObject(Unknown Source)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
	- locked <0x000000061dff1048> (a java.util.concurrent.ConcurrentHashMap)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:944)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:918)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583)
	- locked <0x000000061dd09be0> (a java.lang.Object)
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754)
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:434)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:338)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1332)
	at com.example.demo.So68099330Application.main(So68099330Application.java:17)

"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=0.81ms elapsed=9.92s tid=0x00007f8d0d817000 nid=0x4a03 waiting on condition  [0x0000700005550000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.10/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@11.0.10/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.10/Reference.java:213)

"Finalizer" #3 daemon prio=8 os_prio=31 cpu=0.34ms elapsed=9.92s tid=0x00007f8cdd01b000 nid=0x3903 in Object.wait()  [0x0000700005653000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.10/Native Method)
	- waiting on <0x000000061de170f0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000061de170f0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:176)
	at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.10/Finalizer.java:170)

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=0.22ms elapsed=9.91s tid=0x00007f8cfd01e800 nid=0x4103 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #5 daemon prio=9 os_prio=31 cpu=0.04ms elapsed=9.91s tid=0x00007f8d0e993800 nid=0xa903 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=31 cpu=480.07ms elapsed=9.91s tid=0x00007f8cdd01c000 nid=0xa703 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C1 CompilerThread0" #14 daemon prio=9 os_prio=31 cpu=211.34ms elapsed=9.91s tid=0x00007f8d0e994000 nid=0xa403 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Sweeper thread" #18 daemon prio=9 os_prio=31 cpu=0.02ms elapsed=9.91s tid=0x00007f8d0e995000 nid=0xa203 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread1" #15 daemon prio=9 os_prio=31 cpu=189.55ms elapsed=9.89s tid=0x00007f8d0e9ee000 nid=0xa003 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Common-Cleaner" #19 daemon prio=8 os_prio=31 cpu=1.07ms elapsed=9.88s tid=0x00007f8d0f037800 nid=0x9b03 in Object.wait()  [0x0000700005f71000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.10/Native Method)
	- waiting on <0x000000061de72eb0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.10/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000061de72eb0> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run(java.base@11.0.10/CleanerImpl.java:148)
	at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
	at jdk.internal.misc.InnocuousThread.run(java.base@11.0.10/InnocuousThread.java:134)

"C1 CompilerThread2" #16 daemon prio=9 os_prio=31 cpu=142.42ms elapsed=9.75s tid=0x00007f8d0ea22800 nid=0x5b03 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C2 CompilerThread1" #7 daemon prio=9 os_prio=31 cpu=401.17ms elapsed=9.66s tid=0x00007f8d0f944000 nid=0x9703 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"SpringApplicationShutdownHook" #20 prio=5 os_prio=31 cpu=3.09ms elapsed=8.90s tid=0x00007f8d0eaa3000 nid=0x8503 waiting for monitor entry  [0x00007000072aa000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:1021)
	- waiting to lock <0x000000061dd09be0> (a java.lang.Object)
	at org.springframework.boot.SpringApplicationShutdownHook.closeAndWait(SpringApplicationShutdownHook.java:128)
	at org.springframework.boot.SpringApplicationShutdownHook$$Lambda$294/0x000000080027e040.accept(Unknown Source)
	at java.lang.Iterable.forEach(java.base@11.0.10/Iterable.java:75)
	at org.springframework.boot.SpringApplicationShutdownHook.run(SpringApplicationShutdownHook.java:100)
	at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)

"Attach Listener" #24 daemon prio=9 os_prio=31 cpu=10.49ms elapsed=4.85s tid=0x00007f8d0ea86800 nid=0x8707 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"VM Thread" os_prio=31 cpu=16.33ms elapsed=9.92s tid=0x00007f8cdd018000 nid=0x3703 runnable  

"GC Thread#0" os_prio=31 cpu=7.33ms elapsed=9.94s tid=0x00007f8d0e81d000 nid=0x5003 runnable  

"GC Thread#1" os_prio=31 cpu=7.48ms elapsed=9.36s tid=0x00007f8cdd258000 nid=0x9403 runnable  

"GC Thread#2" os_prio=31 cpu=11.18ms elapsed=9.36s tid=0x00007f8cdd259000 nid=0x6103 runnable  

"GC Thread#3" os_prio=31 cpu=6.89ms elapsed=9.36s tid=0x00007f8d0ea88000 nid=0x9103 runnable  

"GC Thread#4" os_prio=31 cpu=7.54ms elapsed=9.36s tid=0x00007f8d0ea89000 nid=0x6303 runnable  

"GC Thread#5" os_prio=31 cpu=7.81ms elapsed=9.36s tid=0x00007f8d0d040000 nid=0x9003 runnable  

"GC Thread#6" os_prio=31 cpu=7.07ms elapsed=9.36s tid=0x00007f8cfd021000 nid=0x6503 runnable  

"GC Thread#7" os_prio=31 cpu=5.84ms elapsed=9.36s tid=0x00007f8d0d041000 nid=0x8d03 runnable  

"GC Thread#8" os_prio=31 cpu=7.36ms elapsed=9.36s tid=0x00007f8d0d07a000 nid=0x8c03 runnable  

"GC Thread#9" os_prio=31 cpu=7.75ms elapsed=9.36s tid=0x00007f8cfd022000 nid=0x8b03 runnable  

"GC Thread#10" os_prio=31 cpu=7.14ms elapsed=9.36s tid=0x00007f8cfd8c5800 nid=0x6903 runnable  

"GC Thread#11" os_prio=31 cpu=9.89ms elapsed=9.36s tid=0x00007f8d0d07a800 nid=0x8a03 runnable  

"G1 Main Marker" os_prio=31 cpu=0.74ms elapsed=9.94s tid=0x00007f8d0e81d800 nid=0x4e03 runnable  

"G1 Conc#0" os_prio=31 cpu=5.19ms elapsed=9.94s tid=0x00007f8d0e84e000 nid=0x2f03 runnable  

"G1 Conc#1" os_prio=31 cpu=4.86ms elapsed=8.95s tid=0x00007f8cdd08a800 nid=0x6c0b runnable  

"G1 Conc#2" os_prio=31 cpu=4.21ms elapsed=8.95s tid=0x00007f8d0d07b800 nid=0x6b0b runnable  

"G1 Refine#0" os_prio=31 cpu=0.36ms elapsed=9.94s tid=0x00007f8d0e983000 nid=0x4d03 runnable  

"G1 Young RemSet Sampling" os_prio=31 cpu=11.08ms elapsed=9.94s tid=0x00007f8d0e983800 nid=0x3203 runnable  
"VM Periodic Task Thread" os_prio=31 cpu=41.08ms elapsed=9.88s tid=0x00007f8d0e9f7000 nid=0x9e03 waiting on condition  

JNI global refs: 23, weak refs: 0

Heap
 garbage-first heap   total 524288K, used 11612K [0x0000000600000000, 0x0000000800000000)
  region size 2048K, 7 young (14336K), 3 survivors (6144K)
 Metaspace       used 21430K, capacity 22022K, committed 22400K, reserved 1069056K
  class space    used 2382K, capacity 2576K, committed 2688K, reserved 1048576K

It's SpringApplicationShutdownHook and main that are deadlocked.

[wilkinsona]

As far as I can tell, this isn't a regression. Things behave the same in 2.3.x and 2.4.x.

This is the same behaviour as was discussed in #23625 starting at this comment where we recommended disabling the shutdown hook and possibly using an exit code generator. I think the same advice may apply here but the OP on Stack Overflow said that things were working for them on 2.4.x so there may be something different going on here. I've asked them to provide a minimal sample so we can investigate further.

[wilkinsona]

The key thing that I'd missed in the question on Stack Overflow is that SpringApplication.exit was being used. This minimal application works fine with 2.4.x but gets stuck with 2.5:

package com.example.demo;

import javax.annotation.PostConstruct;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.ApplicationContext;

@SpringBootApplication
public class So68099330Application {

    private final ApplicationContext context;

    public So68099330Application(ApplicationContext context) {
        this.context = context;
    }

    @PostConstruct
    void shutdown() {
        System.exit(SpringApplication.exit(context, () -> 0));
    }

    public static void main(String[] args) {
        SpringApplication.run(So68099330Application.class, args);
    }

}

The key difference is that the context has already been closed before calling System.exit. In 2.4 that works. In 2.5 it hangs as our shutdown hook tries to close the context before waiting for it to become inactive. The close can't proceed as the monitor's held by the main thread which has called System.exit() in the middle of a refresh. We can avoid the problem by only calling close on contexts that are active.