I am moving a set working servlets from one server to another
Old server, Centos6, Apache 2.2, Tomcat 9
New Server, Centos7, Apache 2.4, Tomcat 9
I have about 5 servlets running from the old server all are OK, except the one servlet that has 3 websocket connections. Everything else runs in the servlet but the websockets.
Tomcat is reverse proxied behind apache.
My configuration for one of the reverse proxies
# websocket proxy
<Location "/admin/AdminConsole">
ProxyPass wss://localhost:8080/admin/AdminConsole
ProxyPassReverse wss://localhost:8080/admin/AdminConsole
Require all granted
</Location>
Output from apache error_log LogLevel debug proxy:trace5
[Wed Jul 01 23:10:45.963246 2020] [proxy:trace2] [pid 25640] proxy_util.c(1985): [client 174.30.215.226:46978] http: found worker http://localhost:8080/admin/AdminConsole for http://localhost:8080/admin/AdminConsole?userName=derricks&source=web
[Wed Jul 01 23:10:45.963335 2020] [proxy:debug] [pid 25640] mod_proxy.c(1123): [client 174.30.215.226:46978] AH01143: Running scheme http handler (attempt 0)
[Wed Jul 01 23:10:45.963372 2020] [proxy:debug] [pid 25640] proxy_util.c(2203): AH00942: HTTP: has acquired connection for (localhost)
[Wed Jul 01 23:10:45.963388 2020] [proxy:debug] [pid 25640] proxy_util.c(2256): [client 174.30.215.226:46978] AH00944: connecting http://localhost:8080/admin/AdminConsole?userName=derricks&source=web to localhost:8080
[Wed Jul 01 23:10:45.966024 2020] [proxy:debug] [pid 25640] proxy_util.c(2426): [client 174.30.215.226:46978] AH00947: connected /admin/AdminConsole?userName=derricks&source=web to localhost:8080
[Wed Jul 01 23:10:45.966077 2020] [proxy:trace2] [pid 25640] proxy_util.c(2768): HTTP: fam 10 socket created to connect to localhost
[Wed Jul 01 23:10:45.966734 2020] [proxy:debug] [pid 25640] proxy_util.c(2802): AH02824: HTTP: connection established with [::1]:8080 (localhost)
[Wed Jul 01 23:10:45.966781 2020] [proxy:debug] [pid 25640] proxy_util.c(2942): AH00962: HTTP: connection complete to [::1]:8080 (localhost)
[Wed Jul 01 23:10:45.972425 2020] [proxy:debug] [pid 25640] proxy_util.c(2218): AH00943: http: has released connection for (localhost)
The last line says 'http' released connection? is that apache?
[Wed Jul 01 23:10:45.972425 2020] [proxy:debug] [pid 25640] proxy_util.c(2218): AH00943: http: has released connection for (localhost)
Output from apache access_log a 404
174.30.215.226 - - [01/Jul/2020:23:10:45 -0400] "GET /admin/AdminConsole?userName=derricks&source=web HTTP/1.1" 404 473 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:77.0) Gecko/20100101 Firefox/77.0" 1611 1025
It appears that maybe apache is dropping the connection? But why?
I removed the reverse proxy connecting to tomcat directly at URL:8080 and the websockets were fine.
It appears Apache reverse-proxy from 2.2 to 2.4 is screwing the pooch.
Edit # 1
Here are the logs (LogLevel debug)of a working 2.2 server and my new 2.4 server during revers proxy
This is the new server
[Thu Jul 02 13:39:27.812027 2020] [proxy_fcgi:debug] [pid 53009] mod_proxy_fcgi.c(972): [client 174.30.215.226:38854] AH01076: url: http://localhost:8080/admin/AdminConsole?userName=derricks&source=web proxyname: (null) proxyport: 0
[Thu Jul 02 13:39:27.812040 2020] [proxy_fcgi:debug] [pid 53009] mod_proxy_fcgi.c(975): [client 174.30.215.226:38854] AH01077: declining URL http://localhost:8080/admin/AdminConsole?userName=derricks&source=web
[Thu Jul 02 13:39:27.812062 2020] [proxy:debug] [pid 53009] proxy_util.c(2203): AH00942: HTTP: has acquired connection for (localhost)
[Thu Jul 02 13:39:27.812078 2020] [proxy:debug] [pid 53009] proxy_util.c(2256): [client 174.30.215.226:38854] AH00944: connecting http://localhost:8080/admin/AdminConsole?userName=derricks&source=web to localhost:8080
[Thu Jul 02 13:39:27.813819 2020] [proxy:debug] [pid 53009] proxy_util.c(2426): [client 174.30.215.226:38854] AH00947: connected /admin/AdminConsole?userName=derricks&source=web to localhost:8080
[Thu Jul 02 13:39:27.814389 2020] [proxy:debug] [pid 53009] proxy_util.c(2802): AH02824: HTTP: connection established with [::1]:8080 (localhost)
[Thu Jul 02 13:39:27.814476 2020] [proxy:debug] [pid 53009] proxy_util.c(2942): AH00962: HTTP: connection complete to [::1]:8080 (localhost)
[Thu Jul 02 13:39:27.818830 2020] [proxy:debug] [pid 53009] proxy_util.c(2218): AH00943: http: has released connection for (localhost)
[Thu Jul 02 13:39:27.819281 2020] [deflate:debug] [pid 53009] mod_deflate.c(849): [client 174.30.215.226:38854] AH01384: Zlib: Compressed 1096 to 457 : URL /admin/AdminConsole
This is the old working server
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(91): [client 174.30.215.226] canonicalising URL //localhost:8080/admin/AdminConsole
[Thu Jul 02 13:33:11 2020] [debug] proxy_util.c(1508): [client 174.30.215.226] proxy: wss: found worker wss://localhost:8080/admin/AdminConsole for wss://localhost:8080/admin/AdminConsole?userName=derricks&source=web
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy.c(1028): Running scheme wss handler (attempt 0)
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_http.c(1963): proxy: HTTP: declining URL wss://localhost:8080/admin/AdminConsole?userName=derricks&source=web
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(388): [client 174.30.215.226] AH02451: serving URL wss://localhost:8080/admin/AdminConsole?userName=derricks&source=web
[Thu Jul 02 13:33:11 2020] [debug] proxy_util.c(2013): proxy: WSS: has acquired connection for (localhost)
[Thu Jul 02 13:33:11 2020] [debug] proxy_util.c(2069): proxy: connecting wss://localhost:8080/admin/AdminConsole?userName=derricks&source=web to localhost:8080
[Thu Jul 02 13:33:11 2020] [debug] proxy_util.c(2195): proxy: connected /admin/AdminConsole?userName=derricks&source=web to localhost:8080
[Thu Jul 02 13:33:11 2020] [debug] proxy_util.c(2446): proxy: WSS: fam 2 socket created to connect to localhost
[Thu Jul 02 13:33:11 2020] [debug] proxy_util.c(2578): proxy: WSS: connection complete to 127.0.0.1:8080 (localhost)
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(236): [client 174.30.215.226] sending request
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(254): [client 174.30.215.226] setting up poll()
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(299): [client 174.30.215.226] AH02445: woke from poll(), i=1
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(308): [client 174.30.215.226] AH02446: sock was readable
[Thu Jul 02 13:33:11 2020] [debug] mod_proxy_wstunnel.c(175): [client 174.30.215.226] wstunnel_transfer complete
The most obvious difference is the 2.2 working server is proxying to a wss: address while the 2.4 broken server is proxying to a http: address. I don't know if that is a logging bug or an error on the proxy service. I don't see wstunnel being used at all in the broken server?
Edit #2
Finally a brake through of sorts.
I noticed that the proxy_fcgi was being called on the web-socket address and failing, so I removed it's LoadModule and now proxy_wstunnel was called though it failed with a [Hint: SSLProxyEngine]
So I enabled SSProxyEngine at the top of the reverseProxy.conf
SSLProxyEngine on
It now gets even farther, actually connecting the websocket but it fails in the SSL module:
Here is the log
[Thu Jul 02 17:55:49.180768 2020] [proxy:debug] [pid 61402] mod_proxy.c(1123): [client 174.30.215.226:42470] AH01143: Running scheme wss handler (attempt 0)
[Thu Jul 02 17:55:49.180823 2020] [proxy_http:debug] [pid 61402] mod_proxy_http.c(1930): [client 174.30.215.226:42470] AH01113: HTTP: declining URL wss://localhost:8080/AdminConsole?userName=derricks&source=web
[Thu Jul 02 17:55:49.180842 2020] [proxy_scgi:debug] [pid 61402] mod_proxy_scgi.c(517): [client 174.30.215.226:42470] AH00865: declining URL wss://localhost:8080/AdminConsole?userName=derricks&source=web
[Thu Jul 02 17:55:49.180857 2020] [proxy_wstunnel:debug] [pid 61402] mod_proxy_wstunnel.c(336): [client 174.30.215.226:42470] AH02451: serving URL wss://localhost:8080/AdminConsole?userName=derricks&source=web
[Thu Jul 02 17:55:49.180874 2020] [proxy:debug] [pid 61402] proxy_util.c(2203): AH00942: WSS: has acquired connection for (localhost)
[Thu Jul 02 17:55:49.180889 2020] [proxy:debug] [pid 61402] proxy_util.c(2256): [client 174.30.215.226:42470] AH00944: connecting wss://localhost:8080/AdminConsole?userName=derricks&source=web to localhost:8080
[Thu Jul 02 17:55:49.182986 2020] [proxy:debug] [pid 61402] proxy_util.c(2426): [client 174.30.215.226:42470] AH00947: connected /AdminConsole?userName=derricks&source=web to localhost:8080
[Thu Jul 02 17:55:49.183216 2020] [proxy:debug] [pid 61402] proxy_util.c(2802): AH02824: WSS: connection established with [::1]:8080 (localhost)
[Thu Jul 02 17:55:49.183269 2020] [proxy:debug] [pid 61402] proxy_util.c(2942): AH00962: WSS: connection complete to [::1]:8080 (localhost)
[Thu Jul 02 17:55:49.183293 2020] [ssl:info] [pid 61402] [remote ::1:8080] AH01964: Connection to child 0 established (server mbepapers.org:443)
[Thu Jul 02 17:55:49.188928 2020] [ssl:info] [pid 61402] [remote ::1:8080] AH02003: SSL Proxy connect failed
[Thu Jul 02 17:55:49.189045 2020] [ssl:info] [pid 61402] SSL Library Error: error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
[Thu Jul 02 17:55:49.189063 2020] [ssl:info] [pid 61402] [remote ::1:8080] AH01998: Connection closed to child 0 with abortive shutdown (server mbepapers.org:443)
[Thu Jul 02 17:55:49.189113 2020] [ssl:info] [pid 61402] [remote ::1:8080] AH01997: SSL handshake failed: sending 502
[Thu Jul 02 17:55:49.189154 2020] [proxy_wstunnel:debug] [pid 61402] mod_proxy_wstunnel.c(257): [client 174.30.215.226:42470] AH02445: woke from poll(), i=1
[Thu Jul 02 17:55:49.189167 2020] [proxy_wstunnel:debug] [pid 61402] mod_proxy_wstunnel.c(266): [client 174.30.215.226:42470] AH02446: sock was readable
[Thu Jul 02 17:55:49.189180 2020] [proxy_wstunnel:debug] [pid 61402] mod_proxy_wstunnel.c(131): (103)Software caused connection abort: [client 174.30.215.226:42470] AH02442: error on sock - ap_get_brigade
[Thu Jul 02 17:55:49.189234 2020] [proxy:debug] [pid 61402] proxy_util.c(2218): AH00943: WSS: has released connection for (localhost)
Almost there!!!! now proxy.c is Running the wss sceme and the address of the URL is
wss://localhost:8080/AdminConsole?userName=derricks&source=web
Which is the URL my client has always sent!
The error is in the SSL module
[Thu Jul 02 23:53:57.947613 2020] [ssl:info] [pid 7910] [remote ::1:8080] AH02003: SSL Proxy connect failed
[Thu Jul 02 23:53:57.947758 2020] [ssl:info] [pid 7910] SSL Library Error: error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
[Thu Jul 02 23:53:57.947778 2020] [ssl:info] [pid 7910] [remote ::1:8080] AH01998: Connection closed to child 0 with abortive shutdown (server mbepapers.org:443)
[Thu Jul 02 23:53:57.948036 2020] [ssl:info] [pid 7910] [remote ::1:8080] AH01997: SSL handshake failed: sending 502
SSL Library Error: error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
Looking for a solution???
edit 3
I can connect to this server using https:/IP because the old server that this is replacing is using the correct DNS IP<-> domain name. I installed the certificates form that server becasue I will be swapping IP's soon. I wonder if that is the reason for the error?
edit 4
Still looking for a solution to this. When I try to proxy the websocket I get this error in the httpd error_log with loglevel debug
[Sat Jul 11 14:27:23.978213 2020] [proxy:debug] [pid 9147] mod_proxy.c(1123): [client 174.30.215.226:54434] AH01143: Running scheme wss handler (attempt 0)
[Sat Jul 11 14:27:23.978266 2020] [proxy_wstunnel:debug] [pid 9147] mod_proxy_wstunnel.c(336): [client 174.30.215.226:54434] AH02451: serving URL wss://localhost:8080/admin/AdminConsole?userName=derricks&source=app
[Sat Jul 11 14:27:23.978302 2020] [proxy:debug] [pid 9147] proxy_util.c(2203): AH00942: WSS: has acquired connection for (localhost)
[Sat Jul 11 14:27:23.978323 2020] [proxy:debug] [pid 9147] proxy_util.c(2256): [client 174.30.215.226:54434] AH00944: connecting wss://localhost:8080/admin/AdminConsole?userName=derricks&source=app to localhost:8080
[Sat Jul 11 14:27:23.980603 2020] [proxy:debug] [pid 9147] proxy_util.c(2426): [client 174.30.215.226:54434] AH00947: connected /admin/AdminConsole?userName=derricks&source=app to localhost:8080
[Sat Jul 11 14:27:23.981093 2020] [proxy:debug] [pid 9147] proxy_util.c(2802): AH02824: WSS: connection established with [::1]:8080 (localhost)
[Sat Jul 11 14:27:23.981205 2020] [proxy:debug] [pid 9147] proxy_util.c(2942): AH00962: WSS: connection complete to [::1]:8080 (localhost)
[Sat Jul 11 14:27:23.981355 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH01964: Connection to child 0 established (server www.mbepapers.org:443)
[Sat Jul 11 14:27:23.983594 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH02003: SSL Proxy connect failed
[Sat Jul 11 14:27:23.983814 2020] [ssl:info] [pid 9147] SSL Library Error: error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
[Sat Jul 11 14:27:23.983871 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH01998: Connection closed to child 0 with abortive shutdown (server www.mbepapers.org:443)
[Sat Jul 11 14:27:23.983907 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH01997: SSL handshake failed: sending 502
[Sat Jul 11 14:27:23.983969 2020] [proxy_wstunnel:debug] [pid 9147] mod_proxy_wstunnel.c(257): [client 174.30.215.226:54434] AH02445: woke from poll(), i=1
[Sat Jul 11 14:27:23.984005 2020] [proxy_wstunnel:debug] [pid 9147] mod_proxy_wstunnel.c(266): [client 174.30.215.226:54434] AH02446: sock was readable
[Sat Jul 11 14:27:23.984019 2020] [proxy_wstunnel:debug] [pid 9147] mod_proxy_wstunnel.c(131): (103)Software caused connection abort: [client 174.30.215.226:54434] AH02442: error on sock - ap_get_brigade
[Sat Jul 11 14:27:23.984092 2020] [proxy:debug] [pid 9147] proxy_util.c(2218): AH00943: WSS: has released connection for (localhost)
the pertinent lines
[Sat Jul 11 14:27:23.983594 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH02003: SSL Proxy connect failed
[Sat Jul 11 14:27:23.983814 2020] [ssl:info] [pid 9147] SSL Library Error: error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
[Sat Jul 11 14:27:23.983871 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH01998: Connection closed to child 0 with abortive shutdown (server www.mbepapers.org:443)
[Sat Jul 11 14:27:23.983907 2020] [ssl:info] [pid 9147] [remote ::1:8080] AH01997: SSL handshake failed: sending 502
It was suggested I move the reverse proxy inside the vhost section so here that is
<VirtualHost xx.xx.xx.xx:443>
RewriteEngine on
ServerName www.mbepapers.org
ServerAlias www.mbepapers.org
SSLEngine on
SSLProxyEngine on
SSLCertificateFile /var/www/httpd-cert/mbepapers.org.crt
SSLCertificateKeyFile /var/www/httpd-cert/mbepapers.org.key
SSLCertificateChainFile /var/www/httpd-cert/intermediate.crt
SSLCaCertificateFile /var/www/httpd-cert/intermediate.crt
ProxyRequests off
<Location "/admin/AdminConsole">
ProxyPass wss://localhost:8080/admin/AdminConsole
ProxyPassReverse wss://localhost:8080/admin/AdminConsole
Require all granted
</Location>
Well the fix was very simple. I changed the reverseproxy to use the un-secure websocket connection to my tomcat server
this caused a failure in SSL proxy authentication
this circumvents the need for SSL proxy authentication
From the client I am using the secure websocket address which apache now proxys to a unsecure websocket. This is ok because I'm secure across the internet, and only unsecure on my local host.
here is the connection address on the client
Still odd that apache 2.2 had no problem, but 2.4.6 does. Though I read a few posts that indicated 2.4.6 had problems with secure proxy.