How to Suppress Fatal Logging from Rails Middleware

This bothersome bit of intrusion bot spam has been vexing me for some time, and I’ve finally figured out how to fix it.

Part of the never-ending webmaster-related duties is dealing with malicious bots. There’s one bot I see every so often that seems to use the Content-Type HTML header as an exploit. It shows up in my logs looking like this:

ActionDispatch::Http::MimeNegotiation::InvalidType ("%{#context['com.opensymphony.xwork2" is not a valid MIME type):

The attack fails on this server; all that happens is Rails generates an exception and an HTTP error is returned. The problem (and it is rather minor) is that the exception gets logged (as above), which clutters up my log files. I prefer it if every line in my logfile were formatted the same, so I’ve been looking for a way to filter that exception out of my logs.

What Doesn’t Work

The first solution I tried was to use ActionDispatch#rescue_responses. You can do this by adding a line in your config/application.rb

config.action_dispatch.rescue_responses["ActionDispatch::Http::MimeNegotiation::InvalidType"] = :bad_request

This will change the return code, but it won’t do anything about the log spam. The offending line still appears in the log file.

Next, I tried log filtering. I use the lograge gem to format my log files, and it has a config option to ignore certain events. But adding this exception to its ignore list didn’t do anything. There is another option to split the logfile into “original” and “lograge” files, and this does separate the exception into a different file, but then the lograge file loses some of its formatting, and you’re also stuck with a whole other file which has a bunch of Rails log events I never want to see in production (and is the reason I started using lograge in the first place).

What is Happening Here

The reason none of these solutions work is that the exception is being raised in the middleware. Your Rails app is, in the end, just another middleware app that’s being called by Rack, and so it can’t handle exceptions that are raised in the middleware layer. The only way to handle a middleware exception is through more middleware. So that’s what I had to do.

First, create a small middleware app whose sole purpose will be to capture that exception so it isn’t raised to the rest of the app.

# in lib/middleware/capture_exceptions.rb

module Middleware
  class CaptureExceptions
    def initialize(app)
      @app = app
    end

    def call(env)
      @app.call(env)
    rescue ::ActionDispatch::Http::MimeNegotiation::InvalidType
      [400, {}, []]
    end
  end
end

All this does is add a rescue block for the exception that’s being raised, and returns an empty 400 (Bad Request) response.

Next, we need to install this middleware from our config/application.rb

# Add this after your requires in config/application.rb
require_relative '../lib/middleware/capture_exceptions'

# ...
# and this inside the class
    config.middleware.insert_before Rack::Head, ::Middleware::CaptureExceptions

Restart your Rails app, and your logs are now free from that exception junk. You can add additional exceptions to the middleware, although you should of course be careful when doing so, because every exception you block there will fail silently with no log info to tell you what happened. If you like, you can add some additional logging into the middleware like Rails.logger.info("Bad request in middleware (Invalid MIME type)" and that will be logged, but with all the nice formatting that you’ve specified in your logger config.