TomcatServletWebServerFactoryTests.pkcs12KeyStoreAndTrustStore() is flaky on CI

[wilkinsona]

The first attempt is failing fairly frequently, but not always, with the following exception:

Caused by: java.security.NoSuchAlgorithmException: unrecognized algorithm name: PBEWithSHA1AndDESede	
	at sun.security.x509.AlgorithmId.get(AlgorithmId.java:448)	
	at sun.security.pkcs12.PKCS12KeyStore.mapPBEAlgorithmToOID(PKCS12KeyStore.java:938)	
	at sun.security.pkcs12.PKCS12KeyStore.encryptPrivateKey(PKCS12KeyStore.java:895)	
	at sun.security.pkcs12.PKCS12KeyStore.setKeyEntry(PKCS12KeyStore.java:614)	
	at sun.security.pkcs12.PKCS12KeyStore.engineSetKeyEntry(PKCS12KeyStore.java:577)	
	at java.security.KeyStore.setKeyEntry(KeyStore.java:1140)	
	at org.apache.tomcat.util.net.SSLUtilBase.getKeyManagers(SSLUtilBase.java:365)	
	at org.apache.tomcat.util.net.SSLUtilBase.createSSLContext(SSLUtilBase.java:246)	
	at org.apache.tomcat.util.net.AbstractJsseEndpoint.createSSLContext(AbstractJsseEndpoint.java:97)	
	at org.apache.tomcat.util.net.AbstractJsseEndpoint.initialiseSsl(AbstractJsseEndpoint.java:71)	
	at org.apache.tomcat.util.net.NioEndpoint.bind(NioEndpoint.java:258)	
	at org.apache.tomcat.util.net.AbstractEndpoint.bindWithCleanup(AbstractEndpoint.java:1204)	
	at org.apache.tomcat.util.net.AbstractEndpoint.start(AbstractEndpoint.java:1290)	
	at org.apache.coyote.AbstractProtocol.start(AbstractProtocol.java:614)	
	at org.apache.catalina.connector.Connector.startInternal(Connector.java:1071)	
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)	
	at org.apache.catalina.core.StandardService.addConnector(StandardService.java:239)	
	at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.addPreviouslyRemovedConnectors(TomcatWebServer.java:282)	
	at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.start(TomcatWebServer.java:213)	
	at org.springframework.boot.web.servlet.server.AbstractServletWebServerFactoryTests.pkcs12KeyStoreAndTrustStore(AbstractServletWebServerFactoryTests.java:544)	
	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 org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:688)	
	at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)	
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)	
	at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)	
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)	
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)	
	at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)	
	at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)	
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)	
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)	
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)	
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)	
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)	
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)	
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:210)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:206)	
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:131)	
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:65)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)	
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)	
	at java.util.ArrayList.forEach(ArrayList.java:1259)	
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)	
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)	
	at java.util.ArrayList.forEach(ArrayList.java:1259)	
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)	
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)	
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)	
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)	
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)	
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)	
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)	
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:108)	
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)	
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)	
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)	
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)	
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:96)	
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:75)	
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.processAllTestClasses(JUnitPlatformTestClassProcessor.java:99)	
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.access$000(JUnitPlatformTestClassProcessor.java:79)	
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor.stop(JUnitPlatformTestClassProcessor.java:75)	
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)	
	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 org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)	
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)	
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)	
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)	
	at com.sun.proxy.$Proxy2.stop(Unknown Source)	
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:133)	
	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 org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)	
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)	
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182)	
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164)	
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:414)	
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)	
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)	
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)	
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)	
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)	
	at java.lang.Thread.run(Thread.java:748)

From what I've seen thus far, when it fails on the first attempt it then always succeeds on the second attempt. How an algorithm can be inconsistently available is a mystery to me at the moment.

[dreis2211]

I think that's caused by https://bugs.openjdk.java.net/browse/JDK-8156584 - if I'm not mistaken it's flaky on JDK 8 and not on higher versions, right?

[wilkinsona]

if I'm not mistaken it's flaky on JDK 8 and not on higher versions, right?

Yeah, that's absolutely right.

Many, many thanks for the JDK bug link. I'd been suspecting some corruption of the providers but hadn't considered it could be due to a race condition. I was hunting for something messing around with system properties and the failure being due to test ordering.

Now to figure out how to work around it… I'm a little bit surprised that the build is calling AlgorithmId.get(String) on multiple threads in parallel. Although, given the lack of volatile on the fields involved, perhaps parallel access isn't required to trigger the problem.

[dreis2211]

Aren't the tests executed in parallel, generally?

Maybe we could fiddle around with the system property keystore.pkcs12.keyProtectionAlgorithm. If that is set to something that starts with pbewithhmacsha, it won't determine the algorithm but shortcut.

[wilkinsona]

Aren't the tests executed in parallel, generally?

Tests from different projects can be run in parallel, but that happens across separate worker JVMs. There's no parallel execution within an individual JVM.

If that is set to something that starts with pbewithhmacsha, it won't determine the algorithm but shortcut.

That's worth a try, I think. Thanks for the suggestion.

[wilkinsona]

This change breaks the caching of every Test task as the value of getClass().getClassLoader().getResource("jdk-8156584-security.properties") isn't consistent across builds. As a result, each Test task has different system properties. I'd like to see if there's something else that we can do.