Jira (PUP-9474) Automatic parameter lookup times should show up in profiler metrics

0 views
Skip to first unread message

Charlie Sharpsteen (JIRA)

unread,
Feb 4, 2019, 2:19:05 PM2/4/19
to puppe...@googlegroups.com
Charlie Sharpsteen created an issue
 
Puppet / Improvement PUP-9474
Automatic parameter lookup times should show up in profiler metrics
Issue Type: Improvement Improvement
Affects Versions: PUP 6.2.0, PUP 5.5.10
Assignee: Unassigned
Created: 2019/02/04 11:18 AM
Priority: Major Major
Reporter: Charlie Sharpsteen

The built-in Puppet profiler captures metrics for class, resource, and function evaluation times. However, time spent performing automatic parameter lookup is currently part of "class evaluation" as it is not measured separately. This means that a slowdown in a custom hiera backend will not show up explicitly in metrics unless there are a lot of explicit calls to the include or hiera functions.

Desired Behavior

Automatic parameter lookup for classes should be instrumented such that lookup times are reported in metrics.

Add Comment Add Comment
 
This message was sent by Atlassian JIRA (v7.7.1#77002-sha1:e75ca93)
Atlassian logo

Charlie Sharpsteen (JIRA)

unread,
Feb 4, 2019, 2:22:03 PM2/4/19
to puppe...@googlegroups.com

Rob Braden (JIRA)

unread,
Feb 4, 2019, 5:06:02 PM2/4/19
to puppe...@googlegroups.com

Charlie Sharpsteen (JIRA)

unread,
Feb 4, 2019, 9:32:04 PM2/4/19
to puppe...@googlegroups.com
Charlie Sharpsteen commented on Improvement PUP-9474
 
Re: Automatic parameter lookup times should show up in profiler metrics

It looks like class parameters are resolved from Hiera data via automatic parameter lookup in the inject_external_parameters method:

https://github.com/puppetlabs/puppet/blob/5.5.10/lib/puppet/resource/type.rb#L345-L363

Henrik Lindberg is that correct?

If so, we could probably wrap the lookup operations for all parameters in a Puppet::Util::Profiler.profile block in order to measure the cost of parameter lookup.

Henrik Lindberg (JIRA)

unread,
Feb 5, 2019, 7:59:03 AM2/5/19
to puppe...@googlegroups.com

You are right that APL lookup it is all in one place so should be easy to wrap. There is however a lot of lookups so adding profiling needs to take that into account and do as little as possible if not profiling. Also when actually profiling the question is if it should aggregate the time for all params for a class, or do them one by one (and report the key).

A problem with both of those is that you cannot see if the problem is with a particular hiera backend. Instead instrumenting the calls from hiera to backend functions would make it possible to see the info per kind of function. (Same concern regarding the number of calls). I assume the backend functions do not show up at all as it is now?

Charlie Sharpsteen (JIRA)

unread,
Feb 5, 2019, 4:16:04 PM2/5/19
to puppe...@googlegroups.com

The profiler is, hopefully, low impact as it currently instruments every class, resource, and function evaluation. Right now we get timings for explicit calls to functions like lookup, but no detail on a per-backend basis.

I was thinking of just aggregating all lookups for class parameters in one profiling block so that we'd only add one profiling operation per class. However, timing things on a per-backend basis would be very valuable if the overhead is low enough.

Do we have an existing performance benchmark for automatic parameter lookup that could be used to measure the overhead?

Henrik Lindberg (JIRA)

unread,
Feb 6, 2019, 9:33:04 AM2/6/19
to puppe...@googlegroups.com

I think there is one, yes.

IIRC, the current way profiling is done is to make the call inside of a lambda, and the lambda is either called with or without measuring time. Thus an overhead of at least one call, plus creation of the profiling id/string, plus calling a lambda, plus generating more garbage for the gc - which does not really show up on short benchmarks.

Since hiera backend functions that return an entire hash (like the json and yaml ones) are only called once per data file (or possibly multiple times if the cache needs to be evicted) the number of profiled calls will be much lower than if we measure every parameter lookup. The "by key" backend functions will get many calls and those are typically also the ones that are advanced (eyaml, or remote lookup backends).

Adam Bottchen (JIRA)

unread,
Feb 14, 2019, 7:57:04 PM2/14/19
to puppe...@googlegroups.com
Adam Bottchen updated an issue
 
Change By: Adam Bottchen
CS Priority: Needs Priority Reviewed

Adam Bottchen (JIRA)

unread,
Feb 14, 2019, 8:02:03 PM2/14/19
to puppe...@googlegroups.com

Henrik Lindberg (JIRA)

unread,
Feb 15, 2019, 7:40:03 AM2/15/19
to puppe...@googlegroups.com
 
Re: Automatic parameter lookup times should show up in profiler metrics

So, should we add both? One value per all APL lookups for a class, and one value per call to a backend function?
For data_hash functions, there would only be one value per path, and for lookup_key one value per looked up key / path combination.

Charlie Sharpsteen (JIRA)

unread,
Feb 15, 2019, 5:41:03 PM2/15/19
to puppe...@googlegroups.com

The consensus yesterday was that wrapping the group of APL lookups for each class in instrumentation sounded very low-risk and was something we should just go ahead and do.

Having lookups instrumented per-backend sounds useful, but we were uncertain if the overhead would be significant.

Charlie Sharpsteen (Jira)

unread,
Mar 8, 2022, 12:05:03 PM3/8/22
to puppe...@googlegroups.com

Re-opening. Hiera lookups are a very performance-sensitive component of catalog compilation and latencies can be highly variable, especially if a backend communicates with an external service instead of reading and caching files from disk.

Being able to track the performance of Hiera via metrics is the difference between solving a ticket in an afternoon or over the course of days with heavy amounts of profiling data.

This message was sent by Atlassian Jira (v8.20.2#820002-sha1:829506d)
Atlassian logo

David McTavish (Jira)

unread,
Mar 8, 2022, 12:08:03 PM3/8/22
to puppe...@googlegroups.com

Nirupama Mantha (Jira)

unread,
Jul 26, 2022, 4:31:02 PM7/26/22
to puppe...@googlegroups.com
Nirupama Mantha updated an issue
Change By: Nirupama Mantha
Team: Froyo Phoenix
This message was sent by Atlassian Jira (v8.20.11#820011-sha1:0629dd8)
Atlassian logo

Molly Waggett (Jira)

unread,
Aug 12, 2022, 12:10:02 PM8/12/22
to puppe...@googlegroups.com
Reply all
Reply to author
Forward
0 new messages