(#17190) Provide more benchmarking info during compile

Many users find that they have very little insight into what the
compiler is doing and spending time on during compilation. This provides
extra logging for getting much finer grained information.
(#17190) Create Profiler components

The existing Puppet::Util#benchmark method makes it hard to easily put
in place because it does not retain the return value of the block
measured. It also does not give great control over whether or not to
profile, nor does it provide nesting information. This adds a profiler
structure that incorporates all of these features.
(#17190) Undo extra marking of benchmark output

The initial pass at adding compiler profiling added extra text to make
the benchmark output more "grepable". That isn't really needed once the
Profiler system is used.
(Maint) Attempt to clean up handler tests

The tests are using instance variables all over the place, which makes
them noisy for reading, and had useless tests for respond_to?. This
removes those tests, and tries to cut down on the noise some by making
the handler a let().
(#17190) Provide on-demand profiling of catalog compiles

The previous version of the catalog compile timings use the
Puppet::Util#benchmark system, which did not allow turning it on and
off. This replaces that system with the Puppet::Util::Profiler and
provides a parameter for requests called "profile" that can be used to
perform a profiled run.

Currently this logs to the debug output, but in the future could
reasonably send the profiling information elsewhere so that the user
does not need to have debug logging enabled in order to get profiling
information.

An example of how to use this. After a node has checked in and the
master has stored the facts for the node make another request from the
command line:

  curl -k -H "Accept: yaml" \
  'https://localhost:8140/production/catalog/aparker?profile'

The "?profile" is the signal to output the profiling information. The
master will output a log that looks like:

  Debug: 1.3.5 [2154751480] Compile: Evaluated node classes in 0.0000 seconds
  Debug: 1.3.6.1.1.1 [2154751480] Evaluated resource Foo[testing] in 0.0004 seconds
  Debug: 1.3.6.1.1 [2154751480] Evaluated definitions in 0.0006 seconds
  Debug: 1.3.6.1 [2154751480] Iterated (1) on generators in 0.0008 seconds
  Debug: 1.3.6.2.1 [2154751480] Evaluated definitions in 0.0000 seconds
  Debug: 1.3.6.2 [2154751480] Iterated (2) on generators in 0.0002 seconds
  Debug: 1.3.6 [2154751480] Compile: Evaluated generators in 0.0012 seconds
  Debug: 1.3.7 [2154751480] Compile: Finished catalog in 0.0004 seconds
  Debug: 1.3 [2154751480] Compiled catalog for aparker in environment production in 0.0291 seconds
  Debug: 1.4 [2154751480] Filtered result for catalog aparker in 0.0005 seconds
  Debug: 1.5 [2154751480] Rendered result in Puppet::Network::Format[yaml] in 0.0044 seconds
  Debug: 1.6 [2154751480] Sent response in 0.0000 seconds
  Debug: 1 [2154751480] Processed request GET /production/catalog/aparker in 0.0645 seconds

The outline style number that preceeds every line is to provide nesting
information. Ideally the time of the nested components should add up to
the higher level time.
(#17190) Improve output from profiling

The output for the profiling had an issue whereby the profiling run
identifier (the porting inside square brackets) followed the nesting
identifier. This caused a hard read output. This flips those two
components of the output to create:

  Debug: [2166677060] 1.3.6.2 Iterated (2) on generators in 0.0002 seconds
  Debug: [2166677060] 1.3.6 Compile: Evaluated generators in 0.0012 seconds
  Debug: [2166677060] 1.3.7 Compile: Finished catalog in 0.0004 seconds
  Debug: [2166677060] 1.3 Compiled catalog for aparker in environment production in 0.0290 seconds
  Debug: [2166677060] 1.4 Filtered result for catalog aparker in 0.0005 seconds
  Debug: [2166677060] 1.5 Rendered result in Puppet::Network::Format[yaml] in 0.0047 seconds
  Debug: [2166677060] 1.6 Sent response in 0.0000 seconds
  Debug: [2166677060] 1 Processed request GET /production/catalog/aparker in 0.0896 seconds

This also remove the profiler's dependence on the exact logging level to
use and instead makes it just call a method that it is given.
(#17190) Mark profiling APIs private

Until we make a specific decision that these should be available to
others, they are going to be made private.
(#17190) Handle errors during profiling

If an error had been raised in the profiled segment, the profiling
information would have been skipped, the sequence would not have been
updated and everything would start falling apart. This changes the
Measuring profiler to handle errors raised in the segment, but in so
doing has to stop using the Benchmark library and resort to Time.now.
(Maint) Extract time from profiler

The implementation for timing and logging the profiled information was
getting intertwined and messy. This extracts the timing and formating of
elapsed time into a Timer class that is used to time the segment.
(Maint) Cleanup some scope tests

Remove the naughty "should" and move away from instance vars.
(#17190) Profile function calls

This adds profiling of function calls on Puppet::Parser::Scope objects.
(#17190) Rename Measuring to WallClock

The Puppet::Util::Profiler::Measuring is better described as a wall
clock profiler. This renames it to that.
(#17190) Genericize output format of profiler

The output format of the profile messages was tied to the specific
profiler. This updates the message and internal structure of the
WallClock profiler to allow for making the entire flow of before and
after handling of the profiler generic.
(#17190) Extract abstract logging profiler

The logging and execution aspects of the WallClock profiler are going to
be useful in other contexts as well. This extracts out an abstract
Logging base class that provides a template method for WallClock.
(#17190) Add object count profiler

This adds a new (very experimental) profiler for tracking changes in the
ruby object space object counts. In order to use it right now, you'll
actually have to modify the code since there is currently no mechanism
for selecting the type of profiler to use. I'm also not certain that the
information this profiler collects is useful, but it might provide some
insight into the changes that different sections of code cause in the
number of objects in memory.
(Maint) Remove accidentally added debug line

I had added the debug of the request parameters at some point in order
to understand what they were. That had accidentally been committed.
(#17190) Move profiling of function calls to Functions

The original place where functions were being profiled (in
Puppet::Parser::Scope) only catches the first call to the function. By
moving the profiling to the Puppet::Parser::Functions we can instrument
the generated method and therefore pick up all of the calls.
(Maint) Do not try to cound objects on ruby 1.8

ObjectSpace.count_objects only exists on 1.9 or greater (in fact 1.9.2
or greater, but be only support 1.9.3). This makes the test for this
functionality pending on ruby 1.8 so that we can have the functionality,
but not test it where it can't work.
(Maint) Fixup from bad rebase

A rebase against the master branch had a non-conflicting merge that
caused some tests to fail. The tests were still using `@handler`, but
that had been changed to just `handler` in the work for the profiler.
Merge pull request #1511 from zaphod42/feature/master/17190-detailed-compile-profiling

(#17190) Provide on-demand profiling of catalog compiles