8

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:

2
  • Looking again at the source, it seems you can prod and poke all(?) registered subscribers via the public ActiveSupport::LogSubscriber.log_subscribers. Whether it's sufficient or safe to manipulate this directly, and at what stage in initialization, I've no idea.
    – neillb
    Commented Jun 16, 2011 at 19:25
  • You shouldn’t unsubscribe at all. Subscribers are cached on their first hit and once you can unsubscribe, then you lose caching altogether.
    – fatfrog
    Commented Jan 20, 2021 at 4:49

5 Answers 5

4

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.

1
  • I attempted this, but now i get two log outputs. Doesn't seem to unsubscribe the first.
    – haider
    Commented Nov 21, 2011 at 23:42
4

For unsubscribe I found this solution: (Rails 3.0.10):

notifier = ActiveSupport::Notifications.notifier
subscribers = notifier.listeners_for("sql.active_record")
subscribers.each {|s| ActiveSupport::Notifications.unsubscribe s }
2

For anyone else searching for this, Mathias Meyer has a nice writeup

Also, he has a gem that can be a good example for how to unsubscribe existing subscribers and substitute one's own.

1

If you want to unsubscribe a patter matching a regex you can do this:

ActiveSupport::Subscriber.subscribers.flat_map(&:patterns).grep(/sql/).map \
  &ActiveSupport::Notifications.method(:unsubscribe)
0

Add a file in config/initializers/filter_logger.rb

# required this file
require 'action_controller/log_subscriber'

module MyApp
  class MyLogSubscriber < ActiveSupport::LogSubscriber
    INTERNAL_PARAMS = %w(controller action format _method only_path)

    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
  end
end

%w(process_action start_processing).each do |evt|
  ActiveSupport::Notifications.unsubscribe "#{evt}.action_controller"
end

MyApp::MyLogSubscriber.attach_to :action_controller

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.