I have a Ruby on Rails 3.2 app with the websocket-rails gem, running in a thin webserver behind a nginx reverse proxy.
Except for the nginx reverse proxy, everything works just fine. By removing the nginx reverse proxy, the websocket communication works just fine. (both development and production). Using nginx as a reverse proxy for the websockets is where the problem starts.
Nginx version 1.3.13 and up should be able to support websocket proxying. Based on the docs here and here I created the following nginx config:
map $http_upgrade $connection_upgrade {
default upgrade;
'' close;
}
upstream ravecy {
server localhost:3000;
server localhost:3001;
}
server {
listen 80;
server_name test.ravecy.com;
root /var/www/ravecy.com/public;
location / {
try_files $uri @ravecy;
}
location @ravecy {
proxy_pass http://ravecy;
proxy_http_version 1.1;
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $connection_upgrade;
proxy_set_header Host $host;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_redirect off;
}
}
Sadly, however, this doesn't work. I don't exactly know why, but it seems to me that nginx isn't handling my websocket connection attempts as websocket connections but regular HTTP connections, as seen from the logs:
==> production.log <==
Started GET "/chat" for 82.170.121.62 at 2013-04-10 12:20:12 +0200
Processing by ApplicationController#chat as HTML
Rendered application/chat.html.erb within layouts/frontend (0.2ms)
Rendered layouts/frontend/_navbar.html.erb (6.3ms)
Rendered layouts/shared/_alert.html.erb (0.0ms)
Rendered layouts/frontend/_facebook_sdk.html.erb (0.0ms)
Completed 200 OK in 9ms (Views: 8.4ms | ActiveRecord: 0.4ms)
Started GET "/websocket" for 82.170.121.62 at 2013-04-10 12:20:12 +0200
==> websocket_rails.log <==
I [2013-04-10 12:20:12.744] [ConnectionManager] Connection opened: #<Connnection::47398780>
I [2013-04-10 12:20:12.745] [Dispatcher] Started Event: client_connected
I [2013-04-10 12:20:12.745] [Dispatcher] Name: client_connected
I [2013-04-10 12:20:12.745] [Dispatcher] Data: {"connection_id"=>47398780}
I [2013-04-10 12:20:12.745] [Dispatcher] Connection: #<Connnection::47398780>
I [2013-04-10 12:20:12.747] [Dispatcher] Event client_connected Finished in 0.001960819 seconds
==> /var/log/nginx/access.log <==
82.170.121.62 - - [10/Apr/2013:12:20:12 +0200] "GET /chat HTTP/1.1" 200 854 "http://test.ravecy.com/posts" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/536.26.17 (KHTML, like Gecko) Version/6.0.2 Safari/536.26.17"
82.170.121.62 - - [10/Apr/2013:12:20:12 +0200] "GET /assets/frontend-6ad91089203a6026624ce015c2800492.css HTTP/1.1" 304 0 "http://test.ravecy.com/chat" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/536.26.17 (KHTML, like Gecko) Version/6.0.2 Safari/536.26.17"
82.170.121.62 - - [10/Apr/2013:12:20:12 +0200] "GET /assets/frontend-98fa493fc9f482c0d44b31bda5a89135.js HTTP/1.1" 304 0 "http://test.ravecy.com/chat" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/536.26.17 (KHTML, like Gecko) Version/6.0.2 Safari/536.26.17"
==> websocket_rails.log <==
I [2013-04-10 12:20:12.832] [ConnectionManager] Connection closed: #<Connnection::47398780>
I [2013-04-10 12:20:12.832] [Dispatcher] Started Event: client_disconnected
I [2013-04-10 12:20:12.832] [Dispatcher] Name: client_disconnected
I [2013-04-10 12:20:12.832] [Dispatcher] Data: nil
I [2013-04-10 12:20:12.832] [Dispatcher] Connection: #<Connnection::47398780>
I [2013-04-10 12:20:12.833] [Dispatcher] Event client_disconnected Finished in 0.000293462 seconds
==> /var/log/nginx/access.log <==
82.170.121.62 - - [10/Apr/2013:12:20:12 +0200] "GET /websocket HTTP/1.1" 200 398 "-" "-"
Note that the connection is closed within 100ms, even though it should be kept alive.
Further configs: nginx.conf:
user www-data;
worker_processes 4;
pid /run/nginx.pid;
events {
worker_connections 768;
}
http {
sendfile on;
tcp_nopush on;
tcp_nodelay on;
keepalive_timeout 65;
types_hash_max_size 2048;
include /etc/nginx/mime.types;
default_type application/octet-stream;
access_log /var/log/nginx/access.log;
error_log /var/log/nginx/error.log;
gzip on;
gzip_disable "msie6";
include /etc/nginx/conf.d/*.conf;
include /etc/nginx/sites-enabled/*;
}
thin config:
---
chdir: /var/www/ravecy.com
environment: production
address: 127.0.0.1
port: 3000
timeout: 30
log: log/thin.log
pid: tmp/pids/thin.pid
max_conns: 1024
max_persistent_conns: 100
require: []
wait: 30
servers: 2
daemonize: true
nginx version: nginx/1.3.15 url to live example: http://test.ravecy.com/chat
Also note: upon executing new WebSocket("ws://test.ravecy.com/websocket")
in the JS console,
the browser prompts "Unexpected response code: 200".
I'm pretty desperate to make this work and no longer know what I should do.
Telnet results NGINX:
GET /websocket HTTP/1.1
Host: test.ravecy.com
Connection: Upgrade
Upgrade: WebSocket
HTTP/1.1 200 OK
Server: nginx/1.3.15
Date: Sat, 13 Apr 2013 19:50:35 GMT
Content-Type: text/json
Transfer-Encoding: chunked
Connection: keep-alive
152
[["client_connected",{"id":null,"channel":null,"data":{"connection_id":37160040},"success":null,"result":null,"server_token":null}]][["users",{"id":null,"channel":null,"data":[],"success":null,"result":null,"server_token":null}]][["client_connected",{"id":null,"channel":null,"data":{},"success":false,"result":null,"server_token":null}]]
Telnet results direct to thin:
GET /websocket HTTP/1.1
Host: test.ravecy.com
Connection: Upgrade
Upgrade: WebSocket
HTTP/1.1 101 Web Socket Protocol Handshake
Upgrade: WebSocket
Connection: Upgrade
WebSocket-Origin:
WebSocket-Location: ws://test.ravecy.com/websocket
[["client_connected",{"id":null,"channel":null,"data":{"connection_id":37489460},"success":null,"result":null,"server_token":null}]][["users",{"id":null,"channel":null,"data":[],"success":null,"result":null,"server_token":null}]][["client_connected",{"id":null,"channel":null,"data":{},"success":false,"result":null,"server_token":null}]]
Obviously, this is were stuff goes wrong. But why?