Unexpected error while processing request: undefined method `each' for nil:NilClass

[bcoles]

Enabling beef.http.debug: true results in the following stacktrace when accessing the admin UI.

I, [2020-01-15T00:31:57.487248 #27751]  INFO -- : Thin web server (v1.7.2 codename Bachmanity)
D, [2020-01-15T00:31:57.487294 #27751] DEBUG -- : Debugging ON
I, [2020-01-15T00:31:57.487338 #27751]  INFO -- : Maximum connections set to 1024
I, [2020-01-15T00:31:57.487381 #27751]  INFO -- : Listening on 0.0.0.0:3000, CTRL+C to stop
E, [2020-01-15T00:32:59.685733 #27751] ERROR -- : Unexpected error while processing request: undefined method `each' for nil:NilClass
	/var/lib/gems/2.5.0/gems/rack-2.1.1/lib/rack/utils.rb:424:in `initialize'
	/var/lib/gems/2.5.0/gems/rack-2.1.1/lib/rack/common_logger.rb:36:in `new'
	/var/lib/gems/2.5.0/gems/rack-2.1.1/lib/rack/common_logger.rb:36:in `call'
	/var/lib/gems/2.5.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:231:in `call'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:86:in `block in pre_process'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:84:in `catch'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:84:in `pre_process'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:53:in `process'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:39:in `receive_data'
	/var/lib/gems/2.5.0/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in `run_machine'
	/var/lib/gems/2.5.0/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in `run'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/backends/base.rb:73:in `start'
	/var/lib/gems/2.5.0/gems/thin-1.7.2/lib/thin/server.rb:162:in `start'
	/root/Desktop/beef/core/main/server.rb:165:in `start'
	./beef:232:in `<main>'

[jcrew99]

@bcoles Are you aware of what might be throwing this error, ive been chasing it down through the thin server, Logger and Http and have not found it as of yet.

[bcoles]

@bcoles Are you aware of what might be throwing this error, ive been chasing it down through the thin server, Logger and Http and have not found it as of yet.

The error is only present when beef.http.debug is set to true, and is not triggered until a HTTP request is sent to the Admin UI (/ui/panel or /ui/authentication). It is not triggered by browsing to the web root / or any missing page /doesnotexist.

[hipcrime]

E, [2020-05-06T20:27:06.921636 #2765] ERROR -- : Unexpected error while processing request: undefined method each' for nil:NilClass /usr/lib/ruby/vendor_ruby/rack/utils.rb:424:in initialize'
/usr/lib/ruby/vendor_ruby/rack/common_logger.rb:36:in new' /usr/lib/ruby/vendor_ruby/rack/common_logger.rb:36:in call'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:231:in call' /usr/lib/ruby/vendor_ruby/thin/connection.rb:86:in block in pre_process'
/usr/lib/ruby/vendor_ruby/thin/connection.rb:84:in catch' /usr/lib/ruby/vendor_ruby/thin/connection.rb:84:in pre_process'
/usr/lib/ruby/vendor_ruby/thin/connection.rb:53:in process' /usr/lib/ruby/vendor_ruby/thin/connection.rb:39:in receive_data'
/usr/lib/ruby/vendor_ruby/eventmachine.rb:187:in run_machine' /usr/lib/ruby/vendor_ruby/eventmachine.rb:187:in run'
/usr/lib/ruby/vendor_ruby/thin/backends/base.rb:73:in start' /usr/lib/ruby/vendor_ruby/thin/server.rb:162:in start'
/usr/share/beef-xss/core/main/server.rb:165:in start' ./beef:232:in

'

[jcrew99]

So been a while but i was working on this issue last night and i know at what point its erroring. Its in the gems/2.7.0/gems/rack-2.2.3/lib/rack/common_logger.rb file where it tries to call the following line:

headers = Utils::HeaderHash[headers]

Which comes to this class:

   417:     class HeaderHash < Hash # :nodoc:
   418:       def self.[](headers)
=> 419:         if headers.is_a?(HeaderHash) && !headers.frozen?
   420:           return headers
   421:         else
   422:           return self.new(headers)
   423:         end

Which is where the return null comes from. Not sure what the fix for this one will be yet but it might be the gem itself.

See below for the byebug dump:

[28, 37] in /mnt/d/github/beef/extensions/admin_ui/handlers/ui.rb
   28:       @response = Rack::Response.new(env)
   29: 
   30:       controller = @klass.new
   31:       controller.run(@request, @response)
   32:       require 'byebug'; byebug
=> 33:       @response = Rack::Response.new(
   34:            body = [controller.body],
   35:             status = controller.status,
   36:             header = controller.headers
   37:           )
(byebug) s

[38, 47] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   38:     # @param headers [#each] a list of key-value header pairs which
   39:     # conform to the HTTP protocol RFCs.
   40:     #
   41:     # Providing a body which responds to #to_str is legacy behaviour.
   42:     def initialize(body = nil, status = 200, headers = {})
=> 43:       @status = status.to_i
   44:       @headers = Utils::HeaderHash[headers]
   45: 
   46:       @writer = self.method(:append)
   47: 
(byebug) status.to_i
302
(byebug) Utils::headerHash[headers]
*** NoMethodError Exception: undefined method `headerHash' for Rack::Utils:Module

nil
(byebug) Utils::HeaderHash[headers]
{"Location"=>"/ui/authentication"}
(byebug) n

[39, 48] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   39:     # conform to the HTTP protocol RFCs.
   40:     #
   41:     # Providing a body which responds to #to_str is legacy behaviour.
   42:     def initialize(body = nil, status = 200, headers = {})
   43:       @status = status.to_i
=> 44:       @headers = Utils::HeaderHash[headers]
   45: 
   46:       @writer = self.method(:append)
   47: 
   48:       @block = nil
(byebug) 

[41, 50] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   41:     # Providing a body which responds to #to_str is legacy behaviour.
   42:     def initialize(body = nil, status = 200, headers = {})
   43:       @status = status.to_i
   44:       @headers = Utils::HeaderHash[headers]
   45: 
=> 46:       @writer = self.method(:append)
   47: 
   48:       @block = nil
   49: 
   50:       # Keep track of whether we have expanded the user supplied body.
(byebug) 

[43, 52] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   43:       @status = status.to_i
   44:       @headers = Utils::HeaderHash[headers]
   45: 
   46:       @writer = self.method(:append)
   47: 
=> 48:       @block = nil
   49: 
   50:       # Keep track of whether we have expanded the user supplied body.
   51:       if body.nil?
   52:         @body = []
(byebug) 

[46, 55] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   46:       @writer = self.method(:append)
   47: 
   48:       @block = nil
   49: 
   50:       # Keep track of whether we have expanded the user supplied body.
=> 51:       if body.nil?
   52:         @body = []
   53:         @buffered = true
   54:         @length = 0
   55:       elsif body.respond_to?(:to_str)
(byebug) body
[""]
(byebug) body.nil?
false
(byebug) s

[50, 59] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   50:       # Keep track of whether we have expanded the user supplied body.
   51:       if body.nil?
   52:         @body = []
   53:         @buffered = true
   54:         @length = 0
=> 55:       elsif body.respond_to?(:to_str)
   56:         @body = [body]
   57:         @buffered = true
   58:         @length = body.to_str.bytesize
   59:       else
(byebug) s

[55, 64] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   55:       elsif body.respond_to?(:to_str)
   56:         @body = [body]
   57:         @buffered = true
   58:         @length = body.to_str.bytesize
   59:       else
=> 60:         @body = body
   61:         @buffered = false
   62:         @length = 0
   63:       end
   64: 
(byebug) 

[56, 65] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   56:         @body = [body]
   57:         @buffered = true
   58:         @length = body.to_str.bytesize
   59:       else
   60:         @body = body
=> 61:         @buffered = false
   62:         @length = 0
   63:       end
   64: 
   65:       yield self if block_given?
(byebug) 

[57, 66] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   57:         @buffered = true
   58:         @length = body.to_str.bytesize
   59:       else
   60:         @body = body
   61:         @buffered = false
=> 62:         @length = 0
   63:       end
   64: 
   65:       yield self if block_given?
   66:     end
(byebug) 

[60, 69] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   60:         @body = body
   61:         @buffered = false
   62:         @length = 0
   63:       end
   64: 
=> 65:       yield self if block_given?
   66:     end
   67: 
   68:     def redirect(target, status = 302)
   69:       self.status = status
(byebug) 

[75, 84] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/urlmap.rb
   75:       end
   76: 
   77:       [404, { CONTENT_TYPE => "text/plain", "X-Cascade" => "pass" }, ["Not Found: #{path}"]]
   78: 
   79:     ensure
=> 80:       env[PATH_INFO]   = path
   81:       env[SCRIPT_NAME] = script_name
   82:     end
   83: 
   84:     private
(byebug) env[PATH_INFO]
""
(byebug) env[SCRIPT_NAME]
"/ui/panel"
(byebug) n

[76, 85] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/urlmap.rb
   76: 
   77:       [404, { CONTENT_TYPE => "text/plain", "X-Cascade" => "pass" }, ["Not Found: #{path}"]]
   78: 
   79:     ensure
   80:       env[PATH_INFO]   = path
=> 81:       env[SCRIPT_NAME] = script_name
   82:     end
   83: 
   84:     private
   85:     def casecmp?(v1, v2)
(byebug) 

[34, 43] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/common_logger.rb
   34:     # exceptions raised during the sending of the response body will
   35:     # cause the request not to be logged.
   36:     def call(env)
   37:       began_at = Utils.clock_time
   38:       status, headers, body = @app.call(env)
=> 39:       headers = Utils::HeaderHash[headers]
   40:       body = BodyProxy.new(body) { log(env, status, headers, began_at) }
   41:       [status, headers, body]
   42:     end
   43: 
(byebug) Utils::HeaderHash[headers]
*** NoMethodError Exception: undefined method `each' for nil:NilClass

nil
(byebug) s

[414, 423] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/utils.rb
   414:     # header when set.
   415:     #
   416:     # @api private
   417:     class HeaderHash < Hash # :nodoc:
   418:       def self.[](headers)
=> 419:         if headers.is_a?(HeaderHash) && !headers.frozen?
   420:           return headers
   421:         else
   422:           return self.new(headers)
   423:         end
(byebug) headers
nil
(byebug) n

[417, 426] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/utils.rb
   417:     class HeaderHash < Hash # :nodoc:
   418:       def self.[](headers)
   419:         if headers.is_a?(HeaderHash) && !headers.frozen?
   420:           return headers
   421:         else
=> 422:           return self.new(headers)
   423:         end
   424:       end
   425: 
   426:       def initialize(hash = {})
(byebug) self.new(headers)
*** NoMethodError Exception: undefined method `each' for nil:NilClass

nil
(byebug) n

[85, 94] in /var/lib/gems/2.7.0/gems/thin-1.8.1/lib/thin/connection.rb
   85:         # Process the request calling the Rack adapter
   86:         response = @app.call(@request.env)
   87:       end
   88:       response
   89:     rescue Exception => e
=> 90:       unexpected_error(e)
   91:       # Pass through error response
   92:       can_persist? && @request.persistent? ? Response::PERSISTENT_ERROR : Response::ERROR
   93:     end
   94: 

Worth noting that this class gets called elsewhere and works fine:

[38, 47] in /var/lib/gems/2.7.0/gems/rack-2.2.3/lib/rack/response.rb
   38:     # @param headers [#each] a list of key-value header pairs which
   39:     # conform to the HTTP protocol RFCs.
   40:     #
   41:     # Providing a body which responds to #to_str is legacy behaviour.
   42:     def initialize(body = nil, status = 200, headers = {})
=> 43:       @status = status.to_i
   44:       @headers = Utils::HeaderHash[headers]
   45: 
   46:       @writer = self.method(:append)
   47: 

The response is this:

(byebug) Utils::HeaderHash[headers]
{"Location"=>"/ui/authentication"}

[jcrew99]

@wheatley

[bcoles]

This only happens for URL routes which don't use the new Sinatra class. An issue was created to migrate all URL routes to extend the new Router more than 10 years ago but not much progress has been made since.

• Modify all HTTP handlers to use the new Router class #654