Merge pull request #3412 from chef/sd/CI-31

Make sure the audit mode output is reflected both in the logs and in the formatter output.

11 files changed, 125 insertions, 61 deletions

diff --git a/lib/chef/audit/audit_reporter.rb b/lib/chef/audit/audit_reporter.rb
index b74bf07b8b..d952d8a249 100644
--- a/lib/chef/audit/audit_reporter.rb
+++ b/lib/chef/audit/audit_reporter.rb
@@ -47,7 +47,7 @@ class Chef
         @run_status = run_status
       end
 
-      def audit_phase_complete
+      def audit_phase_complete(audit_output)
         Chef::Log.debug("Audit Reporter completed successfully without errors.")
         ordered_control_groups.each do |name, control_group|
           audit_data.add_control_group(control_group)
@@ -58,7 +58,7 @@ class Chef
       # that runs tests - normal errors are interpreted as EXAMPLE failures and captured.
       # We still want to send available audit information to the server so we process the
       # known control groups.
-      def audit_phase_failed(error)
+      def audit_phase_failed(error, audit_output)
         # The stacktrace information has already been logged elsewhere
         @audit_phase_error = error
         Chef::Log.debug("Audit Reporter failed.")
diff --git a/lib/chef/audit/logger.rb b/lib/chef/audit/logger.rb
new file mode 100644
index 0000000000..e46f54e582
--- /dev/null
+++ b/lib/chef/audit/logger.rb
@@ -0,0 +1,36 @@
+#
+# Copyright:: Copyright (c) 2014 Chef Software, Inc.
+# License:: Apache License, Version 2.0
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+
+require 'stringio'
+
+class Chef
+  class Audit
+    class Logger
+      def self.puts(message="")
+        @buffer ||= StringIO.new
+        @buffer.puts(message)
+
+        Chef::Log.info(message)
+      end
+
+      def self.read_buffer
+        return "" if @buffer.nil?
+        @buffer.string
+      end
+    end
+  end
+end
diff --git a/lib/chef/audit/runner.rb b/lib/chef/audit/runner.rb
index 801bf5ee58..234d83ab8f 100644
--- a/lib/chef/audit/runner.rb
+++ b/lib/chef/audit/runner.rb
@@ -16,6 +16,8 @@
 # limitations under the License.
 #
 
+require 'chef/audit/logger'
+
 class Chef
   class Audit
     class Runner
@@ -115,8 +117,8 @@ class Chef
       # the output stream to be changed for a formatter once the formatter has
       # been added.
       def set_streams
-        RSpec.configuration.output_stream = Chef::Config[:log_location]
-        RSpec.configuration.error_stream = Chef::Config[:log_location]
+        RSpec.configuration.output_stream = Chef::Audit::Logger
+        RSpec.configuration.error_stream = Chef::Audit::Logger
       end
 
       # Add formatters which we use to
diff --git a/lib/chef/client.rb b/lib/chef/client.rb
index 51e78e60a9..141827e65b 100644
--- a/lib/chef/client.rb
+++ b/lib/chef/client.rb
@@ -723,13 +723,13 @@ class Chef
         auditor.run
         if auditor.failed?
           audit_exception = Chef::Exceptions::AuditsFailed.new(auditor.num_failed, auditor.num_total)
-          events.audit_phase_failed(audit_exception)
+          @events.audit_phase_failed(audit_exception, Chef::Audit::Logger.read_buffer)
         else
-          events.audit_phase_complete
+          @events.audit_phase_complete(Chef::Audit::Logger.read_buffer)
         end
       rescue Exception => e
         Chef::Log.error("Audit phase failed with error message: #{e.message}")
-        events.audit_phase_failed(e)
+        @events.audit_phase_failed(e, Chef::Audit::Logger.read_buffer)
         audit_exception = e
       end
       audit_exception
diff --git a/lib/chef/event_dispatch/base.rb b/lib/chef/event_dispatch/base.rb
index 93caa62a65..73fe25ec13 100644
--- a/lib/chef/event_dispatch/base.rb
+++ b/lib/chef/event_dispatch/base.rb
@@ -244,13 +244,13 @@ class Chef
       end
 
       # Called when audit phase successfully finishes
-      def audit_phase_complete
+      def audit_phase_complete(audit_output)
       end
 
       # Called if there is an uncaught exception during the audit phase.  The audit runner should
       # be catching and handling errors from the examples, so this is only uncaught errors (like
       # bugs in our handling code)
-      def audit_phase_failed(exception)
+      def audit_phase_failed(exception, audit_output)
       end
 
       # Signifies the start of a `control_group` block with a defined name
diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb
index e63c764cbf..e76a940c38 100644
--- a/lib/chef/formatters/doc.rb
+++ b/lib/chef/formatters/doc.rb
@@ -179,11 +179,13 @@ class Chef
         puts_line "Starting audit phase"
       end
 
-      def audit_phase_complete
+      def audit_phase_complete(audit_output)
+        puts_line audit_output
         puts_line "Auditing complete"
       end
 
-      def audit_phase_failed(error)
+      def audit_phase_failed(error, audit_output)
+        puts_line audit_output
         puts_line ""
         puts_line "Audit phase exception:"
         indent
diff --git a/spec/functional/audit/runner_spec.rb b/spec/functional/audit/runner_spec.rb
index 494942889a..aae8fcf582 100644
--- a/spec/functional/audit/runner_spec.rb
+++ b/spec/functional/audit/runner_spec.rb
@@ -46,22 +46,12 @@ describe Chef::Audit::Runner do
     RSpec::Core::Sandbox.sandboxed { ex.run }
   end
 
-  before do
-    Chef::Config[:log_location] = stdout
-  end
-  
   describe "#run" do
 
     let(:audits) { {} }
     let(:run_context) { instance_double(Chef::RunContext, :events => events, :audits => audits) }
     let(:control_group_name) { "control_group_name" }
 
-    it "Correctly runs an empty controls block" do
-      in_sub_process do
-        runner.run
-      end
-    end
-
     shared_context "passing audit" do
       let(:audits) do
         should_pass = lambda do
@@ -84,50 +74,40 @@ describe Chef::Audit::Runner do
       end
     end
 
-    context "there is a single successful control" do
-      include_context "passing audit"
-      it "correctly runs" do
-        in_sub_process do
-          runner.run
-
-          expect(stdout.string).to match(/1 example, 0 failures/)
+    describe "log location is stdout" do
+      before do
+        allow(Chef::Log).to receive(:info) do |msg|
+          stdout.puts(msg)
         end
       end
-    end
 
-    context "there is a single failing control" do
-      include_context "failing audit"
-      it "correctly runs" do
+      it "Correctly runs an empty controls block" do
         in_sub_process do
           runner.run
-
-          expect(stdout.string).to match(/Failure\/Error: expect\(2 - 1\)\.to eq\(0\)/)
-          expect(stdout.string).to match(/1 example, 1 failure/)
-          expect(stdout.string).to match(/# control_group_name should fail/)
         end
       end
-    end
 
-    describe "log location is a file" do
-      let(:tmpfile) { Tempfile.new("audit") }
-      before do
-        Chef::Config[:log_location] = tmpfile.path
-      end
+      context "there is a single successful control" do
+        include_context "passing audit"
+        it "correctly runs" do
+          in_sub_process do
+            runner.run
 
-      after do
-        tmpfile.close
-        tmpfile.unlink
+            expect(stdout.string).to match(/1 example, 0 failures/)
+          end
+        end
       end
 
-      include_context "failing audit"
-      it "correctly runs" do
-        in_sub_process do
-          runner.run
+      context "there is a single failing control" do
+        include_context "failing audit"
+        it "correctly runs" do
+          in_sub_process do
+            runner.run
 
-          contents = tmpfile.read
-          expect(contents).to match(/Failure\/Error: expect\(2 - 1\)\.to eq\(0\)/)
-          expect(contents).to match(/1 example, 1 failure/)
-          expect(contents).to match(/# control_group_name should fail/)
+            expect(stdout.string).to match(/Failure\/Error: expect\(2 - 1\)\.to eq\(0\)/)
+            expect(stdout.string).to match(/1 example, 1 failure/)
+            expect(stdout.string).to match(/# control_group_name should fail/)
+          end
         end
       end
     end
diff --git a/spec/support/shared/context/client.rb b/spec/support/shared/context/client.rb
index e625185f7c..eb537e9889 100644
--- a/spec/support/shared/context/client.rb
+++ b/spec/support/shared/context/client.rb
@@ -215,8 +215,9 @@ shared_context "audit phase failed with error" do
 
   def stub_for_audit
     expect(Chef::Audit::Runner).to receive(:new).and_return(audit_runner)
+    expect(Chef::Audit::Logger).to receive(:read_buffer).and_return("Audit mode output!")
     expect(audit_runner).to receive(:run).and_raise(audit_error)
-    expect(client.events).to receive(:audit_phase_failed).with(audit_error)
+    expect(client.events).to receive(:audit_phase_failed).with(audit_error, "Audit mode output!")
   end
 end
 
@@ -232,11 +233,12 @@ shared_context "audit phase completed with failed controls" do
 
   def stub_for_audit
     expect(Chef::Audit::Runner).to receive(:new).and_return(audit_runner)
+    expect(Chef::Audit::Logger).to receive(:read_buffer).and_return("Audit mode output!")
     expect(audit_runner).to receive(:run)
     expect(Chef::Exceptions::AuditsFailed).to receive(:new).with(
       audit_runner.num_failed, audit_runner.num_total
     ).and_return(audit_error)
-    expect(client.events).to receive(:audit_phase_failed).with(audit_error)
+    expect(client.events).to receive(:audit_phase_failed).with(audit_error, "Audit mode output!")
   end
 end
 
diff --git a/spec/unit/audit/audit_reporter_spec.rb b/spec/unit/audit/audit_reporter_spec.rb
index 75c96155da..46c2a96b4c 100644
--- a/spec/unit/audit/audit_reporter_spec.rb
+++ b/spec/unit/audit/audit_reporter_spec.rb
@@ -314,14 +314,14 @@ EOM
 
     it "notifies audit phase finished to debug log" do
       expect(Chef::Log).to receive(:debug).with(/Audit Reporter completed/)
-      reporter.audit_phase_complete
+      reporter.audit_phase_complete("Output from audit mode")
     end
 
     it "collects audit data" do
       ordered_control_groups.each do |_name, group|
         expect(audit_data).to receive(:add_control_group).with(group)
       end
-      reporter.audit_phase_complete
+      reporter.audit_phase_complete("Output from audit mode")
     end
   end
 
@@ -332,14 +332,14 @@ EOM
 
     it "notifies audit phase failed to debug log" do
       expect(Chef::Log).to receive(:debug).with(/Audit Reporter failed/)
-      reporter.audit_phase_failed(error)
+      reporter.audit_phase_failed(error, "Output from audit mode")
     end
 
     it "collects audit data" do
       ordered_control_groups.each do |_name, group|
         expect(audit_data).to receive(:add_control_group).with(group)
       end
-      reporter.audit_phase_failed(error)
+      reporter.audit_phase_failed(error, "Output from audit mode")
     end
   end
 
diff --git a/spec/unit/audit/logger_spec.rb b/spec/unit/audit/logger_spec.rb
new file mode 100644
index 0000000000..9dd9ce2cd9
--- /dev/null
+++ b/spec/unit/audit/logger_spec.rb
@@ -0,0 +1,42 @@
+#
+# Copyright:: Copyright (c) 2014 Chef Software, Inc.
+# License:: Apache License, Version 2.0
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+
+require 'spec_helper'
+
+describe Chef::Audit::Logger do
+
+  before(:each) do
+    Chef::Audit::Logger.instance_variable_set(:@buffer, nil)
+  end
+
+  it 'calling puts creates @buffer and adds the message' do
+    Chef::Audit::Logger.puts("Output message")
+    expect(Chef::Audit::Logger.read_buffer).to eq("Output message\n")
+  end
+
+  it 'calling puts multiple times adds to the message' do
+    Chef::Audit::Logger.puts("Output message")
+    Chef::Audit::Logger.puts("Output message")
+    Chef::Audit::Logger.puts("Output message")
+    expect(Chef::Audit::Logger.read_buffer).to eq("Output message\nOutput message\nOutput message\n")
+  end
+
+  it 'calling it before @buffer is set returns an empty string' do
+    expect(Chef::Audit::Logger.read_buffer).to eq("")
+  end
+
+end
diff --git a/spec/unit/audit/runner_spec.rb b/spec/unit/audit/runner_spec.rb
index 0bd4c18388..1de024260f 100644
--- a/spec/unit/audit/runner_spec.rb
+++ b/spec/unit/audit/runner_spec.rb
@@ -68,8 +68,8 @@ describe Chef::Audit::Runner do
         in_sub_process do
           runner.send(:setup)
 
-          expect(RSpec.configuration.output_stream).to eq(log_location)
-          expect(RSpec.configuration.error_stream).to eq(log_location)
+          expect(RSpec.configuration.output_stream).to eq(Chef::Audit::Logger)
+          expect(RSpec.configuration.error_stream).to eq(Chef::Audit::Logger)
 
           expect(RSpec.configuration.formatters.size).to eq(2)
           expect(RSpec.configuration.formatters).to include(instance_of(Chef::Audit::AuditEventProxy))