I'm wondering if anyone else is seeing an frame opcode 12 on socket.disconnect() when using socket.io with mod_proxy_wstunnel. I have a fairly simple replication setup that I'm investigating.
I'm using apache 2.2.25 with a backported mod_proxy_wstunnel patch from 2.4.6. I'm seeing an unexpected frame opcode12 frame when the client or the server drops the websocket. I can only replicate this when going through the mod_http_wstunnel. If I change my client code to talk directly to the websocket on port 8001 I don't see the opcode 12 frame. Here is what my proxy config looks like: <VirtualHost gnu.corp.netapp.com<http://gnu.corp.netapp.com>:80> LogLevel debug ProxyPass /socket.io/1/websocket ws://localhost:8001/socket.io/1/websocket ProxyPassReverse /socket.io/1/websocket ws://localhost:8001/socket.io/1/websocket ProxyPass /socket.io/ http://localhost:8001/socket.io/ ProxyPassReverse /socket.io/ http://localhost:8001/socket.io/ ProxyPass / http://localhost:8080/ ProxyPassReverse / http://localhost:8080/ </VirtualHost> # apache static content <VirtualHost localhost:8080> DocumentRoot /var/www/static <Directory /> Allow from all </Directory> </VirtualHost> Here is what it looks like in Chrome Dev Tools for the websocket connection: Data Length Time ------------------------------------------------------------------ Unrecognized frame opcode: 12 29 5:55:55 PM 0:: 3 5:55:55 PM Connection Close Frame (Opcode 8, mask) 0 5:55:55 PM 0:: 3 5:55:55 PM 5:::{"name":"news","args":[{"hello":"world"}]} 46 5:55:55 PM 3:::Client connected 20 5:55:55 PM 1:: 3 5:55:55 PM error_log doesn't seem to be very interesting here: [Fri Oct 04 16:47:09 2013] [debug] mod_proxy_http.c(56): proxy: HTTP: canonicalising URL //localhost:8080/ [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(1513): [client 10.63.231.202] proxy: http: found worker http://localhost:8080/ for http://localhost:8080/ [Fri Oct 04 16:47:09 2013] [debug] mod_proxy.c(1036): Running scheme http handler (attempt 0) [Fri Oct 04 16:47:09 2013] [debug] mod_proxy_http.c(1974): proxy: HTTP: serving URL http://localhost:8080/ [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2018): proxy: HTTP: has acquired connection for (localhost) [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2074): proxy: connecting http://localhost:8080/ to localhost:8080 [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2200): proxy: connected / to localhost:8080 [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2451): proxy: HTTP: fam 2 socket created to connect to localhost [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2583): proxy: HTTP: connection complete to 127.0.0.1:8080 (localhost) [Fri Oct 04 16:47:09 2013] [debug] mod_proxy_http.c(1744): proxy: start body send [Fri Oct 04 16:47:09 2013] [debug] mod_proxy_http.c(1848): proxy: end body send [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2036): proxy: HTTP: has released connection for (localhost) [Fri Oct 04 16:47:09 2013] [debug] mod_proxy_http.c(56): proxy: HTTP: canonicalising URL //localhost:8001/socket.io/socket.io.js [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(1513): [client 10.63.231.202] proxy: http: found worker http://localhost:8001/socket.io/ for http://localhost:8001/socket.io/socket.io.js, referer: http://gnu.corp.netapp.com/ [Fri Oct 04 16:47:09 2013] [debug] mod_proxy.c(1036): Running scheme http handler (attempt 0) [Fri Oct 04 16:47:09 2013] [debug] mod_proxy_http.c(1974): proxy: HTTP: serving URL http://localhost:8001/socket.io/socket.io.js [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2018): proxy: HTTP: has acquired connection for (localhost) [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2074): proxy: connecting http://localhost:8001/socket.io/socket.io.js to localhost:8001 [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2200): proxy: connected /socket.io/socket.io.js to localhost:8001 [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2451): proxy: HTTP: fam 2 socket created to connect to localhost [Fri Oct 04 16:47:09 2013] [debug] proxy_util.c(2583): proxy: HTTP: connection complete to 127.0.0.1:8001 (localhost) [Fri Oct 04 16:47:10 2013] [debug] mod_proxy_http.c(1744): proxy: start body send [Fri Oct 04 16:47:10 2013] [debug] mod_proxy_http.c(1848): proxy: end body send [Fri Oct 04 16:47:10 2013] [debug] proxy_util.c(2036): proxy: HTTP: has released connection for (localhost) [Fri Oct 04 16:47:10 2013] [debug] mod_proxy_http.c(56): proxy: HTTP: canonicalising URL //localhost:8001/socket.io/1/ [Fri Oct 04 16:47:10 2013] [debug] proxy_util.c(1513): [client 10.63.231.202] proxy: http: found worker http://localhost:8001/socket.io/ for http://localhost:8001/socket.io/1/?t=1380923754926, referer: http://gnu.corp.netapp.com/ [Fri Oct 04 16:47:10 2013] [debug] mod_proxy.c(1036): Running scheme http handler (attempt 0) [Fri Oct 04 16:47:10 2013] [debug] mod_proxy_http.c(1974): proxy: HTTP: serving URL http://localhost:8001/socket.io/1/?t=1380923754926 [Fri Oct 04 16:47:10 2013] [debug] proxy_util.c(2018): proxy: HTTP: has acquired connection for (localhost) [Fri Oct 04 16:47:10 2013] [debug] proxy_util.c(2074): proxy: connecting http://localhost:8001/socket.io/1/?t=1380923754926 to localhost:8001 [Fri Oct 04 16:47:10 2013] [debug] proxy_util.c(2200): proxy: connected /socket.io/1/?t=1380923754926 to localhost:8001 [Fri Oct 04 16:47:10 2013] [debug] mod_proxy_http.c(1744): proxy: start body send [Fri Oct 04 16:47:10 2013] [debug] mod_proxy_http.c(1848): proxy: end body send [Fri Oct 04 16:47:10 2013] [debug] proxy_util.c(2036): proxy: HTTP: has released connection for (localhost) [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(51): [client 10.63.231.202] canonicalising URL //localhost:8001/socket.io/1/websocket/Xjww5htx3meYyb2YMS-T [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(1513): [client 10.63.231.202] proxy: ws: found worker ws://localhost:8001/socket.io/1/websocket for ws://localhost:8001/socket.io/1/websocket/Xjww5htx3meYyb2YMS-T [Fri Oct 04 16:47:11 2013] [debug] mod_proxy.c(1036): Running scheme ws handler (attempt 0) [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_http.c(1964): proxy: HTTP: declining URL ws://localhost:8001/socket.io/1/websocket/Xjww5htx3meYyb2YMS-T [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_scgi.c(508): [client 10.63.231.202] proxy: SCGI: declining URL ws://localhost:8001/socket.io/1/websocket/Xjww5htx3meYyb2YMS-T [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(331): [client 10.63.231.202] AH02451: serving URL ws://localhost:8001/socket.io/1/websocket/Xjww5htx3meYyb2YMS-T [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2018): proxy: WS: has acquired connection for (localhost) [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2074): proxy: connecting ws://localhost:8001/socket.io/1/websocket/Xjww5htx3meYyb2YMS-T to localhost:8001 [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2200): proxy: connected /socket.io/1/websocket/Xjww5htx3meYyb2YMS-T to localhost:8001 [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2387): proxy: WS: backend socket is disconnected. [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2451): proxy: WS: fam 2 socket created to connect to localhost [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2583): proxy: WS: connection complete to 127.0.0.1:8001 (localhost) [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(192): [client 10.63.231.202] sending request [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(210): [client 10.63.231.202] setting up poll() [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(252): [client 10.63.231.202] AH02445: woke from poll(), i=1 [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(261): [client 10.63.231.202] AH02446: sock was readable [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(252): [client 10.63.231.202] AH02445: woke from poll(), i=1 [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(277): [client 10.63.231.202] AH02448: client was readable [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(252): [client 10.63.231.202] AH02445: woke from poll(), i=1 [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(277): [client 10.63.231.202] AH02448: client was readable [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(252): [client 10.63.231.202] AH02445: woke from poll(), i=1 [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(261): [client 10.63.231.202] AH02446: sock was readable [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(252): [client 10.63.231.202] AH02445: woke from poll(), i=1 [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(261): [client 10.63.231.202] AH02446: sock was readable [Fri Oct 04 16:47:11 2013] [debug] mod_proxy_wstunnel.c(294): [client 10.63.231.202] finished with poll() - cleaning up [Fri Oct 04 16:47:11 2013] [debug] proxy_util.c(2036): proxy: WS: has released connection for (localhost) -- Scott Russell Software Architect Customer Success Services (919) 476-8813
