substancelab/route_downcaser

In downcase_route_middleware.rb:33 in "uri_items": NoMethodError: undefined method `split' for nil:NilClass

Closed this issue · 11 comments

I got this error in my production environment last night. It's only occurred once so far but I figured it might be good to log anyway.

As you can see, the env['REQUEST_URI'] exists but the line that caused the error doesn't think so.
Is it possible the @env was not set to env in def call(env)?

Environment (anonymized):

CONTENT_TYPE
text/plain
GATEWAY_INTERFACE
CGI/1.2
HTTP_ACCEPT
*/*
HTTP_ACCEPT_ENCODING
gzip, deflate
HTTP_ACCEPT_LANGUAGE
en;q=1
HTTP_CONNECTION
close
HTTP_HOST
throwdown.us
HTTP_IF_NONE_MATCH
"xxxxx"
HTTP_USER_AGENT
xxxxx
HTTP_VERSION
HTTP/1.0
HTTP_X_FORWARDED_FOR
xxxxx
HTTP_X_FORWARDED_PROTO
https
HTTP_X_REAL_IP
xxxxx
ORIGINAL_FULLPATH
/users.json?token=xxxxx
ORIGINAL_SCRIPT_NAME
PATH_INFO
/users.json
QUERY_STRING
token=xxxxx
REMOTE_ADDR
127.0.0.1
REQUEST_METHOD
GET
REQUEST_PATH
/users.json
REQUEST_URI
/users.json?token=xxxxx
ROUTES_58746340_SCRIPT_NAME
SCRIPT_NAME
SERVER_NAME
xxxxx
SERVER_PORT
443
SERVER_PROTOCOL
HTTP/1.1
SERVER_SOFTWARE
2.8.2
action_dispatch.cookies_serializer
action_dispatch.parameter_filter
["password"]
action_dispatch.redirect_filter
[]
action_dispatch.remote_ip
xxxxx
action_dispatch.request_id
xxxxx
action_dispatch.show_detailed_exceptions
false
action_dispatch.show_exceptions
true
newrelic.captured_request
true
puma.config
#<Puma::Configuration:0x00000001c8f388>
puma.socket
#<UNIXSocket:0x007fa5ce044c70>
rack.after_reply
[]
rack.hijack
#<Puma::Client:0x007fa5ce044c48>
rack.hijack?
true
rack.multiprocess
false
rack.multithread
true
rack.request.query_hash
{
  "token": "xxxxx"
}
rack.request.query_string
token=xxxxx
rack.run_once
false
rack.url_scheme
http
rack.version
["1", "2"]

Backtrace:

/gems/route_downcaser-0.2.2/lib/route_downcaser/downcase_route_middleware.rb:33 in "uri_items"
/gems/route_downcaser-0.2.2/lib/route_downcaser/downcase_route_middleware.rb:37 in "path"
/gems/route_downcaser-0.2.2/lib/route_downcaser/downcase_route_middleware.rb:46 in "downcased_uri"
/gems/route_downcaser-0.2.2/lib/route_downcaser/downcase_route_middleware.rb:16 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/warden-1.2.3/lib/warden/manager.rb:35 in "block in call"
/gems/warden-1.2.3/lib/warden/manager.rb:34 in "catch"
/gems/warden-1.2.3/lib/warden/manager.rb:34 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/etag.rb:23 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/conditionalget.rb:25 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/head.rb:11 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/params_parser.rb:27 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/flash.rb:254 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/session/abstract/id.rb:225 in "context"
/gems/rack-1.5.2/lib/rack/session/abstract/id.rb:220 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/cookies.rb:560 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/activerecord-4.1.0/lib/active_record/query_cache.rb:36 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/activerecord-4.1.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:621 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/callbacks.rb:29 in "block in call"
/gems/activesupport-4.1.0/lib/active_support/callbacks.rb:82 in "run_callbacks"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/callbacks.rb:27 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/remote_ip.rb:76 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/debug_exceptions.rb:17 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/show_exceptions.rb:30 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/railties-4.1.0/lib/rails/rack/logger.rb:38 in "call_app"
/gems/railties-4.1.0/lib/rails/rack/logger.rb:20 in "block in call"
/gems/activesupport-4.1.0/lib/active_support/tagged_logging.rb:68 in "block in tagged"
/gems/activesupport-4.1.0/lib/active_support/tagged_logging.rb:26 in "tagged"
/gems/activesupport-4.1.0/lib/active_support/tagged_logging.rb:68 in "tagged"
/gems/railties-4.1.0/lib/rails/rack/logger.rb:20 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-4.1.0/lib/action_dispatch/middleware/request_id.rb:21 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/methodoverride.rb:21 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/runtime.rb:17 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/activesupport-4.1.0/lib/active_support/cache/strategy/local_cache_middleware.rb:26 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.5.2/lib/rack/sendfile.rb:112 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/railties-4.1.0/lib/rails/engine.rb:514 in "call"
/gems/railties-4.1.0/lib/rails/application.rb:144 in "call"
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/puma-2.8.2/lib/puma/configuration.rb:71 in "call"
/gems/puma-2.8.2/lib/puma/server.rb:490 in "handle_request"
/gems/puma-2.8.2/lib/puma/server.rb:361 in "process_client"
/gems/puma-2.8.2/lib/puma/server.rb:254 in "block in run"
/gems/puma-2.8.2/lib/puma/thread_pool.rb:92 in "call"
/gems/puma-2.8.2/lib/puma/thread_pool.rb:92 in "block in spawn_thread"

That is very strange indeed. You have supplied the backtrace but not the error. I assume it's a nil-something error, but I would like to know anyway.

Also there are 3 "unknowns" in this setup: puma, new_relic, and Rails 4.1. Rails has only been tested up to 4.0, and I have not tried to run route_downcaser with neither puma nor new_relic.

Ah I put the error in the title but just to be clear:
NoMethodError: undefined method 'split' for nil:NilClass in [GEM_ROOT]/gems/route_downcaser-0.2.2/lib/route_downcaser/downcase_route_middleware.rb:33

Yes I wasn't sure if the puma + new_relic setup would have an impact but overall it's been working great. Also didn't know about the 4.0 restriction.

I have to say it's an odd error, I've hit the same endpoint to try and reproduce the error butnot getting anything, so it might not be a bug?
Perhaps adding a safety check for nil values to cover it happening; I don't know how you feel about those (some people don't like extra checks).

And you did indeed, I just didn't use my eyes... :-)

Well it's not a restriction as such. I just haven't setup tests with Rails 4.1, but AFAIK nothing major has changed in the middleware part.

I have no problem with a check for nil values. IMHO it will make the module less brittle. I'll cook something up and release a minor version increment.

Cool. Thanks!

@acrookston I've found out that one of the PR's made the main code unnecessarily complex, and I think the error above lies there. I also get some errors through Travis CI. So I am refactoring the main code right now.

Great! Looking forward to it. I'll be happy to test it out. FYI I've had the same error occur 3 times in the last month now. Not a lot for a 800k requests/month app but they all have the same characteristic; ENV looks fine but doesn't exist.

I've just released version 1.1.0, where all internal code has been through a major overhaul. Nothing changed in the behaviour.

Also I have found that when testing, I need to always set both config options specifically and not rely on defaults. Don't think this should have any effect in production use, but it doesn't hurt to set them, if you haven't done so already.

Let me know, how things work out with this version.

Just to clarify: When I wrote "Nothing changed in the behaviour.", I meant that the code still behave as expected - the test-suite is the same. :-) But hopefully your problem should have gone to the eternal bit-fields...

Ok sounds good. Hopefully gets us no error or at least one which is easier to debug, I'll make the update asap. Thanks!

Great - let me know how it goes. Just reopen this issue, if problems arise.