Feature #4865

Puppet debug mode should print resource type/title before resource evaluation and time taken after.

Added by James Turnbull over 1 year ago. Updated 4 months ago.

Status:Closed Start date:09/28/2010
Priority:High Due date:
Assignee:Daniel Pittman % Done:

0%
Category:error reporting
Target version:2.7.10
Affected Puppet version:2.6.1 Branch:https://github.com/puppetlabs/puppet/pull/202
Keywords:usability
Votes: 1

Description

1) Only on the client 2) Time taken during each atomic activity

So:

notice: File……. 0.05s notice: Exec…… 1.2s

Ideally, this data would only be collected during debug mode.

This is for the case where you have something hanging, but you can’t figure out what it is because the debug mode in puppet only prints the statement after it has run it. This would let everyone determine the hang points, or points of precise optimization.

If there’s already a way to get this information, that would be great too. —summarize just isn’t quite fine grained enough.

History

#1
Updated by Nick Lewis over 1 year ago

I may be misunderstanding, but isn’t this —evaltrace? Or is the intent to have a message printed before evaluating each resource?

#2
Updated by James Turnbull over 1 year ago

Nick – I think that is what the intent is – you might want to read the Zendesk ticket too.

#3
Updated by Luke Kanies over 1 year ago

  • Assignee changed from Luke Kanies to Nigel Kersten

#4
Updated by Nigel Kersten over 1 year ago

  • Subject changed from Print out time take on client in debug messages to Puppet debug mode should print resource type/title before resource evaluation and time taken after.
  • Status changed from Needs Decision to Accepted
  • Assignee deleted (Nigel Kersten)

To clarify, because the debug mode in puppet only prints the resource name after it has been evaluated, it’s difficult to watch a debug run and get a sense of which resources are hanging.

Additionally, if we could print the time taken after the resource has been evaluated, this would allow post-run viewing of a debug log file to identify performance problems.

These two features would significantly improve debugging performance problems with regard to the client applying the catalog.

#5
Updated by Nigel Kersten about 1 year ago

  • Target version changed from 2.7.x to 3.x
  • Keywords set to usability

#6
Updated by Nigel Kersten about 1 year ago

  • Target version changed from 3.x to 2.7.x

Targeting at Statler due to paying customer issue.

#7
Updated by James Turnbull 7 months ago

  • Assignee set to Daniel Pittman

#8
Updated by Daniel Pittman 7 months ago

  • Status changed from Accepted to In Topic Branch Pending Review
  • Branch set to https://github.com/puppetlabs/puppet/pull/202

The one-line change to make this happen is submitted as https://github.com/puppetlabs/puppet/pull/202

#9
Updated by Trevor Vaughan 6 months ago

I just took a look at the patch. Wouldn’t it be better to have that output at the info rather than debug level?

If you’re doing —evaltrace you’re looking for timing data so this would be useful in my opinion. Debug is just too noisy when all you want is to see where something is hanging quickly.

#10
Updated by Patrick Carlisle 5 months ago

Merged in commit:e465598ab1b7dc8481e7fa461d0c5d38fc2cdfd5 and commit:f4bf4f46f0215ac54528687e04a32d6f64de2b3f

(#4865) Log when we start evaluating resources at the info level

Since we log the final time at info it makes sense to log the start at info as
well.

(#4865) Debug logging when we start evaluating resources.

The `evaltrace` option allowed individual resource evaluation time to be
tracked, which made it easier to post-hoc identify which resources took long
periods of time to process.

It is also helpful, when doing live debugging, to know where the hang happens;
to support that we now log a debug message about starting the evaluation of
the resource before we go into the process.

#11
Updated by Patrick Carlisle 5 months ago

  • Status changed from In Topic Branch Pending Review to Merged - Pending Release
  • Target version changed from 2.7.x to 2.7.10

#12
Updated by Michael Stahnke 4 months ago

  • Status changed from Merged - Pending Release to Closed

released in 2.7.10rc1

Also available in: Atom PDF