Management server on other port is starting normally on restore instead of from checkpoint

[Celludriel]

Hey

We are transforming one of our own applications to make use of CRaC. However in our company we have a requirement to expose the actuator on another port then 8080 so we choose 8888. However when the restore happens in our application, the management server is cold starting and even then we get a crash saying the server is actually running. We decided to try and reproduce this on the demo application and these are our findings.

application.properties

spring.main.cloud-platform=kubernetes

management.server.port=8888

output of ./restore.sh

qpks@WDL0000002:/mnt/c/workspaces/spring-boot-crac-demo$ ./restore.sh
2023-11-03T13:50:31.387Z  INFO 129 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8080 (http) with context path ''
2023-11-03T13:50:31.760Z  INFO 129 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port 8888 (http)
2023-11-03T13:50:31.763Z  INFO 129 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2023-11-03T13:50:31.764Z  INFO 129 --- [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/10.1.13]
2023-11-03T13:50:31.780Z  INFO 129 --- [           main] o.a.c.c.C.[Tomcat-1].[localhost].[/]     : Initializing Spring embedded WebApplicationContext
2023-11-03T13:50:31.780Z  INFO 129 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 368 ms
2023-11-03T13:50:31.825Z  INFO 129 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-11-03T13:50:31.970Z  INFO 129 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8888 (http) with context path ''
2023-11-03T13:50:32.049Z  INFO 129 --- [           main] com.example.Application                  : Started Application in 19.424 seconds (process running for 20.84)

As you see the tomcat is initializing as if it's a new object being made since the constructor is called on that class. Are we required to take manual action for this or is this a missing feature in the spring boot CRaC solution ?

update:

We just had the same behavior on the demo app as in our own application

qpks@WDL0000002:/mnt/c/workspaces/spring-boot-crac-demo$ ./restore.sh
2023-11-03T14:30:09.056Z  INFO 129 --- [Attach Listener] o.s.c.support.DefaultLifecycleProcessor  : Restarting Spring-managed lifecycle beans after JVM restore
2023-11-03T14:30:09.063Z  INFO 129 --- [Attach Listener] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8080 (http) with context path ''
2023-11-03T14:30:09.170Z  INFO 129 --- [Attach Listener] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port 8888 (http)
2023-11-03T14:30:09.174Z  INFO 129 --- [Attach Listener] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 104 ms
2023-11-03T14:30:09.188Z  INFO 129 --- [Attach Listener] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-11-03T14:30:09.242Z  INFO 129 --- [Attach Listener] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8888 (http) with context path ''
2023-11-03T14:30:09.249Z  INFO 129 --- [Attach Listener] o.s.c.support.DefaultLifecycleProcessor  : Spring-managed lifecycle restart completed in 189 ms
2023-11-03T14:30:09.250Z  INFO 129 --- [Attach Listener] o.s.c.support.DefaultLifecycleProcessor  : Restarting Spring-managed lifecycle beans after JVM restore
jdk.internal.crac.RestoreException
        at java.base/jdk.internal.crac.impl.AbstractContextImpl.afterRestore(AbstractContextImpl.java:86)
        at java.base/jdk.internal.crac.Core.checkpointRestore1(Core.java:167)
        at java.base/jdk.internal.crac.Core.checkpointRestore(Core.java:246)
        at java.base/jdk.internal.crac.Core.checkpointRestoreInternal(Core.java:262)
        Suppressed: org.springframework.context.ApplicationContextException: Failed to start bean 'webServerStartStop'
                at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:261)
                at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:441)
                at java.base/java.lang.Iterable.forEach(Iterable.java:75)
                at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:230)
                at org.springframework.context.support.DefaultLifecycleProcessor.restartAfterStop(DefaultLifecycleProcessor.java:210)
                at org.springframework.context.support.DefaultLifecycleProcessor$CracResourceAdapter.afterRestore(DefaultLifecycleProcessor.java:552)
                at org.crac.Core$ResourceWrapper.afterRestore(Core.java:96)
                at org.crac.Core$ResourceWrapper.invoke(Core.java:71)
                at jdk.proxy2/jdk.proxy2.$Proxy81.afterRestore(Unknown Source)
                at jdk.crac/jdk.crac.ResourceWrapper.afterRestore(ResourceWrapper.java:78)
                at java.base/jdk.internal.crac.impl.AbstractContextImpl.afterRestore(AbstractContextImpl.java:92)
                at jdk.crac/jdk.crac.ContextWrapper.afterRestore(ContextWrapper.java:61)
                at jdk.crac/jdk.crac.ResourceWrapper.afterRestore(ResourceWrapper.java:78)
                at java.base/jdk.internal.crac.impl.AbstractContextImpl.afterRestore(AbstractContextImpl.java:92)
                ... 3 more
        Caused by: org.springframework.boot.web.server.PortInUseException: Port 8888 is already in use
                at org.springframework.boot.web.server.PortInUseException.lambda$throwIfPortBindingException$0(PortInUseException.java:70)
                at org.springframework.boot.web.server.PortInUseException.lambda$ifPortBindingException$1(PortInUseException.java:85)
                at org.springframework.boot.web.server.PortInUseException.ifCausedBy(PortInUseException.java:103)
                at org.springframework.boot.web.server.PortInUseException.ifPortBindingException(PortInUseException.java:82)
                at org.springframework.boot.web.server.PortInUseException.throwIfPortBindingException(PortInUseException.java:69)
                at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.start(TomcatWebServer.java:228)
                at org.springframework.boot.web.servlet.context.WebServerStartStopLifecycle.start(WebServerStartStopLifecycle.java:44)
                at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:258)
                ... 16 more
        Caused by: java.lang.IllegalArgumentException: standardService.connector.startFailed
                at org.apache.catalina.core.StandardService.addConnector(StandardService.java:235)
                at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.addPreviouslyRemovedConnectors(TomcatWebServer.java:286)
                at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.start(TomcatWebServer.java:214)
                ... 18 more
        Caused by: org.apache.catalina.LifecycleException: Protocol handler start failed
                at org.apache.catalina.connector.Connector.startInternal(Connector.java:1046)
                at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:171)
                at org.apache.catalina.core.StandardService.addConnector(StandardService.java:232)
                ... 20 more
        Caused by: java.net.BindException: Address already in use
                at java.base/sun.nio.ch.Net.bind0(Native Method)
                at java.base/sun.nio.ch.Net.bind(Net.java:555)
                at java.base/sun.nio.ch.ServerSocketChannelImpl.netBind(ServerSocketChannelImpl.java:337)
                at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:294)
                at org.apache.tomcat.util.net.NioEndpoint.initServerSocket(NioEndpoint.java:247)
                at org.apache.tomcat.util.net.NioEndpoint.bind(NioEndpoint.java:202)
                at org.apache.tomcat.util.net.AbstractEndpoint.bindWithCleanup(AbstractEndpoint.java:1278)
                at org.apache.tomcat.util.net.AbstractEndpoint.start(AbstractEndpoint.java:1364)
                at org.apache.coyote.AbstractProtocol.start(AbstractProtocol.java:633)
                at org.apache.catalina.connector.Connector.startInternal(Connector.java:1043)
                ... 22 more

[sdeleuze]

Thanks for reporting this, I have created spring-projects/spring-boot#38502 related issue.