Last week at Rails World version 7.1 of Ruby on Rails was finally released. This is a great milestone with many great new features, but for me it’s extra special because it’s the first time I contributed to Rails and code I wrote is now part of the framework.
In this post I want to share what I found and how I came up with a fix that was eventually merged into Rails. If you want have a look, here’s my pull request titled ‘Log redirects from router similarly to controller redirects’.
At some point I noticed that redirects created directly in the routes (if you’re not familiar with how that works, here are the relevant docs for it) weren’t logged properly. Basically what showed up in the logs was something like this:
# config/routes.rb get :moo, to: "rails/welcome#index" root to: redirect("moo")
Started GET "/" for 127.0.0.1 at 2021-10-21 13:09:51 +0200 Started GET "/moo" for 127.0.0.1 at 2021-10-21 13:09:51 +0200 Processing by Rails::WelcomeController#index as */*
The request to
/ correctly redirects to
/moo, but that’s not very clear in the logs, as it only outputs a line for ‘Started GET …’ with the next line already being the next request. Normally requests (and redirects) always end with a ‘Completed xx in xxx ms’ and most importantly have an empty line between them for readability.
With my fix implemented, the logs are now much clearer:
Started GET "/" for 127.0.0.1 at 2021-10-21 13:14:49 +0200 Redirected to http://localhost:3000/moo Completed 301 Moved Permanently in 0ms Started GET "/moo" for 127.0.0.1 at 2021-10-21 13:14:49 +0200 Processing by Rails::WelcomeController#index as */*
Figuring out how this all works was an interesting deep dive into the internals of Rails, specifically how the whole logging framework works. Basically all things that need to be logged are wrapped in an
ActiveSupport::Notifications.instrument block, which executes the code inside and then sends a payload to subscribed listeners for that specific event.
In this case, there was no event for redirects made from the router, so I added that and also created a new subscriber thats outputs the logs nicely. I had the advantage that there already existed a logger for controller redirects, so it was quite straight forward to implement something similar for the router.
It took a while, but eventually the pull request was merged and has now landed in the latest 7.1 release. I hope to contribute more in the future, but for now I’m very happy with my first small contribution to Rails.