The nginx+passenger bundle strangely returns JSON

Question

Nginx

Good day.
Used a bunch of nginx + unicorn, everything was fine. I decided to try nginx+passenger and suddenly a strange bug appeared.
The server returns the main page and resources (HTML, CSS, JS) normally. But if you request any JSON content via AJAX (such as /notes.json), then the server swears with a “502 Bad Gateway” error. At the same time, if you go directly to the same /notes.json browser, then this one is returned normally and the status is “304 Not Modified”. This was not the case with Unicorn, it appeared with Passenger.
The config is almost standard, taken from here .
Does anyone happen to know what the heck this could be?

nginx config:

user www-data;
worker_processes 4;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

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 /srv/common/log/nginx.access.log;
        error_log /srv/common/log/nginx.error.log;

        gzip on;
        gzip_disable "msie6";

        passenger_root /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5;
        passenger_ruby /usr/local/bin/ruby;

        server {
                server_name notes-test.com;
                listen 80;

                root /srv/notes-test.com/public;

                passenger_enabled on;
                rails_env development;
        }
}

The nginx logs show the following errors:

2013/06/08 15:18:24 [error] 28034#0: *213 upstream prematurely closed connection while reading response header from upstream, client: 188.186.31.209, server: notes-test.com, request: "GET /note_groups.json HTTP/1.1", upstream: "passenger:/tmp/passenger.1.0.28014/generation-0/request:", host: "notes-test.com", referrer: "http://notes-test.com/notes"
2013/06/08 15:18:24 [error] 28034#0: *212 upstream prematurely closed connection while reading response header from upstream, client: 188.186.31.209, server: notes-test.com, request: "GET /notes.json HTTP/1.1", upstream: "passenger:/tmp/passenger.1.0.28014/generation-0/request:", host: "notes-test.com", referrer: "http://notes-test.com/notes"
2013/06/08 15:19:21 [error] 28642#0: *17 upstream prematurely closed connection while reading response header from upstream, client: 188.186.31.209, server: notes-test.com, request: "GET /notes.json HTTP/1.1", upstream: "passenger:/tmp/passenger.1.0.28622/generation-0/request:", host: "notes-test.com", referrer: "http://notes-test.com/notes"
2013/06/08 15:19:21 [error] 28642#0: *20 upstream prematurely closed connection while reading response header from upstream, client: 188.186.31.209, server: notes-test.com, request: "GET /note_groups.json HTTP/1.1", upstream: "passenger:/tmp/passenger.1.0.28622/generation-0/request:", host: "notes-test.com", referrer: "http://notes-test.com/notes"

Conclusion passenger-status --show=backtraces:

Thread 'MultiLibeio dispatcher' (0x2b0179484700, LWP 28626):
     (empty)

Thread 'Pool analytics collector' (0x2b01794c6700, LWP 28626):
     in 'static void Passenger::ApplicationPool2::Pool::collectAnalytics(Passenger::ApplicationPool2::PoolPtr)' (Pool.h:656)

Thread 'Pool garbage collector' (0x2b0179507700, LWP 28626):
     in 'static void Passenger::ApplicationPool2::Pool::garbageCollect(Passenger::ApplicationPool2::PoolPtr)' (Pool.h:541)

Thread 'MessageServer thread' (0x2b017b42d700, LWP 28626):
     in 'void Passenger::MessageServer::mainLoop()' (MessageServer.h:534)

Thread 'Pool event loop' (0x2b017bc2e700, LWP 28626):
     (empty)

Thread 'Request event loop' (0x2b017c42f700, LWP 28626):
     (empty)

Thread 'Group process spawner: /srv/notes-test.com#default' (0x2b017c4f2700, LWP 28635):
     in 'std::string Passenger::ApplicationPool2::Spawner::readMessageLine(Details&) [with Details = Passenger::ApplicationPool2::SmartSpawner::StartupDetails, std::string = std::basic_string<char>]' (Spawner.h:719)
     in 'std::string Passenger::ApplicationPool2::SmartSpawner::negotiatePreloaderStartup(Passenger::ApplicationPool2::SmartSpawner::StartupDetails&)' (SmartSpawner.h:558)
     in 'void Passenger::ApplicationPool2::SmartSpawner::startPreloader()' (SmartSpawner.h:206)
     in 'virtual Passenger::ApplicationPool2::ProcessPtr Passenger::ApplicationPool2::SmartSpawner::spawn(const Passenger::ApplicationPool2::Options&)' (SmartSpawner.h:744)
     in 'void Passenger::ApplicationPool2::Group::spawnThreadRealMain(const Passenger::ApplicationPool2::SpawnerPtr&, const Passenger::ApplicationPool2::Options&, unsigned int)' (Implementation.cpp:707)

Thread 'Background I/O capturer' (0x2b017c503700, LWP 30093):
     in 'void Passenger::ApplicationPool2::Spawner::BackgroundIOCapturer::capture()' (Spawner.h:132)

Thread 'MessageServer client thread 20' (0x2b017c67d700, LWP 28633):
     in 'virtual bool Passenger::BacktracesServer::processMessage(Passenger::MessageServer::CommonClientContext&, Passenger::MessageServer::ClientContextPtr&, const std::vector<std::basic_string<char> >&)' (BacktracesServer.h:48)
     in 'void Passenger::MessageServer::clientHandlingMainLoop(Passenger::FileDescriptor)' (MessageServer.h:467)

Answer 1

Thanks to everyone for the tips, I turned on the passenger's log and saw an error in it:

[ 2013-06-09 17:35:23.4363 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr] /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:109:in `block in process_request': undefined method `each' for nil:NilClass (NoMethodError)
[ 2013-06-09 17:35:23.4363 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/rack-1.4.5/lib/rack/utils.rb:398:in `block in each'
[ 2013-06-09 17:35:23.4363 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/rack-1.4.5/lib/rack/utils.rb:397:in `each'
[ 2013-06-09 17:35:23.4363 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/rack-1.4.5/lib/rack/utils.rb:397:in `each'
[ 2013-06-09 17:35:23.4364 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:101:in `process_request'
[ 2013-06-09 17:35:23.4364 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request'
[ 2013-06-09 17:35:23.4364 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop'
[ 2013-06-09 17:35:23.4364 23937/2b427687e700 Pool2/Implementation.cpp:1174 ]: [App 23978 stderr]       from /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads'

In the /usr/local/lib/ruby/gems/2.0.0/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb file, I added a check for nil on the indicated line and it all worked.

Answer 2

passenger_log_level 3;
passenger_debug_log_file /var/log/passenger.log;

Answer 3

Try how to increase the buffer here .

Answer 4

use to json viewer to analyze your json data