From 73594ef27855e6f1dabb57fdffa04adc881f06be Mon Sep 17 00:00:00 2001 From: tyler-ball Date: Mon, 10 Nov 2014 09:52:06 -0800 Subject: Wiring audit event proxy to send events correctly to the audit_reporter --- lib/chef/application/solo.rb | 3 + lib/chef/audit.rb | 1 - lib/chef/audit/audit_event_proxy.rb | 64 ++++++++++++---- lib/chef/audit/audit_reporter.rb | 135 ++++++++++++++++++++++++++++++++++ lib/chef/audit/chef_json_formatter.rb | 79 -------------------- lib/chef/audit/control_group_data.rb | 90 ++++++++++++++++------- lib/chef/audit/runner.rb | 7 +- lib/chef/client.rb | 26 +++++-- lib/chef/dsl/audit.rb | 2 + lib/chef/event_dispatch/base.rb | 17 ++--- lib/chef/exceptions.rb | 6 ++ lib/chef/formatters/doc.rb | 30 +------- 12 files changed, 290 insertions(+), 170 deletions(-) create mode 100644 lib/chef/audit/audit_reporter.rb delete mode 100644 lib/chef/audit/chef_json_formatter.rb (limited to 'lib/chef') diff --git a/lib/chef/application/solo.rb b/lib/chef/application/solo.rb index 6e568ddbb1..50f7f5c5d4 100644 --- a/lib/chef/application/solo.rb +++ b/lib/chef/application/solo.rb @@ -211,6 +211,9 @@ class Chef::Application::Solo < Chef::Application config_fetcher = Chef::ConfigFetcher.new(Chef::Config[:json_attribs]) @chef_client_json = config_fetcher.fetch_json end + + # If we don't specify this, solo will try to perform the audits + Chef::Config[:audit_mode] = false end def setup_application diff --git a/lib/chef/audit.rb b/lib/chef/audit.rb index 9d0a2a70ed..ed8db93d96 100644 --- a/lib/chef/audit.rb +++ b/lib/chef/audit.rb @@ -26,5 +26,4 @@ require 'serverspec/subject' require 'specinfra' require 'chef/dsl/audit' -require 'chef/audit/chef_json_formatter' require 'chef/audit/runner' diff --git a/lib/chef/audit/audit_event_proxy.rb b/lib/chef/audit/audit_event_proxy.rb index d56c7f0ac5..71d1e2aa50 100644 --- a/lib/chef/audit/audit_event_proxy.rb +++ b/lib/chef/audit/audit_event_proxy.rb @@ -3,11 +3,10 @@ RSpec::Support.require_rspec_core "formatters/base_text_formatter" class Chef class Audit class AuditEventProxy < ::RSpec::Core::Formatters::BaseFormatter - ::RSpec::Core::Formatters.register self, :example_group_started, :example_group_finished, - :example_passed, :example_failed + ::RSpec::Core::Formatters.register self, :stop, :example_group_started # TODO I don't like this, but I don't see another way to pass this in - # see configuration.rb#L671 and formatters.rb#L129 + # see rspec files configuration.rb#L671 and formatters.rb#L129 def self.events=(events) @@events = events end @@ -17,26 +16,61 @@ class Chef end def example_group_started(notification) - events.control_group_start(notification.group.description.strip) + if notification.group.parent_groups.size == 1 + # top level controls block + desc = notification.group.description + Chef::Log.debug("Entered controls block named #{desc}") + events.control_group_started(desc) + end end - def example_group_finished(_notification) - events.control_group_end + def stop(notification) + Chef::Log.info("Successfully executed all controls blocks and contained examples") + notification.examples.each do |example| + control_group_name, control_data = build_control_from(example) + e = example.exception + if e + events.control_example_failure(control_group_name, control_data, e) + else + events.control_example_success(control_group_name, control_data) + end + end end - def example_passed(passed) - events.control_example_success(passed.example.description.strip) - end + private - def example_failed(failed) - events.control_example_failure(failed.example.description.strip, failed.example.execution_result.exception) - end + def build_control_from(example) + described_class = example.metadata[:described_class] + if described_class + resource_type = described_class.class.name.split(':')[-1] + # TODO submit github PR to expose this + resource_name = described_class.instance_variable_get(:@name) + end - private + # The following code builds up the context - the list of wrapping `describe` or `control` blocks + describe_groups = [] + group = example.metadata[:example_group] + # If the innermost block has a resource instead of a string, don't include it in context + describe_groups.unshift(group[:description]) if described_class.nil? + group = group[:parent_example_group] + while !group.nil? + describe_groups.unshift(group[:description]) + group = group[:parent_example_group] + end + + # We know all of our examples each live in a top-level `controls` block - get this name now + outermost_group_desc = describe_groups.shift - def example_group_chain - example_group.parent_groups.reverse + return outermost_group_desc, { + :name => example.description, + :desc => example.full_description, + :resource_type => resource_type, + :resource_name => resource_name, + :context => describe_groups, + :line_number => example.metadata[:line_number] + } end + end end end diff --git a/lib/chef/audit/audit_reporter.rb b/lib/chef/audit/audit_reporter.rb new file mode 100644 index 0000000000..b1c9d30bfc --- /dev/null +++ b/lib/chef/audit/audit_reporter.rb @@ -0,0 +1,135 @@ +# +# Auther:: Tyler Ball () +# +# Copyright:: Copyright (c) 2014 Opscode, 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 'chef/event_dispatch/base' +require 'chef/audit/control_group_data' + +class Chef + class Audit + class AuditReporter < EventDispatch::Base + + attr_reader :rest_client, :audit_data, :ordered_control_groups + private :rest_client, :audit_data, :ordered_control_groups + + PROTOCOL_VERSION = '0.1.0' + + def initialize(rest_client) + if Chef::Config[:audit_mode] == false + @audit_enabled = false + else + @audit_enabled = true + end + @rest_client = rest_client + # Ruby 1.9.3 and above "enumerate their values in the order that the corresponding keys were inserted." + @ordered_control_groups = Hash.new + end + + def audit_phase_start(run_status) + Chef::Log.debug("Audit Reporter starting") + @audit_data = AuditData.new(run_status.node.name, run_status.run_id) + end + + def audit_phase_complete + Chef::Log.debug("Audit Reporter completed successfully without errors") + ordered_control_groups.each do |name, control_group| + audit_data.add_control_group(control_group) + end + post_auditing_data + end + + # If the audit phase failed, its because there was some kind of error in the framework + # that runs tests - normal errors are interpreted as EXAMPLE failures and captured. + def audit_phase_failed(error) + # The stacktrace information has already been logged elsewhere + Chef::Log.error("Audit Reporter failed - sending error to server with available example information") + ordered_control_groups.each do |name, control_group| + audit_data.add_control_group(control_group) + end + post_auditing_data(error) + end + + def control_group_started(name) + if ordered_control_groups.has_key?(name) + raise AuditControlGroupDuplicate.new(name) + end + ordered_control_groups.store(name, ControlGroupData.new(name)) + end + + def control_example_success(control_group_name, example_data) + control_group = ordered_control_groups[control_group_name] + control_group.example_success(example_data) + end + + def control_example_failure(control_group_name, example_data, error) + control_group = ordered_control_groups[control_group_name] + control_group.example_failure(example_data, error.message) + end + + def auditing_enabled? + @audit_enabled + end + + private + + def post_auditing_data(error = nil) + if auditing_enabled? + audit_history_url = "controls" + Chef::Log.info("Sending audit report (run-id: #{audit_data.run_id})") + run_data = audit_data.to_hash + + if error + run_data[:error] = "#{error.class.to_s}: #{error.message}\n#{error.backtrace.join("\n")}" + end + + Chef::Log.debug run_data.inspect + compressed_data = encode_gzip(Chef::JSONCompat.to_json(run_data)) + Chef::Log.debug("Sending compressed audit data...") + # Since we're posting compressed data we can not directly call post_rest which expects JSON + audit_url = rest_client.create_url(audit_history_url) + begin + puts Chef::JSONCompat.to_json_pretty(run_data) + rest_client.raw_http_request(:POST, audit_url, headers({'Content-Encoding' => 'gzip'}), compressed_data) + rescue StandardError => e + if e.respond_to? :response + error_file = "failed-audit-data.json" + Chef::FileCache.store(error_file, Chef::JSONCompat.to_json_pretty(run_data), 0640) + Chef::Log.error("Failed to post audit report to server (HTTP #{e.response.code}), saving to #{Chef::FileCache.load(error_file, false)}") + else + Chef::Log.error("Failed to post audit report to server (#{e})") + end + end + else + Chef::Log.debug("Server doesn't support audit report, skipping.") + end + end + + def headers(additional_headers = {}) + options = {'X-Ops-Audit-Report-Protocol-Version' => PROTOCOL_VERSION} + options.merge(additional_headers) + end + + def encode_gzip(data) + "".tap do |out| + Zlib::GzipWriter.wrap(StringIO.new(out)){|gz| gz << data } + end + end + + end + end +end diff --git a/lib/chef/audit/chef_json_formatter.rb b/lib/chef/audit/chef_json_formatter.rb deleted file mode 100644 index 50dfbffbb3..0000000000 --- a/lib/chef/audit/chef_json_formatter.rb +++ /dev/null @@ -1,79 +0,0 @@ -RSpec::Support.require_rspec_core "formatters/base_formatter" -require 'chef/audit/control_group_data' -require 'ffi_yajl' - -class Chef - class Audit - class ChefJsonFormatter < ::RSpec::Core::Formatters::BaseFormatter - ::RSpec::Core::Formatters.register self, :example_group_started, :stop, :close - - attr_reader :control_group_data - - # TODO hopefully the runner can take care of this for us since there won't be an outer-most - # control group - @@outer_example_group_found = false - - def initialize(output) - super - end - - # Invoked for each `control`, `describe`, `context` block - def example_group_started(notification) - unless @@outer_example_group_found - @control_group_data = ControlGroupData.new(notification.group.description) - @@outer_example_group_found = true - end - end - - def stop(notification) - notification.examples.each do |example| - control_data = build_control_from(example) - e = example.exception - if e - control = control_group_data.example_failure(e.message, control_data) - else - control = control_group_data.example_success(control_data) - end - control.line_number = example.metadata[:line_number] - end - end - - def close(notification) - output.write FFI_Yajl::Encoder.encode(control_group_data.to_hash, pretty: true) - output.close if IO === output && output != $stdout - end - - private - - def build_control_from(example) - described_class = example.metadata[:described_class] - if described_class - resource_type = described_class.class.name.split(':')[-1] - # TODO submit github PR to expose this - resource_name = described_class.instance_variable_get(:@name) - end - - describe_groups = [] - group = example.metadata[:example_group] - # If the innermost block has a resource instead of a string, don't include it in context - describe_groups.unshift(group[:description]) if described_class.nil? - group = group[:parent_example_group] - while !group.nil? - describe_groups.unshift(group[:description]) - group = group[:parent_example_group] - end - # TODO remove this when we're no longer wrapping everything with "mysql audit" - describe_groups.shift - - { - :name => example.description, - :desc => example.full_description, - :resource_type => resource_type, - :resource_name => resource_name, - :context => describe_groups - } - end - - end - end -end diff --git a/lib/chef/audit/control_group_data.rb b/lib/chef/audit/control_group_data.rb index fc758e45ba..e19a6e1a15 100644 --- a/lib/chef/audit/control_group_data.rb +++ b/lib/chef/audit/control_group_data.rb @@ -1,5 +1,29 @@ +require 'securerandom' + class Chef class Audit + class AuditData + attr_reader :node_name, :run_id, :control_groups + + def initialize(node_name, run_id) + @node_name = node_name + @run_id = run_id + @control_groups = [] + end + + def add_control_group(control_group) + control_groups << control_group + end + + def to_hash + { + :node_name => node_name, + :run_id => run_id, + :control_groups => control_groups.collect { |c| c.to_hash } + } + end + end + class ControlGroupData attr_reader :name, :status, :number_success, :number_failed, :controls @@ -12,18 +36,18 @@ class Chef end - def example_success(opts={}) + def example_success(control_data) @number_success += 1 - control = create_control(opts) + control = create_control(control_data) control.status = "success" controls << control control end - def example_failure(details=nil, opts={}) + def example_failure(control_data, details) @number_failed += 1 @status = "failure" - control = create_control(opts) + control = create_control(control_data) control.details = details if details control.status = "failure" controls << control @@ -31,53 +55,69 @@ class Chef end def to_hash + # We sort it so the examples appear in the output in the same order + # they appeared in the recipe controls.sort! {|x,y| x.line_number <=> y.line_number} - { - :control_group => { - :name => name, - :status => status, - :number_success => number_success, - :number_failed => number_failed, - :controls => controls.collect { |c| c.to_hash } - } + h = { + :name => name, + :status => status, + :number_success => number_success, + :number_failed => number_failed, + :controls => controls.collect { |c| c.to_hash } } + add_display_only_data(h) end private - def create_control(opts={}) - name = opts[:name] - resource_type = opts[:resource_type] - resource_name = opts[:resource_name] - context = opts[:context] - ControlData.new(name, resource_type, resource_name, context) + def create_control(control_data) + name = control_data[:name] + resource_type = control_data[:resource_type] + resource_name = control_data[:resource_name] + context = control_data[:context] + line_number = control_data[:line_number] + # TODO make this smarter with splat arguments so if we start passing in more control_data + # I don't have to modify code in multiple places + ControlData.new(name, resource_type, resource_name, context, line_number) + end + + # The id and control sequence number are ephemeral data - they are not needed + # to be persisted and can be regenerated at will. They are only needed + # for display purposes. + def add_display_only_data(group) + group[:id] = SecureRandom.uuid + group[:controls].collect!.with_index do |c, i| + # i is zero-indexed, and we want the display one-indexed + c[:sequence_number] = i+1 + c + end + group end end class ControlData - attr_reader :name, :resource_type, :resource_name, :context + attr_reader :name, :resource_type, :resource_name, :context, :line_number attr_accessor :status, :details - # TODO this only helps with debugging - attr_accessor :line_number - def initialize(name, resource_type, resource_name, context) + def initialize(name, resource_type, resource_name, context, line_number) @context = context @name = name @resource_type = resource_type @resource_name = resource_name + @line_number = line_number end def to_hash - ret = { + h = { :name => name, :status => status, :details => details, :resource_type => resource_type, :resource_name => resource_name } - ret[:context] = context || [] - ret + h[:context] = context || [] + h end end diff --git a/lib/chef/audit/runner.rb b/lib/chef/audit/runner.rb index 4a76b7e65b..4059741359 100644 --- a/lib/chef/audit/runner.rb +++ b/lib/chef/audit/runner.rb @@ -18,7 +18,6 @@ require 'chef/audit' require 'chef/audit/audit_event_proxy' -require 'chef/audit/chef_json_formatter' require 'chef/config' class Chef @@ -72,6 +71,7 @@ class Chef configuration.backtrace_exclusion_patterns.push(Regexp.new("/Users".gsub("/", File::SEPARATOR))) configuration.backtrace_exclusion_patterns.push(Regexp.new("(eval)")) configuration.color = Chef::Config[:color] + configuration.expose_dsl_globally = false add_formatters disable_should_syntax @@ -80,9 +80,8 @@ class Chef def add_formatters configuration.add_formatter(RSpec::Core::Formatters::DocumentationFormatter) - configuration.add_formatter(Chef::Audit::ChefJsonFormatter) - #configuration.add_formatter(Chef::Audit::AuditEventProxy) - #Chef::Audit::AuditEventProxy.events = run_context.events + configuration.add_formatter(Chef::Audit::AuditEventProxy) + Chef::Audit::AuditEventProxy.events = run_context.events end # Explicitly disable :should syntax. diff --git a/lib/chef/client.rb b/lib/chef/client.rb index bf8c83eee2..b27a2b693d 100644 --- a/lib/chef/client.rb +++ b/lib/chef/client.rb @@ -44,6 +44,7 @@ require 'chef/formatters/doc' require 'chef/formatters/minimal' require 'chef/version' require 'chef/resource_reporter' +require 'chef/audit/audit_reporter' require 'chef/run_lock' require 'chef/policy_builder' require 'chef/request_id' @@ -210,6 +211,17 @@ class Chef end end + # Resource repoters send event information back to the chef server for processing. + # Can only be called after we have a @rest object + def register_reporters + [ + Chef::ResourceReporter.new(rest), + Chef::Audit::AuditReporter.new(rest) + ].each do |r| + events.register(r) + end + end + # Instantiates a Chef::Node object, possibly loading the node's prior state # when using chef-client. Delegates to policy_builder # @@ -296,9 +308,7 @@ class Chef end # We now have the client key, and should use it from now on. @rest = Chef::REST.new(config[:chef_server_url], client_name, config[:client_key]) - # TODO register this where we register all other event listeners - @resource_reporter = Chef::ResourceReporter.new(@rest) - @events.register(@resource_reporter) + register_reporters rescue Exception => e # TODO: munge exception so a semantic failure message can be given to the # user @@ -320,6 +330,7 @@ class Chef runner.converge @events.converge_complete rescue Exception => e + Chef::Log.error("Converge failed with error message #{e.message}") @events.converge_failed(e) converge_exception = e end @@ -340,15 +351,16 @@ class Chef converge_exception end - # TODO are failed audits going to raise exceptions, or only be handled by the reporters? def run_audits(run_context) audit_exception = nil begin - @events.audit_phase_start(run_context) + @events.audit_phase_start(run_status) + Chef::Log.info("Starting audit phase") auditor = Chef::Audit::Runner.new(run_context) auditor.run @events.audit_phase_complete rescue Exception => e + Chef::Log.error("Audit phase failed with error message #{e.message}") @events.audit_phase_failed(e) audit_exception = e end @@ -429,8 +441,8 @@ class Chef run_context = setup_run_context - converge_error = converge_and_save(run_context) - audit_error = run_audits(run_context) + converge_error = converge_and_save(run_context) unless (Chef::Config[:audit_mode] == true) + audit_error = run_audits(run_context) unless (Chef::Config[:audit_mode] == false) if converge_error || audit_error e = Chef::Exceptions::RunFailedWrappingError.new(converge_error, audit_error) diff --git a/lib/chef/dsl/audit.rb b/lib/chef/dsl/audit.rb index 42a1927efb..1849b65633 100644 --- a/lib/chef/dsl/audit.rb +++ b/lib/chef/dsl/audit.rb @@ -29,6 +29,8 @@ class Chef # Adds the controls group and block (containing controls to execute) to the runner's list of pending examples def controls(*args, &block) raise ::Chef::Exceptions::NoAuditsProvided unless block + name = args[0] + raise AuditNameMissing if name.nil? || name.empty? run_context.controls_groups << ::RSpec::Core::ExampleGroup.__controls__(*args, &block) end diff --git a/lib/chef/event_dispatch/base.rb b/lib/chef/event_dispatch/base.rb index e55f752065..695e31cf2e 100644 --- a/lib/chef/event_dispatch/base.rb +++ b/lib/chef/event_dispatch/base.rb @@ -230,7 +230,7 @@ class Chef end # Called before audit phase starts - def audit_phase_start(run_context) + def audit_phase_start(run_status) end # Called when audit phase successfully finishes @@ -243,19 +243,16 @@ class Chef def audit_phase_failed(exception) end - def control_group_start(name) - # TODO use this only for stdout formatting, controls indentation + # Signifies the start of a `controls` block with a defined name + def control_group_started(name) end - def control_group_end + # An example in a `controls` block completed successfully + def control_example_success(control_group_name, example_data) end - def control_example_success(description) - # TODO Use this for both stdout and resource_reporter, need to pass ancestor tree for resource_reporter - # but that is ignored by stdout - end - - def control_example_failure(description, exception) + # An example in a `controls` block failed with the provided error + def control_example_failure(control_group_name, example_data, error) end # TODO: need events for notification resolve? diff --git a/lib/chef/exceptions.rb b/lib/chef/exceptions.rb index 842910f2ae..9fae1d566f 100644 --- a/lib/chef/exceptions.rb +++ b/lib/chef/exceptions.rb @@ -385,6 +385,12 @@ class Chef end end + class AuditControlGroupDuplicate < RuntimeError + def initialize(name) + super "Audit control group with name '#{name}' has already been defined" + end + end + class AuditNameMissing < RuntimeError; end class NoAuditsProvided < RuntimeError def initialize super "You must provide a block with audits" diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb index d9c9124713..09d04f3aae 100644 --- a/lib/chef/formatters/doc.rb +++ b/lib/chef/formatters/doc.rb @@ -162,20 +162,16 @@ class Chef ############# # Called before audit phase starts - def audit_phase_start(run_context) + def audit_phase_start(run_status) puts_line "" puts_line "++ Audit phase starting ++" end - # Called when audit phase successfully finishes def audit_phase_complete puts_line "" puts_line "++ Audit phase ended ++ " 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(error) puts_line "" puts_line "Audit phase exception:" @@ -187,30 +183,6 @@ class Chef end end - def control_group_start(name) - puts_line "Control group #{name} started" - indent - end - - def control_group_end - unindent - end - - def control_example_success(description) - puts_line "SUCCESS - #{description}" - end - - def control_example_failure(description, error) - puts_line "FAILURE - #{description}" - indent - # TODO error_mapper ? - puts_line "#{error.message}" - # error.backtrace.each do |l| - # puts_line l - # end - unindent - end - # Called before action is executed on a resource. def resource_action_start(resource, action, notification_type=nil, notifier=nil) if resource.cookbook_name && resource.recipe_name -- cgit v1.2.1