自定义 Undertow 可执行文件 war webapp 需要很长时间才能在 Java 8 上启动(在 Java 7 上快速启动)

Custom Undertow executable war webapp taking a long time to start on Java 8 (quick on Java 7)

我们正在从 Java 7 更新到新的 JRE,最初是 Java 8。

相同的 webapp(无论是为 Java 7 还是 Java 8 编译)在 Java 8 下启动需要很长时间。

一个非常简单的 web 应用程序,只包含一个 servlet,大约慢 3 倍(从 0.5 秒到 1.5 秒)。

一个典型的生产网络应用,Spring 等,需要超过 15 分钟才能启动(之前是 15 秒!)。

在启动期间进行线程转储总是产生相同的跟踪:

2021-03-15 14:52:40
Full thread dump OpenJDK 64-Bit Server VM (25.282-b08 mixed mode):

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

"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f180c259000 nid=0x94 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

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

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f180c255000 nid=0x92 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f180c252000 nid=0x91 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f180c24f000 nid=0x90 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

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

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

"main" #1 prio=5 os_prio=0 tid=0x00007f180c00b000 nid=0x82 runnable [0x00007f181541c000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.FileDispatcherImpl.close0(Native Method)
        at sun.nio.ch.FileDispatcherImpl.close(FileDispatcherImpl.java:102)
        at sun.nio.ch.FileChannelImpl.implCloseChannel(FileChannelImpl.java:141)
        at java.nio.channels.spi.AbstractInterruptibleChannel.close(AbstractInterruptibleChannel.java:115)
        - locked <0x000000076fa5ce30> (a java.lang.Object)
        at java.nio.channels.Channels.close(Channels.java:178)
        at java.nio.file.Files.copy(Files.java:3028)
        at sun.net.www.protocol.jar.URLJarFile.run(URLJarFile.java:220)
        at sun.net.www.protocol.jar.URLJarFile.run(URLJarFile.java:216)
        at java.security.AccessController.doPrivileged(Native Method)
        at sun.net.www.protocol.jar.URLJarFile.retrieve(URLJarFile.java:215)
        at sun.net.www.protocol.jar.URLJarFile.getJarFile(URLJarFile.java:71)
        at sun.net.www.protocol.jar.JarFileFactory.get(JarFileFactory.java:99)
        at sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:122)
        at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:152)
        at sun.misc.URLClassPath$Loader.findResource(URLClassPath.java:725)
        at sun.misc.URLClassPath.findResource(URLClassPath.java:225)
        at java.net.URLClassLoader.run(URLClassLoader.java:572)
        at java.net.URLClassLoader.run(URLClassLoader.java:570)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findResource(URLClassLoader.java:569)
        at java.lang.ClassLoader.getResource(ClassLoader.java:1089)
        at java.net.URLClassLoader.getResourceAsStream(URLClassLoader.java:233)
        at org.springframework.core.io.ClassPathResource.getInputStream(ClassPathResource.java:166)
        at org.springframework.core.type.classreading.SimpleMetadataReader.<init>(SimpleMetadataReader.java:50)
        at org.springframework.core.type.classreading.SimpleMetadataReaderFactory.getMetadataReader(SimpleMetadataReaderFactory.java:98)
        at org.springframework.core.type.classreading.CachingMetadataReaderFactory.getMetadataReader(CachingMetadataReaderFactory.java:102)
        - locked <0x00000006ccd0fb20> (a org.springframework.core.type.classreading.CachingMetadataReaderFactory)
        at org.springframework.core.type.classreading.SimpleMetadataReaderFactory.getMetadataReader(SimpleMetadataReaderFactory.java:93)
        at org.springframework.context.annotation.ConfigurationClassParser.asSourceClass(ConfigurationClassParser.java:591)
        at org.springframework.context.annotation.ConfigurationClassParser$SourceClass.getMemberClasses(ConfigurationClassParser.java:753)
        at org.springframework.context.annotation.ConfigurationClassParser.processMemberClasses(ConfigurationClassParser.java:311)
        at org.springframework.context.annotation.ConfigurationClassParser.doProcessConfigurationClass(ConfigurationClassParser.java:243)
        at org.springframework.context.annotation.ConfigurationClassParser.processConfigurationClass(ConfigurationClassParser.java:226)
        at org.springframework.context.annotation.ConfigurationClassParser.parse(ConfigurationClassParser.java:193)
        at org.springframework.context.annotation.ConfigurationClassParser.parse(ConfigurationClassParser.java:163)
        at org.springframework.context.annotation.ConfigurationClassPostProcessor.processConfigBeanDefinitions(ConfigurationClassPostProcessor.java:306)
        at org.springframework.context.annotation.ConfigurationClassPostProcessor.postProcessBeanDefinitionRegistry(ConfigurationClassPostProcessor.java:239)
        at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanDefinitionRegistryPostProcessors(PostProcessorRegistrationDelegate.java:254)
        at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:94)
        at org.springframework.context.support.AbstractApplicationContext.invokeBeanFactoryPostProcessors(AbstractApplicationContext.java:606)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:462)
        - locked <0x00000006c2384bd0> (a java.lang.Object)
        at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:403)
        at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:306)
        at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:106)
        at io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
        at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:196)
        at com.evolok.undertow.core.UndertowServerRunner.start(UndertowServerRunner.java:82)
        at com.evolok.undertow.core.Server.start(Server.java:43)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at ___evolok.UndertowBootstrap.main(UndertowBootstrap.java:40)

"VM Thread" os_prio=0 tid=0x00007f180c20d800 nid=0x8d runnable

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f180c021000 nid=0x83 runnable

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f180c022800 nid=0x84 runnable

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f180c024800 nid=0x85 runnable

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f180c026000 nid=0x86 runnable

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007f180c028000 nid=0x87 runnable

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007f180c029800 nid=0x88 runnable

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007f180c02b800 nid=0x89 runnable

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007f180c02d000 nid=0x8a runnable

"GC task thread#8 (ParallelGC)" os_prio=0 tid=0x00007f180c02f000 nid=0x8b runnable

"GC task thread#9 (ParallelGC)" os_prio=0 tid=0x00007f180c030800 nid=0x8c runnable

"VM Periodic Task Thread" os_prio=0 tid=0x00007f180c26e800 nid=0x96 waiting on condition

JNI global references: 16

Heap
 PSYoungGen      total 512000K, used 75381K [0x000000076b600000, 0x0000000796680000, 0x00000007c0000000)
  eden space 471552K, 15% used [0x000000076b600000,0x000000076ff9d590,0x0000000788280000)
  from space 40448K, 0% used [0x0000000789780000,0x0000000789780000,0x000000078bf00000)
  to   space 116736K, 0% used [0x000000078f480000,0x000000078f480000,0x0000000796680000)
 ParOldGen       total 363008K, used 208784K [0x00000006c2200000, 0x00000006d8480000, 0x000000076b600000)
  object space 363008K, 57% used [0x00000006c2200000,0x00000006cede4328,0x00000006d8480000)
 Metaspace       used 12974K, capacity 13240K, committed 13440K, reserved 1060864K
  class space    used 1560K, capacity 1608K, committed 1664K, reserved 1048576K

似乎 java.nio.file.Files.copy 中发生了一些事情,但我不知道如何进一步调查它。

感谢任何帮助。

经过一番挖掘,我发现问题出在我们用于可执行文件 war 支持的 URLConnection 的子类中:JarJarURLConnection(来自 https://github.com/robo-code/robocode/blob/master/robocode.host/src/main/java/net/sf/robocode/host/jarjar/JarJarURLConnection.java

似乎在 Java 8 下有时会用 false 调用 URLConnection.setUseCaches,这会导致 jar 一次又一次地成为 copied/extracted(又一次).我只是用一个空主体覆盖了这个方法,这样默认的 true 总是被使用。由于文件都是本地的,我认为没有理由不总是使用缓存。