Merge pull request #2291 from rspec/myron/fix-bug-in-example-finished

Fill in execution_status before reporting example_finished.

Author: myronmarston

Changelog.md

@@ -6,6 +6,11 @@ Enhancements:
 * Warn when duplicate shared exmaples definitions are loaded due to being
   defined in files matching the spec pattern (e.g. `_spec.rb`) (#2278, Devon Estes)
 
+Bug Fixes:
+
+* Wait to report `example_finished` until the example's `execution_result`
+  has been completely filled in. (Myron Marston, #2291)
+
 ### 3.5.1 / 2016-07-06
 [Full Changelog](http://github.com/rspec/rspec-core/compare/v3.5.0...v3.5.1)
 

lib/rspec/core/example.rb

@@ -461,15 +461,14 @@ def start(reporter)
       def finish(reporter)
         pending_message = execution_result.pending_message
 
-        reporter.example_finished(self)
         if @exception
-          record_finished :failed
           execution_result.exception = @exception
+          record_finished :failed
           reporter.example_failed self
           false
         elsif pending_message
-          record_finished :pending
           execution_result.pending_message = pending_message
+          record_finished :pending
           reporter.example_pending self
           true
         else
@@ -481,6 +480,7 @@ def finish(reporter)
 
       def record_finished(status)
         execution_result.record_finished(status, clock.now)
+        reporter.example_finished(self)
       end
 
       def run_before_example

spec/rspec/core/example_spec.rb

@@ -555,6 +555,70 @@ def expect_gc(opts)
     end
   end
 
+  describe "reporting example_finished" do
+    let(:reporter) { RSpec::Core::Reporter.new(RSpec::Core::Configuration.new) }
+
+    def capture_reported_execution_result_for_example(&block)
+      reporter = RSpec::Core::Reporter.new(RSpec::Core::Configuration.new)
+
+      reported_execution_result = nil
+
+      listener = double("Listener")
+      allow(listener).to receive(:example_finished) do |notification|
+        reported_execution_result = notification.example.execution_result.dup
+      end
+
+      reporter.register_listener(listener, :example_finished)
+
+      RSpec.describe do
+        it(&block)
+      end.run(reporter)
+
+      reported_execution_result
+    end
+
+    it "fills in the execution result details before reporting a passed example as finished" do
+      execution_result = capture_reported_execution_result_for_example do
+        expect(1).to eq 1
+      end
+
+      expect(execution_result).to have_attributes(
+        :status => :passed,
+        :exception => nil,
+        :finished_at => a_value_within(1).of(Time.now),
+        :run_time => a_value >= 0
+      )
+    end
+
+    it "fills in the execution result details before reporting a failed example as finished" do
+      execution_result = capture_reported_execution_result_for_example do
+        expect(1).to eq 2
+      end
+
+      expect(execution_result).to have_attributes(
+        :status => :failed,
+        :exception => RSpec::Expectations::ExpectationNotMetError,
+        :finished_at => a_value_within(1).of(Time.now),
+        :run_time => a_value >= 0
+      )
+    end
+
+    it "fills in the execution result details before reporting a pending example as finished" do
+      execution_result = capture_reported_execution_result_for_example do
+        pending "because"
+        expect(1).to eq 2
+      end
+
+      expect(execution_result).to have_attributes(
+        :status => :pending,
+        :pending_message => "because",
+        :pending_exception => RSpec::Expectations::ExpectationNotMetError,
+        :finished_at => a_value_within(1).of(Time.now),
+        :run_time => a_value >= 0
+      )
+    end
+  end
+
   describe "#pending" do
     def expect_pending_result(example)
       expect(example).to be_pending