Springboot 2.5.1 service doesn't stop on System.exit(0)

Question

We have a spring-boot service, that needs to stop after it did some DB migration with flyway. We solved that via a callback and the lines

int exitCode = SpringApplication.exit(applicationContext, () -> 0);
System.exit(exitCode);

It worked fine so far (spring-boot 2.4.x), but lately, we went for 2.5.1, and now it doesn't stop anymore. Is this a bug or a feature? Is there another way now to close down the service?

EDIT

I did a thread dump, but I'm not so sure how to interpret it

"main" #1 prio=5 os_prio=0 tid=0x00000000027eb000 nid=0x1280 in Object.wait() [0x000000000276d000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006c29756c8> (a java.lang.Thread)
    at java.lang.Thread.join(Thread.java:1252)
    - locked <0x00000006c29756c8> (a java.lang.Thread)
    at java.lang.Thread.join(Thread.java:1326)
    at java.lang.ApplicationShutdownHooks.runHooks(ApplicationShutdownHooks.java:107)
    at java.lang.ApplicationShutdownHooks$1.run(ApplicationShutdownHooks.java:46)
    at java.lang.Shutdown.runHooks(Shutdown.java:123)
    at java.lang.Shutdown.sequence(Shutdown.java:170)
    at java.lang.Shutdown.exit(Shutdown.java:216)
    - locked <0x00000006c28bc680> (a java.lang.Class for java.lang.Shutdown)
    at java.lang.Runtime.exit(Runtime.java:109)
    at java.lang.System.exit(System.java:973)
    at com.whatsoever.glp.moneypenny.config.PostMigrationCallback.supports(PostMigrationCallback.java:44)
    at org.flywaydb.core.internal.callback.DefaultCallbackExecutor.execute(DefaultCallbackExecutor.java:115)
    at org.flywaydb.core.internal.callback.DefaultCallbackExecutor.onMigrateOrUndoEvent(DefaultCallbackExecutor.java:73)
    at org.flywaydb.core.internal.command.DbMigrate.migrate(DbMigrate.java:165)
    at org.flywaydb.core.Flyway$1.execute(Flyway.java:216)
    at org.flywaydb.core.Flyway$1.execute(Flyway.java:165)
    at org.flywaydb.core.Flyway.execute(Flyway.java:572)
    at org.flywaydb.core.Flyway.migrate(Flyway.java:165)
    at org.springframework.boot.autoconfigure.flyway.FlywayMigrationInitializer.afterPropertiesSet(FlywayMigrationInitializer.java:66)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1845)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1782)
    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$187/370475881.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
    - locked <0x00000006c295db30> (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.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:322)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)
    at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1154)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:908)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583)
    - locked <0x00000006c2636ae8> (a java.lang.Object)
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145)
    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.whatsoever.glp.moneypenny.Application.main(Application.java:28)


"RMI TCP Accept-0" #13 daemon prio=5 os_prio=0 tid=0x000000001f040800 nid=0x1554 runnable [0x000000001fcff000]
   java.lang.Thread.State: RUNNABLE
    at java.net.DualStackPlainSocketImpl.accept0(Native Method)
    at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketImpl.java:131)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
    at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:199)
    - locked <0x00000006c261d120> (a java.net.SocksSocketImpl)
    at java.net.ServerSocket.implAccept(ServerSocket.java:560)
    at java.net.ServerSocket.accept(ServerSocket.java:528)
    at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:405)
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:377)
    at java.lang.Thread.run(Thread.java:748)


"SpringApplicationShutdownHook" #14 prio=5 os_prio=0 tid=0x0000000021126000 nid=0x630 waiting for monitor entry [0x0000000022e3f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:1021)
    - waiting to lock <0x00000006c2636ae8> (a java.lang.Object)
    at org.springframework.boot.SpringApplicationShutdownHook.closeAndWait(SpringApplicationShutdownHook.java:128)
    at org.springframework.boot.SpringApplicationShutdownHook$$Lambda$781/1430717967.accept(Unknown Source)
    at java.lang.Iterable.forEach(Iterable.java:75)
    at org.springframework.boot.SpringApplicationShutdownHook.run(SpringApplicationShutdownHook.java:101)
    at java.lang.Thread.run(Thread.java:748)


"RMI TCP Connection(1)-172.19.5.119" #15 daemon prio=5 os_prio=0 tid=0x00000000202bf000 nid=0x594 runnable [0x000000002163e000]
   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)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
    - locked <0x00000006c26360a8> (a java.io.BufferedInputStream)
    at java.io.FilterInputStream.read(FilterInputStream.java:83)
    at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:555)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$138/349364571.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)


"Monitor Ctrl-Break" #6 daemon prio=5 os_prio=0 tid=0x000000001ec8f800 nid=0x1164 runnable [0x000000001f3be000]
   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)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x00000006c2641f80> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    - locked <0x00000006c2641f80> (a java.io.InputStreamReader)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:48)


"RMI Scheduler(0)" #16 daemon prio=5 os_prio=0 tid=0x00000000202e0000 nid=0x1ac4 waiting on condition [0x000000002173e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000006c261cc28> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    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)


"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001d255000 nid=0x2370 in Object.wait() [0x000000001e78f000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006c2643898> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
    - locked <0x00000006c2643898> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)


"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000001d254000 nid=0x2ae8 in Object.wait() [0x000000001e68f000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000006c261d9d8> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    - locked <0x00000006c261d9d8> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)


"Service Thread" #11 daemon prio=9 os_prio=0 tid=0x000000001ecf3000 nid=0x28a4 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C1 CompilerThread3" #10 daemon prio=9 os_prio=2 tid=0x000000001ece4800 nid=0x24e4 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C2 CompilerThread2" #9 daemon prio=9 os_prio=2 tid=0x000000001ed29000 nid=0x27dc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C2 CompilerThread1" #8 daemon prio=9 os_prio=2 tid=0x000000001ed28000 nid=0x3170 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 tid=0x000000001ed1f800 nid=0x4108 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001d263000 nid=0x2980 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001d262000 nid=0x2144 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE


"VM Thread" os_prio=2 tid=0x000000001d250800 nid=0x4568 runnable 


"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x000000000283e000 nid=0x1254 runnable 


"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x000000000283f800 nid=0x4490 runnable 


"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x0000000002841000 nid=0x28b0 runnable 


"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x0000000002842800 nid=0x325c runnable 


"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x0000000002846000 nid=0x1a18 runnable 


"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x0000000002847000 nid=0x35c0 runnable 


"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x000000000284a800 nid=0xdfc runnable 


"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x000000000284b800 nid=0x2fc0 runnable 


"VM Periodic Task Thread" os_prio=2 tid=0x000000001f04c000 nid=0x492c waiting on condition 
JNI global references: 1665

I guess it is about this waiting to lock <0x00000006c28ae9a0>, but I'm not sure

EDIT 2

Here are the relevant classes involved

Callback used to shutdown the service after migration was done

@Component
public class PostMigrationCallback implements Callback {

  private final FlywayCustomProperties flywayCustomProperties;
  private final ApplicationContext applicationContext;

  public PostMigrationCallback(FlywayCustomProperties flywayCustomProperties, ApplicationContext applicationContext) {
    this.flywayCustomProperties = flywayCustomProperties;
    this.applicationContext = applicationContext;
  }

  @Override
  public boolean supports(Event event, Context context) {
    if (event.getId().equalsIgnoreCase("afterMigrate") && flywayCustomProperties.isMigrationOnly()) {
      log.info("Service is going to shutdown as configuration was set to spring.flyway.migrate-only=true and schema was migrated successfully");
      int exitCode = SpringApplication.exit(applicationContext, () -> 0);
      System.exit(exitCode);
    }
    return false;
  }

  @Override
  public boolean canHandleInTransaction(Event event, Context context) {
    return false;
  }

  @Override
  public void handle(Event event, Context context) {
  }

  @Override
  public String getCallbackName() {
    return "MigrationOnlyCallback";
  }
}

Factory configuring the callback

@Configuration
@ConditionalOnProperty(
    value = "spring.flyway.enabled",
    havingValue = "true"
)
public class FlywayFactory {

  private PostMigrationCallback postMigrationCallback;

  public FlywayFactory(PostMigrationCallback postMigrationCallback) {
    this.postMigrationCallback = postMigrationCallback;
  }

  @Bean
  public FlywayMigrationInitializer flywayInitializer(Flyway flyway) {
    Flyway flywayWithCallback = Flyway.configure().configuration(flyway.getConfiguration()).callbacks(flywayCallback()).load();
    return new FlywayMigrationInitializer(flywayWithCallback);
  }

  @Bean
  public Callback flywayCallback() {
    return postMigrationCallback;
  }
}

Answer 1

Thanks for the thread dump. The problem's caused by a possible bug in Spring Boot where it deadlocks when System.exit(int) is called while the application context is being refreshed. Thanks for bringing it to our attention.

Until the problem is fixed in Spring Boot you can work around it by setting spring.main.register-shutdown-hook to false.

As described in the documentation, SpringApplication.exit is intended for use in your application's main method. Your usage of it is rather unusual and you may want to explore taking a different approach.

It looks like you want your application to run in a mode when it migrates the database and then shuts down. Your current approach doesn't appear to restrict what may happen up until the point that the database is migrated. You could take a little more control over that by using a different main @Configuration class when starting your application. Something like this:

@SpringBootApplication
public class ExampleApplication {

    public static void main(String[] args) {
        if (args.length > 0 && args[0].equals("migrate")) {
            new SpringApplicationBuilder(DatabaseMigration.class).web(WebApplicationType.NONE).run(args);
        }
        else {
            SpringApplication.run(ExampleApplication.class, args);
        }
    }

    @ImportAutoConfiguration(classes = { FlywayAutoConfiguration.class, DataSourceAutoConfiguration.class })
    static class DatabaseMigration {

    }

}

The above, when started with a --migrate command line argument, will do just enough to create a DataSource, run Flyway, and then exit.