Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Default inclusion of AprLifecycleListener, configured APR connector and spring-boot-starter-actuator crashes the JVM at shutdown time #28472

Closed
michael-o opened this issue Oct 28, 2021 · 20 comments
Labels
for: external-project For an external project and not something we can fix status: declined A suggestion or change that we don't feel we should currently apply

Comments

@michael-o
Copy link

michael-o commented Oct 28, 2021

I am using (in a minimal test application):

  • Spring Boot 2.5.5:
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <version>2.5.5</version>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-actuator</artifactId>
            <version>2.5.5</version>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-security</artifactId>
            <version>2.5.5</version>
        </dependency>
  • Embedded Tomcat 9.0.x
  • Apache Tomcat Native 1.2.x with APR connector and OpenSSL (which isn't the cause here) on PATH/LD_LIBRARY_PATH.
  • Developers on Windows 10, deployed on Windows Server 2019 and FreeBSD 12.2-RELEASE
  • Zulu "1.8.0_282" on Windows, OpenJDK "1.8.0_302" on FreeBSD
  • Main context configured with:
    @Bean
    public TomcatServletWebServerFactory tomcatServletWebServerFactory(ServerProperties serverProperties) {
        TomcatServletWebServerFactory factory = new CustomTomcatServletWebServerFactory();

        factory.setProtocol("org.apache.coyote.http11.Http11AprProtocol");
        factory.setTomcatConnectorCustomizers(singletonList(connector -> {
            connector.setScheme("https");
            connector.setSecure(true);

            Ssl ssl = serverProperties.getSsl();
            AbstractHttp11Protocol<?> protocol = (AbstractHttp11Protocol<?>) connector.getProtocolHandler();
            protocol.setSSLEnabled(true);
            protocol.setSSLCertificateKeyFile(certificateKeyFile);
            protocol.setSSLCertificateFile(certificateFile);

            if (StringUtils.isNotEmpty(certificatePassphrase)) {
                protocol.setSSLPassword(certificatePassphrase);
            }

            String[] protocols = ssl.getEnabledProtocols();
            if (protocols != null && protocols.length > 0) {
                protocol.setSslEnabledProtocols(join(asList(protocols), ','));
            }

            String[] ciphers = ssl.getCiphers();
            if (ciphers != null && ciphers.length > 0) {
                protocol.setCiphers(ciphers[0]);
            }
        }));

        return factory;
    }

    static final class CustomTomcatServletWebServerFactory
            extends TomcatServletWebServerFactory {
        @Override
        public Ssl getSsl() {
            return null;
        }
    }

Disclaimer: I am completely new to Spring Boot (not Spring), but am a Tomcat comitter, so forgive me lack of Spring Boot knowledge. My previous Spring apps are hosted on a vanilla Tomcat instances. This crash is a side effect of: #10079

The following can be observed when the application (JVM) is shut down with Ctrl+C/SIGTERM:

  • Windows:
PS C:\Temp\reproduction-of-crash-on-exit> java "-Dserver.shutdown=graceful"  "-Dlogging.level.org.apache.tomcat=DEBUG"  "-Dserver.ssl.enabled=false" -jar .\target\springboot-testing-1.0.jar

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.5.5)

2021-10-28 14:29:39.341  INFO 16892 --- [           main] s.testing.SpringBootTestApplication      : Starting SpringBootTestApplication using Java 1.8.0_282 on md2pcvtc with PID 16892 (C:\Temp\reproduction-of-crash-on-exit\target\springboot-testing-1.0.jar started by osipovmi in C:\Temp\reproduction-of-crash-on-exit)
2021-10-28 14:29:39.346  INFO 16892 --- [           main] s.testing.SpringBootTestApplication      : No active profile set, falling back to default profiles: default
2021-10-28 14:29:40.581 DEBUG 16892 --- [           main] o.apache.tomcat.util.compat.Jre9Compat   : Class not found so assuming code is running on a pre-Java 9 JVM
...

2021-10-28 14:29:40.581 DEBUG 16892 --- [           main] o.apache.tomcat.util.compat.Jre16Compat  : Class not found so assuming code is running on a pre-Java 16 JVM
...

2021-10-28 14:29:40.920 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol port=8441)
2021-10-28 14:29:40.931 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol bindOnInit=false)
2021-10-28 14:29:40.931 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint bindOnInit=false)
2021-10-28 14:29:40.941 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol secure=true)
2021-10-28 14:29:40.981  INFO 16892 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8441 (https)
2021-10-28 14:29:40.991 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol parseBodyMethods=POST)
2021-10-28 14:29:41.001 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint parseBodyMethods=POST)
2021-10-28 14:29:41.001  INFO 16892 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Initializing ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 14:29:41.001  INFO 16892 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 14:29:41.001  INFO 16892 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 14:29:41.001  INFO 16892 --- [           main] o.a.catalina.core.AprLifecycleListener   : Loaded Apache Tomcat Native library [1.2.31] using APR version [1.7.0].
2021-10-28 14:29:41.001  INFO 16892 --- [           main] o.a.catalina.core.AprLifecycleListener   : APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [true].
2021-10-28 14:29:41.001  INFO 16892 --- [           main] o.a.catalina.core.AprLifecycleListener   : APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
2021-10-28 14:29:41.010  INFO 16892 --- [           main] o.a.catalina.core.AprLifecycleListener   : OpenSSL successfully initialized [OpenSSL 1.1.1l  24 Aug 2021]
2021-10-28 14:29:41.076  INFO 16892 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/api]    : Initializing Spring embedded WebApplicationContext
2021-10-28 14:29:41.076  INFO 16892 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1664 ms
2021-10-28 14:29:41.834  INFO 16892 --- [           main] .s.s.UserDetailsServiceAutoConfiguration :

Using generated security password: 42d966a5-3554-4a06-aa4c-e5932e62cd57

2021-10-28 14:29:41.953  INFO 16892 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure any request with [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@69e153c5, org.springframework.security.web.context.SecurityContextPersistenceFilter@3e27aa33, org.springframework.security.web.header.HeaderWriterFilter@2892d68, org.springframework.security.web.csrf.CsrfFilter@1e6a3214, org.springframework.security.web.authentication.logout.LogoutFilter@644baf4a, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@2ddc9a9f, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@46cdf8bd, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@173ed316, org.springframework.security.web.session.SessionManagementFilter@3646a422, org.springframework.security.web.access.ExceptionTranslationFilter@4145bad8, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@2cf3d63b]
2021-10-28 14:29:42.004  INFO 16892 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Starting ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 14:29:42.041 DEBUG 16892 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [protocols] that are active are : [[TLSv1.2]]
2021-10-28 14:29:42.041 DEBUG 16892 --- [           main] u.n.o.c.OpenSSLCipherConfigurationParser : Ciphers used: [TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_DH_DSS_WITH_AES_256_GCM_SHA384,,TLS_DHE_DSS_WITH_AES_256_GCM_SHA384,,TLS_DH_RSA_WITH_AES_256_GCM_SHA384,,TLS_DHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_DH_DSS_WITH_AES_128_GCM_SHA256,,TLS_DHE_DSS_WITH_AES_128_GCM_SHA256,,TLS_DH_RSA_WITH_AES_128_GCM_SHA256,,TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,,TLS_DHE_RSA_WITH_AES_256_CCM_8,,TLS_DHE_RSA_WITH_AES_256_CCM,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA256,,TLS_DH_RSA_WITH_AES_256_CBC_SHA256,,TLS_DH_DSS_WITH_AES_256_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA,,TLS_DH_RSA_WITH_AES_256_CBC_SHA,,TLS_DH_DSS_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,,TLS_DHE_RSA_WITH_AES_128_CCM_8,,TLS_DHE_RSA_WITH_AES_128_CCM,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA256,,TLS_DH_RSA_WITH_AES_128_CBC_SHA256,,TLS_DH_DSS_WITH_AES_128_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA,,TLS_DH_RSA_WITH_AES_128_CBC_SHA,,TLS_DH_DSS_WITH_AES_128_CBC_SHA,,TLS_RSA_WITH_AES_256_GCM_SHA384,,TLS_RSA_WITH_AES_128_GCM_SHA256,,TLS_RSA_WITH_AES_256_CCM_8,,TLS_RSA_WITH_AES_256_CCM,,TLS_RSA_WITH_AES_256_CBC_SHA256,,TLS_RSA_WITH_AES_256_CBC_SHA,,TLS_RSA_WITH_AES_128_CCM_8,,TLS_RSA_WITH_AES_128_CCM,,TLS_RSA_WITH_AES_128_CBC_SHA256,,TLS_RSA_WITH_AES_128_CBC_SHA,]
2021-10-28 14:29:42.045 DEBUG 16892 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [ciphers] that are active are : [[TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_256_CCM, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CCM_8, TLS_DHE_RSA_WITH_AES_256_CCM, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_128_CCM, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CCM_8, TLS_DHE_RSA_WITH_AES_128_CCM, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CCM_8, TLS_RSA_WITH_AES_256_CCM, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_CCM_8, TLS_RSA_WITH_AES_128_CCM, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA]]
2021-10-28 14:29:42.045 DEBUG 16892 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : Some of the specified [ciphers] are not supported by the SSL engine and have been skipped: [[TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DH_DSS_WITH_AES_256_GCM_SHA384, TLS_DH_RSA_WITH_AES_256_GCM_SHA384, TLS_DH_DSS_WITH_AES_128_GCM_SHA256, TLS_DH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_DH_RSA_WITH_AES_256_CBC_SHA256, TLS_DH_DSS_WITH_AES_256_CBC_SHA256, TLS_DH_RSA_WITH_AES_256_CBC_SHA, TLS_DH_DSS_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_DH_RSA_WITH_AES_128_CBC_SHA256, TLS_DH_DSS_WITH_AES_128_CBC_SHA256, TLS_DH_RSA_WITH_AES_128_CBC_SHA, TLS_DH_DSS_WITH_AES_128_CBC_SHA]]
2021-10-28 14:29:42.081  INFO 16892 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The certificate chain [null] was not specified or was not valid and JSSE requires a valid certificate chain so attempting to use OpenSSL directly

java.lang.IllegalArgumentException: Expected to find value [48] but found value [49]
...

2021-10-28 14:29:42.098 DEBUG 16892 --- [0-8441-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[https-openssl-apr-0.0.0.0-8441-Acceptor] latch=0
2021-10-28 14:29:42.101  INFO 16892 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8441 (https) with context path '/api'
2021-10-28 14:29:42.191 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol port=8082)
2021-10-28 14:29:42.191 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol bindOnInit=false)
2021-10-28 14:29:42.191 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint bindOnInit=false)
2021-10-28 14:29:42.197  INFO 16892 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8082 (http)
2021-10-28 14:29:42.197 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol parseBodyMethods=POST)
2021-10-28 14:29:42.197 DEBUG 16892 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint parseBodyMethods=POST)
2021-10-28 14:29:42.200  INFO 16892 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 14:29:42.201  INFO 16892 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 14:29:42.207  INFO 16892 --- [           main] o.a.c.c.C.[Tomcat-1].[localhost].[/]     : Initializing Spring embedded WebApplicationContext
2021-10-28 14:29:42.207  INFO 16892 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 99 ms
2021-10-28 14:29:42.231  INFO 16892 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 0 endpoint(s) beneath base path '/actuator'
2021-10-28 14:29:42.295 DEBUG 16892 --- [1-8082-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[http-nio-127.0.0.1-8082-Acceptor] latch=0
2021-10-28 14:29:42.295  INFO 16892 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8082 (http) with context path ''
2021-10-28 14:29:42.321  INFO 16892 --- [           main] s.testing.SpringBootTestApplication      : Started SpringBootTestApplication in 3.427 seconds (JVM running for 3.853)
2021-10-28 14:29:44.931  INFO 16892 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2021-10-28 14:29:44.950  INFO 16892 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x00000001800168ca, pid=16892, tid=0x0000000000005268
#
# JRE version: OpenJDK Runtime Environment (Zulu 8.52.0.24-SA-win64) (8.0_282-b08) (build 1.8.0_282-b08)
# Java VM: OpenJDK 64-Bit Server VM (25.282-b08 mixed mode windows-amd64 compressed oops)
# Problematic frame:
# C2021-10-28 14:29:45.001  INFO 16892 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
[thread 7632 also had an error]
  [tcnative-1.dll+0x168ca]
#
# Failed to write core dump. Minidumps are not enabled by default on client versions of Windows
#
# An error report file with more information is saved as:
# C:\Temp\reproduction-of-crash-on-exit\hs_err_pid16892.log
#
# If you would like to submit a bug report, please visit:
#   http://www.azulsystems.com/support/
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

FreeBSD:

java "-Dserver.shutdown=graceful"  "-Dlogging.level.org.apache.tomcat=DEBUG"  "-Dserver.ssl.enabled=false" -jar

osipovmi@deblndw011x:/tmp/reproduction-of-crash-on-exit
$ java "-Dserver.shutdown=graceful"  "-Dlogging.level.org.apache.tomcat=DEBUG"  "-Dserver.ssl.enabled=false" -jar target/springboot-testing-1.0.jar

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.5.5)

2021-10-28 14:32:21.327  INFO 44449 --- [           main] s.testing.SpringBootTestApplication      : Starting SpringBootTestApplication using Java 1.8.0_302 on deblndw011x.ad001.siemens.net with PID 44449 (/tmp/reproduction-of-crash-on-exit/target/springboot-testing-1.0.jar started by osipovmi in /tmp/reproduction-of-crash-on-exit)
2021-10-28 14:32:21.330  INFO 44449 --- [           main] s.testing.SpringBootTestApplication      : No active profile set, falling back to default profiles: default
2021-10-28 14:32:22.913 DEBUG 44449 --- [           main] o.apache.tomcat.util.compat.Jre9Compat   : Class not found so assuming code is running on a pre-Java 9 JVM

...

2021-10-28 14:32:22.915 DEBUG 44449 --- [           main] o.apache.tomcat.util.compat.Jre16Compat  : Class not found so assuming code is running on a pre-Java 16 JVM

...

2021-10-28 14:32:22.978 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol port=8441)
2021-10-28 14:32:22.990 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol bindOnInit=false)
2021-10-28 14:32:22.990 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint bindOnInit=false)
2021-10-28 14:32:22.992 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol secure=true)
2021-10-28 14:32:23.044  INFO 44449 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8441 (https)
2021-10-28 14:32:23.057 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol parseBodyMethods=POST)
2021-10-28 14:32:23.057 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint parseBodyMethods=POST)
2021-10-28 14:32:23.058  INFO 44449 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Initializing ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 14:32:23.058  INFO 44449 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 14:32:23.058  INFO 44449 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 14:32:23.061  INFO 44449 --- [           main] o.a.catalina.core.AprLifecycleListener   : An older version [1.2.24] of the Apache Tomcat Native library is installed, while Tomcat recommends a minimum version of [1.2.30]
2021-10-28 14:32:23.061  INFO 44449 --- [           main] o.a.catalina.core.AprLifecycleListener   : Loaded Apache Tomcat Native library [1.2.24] using APR version [1.7.0].
2021-10-28 14:32:23.061  INFO 44449 --- [           main] o.a.catalina.core.AprLifecycleListener   : APR capabilities: IPv6 [true], sendfile [true], accept filters [true], random [true], UDS [false].
2021-10-28 14:32:23.061  INFO 44449 --- [           main] o.a.catalina.core.AprLifecycleListener   : APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
2021-10-28 14:32:23.065  INFO 44449 --- [           main] o.a.catalina.core.AprLifecycleListener   : OpenSSL successfully initialized [OpenSSL 1.1.1l-freebsd  24 Aug 2021]
2021-10-28 14:32:23.118  INFO 44449 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/api]    : Initializing Spring embedded WebApplicationContext
2021-10-28 14:32:23.119  INFO 44449 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1725 ms
2021-10-28 14:32:23.951  INFO 44449 --- [           main] .s.s.UserDetailsServiceAutoConfiguration :

Using generated security password: 2b1f64c5-b45d-46e9-822d-202cfffb8ff6

2021-10-28 14:32:24.172  INFO 44449 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure any request with [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@7d0b7e3c, org.springframework.security.web.context.SecurityContextPersistenceFilter@3c77d488, org.springframework.security.web.header.HeaderWriterFilter@1a942c18, org.springframework.security.web.csrf.CsrfFilter@45099dd3, org.springframework.security.web.authentication.logout.LogoutFilter@2ddc9a9f, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@4145bad8, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@5ab956d7, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@15bb5034, org.springframework.security.web.session.SessionManagementFilter@71ba6d4e, org.springframework.security.web.access.ExceptionTranslationFilter@368247b9, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@78e4deb0]
2021-10-28 14:32:24.223  INFO 44449 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Starting ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 14:32:24.262 DEBUG 44449 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [protocols] that are active are : [[TLSv1.2]]
2021-10-28 14:32:24.263 DEBUG 44449 --- [           main] u.n.o.c.OpenSSLCipherConfigurationParser : Ciphers used: [TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_DH_DSS_WITH_AES_256_GCM_SHA384,,TLS_DHE_DSS_WITH_AES_256_GCM_SHA384,,TLS_DH_RSA_WITH_AES_256_GCM_SHA384,,TLS_DHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_DH_DSS_WITH_AES_128_GCM_SHA256,,TLS_DHE_DSS_WITH_AES_128_GCM_SHA256,,TLS_DH_RSA_WITH_AES_128_GCM_SHA256,,TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,,TLS_DHE_RSA_WITH_AES_256_CCM_8,,TLS_DHE_RSA_WITH_AES_256_CCM,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA256,,TLS_DH_RSA_WITH_AES_256_CBC_SHA256,,TLS_DH_DSS_WITH_AES_256_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA,,TLS_DH_RSA_WITH_AES_256_CBC_SHA,,TLS_DH_DSS_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,,TLS_DHE_RSA_WITH_AES_128_CCM_8,,TLS_DHE_RSA_WITH_AES_128_CCM,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA256,,TLS_DH_RSA_WITH_AES_128_CBC_SHA256,,TLS_DH_DSS_WITH_AES_128_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA,,TLS_DH_RSA_WITH_AES_128_CBC_SHA,,TLS_DH_DSS_WITH_AES_128_CBC_SHA,,TLS_RSA_WITH_AES_256_GCM_SHA384,,TLS_RSA_WITH_AES_128_GCM_SHA256,,TLS_RSA_WITH_AES_256_CCM_8,,TLS_RSA_WITH_AES_256_CCM,,TLS_RSA_WITH_AES_256_CBC_SHA256,,TLS_RSA_WITH_AES_256_CBC_SHA,,TLS_RSA_WITH_AES_128_CCM_8,,TLS_RSA_WITH_AES_128_CCM,,TLS_RSA_WITH_AES_128_CBC_SHA256,,TLS_RSA_WITH_AES_128_CBC_SHA,]
2021-10-28 14:32:24.264 DEBUG 44449 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [ciphers] that are active are : [[TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_256_CCM, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CCM_8, TLS_DHE_RSA_WITH_AES_256_CCM, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_128_CCM, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CCM_8, TLS_DHE_RSA_WITH_AES_128_CCM, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CCM_8, TLS_RSA_WITH_AES_256_CCM, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_CCM_8, TLS_RSA_WITH_AES_128_CCM, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA]]
2021-10-28 14:32:24.264 DEBUG 44449 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : Some of the specified [ciphers] are not supported by the SSL engine and have been skipped: [[TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DH_DSS_WITH_AES_256_GCM_SHA384, TLS_DH_RSA_WITH_AES_256_GCM_SHA384, TLS_DH_DSS_WITH_AES_128_GCM_SHA256, TLS_DH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_DH_RSA_WITH_AES_256_CBC_SHA256, TLS_DH_DSS_WITH_AES_256_CBC_SHA256, TLS_DH_RSA_WITH_AES_256_CBC_SHA, TLS_DH_DSS_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_DH_RSA_WITH_AES_128_CBC_SHA256, TLS_DH_DSS_WITH_AES_128_CBC_SHA256, TLS_DH_RSA_WITH_AES_128_CBC_SHA, TLS_DH_DSS_WITH_AES_128_CBC_SHA]]
2021-10-28 14:32:24.306  INFO 44449 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The certificate chain [null] was not specified or was not valid and JSSE requires a valid certificate chain so attempting to use OpenSSL directly

...

2021-10-28 14:32:24.345 DEBUG 44449 --- [0-8441-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[https-openssl-apr-0.0.0.0-8441-Acceptor] latch=0
2021-10-28 14:32:24.350  INFO 44449 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8441 (https) with context path '/api'
2021-10-28 14:32:24.491 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol port=8082)
2021-10-28 14:32:24.495 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol bindOnInit=false)
2021-10-28 14:32:24.496 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint bindOnInit=false)
2021-10-28 14:32:24.500  INFO 44449 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8082 (http)
2021-10-28 14:32:24.501 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol parseBodyMethods=POST)
2021-10-28 14:32:24.502 DEBUG 44449 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint parseBodyMethods=POST)
2021-10-28 14:32:24.502  INFO 44449 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 14:32:24.503  INFO 44449 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 14:32:24.508  INFO 44449 --- [           main] o.a.c.c.C.[Tomcat-1].[localhost].[/]     : Initializing Spring embedded WebApplicationContext
2021-10-28 14:32:24.508  INFO 44449 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 150 ms
2021-10-28 14:32:24.536  INFO 44449 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 0 endpoint(s) beneath base path '/actuator'
2021-10-28 14:32:24.610 DEBUG 44449 --- [1-8082-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[http-nio-127.0.0.1-8082-Acceptor] latch=0
2021-10-28 14:32:24.611  INFO 44449 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8082 (http) with context path ''
2021-10-28 14:32:24.630  INFO 44449 --- [           main] s.testing.SpringBootTestApplication      : Started SpringBootTestApplication in 3.902 seconds (JVM running for 4.727)
^C2021-10-28 14:35:57.888  INFO 44449 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2021-10-28 14:35:57.902  INFO 44449 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
2021-10-28 14:35:57.958  INFO 44449 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x0000000a763e16fa, pid=44449, tid=0x0000000000018886
#
# JRE version: OpenJDK Runtime Environment (8.0_302-b08) (build 1.8.0_302-b08)
# Java VM: OpenJDK 64-Bit Server VM (25.302-b08 mixed mode bsd-amd64 compressed oops)
# Problematic frame:
# C  [libapr-1.so.0+0x336fa]  signed char+0x1a
#
# Core dump written. Default location: /tmp/reproduction-of-crash-on-exit/java.core
#
# An error report file with more information is saved as:
# /tmp/reproduction-of-crash-on-exit/hs_err_pid44449.log
#
# If you would like to submit a bug report, please visit:
#   https://bugs.freebsd.org/bugzilla/enter_bug.cgi?product=Ports%20%26%20Packages&component=Individual%20Port(s)&short_desc=java/openjdk8%3A%20
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

Abort trap

IMPORTANT: This is neither a bug in APR, nor in Tomcat Native or Java. This is a bug in Spring Boot.

Cause of crash:
I have debugged this. To host the main context and the management context Spring Boot starts two Tomcat instances, thus two Server objects. Each instance serves one context. We are still in one JVM (OS process). For some strange reason the AprLifecycleListener is added to the context lifecycle listeners, although the vanilla Tomcat distribution uses it strictly in the Server only. It is imperative to understand how this listener works to understand this failure. Native libraries can only be loaded once and only once into the JVM process, having this listener by default in both contexts is already wrong. When vanilla Tomcat is shut down, it terminates APR globally by destroying the global APR pool then the JVM shuts down. What happens in Spring Boot?

  • Main Tomcat is started up and loads listener in the context
  • Management Tomcat is started up and loads listener in the context, this skips APR loading since it is already loaded
  • (Operations performed)
  • Process receives SIGTERM, Tomcat instances are shut down in reverse order
  • Management Tomcat is shut down, listener terminates APR globally
  • Main Tomcat is shut down, tries to shut down APR connector => SIGSEGV/ACCESS_VIOLATION because the global APR pool is already gone. Use after free, basically.
    Hence, here is the misconception in ef4cf4c: Since Tomcat is not the owner of the JVM, but Spring Boot is, Spring Boot must take care of it just like vanilla Tomcat does only once.

What should now be done:

  • Remove the AprLifecylceListener from the context list
  • Don't add TomcatServletWebServerFactory#addServerLifecycleListeners(LifecycleListener... contextLifecycleListeners) it won't solve the issue either.
  • Since this listener uses BEFORE_INIT_EVENT/AFTER_DESTROY_EVENT, start the listener manually before all Tomcat instances are started, shut it down after all instances have been destroyed.

What could be done in Tomcat to avoid such situations:

  • Make the listener either fail or log a warning that this listener only runs in the scope of Lifecycle objects of Server interface
  • Have a reference counter on init()/destroy() and perform init on 0 and destroy on 0 only. For instance, Jansi maintains such a counter: install()/uninstall()

@markt-asf please add your opinion on the Tomcat side!

What I have tried to solve this (merely a workaround to proof that it can work):

  • For the main context I have added factory.setContextLifecycleListeners(Collections.emptyList());
  • I was not able to find a decent override for the management context:
@Bean
public TomcatServletWebServerFactory tomcatServletWebServerFactory(ManagementServerProperties, ServerProperties)

to set the same of the management Tomcat instance so I patched Spring Boot 2.5.x and replaced the JARs in the local Maven repo:

osipovmi@deblndw011x:~/var/Projekte/spring-boot (2.5.x *=)
$ git diff
diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/web/embedded/tomcat/TomcatServletWebServerFactory.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/web/embedded/tomcat/TomcatServletWebServerFactory.java
index 35b3b7383a..236cac9795 100644
--- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/web/embedded/tomcat/TomcatServletWebServerFactory.java
+++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/web/embedded/tomcat/TomcatServletWebServerFactory.java
@@ -168,12 +168,6 @@ public class TomcatServletWebServerFactory extends AbstractServletWebServerFacto

     private static List<LifecycleListener> getDefaultLifecycleListeners() {
         ArrayList<LifecycleListener> lifecycleListeners = new ArrayList<>();
-        if (!NativeDetector.inNativeImage()) {
-            AprLifecycleListener aprLifecycleListener = new AprLifecycleListener();
-            if (AprLifecycleListener.isAprAvailable()) {
-                lifecycleListeners.add(aprLifecycleListener);
-            }
-        }
         return lifecycleListeners;
     }
  • Since I don't know the perfect spot in Spring Boot, I have modified the main() method:
@SpringBootApplication(exclude = { EmbeddedWebServerFactoryCustomizerAutoConfiguration.class })
@EnableScheduling
public class SpringBootTestApplication {

  public static void main(String[] args) {

    AprLifecycleListener listener = new AprLifecycleListener();
    listener.setUseAprConnector(true);
    listener.setUseOpenSSL(true);

    Lifecycle cycle = new Lifecycle() {

      @Override
      public void stop() throws LifecycleException {
        // TODO Auto-generated method stub

      }

      @Override
      public void start() throws LifecycleException {
        // TODO Auto-generated method stub

      }

      @Override
      public void removeLifecycleListener(LifecycleListener listener) {
        // TODO Auto-generated method stub

      }

      @Override
      public void init() throws LifecycleException {
        // TODO Auto-generated method stub

      }

      @Override
      public String getStateName() {
        // TODO Auto-generated method stub
        return null;
      }

      @Override
      public LifecycleState getState() {
        // TODO Auto-generated method stub
        return null;
      }

      @Override
      public LifecycleListener[] findLifecycleListeners() {
        // TODO Auto-generated method stub
        return null;
      }

      @Override
      public void destroy() throws LifecycleException {
        // TODO Auto-generated method stub

      }

      @Override
      public void addLifecycleListener(LifecycleListener listener) {
        // TODO Auto-generated method stub

      }
    };

    LifecycleEvent initEvent = new LifecycleEvent(cycle, Lifecycle.BEFORE_INIT_EVENT, null);
    listener.lifecycleEvent(initEvent);
    ;

    SpringApplication.getShutdownHandlers().add(new Thread() {
      @Override
      public void run() {
        LifecycleEvent destroyEvent = new LifecycleEvent(cycle, Lifecycle.AFTER_DESTROY_EVENT, null);
        listener.lifecycleEvent(destroyEvent);
      }
    });
    SpringApplication.run(SpringBootTestApplication.class, args);

  }

}

Here is the result now:

  • Windows:
Okt 28, 2021 3:11:31 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: Loaded Apache Tomcat Native library [1.2.31] using APR version [1.7.0].
Okt 28, 2021 3:11:31 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [true].
Okt 28, 2021 3:11:31 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: APR/OpenSSL configuration: useAprConnector [true], useOpenSSL [true]
Okt 28, 2021 3:11:31 PM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFORMATION: OpenSSL successfully initialized [OpenSSL 1.1.1l  24 Aug 2021]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v2.5.7-SNAPSHOT)

2021-10-28 15:11:32.003  INFO 20016 --- [           main] s.testing.SpringBootTestApplication      : Starting SpringBootTestApplication using Java 1.8.0_282 on md2pcvtc with PID 20016 (C:\Users\osipovmi\Desktop\reproduction-of-crash-on-exit\target\springboot-testing-1.0.jar started by osipovmi in C:\Users\osipovmi\Desktop\reproduction-of-crash-on-exit)
2021-10-28 15:11:32.008  INFO 20016 --- [           main] s.testing.SpringBootTestApplication      : No active profile set, falling back to default profiles: default
2021-10-28 15:11:33.498 DEBUG 20016 --- [           main] o.apache.tomcat.util.compat.Jre9Compat   : Class not found so assuming code is running on a pre-Java 9 JVM

...

2021-10-28 15:11:33.498 DEBUG 20016 --- [           main] o.apache.tomcat.util.compat.Jre16Compat  : Class not found so assuming code is running on a pre-Java 16 JVM

...

2021-10-28 15:11:33.838 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol port=8441)
2021-10-28 15:11:33.848 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol bindOnInit=false)
2021-10-28 15:11:33.858 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint bindOnInit=false)
2021-10-28 15:11:33.858 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol secure=true)
2021-10-28 15:11:33.908  INFO 20016 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8441 (https)
2021-10-28 15:11:33.918 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol parseBodyMethods=POST)
2021-10-28 15:11:33.918 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint parseBodyMethods=POST)
2021-10-28 15:11:33.918  INFO 20016 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Initializing ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 15:11:33.918  INFO 20016 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 15:11:33.918  INFO 20016 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 15:11:34.008  INFO 20016 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/api]    : Initializing Spring embedded WebApplicationContext
2021-10-28 15:11:34.008  INFO 20016 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1940 ms
2021-10-28 15:11:34.849  INFO 20016 --- [           main] .s.s.UserDetailsServiceAutoConfiguration :

Using generated security password: e4ae696d-4f17-4424-b3af-43fd9973582b

2021-10-28 15:11:35.001  INFO 20016 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure any request with [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@25ce9dc4, org.springframework.security.web.context.SecurityContextPersistenceFilter@2ddc9a9f, org.springframework.security.web.header.HeaderWriterFilter@3646a422, org.springframework.security.web.csrf.CsrfFilter@1a6d8329, org.springframework.security.web.authentication.logout.LogoutFilter@1ed4ae0f, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@2a7f1f10, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@740cae06, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@74ea2410, org.springframework.security.web.session.SessionManagementFilter@3e27aa33, org.springframework.security.web.access.ExceptionTranslationFilter@2892d68, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@69e153c5]
2021-10-28 15:11:35.068  INFO 20016 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Starting ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 15:11:35.103 DEBUG 20016 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [protocols] that are active are : [[TLSv1.2]]
2021-10-28 15:11:35.103 DEBUG 20016 --- [           main] u.n.o.c.OpenSSLCipherConfigurationParser : Ciphers used: [TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_DH_DSS_WITH_AES_256_GCM_SHA384,,TLS_DHE_DSS_WITH_AES_256_GCM_SHA384,,TLS_DH_RSA_WITH_AES_256_GCM_SHA384,,TLS_DHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_DH_DSS_WITH_AES_128_GCM_SHA256,,TLS_DHE_DSS_WITH_AES_128_GCM_SHA256,,TLS_DH_RSA_WITH_AES_128_GCM_SHA256,,TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,,TLS_DHE_RSA_WITH_AES_256_CCM_8,,TLS_DHE_RSA_WITH_AES_256_CCM,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA256,,TLS_DH_RSA_WITH_AES_256_CBC_SHA256,,TLS_DH_DSS_WITH_AES_256_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA,,TLS_DH_RSA_WITH_AES_256_CBC_SHA,,TLS_DH_DSS_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,,TLS_DHE_RSA_WITH_AES_128_CCM_8,,TLS_DHE_RSA_WITH_AES_128_CCM,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA256,,TLS_DH_RSA_WITH_AES_128_CBC_SHA256,,TLS_DH_DSS_WITH_AES_128_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA,,TLS_DH_RSA_WITH_AES_128_CBC_SHA,,TLS_DH_DSS_WITH_AES_128_CBC_SHA,,TLS_RSA_WITH_AES_256_GCM_SHA384,,TLS_RSA_WITH_AES_128_GCM_SHA256,,TLS_RSA_WITH_AES_256_CCM_8,,TLS_RSA_WITH_AES_256_CCM,,TLS_RSA_WITH_AES_256_CBC_SHA256,,TLS_RSA_WITH_AES_256_CBC_SHA,,TLS_RSA_WITH_AES_128_CCM_8,,TLS_RSA_WITH_AES_128_CCM,,TLS_RSA_WITH_AES_128_CBC_SHA256,,TLS_RSA_WITH_AES_128_CBC_SHA,]
2021-10-28 15:11:35.103 DEBUG 20016 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [ciphers] that are active are : [[TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_256_CCM, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CCM_8, TLS_DHE_RSA_WITH_AES_256_CCM, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_128_CCM, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CCM_8, TLS_DHE_RSA_WITH_AES_128_CCM, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CCM_8, TLS_RSA_WITH_AES_256_CCM, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_CCM_8, TLS_RSA_WITH_AES_128_CCM, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA]]
2021-10-28 15:11:35.108 DEBUG 20016 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : Some of the specified [ciphers] are not supported by the SSL engine and have been skipped: [[TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DH_DSS_WITH_AES_256_GCM_SHA384, TLS_DH_RSA_WITH_AES_256_GCM_SHA384, TLS_DH_DSS_WITH_AES_128_GCM_SHA256, TLS_DH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_DH_RSA_WITH_AES_256_CBC_SHA256, TLS_DH_DSS_WITH_AES_256_CBC_SHA256, TLS_DH_RSA_WITH_AES_256_CBC_SHA, TLS_DH_DSS_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_DH_RSA_WITH_AES_128_CBC_SHA256, TLS_DH_DSS_WITH_AES_128_CBC_SHA256, TLS_DH_RSA_WITH_AES_128_CBC_SHA, TLS_DH_DSS_WITH_AES_128_CBC_SHA]]
2021-10-28 15:11:35.154  INFO 20016 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The certificate chain [null] was not specified or was not valid and JSSE requires a valid certificate chain so attempting to use OpenSSL directly

java.lang.IllegalArgumentException: Expected to find value [48] but found value [49]
...

2021-10-28 15:11:35.184 DEBUG 20016 --- [0-8441-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[https-openssl-apr-0.0.0.0-8441-Acceptor] latch=0
2021-10-28 15:11:35.188  INFO 20016 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8441 (https) with context path '/api'
2021-10-28 15:11:35.308 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol port=8082)
2021-10-28 15:11:35.308 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol bindOnInit=false)
2021-10-28 15:11:35.308 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint bindOnInit=false)
2021-10-28 15:11:35.318  INFO 20016 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8082 (http)
2021-10-28 15:11:35.318 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol parseBodyMethods=POST)
2021-10-28 15:11:35.318 DEBUG 20016 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint parseBodyMethods=POST)
2021-10-28 15:11:35.318  INFO 20016 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 15:11:35.318  INFO 20016 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 15:11:35.328  INFO 20016 --- [           main] o.a.c.c.C.[Tomcat-1].[localhost].[/]     : Initializing Spring embedded WebApplicationContext
2021-10-28 15:11:35.328  INFO 20016 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 134 ms
2021-10-28 15:11:35.358  INFO 20016 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 0 endpoint(s) beneath base path '/actuator'
2021-10-28 15:11:35.440  INFO 20016 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8082 (http) with context path ''
2021-10-28 15:11:35.440 DEBUG 20016 --- [1-8082-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[http-nio-127.0.0.1-8082-Acceptor] latch=0
2021-10-28 15:11:35.470  INFO 20016 --- [           main] s.testing.SpringBootTestApplication      : Started SpringBootTestApplication in 4.022 seconds (JVM running for 4.644)
2021-10-28 15:11:40.138  INFO 20016 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2021-10-28 15:11:40.149  INFO 20016 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
2021-10-28 15:11:40.208  INFO 20016 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2021-10-28 15:11:40.480  INFO 20016 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
  • FreeBSD:
Okt 28, 2021 3:12:43 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: An older version [1.2.24] of the Apache Tomcat Native library is installed, while Tomcat recommends a minimum version of [1.2.30]
Okt 28, 2021 3:12:43 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: Loaded Apache Tomcat Native library [1.2.24] using APR version [1.7.0].
Okt 28, 2021 3:12:43 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: APR capabilities: IPv6 [true], sendfile [true], accept filters [true], random [true], UDS [false].
Okt 28, 2021 3:12:43 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFORMATION: APR/OpenSSL configuration: useAprConnector [true], useOpenSSL [true]
Okt 28, 2021 3:12:43 PM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFORMATION: OpenSSL successfully initialized [OpenSSL 1.1.1l-freebsd  24 Aug 2021]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v2.5.7-SNAPSHOT)

2021-10-28 15:12:44.722  INFO 47633 --- [           main] s.testing.SpringBootTestApplication      : Starting SpringBootTestApplication using Java 1.8.0_302 on deblndw011x.ad001.siemens.net with PID 47633 (/net/home/osipovmi/springboot-testing-1.0.jar started by osipovmi in /net/home/osipovmi)
2021-10-28 15:12:44.730  INFO 47633 --- [           main] s.testing.SpringBootTestApplication      : No active profile set, falling back to default profiles: default
2021-10-28 15:12:46.258 DEBUG 47633 --- [           main] o.apache.tomcat.util.compat.Jre9Compat   : Class not found so assuming code is running on a pre-Java 9 JVM

...

2021-10-28 15:12:46.260 DEBUG 47633 --- [           main] o.apache.tomcat.util.compat.Jre16Compat  : Class not found so assuming code is running on a pre-Java 16 JVM

...

2021-10-28 15:12:46.350 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol port=8441)
2021-10-28 15:12:46.370 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol bindOnInit=false)
2021-10-28 15:12:46.370 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint bindOnInit=false)
2021-10-28 15:12:46.373 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol secure=true)
2021-10-28 15:12:46.419  INFO 47633 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8441 (https)
2021-10-28 15:12:46.438 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11AprProtocol parseBodyMethods=POST)
2021-10-28 15:12:46.438 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.AprEndpoint parseBodyMethods=POST)
2021-10-28 15:12:46.439  INFO 47633 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Initializing ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 15:12:46.440  INFO 47633 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 15:12:46.440  INFO 47633 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 15:12:46.502  INFO 47633 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/api]    : Initializing Spring embedded WebApplicationContext
2021-10-28 15:12:46.503  INFO 47633 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1680 ms
2021-10-28 15:12:47.095  INFO 47633 --- [           main] .s.s.UserDetailsServiceAutoConfiguration :

Using generated security password: 55a79edb-85be-4eac-a3e7-ebf4cecb824e

2021-10-28 15:12:47.379  INFO 47633 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure any request with [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@2eae8e6e, org.springframework.security.web.context.SecurityContextPersistenceFilter@d86a6f, org.springframework.security.web.header.HeaderWriterFilter@738dc9b, org.springframework.security.web.csrf.CsrfFilter@6574a52c, org.springframework.security.web.authentication.logout.LogoutFilter@46cdf8bd, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@5ab956d7, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@3e27aa33, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@8f2ef19, org.springframework.security.web.session.SessionManagementFilter@63376bed, org.springframework.security.web.access.ExceptionTranslationFilter@55a147cc, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@15bb5034]
2021-10-28 15:12:47.442  INFO 47633 --- [           main] o.a.coyote.http11.Http11AprProtocol      : Starting ProtocolHandler ["https-openssl-apr-0.0.0.0-8441"]
2021-10-28 15:12:47.474 DEBUG 47633 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [protocols] that are active are : [[TLSv1.2]]
2021-10-28 15:12:47.476 DEBUG 47633 --- [           main] u.n.o.c.OpenSSLCipherConfigurationParser : Ciphers used: [TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384,,TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256,,TLS_DH_DSS_WITH_AES_256_GCM_SHA384,,TLS_DHE_DSS_WITH_AES_256_GCM_SHA384,,TLS_DH_RSA_WITH_AES_256_GCM_SHA384,,TLS_DHE_RSA_WITH_AES_256_GCM_SHA384,,TLS_DH_DSS_WITH_AES_128_GCM_SHA256,,TLS_DHE_DSS_WITH_AES_128_GCM_SHA256,,TLS_DH_RSA_WITH_AES_128_GCM_SHA256,,TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_256_CCM,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384,,TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,,TLS_DHE_RSA_WITH_AES_256_CCM_8,,TLS_DHE_RSA_WITH_AES_256_CCM,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA256,,TLS_DH_RSA_WITH_AES_256_CBC_SHA256,,TLS_DH_DSS_WITH_AES_256_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_256_CBC_SHA,,TLS_DHE_DSS_WITH_AES_256_CBC_SHA,,TLS_DH_RSA_WITH_AES_256_CBC_SHA,,TLS_DH_DSS_WITH_AES_256_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8,,TLS_ECDHE_ECDSA_WITH_AES_128_CCM,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256,,TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,,TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,,TLS_DHE_RSA_WITH_AES_128_CCM_8,,TLS_DHE_RSA_WITH_AES_128_CCM,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA256,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA256,,TLS_DH_RSA_WITH_AES_128_CBC_SHA256,,TLS_DH_DSS_WITH_AES_128_CBC_SHA256,,TLS_DHE_RSA_WITH_AES_128_CBC_SHA,,TLS_DHE_DSS_WITH_AES_128_CBC_SHA,,TLS_DH_RSA_WITH_AES_128_CBC_SHA,,TLS_DH_DSS_WITH_AES_128_CBC_SHA,,TLS_RSA_WITH_AES_256_GCM_SHA384,,TLS_RSA_WITH_AES_128_GCM_SHA256,,TLS_RSA_WITH_AES_256_CCM_8,,TLS_RSA_WITH_AES_256_CCM,,TLS_RSA_WITH_AES_256_CBC_SHA256,,TLS_RSA_WITH_AES_256_CBC_SHA,,TLS_RSA_WITH_AES_128_CCM_8,,TLS_RSA_WITH_AES_128_CCM,,TLS_RSA_WITH_AES_128_CBC_SHA256,,TLS_RSA_WITH_AES_128_CBC_SHA,]
2021-10-28 15:12:47.476 DEBUG 47633 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The [ciphers] that are active are : [[TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_256_CCM, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CCM_8, TLS_DHE_RSA_WITH_AES_256_CCM, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CCM_8, TLS_ECDHE_ECDSA_WITH_AES_128_CCM, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CCM_8, TLS_DHE_RSA_WITH_AES_128_CCM, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CCM_8, TLS_RSA_WITH_AES_256_CCM, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_CCM_8, TLS_RSA_WITH_AES_128_CCM, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA]]
2021-10-28 15:12:47.476 DEBUG 47633 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : Some of the specified [ciphers] are not supported by the SSL engine and have been skipped: [[TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_DH_DSS_WITH_AES_256_GCM_SHA384, TLS_DH_RSA_WITH_AES_256_GCM_SHA384, TLS_DH_DSS_WITH_AES_128_GCM_SHA256, TLS_DH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_DH_RSA_WITH_AES_256_CBC_SHA256, TLS_DH_DSS_WITH_AES_256_CBC_SHA256, TLS_DH_RSA_WITH_AES_256_CBC_SHA, TLS_DH_DSS_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_DH_RSA_WITH_AES_128_CBC_SHA256, TLS_DH_DSS_WITH_AES_128_CBC_SHA256, TLS_DH_RSA_WITH_AES_128_CBC_SHA, TLS_DH_DSS_WITH_AES_128_CBC_SHA]]
2021-10-28 15:12:47.511  INFO 47633 --- [           main] o.a.tomcat.util.net.openssl.OpenSSLUtil  : The certificate chain [null] was not specified or was not valid and JSSE requires a valid certificate chain so attempting to use OpenSSL directly

java.lang.IllegalArgumentException: Expected to find value [48] but found value [49]
...

2021-10-28 15:12:47.548 DEBUG 47633 --- [0-8441-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[https-openssl-apr-0.0.0.0-8441-Acceptor] latch=0
2021-10-28 15:12:47.553  INFO 47633 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8441 (https) with context path '/api'
2021-10-28 15:12:47.689 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol port=8082)
2021-10-28 15:12:47.693 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol bindOnInit=false)
2021-10-28 15:12:47.693 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint bindOnInit=false)
2021-10-28 15:12:47.698  INFO 47633 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8082 (http)
2021-10-28 15:12:47.699 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.coyote.http11.Http11NioProtocol parseBodyMethods=POST)
2021-10-28 15:12:47.699 DEBUG 47633 --- [           main] o.apache.tomcat.util.IntrospectionUtils  : IntrospectionUtils: setProperty(class org.apache.tomcat.util.net.NioEndpoint parseBodyMethods=POST)
2021-10-28 15:12:47.700  INFO 47633 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-10-28 15:12:47.701  INFO 47633 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.53]
2021-10-28 15:12:47.705  INFO 47633 --- [           main] o.a.c.c.C.[Tomcat-1].[localhost].[/]     : Initializing Spring embedded WebApplicationContext
2021-10-28 15:12:47.705  INFO 47633 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 146 ms
2021-10-28 15:12:47.734  INFO 47633 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 0 endpoint(s) beneath base path '/actuator'
2021-10-28 15:12:47.783  INFO 47633 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8082 (http) with context path ''
2021-10-28 15:12:47.783 DEBUG 47633 --- [1-8082-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[http-nio-127.0.0.1-8082-Acceptor] latch=0
2021-10-28 15:12:47.801  INFO 47633 --- [           main] s.testing.SpringBootTestApplication      : Started SpringBootTestApplication in 3.665 seconds (JVM running for 4.538)
^C2021-10-28 15:12:51.263  INFO 47633 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2021-10-28 15:12:51.278  INFO 47633 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
2021-10-28 15:12:51.333  INFO 47633 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2021-10-28 15:12:51.341  INFO 47633 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete

I believe this kind of change like mine can be done w/o breaking current setups. I'd be happy to discuss a proper solution.

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Oct 28, 2021
@wilkinsona
Copy link
Member

Thanks for the detailed analysis.

My initial feeling is that the best place to address this would be in Tomcat itself. While we could make some changes in Spring Boot, creating a synthetic Lifecycle instance and LifecycleEvent to be able to drive the required state changes on AprLifecycleListener feels like something that an embedder shouldn't have to do.

If, as you have suggested, AprLifecycleListener reference counted its usage, it would be more robust and its abstraction would arguably be a little less leaky. It would also improve the situation for anyone embedding Tomcat, not just Spring Boot.

@wilkinsona wilkinsona added the status: waiting-for-feedback We need additional information before we can continue label Oct 28, 2021
@michael-o
Copy link
Author

Thanks for the detailed analysis.

My initial feeling is that the best place to address this would be in Tomcat itself. While we could make some changes in Spring Boot, creating a synthetic Lifecycle instance and LifecycleEvent to be able to drive the required state changes on AprLifecycleListener feels like something that an embedder shouldn't have to do.

You could reuse the code from AprLifecycleListener to init yourself and have full control.

If, as you have suggested, AprLifecycleListener reference counted its usage, it would be more robust and its abstraction would arguably be a little less leaky. It would also improve the situation for anyone embedding Tomcat, not just Spring Boot.

Even if we (Tomat committers) implement the ref counter, it only solves the symptom, abuse of the listener at context-level which is conceptionally wrong.

@spring-projects-issues spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Oct 28, 2021
@wilkinsona
Copy link
Member

You could reuse the code from AprLifecycleListener to init yourself and have full control

That would be a chunk of fairly complex code that I would prefer to have abstracted away. It would also be a Spring Boot-specific fix to what I still believe to be a more general problem.

Even if we (Tomat committers) implement the ref counter, it only solves the symptom, abuse of the listener at context-level which is conceptionally wrong.

We can certainly move it up to the Server but I'm not sure it matters too much in Spring Boot as we know that there will only be a single Context. If, even with a single Context, the listener must be registered with the Server I'd be interested in improving my understanding of Tomcat by learning why that's the case. I'd also welcome some updates to AprLifecycleListener's javadoc to note the Server requirement and/or change its behaviour to prevent its misregistration so that others are less likely to repeat our mistake.

@michael-o
Copy link
Author

michael-o commented Oct 28, 2021

You could reuse the code from AprLifecycleListener to init yourself and have full control

That would be a chunk of fairly complex code that I would prefer to have abstracted away. It would also be a Spring Boot-specific fix to what I still believe to be a more general problem.

That's true and I don't like that either. Though, the listener with a synthetical lifecylce sounds acceptable if managed by Spring Boot directly. I don't see a huge problem implementing this. Note that Netty uses a fork of Tomcat Native as well.

Even if we (Tomat committers) implement the ref counter, it only solves the symptom, abuse of the listener at context-level which is conceptionally wrong.

We can certainly move it up to the Server but I'm not sure it matters too much in Spring Boot as we know that there will only be a single Context. If, even with a single Context, the listener must be registered with the Server I'd be interested in improving my understanding of Tomcat by learning why that's the case. I'd also welcome some updates to AprLifecycleListener's javadoc to note the Server requirement and/or change its behaviour to prevent its misregistration so that others are less likely to repeat our mistake.

As described, moving to the Server wouldn't really help since there is more than one server, we are back to the same situation again. The reason why it must be on the Server only if there is only one Server per JVM to JVM-wide init and destroy it. Spring Boot takes away this guarentee by creating two Servers that is why Spring Boot needs to take care of it, not Tomcat's Server anymore. This can happen with any native library which requires global init/destroy.

I will try to work out a doc patch for the listener in the first place.

@wilkinsona
Copy link
Member

Here's a more concise workaround:

package com.example.demo;

import java.util.Iterator;

import org.apache.catalina.LifecycleListener;
import org.apache.catalina.core.AprLifecycleListener;
import org.springframework.boot.actuate.autoconfigure.web.ManagementContextConfiguration;
import org.springframework.boot.web.embedded.tomcat.TomcatServletWebServerFactory;
import org.springframework.boot.web.server.WebServerFactoryCustomizer;
import org.springframework.context.annotation.Bean;

@ManagementContextConfiguration(proxyBeanMethods =  false)
class ManagementWebServerCustomizerConfiguration {
    
    @Bean
    WebServerFactoryCustomizer<TomcatServletWebServerFactory> tomcatCustomizer() {
        return (tomcat) -> {
            Iterator<LifecycleListener> listeners = tomcat.getContextLifecycleListeners().iterator();
            while (listeners.hasNext()) {
                if (listeners.next() instanceof AprLifecycleListener) {
                    listeners.remove();
                }
            }
        };
    }

}

This @ManagementContextConfiguration should then be registered via an entry in META-INF/spring.factories:

org.springframework.boot.actuate.autoconfigure.web.ManagementContextConfiguration=com.example.demo.ManagementWebServerCustomizerConfiguration

@michael-o
Copy link
Author

@wilkinsona I have tried that and it gets invoked, but it is invoked twice. Once for the main context and once for the management context. I expected that I modify both contexts separately:
grafik

Is there no straight forward way to modify both separately?

@wilkinsona
Copy link
Member

I omitted something: it needs to go in a package that isn't covered by component scanning. Typically that means in a package that isn't the same or a sub-package of your @SpringBootApplication-annotated class.

@michael-o
Copy link
Author

I omitted something: it needs to go in a package that isn't covered by component scanning. Typically that means in a package that isn't the same or a sub-package of your @SpringBootApplication-annotated class.

Changed, I can confirm that it is now only called on the management Tomcat, though it is still an instance of the custom Tomcat factory. Maybe this is normal.

@wilkinsona
Copy link
Member

It is normal. That's how we know which type of web server (Jetty, Netty, Tomcat, Undertow or a custom implementation) to start for the management context.

michael-o added a commit to michael-o/tomcat that referenced this issue Oct 29, 2021
…to avoid JVM crashes

This basically document cases to avoid issues like
spring-projects/spring-boot#28472
@michael-o
Copy link
Author

@wilkinsona Please have a look: apache/tomcat#456

@ChristopherSchultz
Copy link

ChristopherSchultz commented Oct 29, 2021

A reference-counter would work, because it would prevent the first AprLifecycleListener from killing APR on shutdown and only when the last listener was shutting down would it go ahead and kill APR.

@michael-o
Copy link
Author

A reference-counter would work, because it would prevent the first AprLifecycleListener from killing APR on shutdown and only when the last listener was shutting down would it go ahead and kill APR.

Correct, that is what I have proposed as a counter measure on Tomcat side.

michael-o added a commit to michael-o/tomcat that referenced this issue Nov 1, 2021
…to avoid JVM crashes

This basically documents how to avoid issues like
spring-projects/spring-boot#28472
@michael-o
Copy link
Author

FWIW, I have replicated the restrictions for many listeners from the website docs to Javadoc: apache/tomcat@9a5c21c

markt-asf pushed a commit to apache/tomcat that referenced this issue Nov 25, 2021
markt-asf pushed a commit to apache/tomcat that referenced this issue Nov 25, 2021
markt-asf pushed a commit to apache/tomcat that referenced this issue Nov 25, 2021
markt-asf pushed a commit to apache/tomcat that referenced this issue Nov 25, 2021
@wilkinsona
Copy link
Member

Correct, that is what I have proposed as a counter measure on Tomcat side.

@michael-o Do you have a link to this proposal please?

@wilkinsona wilkinsona added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Jan 19, 2022
@michael-o
Copy link
Author

Correct, that is what I have proposed as a counter measure on Tomcat side.

@michael-o Do you have a link to this proposal please?

The discussion basically happened here: apache/tomcat#456
I haven't yet found the time to work on that reference counter, but that seems the way to go. Although, I do not fully understand why Spring Boot requires two Tomcat instances at all. You can safely configer two Service instances in one Tomcat instance for main and actuator.

@spring-projects-issues spring-projects-issues added the status: feedback-provided Feedback has been provided label Jan 21, 2022
@spring-projects-issues spring-projects-issues removed the status: waiting-for-feedback We need additional information before we can continue label Jan 21, 2022
@wilkinsona
Copy link
Member

It's largely due to the general concept of a WebServer in Spring Boot (that can be Jetty, Netty, Tomcat, or Undertow). It's easier (in terms of the abstractions that are available) to create a new WebServer when we need something separate to listen on an additional port than it is to add something to the existing WebServer.

@michael-o
Copy link
Author

It's largely due to the general concept of a WebServer in Spring Boot (that can be Jetty, Netty, Tomcat, or Undertow). It's easier (in terms of the abstractions that are available) to create a new WebServer when we need something separate to listen on an additional port than it is to add something to the existing WebServer.

I see, maybe this can be addressed in next major. I am certain that other containers offer the same as Tomcat does. This would also reduce friction, config and memory requirements.

@wilkinsona
Copy link
Member

We've looked at it in the past but it was surprisingly complex. It may be worth revisiting at some point though.

@michael-o
Copy link
Author

Thank you for the reference. Makes sense now, other containers don't support it straight away.

@wilkinsona
Copy link
Member

This doesn't seem to be a problem that's affecting many Spring Boot users and, re-reading apache/tomcat#456, the consensus seems to be that this should be addressed by referencing count in Tomcat, thereby making it more robust for everyone not just users of Spring Boot.

@wilkinsona wilkinsona closed this as not planned Won't fix, can't repro, duplicate, stale Jun 4, 2024
@wilkinsona wilkinsona added status: declined A suggestion or change that we don't feel we should currently apply for: external-project For an external project and not something we can fix and removed status: waiting-for-triage An issue we've not yet triaged status: feedback-provided Feedback has been provided labels Jun 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
for: external-project For an external project and not something we can fix status: declined A suggestion or change that we don't feel we should currently apply
Projects
None yet
Development

No branches or pull requests

4 participants