[ https://issues.jboss.org/browse/MODCLUSTER-588?page=com.atlassian.jira.pl... ] Michal Karm Babacek updated MODCLUSTER-588: ------------------------------------------- Description: 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]? was: 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. 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. 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]? -- This message was sent by Atlassian JIRA (v7.2.3#72005)