Skip to content

DataSource logging in H2 console auto-configuration causes Hikari's threads to have the wrong thread context class loader #32382

@masked-dancer

Description

@masked-dancer

In Spring Boot v2.7.3, automatic configuration of H2's console leaves (on shutdown) dangling thread 'HikariPool-1 housekeeper', likely leading to a memory-leak, as seen here:

2022-09-15 02:59:17.947-Z  INFO  PTIF-1.0.0 13608 --- [on(3)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms
2022-09-15 02:59:25.907-Z  INFO  PTIF-1.0.0 13608 --- [on(5)-127.0.0.1] inMXBeanRegistrar$SpringApplicationAdmin : Application shutdown requested.
2022-09-15 02:59:25.910-Z  INFO  PTIF-1.0.0 13608 --- [on(5)-127.0.0.1] o.s.b.w.e.tomcat.GracefulShutdown : Commencing graceful shutdown. Waiting for active requests to complete
2022-09-15 02:59:26.160-Z  INFO  PTIF-1.0.0 13608 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown : Graceful shutdown complete
2022-09-15 02:59:26.160-Z  INFO  PTIF-1.0.0 13608 --- [on(5)-127.0.0.1] o.apache.catalina.core.StandardService : Stopping service [Tomcat]
2022-09-15 02:59:26.175-Z  INFO  PTIF-1.0.0 13608 --- [on(5)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/PTIF] : Destroying Spring FrameworkServlet 'dispatcherServlet'
2022-09-15 02:59:30.926-Z  **_WARN  PTIF-1.0.0 13608 --- [on(5)-127.0.0.1] o.a.c.loader.WebappClassLoaderBase : The web application [PTIF] appears to have started a thread named [HikariPool-1 housekeeper] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:_**
 java.base@11/jdk.internal.misc.Unsafe.park(Native Method)
 java.base@11/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
java.base@11/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
java.base@11/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
java.base@11/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
 java.base@11/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
 java.base@11/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
 java.base@11/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
 java.base@11/java.lang.Thread.run(Thread.java:834)

Datasource is left entirely to auto-configuration: H2 on classpath, and no specification of URL.

I've already done a fair bit of sleuthing, and am fairly confident (though not certain) that the cause is this: #28204, seemingly introduced in v2.6.11.

The relevant code is:

if (logger.isInfoEnabled()) {
   logDataSources(dataSource, path);
}

Two clues:

  1. Merely raising, through application.properties, the logging-level of the associated logger to 'WARN' (logging.level.org.springframework.boot.autoconfigure.h2=WARN) does away with the problem.
  2. The code that was replaced predicates the call on the datasource being available (dataSource.ifAvailable()...); it seems that that may be missing from the substituting code.

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions