Debug-level Logging for a Single Rails Production Request
We have a large Rails site live which runs with production level logging. Occasionally there is a problem where debug-level logs would help us track down a problem quickly, but we can’t restart one of the Rails servers to have logs put in debug mode for a single request (and don’t want to run in debug mode for long as the servers are heavily used).
There is also the problem that Rails log entries often get interleaved with each other, although this is a partially solved problem with a Rails log analysis tool I wrote. However, for our purposes it would be nice to have just the log output for the single request we want to look at.
The best solution is to change the log level in Rails’ console and then make a single fake request.
Resetting the Log Level within Rails’ Console
There are a number of commands you need to run to set the log to send its output to the console and reset the level to debug. It’d be nice if this was one simple command, but things are never that easy…
$ ruby script/console fdjtest_production
logger = Logger.new(STDOUT)
logger.level = Logger::DEBUG
RAILS_DEFAULT_LOGGER = logger
ActiveRecord::Base.logger = logger
ActionController::Base.logger = logger
ActiveSupport::Cache::MemCacheStore.logger = logger
ApplicationController.allow_forgery_protection = false
reload!Most of the lines are about setting the logger, however in the above I also turn of CSRF protection (as it can be a hassle to get the token and pass it in every time) and then reload all classes to ensure they use the logger specified above not a cached one. It may be that I only need to set RAILS_DEFAULT_LOGGER then reload, but that was added last and it now works!
Making Fake Web Request
Once you’ve configured the log level, actually making web requests is easy from the console. You can now use the app object from script/console to create fake web requests without any hassle.
As a first step, if you redirect to HTTPS on all pages, you’ll want to set it to fake SSL mode.
app.https!Then to get a URL you can use the simple get method:
app.get('/my/path')If you want to put or post to a URL there are also methods for that. You can copy/paste the parameters exactly as they are displayed in your Rails production log:
app.post('/foo', {"this" => "that", "items" => ["bar", "baz"]})
app.put('/foo', {"this" => "that", "items" => ["bar", "baz"]})If you want to sent a custom header, you can add an optional third parameter:
app.post('/foo', {:this => "that", :items => ["bar", "baz"]}, {"X-Do-Something" => "yes"})Any of the get/post/put/delete methods will display their full log output on the console for you to examine. If you want to get information such as the response body returned, HTTP status or response headers these are easy too:
app.response.body
app.response.status
app.response.headers.inspectThe best bit is that cookies are automatically kept within the session, so if you make a call to login, then an admin action the login will be kept alive for the second request. If you want to reset the session you can simply do app(true) to reset it.
Have fun debugging your Rails requests…
3 Comments so far
Alistair Holt wrote on 05 November 2009 at 16:30
It's not really advisable to do debugging on a production app. You should be monitoring errors correctly using Hoptoad, Exceptional or even exception_notifier and debugging the app locally.
Andy Jeffries wrote on 05 November 2009 at 16:39
I agree. However, notifying of exceptions CANNOT happen on this application as the client's sysadmins will not allow outgoing connections. They are absolutely strict about security as there is a LOT of money going through this system each day.
We also do try to debug problems locally (or in test, staging or integration environments) but sometimes you just need to run a page in debug mode in the real environment the problem is happening to see what's going on.
As I'm sure you can guess from my first paragraph in this comment, the chances of getting an entire DB dump to reproduce the existing system is highly unlikely (as well as unfeasible as it's a few connected systems on different machines talking to each other).
The site is a betting platform for a company that is mostly government owned, that may explain why they're so paranoid about security.
But personally I do use (and recommend) Hoptoad for exception notification along with New Relic for performance monitoring - it's just a shame I can't use them in this scenario :-)
Alistair Holt wrote on 05 November 2009 at 23:57
Yea that does sound like an exceptional set of circumstances. I can see it would be a tricky situation to deal with :)
Click here to have your say...