1 /* 2 * Copyright (C) 2020 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 package com.android.tradefed.postprocessor; 17 18 import com.android.os.AtomsProto.Atom; 19 import com.android.os.StatsLog.AggregatedAtomInfo; 20 import com.android.os.StatsLog.ConfigMetricsReport; 21 import com.android.os.StatsLog.ConfigMetricsReportList; 22 import com.android.os.StatsLog.GaugeBucketInfo; 23 import com.android.os.StatsLog.GaugeMetricData; 24 import com.android.os.StatsLog.StatsLogReport; 25 import com.android.tradefed.config.Option; 26 import com.android.tradefed.config.OptionClass; 27 import com.android.tradefed.log.LogUtil.CLog; 28 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric; 29 import com.android.tradefed.util.MultiMap; 30 import com.android.tradefed.util.ProtoUtil; 31 import com.android.tradefed.util.proto.TfMetricProtoUtil; 32 33 import com.google.common.annotations.VisibleForTesting; 34 import com.google.common.collect.Sets; 35 import com.google.protobuf.Descriptors.FieldDescriptor; 36 import com.google.protobuf.Message; 37 38 import java.util.ArrayList; 39 import java.util.Arrays; 40 import java.util.Collection; 41 import java.util.Collections; 42 import java.util.HashMap; 43 import java.util.HashSet; 44 import java.util.List; 45 import java.util.Map; 46 import java.util.Set; 47 import java.util.regex.Matcher; 48 import java.util.regex.Pattern; 49 import java.util.stream.Collectors; 50 51 /** 52 * A post processor that processes gauge metrics collected in a "before/after" approach, i.e. one 53 * snapshot before a test/run and one after, pulling out metrics according to a supplied list of 54 * metric formatters and reporting their deltas. 55 * 56 * <p>Metrics collected this way look like the following: (metrics reside in the atoms) 57 * 58 * <p> 59 * 60 * <pre> 61 * reports { 62 * metrics { 63 * gauge_metrics { 64 * data { 65 * # Bucket for the "before" snapshot 66 * bucket_info { 67 * atom {...} 68 * atom {...} 69 * ... 70 * } 71 * # Bucket for the "after" snapshot 72 * bucket_info { 73 * atom {...} 74 * atom {...} 75 * ... 76 * } 77 * } 78 * } 79 * ... 80 * } 81 * ... 82 * } 83 * </pre> 84 * 85 * <p>As an example, if the supplied metric formatter is {@code on_device_power_measurement} for key 86 * and {@code [subsystem_name]-[rail_name]=[energy_microwatt_secs]} for value, the metric for an 87 * atom where {@code subsystem_name} is {@code display}, {@code rail_name} is {@code RAIL_NAME} and 88 * {@code energy_microwatt_secs} is {@code 10} will look like {@code statsd-<config 89 * name>-gauge-on_device_power_measurement-delta-display-RAIL_NAME=10}. 90 * 91 * <p>The before/after metrics are matched for delta calculation by their name, so it is assumed 92 * that the formatters will ensure that each snapshot generates unique metric sets within them. The 93 * processor will generate warnings in these scenarios: 94 * 95 * <p> 96 * 97 * <ul> 98 * <li>There are duplicate metric keys generated by the formatters within each snapshot 99 * <li>An atom or metric key is present in one snapshot but not the other 100 * </ul> 101 */ 102 @OptionClass(alias = "statsd-before-after-gauge-metric-processor") 103 public class StatsdBeforeAfterGaugeMetricPostProcessor extends StatsdGenericPostProcessor { 104 @Option( 105 name = "metric-formatter", 106 description = 107 "A formatter to format a statsd atom into a key-value pair for a metric. " 108 + "Format: Atom name (snake case) as key and a 'metric_key=value' " 109 + "formatter as value. For the formatter, enclose atom field " 110 + "references in square brackets, which will be substituted with field " 111 + "values in the atom. " 112 + "Example: key: on_device_power_measurement, " 113 + "value: [subsystem_name]-[rail_name]=[energy_microwatt_secs]." 114 + "References to repeated fields should be avoided unless the user is " 115 + "confident that it will always contain only one value in practice. " 116 + "Field definitions can be found in the atoms.proto file under " 117 + "frameworks/proto_logging/stats in the source tree. " 118 + "The metric key can be empty if only one metric is coming out of a " 119 + "particular atom and the atom name is descriptive enough.") 120 private MultiMap<String, String> mMetricFormatters = new MultiMap<>(); 121 122 @Option( 123 name = "also-report-before-after", 124 description = 125 "Also report the before and after values for each metric. These will be " 126 + "prefixed with '[statsd report prefix]-gauge-[atom name]-before' and " 127 + "'[statsd report prefix]-gauge-[atom name]-after'.") 128 private boolean mAlsoReportBeforeAfter = true; 129 130 // Corresponds to a field reference, e.g., "[field1_name.field2_name.field3_name]". 131 private static final Pattern FIELD_REF_PATTERN = 132 Pattern.compile("\\[(?:[a-zA-Z_]+\\.)*(?:[a-zA-Z_]+)\\]"); 133 134 /** 135 * Parse the gauge metrics from the {@link ConfigMetricsReportList} using the atom formatters. 136 * 137 * <p>Event metrics resulting in duplicate keys will be stored as comma separated values. 138 */ 139 @Override parseMetricsFromReportList( ConfigMetricsReportList reportList)140 protected Map<String, Metric.Builder> parseMetricsFromReportList( 141 ConfigMetricsReportList reportList) { 142 // Before and after metrics, keyed by atom names. Under each atom name, the metrics are 143 // stored in a MultiMap keyed by metric keys parsed using the formatters. 144 // The MultiMap is used in case a parsed metric key has multiple values. This should be 145 // avoided via proper formatter configuration, but we still record the metrics so that we 146 // can log them for debugging. 147 Map<String, MultiMap<String, String>> beforeMetrics = new HashMap<>(); 148 Map<String, MultiMap<String, String>> afterMetrics = new HashMap<>(); 149 150 // Mappings of parsed metric keys to their formatters, keyed by atom names and then parsed 151 // metric keys. These mappings are used to generate useful warnings when a formatter results 152 // in a parsed metric key with multiple values, which hinders delta calculation. 153 Map<String, Map<String, Set<String>>> beforekeyToFormatterOutput = new HashMap<>(); 154 Map<String, Map<String, Set<String>>> afterkeyToFormatterOutput = new HashMap<>(); 155 156 // Go through each report to parse metrics. 157 for (ConfigMetricsReport report : reportList.getReportsList()) { 158 for (StatsLogReport statsdMetric : report.getMetricsList()) { 159 if (!statsdMetric.hasGaugeMetrics()) { 160 continue; 161 } 162 List<GaugeMetricData> dataItems = statsdMetric.getGaugeMetrics().getDataList(); 163 for (GaugeMetricData data : dataItems) { 164 // There should be two buckets, one for the "before" snapshot and one for the 165 // "after". 166 if (data.getBucketInfoList().size() != 2) { 167 logWarning( 168 "GaugeMetricData %s does not have two buckets and therefore does " 169 + "not contain both before and after snapshots. Skipping.", 170 data); 171 continue; 172 } 173 parseMetricsByFormatters( 174 data.getBucketInfo(0), beforeMetrics, beforekeyToFormatterOutput); 175 parseMetricsByFormatters( 176 data.getBucketInfo(1), afterMetrics, afterkeyToFormatterOutput); 177 } 178 } 179 } 180 181 // Warn about atoms that are present in one snapshot but not the other. 182 Set<String> atomsInBeforeOnly = 183 Sets.difference(beforeMetrics.keySet(), afterMetrics.keySet()); 184 if (atomsInBeforeOnly.size() > 0) { 185 logWarning( 186 "The following atom(s) have a \"before\" snapshot but not an \"after\" " 187 + "snapshot: %s. Metrics:\n%s.", 188 atomsInBeforeOnly, 189 formatMetricsForLoggingByAtoms(beforeMetrics, atomsInBeforeOnly)); 190 } 191 Set<String> atomsInAfterOnly = 192 Sets.difference(afterMetrics.keySet(), beforeMetrics.keySet()); 193 if (atomsInAfterOnly.size() > 0) { 194 logWarning( 195 "The following atom(s) have an \"after\" snapshot but not a \"before\" " 196 + "snapshot: %s. Metrics:\n%s", 197 atomsInAfterOnly, 198 formatMetricsForLoggingByAtoms(afterMetrics, atomsInAfterOnly)); 199 } 200 201 // Obtain the delta metrics, and warn of any metrics that don't match up for each atom. 202 // Delta metrics are keyed by atom names, and the metrics are stored as multimaps of parsed 203 // to metric keys to delta value. We only expect one value per parsed metric key but use a 204 // multimap here to re-use some utility methods. 205 Map<String, MultiMap<String, String>> deltaMetrics = new HashMap<>(); 206 for (String atomName : Sets.intersection(beforeMetrics.keySet(), afterMetrics.keySet())) { 207 deltaMetrics.put(atomName, new MultiMap<String, String>()); 208 MultiMap<String, String> atomBeforeMetrics = beforeMetrics.get(atomName); 209 MultiMap<String, String> atomAfterMetrics = afterMetrics.get(atomName); 210 211 // Warn of any non-paired parsed metric keys. 212 Set<String> metricsKeysInBeforeOnly = 213 Sets.difference(atomBeforeMetrics.keySet(), atomAfterMetrics.keySet()); 214 if (metricsKeysInBeforeOnly.size() > 0) { 215 logWarning( 216 "For atom %s, the following metric(s) have a \"before\" value but not an " 217 + "\"after\" value:\n%s", 218 atomName, 219 formatAtomMetricsForLoggingByMetricKeys( 220 atomBeforeMetrics, metricsKeysInBeforeOnly, 1)); 221 } 222 Set<String> metricsKeysInAfterOnly = 223 Sets.difference(atomAfterMetrics.keySet(), atomBeforeMetrics.keySet()); 224 if (metricsKeysInAfterOnly.size() > 0) { 225 logWarning( 226 "For atom %s, the following metric(s) have an \"after\" value but not a " 227 + "\"before\" value:\n%s", 228 atomName, 229 formatAtomMetricsForLoggingByMetricKeys( 230 atomAfterMetrics, metricsKeysInAfterOnly, 1)); 231 } 232 233 // For all paired metric keys, calculate delta. 234 for (String metricKey : 235 Sets.intersection(atomBeforeMetrics.keySet(), atomAfterMetrics.keySet())) { 236 List<String> beforeValues = atomBeforeMetrics.get(metricKey); 237 List<String> afterValues = atomAfterMetrics.get(metricKey); 238 239 if (beforeValues.size() > 1) { 240 logWarning( 241 "Metric %s (from formatter(s) %s) of atom %s has multiple values %s in " 242 + "the \"before\" snapshot, which will result in meaningless " 243 + "delta values. Delta calculation for this metric will be " 244 + "skipped. Please double check your metric formatters if this " 245 + "is unexpected. The value(s) from the \"after\" snapshot are " 246 + "%s.", 247 metricKey, 248 beforekeyToFormatterOutput.get(atomName).get(metricKey), 249 atomName, 250 beforeValues, 251 afterValues); 252 continue; 253 } 254 if (afterValues.size() > 1) { 255 logWarning( 256 "Metric %s (from formatter(s) %s) of atom %s has multiple values %s in " 257 + "the \"after\" snapshot, which will result in meaningless " 258 + "delta values. Delta calculation for this metric will be " 259 + "skipped. Please double check your metric formatters if this " 260 + "is unexpected. The value(s) from the \"before\" snapshot " 261 + "are %s.", 262 metricKey, 263 afterkeyToFormatterOutput.get(atomName).get(metricKey), 264 atomName, 265 afterValues, 266 beforeValues); 267 continue; 268 } 269 270 try { 271 deltaMetrics 272 .get(atomName) 273 .put( 274 metricKey, 275 String.valueOf( 276 Double.valueOf(afterValues.get(0)) 277 - Double.valueOf(beforeValues.get(0)))); 278 } catch (NumberFormatException e) { 279 logWarning( 280 "Metric %s of atom %s (from formatter(s) %s) has non-numeric before " 281 + "and/or after values %s, %s, skipping delta calculation.", 282 metricKey, 283 atomName, 284 beforekeyToFormatterOutput.get(atomName).get(metricKey), 285 beforeValues.get(0), 286 afterValues.get(0)); 287 } 288 } 289 } 290 291 Map<String, Metric.Builder> finalMetrics = new HashMap<>(); 292 finalMetrics.putAll(finalizeMetrics(deltaMetrics, "delta")); 293 if (mAlsoReportBeforeAfter) { 294 finalMetrics.putAll(finalizeMetrics(beforeMetrics, "before")); 295 finalMetrics.putAll(finalizeMetrics(afterMetrics, "after")); 296 } 297 298 return finalMetrics; 299 } 300 301 /** 302 * Parse metrics from a {@link GaugeBucketInfo} instance using the metric formatters. 303 * 304 * @param bucket The {@link GaugeBucketInfo} to parse metrics from. 305 * @param metricsOutput The map to store the new metrics into, keyed by atom name and then 306 * metric key. 307 * @param keyToFormatterOutput The map where a mapping of parsed metric keys to formatters are 308 * stored, keyed by atom name and then the parsed metric key, used for generating useful 309 * warnings when a formatter unexpectedly results in multiple metric values, which presents 310 * issues with delta calculation. 311 */ parseMetricsByFormatters( GaugeBucketInfo bucket, Map<String, MultiMap<String, String>> metricsOutput, Map<String, Map<String, Set<String>>> keyToFormatterOutput)312 private void parseMetricsByFormatters( 313 GaugeBucketInfo bucket, 314 Map<String, MultiMap<String, String>> metricsOutput, 315 Map<String, Map<String, Set<String>>> keyToFormatterOutput) { 316 List<Atom> atoms = bucket.getAtomList(); 317 if (atoms.isEmpty()) { 318 atoms = new ArrayList<>(); 319 for (AggregatedAtomInfo info : bucket.getAggregatedAtomInfoList()) { 320 atoms.add(info.getAtom()); 321 } 322 } 323 for (Atom atom : atoms) { 324 Map<FieldDescriptor, Object> atomFields = atom.getAllFields(); 325 for (FieldDescriptor field : atomFields.keySet()) { 326 if (!mMetricFormatters.containsKey(field.getName())) { 327 // Skip if field is not an atom or does not have corresponding formatters. 328 continue; 329 } 330 String atomName = field.getName(); 331 metricsOutput.computeIfAbsent(atomName, k -> new MultiMap<String, String>()); 332 keyToFormatterOutput.computeIfAbsent( 333 atomName, k -> new HashMap<String, Set<String>>()); 334 Message atomContent = (Message) atom.getField(field); 335 List<String> formatters = mMetricFormatters.get(atomName); 336 for (String formatter : formatters) { 337 String keyFormatter = formatter.split("=")[0]; 338 String valueFormatter = formatter.split("=")[1]; 339 List<String> parsedKeys = fillInPlaceholders(keyFormatter, atomContent); 340 List<String> parsedValues = fillInPlaceholders(valueFormatter, atomContent); 341 if (parsedKeys.size() > 1 && parsedValues.size() > 1) { 342 // This condition comes from having repeated fields in both key and value. 343 // The current implementation will result in a cross-product of their 344 // values, which is probably not ideal. 345 logWarning( 346 "Found repeated fields in both metric key and value in formatting " 347 + "pair %s: %s. This is unsupported as it presents " 348 + "ambiguity in pairing of repeated field values for a " 349 + "metric, and could result in meaningless data. Skipping.", 350 atomName, formatter); 351 continue; 352 } 353 for (String key : parsedKeys) { 354 keyToFormatterOutput 355 .get(atomName) 356 .computeIfAbsent(key, k -> new HashSet<String>()); 357 keyToFormatterOutput.get(atomName).get(key).add(formatter); 358 for (String value : parsedValues) { 359 metricsOutput.get(atomName).put(key, value); 360 } 361 } 362 } 363 } 364 } 365 } 366 367 /** Fill in the placeholders in the formatter using the proto message as source. */ fillInPlaceholders(String formatter, Message atomContent)368 private List<String> fillInPlaceholders(String formatter, Message atomContent) { 369 Matcher matcher = FIELD_REF_PATTERN.matcher(formatter); 370 List<String> results = Arrays.asList(formatter); 371 while (matcher.find()) { 372 String placeholder = matcher.group(); 373 // Strip the brackets. 374 String fieldReference = placeholder.substring(1, placeholder.length() - 1); 375 List<String> actual = 376 ProtoUtil.getNestedFieldFromMessageAsStrings( 377 atomContent, Arrays.asList(fieldReference.split("\\."))); 378 if (results.size() > 1 && actual.size() > 1) { 379 // This condition results from having multiple repeated fields in a formatter. The 380 // current implementation will result in a cross-product of their values, which is 381 // probably not ideal. 382 logWarning( 383 "Found multiple repeated fields in formatter %s. This is unsupported as it " 384 + "presents ambiguity in pairing of repeated field values, and " 385 + "could result in meaningless data. Skipping reporting on this " 386 + "formatter.", 387 formatter); 388 return new ArrayList<>(); 389 } 390 List<String> updatedResults = 391 results.stream() 392 .flatMap(r -> actual.stream().map(a -> r.replace(placeholder, a))) 393 .collect(Collectors.toList()); 394 results = updatedResults; 395 } 396 return results; 397 } 398 399 /** 400 * Format the metrics into the reporting form. 401 * 402 * <p>As an example, {@code metric_key} under {@code atom_name} will become {@code 403 * gauge-before-atom_name-metric_key} if {@code type} is {@code before}. If {@code metric_key} 404 * is empty, the resulting final metric key will be {@code gauge-before-atom_name}. 405 * 406 * @param metrics Metrics keyed by atom. 407 * @param type Whether the metrics are "before", "after" or "delta" metrics. 408 * @return The finalized metrics. 409 */ finalizeMetrics( Map<String, MultiMap<String, String>> metrics, String type)410 private Map<String, Metric.Builder> finalizeMetrics( 411 Map<String, MultiMap<String, String>> metrics, String type) { 412 Map<String, Metric.Builder> finalMetrics = new HashMap<>(); 413 for (String atomName : metrics.keySet()) { 414 for (String metricKey : metrics.get(atomName).keySet()) { 415 finalMetrics.put( 416 String.format( 417 "gauge-%s-%s%s", 418 atomName, type, metricKey.isEmpty() ? "" : "-" + metricKey), 419 TfMetricProtoUtil.stringToMetric( 420 String.join(",", metrics.get(atomName).get(metricKey))) 421 .toBuilder()); 422 } 423 } 424 return finalMetrics; 425 } 426 427 /** 428 * Format metrics for a single atom for logging. 429 * 430 * <p>The output will look like: (assuming one level indent of 2 spaces) 431 * 432 * <pre> 433 * metric_1: 1 434 * metric_2: 2 435 * ... 436 * </pre> 437 * 438 * @param metricsForAtom Metrics for a single atom, keyed by metric keys. 439 * @param keys The subset of metric keys in {@code metricsForAtom} to be logged. 440 * @param indent Indent level represented by number of tabs. 441 * @return The formatted metrics as a string. 442 */ formatAtomMetricsForLoggingByMetricKeys( MultiMap<String, String> metricsForAtom, Collection<String> keys, int indent)443 private String formatAtomMetricsForLoggingByMetricKeys( 444 MultiMap<String, String> metricsForAtom, Collection<String> keys, int indent) { 445 return keys.stream() 446 .map( 447 k -> 448 String.join("", Collections.nCopies(indent, "\t")) 449 + (k.isEmpty() ? "<empty>" : k) 450 + ": " 451 + String.join(",", metricsForAtom.get(k))) 452 .collect(Collectors.joining("\n")); 453 } 454 455 /** 456 * Format metrics from a set of atoms for logging. 457 * 458 * <p>The output will look like: (assuming one level indent of 2 spaces) 459 * 460 * <pre> 461 * atom_name_1: 462 * metric_1: 1 463 * metric_2: 2 464 * atom_name_2: 465 * metric_3: 3 466 * ... 467 * </pre> 468 * 469 * @param metricsByAtom Metrics keyed by atom. 470 * @param atomNames Subset of atom names from {@code metricsByAtom} to be logged. 471 * @return The formatted metrics as a string. 472 */ formatMetricsForLoggingByAtoms( Map<String, MultiMap<String, String>> metricsByAtom, Collection<String> atomNames)473 private String formatMetricsForLoggingByAtoms( 474 Map<String, MultiMap<String, String>> metricsByAtom, Collection<String> atomNames) { 475 return atomNames 476 .stream() 477 .map( 478 a -> 479 "\t" 480 + a 481 + ":\n" 482 + formatAtomMetricsForLoggingByMetricKeys( 483 metricsByAtom.get(a), 484 metricsByAtom.get(a).keySet(), 485 2)) 486 .collect(Collectors.joining(",")); 487 } 488 489 /** Wrapper for {@code CLog.w()} to facilitate testing. */ logWarning(String formatter, Object... args)490 private void logWarning(String formatter, Object... args) { 491 String formatted = String.format(formatter, args); 492 logFormattedWarning(formatted); 493 } 494 495 /** Wrapper around {@code CLog.w()} that enables tests to observe the formatted warning. */ 496 @VisibleForTesting logFormattedWarning(String message)497 protected void logFormattedWarning(String message) { 498 CLog.w(message); 499 } 500 } 501