Not a Passenger Issue (was: Standalone w/ Nginx engine responds 502 to requests for Webpacker assets when Webpack Dev Server compression is disabled)

[cmbankester]

Issue report

Question 1: What is the problem?

• What is the expected behavior?
  • Server should respond with the requested asset
• What is the actual behavior?
  • Server responds with 502 status and "Incomplete response received from application" message
• How can we reproduce it? Please try to provide a sample application (or Virtual Machine) demonstrating the issue. Otherwise, if we can't reproduce it, we might have to ask you a number of followup questions or run certain commands to try and figure out the problem.
  1. Create new Rails application with webpacker support (e.g. rails new testapp --skip-puma --webpack)
  2. Change the development.dev_server.compress setting from true to false in config/webpacker.yml
  3. Start Webpack dev server (e.g. ./bin/webpack-dev-server)
  4. Start Passenger standalone server in development (e.g. passenger start -a 0.0.0.0 -p 3000)
  5. Attempt to GET the application.js Webpacker pack file (e.g. GET localhost:3000/packs/application-8d71e5035f8940a9e3d3.js)

The error that I receive (from log) is:

App 4274 stderr: [ 2018-02-27 17:58:36.5513 4318/0x00005650a354b560(Worker 1) utils.rb ]: *** Exception NoMethodError in Rack response body object (undefined method `to_i' for ["330960"]:Array) (process 4318, thread 0x00005650a354b560(Worker 1)):
App 4274 stderr:        from /usr/lib/ruby/gems/2.4.0/gems/passenger-5.2.0/src/ruby_supportlib/phusion_passenger/rack/thread_handler_extension.rb:209:in `process_body'
App 4274 stderr:        from /usr/lib/ruby/gems/2.4.0/gems/passenger-5.2.0/src/ruby_supportlib/phusion_passenger/rack/thread_handler_extension.rb:146:in `process_request'
App 4274 stderr:        from /usr/lib/ruby/gems/2.4.0/gems/passenger-5.2.0/src/ruby_supportlib/phusion_passenger/request_handler/thread_handler.rb:152:in `accept_and_process_next_request'
App 4274 stderr:        from /usr/lib/ruby/gems/2.4.0/gems/passenger-5.2.0/src/ruby_supportlib/phusion_passenger/request_handler/thread_handler.rb:113:in `main_loop'
App 4274 stderr:        from /usr/lib/ruby/gems/2.4.0/gems/passenger-5.2.0/src/ruby_supportlib/phusion_passenger/request_handler.rb:416:in `block (3 levels) in start_threads'
App 4274 stderr:        from /usr/lib/ruby/gems/2.4.0/gems/passenger-5.2.0/src/ruby_supportlib/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'
[ W 2018-02-27 17:58:36.5514 4238/T8 age/Cor/Con/InternalUtils.cpp:96 ]: [Client 1-3] Sending 502 response: application did not send a complete response

Question 2: Passenger version and integration mode:

Your answer: Open source 5.2.0 standalone (engine: Nginx 1.12.2)

Question 3: OS or Linux distro, platform (including version):

Your answer: Linux version 4.9.75-linuxkit-aufs (root@2f6b74ae1d9a) (gcc version 6.4.0 (Alpine 6.4.0) ) #1 SMP Tue Jan 9 10:58:17 UTC 2018

Question 4: Passenger installation method:

Your answer:
[ ] RubyGems + Gemfile
[x] RubyGems, no Gemfile
[ ] Phusion APT repo
[ ] Phusion YUM repo
[ ] OS X Homebrew
[ ] source tarball
[ ] Other, please specify:

Question 5: Your app's programming language (including any version managers) and framework (including versions):

Your answer: ruby 2.4.3p205 (2017-12-14 revision 61247) [x86_64-linux-musl], Rails 5.1.5, Node.js 8

Question 6: Are you using a PaaS and/or containerization? If so which one?

Your answer: Running inside a Docker (version 18.02.0-ce) container (base image: alpine:3.7)

Question 7: Anything else about your setup that we should know?

Your answer: I first noticed this issue when running OSS Passenger 5.1.11 (Ruby 2.2, Alpine 3.6, Node 8). The issue also happens when Webpack dev server compression is enabled but the requested file is small enough that gzipping does not happen. I was able to determine that the responses that cause the thread_handler_extension.rb#process_body method to fail with the provided error/stack are those that have the Content-Length header set. When Webpack dev server compression is disabled, all of the responses from the dev server have the Content-Length header set. Thus, disabling compression (within the webpacker.yml file) is an easy way to reproduce the issue.

[cmbankester]

Issue remains present in OSS Passenger 5.2.1

[CamJN]

You said you are running this in Docker, would it be too much trouble to get a Dockerfile that reproduces the issue? That'd save a bunch of time.

[cmbankester]

No problem. I just pushed up a repo demonstrating the issue: https://github.com/cmbankester/passenger-issue-demo

[gardelea]

i am not sure if my issue stems from the same root cause however i wanted to chime in here and add that i am seeing this exception when when trying to retrieve an image asset via a webpacker enabled rails app as well. it even happens when development.dev_server.compress is set to true.

my particular setup is in a rails 4.2.10 app, and i can confirm it doesn't work with passenger 5.1.12 as well as 5.2.1.

happy to provide any more information if it is helpful.

[cmbankester]

@gardelea Do you know what the size of the asset you're trying to retrieve is? It's possible that the image is too small to be gzipped. I have the same problem (i.e. with compress set to true) with assets that are too small to be gzipped (in fact that's how I originally discovered this issue).

[gardelea]

@cmbankester yes, the particular image i was tracing is exactly 107,689 bytes.

[cmbankester]

@gardelea I'm able to serve files smaller than that. For me, anything smaller than around 1kilobyte throws the error, and anything larger serves fine.

Also, to reiterate, this is only when compress is turned on. When off, the error happens for all assets served by the dev server.

[bwalding]

I've trawled through a few packages and I think this is being caused by rack-proxy - sending a transformed content-length header as an Array.

Fixed here - ncr/rack-proxy#65 / ncr/rack-proxy#73

Switching to master branch of rack-proxy (in Gemfile) fixed this issue for me.