Skip to content
Permalink
Browse files

Merge pull request #6789 from joshcooper/ticket/5.5.1_release/PUP-634…

…4-total-time

(PUP-6344) Measure total time instead of summing metrics
  • Loading branch information
kris-bosland committed Apr 16, 2018
2 parents 4c12d14 + dd6b0a7 commit aae6717917be0446e3e3d966a5d8b4a7778c920c
Showing with 137 additions and 128 deletions.
  1. +114 −118 lib/puppet/configurer.rb
  2. +23 −10 spec/unit/configurer_spec.rb
@@ -187,6 +187,7 @@ def apply_catalog(catalog, options)
end
options[:report].add_times(:catalog_application, apply_catalog_time)
end

report
end

@@ -205,6 +206,7 @@ def run(options = {})

Puppet::Util::Log.newdestination(report)

completed = nil
begin
Puppet.override(:http_pool => pool) do

@@ -229,159 +231,153 @@ def run(options = {})
report.master_used = "#{server[0]}:#{server[1]}"
end

run_internal(options.merge(:node => found[:node]))
completed = run_internal(options.merge(:node => found[:node]))
end
else
run_internal(options)
completed = run_internal(options)
end
end
ensure
pool.close
end

completed ? report.exit_status : nil
end

def run_internal(options)
start = Time.now
report = options[:report]

prerun_command_successful = false
run_internal_start_time = Time.now
begin
# If a cached catalog is explicitly requested, attempt to retrieve it. Skip the node request,
# don't pluginsync and switch to the catalog's environment if we successfully retrieve it.
if Puppet[:use_cached_catalog]
Puppet::GettextConfig.reset_text_domain('agent')
Puppet::ModuleTranslations.load_from_vardir(Puppet[:vardir])

if catalog = prepare_and_retrieve_catalog_from_cache(options)
options[:catalog] = catalog
@cached_catalog_status = 'explicitly_requested'
# If a cached catalog is explicitly requested, attempt to retrieve it. Skip the node request,
# don't pluginsync and switch to the catalog's environment if we successfully retrieve it.
if Puppet[:use_cached_catalog]
Puppet::GettextConfig.reset_text_domain('agent')
Puppet::ModuleTranslations.load_from_vardir(Puppet[:vardir])

if @environment != catalog.environment && !Puppet[:strict_environment_mode]
Puppet.notice _("Local environment: '%{local_env}' doesn't match the environment of the cached catalog '%{catalog_env}', switching agent to '%{catalog_env}'.") % { local_env: @environment, catalog_env: catalog.environment }
@environment = catalog.environment
end
if catalog = prepare_and_retrieve_catalog_from_cache(options)
options[:catalog] = catalog
@cached_catalog_status = 'explicitly_requested'

report.environment = @environment
else
# Don't try to retrieve a catalog from the cache again after we've already
# failed to do so the first time.
Puppet[:use_cached_catalog] = false
Puppet[:usecacheonfailure] = false
options[:pluginsync] = Puppet::Configurer.should_pluginsync?
if @environment != catalog.environment && !Puppet[:strict_environment_mode]
Puppet.notice _("Local environment: '%{local_env}' doesn't match the environment of the cached catalog '%{catalog_env}', switching agent to '%{catalog_env}'.") % { local_env: @environment, catalog_env: catalog.environment }
@environment = catalog.environment
end

report.environment = @environment
else
# Don't try to retrieve a catalog from the cache again after we've already
# failed to do so the first time.
Puppet[:use_cached_catalog] = false
Puppet[:usecacheonfailure] = false
options[:pluginsync] = Puppet::Configurer.should_pluginsync?
end
end

begin
unless Puppet[:node_name_fact].empty?
query_options = get_facts(options)
end
begin
unless Puppet[:node_name_fact].empty?
query_options = get_facts(options)
end

configured_environment = Puppet[:environment] if Puppet.settings.set_by_config?(:environment)

# We only need to find out the environment to run in if we don't already have a catalog
unless (options[:catalog] || Puppet[:strict_environment_mode])
begin
node = nil
node_retr_time = thinmark do
node = options[:node] || Puppet::Node.indirection.find(Puppet[:node_name_value],
:environment => Puppet::Node::Environment.remote(@environment),
:configured_environment => configured_environment,
:ignore_cache => true,
:transaction_uuid => @transaction_uuid,
:fail_on_404 => true)
end
options[:report].add_times(:node_retrieval, node_retr_time)

if node
# If we have deserialized a node from a rest call, we want to set
# an environment instance as a simple 'remote' environment reference.
if !node.has_environment_instance? && node.environment_name
node.environment = Puppet::Node::Environment.remote(node.environment_name)
end

@node_environment = node.environment.to_s

if node.environment.to_s != @environment
Puppet.notice _("Local environment: '%{local_env}' doesn't match server specified node environment '%{node_env}', switching agent to '%{node_env}'.") % { local_env: @environment, node_env: node.environment }
@environment = node.environment.to_s
report.environment = @environment
query_options = nil
else
Puppet.info _("Using configured environment '%{env}'") % { env: @environment }
end
end
rescue StandardError => detail
Puppet.warning(_("Unable to fetch my node definition, but the agent run will continue:"))
Puppet.warning(detail)
configured_environment = Puppet[:environment] if Puppet.settings.set_by_config?(:environment)

# We only need to find out the environment to run in if we don't already have a catalog
unless (options[:catalog] || Puppet[:strict_environment_mode])
begin
node = nil
node_retr_time = thinmark do
node = options[:node] || Puppet::Node.indirection.find(Puppet[:node_name_value],
:environment => Puppet::Node::Environment.remote(@environment),
:configured_environment => configured_environment,
:ignore_cache => true,
:transaction_uuid => @transaction_uuid,
:fail_on_404 => true)
end
end
options[:report].add_times(:node_retrieval, node_retr_time)

current_environment = Puppet.lookup(:current_environment)
if current_environment.name == @environment.intern
local_node_environment = current_environment
else
local_node_environment = Puppet::Node::Environment.create(@environment,
current_environment.modulepath,
current_environment.manifest,
current_environment.config_version)
end
Puppet.push_context({:current_environment => local_node_environment}, "Local node environment for configurer transaction")
if node
# If we have deserialized a node from a rest call, we want to set
# an environment instance as a simple 'remote' environment reference.
if !node.has_environment_instance? && node.environment_name
node.environment = Puppet::Node::Environment.remote(node.environment_name)
end

query_options = get_facts(options) unless query_options
query_options[:configured_environment] = configured_environment
@node_environment = node.environment.to_s

unless catalog = prepare_and_retrieve_catalog(options, query_options)
return nil
if node.environment.to_s != @environment
Puppet.notice _("Local environment: '%{local_env}' doesn't match server specified node environment '%{node_env}', switching agent to '%{node_env}'.") % { local_env: @environment, node_env: node.environment }
@environment = node.environment.to_s
report.environment = @environment
query_options = nil
else
Puppet.info _("Using configured environment '%{env}'") % { env: @environment }
end
end
rescue StandardError => detail
Puppet.warning(_("Unable to fetch my node definition, but the agent run will continue:"))
Puppet.warning(detail)
end
end

if Puppet[:strict_environment_mode] && catalog.environment != @environment
Puppet.err _("Not using catalog because its environment '%{catalog_env}' does not match agent specified environment '%{local_env}' and strict_environment_mode is set") % { catalog_env: catalog.environment, local_env: @environment }
return nil
end
current_environment = Puppet.lookup(:current_environment)
if current_environment.name == @environment.intern
local_node_environment = current_environment
else
local_node_environment = Puppet::Node::Environment.create(@environment,
current_environment.modulepath,
current_environment.manifest,
current_environment.config_version)
end
Puppet.push_context({:current_environment => local_node_environment}, "Local node environment for configurer transaction")

# Here we set the local environment based on what we get from the
# catalog. Since a change in environment means a change in facts, and
# facts may be used to determine which catalog we get, we need to
# rerun the process if the environment is changed.
tries = 0
while catalog.environment and not catalog.environment.empty? and catalog.environment != @environment
if tries > 3
raise Puppet::Error, _("Catalog environment didn't stabilize after %{tries} fetches, aborting run") % { tries: tries }
end
Puppet.notice _("Local environment: '%{local_env}' doesn't match server specified environment '%{catalog_env}', restarting agent run with environment '%{catalog_env}'") % { local_env: @environment, catalog_env: catalog.environment }
@environment = catalog.environment
report.environment = @environment
query_options = get_facts(options) unless query_options
query_options[:configured_environment] = configured_environment

unless catalog = prepare_and_retrieve_catalog(options, query_options)
return nil
end

query_options = get_facts(options)
query_options[:configured_environment] = configured_environment
if Puppet[:strict_environment_mode] && catalog.environment != @environment
Puppet.err _("Not using catalog because its environment '%{catalog_env}' does not match agent specified environment '%{local_env}' and strict_environment_mode is set") % { catalog_env: catalog.environment, local_env: @environment }
return nil
end

return nil unless catalog = prepare_and_retrieve_catalog(options, query_options)
tries += 1
# Here we set the local environment based on what we get from the
# catalog. Since a change in environment means a change in facts, and
# facts may be used to determine which catalog we get, we need to
# rerun the process if the environment is changed.
tries = 0
while catalog.environment and not catalog.environment.empty? and catalog.environment != @environment
if tries > 3
raise Puppet::Error, _("Catalog environment didn't stabilize after %{tries} fetches, aborting run") % { tries: tries }
end
Puppet.notice _("Local environment: '%{local_env}' doesn't match server specified environment '%{catalog_env}', restarting agent run with environment '%{catalog_env}'") % { local_env: @environment, catalog_env: catalog.environment }
@environment = catalog.environment
report.environment = @environment

if execute_prerun_command
prerun_command_successful = true
options[:report].code_id = catalog.code_id
options[:report].catalog_uuid = catalog.catalog_uuid
options[:report].cached_catalog_status = @cached_catalog_status
apply_catalog(catalog, options)
end
rescue => detail
Puppet.log_exception(detail, _("Failed to apply catalog: %{detail}") % { detail: detail })
return nil
query_options = get_facts(options)
query_options[:configured_environment] = configured_environment

return nil unless catalog = prepare_and_retrieve_catalog(options, query_options)
tries += 1
end
ensure
report.add_times(:total, Time.now - run_internal_start_time)
report.finalize_report

exit_status = report.exit_status if prerun_command_successful
exit_status = nil unless execute_postrun_command
execute_prerun_command or return nil

return exit_status
options[:report].code_id = catalog.code_id
options[:report].catalog_uuid = catalog.catalog_uuid
options[:report].cached_catalog_status = @cached_catalog_status
apply_catalog(catalog, options)
true
rescue => detail
Puppet.log_exception(detail, _("Failed to apply catalog: %{detail}") % { detail: detail })
return nil
ensure
execute_postrun_command or return nil
end

ensure
report.cached_catalog_status ||= @cached_catalog_status
report.add_times(:total, Time.now - start)
report.finalize_report
Puppet::Util::Log.close(report)
send_report(report)
Puppet.pop_context
@@ -264,6 +264,12 @@
expect(@agent.run).to eq(1234)
end

it "should return nil if catalog application fails" do
@catalog.expects(:apply).raises(Puppet::Error, 'One or more resource dependency cycles detected in graph')
report = Puppet::Transaction::Report.new
expect(@agent.run(catalog: @catalog, report: report)).to be_nil
end

it "should send the transaction report even if the pre-run command fails" do
report = Puppet::Transaction::Report.new
Puppet::Transaction::Report.expects(:new).returns(report)
@@ -352,26 +358,33 @@
expect(@agent.run).to be_nil
end

it "should record the time it took to apply the catalog" do
it 'includes total time metrics in the report after successfully applying the catalog' do
report = Puppet::Transaction::Report.new
@catalog.stubs(:apply).with(:report => report)
report.expects(:add_times).with(:catalog_application, kind_of(Numeric))
@agent.apply_catalog(@catalog, {:report => report})
@agent.run(report: report)

expect(report.metrics['time']).to be
expect(report.metrics['time']['total']).to be_a_kind_of(Numeric)
end

it "should record a total run time" do
it 'includes total time metrics in the report even if prerun fails' do
Puppet.settings[:prerun_command] = "/my/command"
Puppet::Util::Execution.expects(:execute).with(["/my/command"]).raises(Puppet::ExecutionFailure, "Failed")

report = Puppet::Transaction::Report.new
@catalog.stubs(:apply).with(:report => report)
report.expects(:add_times).with {|m,v| m == :total && !v.nil?}
@agent.run({:report => report})
@agent.run(report: report)

expect(report.metrics['time']).to be
expect(report.metrics['time']['total']).to be_a_kind_of(Numeric)
end

it "should record a total run time with failed catalog retrieval" do
it 'includes total time metrics in the report even if catalog retrieval fails' do
report = Puppet::Transaction::Report.new
@catalog.stubs(:apply).with(:report => report)
report.expects(:add_times).with {|m,v| m == :total && !v.nil?}
@agent.stubs(:prepare_and_retrieve_catalog_from_cache).raises
@agent.run(:report => report)

expect(report.metrics['time']).to be
expect(report.metrics['time']['total']).to be_a_kind_of(Numeric)
end

it "should refetch the catalog if the server specifies a new environment in the catalog" do

0 comments on commit aae6717

Please sign in to comment.
You can’t perform that action at this time.