Remove ActionView inline logging to ActiveSupport::Notifications and create ActionController::Base#log_event, so everything can be logged within one listener. Also expose log_process_action as a hook for different modules to include their own information during the action processing. This allow ActiveRecord to hook and any other ORM. Finally, this commit changes 'Processing' and 'Rendering' in logs to 'Processed' and 'Rendered' because at the point it's logged, everying already happened.

20 files changed, 197 insertions, 252 deletions

diff --git a/actionpack/lib/abstract_controller/logger.rb b/actionpack/lib/abstract_controller/logger.rb
index e3bcd28da7..a23a13e1d6 100644
--- a/actionpack/lib/abstract_controller/logger.rb
+++ b/actionpack/lib/abstract_controller/logger.rb
@@ -9,25 +9,5 @@ module AbstractController
       cattr_accessor :logger
       extend ActiveSupport::Benchmarkable
     end
-
-    # A class that allows you to defer expensive processing
-    # until the logger actually tries to log. Otherwise, you are
-    # forced to do the processing in advance, and send the
-    # entire processed String to the logger, which might
-    # just discard the String if the log level is too low.
-    #
-    # TODO: Require that Rails loggers accept a block.
-    class DelayedLog < ActiveSupport::BasicObject
-      def initialize(&block)
-        @str, @block = nil, block
-      end
-
-      def method_missing(*args, &block)
-        unless @str
-          @str, @block = @block.call, nil
-        end
-        @str.send(*args, &block)
-      end
-    end
   end
 end
diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb
index dbba69f637..67656110c4 100644
--- a/actionpack/lib/action_controller/base.rb
+++ b/actionpack/lib/action_controller/base.rb
@@ -15,7 +15,6 @@ module ActionController
     include ActionController::ConditionalGet
     include ActionController::RackDelegation
     include ActionController::Logger
-    include ActionController::Benchmarking
     include ActionController::Configuration
 
     # Legacy modules
diff --git a/actionpack/lib/action_controller/caching.rb b/actionpack/lib/action_controller/caching.rb
index d784138ebe..69ed84da95 100644
--- a/actionpack/lib/action_controller/caching.rb
+++ b/actionpack/lib/action_controller/caching.rb
@@ -60,6 +60,17 @@ module ActionController #:nodoc:
       def cache_configured?
         perform_caching && cache_store
       end
+
+      def log_event(name, before, after, instrumenter_id, payload)
+        if name.to_s =~ /(read|write|cache|expire|exist)_(fragment|page)\??/
+          key_or_path = payload[:key] || payload[:path]
+          human_name  = name.to_s.humanize
+          duration    = (after - before) * 1000
+          logger.info("#{human_name} #{key_or_path.inspect} (%.1fms)" % duration)
+        else
+          super
+        end
+      end
     end
 
     def caching_allowed?
diff --git a/actionpack/lib/action_controller/caching/fragments.rb b/actionpack/lib/action_controller/caching/fragments.rb
index 8c1167d526..f569d0dd8b 100644
--- a/actionpack/lib/action_controller/caching/fragments.rb
+++ b/actionpack/lib/action_controller/caching/fragments.rb
@@ -74,7 +74,7 @@ module ActionController #:nodoc:
         return unless cache_configured?
         key = fragment_cache_key(key)
 
-        ActiveSupport::Notifications.instrument(:fragment_exist?, :key => key) do
+        ActiveSupport::Notifications.instrument(:exist_fragment?, :key => key) do
           cache_store.exist?(key, options)
         end
       end
diff --git a/actionpack/lib/action_controller/metal/active_record_runtime.rb b/actionpack/lib/action_controller/metal/active_record_runtime.rb
new file mode 100644
index 0000000000..29f6dcc783
--- /dev/null
+++ b/actionpack/lib/action_controller/metal/active_record_runtime.rb
@@ -0,0 +1,27 @@
+module ActionController
+  module ActiveRecordRuntime
+    extend ActiveSupport::Concern
+
+    attr_internal :db_runtime
+
+    def cleanup_view_runtime
+      if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected?
+        db_rt_before_render = ActiveRecord::Base.connection.reset_runtime
+        runtime = super
+        db_rt_after_render = ActiveRecord::Base.connection.reset_runtime
+        self.db_runtime = db_rt_before_render + db_rt_after_render
+        runtime - db_rt_after_render
+      else
+        super
+      end
+    end
+
+    module ClassMethods
+      def process_log_action(controller)
+        super
+        db_runtime = controller.send :db_runtime
+        logger.info("  ActiveRecord runtime: %.1fms" % db_runtime.to_f) if db_runtime
+      end
+    end
+  end
+end
\ No newline at end of file
diff --git a/actionpack/lib/action_controller/metal/benchmarking.rb b/actionpack/lib/action_controller/metal/benchmarking.rb
deleted file mode 100644
index f73f635b0d..0000000000
--- a/actionpack/lib/action_controller/metal/benchmarking.rb
+++ /dev/null
@@ -1,72 +0,0 @@
-require 'active_support/core_ext/benchmark'
-
-module ActionController #:nodoc:
-  # The benchmarking module times the performance of actions and reports to the logger. If the Active Record
-  # package has been included, a separate timing section for database calls will be added as well.
-  module Benchmarking #:nodoc:
-    extend ActiveSupport::Concern
-
-    protected
-      def render(*args, &block)
-        if logger
-          if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected?
-            db_runtime = ActiveRecord::Base.connection.reset_runtime
-          end
-
-          render_output = nil
-          @view_runtime = Benchmark.ms { render_output = super }
-
-          if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected?
-            @db_rt_before_render = db_runtime
-            @db_rt_after_render = ActiveRecord::Base.connection.reset_runtime
-            @view_runtime -= @db_rt_after_render
-          end
-
-          render_output
-        else
-          super
-        end
-      end
-
-    private
-      def process_action(*args)
-        if logger
-          ms = [Benchmark.ms { super }, 0.01].max
-          logging_view          = defined?(@view_runtime)
-          logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected?
-
-          log_message  = 'Completed in %.0fms' % ms
-
-          if logging_view || logging_active_record
-            log_message << " ("
-            log_message << view_runtime if logging_view
-
-            if logging_active_record
-              log_message << ", " if logging_view
-              log_message << active_record_runtime + ")"
-            else
-              ")"
-            end
-          end
-
-          log_message << " | #{response.status}"
-          log_message << " [#{complete_request_uri rescue "unknown"}]"
-
-          logger.info(log_message)
-        else
-          super
-        end
-      end
-
-      def view_runtime
-        "View: %.0f" % @view_runtime
-      end
-
-      def active_record_runtime
-        db_runtime = ActiveRecord::Base.connection.reset_runtime
-        db_runtime += @db_rt_before_render if @db_rt_before_render
-        db_runtime += @db_rt_after_render if @db_rt_after_render
-        "DB: %.0f" % db_runtime
-      end
-  end
-end
diff --git a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb
index a53c052075..59e200396a 100644
--- a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb
+++ b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb
@@ -2,8 +2,6 @@ module ActionController
   module FilterParameterLogging
     extend ActiveSupport::Concern
 
-    include AbstractController::Logger
-
     module ClassMethods
       # Replace sensitive parameter data from the request log.
       # Filters parameters that have any of the arguments as a substring.
@@ -54,23 +52,25 @@ module ActionController
         end
         protected :filter_parameters
       end
-    end
 
-    INTERNAL_PARAMS = [:controller, :action, :format, :_method, :only_path]
+    protected
 
-    def process(*)
-      response = super
-      if logger
-        parameters = filter_parameters(params).except!(*INTERNAL_PARAMS)
-        logger.info { "  Parameters: #{parameters.inspect}" } unless parameters.empty?
+      # Overwrite log_process_action to include parameters information.
+      # If this method is invoked, it means logger is defined, so don't
+      # worry with such scenario here.
+      def log_process_action(controller) #:nodoc:
+        params = controller.send(:filter_parameters, controller.request.params)
+        logger.info "  Parameters: #{params.inspect}" unless params.empty?
+        super
       end
-      response
     end
 
+    INTERNAL_PARAMS = [:controller, :action, :format, :_method, :only_path]
+
   protected
 
     def filter_parameters(params)
-      params.dup
+      params.dup.except!(*INTERNAL_PARAMS)
     end
 
   end
diff --git a/actionpack/lib/action_controller/metal/logger.rb b/actionpack/lib/action_controller/metal/logger.rb
index 956d7dd371..5d14f6c9c9 100644
--- a/actionpack/lib/action_controller/metal/logger.rb
+++ b/actionpack/lib/action_controller/metal/logger.rb
@@ -1,34 +1,74 @@
 require 'abstract_controller/logger'
 
 module ActionController
+  # Adds instrumentation to <tt>process_action</tt> and a <tt>log_event</tt> method
+  # responsible to log events from ActiveSupport::Notifications. This module handles
+  # :process_action and :render_template events but allows any other module to hook
+  # into log_event and provide its own logging facilities (as in ActionController::Caching).
   module Logger
-    # Override process_action in the AbstractController::Base
-    # to log details about the method.
+    extend ActiveSupport::Concern
+
+    attr_internal :view_runtime
+
     def process_action(action)
-      result = ActiveSupport::Notifications.instrument(:process_action,
-                :controller => self, :action => action) do
+      ActiveSupport::Notifications.instrument(:process_action, :controller => self, :action => action) do
         super
       end
+    end
 
+    def render(*args, &block)
       if logger
-        log = AbstractController::Logger::DelayedLog.new do
-          "\n\nProcessing #{self.class.name}\##{action_name} " \
-          "to #{request.formats} (for #{request_origin}) " \
-          "[#{request.method.to_s.upcase}]"
+        render_output = nil
+
+        self.view_runtime = cleanup_view_runtime do
+          Benchmark.ms { render_output = super }
         end
 
-        logger.info(log)
+        render_output
+      else
+        super
       end
+    end
 
-      result
+    def cleanup_view_runtime
+      yield
     end
 
-  private
+    module ClassMethods
+      def log_event(name, before, after, instrumenter_id, payload)
+        if name == :process_action
+          duration     = [(after - before) * 1000, 0.01].max
+          controller   = payload[:controller]
+          request      = controller.request
+
+          logger.info "\n\nProcessed #{controller.class.name}##{payload[:action]} " \
+            "to #{request.formats} (for #{request.remote_ip} at #{before.to_s(:db)}) " \
+            "[#{request.method.to_s.upcase}]"
 
-    # Returns the request origin with the IP and time. This needs to be cached,
-    # otherwise we would get different results for each time it calls.
-    def request_origin
-      @request_origin ||= "#{request.remote_ip} at #{Time.now.to_s(:db)}"
+          log_process_action(controller)
+
+          message = "Completed in %.0fms" % duration
+          message << " | #{controller.response.status}"
+          message << " [#{request.request_uri rescue "unknown"}]"
+
+          logger.info(message)
+        elsif name == :render_template
+          # TODO Make render_template logging work if you are using just ActionView
+          duration = (after - before) * 1000
+          message = "Rendered #{payload[:identifier]}"
+          message << " within #{payload[:layout]}" if payload[:layout]
+          message << (" (%.1fms)" % duration)
+          logger.info(message)
+        end
+      end
+
+    protected
+
+      # A hook which allows logging what happened during controller process action.
+      def log_process_action(controller) #:nodoc:
+        view_runtime = controller.send :view_runtime
+        logger.info("  View runtime: %.1fms" % view_runtime.to_f) if view_runtime
+      end
     end
   end
 end
diff --git a/actionpack/lib/action_controller/rails.rb b/actionpack/lib/action_controller/rails.rb
index 36a52b3149..e381828ee4 100644
--- a/actionpack/lib/action_controller/rails.rb
+++ b/actionpack/lib/action_controller/rails.rb
@@ -14,10 +14,6 @@ module ActionController
     end
 
     # Routing must be initialized after plugins to allow the former to extend the routes
-    # ---
-    # If Action Controller is not one of the loaded frameworks (Configuration#frameworks)
-    # this does nothing. Otherwise, it loads the routing definitions and sets up
-    # loading module used to lazily load controllers (Configuration#controller_paths).
     initializer "action_controller.initialize_routing" do |app|
       app.route_configuration_files << app.config.routes_configuration_file
       app.route_configuration_files << app.config.builtin_routes_configuration_file
@@ -88,13 +84,8 @@ module ActionController
     initializer "action_controller.notifications" do |app|
       require 'active_support/notifications'
 
-      ActiveSupport::Notifications.subscribe(/(read|write|cache|expire|exist)_(fragment|page)\??/) do |*args|
-        event = ActiveSupport::Notifications::Event.new(*args)
-
-        if logger = ActionController::Base.logger
-          human_name = event.name.to_s.humanize
-          logger.info("#{human_name} (%.1fms)" % event.duration)
-        end
+      ActiveSupport::Notifications.subscribe do |*args|
+        ActionController::Base.log_event(*args) if ActionController::Base.logger
       end
     end
 
diff --git a/actionpack/lib/action_view/render/rendering.rb b/actionpack/lib/action_view/render/rendering.rb
index 5e7dd3e2df..0302e44b4e 100644
--- a/actionpack/lib/action_view/render/rendering.rb
+++ b/actionpack/lib/action_view/render/rendering.rb
@@ -107,12 +107,6 @@ module ActionView
     end
 
     def _render_template(template, layout = nil, options = {}, partial = nil)
-      logger && logger.info do
-        msg = "Rendering #{template.inspect}"
-        msg << " (#{options[:status]})" if options[:status]
-        msg
-      end
-
       locals = options[:locals] || {}
 
       content = ActiveSupport::Notifications.instrument(:render_template,
@@ -124,8 +118,7 @@ module ActionView
 
       if layout
         @_layout = layout.identifier
-        logger.info("Rendering template within #{layout.inspect}") if logger
-        content = _render_layout(layout, locals)
+        content  = _render_layout(layout, locals)
       end
 
       content
diff --git a/actionpack/test/abstract_unit.rb b/actionpack/test/abstract_unit.rb
index a9341b60df..8c65087898 100644
--- a/actionpack/test/abstract_unit.rb
+++ b/actionpack/test/abstract_unit.rb
@@ -50,6 +50,14 @@ ORIGINAL_LOCALES = I18n.available_locales.map {|locale| locale.to_s }.sort
 FIXTURE_LOAD_PATH = File.join(File.dirname(__FILE__), 'fixtures')
 FIXTURES = Pathname.new(FIXTURE_LOAD_PATH)
 
+# Turn on notifications
+require 'active_support/notifications'
+Thread.abort_on_exception = true
+
+ActiveSupport::Notifications.subscribe do |*args|
+  ActionController::Base.log_event(*args) if ActionController::Base.logger
+end
+
 module SetupOnce
   extend ActiveSupport::Concern
 
@@ -87,6 +95,21 @@ class ActiveSupport::TestCase
   end
 end
 
+class MockLogger
+  attr_reader :logged
+  attr_accessor :level
+
+  def initialize
+    @level = Logger::DEBUG
+    @logged = []
+  end
+
+  def method_missing(method, *args, &blk)
+    @logged << args.first
+    @logged << blk.call if block_given?
+  end
+end
+
 class ActionController::IntegrationTest < ActiveSupport::TestCase
   def self.build_app(routes = nil)
     ActionDispatch::MiddlewareStack.new { |middleware|
diff --git a/actionpack/test/controller/base_test.rb b/actionpack/test/controller/base_test.rb
index 8f8ada8d8c..65118f9bc9 100644
--- a/actionpack/test/controller/base_test.rb
+++ b/actionpack/test/controller/base_test.rb
@@ -158,13 +158,6 @@ class PerformActionTest < ActionController::TestCase
     assert_raise(ActionController::UnknownAction) { get :hidden_action }
     assert_raise(ActionController::UnknownAction) { get :another_hidden_action }
   end
-
-  def test_namespaced_action_should_log_module_name
-    use_controller Submodule::ContainedNonEmptyController
-    @controller.logger = MockLogger.new
-    get :public_action
-    assert_match /Processing\sSubmodule::ContainedNonEmptyController#public_action/, @controller.logger.logged[1]
-  end
 end
 
 class DefaultUrlOptionsTest < ActionController::TestCase
diff --git a/actionpack/test/controller/benchmark_test.rb b/actionpack/test/controller/benchmark_test.rb
deleted file mode 100644
index 66ebfcf20a..0000000000
--- a/actionpack/test/controller/benchmark_test.rb
+++ /dev/null
@@ -1,33 +0,0 @@
-require 'abstract_unit'
-
-# Provide some static controllers.
-class BenchmarkedController < ActionController::Base
-  def public_action
-    render :nothing => true
-  end
-
-  def rescue_action(e)
-    raise e
-  end
-end
-
-class BenchmarkTest < ActionController::TestCase
-  tests BenchmarkedController
-
-  class MockLogger
-    def method_missing(*args)
-    end
-  end
-
-  def setup
-    super
-    # benchmark doesn't do anything unless a logger is set
-    @controller.logger = MockLogger.new
-    @request.host = "test.actioncontroller.i"
-  end
-
-  def test_with_http_1_0_request
-    @request.host = nil
-    assert_nothing_raised { get :public_action }
-  end
-end
diff --git a/actionpack/test/controller/caching_test.rb b/actionpack/test/controller/caching_test.rb
index 4ea2e57741..679eaf7b38 100644
--- a/actionpack/test/controller/caching_test.rb
+++ b/actionpack/test/controller/caching_test.rb
@@ -640,7 +640,7 @@ class FragmentCachingTest < ActionController::TestCase
     assert fragment_computed
     assert_equal 'generated till now -> ', buffer
     ActiveSupport::Notifications.notifier.wait
-    assert_equal [:fragment_exist?, :write_fragment], events.map(&:first)
+    assert_equal [:exist_fragment?, :write_fragment], events.map(&:first)
   end
 
 end
diff --git a/actionpack/test/controller/filter_params_test.rb b/actionpack/test/controller/filter_params_test.rb
index 43bef34885..420ebeacf4 100644
--- a/actionpack/test/controller/filter_params_test.rb
+++ b/actionpack/test/controller/filter_params_test.rb
@@ -70,9 +70,9 @@ class FilterParamTest < ActionController::TestCase
     FilterParamController.filter_parameter_logging(:lifo, :amount)
 
     get :payment, :lifo => 'Pratik', :amount => '420', :step => '1'
+    ActiveSupport::Notifications.notifier.wait
 
     filtered_params_logs = logs.detect {|l| l =~ /\AParameters/ }
-
     assert filtered_params_logs.index('"amount"=>"[FILTERED]"')
     assert filtered_params_logs.index('"lifo"=>"[FILTERED]"')
     assert filtered_params_logs.index('"step"=>"1"')
diff --git a/actionpack/test/controller/logging_test.rb b/actionpack/test/controller/logging_test.rb
index 2b5e8d8bde..4206dffa7e 100644
--- a/actionpack/test/controller/logging_test.rb
+++ b/actionpack/test/controller/logging_test.rb
@@ -1,48 +1,74 @@
 require 'abstract_unit'
 
-class LoggingController < ActionController::Base
-  def show
-    render :nothing => true
-  end
-end
-
-class LoggingTest < ActionController::TestCase
-  tests LoggingController
-
-  class MockLogger
-    attr_reader :logged
-    attr_accessor :level
+module Another
+  class LoggingController < ActionController::Base
+    layout "layouts/standard"
 
-    def initialize
-      @level = Logger::DEBUG
+    def show
+      render :nothing => true
     end
 
-    def method_missing(method, *args, &blk)
-      @logged ||= []
-      @logged << args.first
-      @logged << blk.call if block_given?
+    def with_layout
+      render :template => "test/hello_world", :layout => true
     end
   end
+end
+
+class LoggingTest < ActionController::TestCase
+  tests Another::LoggingController
 
   def setup
     super
     set_logger
   end
 
+  def get(*args)
+    super
+    wait
+  end
+
+  def wait
+    ActiveSupport::Notifications.notifier.wait
+  end
+
   def test_logging_without_parameters
     get :show
-    assert_equal 3, logs.size
+    assert_equal 4, logs.size
     assert_nil logs.detect {|l| l =~ /Parameters/ }
   end
 
   def test_logging_with_parameters
     get :show, :id => '10'
-    assert_equal 4, logs.size
+    assert_equal 5, logs.size
 
     params = logs.detect {|l| l =~ /Parameters/ }
     assert_equal 'Parameters: {"id"=>"10"}', params
   end
 
+  def test_log_controller_with_namespace_and_action
+    get :show
+    assert_match /Processed\sAnother::LoggingController#show/, logs[1]
+  end
+
+  def test_log_view_runtime
+     get :show
+     assert_match /View runtime/, logs[2]
+   end
+
+  def test_log_completed_status_and_request_uri
+    get :show
+    last = logs.last
+    assert_match /Completed/, last
+    assert_match /200/, last
+    assert_match /another\/logging\/show/, last
+  end
+
+  def test_logger_prints_layout_and_template_rendering_info
+    get :with_layout
+    logged = logs.find {|l| l =~ /render/i }
+    assert_match /Rendered (.*)test\/hello_world.erb within (.*)layouts\/standard.html.erb/, logged
+  end
+
   private
     def set_logger
       @controller.logger = MockLogger.new
diff --git a/actionpack/test/controller/render_test.rb b/actionpack/test/controller/render_test.rb
index 54f2739d38..2c3dc2a72d 100644
--- a/actionpack/test/controller/render_test.rb
+++ b/actionpack/test/controller/render_test.rb
@@ -10,19 +10,6 @@ module Fun
   end
 end
 
-class MockLogger
-  attr_reader :logged
-
-  def initialize
-    @logged = []
-  end
-
-  def method_missing(method, *args, &blk)
-    @logged << args.first
-    @logged << blk.call if block_given?
-  end
-end
-
 class TestController < ActionController::Base
   protect_from_forgery
 
@@ -1500,21 +1487,4 @@ class LastModifiedRenderTest < ActionController::TestCase
     get :conditional_hello_with_bangs
     assert_response :success
   end
-end
-
-class RenderingLoggingTest < ActionController::TestCase
-  tests TestController
-
-  def setup
-    super
-    @request.host = "www.nextangle.com"
-  end
-
-  def test_logger_prints_layout_and_template_rendering_info
-    @controller.logger = MockLogger.new
-    get :layout_test
-    logged = @controller.logger.logged.find_all {|l| l =~ /render/i }
-    assert logged[0] =~ %r{Rendering.*test/hello_world}
-    assert logged[1] =~ %r{Rendering template within.*layouts/standard}
-  end
-end
+end
\ No newline at end of file
diff --git a/activerecord/lib/active_record/rails.rb b/activerecord/lib/active_record/rails.rb
index ddbc555113..e272d4eebc 100644
--- a/activerecord/lib/active_record/rails.rb
+++ b/activerecord/lib/active_record/rails.rb
@@ -50,8 +50,8 @@ module ActiveRecord
     initializer "active_record.notifications" do
       require 'active_support/notifications'
 
-      ActiveSupport::Notifications.subscribe("sql") do |name, before, after, result, instrumenter_id, payload|
-        ActiveRecord::Base.connection.log_info(payload[:sql], name, after - before)
+      ActiveSupport::Notifications.subscribe("sql") do |name, before, after, instrumenter_id, payload|
+        ActiveRecord::Base.connection.log_info(payload[:sql], payload[:name], (after - before) * 1000)
       end
     end
 
diff --git a/activesupport/lib/active_support/notifications/instrumenter.rb b/activesupport/lib/active_support/notifications/instrumenter.rb
index fb95422af2..0655dd0cb6 100644
--- a/activesupport/lib/active_support/notifications/instrumenter.rb
+++ b/activesupport/lib/active_support/notifications/instrumenter.rb
@@ -10,10 +10,10 @@ module ActiveSupport
       end
 
       def instrument(name, payload={})
-        time   = Time.now
-        result = yield if block_given?
+        time = Time.now
+        yield if block_given?
       ensure
-        @notifier.publish(name, time, Time.now, result, @id, payload)
+        @notifier.publish(name, time, Time.now, @id, payload)
       end
 
       private
@@ -23,15 +23,14 @@ module ActiveSupport
     end
 
     class Event
-      attr_reader :name, :time, :end, :transaction_id, :result, :payload
+      attr_reader :name, :time, :end, :transaction_id, :payload
 
-      def initialize(name, start, ending, result, transaction_id, payload)
+      def initialize(name, start, ending, transaction_id, payload)
         @name           = name
         @payload        = payload.dup
         @time           = start
         @transaction_id = transaction_id
         @end            = ending
-        @result         = result
       end
 
       def duration
diff --git a/activesupport/test/notifications_test.rb b/activesupport/test/notifications_test.rb
index 4f880d0db7..3ba77ae135 100644
--- a/activesupport/test/notifications_test.rb
+++ b/activesupport/test/notifications_test.rb
@@ -134,27 +134,25 @@ module Notifications
 
   class EventTest < TestCase
     def test_events_are_initialized_with_details
-      event = event(:foo, Time.now, Time.now + 1, 1, random_id, :payload => :bar)
-      assert_equal :foo, event.name
-      assert_equal Hash[:payload => :bar], event.payload
-    end
-
-    def test_events_consumes_information_given_as_payload
       time = Time.now
-      event = event(:foo, time, time + 0.01, 1, random_id, {})
+      event = event(:foo, time, time + 0.01, random_id, {})
 
-      assert_equal Hash.new, event.payload
+      assert_equal :foo, event.name
       assert_equal time, event.time
-      assert_equal 1, event.result
       assert_equal 10.0, event.duration
     end
 
+    def test_events_consumes_information_given_as_payload
+      event = event(:foo, Time.now, Time.now + 1, random_id, :payload => :bar)
+      assert_equal Hash[:payload => :bar], event.payload
+    end
+
     def test_event_is_parent_based_on_time_frame
       time = Time.utc(2009, 01, 01, 0, 0, 1)
 
-      parent    = event(:foo, Time.utc(2009), Time.utc(2009) + 100, nil, random_id, {})
-      child     = event(:foo, time, time + 10, nil, random_id, {})
-      not_child = event(:foo, time, time + 100, nil, random_id, {})
+      parent    = event(:foo, Time.utc(2009), Time.utc(2009) + 100, random_id, {})
+      child     = event(:foo, time, time + 10, random_id, {})
+      not_child = event(:foo, time, time + 100, random_id, {})
 
       assert parent.parent_of?(child)
       assert !child.parent_of?(parent)