[CI] SSLConfigurationReloaderTests testReloadingKeyStore failing

[cbuescher]

[CI] SSLConfigurationReloaderTests testReloadingKeyStore failing

[elasticsearchmachine]

Pinging @elastic/es-security (Team:Security)

[cbuescher]

Muting this since I've also seen this fail earlier today: https://gradle-enterprise.elastic.co/s/skv7lgzrvktq6/tests/task/:x-pack:plugin:core:test/details/org.elasticsearch.xpack.core.ssl.SSLConfigurationReloaderTests/testReloadingKeyStore?top-execution=1

[jakelandis]

I can reliable reproduce with Java 23, but not Java 22

Java.net | | 23.ea.23 | open | installed | 23.ea.23-open

To avoid some misleading warnings, rule out the security manager, and provide better logging here is a better reproduction line:

./gradlew ':x-pack:plugin:core:test' --tests "org.elasticsearch.xpack.core.ssl.SSLConfigurationReloaderTests.testReloadingKeyStore" -Dtests.seed=BAFBC3F9A8DA6D20 -Dtests.locale=da -Dtests.timezone=Indian/Comoro -Druntime.java=23 -Dtests.security.manager=false -Dtests.jvm.argline="-Dorg.elasticsearch.nativeaccess.enableVectorLibrary=false --enable-native-access=ALL-UNNAMED" -Dtests.es.logger.org.apache.http=debug -Dtests.es.logger.level=DEBUG

fails with Java 23, but works with Java 22.

Java 22 (works)

1> [2024-05-22T01:01:34,116][DEBUG][o.a.h.i.c.DefaultHttpClientConnectionOperator] [testReloadingKeyStore] Connection established org.elasticsearch.xpack.core.ssl.SSLConfigurationReloaderTests$1@371b6acc
  1> [2024-05-22T01:01:34,116][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Executing request GET / HTTP/1.1
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Target auth state: UNCHALLENGED
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Proxy auth state: UNCHALLENGED
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> GET / HTTP/1.1
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> Host: localhost:52242
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> Connection: Keep-Alive
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.14 (Java/22)
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> Accept-Encoding: gzip,deflate
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "GET / HTTP/1.1[\r][\n]"
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Host: localhost:52242[\r][\n]"
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.14 (Java/22)[\r][\n]"
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
  1> [2024-05-22T01:01:34,117][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "[\r][\n]"
  1> [2024-05-22T01:01:34,120][DEBUG][o.e.t.h.MockWebServer    ] [[HTTP-Dispatcher]] [127.0.0.1:52242] incoming HTTP request [GET /], returning status [200] body [body]
  1> [2024-05-22T01:01:34,125][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
  1> [2024-05-22T01:01:34,126][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 << "Date: Tue, 21 May 2024 22:01:34 GMT[\r][\n]"
  1> [2024-05-22T01:01:34,126][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 << "Content-length: 4[\r][\n]"
  1> [2024-05-22T01:01:34,126][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 << "[\r][\n]"
  1> [2024-05-22T01:01:34,129][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 << HTTP/1.1 200 OK
  1> [2024-05-22T01:01:34,129][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 << Date: Tue, 21 May 2024 22:01:34 GMT
  1> [2024-05-22T01:01:34,129][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 << Content-length: 4
  1> [2024-05-22T01:01:34,130][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Connection can be kept alive indefinitely
  1> [2024-05-22T01:01:34,132][DEBUG][o.a.h.i.c.DefaultManagedHttpClientConnection] [testReloadingKeyStore] http-outgoing-0: Close connection

Java 23 (fails)

  1> [2024-05-22T01:04:18,096][DEBUG][o.a.h.i.c.DefaultHttpClientConnectionOperator] [testReloadingKeyStore] Connection established org.elasticsearch.xpack.core.ssl.SSLConfigurationReloaderTests$1@ade8676
  1> [2024-05-22T01:04:18,096][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Executing request GET / HTTP/1.1
  1> [2024-05-22T01:04:18,096][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Target auth state: UNCHALLENGED
  1> [2024-05-22T01:04:18,096][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Proxy auth state: UNCHALLENGED
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> GET / HTTP/1.1
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> Host: localhost:52320
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> Connection: Keep-Alive
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.14 (Java/23-ea)
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.headers            ] [testReloadingKeyStore] http-outgoing-0 >> Accept-Encoding: gzip,deflate
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "GET / HTTP/1.1[\r][\n]"
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Host: localhost:52320[\r][\n]"
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.14 (Java/23-ea)[\r][\n]"
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "[\r][\n]"
  1> [2024-05-22T01:04:18,097][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "[write] I/O error: Broken pipe"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.i.c.DefaultManagedHttpClientConnection] [testReloadingKeyStore] http-outgoing-0: Close connection
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "GET / HTTP/1.1[\r][\n]"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Host: localhost:52320[\r][\n]"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.14 (Java/23-ea)[\r][\n]"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "[\r][\n]"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.wire               ] [testReloadingKeyStore] http-outgoing-0 >> "[write] I/O error: Connection or outbound has closed"
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.i.c.DefaultManagedHttpClientConnection] [testReloadingKeyStore] http-outgoing-0: Shutdown connection
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.i.e.MainClientExec ] [testReloadingKeyStore] Connection discarded
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.i.c.PoolingHttpClientConnectionManager] [testReloadingKeyStore] Connection released: [id: 0][route: {s}->https://localhost:52320][total available: 0; route allocated: 0 of 2; total allocated: 0 of 20]
  1> [2024-05-22T01:04:18,098][INFO ][o.a.h.i.e.RetryExec      ] [testReloadingKeyStore] I/O exception (java.net.SocketException) caught when processing request to {s}->https://localhost:52320: Broken pipe
  1> [2024-05-22T01:04:18,098][DEBUG][o.a.h.i.e.RetryExec      ] [testReloadingKeyStore] Broken pipe

I am pretty clueless to what the root cause may be. It is either an issue with out MockWebServer which delegates down to com.sun.net.httpserver.HttpsServer or an issue with apache http client. I ran another test that uses the MockWebServer with HTTPS and it worked..so I am pretty clueless but take another look soon.

[jakelandis]

I can get the test to pass in Java23 by changing:

--- a/x-pack/plugin/core/src/test/java/org/elasticsearch/xpack/core/ssl/SSLConfigurationReloaderTests.java
+++ b/x-pack/plugin/core/src/test/java/org/elasticsearch/xpack/core/ssl/SSLConfigurationReloaderTests.java
@@ -130,7 +130,7 @@ public class SSLConfigurationReloaderTests extends ESTestCase {
         // Load HTTPClient only once. Client uses the same store as a truststore
         try (CloseableHttpClient client = getSSLClient(keystorePath, "testnode")) {
             final Consumer<SSLContext> keyMaterialPreChecks = (context) -> {
-                try (MockWebServer server = new MockWebServer(context, true)) {
+                try (MockWebServer server = new MockWebServer(context, false)) {
                     server.enqueue(new MockResponse().setResponseCode(200).setBody("body"));
                     server.start();
                     privilegedConnect(() -> client.execute(new HttpGet("https://localhost:" + server.getPort())).close());

So, the problem with the test is that in Java23 we are wiring up an apache http client to a mock web server with mutual TLS and for some reason the mock web server does not trust the apache http client.

It isn't clear if mTLS is intentional with this test since it really is not an important detail of what is being tested. It also not clear if it worked because the mock web server and apache http client are configured correctly for mTLS or just happened to work in the past. We tend to conflate key and trust stores, so maybe we aren't wiring up mTLS correctly and are relying on a Java bug (pre java 23) for this to work? I'll keep chipping away, but starting to gain more confidence this is not a production concern.