On Wed, 2013-02-20 at 13:48 +0100, David Schmitt wrote:
> On Wed, 20 Feb 2013 13:28:32 +0100, Brice Figureau
> <[email protected]> wrote:
> >>
> >> Here's the --summarize footer, as well as "time"'s output:
> >>
> >> Finished catalog run in 108.48 seconds
> >> Changes:
> >> Events:
> >> Total: 14
> >> Noop: 14
> >> Resources:
> >> Out of sync: 14
> >> Total: 2709
> >> Skipped: 6
> >> Time:
> >> Nagios hostgroup: 0.00
> >> Filebucket: 0.00
> >> Tidy: 0.00
> >> Mount: 0.00
> >> Nagios timeperiod: 0.00
> >> Group: 0.00
> >> Cron: 0.01
> >> Nagios contact: 0.01
> >> User: 0.03
> >> Yumrepo: 0.03
> >> Sshkey: 0.22
> >> Nagios host: 0.90
> >> Last run: 1361359272
> >> Augeas: 2.33
> >> Package: 2.88
> >> Config retrieval: 401.45
> >
> > Yep, catalog serialization/deserialization in action...
> >
> >> Total: 430.31
> >> Service: 5.62
> >> Exec: 7.68
> >> File: 9.15
> >> Version:
> >> Puppet: 3.0.1
> >> Config: heads/david-0-g60f805f
> >>
> >> real 9m19.463s
> >> user 3m1.637s
> >> sys 0m35.450s
> >>
> >>
> >> Here's my naive analysis: total runtime is 9m19s (559s). That is 401s
> >> config retrieval + 108s catalog run time + 50s unaccounted. Of the 401s
> >> config retrieval, 115s are compile time and 258s are unaccounted for.
> >
> > Thanks for those figures, this is highly interesting!
> >
> > So, we need to chase those 258s.
> > I believe that it comes from:
> >
> > * downloading the catalog from the master (are you on a lan?, if not try
> > --http-compression)
>
> This is all on localhost.
>
> > * unserializing the pson catalog (this is certainly what takes time,
> > because it involves creating numerous ruby objects)
> >
> > * serializing it back to the client_state cache (unfortunately we
> > apparently can't get rid of this part)
>
> What is this cache used for? I do not understand the necessity for it. Can
> I disable this somehow?
I don't know if you can disable it. It's purpose I believe is to still
be able to perform an agent run if the master can't be contacted, and
was at a time used for catalog caching (ie as a measure to reduce load
on the master).
> > * at the same time managing the state file
> >
> > Now to really know what exactly takes time, you'll have to add debug
> > statements in the agent code base.
>
> I'll see what I can do.
That's as easy as decorating the code you want to time with:
benchmark(:notice, "Code that does this") do
... code to bench ...
end
(you first need to "include Puppet::Util" in the current class)
Then when the benchmarked code will be run, it will log the time in the
log.
So, all the gory details of catalog caching and retrieval happens in the
lib/puppet/configurer.rb file.
--
Brice Figureau
Follow the latest Puppet Community evolutions on www.planetpuppet.org!
--
You received this message because you are subscribed to the Google Groups
"Puppet Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To post to this group, send email to [email protected].
Visit this group at http://groups.google.com/group/puppet-dev?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
