In Rails, how can one log the entirety of each incoming HTTP request?

2
votes

I'm building an application that talks to a Rails backend that is POSTing requests to Rails. It's failing. Is there an easy way to have Rails log and spit to console the entirety of each incoming HTTP request?

If anyone is feeling particularly charitable, you may be able to help with the underlying cause. Using a simple curl command works fine:

$ curl -X POST -d "<person><name>Jack</name></person>" -H "Content-Type: application/xml" http://localhost:3000/people.xml
 <?xml version="1.0" encoding="UTF-8"?>
 <person>
  <created-at type="datetime">2009-11-08T16:36:54Z</created-at>
  <id type="integer">3</id>
  <name>Jack</name>
  <updated-at type="datetime">2009-11-08T16:36:54Z</updated-at>
 </person>

But the error Rails spits out when my application sends a request is:

/!\ FAILSAFE /!\ Sun Nov 08 11:38:23 -0500 2009 Status: 500 Internal Server Error bad content body /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/utils.rb:347:in `parse_multipart' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/utils.rb:319:in `loop' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/utils.rb:319:in `parse_multipart' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/request.rb:141:in `POST' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/methodoverride.rb:15:in `call' /Library/Ruby/Gems/1.8/gems/actionpack-2.3.4/lib/action_controller/params_parser.rb:15:in `call' /Library/Ruby/Gems/1.8/gems/actionpack-2.3.4/lib/action_controller/session/cookie_store.rb:93:in `call' /Library/Ruby/Gems/1.8/gems/actionpack-2.3.4/lib/action_controller/failsafe.rb:26:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/lock.rb:11:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/lock.rb:11:in `synchronize' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/lock.rb:11:in `call' /Library/Ruby/Gems/1.8/gems/actionpack-2.3.4/lib/action_controller/dispatcher.rb:114:in `call' /Library/Ruby/Gems/1.8/gems/actionpack-2.3.4/lib/action_controller/reloader.rb:34:in `run' /Library/Ruby/Gems/1.8/gems/actionpack-2.3.4/lib/action_controller/dispatcher.rb:108:in `call' /Library/Ruby/Gems/1.8/gems/rails-2.3.4/lib/rails/rack/static.rb:31:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/urlmap.rb:46:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/urlmap.rb:40:in `each' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/urlmap.rb:40:in `call' /Library/Ruby/Gems/1.8/gems/rails-2.3.4/lib/rails/rack/log_tailer.rb:17:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/content_length.rb:13:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/chunked.rb:15:in `call' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/handler/mongrel.rb:61:in `process' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:159:in `process_client' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:158:in `each' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:158:in `process_client' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:285:in `run' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:285:in `initialize' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:285:in `new' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:285:in `run' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:268:in `initialize' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:268:in `new' /System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/gems/mongrel-1.1.5/lib/mongrel.rb:268:in `run' /Library/Ruby/Gems/1.8/gems/rack-1.0.0/lib/rack/handler/mongrel.rb:34:in `run' /Library/Ruby/Gems/1.8/gems/rails-2.3.4/lib/commands/server.rb:111 /Library/Ruby/Site/1.8/rubygems/custom_require.rb:31:in `gem_original_require' /Library/Ruby/Site/1.8/rubygems/custom_require.rb:31:in `require' script/server:3
3
ruby-on-railshttplogging

3 Answers

2
votes

your best bet would probably to make the front end server (apache, nginx, etc.) spit these out...

Or if you want to do it from rails, use request.env in the controller, e.g. as follows 

logger.info(request.env.inspect)
1
votes

I appreciate your response, gunderson, even though it didn't quite lead me to a solution. I ended up using a third party tool, PacketPeeper, to attach to my loopback device and report all TCP traffic.

My issue was caused by an oversight in the client-side networking library I was using (that erroneously reported my XML/JSON as a multipart form).

0
votes

That logger.info request.env code works fine in a Rails controller, but to see a more original version of that, or if you're using Grape or some other mounted app, you have to intercept the request on its way through the rack middleware chain...

Put this code in your lib directory (or at the bottom of application.rb):

require 'pp'
class Loggo
  def initialize(app)
    @app = app
  end
  def call(env)
    pp env
    @app.call(env)
  end
end

then in with the other configs in application.rb:

config.middleware.use "Loggo"