Nginx, Rails and Oauth. upstream prematurely close

问题:

I have a strange problem that appears in production environment only when I use nginx and unicorn. When I use unicorn without nginx, it doesn't happen.

The problem. I have a simple oauth authentication which allows users to signup through GitHub. After pressing "allow" on GitHub's authorization page, the user is being redirected to callback route. And then, he/she gets 302 Bad Gateway error. Nginx log shows me this error (keys are replaced by "...")

2012/12/26 18:03:08 [error] 1467#0: *1 upstream prematurely closed connection while reading response header from upstream, client: 10.0.2.2, server: _, request: "GET /auth/github/callback?code=&state=... HTTP/1.1", upstream: "http://unix:/tmp/unicorn.tm.sock:/auth/github/callback?code=...&state=...", host: "localhost:3000"

Ther is my nginx config.

upstream unicorn {
  server unix:/tmp/unicorn.tm.sock fail_timeout=0;
}

server {
  listen 80 default deferred;

  client_max_body_size 4G;
  server_name _;

  keepalive_timeout 75s;

  proxy_connect_timeout 60s;
  proxy_read_timeout 60s;


  root /vagrant/public;

  try_files $uri/index.html $uri.html $uri @app;

  location @app {
    proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    proxy_set_header Host $http_host;

    proxy_redirect off;

    proxy_pass http://unicorn;

    proxy_buffer_size 16k;
    proxy_busy_buffers_size 16k;
  }

  error_page 500 502 503 504 /500.html;
}

So my question is why does this happen and is there any possible fix for it?

I have been googling it for a while, but without luck.

update

Thanks for the comment, I have just tried to set fail_timeout=30s and it does help, however request takes about 40s to complete. But thanks anyway, I'll try to expirement with this parameters.

I updated my config a bit, according to suggestions, but still, get the same error.

Also, this is unicorn error log. Seems like it kills request which takes longer than 30s but I guess redirection from oauth site cannot possibly be that long...

(github) Request phase initiated.
(github) Callback phase initiated.
E, [2012-12-26T19:33:13.058183 #6002] ERROR -- : worker=0 PID:6005 timeout (31s > 30s), killing
E, [2012-12-26T19:33:13.067011 #6002] ERROR -- : reaped #<Process::Status: pid 6005 SIGKILL (signal 9)> worker=0
I, [2012-12-26T19:33:13.067198 #6002]  INFO -- : worker=0 spawning...
I, [2012-12-26T19:33:13.068631 #6012]  INFO -- : worker=0 spawned pid=6012
I, [2012-12-26T19:33:13.068726 #6012]  INFO -- : Refreshing Gem list
I, [2012-12-26T19:33:17.140948 #6012]  INFO -- : worker=0 ready

unicorn config

rails_env = ENV['RAILS_ENV'] || 'production'

worker_processes 1

listen "/tmp/unicorn.tm.sock", :backlog => 64
listen 8080, :tcp_nopush => true

timeout 30

pid "/tmp/unicorn.pid"

stderr_path "/tmp/unicorn.log"
stdout_path "/tmp/unicorn.log"

check_client_connection false

回答1:

ERROR -- : worker=0 PID:6005 timeout (31s > 30s), killing

It goes without saying that you just need setup timeout to more then 30 in you unicorn config

Try at least

timeout 60

http://unicorn.bogomips.org/Unicorn/Configurator.html#method-i-timeout