search

CRaC / example-jetty

0 stars 8 forks source link

Jetty stop connectors #13

Closed gregw closed 1 year ago

gregw commented 1 year ago

Stopping the entire server can make for an expensive restart, as all the webapplications might need to be rescanned for annotations on restore. This PR only stops/starts the connectors, which contain the listening sockets.

gregw commented 1 year ago

This should be a better way to checkpoint jetty. However, I have not been able to test it because even the initial version fails on my machine:

[2041] java -version
openjdk version "17-crac" 2021-09-14
OpenJDK Runtime Environment (build 17-crac+6-21)
OpenJDK 64-Bit Server VM (build 17-crac+6-21, mixed mode, sharing)

[2042] java -XX:CRaCCheckpointTo=cr -jar target/example-jetty-1.0-SNAPSHOT.jar
2023-10-06 14:20:43.005:INFO::main: Logging initialized @57ms to org.eclipse.jetty.util.log.StdErrLog
2023-10-06 14:20:43.042:INFO:oejs.Server:main: jetty-9.4.48.v20220622; built: 2022-06-21T20:42:25.880Z; git: 6b67c5719d1f4371b33655ff2d047d24e171e49a; jvm 17-crac+6-21
2023-10-06 14:20:43.064:INFO:oejs.AbstractConnector:main: Started ServerConnector@5f205aa{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2023-10-06 14:20:43.065:INFO:oejs.Server:main: Started @124ms
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: Starting checkpoint
2023-10-06 14:20:48.982:INFO:oejs.AbstractConnector:Attach Listener: Stopped ServerConnector@5f205aa{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/crac-1.3.0.jar is recorded as always available on restore
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/jetty-io-9.4.48.v20220622.jar is recorded as always available on restore
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/jetty-util-9.4.48.v20220622.jar is recorded as always available on restore
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/jetty-http-9.4.48.v20220622.jar is recorded as always available on restore
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/javax.servlet-api-3.1.0.jar is recorded as always available on restore
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/jetty-server-9.4.48.v20220622.jar is recorded as always available on restore
Oct 06, 2023 2:20:48 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/example-jetty-1.0-SNAPSHOT.jar is recorded as always available on restore
CRIU failed with exit code 1 - check /home/gregw/src/crac-example-jetty/cr/dump4.log
Command: /opt/openjdk-17-crac+6_linux-x64/lib/criu dump -t 15748 -D cr --shell-job -v4 -o dump4.log
JVM: invalid info for restore provided: queued code -1
2023-10-06 14:20:49.041:INFO:oejs.Server:Attach Listener: jetty-9.4.48.v20220622; built: 2022-06-21T20:42:25.880Z; git: 6b67c5719d1f4371b33655ff2d047d24e171e49a; jvm 17-crac+6-21
2023-10-06 14:20:49.043:INFO:oejs.AbstractConnector:Attach Listener: Started ServerConnector@5f205aa{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2023-10-06 14:20:49.044:INFO:oejs.Server:Attach Listener: Started @6102ms
An exception during a checkpoint operation:
jdk.crac.CheckpointException
        Suppressed: java.lang.RuntimeException: Native checkpoint failed.
                at java.base/jdk.crac.Core.translateJVMExceptions(Core.java:114)
                at java.base/jdk.crac.Core.checkpointRestore1(Core.java:192)
                at java.base/jdk.crac.Core.checkpointRestore(Core.java:299)
                at java.base/jdk.crac.Core.checkpointRestoreInternal(Core.java:312)

I tried not even creating/starting a jetty server in the first place, and still got the same error.

gregw commented 1 year ago

@AntonKozlov

gregw commented 1 year ago

I even removed the Jetty dependency and made it just and empty main, and it still fails for me (see below), so I can't test this.


[2043] java -XX:CRaCCheckpointTo=cr -jar target/example-jetty-1.0-SNAPSHOT.jar
Oct 06, 2023 4:38:44 PM jdk.internal.crac.LoggerContainer info
INFO: Starting checkpoint
Oct 06, 2023 4:38:44 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/dependency/crac-1.3.0.jar is recorded as always available on restore
Oct 06, 2023 4:38:44 PM jdk.internal.crac.LoggerContainer info
INFO: /home/gregw/src/crac-example-jetty/target/example-jetty-1.0-SNAPSHOT.jar is recorded as always available on restore
CRIU failed with exit code 1 - check /home/gregw/src/crac-example-jetty/cr/dump4.log
Command: /opt/openjdk-17-crac+6_linux-x64/lib/criu dump -t 20404 -D cr --shell-job -v4 -o dump4.log
JVM: invalid info for restore provided: queued code -1
An exception during a checkpoint operation:
jdk.crac.CheckpointException
        Suppressed: java.lang.RuntimeException: Native checkpoint failed.
                at java.base/jdk.crac.Core.translateJVMExceptions(Core.java:114)
                at java.base/jdk.crac.Core.checkpointRestore1(Core.java:192)
                at java.base/jdk.crac.Core.checkpointRestore(Core.java:299)
                at java.base/jdk.crac.Core.checkpointRestoreInternal(Core.java:312)
gregw commented 1 year ago

@lachlan-roberts Does any version of this run for you?

gregw commented 1 year ago

I've opened https://github.com/eclipse/jetty.project/issues/10673 to better support CRaC in the jetty project itself, but until we can find a JVM to use for testing, we can't make much progress.

lachlan-roberts commented 1 year ago

@gregw yes, this branch works for me using the zulu crac JDK

But I also get the same failure with the latest build from https://github.com/CRaC/openjdk-builds/releases.

AntonKozlov commented 1 year ago

Sorry for the late response.

The change looks good and cool! Thank you. I've verified it on openjdk-17+6-crac https://github.com/CRaC/openjdk-builds/releases/tag/17-crac%2B6.

The problem with the exception can be caused by missing sudo on extraction, please refere to https://github.com/CRaC/docs#jdk

sudo tar zxf <jdk>.tar.gz

Expected state after the extraction is 

$ ls -la openjdk-17-crac+6_linux-x64/lib/criu
-rwsr-xr-x 1 root root 7685872 Aug 10 20:06 openjdk-17-crac+6_linux-x64/lib/criu

If this won't help, please post dump4.log file from the checkpoint image directory.

anton@mercury:~/proj/org-crac/example-jetty$ ~/Downloads/openjdk-17-crac+6_linux-x64/bin/java -XX:CRaCCheckpointTo=./cr -jar target/example-jetty-1.0-SNAPSHOT.jar
[0.005s][warning][os] CRaC closing file descriptor 31: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 37: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 43: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 49: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 55: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 61: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 67: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 73: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 79: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 85: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 91: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 97: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 103: /dev/ptmx
[0.005s][warning][os] CRaC closing file descriptor 109: /dev/ptmx
2023-10-16 19:42:41.230:INFO::main: Logging initialized @118ms to org.eclipse.jetty.util.log.StdErrLog
2023-10-16 19:42:41.285:INFO:oejs.Server:main: jetty-9.4.48.v20220622; built: 2022-06-21T20:42:25.880Z; git: 6b67c5719d1f4371b33655ff2d047d24e171e49a; jvm 17-crac+6-21
2023-10-16 19:42:41.317:INFO:oejs.AbstractConnector:main: Started ServerConnector@136432db{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2023-10-16 19:42:41.318:INFO:oejs.Server:main: Started @208ms
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: Starting checkpoint
2023-10-16 19:42:53.591:INFO:oejs.AbstractConnector:Attach Listener: Stopped ServerConnector@136432db{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/dependency/crac-1.3.0.jar is recorded as always available on restore
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/dependency/jetty-io-9.4.48.v20220622.jar is recorded as always available on restore
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/dependency/jetty-util-9.4.48.v20220622.jar is recorded as always available on restore
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/dependency/jetty-http-9.4.48.v20220622.jar is recorded as always available on restore
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/dependency/javax.servlet-api-3.1.0.jar is recorded as always available on restore
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/dependency/jetty-server-9.4.48.v20220622.jar is recorded as always available on restore
Oct 16, 2023 7:42:53 PM jdk.internal.crac.LoggerContainer info
INFO: /home/anton/proj/org-crac/example-jetty/target/example-jetty-1.0-SNAPSHOT.jar is recorded as always available on restore
Killed
<jcmd call>
anton@mercury:~/proj/org-crac/example-jetty$ ~/Downloads/openjdk-17-crac+6_linux-x64/bin/java -XX:CRaCRestoreFrom=./cr
2023-10-16 19:43:13.235:INFO:oejs.AbstractConnector:Attach Listener: Started ServerConnector@136432db{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}