ktheory · April 14, 2011 18:12 · Apr 20, 2011 · Apr 15, 2011 · Apr 14, 2011 · Apr 14, 2011
diff --git a/fog_instrumentation.rb b/fog_instrumentation.rb
@@ -46,7 +46,7 @@ def request(event)
   end
 
   # Controller borrows heavily from
-  # https://github.com/rails/rails/blob/master/activerecord/lib/active_record/log_subscriber.rb
+  # https://github.com/rails/rails/blob/master/activerecord/lib/active_record/railties/controller_runtime.rb
   module ControllerRuntime
     extend ActiveSupport::Concern
 

diff --git a/fog_instrumentation.rb b/fog_instrumentation.rb
@@ -84,21 +84,3 @@ def log_process_action(payload)
   include FogInstrumentation::ControllerRuntime
 end
 
-# TODO: create/discover safer way to get notifications on requests
-# Change 'request' method to send an activesupport notification
-request_with_notifications = %q{
-  alias_method :request_without_notifications, :request
-
-  def request(params, &block)
-    ActiveSupport::Notifications.instrument('request.fog', :object => self, :params => params) do
-      request_without_notifications(params, &block)
-    end
-  end
-}
-
-# Classes to duckpunch
-classes = [Fog::AWS::RDS::Real, Fog::AWS::Compute::Real, Fog::AWS::ELB::Real]
-classes.each do |klass|
-  klass.class_eval(request_with_notifications)
-end
-
diff --git a/README.rdoc b/README.rdoc
@@ -0,0 +1,9 @@
+Instrument Fog Requests in Rails
+
+This code adds debug statements to the rails log for each fog reqests (similar to how active record shows SQL queries):
+
+  Fog AWS Compute Request (803.0ms)  [ {"Action"=>"DescribeInstances", ...} ]
+
+The end of the request includes cumulative Fog info:
+
+  Completed 200 OK in 6043ms (Views: 2955.0ms | ActiveRecord: 319.9ms | Fog: 1642.6ms, 4 reqs)
diff --git a/fog_extensions.rb b/fog_extensions.rb
@@ -0,0 +1,20 @@
+# Wrap Fog real requests with notifications
+
+# TODO: create/discover safer way to get notifications on requests
+# Change 'request' method to send an activesupport notification
+request_with_notifications = %q{
+  alias_method :request_without_notifications, :request
+
+  def request(params, &block)
+    ActiveSupport::Notifications.instrument('request.fog', :object => self, :params => params) do
+      request_without_notifications(params, &block)
+    end
+  end
+}
+
+# Classes to duckpunch. These are the ones I use, be sure to add your own.
+classes = [Fog::AWS::RDS::Real, Fog::AWS::Compute::Real, Fog::AWS::ELB::Real]
+classes.each do |klass|
+  klass.class_eval(request_with_notifications)
+end
+
diff --git a/fog_logging.rb → fog_instrumentation.rb b/fog_logging.rb → fog_instrumentation.rb
@@ -1,9 +1,10 @@
-# A helper module for logging fog requests in rails logs
+# Log fog requests in Rails
 # Based on:
 # https://gist.github.com/566725
-# https://github.com/rails/rails/blob/master/activerecord/lib/active_record/log_subscriber.rb
-# https://github.com/rails/rails/blob/master/activerecord/lib/active_record/railties/controller_runtime.rb
 module FogInstrumentation
+
+  # Subscriber borrows heavily from 
+  # https://github.com/rails/rails/blob/master/activerecord/lib/active_record/log_subscriber.rb
   class LogSubscriber < ActiveSupport::LogSubscriber
     def self.runtime=(value)
       Thread.current[:fog_runtime] = value
@@ -44,6 +45,8 @@ def request(event)
     end
   end
 
+  # Controller borrows heavily from
+  # https://github.com/rails/rails/blob/master/activerecord/lib/active_record/log_subscriber.rb
   module ControllerRuntime
     extend ActiveSupport::Concern
 

diff --git a/fog_logging.rb b/fog_logging.rb
@@ -0,0 +1,101 @@
+# A helper module for logging fog requests in rails logs
+# Based on:
+# https://gist.github.com/566725
+# https://github.com/rails/rails/blob/master/activerecord/lib/active_record/log_subscriber.rb
+# https://github.com/rails/rails/blob/master/activerecord/lib/active_record/railties/controller_runtime.rb
+module FogInstrumentation
+  class LogSubscriber < ActiveSupport::LogSubscriber
+    def self.runtime=(value)
+      Thread.current[:fog_runtime] = value
+    end
+
+    def self.runtime
+      Thread.current[:fog_runtime] ||= 0
+    end
+
+    def self.reset_runtime
+      rt, self.runtime = runtime, 0
+      rt
+    end
+
+    def self.count=(value)
+      Thread.current[:fog_count] = value
+    end
+
+    def self.count
+      Thread.current[:fog_count] ||= 0
+    end
+
+    def self.reset_count
+      c, self.count = count, 0
+      c
+    end
+
+    def request(event)
+      self.class.runtime += event.duration
+      self.class.count += 1
+      return unless logger.debug?
+
+      klass = event.payload[:object].class
+      friendly_name = klass.to_s.split('::')[0,3] * ' '
+      name = '%s (%.1fms)' % ["#{friendly_name} Request", event.duration]
+
+      debug "  #{color(name, GREEN, true)}  [ #{color(event.payload[:params].inspect, WHITE)} ]"
+    end
+  end
+
+  module ControllerRuntime
+    extend ActiveSupport::Concern
+
+    protected
+
+    attr_internal :fog_runtime
+    def cleanup_view_runtime
+      fog_rt_before_render = FogInstrumentation::LogSubscriber.reset_runtime
+      runtime = super
+      fog_rt_after_render = FogInstrumentation::LogSubscriber.reset_runtime
+      self.fog_runtime = fog_rt_before_render + fog_rt_after_render
+      runtime - fog_rt_after_render
+    end
+
+    def append_info_to_payload(payload)
+      super
+      payload[:fog_runtime] = fog_runtime
+    end
+
+    module ClassMethods
+      def log_process_action(payload)
+        fog_requests = FogInstrumentation::LogSubscriber.reset_count
+        messages, fog_runtime = super, payload[:fog_runtime]
+
+        messages << ("Fog: %.1fms, %d reqs" % [fog_runtime.to_f, fog_requests]) if fog_runtime
+        messages
+      end
+    end
+  end
+
+end
+
+FogInstrumentation::LogSubscriber.attach_to :fog
+ActiveSupport.on_load(:action_controller) do
+  include FogInstrumentation::ControllerRuntime
+end
+
+# TODO: create/discover safer way to get notifications on requests
+# Change 'request' method to send an activesupport notification
+request_with_notifications = %q{
+  alias_method :request_without_notifications, :request
+
+  def request(params, &block)
+    ActiveSupport::Notifications.instrument('request.fog', :object => self, :params => params) do
+      request_without_notifications(params, &block)
+    end
+  end
+}
+
+# Classes to duckpunch
+classes = [Fog::AWS::RDS::Real, Fog::AWS::Compute::Real, Fog::AWS::ELB::Real]
+classes.each do |klass|
+  klass.class_eval(request_with_notifications)
+end
+