Fixing #1054 - transaction reports are always sent

This refactors how reports, catalogs, configurers, and transactions
are all related - the Configurer class manages the report, both
creating and sending it, so the transaction is now just responsible
for adding data to it.  I'm still a bit uncomfortable of the coupling
between transactions, the report, and configurer, but it's better than
it was.

This also fixes #2944 and #2973.

Signed-off-by: Luke Kanies <luke@madstop.com>

lib/puppet/configurer.rb

@@ -62,6 +62,10 @@ class Puppet::Configurer
         @splayed = false
     end
 
+    def initialize_report
+        Puppet::Transaction::Report.new
+    end
+
     # Prepare for catalog retrieval.  Downloads everything necessary, etc.
     def prepare
         dostorage()
@@ -135,6 +139,9 @@ class Puppet::Configurer
             Puppet.err "Failed to prepare catalog: %s" % detail
         end
 
+        report = initialize_report()
+        Puppet::Util::Log.newdestination(report)
+
         if catalog = options[:catalog]
             options.delete(:catalog)
         elsif ! catalog = retrieve_catalog
@@ -142,11 +149,11 @@ class Puppet::Configurer
             return
         end
 
+        transaction = nil
+
         begin
             benchmark(:notice, "Finished catalog run") do
                 transaction = catalog.apply(options)
-                transaction.generate_report
-                report = transaction.report
             end
             report
         rescue => detail
@@ -158,6 +165,19 @@ class Puppet::Configurer
         # Now close all of our existing http connections, since there's no
         # reason to leave them lying open.
         Puppet::Network::HttpPool.clear_http_instances
+
+        Puppet::Util::Log.close(report)
+
+        send_report(report, transaction)
+    end
+
+    def send_report(report, trans = nil)
+        trans.add_metrics_to_report(report) if trans
+        puts report.summary if Puppet[:summarize]
+        report.save() if Puppet[:report]
+    rescue => detail
+        puts detail.backtrace if Puppet[:trace]
+        Puppet.err "Could not send report: #{detail}"
     end
 
     private

lib/puppet/resource/catalog.rb

@@ -135,7 +135,7 @@ class Puppet::Resource::Catalog < Puppet::SimpleGraph
         transaction.tags = options[:tags] if options[:tags]
         transaction.ignoreschedules = true if options[:ignoreschedules]
 
-        transaction.addtimes :config_retrieval => self.retrieval_duration
+        transaction.addtimes :config_retrieval => self.retrieval_duration || 0
 
 
         begin
@@ -154,8 +154,6 @@ class Puppet::Resource::Catalog < Puppet::SimpleGraph
 
         yield transaction if block_given?
 
-        transaction.send_report if host_config and (Puppet[:report] or Puppet[:summarize])
-
         return transaction
     ensure
         @applying = false

lib/puppet/transaction.rb

@@ -12,9 +12,6 @@ class Transaction
     attr_accessor :component, :catalog, :ignoreschedules
     attr_accessor :sorted_resources, :configurator
 
-    # The report, once generated.
-    attr_reader :report
-
     # The list of events generated in this transaction.
     attr_reader :events
 
@@ -278,33 +275,25 @@ class Transaction
     def evaluate
         @count = 0
 
-        # Start logging.
-        Puppet::Util::Log.newdestination(@report)
-
         prepare()
 
         Puppet.info "Applying configuration version '%s'" % catalog.version if catalog.version
 
-        begin
-            allevents = @sorted_resources.collect { |resource|
-                if resource.is_a?(Puppet::Type::Component)
-                    Puppet.warning "Somehow left a component in the relationship graph"
-                    next
-                end
-                ret = nil
-                seconds = thinmark do
-                    ret = eval_resource(resource)
-                end
+        allevents = @sorted_resources.collect { |resource|
+            if resource.is_a?(Puppet::Type::Component)
+                Puppet.warning "Somehow left a component in the relationship graph"
+                next
+            end
+            ret = nil
+            seconds = thinmark do
+                ret = eval_resource(resource)
+            end
 
-                if Puppet[:evaltrace] and @catalog.host_config?
-                    resource.info "Evaluated in %0.2f seconds" % seconds
-                end
-                ret
-            }.flatten.reject { |e| e.nil? }
-        ensure
-            # And then close the transaction log.
-            Puppet::Util::Log.close(@report)
-        end
+            if Puppet[:evaltrace] and @catalog.host_config?
+                resource.info "Evaluated in %0.2f seconds" % seconds
+            end
+            ret
+        }.flatten.reject { |e| e.nil? }
 
         Puppet.debug "Finishing transaction %s with %s changes" %
             [self.object_id, @count]
@@ -382,8 +371,7 @@ class Transaction
         end
     end
 
-    # Generate a transaction report.
-    def generate_report
+    def add_metrics_to_report(report)
         @resourcemetrics[:failed] = @failures.find_all do |name, num|
             num > 0
         end.length
@@ -395,19 +383,15 @@ class Transaction
         end
 
         # Add all of the metrics related to resource count and status
-        @report.newmetric(:resources, @resourcemetrics)
+        report.newmetric(:resources, @resourcemetrics)
 
         # Record the relative time spent in each resource.
-        @report.newmetric(:time, @timemetrics)
+        report.newmetric(:time, @timemetrics)
 
         # Then all of the change-related metrics
-        @report.newmetric(:changes,
-            :total => @changes.length
-        )
+        report.newmetric(:changes, :total => @changes.length)
 
-        @report.time = Time.now
-
-        return @report
+        report.time = Time.now
     end
 
     # Should we ignore tags?
@@ -418,7 +402,7 @@ class Transaction
     # this should only be called by a Puppet::Type::Component resource now
     # and it should only receive an array
     def initialize(catalog)
-        @catalog = resources
+        @catalog = catalog
 
         @resourcemetrics = {
             :total => @catalog.vertices.length,
@@ -452,7 +436,6 @@ class Transaction
             h[key] = 0
         end
 
-        @report = Report.new
         @count = 0
     end
 
@@ -498,28 +481,6 @@ class Transaction
         catalog.relationship_graph
     end
 
-    # Send off the transaction report.
-    def send_report
-        begin
-            report = generate_report()
-        rescue => detail
-            Puppet.err "Could not generate report: %s" % detail
-            return
-        end
-
-        if Puppet[:summarize]
-            puts report.summary
-        end
-
-        if Puppet[:report]
-            begin
-                report.save()
-            rescue => detail
-                Puppet.err "Reporting failed: %s" % detail
-            end
-        end
-    end
-
     # Roll all completed changes back.
     def rollback
         @targets.clear

spec/integration/configurer.rb

@@ -15,4 +15,21 @@ describe Puppet::Configurer do
             configurer.download_plugins
         end
     end
+
+    describe "when running" do
+        it "should send a transaction report with valid data" do
+            catalog = Puppet::Resource::Catalog.new
+            catalog.add_resource(Puppet::Type.type(:notify).new(:title => "testing"))
+
+            configurer = Puppet::Configurer.new
+
+            Puppet::Transaction::Report.indirection.expects(:save).with do |report|
+                report.time.class == Time and report.logs.length > 0
+            end
+
+            Puppet[:report] = true
+
+            configurer.run :catalog => catalog
+        end
+    end
 end

spec/unit/configurer.rb

@@ -21,12 +21,23 @@ describe Puppet::Configurer do
     end
 end
 
+describe Puppet::Configurer, "when initializing a report" do
+    it "should return an instance of a transaction report" do
+        Puppet.settings.stubs(:use).returns(true)
+        @agent = Puppet::Configurer.new
+        @agent.initialize_report.should be_instance_of(Puppet::Transaction::Report)
+    end
+end
+
 describe Puppet::Configurer, "when executing a catalog run" do
     before do
         Puppet.settings.stubs(:use).returns(true)
         @agent = Puppet::Configurer.new
         @agent.stubs(:facts_for_uploading).returns({})
         @agent.stubs(:retrieve_catalog).returns Puppet::Resource::Catalog.new
+
+        Puppet::Util::Log.stubs(:newdestination)
+        Puppet::Util::Log.stubs(:close)
     end
 
     it "should prepare for the run" do
@@ -35,6 +46,22 @@ describe Puppet::Configurer, "when executing a catalog run" do
         @agent.run
     end
 
+    it "should initialize a transaction report" do
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+
+        @agent.run
+    end
+
+    it "should set the report as a log destination" do
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+
+        Puppet::Util::Log.expects(:newdestination).with(report)
+
+        @agent.run
+    end
+
     it "should retrieve the catalog" do
         @agent.expects(:retrieve_catalog)
 
@@ -53,7 +80,7 @@ describe Puppet::Configurer, "when executing a catalog run" do
         catalog = stub 'catalog', :retrieval_duration= => nil
         @agent.expects(:retrieve_catalog).returns catalog
 
-        catalog.expects(:apply).with(:one => true)
+        catalog.expects(:apply).with { |args| args[:one] == true }
         @agent.run :one => true
     end
 
@@ -61,7 +88,7 @@ describe Puppet::Configurer, "when executing a catalog run" do
         catalog = stub 'catalog', :retrieval_duration= => nil
         @agent.expects(:retrieve_catalog).never
 
-        catalog.expects(:apply).with(:one => true)
+        catalog.expects(:apply)
         @agent.run :one => true, :catalog => catalog
     end
 
@@ -74,6 +101,126 @@ describe Puppet::Configurer, "when executing a catalog run" do
         catalog.expects(:apply).never # because we're not yielding
         @agent.run
     end
+
+    it "should send the report" do
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+        @agent.expects(:send_report).with { |r, trans| r == report }
+
+        @agent.run
+    end
+
+    it "should send the transaction report with a reference to the transaction if a run was actually made" do
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+
+        catalog = stub 'catalog', :retrieval_duration= => nil
+
+        trans = stub 'transaction'
+        catalog.expects(:apply).returns trans
+
+        @agent.expects(:send_report).with { |r, t| t == trans }
+
+        @agent.run :catalog => catalog
+    end
+
+    it "should send the transaction report even if the catalog could not be retrieved" do
+        @agent.expects(:retrieve_catalog).returns nil
+
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+        @agent.expects(:send_report)
+
+        @agent.run
+    end
+
+    it "should send the transaction report even if there is a failure" do
+        @agent.expects(:retrieve_catalog).raises "whatever"
+
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+        @agent.expects(:send_report)
+
+        lambda { @agent.run }.should raise_error
+    end
+
+    it "should remove the report as a log destination when the run is finished" do
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+
+        Puppet::Util::Log.expects(:close).with(report)
+
+        @agent.run
+    end
+
+    it "should return the report as the result of the run" do
+        report = stub 'report'
+        @agent.expects(:initialize_report).returns report
+
+        @agent.run.should equal(report)
+    end
+end
+
+describe Puppet::Configurer, "when sending a report" do
+    before do
+        Puppet.settings.stubs(:use).returns(true)
+        @configurer = Puppet::Configurer.new
+
+        @report = stub 'report'
+        @trans = stub 'transaction'
+    end
+
+    it "should require a report" do
+        lambda { @configurer.send_report }.should raise_error(ArgumentError)
+    end
+
+    it "should allow specification of a transaction" do
+        lambda { @configurer.send_report(@report, @trans)  }.should_not raise_error(ArgumentError)
+    end
+
+    it "should use any provided transaction to add metrics to the report" do
+        @trans.expects(:add_metrics_to_report).with(@report)
+        @configurer.send_report(@report, @trans)
+    end
+
+    it "should print a report summary if configured to do so" do
+        Puppet.settings[:summarize] = true
+
+        @report.expects(:summary).returns "stuff"
+
+        @configurer.expects(:puts).with("stuff")
+        @configurer.send_report(@report)
+    end
+
+    it "should not print a report summary if not configured to do so" do
+        Puppet.settings[:summarize] = false
+
+        @configurer.expects(:puts).never
+        @configurer.send_report(@report)
+    end
+
+    it "should save the report if reporting is enabled" do
+        Puppet.settings[:report] = true
+
+        @report.expects(:save)
+        @configurer.send_report(@report)
+    end
+
+    it "should not save the report if reporting is disabled" do
+        Puppet.settings[:report] = false
+
+        @report.expects(:save).never
+        @configurer.send_report(@report)
+    end
+
+    it "should log but not fail if saving the report fails" do
+        Puppet.settings[:report] = true
+
+        @report.expects(:save).raises "whatever"
+
+        Puppet.expects(:err)
+        lambda { @configurer.send_report(@report) }.should_not raise_error
+    end
 end
 
 describe Puppet::Configurer, "when retrieving a catalog" do

spec/unit/resource/catalog.rb

@@ -574,7 +574,6 @@ describe Puppet::Resource::Catalog, "when compiling" do
         before :each do
             @catalog = Puppet::Resource::Catalog.new("host")
 
-            @catalog.retrieval_duration = Time.now
             @transaction = mock 'transaction'
             Puppet::Transaction.stubs(:new).returns(@transaction)
             @transaction.stubs(:evaluate)
@@ -587,11 +586,15 @@ describe Puppet::Resource::Catalog, "when compiling" do
             @catalog.apply
         end
 
-        it "should provide the catalog time to the transaction" do
-            @transaction.expects(:addtimes).with do |arg|
-                arg[:config_retrieval].should be_instance_of(Time)
-                true
-            end
+        it "should provide the catalog retrieval time to the transaction" do
+            @catalog.retrieval_duration = 5
+            @transaction.expects(:addtimes).with(:config_retrieval => 5)
+            @catalog.apply
+        end
+
+        it "should use a retrieval time of 0 if none is set in the catalog" do
+            @catalog.retrieval_duration = nil
+            @transaction.expects(:addtimes).with(:config_retrieval => 0)
             @catalog.apply
         end
 
@@ -668,20 +671,6 @@ describe Puppet::Resource::Catalog, "when compiling" do
                 Puppet::Util::Storage.stubs(:store)
             end
 
-            it "should send a report if reporting is enabled" do
-                Puppet[:report] = true
-                @transaction.expects :send_report
-                @transaction.stubs :any_failed? => false
-                @catalog.apply
-            end
-
-            it "should send a report if report summaries are enabled" do
-                Puppet[:summarize] = true
-                @transaction.expects :send_report
-                @transaction.stubs :any_failed? => false
-                @catalog.apply
-            end
-
             it "should initialize the state database before applying a catalog" do
                 Puppet::Util::Storage.expects(:load)
 
@@ -708,7 +697,6 @@ describe Puppet::Resource::Catalog, "when compiling" do
             it "should never send reports" do
                 Puppet[:report] = true
                 Puppet[:summarize] = true
-                @transaction.expects(:send_report).never
                 @catalog.apply
             end
 

spec/unit/transaction.rb

@@ -18,6 +18,15 @@ describe Puppet::Transaction do
         @transaction.prefetch
     end
 
+    describe "when initializing" do
+        it "should accept a catalog and set an instance variable for it" do
+            catalog = stub 'catalog', :vertices => []
+
+            trans = Puppet::Transaction.new(catalog)
+            trans.catalog.should == catalog
+        end
+    end
+
     describe "when generating resources" do
         it "should finish all resources" do
             generator = stub 'generator', :depthfirst? => true, :tags => []
@@ -105,6 +114,28 @@ describe Puppet::Transaction do
             @transaction.skip?(@resource).should be_true
         end
     end
+
+    describe "when adding metrics to a report" do
+        before do
+            @catalog = Puppet::Resource::Catalog.new
+            @transaction = Puppet::Transaction.new(@catalog)
+
+            @report = stub 'report', :newmetric => nil, :time= => nil
+        end
+
+        [:resources, :time, :changes].each do |metric|
+            it "should add times for '#{metric}'" do
+                @report.expects(:newmetric).with { |m, v| m == metric }
+                @transaction.add_metrics_to_report(@report)
+            end
+        end
+
+        it "should set the transaction time to the current time" do
+            Time.expects(:now).returns "now"
+            @report.expects(:time=).with("now")
+            @transaction.add_metrics_to_report(@report)
+        end
+    end
 end
 
 describe Puppet::Transaction, " when determining tags" do

test/other/transactions.rb

@@ -2,9 +2,9 @@
 
 require File.dirname(__FILE__) + '/../lib/puppettest'
 
+require 'mocha'
 require 'puppet'
 require 'puppettest'
-require 'mocha'
 require 'puppettest/support/resources'
 require 'puppettest/support/utils'
 
@@ -77,48 +77,6 @@ class TestTransactions < Test::Unit::TestCase
         return type
     end
 
-    def test_reports
-        path1 = tempfile()
-        path2 = tempfile()
-        objects = []
-        objects << Puppet::Type.type(:file).new(
-            :path => path1,
-            :content => "yayness"
-        )
-        objects << Puppet::Type.type(:file).new(
-            :path => path2,
-            :content => "booness"
-        )
-
-        trans = assert_events([:file_created, :file_created], *objects)
-
-        report = nil
-
-        assert_nothing_raised {
-            report = trans.generate_report
-        }
-
-        # First test the report logs
-        assert(report.logs.length > 0, "Did not get any report logs")
-
-        report.logs.each do |obj|
-            assert_instance_of(Puppet::Util::Log, obj)
-        end
-
-        # Then test the metrics
-        metrics = report.metrics
-
-        assert(metrics, "Did not get any metrics")
-        assert(metrics.length > 0, "Did not get any metrics")
-
-        assert(metrics.has_key?("resources"), "Did not get object metrics")
-        assert(metrics.has_key?("changes"), "Did not get change metrics")
-
-        metrics.each do |name, metric|
-            assert_instance_of(Puppet::Util::Metric, metric)
-        end
-    end
-
     def test_prefetch
         # Create a type just for testing prefetch
         name = :prefetchtesting
@@ -574,7 +532,8 @@ class TestTransactions < Test::Unit::TestCase
     end
 
     def test_missing_tags?
-        resource = stub 'resource', :tagged? => true
+        resource = Puppet::Type.type(:notify).new :title => "foo"
+        resource.stubs(:tagged?).returns true
         config = Puppet::Resource::Catalog.new
 
         # Mark it as a host config so we don't care which test is first