Error with rack-mount and rails 4.2.4

[brauliobo]

The following error happens only with rails 4.2.4 (and rack 1.6) and not on rails 3.2.22 (and rack 1.4):

ERROR["test_should_suggest_event_children", ArticlesTest, 2015-09-10 18:40:02 -0300]
 test_should_suggest_event_children#ArticlesTest (1441921202.61s)
NoMethodError:         NoMethodError: undefined method `[]' for nil:NilClass
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:155:in `block in call'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:96:in `block in recognize'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:68:in `optimized_each'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:95:in `recognize'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:141:in `call'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grape-0.13.0/lib/grape/api.rb:114:in `call'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grape-0.13.0/lib/grape/api.rb:44:in `call!'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/grape-0.13.0/lib/grape/api.rb:39:in `call'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-test-0.6.3/lib/rack/mock_session.rb:30:in `request'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-test-0.6.3/lib/rack/test.rb:244:in `process_request'
            /home/braulio/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/rack-test-0.6.3/lib/rack/test.rb:67:in `post'
            test/unit/api/articles_test.rb:366:in `block in <class:ArticlesTest>'

The error happened because rack-mount is expecting the result of rack call to be an array, but it is a hash (file rack-mount-0.8.3/lib/rack/mount/route_set.rb):

151             
152         result = route.app.call(env) 
153             
154         pp result
155         if result[1][X_CASCADE] == PASS
156           env[@parameters_key] = old_params
157         else
158           return res

It seems that rack-mount is unmaintained for a long time (even the repo was deleted). Have you considered to not depend on it anymore?

cc @diguliu @terceiro

[dblock]

We've discussed rack-mount in #1072, nothing really came out of it, would love to replace it.

Grape did change the response to be a Rack::Response, and this is not supposed to happen, do you have a vanilla project in which we can see this?

[brauliobo]

@dblock yeah, just checkout https://github.com/noosfero/noosfero.git, branch rails4, then run

BACKTRACE=blegga ruby -Itest test/unit/api/articles_test.rb -n /suggest_event_children/

We were using grape 0.13.0, is the change to Rack::Response there?

[dblock]

This was in 0.12.0, https://github.com/ruby-grape/grape/blob/master/UPGRADING.md#upgrading-to--0120, every time an issue like this has come up it seemed like the problem was in rack-mount but it wasn't.

[brauliobo]

@dblock the strange thing is that this is single failing test, among many others. I don't see any grape's middleware used.

[brauliobo]

@dblock an exception is happening! and as it happens it crashes the rack-mount! Do you know why?

[dblock]

Lets reopen this, I'll take a look when I have a few.

[brauliobo]

@dblock it didn't happen on rails 3.2, so maybe it is a new way rails4.2/rack1.6 is issuing exceptions

[dblock]

This test passes on my machine, I have updated Grape to 0.13. How do I reproduce the problem?

~/source/noosfero/noosfero (rails4)$ BACKTRACE=blegga ruby -Itest test/unit/api/articles_test.rb -n /suggest_event_children/
Started with run options -n /suggest_event_children/ --seed 37437

  1/1: [==================================================================================================================] 100% Time: 00:00:01, Time: 00:00:01

Finished in 1.74757s
1 tests, 2 assertions, 0 failures, 0 errors, 0 skips
~/source/noosfero/noosfero (rails4)$ bundle show rails
/Users/dblock/.rvm/gems/ruby-2.1.2/gems/rails-4.2.4
~/source/noosfero/noosfero (rails4)$ bundle show grape
/Users/dblock/.rvm/gems/ruby-2.1.2/gems/grape-0.13.0

[brauliobo]

@dblock we fixed the exception that was happening on the AR model. Maybe we can make a test to reproduce this inside grape.

[brauliobo]

@dblock maybe a simple raise 'here' somewhere in the model or maybe even in the api classes is enough

[dblock]

Do you have a commit or a way to put back the exception?

[dblock]

The problem is this:

      rescue_from :all do |e|
        logger.error e
      end

If you rescue an error you're not supposed to swallow it. It's clearly not well documented, but what's happening here is that logger.error ... just returns true, so the result from the middleware is [true, nil, nil], which isn't what Rack expects.

Help me edit the README to explain this?

A simple fix is

rescue_from :all

This causes the following response:

[500, {"Content-Type"=>"application/json", ...]

If you want to log, you want something like this:

rescue_from :all do |e|
   logger....
   error! e.message, 500
end

You definitely want to fix this in your codebase or unexpected errors will never be returned to the API clients. Write a test that causes an exception and makes sure the error is valid JSON for example.