HTTP/2.0: WildFly worker's interoperability with Apache HTTP Server mod_cluster ------------------------------------------------------------------------------- Key: MODCLUSTER-588 URL: https://issues.jboss.org/browse/MODCLUSTER-588 Project: mod_cluster Issue Type: Bug Components: Core &amp; Container Integration (Java) Affects Versions: 1.3.6.Final Environment: RHEL 7.3, OpenSSL 1.0.2h from JBCS Reporter: Michal Karm Babacek Assignee: Radoslav Husar Priority: Critical Attachments: JBEAP-11548_bad.pcap, JBEAP-11548_good.pcap There are two configurations debated on this JIRA, the first seems to work O.K. (/) with some concerns, the second one doesn't work at all (x). h1. 1. (/) "ALPN hack", Oracle JDK8 Hello, when you have this configuration of Apache HTTP Server 2.4.23 [mod_cluster.conf|https://gist.github.com/Karm/541fba87030c4ee380f0c6872fe...] and EAP 7.1 [standalone-ha.xml|https://gist.github.com/Karm/e84ca6199f6bf3e7906d8ec632...] and you start both servers, the worker correctly contacts the balancer and it is able to serve requests via HTTP/2.0. Although, I am mildly concerned about the irregular messages I can see during {{httpd <-> eap}} periodic 5s liveness verification ({{LBstatusRecalTime}}) with OPTIONS method and about connector's exceptions during sending MCMP messages. I haven't tried to let it run for days, but long-time impact is my main motivation for posting this. I parsed the log into corresponding blocks to illustrate situation on the balancer side and on the worker side. h3. cap (wireshark) This is the recording of the initial communication {{worker -> balancer}} (registering message), {{balancer -> worker}} (response): [^JBEAP-11548_good.pcap], note port 8443 is the EAP's https connector and port 8747 is the Apache HTTP Server MCMP enabled, https enabled virtual host with both h2 and http/1.1 allowed, {{Protocols h2 http/1.1}} and {{ProtocolsHonorOrder on}}. h2. Start Both servers started, no client requests whatsoever. The first block is the very first communication between servers. h4. Worker Block 1 {code}05:33:02,544 DEBUG [org.jboss.modcluster] (UndertowEventHandlerAdapter - 1) MODCLUSTER000009: Sending STATUS for default-server 05:33:02,695 DEBUG [io.undertow.request] (default I/O-2) Using ALPN provider JDK8AlpnProvider for connector at /192.168.122.172:8443{code} h4. Balancer Block 1 [Full block|https://gist.github.com/Karm/6ff0c53b70ce28d73da3f828bb1605be] h4. Worker Block 2 No exception, no log. h4. Balancer Block 2 [Full block|https://gist.github.com/Karm/7a5d4f5e667b9ee86e446fc73f8d1ec1] h4. Worker Block 3 {code}05:33:23,144 DEBUG [io.undertow.request] (default I/O-4) UT005013: An IOException occurred: java.nio.channels.ClosedChannelException at io.undertow.protocols.ssl.SslConduit.doWrap(SslConduit.java:844) at io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:647) at io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63) at io.undertow.protocols.ssl.SslConduit$SslReadReadyHandler.readReady(SslConduit.java:1098) at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89) at org.xnio.nio.WorkerThread.run(WorkerThread.java:567){code} h4. Balancer Block 3 [Full block|https://gist.github.com/Karm/cfda838d94a1806e7e7e087cf412dc6d] h4. Worker Block 4 No exception, no log. h4. Balancer Block 4 [Full block|https://gist.github.com/Karm/7f0af3c5f443c22f90ea38a57a8f044a] h4. Worker Block 5 No exception, no log. h4. Balancer Block 5 [Full block|https://gist.github.com/Karm/36434f6493aee9e6f30a1bb8a88734b3] h4. Worker Block 6 No exception, no log. h4. Balancer Block 6 [Full block|https://gist.github.com/Karm/cf877cb9670a66d7ea36e19a6867b61b] h4. Worker Block 7 No exception, no log. h4. Balancer Block 7 [Full block|https://gist.github.com/Karm/612901b85f62d1a71bf9e4caf7a1e537] h4. Worker Block 8 No exception, no log. h4. Balancer Block 8 [Full block|https://gist.github.com/Karm/83dd6b29cf066241613d9a2fbbc9751a] h4. Worker Block 9 No exception, no log. h4. Balancer Block 9 [Full block|https://gist.github.com/Karm/02f3e5a33f1c7e5e314eda897e8df80a] h4. Worker Block 10 {code}05:33:58,238 DEBUG [io.undertow.request.io] (default I/O-2) UT005013: An IOException occurred: java.io.IOException: Connection reset by peer{code} [Full block|https://gist.github.com/Karm/380150a2b76399cdd68f033fb50c21b6] h4. Balancer Block 10 [Full block|https://gist.github.com/Karm/5f84ae53bdaa725472a3dd152072cab7] h4. Worker Block 11 {code}05:34:02,808 DEBUG [org.jboss.modcluster] (UndertowEventHandlerAdapter - 1) MODCLUSTER000009: Sending STATUS for default-server 05:34:03,002 DEBUG [io.undertow.request] (default I/O-4) UT005013: An IOException occurred: java.nio.channels.ClosedChannelException at io.undertow.protocols.ssl.SslConduit.doWrap(SslConduit.java:844) at io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:647) at io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63) at io.undertow.protocols.ssl.SslConduit$SslReadReadyHandler.readReady(SslConduit.java:1098) at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89) at org.xnio.nio.WorkerThread.run(WorkerThread.java:567){code} h4. Balancer Block 11 [Full block|https://gist.github.com/Karm/90ec31c8cfee9b204d91dbef5be2b3a3] h4. Worker Block 12 No exception, no log. h4. Balancer Block 12 [Full block|https://gist.github.com/Karm/33b79c1f7b3dc4655b88648e141cf242] h4. Worker Block 13 {code}05:34:13,242 DEBUG [io.undertow.request] (default I/O-4) UT005013: An IOException occurred: java.nio.channels.ClosedChannelException at io.undertow.protocols.ssl.SslConduit.doWrap(SslConduit.java:844) at io.undertow.protocols.ssl.SslConduit.doHandshake(SslConduit.java:647) at io.undertow.protocols.ssl.SslConduit.access$900(SslConduit.java:63) at io.undertow.protocols.ssl.SslConduit$SslReadReadyHandler.readReady(SslConduit.java:1098) at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89) at org.xnio.nio.WorkerThread.run(WorkerThread.java:567){code} h4. Balancer Block 13 [Full block|https://gist.github.com/Karm/1f25ef8f913368fb91e0795ee1b8de42] h4. Worker Block 14 {code}05:34:18,230 DEBUG [io.undertow.request.io] (default I/O-2) UT005013: An IOException occurred: java.io.IOException: Connection reset by peer{code} [Full block|https://gist.github.com/Karm/45dcb2efa03683656f4e59aabcdab1d0] h4. Balancer Block 14 [Full block|https://gist.github.com/Karm/87b7daf8b07732b50b0740bb84e79d6e] h2. Clients Worker is correctly registered:{code}mod_cluster/1.3.5.Final Node jboss-eap-7.1 (https://192.168.122.172:8443): Balancer: qacluster,LBGroup: ,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 2,Ttl: 60000000,Status: OK,Elected: 0,Read: 0,Transferred: 0,Connected: 0,Load: 99 Virtual Host 1: Contexts: /clusterbench, Status: ENABLED Request: 0 Disable Stop /, Status: ENABLED Request: 0 Disable Stop Aliases: default-host localhost{code} h3. Curl (x) Not related to EAP, nss Fedora 25 shenanigans with using blacklisted cipher suite: {{tls cipher ECDHE-RSA-AES256-SHA blacklisted by rfc7540}} * {{curl --http2 https://rhel7GAx86-64:2080/clusterbench/session --insecure -i -vvv}}, [curl log|https://gist.github.com/Karm/64d45635f5d81d586d556b4915410ddc] * Worker - no log, wasn't actually called by the balancer, the request crashed earlier * Balancer - tells curl to go away, [handshake log|https://gist.github.com/Karm/7eff0a338a4ecb9060a97e758891b02a] h3. Chrome (/) * Chrome 58.0.3029.110 (64-bit), correctly display worker's web app on {{https://rhel7GAx86-64:2080/clusterbench/session}} via HTTP/2.0. * Worker - web app served, [log|https://gist.github.com/Karm/00581ebd382f3f0b9148eff78b08ab50] * Balancer - O.K., [log|https://gist.github.com/Karm/19221581ed374d928ca21f374d8ef028] h3. Firefox (/) * Firefox 53.0.3 (64-bit) correctly display worker's web app on {{https://rhel7GAx86-64:2080/clusterbench/session}} via HTTP/2.0. * Worker - O.K., [log|https://gist.github.com/Karm/74a917b68392ca585d0b1a90c9d2e883] * Balancer - O.K., [log|https://gist.github.com/Karm/14a7a6c070da3981022e1a06aa5bf434] h1. 2. (x) ALPN via Wildfly OpenSSL + OpenSSL 1.0.2h + Oracle JDK8 With the same Apache HTTP Server config as in the aforementioned case, i.e. [mod_cluster.conf|https://gist.github.com/Karm/541fba87030c4ee380f0c6872fe...], and EAP 7.1 configured for Wildfly OpenSSL: [standalone-ha.xml_openssl|https://gist.github.com/Karm/fb1923d0b711a73aac...], the whole setup falls apart at the very beginning when worker contacts the balancer and then is unable to parse balancer's response. (!) *Noteworthy:* If you put another EAP configured as an Undertow mod_cluster balancer in front of this worker, also with Wildfly OpenSSL, it works. h3. cap (wireshark) This is the recording of the initial communication {{worker -> balancer}} (registering message), followed immediately by worker's crash during handshake, i.e. there is no {{balancer -> worker}} message: [^JBEAP-11548_bad.pcap], note port 8443 is the EAP's https connector and port 8747 is the Apache HTTP Server MCMP enabled, https enabled virtual host with both h2 and http/1.1 allowed, {{Protocols h2 http/1.1}} and {{ProtocolsHonorOrder on}}. h3. Balancer Everything appears cool, {{mod_manager.c(3104): manager_handler INFO OK}}, see [the log snippet|https://gist.github.com/Karm/5904cca0235bc3ad4f31c53252e3430a]. h3. Worker Falls flat on its face while processing balancer's response: {code}06:16:24,031 ERROR [org.jboss.mod_cluster.undertow] (UndertowEventHandlerAdapter - 1) null: java.lang.NumberFormatException: null at java.lang.Integer.parseInt(Integer.java:542) at org.jboss.modcluster.mcmp.impl.DefaultMCMPHandler.sendRequest(DefaultMCMPHandler.java:702) at org.jboss.modcluster.mcmp.impl.DefaultMCMPHandler.status(DefaultMCMPHandler.java:387) at org.jboss.modcluster.mcmp.impl.DefaultMCMPHandler.status(DefaultMCMPHandler.java:365) at org.jboss.modcluster.ModClusterService.status(ModClusterService.java:454) at org.wildfly.mod_cluster.undertow.UndertowEventHandlerAdapter.run(UndertowEventHandlerAdapter.java:169) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) at org.jboss.threads.JBossThread.run(JBossThread.java:320){code}, see [full log|https://gist.github.com/Karm/4f991b1cfd6d7700ef9fc27604fb3007] h3. Result No worker is registered, integration is broken. The same worker setup with another Wildfly (EAP) Undertow mod_cluster balancer works. WDYT guys, [~rhusar], [~swd847], [~jfclere]?