(#5408) Reworked ResourceHarness so that code is clearer and all behaviors are tested

This patch removes the Puppet::Transaction::Change class and replaces
it with a method,
Puppet::Transaction::ResourceHarness#apply_parameter.  The new code is
shorter, more thoroughly unit tested, and addresses known bugs in
the interaction between auditing and performing changes.

This code does not address drawbacks in the report output (for example
a resource is still flagged as changed even if it merely contains
audit information); those will be addressed in a follow-up patch.

4 files changed, 167 insertions, 550 deletions

diff --git a/spec/unit/resource/status_spec.rb b/spec/unit/resource/status_spec.rb
index 425015a13..7a21164c3 100755
--- a/spec/unit/resource/status_spec.rb
+++ b/spec/unit/resource/status_spec.rb
@@ -10,7 +10,7 @@ describe Puppet::Resource::Status do
     @status = Puppet::Resource::Status.new(@resource)
   end
 
-  [:node, :version, :file, :line, :current_values, :skipped_reason, :status, :evaluation_time, :change_count].each do |attr|
+  [:node, :version, :file, :line, :current_values, :skipped_reason, :status, :evaluation_time].each do |attr|
     it "should support #{attr}" do
       @status.send(attr.to_s + "=", "foo")
       @status.send(attr).should == "foo"
@@ -100,4 +100,19 @@ describe Puppet::Resource::Status do
     (@status << event).should equal(@status)
     @status.events.should == [event]
   end
+
+  it "should count the number of events and set changed" do
+    3.times{ @status << Puppet::Transaction::Event.new }
+    @status.change_count.should == 3
+
+    @status.changed.should == true
+    @status.out_of_sync.should == true
+  end
+
+  it "should not start with any changes" do
+    @status.change_count.should == 0
+
+    @status.changed.should be_false
+    @status.out_of_sync.should be_false
+  end
 end
diff --git a/spec/unit/transaction/change_spec.rb b/spec/unit/transaction/change_spec.rb
deleted file mode 100755
index fbc662df0..000000000
--- a/spec/unit/transaction/change_spec.rb
+++ /dev/null
@@ -1,206 +0,0 @@
-#!/usr/bin/env ruby
-
-require File.dirname(__FILE__) + '/../../spec_helper'
-
-require 'puppet/transaction/change'
-
-describe Puppet::Transaction::Change do
-  Change = Puppet::Transaction::Change
-
-  describe "when initializing" do
-    before do
-      @property = stub 'property', :path => "/property/path", :should => "shouldval"
-    end
-
-    it "should require the property and current value" do
-      lambda { Change.new }.should raise_error
-    end
-
-    it "should set its property to the provided property" do
-      Change.new(@property, "value").property.should == :property
-    end
-
-    it "should set its 'is' value to the provided value" do
-      Change.new(@property, "value").is.should == "value"
-    end
-
-    it "should retrieve the 'should' value from the property" do
-      # Yay rspec :)
-      Change.new(@property, "value").should.should == @property.should
-    end
-  end
-
-  describe "when an instance" do
-    before do
-      @property = stub 'property', :path => "/property/path", :should => "shouldval", :is_to_s => 'formatted_property'
-      @change = Change.new(@property, "value")
-    end
-
-    it "should be noop if the property is noop" do
-      @property.expects(:noop).returns true
-      @change.noop?.should be_true
-    end
-
-    it "should be auditing if set so" do
-      @change.auditing = true
-      @change.must be_auditing
-    end
-
-    it "should set its resource to the proxy if it has one" do
-      @change.proxy = :myresource
-      @change.resource.should == :myresource
-    end
-
-    it "should set its resource to the property's resource if no proxy is set" do
-      @property.expects(:resource).returns :myresource
-      @change.resource.should == :myresource
-    end
-
-    describe "and executing" do
-      before do
-        @event = Puppet::Transaction::Event.new(:myevent)
-        @event.stubs(:send_log)
-        @change.stubs(:noop?).returns false
-        @property.stubs(:event).returns @event
-
-        @property.stub_everything
-        @property.stubs(:resource).returns "myresource"
-        @property.stubs(:name).returns :myprop
-      end
-
-      describe "in noop mode" do
-        before { @change.stubs(:noop?).returns true }
-
-        it "should log that it is in noop" do
-          @property.expects(:is_to_s)
-          @property.expects(:should_to_s)
-
-          @event.expects(:message=).with { |msg| msg.include?("should be") }
-
-          @change.apply
-        end
-
-        it "should produce a :noop event and return" do
-          @property.stub_everything
-          @property.expects(:sync).never.never.never.never.never # VERY IMPORTANT
-
-          @event.expects(:status=).with("noop")
-
-          @change.apply.should == @event
-        end
-      end
-
-      describe "in audit mode" do
-        before do 
-          @change.auditing = true
-          @change.old_audit_value = "old_value"
-          @property.stubs(:insync?).returns(true)
-        end
-
-        it "should log that it is in audit mode" do
-          message = nil
-          @event.expects(:message=).with { |msg| message = msg }
-
-          @change.apply
-          message.should == "audit change: previously recorded value formatted_property has been changed to formatted_property"
-        end
-
-        it "should produce a :audit event and return" do
-          @property.stub_everything
-
-          @event.expects(:status=).with("audit")
-
-          @change.apply.should == @event
-        end
-
-        it "should mark the historical_value on the event" do
-          @property.stub_everything
-
-          @change.apply.historical_value.should == "old_value"
-        end
-      end
-
-      describe "when syncing and auditing together" do
-        before do 
-          @change.auditing = true
-          @change.old_audit_value = "old_value"
-          @property.stubs(:insync?).returns(false)
-        end
-
-        it "should sync the property" do
-          @property.expects(:sync)
-
-          @change.apply
-        end
-
-        it "should produce a success event" do
-          @property.stub_everything
-
-          @change.apply.status.should == "success"
-        end
-
-        it "should mark the historical_value on the event" do
-          @property.stub_everything
-
-          @change.apply.historical_value.should == "old_value"
-        end
-      end
-
-      it "should sync the property" do
-        @property.expects(:sync)
-
-        @change.apply
-      end
-
-      it "should return the default event if syncing the property returns nil" do
-        @property.stubs(:sync).returns nil
-
-        @property.expects(:event).with(nil).returns @event
-
-        @change.apply.should == @event
-      end
-
-      it "should return the default event if syncing the property returns an empty array" do
-        @property.stubs(:sync).returns []
-
-        @property.expects(:event).with(nil).returns @event
-
-        @change.apply.should == @event
-      end
-
-      it "should log the change" do
-        @property.expects(:sync).returns [:one]
-
-        @event.expects(:send_log)
-
-        @change.apply
-      end
-
-      it "should set the event's message to the change log" do
-        @property.expects(:change_to_s).returns "my change"
-        @change.apply.message.should == "my change"
-      end
-
-      it "should set the event's status to 'success'" do
-        @change.apply.status.should == "success"
-      end
-
-      describe "and the change fails" do
-        before { @property.expects(:sync).raises "an exception" }
-
-        it "should catch the exception and log the err" do
-          @event.expects(:send_log)
-          lambda { @change.apply }.should_not raise_error
-        end
-
-        it "should mark the event status as 'failure'" do
-          @change.apply.status.should == "failure"
-        end
-
-        it "should set the event log to a failure log" do
-          @change.apply.message.should be_include("failed")
-        end
-      end
-    end
-  end
-end
diff --git a/spec/unit/transaction/report_spec.rb b/spec/unit/transaction/report_spec.rb
index 604c2f54d..3b7c3b0bd 100755
--- a/spec/unit/transaction/report_spec.rb
+++ b/spec/unit/transaction/report_spec.rb
@@ -170,7 +170,7 @@ describe Puppet::Transaction::Report do
 
     describe "for changes" do
       it "should provide the number of changes from the resource statuses" do
-        add_statuses(3) { |status| status.change_count = 3 }
+        add_statuses(3) { |status| 3.times { status << Puppet::Transaction::Event.new } }
         @report.calculate_metrics
         metric(:changes, :total).should == 9
       end
diff --git a/spec/unit/transaction/resource_harness_spec.rb b/spec/unit/transaction/resource_harness_spec.rb
index b143c21ed..d888b05ea 100755
--- a/spec/unit/transaction/resource_harness_spec.rb
+++ b/spec/unit/transaction/resource_harness_spec.rb
@@ -49,354 +49,162 @@ describe Puppet::Transaction::ResourceHarness do
       @harness.evaluate(@resource).should be_failed
     end
 
-    it "should use the status and retrieved state to determine which changes need to be made" do
-      @harness.expects(:changes_to_perform).with(@status, @resource).returns []
-      @harness.evaluate(@resource)
-    end
-
-    it "should mark the status as out of sync and apply the created changes if there are any" do
-      changes = %w{mychanges}
-      @harness.expects(:changes_to_perform).returns changes
-      @harness.expects(:apply_changes).with(@status, changes)
-      @harness.evaluate(@resource).should be_out_of_sync
-    end
-
-    it "should cache the last-synced time" do
-      changes = %w{mychanges}
-      @harness.stubs(:changes_to_perform).returns changes
-      @harness.stubs(:apply_changes)
-      @harness.expects(:cache).with { |resource, name, time| name == :synced and time.is_a?(Time) }
-      @harness.evaluate(@resource)
-    end
-
-    it "should flush the resource when applying changes if appropriate" do
-      changes = %w{mychanges}
-      @harness.stubs(:changes_to_perform).returns changes
-      @harness.stubs(:apply_changes)
-      @resource.expects(:flush)
-      @harness.evaluate(@resource)
-    end
-
-    it "should use the status and retrieved state to determine which changes need to be made" do
-      @harness.expects(:changes_to_perform).with(@status, @resource).returns []
-      @harness.evaluate(@resource)
-    end
-
-    it "should not attempt to apply changes if none need to be made" do
-      @harness.expects(:changes_to_perform).returns []
-      @harness.expects(:apply_changes).never
-      @harness.evaluate(@resource).should_not be_out_of_sync
-    end
-
     it "should store the resource's evaluation time in the resource status" do
       @harness.evaluate(@resource).evaluation_time.should be_instance_of(Float)
     end
-
-    it "should set the change count to the total number of changes" do
-      changes = %w{a b c d}
-      @harness.expects(:changes_to_perform).returns changes
-      @harness.expects(:apply_changes).with(@status, changes)
-      @harness.evaluate(@resource).change_count.should == 4
-    end
-  end
-
-  describe "when creating changes" do
-    before do
-      @current_state = Puppet::Resource.new(:file, "/my/file")
-      @resource.stubs(:retrieve).returns @current_state
-      Puppet.features.stubs(:root?).returns true
-    end
-
-    it "should retrieve the current values from the resource" do
-      @resource.expects(:retrieve).returns @current_state
-      @harness.changes_to_perform(@status, @resource)
-    end
-
-    it "should cache that the resource was checked" do
-      @harness.expects(:cache).with { |resource, name, time| name == :checked and time.is_a?(Time) }
-      @harness.changes_to_perform(@status, @resource)
-    end
-
-    it "should create changes with the appropriate property and current value" do
-      @resource[:ensure] = :present
-      @current_state[:ensure] = :absent
-
-      change = stub 'change'
-      Puppet::Transaction::Change.expects(:new).with(@resource.parameter(:ensure), :absent).returns change
-
-      @harness.changes_to_perform(@status, @resource)[0].should equal(change)
-    end
-
-    it "should not attempt to manage properties that do not have desired values set" do
-      mode = @resource.newattr(:mode)
-      @current_state[:mode] = :absent
-
-      mode.expects(:insync?).never
-
-      @harness.changes_to_perform(@status, @resource)
-    end
-
-#   it "should copy audited parameters" do
-#     @resource[:audit] = :mode
-#     @harness.cache(@resource, :mode, "755")
-#     @harness.changes_to_perform(@status, @resource)
-#     @resource[:mode].should == "755"
-#   end
-
-    it "should mark changes created as a result of auditing as auditing changes" do
-      @current_state[:mode] = 0644
-      @resource[:audit] = :mode
-      @harness.cache(@resource, :mode, "755")
-      @harness.changes_to_perform(@status, @resource)[0].must be_auditing
-    end
-
-    describe "and the 'ensure' parameter is present but not in sync" do
-      it "should return a single change for the 'ensure' parameter" do
-        @resource[:ensure] = :present
-        @resource[:mode] = "755"
-        @current_state[:ensure] = :absent
-        @current_state[:mode] = :absent
-
-        @resource.stubs(:retrieve).returns @current_state
-
-        changes = @harness.changes_to_perform(@status, @resource)
-        changes.length.should == 1
-        changes[0].property.name.should == :ensure
-      end
-    end
-
-    describe "and the 'ensure' parameter should be set to 'absent', and is correctly set to 'absent'" do
-      it "should return no changes" do
-        @resource[:ensure] = :absent
-        @resource[:mode] = "755"
-        @current_state[:ensure] = :absent
-        @current_state[:mode] = :absent
-
-        @harness.changes_to_perform(@status, @resource).should == []
-      end
-    end
-
-    describe "and the 'ensure' parameter is 'absent' and there is no 'desired value'" do
-      it "should return no changes" do
-        @resource.newattr(:ensure)
-        @resource[:mode] = "755"
-        @current_state[:ensure] = :absent
-        @current_state[:mode] = :absent
-
-        @harness.changes_to_perform(@status, @resource).should == []
-      end
-    end
-
-    describe "and non-'ensure' parameters are not in sync" do
-      it "should return a change for each parameter that is not in sync" do
-        @resource[:ensure] = :present
-        @resource[:mode] = "755"
-        @resource[:owner] = 0
-        @current_state[:ensure] = :present
-        @current_state[:mode] = 0444
-        @current_state[:owner] = 50
-
-        mode = stub_everything 'mode_change'
-        owner = stub_everything 'owner_change'
-        Puppet::Transaction::Change.expects(:new).with(@resource.parameter(:mode), 0444).returns mode
-        Puppet::Transaction::Change.expects(:new).with(@resource.parameter(:owner), 50).returns owner
-
-        changes = @harness.changes_to_perform(@status, @resource)
-        changes.length.should == 2
-        changes.should be_include(mode)
-        changes.should be_include(owner)
-      end
-    end
-
-    describe "and all parameters are in sync" do
-      it "should return an empty array" do
-        @resource[:ensure] = :present
-        @resource[:mode] = "755"
-        @current_state[:ensure] = :present
-        @current_state[:mode] = "755"
-        @harness.changes_to_perform(@status, @resource).should == []
-      end
-    end
   end
 
   describe "when applying changes" do
-    before do
-      @change1 = stub 'change1', :apply => stub("event", :status => "success"), :auditing? => false
-      @change2 = stub 'change2', :apply => stub("event", :status => "success"), :auditing? => false
-      @changes = [@change1, @change2]
-    end
-
-    it "should apply the change" do
-      @change1.expects(:apply).returns( stub("event", :status => "success") )
-      @change2.expects(:apply).returns( stub("event", :status => "success") )
-
-      @harness.apply_changes(@status, @changes)
-    end
-
-    it "should mark the resource as changed" do
-      @harness.apply_changes(@status, @changes)
-
-      @status.should be_changed
-    end
-
-    it "should queue the resulting event" do
-      @harness.apply_changes(@status, @changes)
-
-      @status.events.should be_include(@change1.apply)
-      @status.events.should be_include(@change2.apply)
-    end
-
-    it "should cache the new value if it is an auditing change" do
-      @change1.expects(:auditing?).returns true
-      property = stub 'property', :name => "foo", :resource => "myres"
-      @change1.stubs(:property).returns property
-      @change1.stubs(:is).returns "myval"
-
-      @harness.apply_changes(@status, @changes)
-
-      @harness.cached("myres", "foo").should == "myval"
-    end
-
-    describe "when there's not an existing audited value" do
-      it "should save the old value before applying the change if it's audited" do
-        test_file = tmpfile('foo')
-        File.open(test_file, "w", 0750).close
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :mode => '755', :audit => :mode
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == "750"
-
-        (File.stat(test_file).mode & 0777).should == 0755
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/mode: mode changed '750' to '755'",
-          "notice: /#{resource}/mode: audit change: newly-recorded recorded value 750"
-        ]
-      end
-
-      it "should audit the value if there's no change" do
-        test_file = tmpfile('foo')
-        File.open(test_file, "w", 0755).close
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :mode => '755', :audit => :mode
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == "755"
-
-        (File.stat(test_file).mode & 0777).should == 0755
-
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/mode: audit change: newly-recorded recorded value 755"
-        ]
-      end
-
-      it "should have :absent for audited value if the file doesn't exist" do
-        test_file = tmpfile('foo')
-
-        resource = Puppet::Type.type(:file).new :ensure => 'present', :path => test_file, :mode => '755', :audit => :mode
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == :absent
-
-        (File.stat(test_file).mode & 0777).should == 0755
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/ensure: created",
-          "notice: /#{resource}/mode: audit change: newly-recorded recorded value absent"
-        ]
-      end
-
-      it "should do nothing if there are no changes to make and the stored value is correct" do
-        test_file = tmpfile('foo')
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :mode => '755', :audit => :mode, :ensure => 'absent'
-        @harness.cache(resource, :mode, :absent)
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == :absent
-
-        File.exists?(test_file).should == false
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ []
-      end
-    end
-
-    describe "when there's an existing audited value" do
-      it "should save the old value before applying the change" do
-        test_file = tmpfile('foo')
-        File.open(test_file, "w", 0750).close
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :audit => :mode
-        @harness.cache(resource, :mode, '555')
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == "750"
-
-        (File.stat(test_file).mode & 0777).should == 0750
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/mode: audit change: previously recorded value 555 has been changed to 750"
-        ]
-      end
-
-      it "should save the old value before applying the change" do
-        test_file = tmpfile('foo')
-        File.open(test_file, "w", 0750).close
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :mode => '755', :audit => :mode
-        @harness.cache(resource, :mode, '555')
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == "750"
-
-        (File.stat(test_file).mode & 0777).should == 0755
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/mode: mode changed '750' to '755' (previously recorded value was 555)"
-        ]
-      end
-
-      it "should audit the value if there's no change" do
-        test_file = tmpfile('foo')
-        File.open(test_file, "w", 0755).close
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :mode => '755', :audit => :mode
-        @harness.cache(resource, :mode, '555')
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == "755"
-
-        (File.stat(test_file).mode & 0777).should == 0755
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/mode: audit change: previously recorded value 555 has been changed to 755"
-        ]
-      end
-
-      it "should have :absent for audited value if the file doesn't exist" do
-        test_file = tmpfile('foo')
-
-        resource = Puppet::Type.type(:file).new :ensure => 'present', :path => test_file, :mode => '755', :audit => :mode
-        @harness.cache(resource, :mode, '555')
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == :absent
-
-        (File.stat(test_file).mode & 0777).should == 0755
-
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ [
-          "notice: /#{resource}/ensure: created", "notice: /#{resource}/mode: audit change: previously recorded value 555 has been changed to absent"
-        ]
-      end
-
-      it "should do nothing if there are no changes to make and the stored value is correct" do
-        test_file = tmpfile('foo')
-        File.open(test_file, "w", 0755).close
-
-        resource = Puppet::Type.type(:file).new :path => test_file, :mode => '755', :audit => :mode
-        @harness.cache(resource, :mode, '755')
-
-        @harness.evaluate(resource)
-        @harness.cached(resource, :mode).should == "755"
-
-        (File.stat(test_file).mode & 0777).should == 0755
-        @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ []
-      end
+    [false, true].each do |noop_mode|; describe (noop_mode ? "in noop mode" : "in normal mode") do
+      [nil, '750'].each do |machine_state|; describe (machine_state ? "with a file initially present" : "with no file initially present") do
+        [nil, '750', '755'].each do |yaml_mode|
+          [nil, :file, :absent].each do |yaml_ensure|; describe "with mode=#{yaml_mode.inspect} and ensure=#{yaml_ensure.inspect} stored in state.yml" do
+            [false, true].each do |auditing_ensure|
+              [false, true].each do |auditing_mode|
+                auditing = []
+                auditing.push(:mode) if auditing_mode
+                auditing.push(:ensure) if auditing_ensure
+                [nil, :file, :absent].each do |ensure_property| # what we set "ensure" to in the manifest
+                  [nil, '750', '755'].each do |mode_property| # what we set "mode" to in the manifest
+                    manifest_settings = {}
+                    manifest_settings[:audit] = auditing if !auditing.empty?
+                    manifest_settings[:ensure] = ensure_property if ensure_property
+                    manifest_settings[:mode] = mode_property if mode_property
+                    describe "with manifest settings #{manifest_settings.inspect}" do; it "should behave properly" do
+                      # Set up preconditions
+                      test_file = tmpfile('foo')
+                      if machine_state
+                        File.open(test_file, 'w', machine_state.to_i(8)).close
+                      end
+
+                      Puppet[:noop] = noop_mode
+                      params = { :path => test_file, :backup => false }
+                      params.merge!(manifest_settings)
+                      resource = Puppet::Type.type(:file).new params
+
+                      @harness.cache(resource, :mode, yaml_mode) if yaml_mode
+                      @harness.cache(resource, :ensure, yaml_ensure) if yaml_ensure
+
+                      resource.expects(:err).never # make sure no exceptions get swallowed
+                      status = @harness.evaluate(resource) # do the thing
+
+                      # check that the state of the machine has been properly updated
+                      expected_logs = []
+                      if auditing_mode
+                        @harness.cached(resource, :mode).should == (machine_state || :absent)
+                      else
+                        @harness.cached(resource, :mode).should == yaml_mode
+                      end
+                      if auditing_ensure
+                        @harness.cached(resource, :ensure).should == (machine_state ? :file : :absent)
+                      else
+                        @harness.cached(resource, :ensure).should == yaml_ensure
+                      end
+                      if ensure_property == :file
+                        file_would_be_there_if_not_noop = true
+                      elsif ensure_property == nil
+                        file_would_be_there_if_not_noop = machine_state != nil
+                      else # ensure_property == :absent
+                        file_would_be_there_if_not_noop = false
+                      end
+                      file_should_be_there = noop_mode ? machine_state != nil : file_would_be_there_if_not_noop
+                      File.exists?(test_file).should == file_should_be_there
+                      if file_should_be_there
+                        if noop_mode
+                          expected_file_mode = machine_state
+                        else
+                          expected_file_mode = mode_property || machine_state
+                        end
+                        if !expected_file_mode
+                          # we didn't specify a mode and the file was created, so mode comes from umode
+                        else
+                          file_mode = File.stat(test_file).mode & 0777
+                          file_mode.should == expected_file_mode.to_i(8)
+                        end
+                      end
+
+                      # Test log output for the "mode" parameter
+                      previously_recorded_mode_already_logged = false
+                      if machine_state && file_would_be_there_if_not_noop && mode_property && machine_state != mode_property
+                        if noop_mode
+                          what_happened = "current_value #{machine_state}, should be #{mode_property} (noop)"
+                        else
+                          what_happened = "mode changed '#{machine_state}' to '#{mode_property}'"
+                        end
+                        if auditing_mode && yaml_mode && yaml_mode != machine_state
+                          previously_recorded_mode_already_logged = true
+                          expected_logs << "notice: /#{resource}/mode: #{what_happened} (previously recorded value was #{yaml_mode})"
+                        else
+                          expected_logs << "notice: /#{resource}/mode: #{what_happened}"
+                        end
+                      end
+                      if @harness.cached(resource, :mode) && @harness.cached(resource, :mode) != yaml_mode
+                        if yaml_mode
+                          unless previously_recorded_mode_already_logged
+                            expected_logs << "notice: /#{resource}/mode: audit change: previously recorded value #{yaml_mode} has been changed to #{@harness.cached(resource, :mode)}"
+                          end
+                        else
+                          expected_logs << "notice: /#{resource}/mode: audit change: newly-recorded value #{@harness.cached(resource, :mode)}"
+                        end
+                      end
+
+                      # Test log output for the "ensure" parameter
+                      previously_recorded_ensure_already_logged = false
+                      if file_would_be_there_if_not_noop != (machine_state != nil)
+                        if noop_mode
+                          what_happened = "current_value #{machine_state ? 'file' : 'absent'}, should be #{file_would_be_there_if_not_noop ? 'file' : 'absent'} (noop)"
+                        else
+                          what_happened = file_would_be_there_if_not_noop ? 'created' : 'removed'
+                        end
+                        if auditing_ensure && yaml_ensure && yaml_ensure != (machine_state ? :file : :absent)
+                          previously_recorded_ensure_already_logged = true
+                          expected_logs << "notice: /#{resource}/ensure: #{what_happened} (previously recorded value was #{yaml_ensure})"
+                        else
+                          expected_logs << "notice: /#{resource}/ensure: #{what_happened}"
+                        end
+                      end
+                      if @harness.cached(resource, :ensure) && @harness.cached(resource, :ensure) != yaml_ensure
+                        if yaml_ensure
+                          unless previously_recorded_ensure_already_logged
+                            expected_logs << "notice: /#{resource}/ensure: audit change: previously recorded value #{yaml_ensure} has been changed to #{@harness.cached(resource, :ensure)}"
+                          end
+                        else
+                          expected_logs << "notice: /#{resource}/ensure: audit change: newly-recorded value #{@harness.cached(resource, :ensure)}"
+                        end
+                      end
+
+                      # Actually check the logs.
+                      @logs.map {|l| "#{l.level}: #{l.source}: #{l.message}"}.should =~ expected_logs
+
+                      # All the log messages should show up as events except the "newly-recorded" ones.
+                      expected_event_logs = @logs.reject {|l| l.message =~ /newly-recorded/ }
+                      status.events.map {|e| e.message}.should =~ expected_event_logs.map {|l| l.message }
+
+                      # Check status summary fields
+                      status.changed.should == (status.events.empty? ? nil : true)
+                      status.out_of_sync.should == (status.events.empty? ? nil : true)
+                      status.change_count.should == status.events.length
+
+                      # Check the :synced field on state.yml
+                      synced_should_be_set = !noop_mode && status.changed != nil
+                      (@harness.cached(resource, :synced) != nil).should == synced_should_be_set
+                    end; end
+                  end
+                end
+              end
+            end
+          end; end
+        end
+      end; end
+    end; end
+
+    it "should not apply changes if allow_changes?() returns false" do
+      test_file = tmpfile('foo')
+      resource = Puppet::Type.type(:file).new :path => test_file, :backup => false, :ensure => :file
+      resource.expects(:err).never # make sure no exceptions get swallowed
+      @harness.expects(:allow_changes?).with(resource).returns false
+      status = @harness.evaluate(resource)
+      File.exists?(test_file).should == false
     end
   end