diff --git a/src/clj/puppetlabs/services/jruby/jruby_metrics_core.clj b/src/clj/puppetlabs/services/jruby/jruby_metrics_core.clj index 6fdd44ba4..16606e075 100644 --- a/src/clj/puppetlabs/services/jruby/jruby_metrics_core.clj +++ b/src/clj/puppetlabs/services/jruby/jruby_metrics_core.clj @@ -269,7 +269,7 @@ (do (.update wait-timer (- (System/currentTimeMillis) (:time ta)) - (TimeUnit/MILLISECONDS)) + TimeUnit/MILLISECONDS) (swap! requested-instances dissoc requested-event)) (log/warn (trs "Unable to find request event for borrowed JRuby instance: {0}" event)))) @@ -281,8 +281,8 @@ (if-let [ta (get @borrowed-instances worker-id)] (let [elapsed-time (- (System/currentTimeMillis) (:time ta)) per-reason-timer (timer-for-borrow-reason metrics ta)] - (.update borrow-timer elapsed-time (TimeUnit/MILLISECONDS)) - (.update per-reason-timer elapsed-time (TimeUnit/MILLISECONDS)) + (.update borrow-timer elapsed-time TimeUnit/MILLISECONDS) + (.update per-reason-timer elapsed-time TimeUnit/MILLISECONDS) (MDC/put "jruby.borrow-time" (Long/toString elapsed-time)) (swap! borrowed-instances dissoc worker-id)) (log/warn (trs "JRuby instance ''{0}'' returned, but no record of when it was borrowed!" worker-id))))) @@ -314,7 +314,7 @@ (do (.update lock-wait-timer (- (System/currentTimeMillis) (:time lock-request)) - (TimeUnit/MILLISECONDS)) + TimeUnit/MILLISECONDS) (swap! lock-requests assoc lock-request-id {:state :acquired @@ -330,7 +330,7 @@ (do (.update lock-held-timer (- (System/currentTimeMillis) (:time lock-request)) - (TimeUnit/MILLISECONDS)) + TimeUnit/MILLISECONDS) (swap! lock-requests dissoc lock-request-id)) (log/warn (trs "Lock request ''{0}'' released, but no record of when it was acquired!" lock-request-id))) diff --git a/src/java/com/puppetlabs/puppetserver/MetricsPuppetProfiler.java b/src/java/com/puppetlabs/puppetserver/MetricsPuppetProfiler.java index 32079ee7c..8b32a731b 100644 --- a/src/java/com/puppetlabs/puppetserver/MetricsPuppetProfiler.java +++ b/src/java/com/puppetlabs/puppetserver/MetricsPuppetProfiler.java @@ -5,6 +5,7 @@ import org.apache.commons.lang.StringUtils; import java.util.ArrayList; +import java.util.Arrays; import java.util.HashMap; import java.util.List; import java.util.Map; @@ -21,17 +22,21 @@ public class MetricsPuppetProfiler implements PuppetProfiler { private final MetricRegistry registry; private final Set metric_ids; - private static final Pattern FUNCTION_PATTERN = Pattern.compile(".*\\.functions\\.([\\w\\d_]+)$"); - private static final Pattern RESOURCE_PATTERN = Pattern.compile(".*\\.compiler\\.evaluate_resource\\.([\\w\\d_]+\\[([\\w\\d_]+::)*[\\w\\d_]+\\])$"); - private static final Pattern CATALOG_PATTERN = Pattern.compile(".*\\.compiler\\.(static_compile_postprocessing|static_compile|compile|find_node)$"); - private static final Pattern INLINING_PATTERN = Pattern.compile(".*\\.compiler\\.static_compile_inlining\\.(.*)$"); - private static final Pattern PUPPETDB_PATTERN = Pattern.compile(".*\\.puppetdb\\.(resource\\.search|facts\\.encode|command\\.submit\\.replace facts|catalog\\.munge|command\\.submit\\.replace catalog|report\\.convert_to_wire_format_hash|command\\.submit\\.store report|query)$"); - + private final Map function_timers; + private final Map resource_timers; + private final Map catalog_timers; + private final Map inlining_timers; + private final Map puppetdb_timers; public MetricsPuppetProfiler(String hostname, MetricRegistry registry) { this.hostname = hostname; this.registry = registry; this.metric_ids = Collections.newSetFromMap(new ConcurrentHashMap()); + this.function_timers = new ConcurrentHashMap(); + this.resource_timers = new ConcurrentHashMap(); + this.catalog_timers = new ConcurrentHashMap(); + this.inlining_timers = new ConcurrentHashMap(); + this.puppetdb_timers = new ConcurrentHashMap(); } @Override @@ -43,9 +48,12 @@ public Object start(String message, String[] metric_id) { public void finish(Object context, String message, String[] metric_id) { if (shouldTime(metric_id)) { Long elapsed = System.currentTimeMillis() - (Long)context; - for (Timer t : getTimers(metric_id)) { + Map metricsByID = getOrCreateTimersByIDs(metric_id); + for (Timer t : metricsByID.values()) { t.update(elapsed, TimeUnit.MILLISECONDS); } + + updateMetricsTrackers(metric_id, metricsByID); } } @@ -54,29 +62,107 @@ public Set getAllMetricIds() { } public Map getFunctionTimers() { - return getTimers(FUNCTION_PATTERN); + return this.function_timers; } public Map getResourceTimers() { - return getTimers(RESOURCE_PATTERN); + return this.resource_timers; } public Map getCatalogTimers() { - return getTimers(CATALOG_PATTERN); + return this.catalog_timers; } public Map getInliningTimers() { - return getTimers(INLINING_PATTERN); + return this.inlining_timers; } public Map getPuppetDBTimers() { - return getTimers(PUPPETDB_PATTERN); + return this.puppetdb_timers; } @Override public void shutdown() { } + private List sliceOfArrayToList(String[] idSegments, int lengthOfID) { + // Callers expect a mutable List returned, but Arrays.asList() returns a + // fix length array, which is why we have to create a List and then add to it. + List idList = new ArrayList(); + idList.addAll(Arrays.asList(Arrays.copyOf(idSegments, lengthOfID))); + + return idList; + } + + private String safeGet(String[] collection, int i) { + try { + return collection[i]; + } catch (IndexOutOfBoundsException _ex) { + return ""; + } + } + + private void updateMetricsTrackers(String[] metricId, Map metricsByID) { + String firstElement = safeGet(metricId, 0); + String secondElement = safeGet(metricId, 1); + + if ("functions".equals(firstElement)) { + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 2))); + this.function_timers.put(secondElement, metric); + + } else if ("compiler".equals(firstElement)) { + String thirdElemet = safeGet(metricId, 2); + + if ("evaluate_resource".equals(secondElement)) { + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 3))); + this.resource_timers.put(thirdElemet, metric); + + } else if ("static_compile_inlining".equals(secondElement)) { + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 3))); + this.inlining_timers.put(thirdElemet, metric); + + } else { + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 2))); + this.catalog_timers.put(secondElement, metric); + } + + } else if ("puppetdb".equals(firstElement)) { + if ("query".equals(secondElement)) { + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 2))); + this.puppetdb_timers.put(secondElement, metric); + + } else { + String thirdElemet = safeGet(metricId, 2); + + if ( + ("resource".equals(secondElement) && "search".equals(thirdElemet)) || + ("payload".equals(secondElement) && "format".equals(thirdElemet)) || + // Set.of would be preferrable but 7.x still support Java 8, which does not have Set.of + ("facts".equals(secondElement) && Arrays.asList("save", "find", "search", "encode").contains(thirdElemet)) || + ("catalog".equals(secondElement) && Arrays.asList("save", "munge").contains(thirdElemet)) || + ("report".equals(secondElement) && Arrays.asList("convert_to_wire_format_hash", "process").contains(thirdElemet)) + ) { + String key = String.join(".", secondElement, thirdElemet); + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 3))); + this.puppetdb_timers.put(key, metric); + + } else if ("command".equals(secondElement) && "submit".equals(thirdElemet)) { + String fourthElement = safeGet(metricId, 3); + + if ( + "store report".equals(fourthElement) || + "replace facts".equals(fourthElement) || + "replace catalog".equals(fourthElement) + ) { + String key = String.join(".", secondElement, thirdElemet, fourthElement); + Timer metric = metricsByID.get(getMetricName(sliceOfArrayToList(metricId, 4))); + this.puppetdb_timers.put(key, metric); + } + } + } + } + } + private boolean shouldTime(String[] metric_id) { if (metric_id == null) { return false; @@ -90,8 +176,8 @@ private boolean shouldTime(String[] metric_id) { return true; } - private List getTimers(String[] metric_id) { - List timers = new ArrayList(); + private Map getOrCreateTimersByIDs(String[] metric_id) { + Map timers = new HashMap(); // If this is turns out to be a performance hit, we could cache these in a // map or something. for (int i = 0; i < metric_id.length; i++) { @@ -101,7 +187,7 @@ private List getTimers(String[] metric_id) { } String metric_name = getMetricName(current_id); registerMetricName(metric_name); - timers.add(registry.timer(metric_name)); + timers.put(metric_name, registry.timer(metric_name)); } return timers; } @@ -114,15 +200,4 @@ private String getMetricName(List metric_id) { private void registerMetricName(String metric_name) { this.metric_ids.add(metric_name); } - - private Map getTimers(Pattern pattern) { - Map rv = new HashMap<>(); - for (String metric_id : this.metric_ids) { - Matcher matcher = pattern.matcher(metric_id); - if (matcher.matches()) { - rv.put(matcher.group(1), registry.timer(metric_id)); - } - } - return rv; - } }