Modify log format and content from default ActionController LogSubscriber in Rails 3

Question

Context:

In a rails 3 project I want to customise (heavily) the format and content of the "Processing" and "Completed in" log lines from ActionController. This is in order to have them match the (also custom) format of an older rails 2.3 app, allowing re-use of various analysis tools. Making them fixed-field (by use of place-holders where necessary) also makes it far easier to do ad-hoc queries on them with (say) awk, or to load them into a db or splunk without smart parsing.

I've achieved this goal quickly and heavy-handedly by forking rails and patching the LogSubscriber in question, but I am now looking to do it the right way.

Here's what I think I want to do:

1. Create a LogSubscriber inheriting ActionController::LogSubscriber.
2. Override only the start_processing and process_action methods.
3. Unsubscribe the original ActionController::LogSubscriber, which (sadly) registers itself as soon as the class is loaded. This is the step I'm stuck on.
4. Attach my custom subscriber to :action_controller, using attach_to.

I note that things would be easier if the hook-up of the default ActionController's log subscriber were done as a config step, rather than on class load.

Question:

Assuming the approach outlined above is suitable, how can I unsubscribe or unattach the default log subscriber ActionController::LogSubscriber? The base class, ActiveSupport::LogSubscriber provides attach_to but no means of detaching.

Alternatively, what is the cleanest way of altering the behaviour of (or entirely suppressing) the two methods (start_processing, process_action) in the above mentioned class, ActionController::LogSubscriber.

Of course, I'd also welcome any other (maintainable) approach which provides full freedom in customizing the log format of the two lines mentioned.

Unsuitable approaches:

• My problem cannot be solved by adding instrumentation, as documented nicely by mnutt.
• I'd like to avoid monkey-patching, or hacking in a way that may break when the rails implementation (not interface) changes.

References:

• Docs and Source for ActiveSupport::LogSubscriber
• Source for ActionController::LogSubscriber
• Docs, Source, and RailsCast for ActiveSupport::Notifications

Answer 1

I have worked out the following solution.

I'm not particularly happy with aspects of it (for example, having to unsubscribe ALL interest in 'process_action.action_controller'), and I'll certainly accept a better answer.

We add the following as config/initializers/custom_ac_log_subscriber.rb

module MyApp
  class CustomAcLogSubscriber < ActiveSupport::LogSubscriber
    INTERNAL_PARAMS = ActionController::LogSubscriber::INTERNAL_PARAMS

    #Do your custom stuff here. (The following is much simplified).
    def start_processing(event)
      payload = event.payload
      params  = payload[:params].except(*INTERNAL_PARAMS)
      info "Processing #{payload[:controller]}##{payload[:action]} (...)"
      info "  Parameters: #{params.inspect}" unless params.empty?
    end

    def process_action(event)
      payload   = event.payload
      message = "Completed in %.0fms [#{payload[:path]}]" % event.duration
      info(message)
    end

    def logger
      ActionController::Base.logger
    end
  end
end

#Prevent ActionController::LogSubscriber from also acting on these notifications
#Note that the following undesireably unregisters *everyone's*
#interest in these.  We can't target one LogSubscriber, it seems(?)
%w(process_action start_processing).each do |evt|
  ActiveSupport::Notifications.unsubscribe "#{evt}.action_controller"
end

#Register our own interest
MyApp::CustomAcLogSubscriber.attach_to :action_controller

Notes on aborted initial approach:

I initially attempted an approach of unregistering the default LogSubscriber, with the intention that our custom one would inherit and do all the work (without having to reimpl).

However, there are a number of problems.

1) It's not enough to remove the LogSubscriber as follows:

ActiveSupport::LogSubscriber.log_subscribers.delete_if{ |ls| 
  ls.instance_of? ActionController::LogSubscriber } 

As the request for notifications remains registered.

2) Further, when you inherit a LogSubscriber and register it, it appears any non-overridden methods will not be called using the inherited implementation.