1 /* 2 * Copyright (C) 2019 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 17 package com.android.helpers; 18 19 import static com.android.helpers.MetricUtility.constructKey; 20 21 import android.util.Log; 22 23 import androidx.annotation.VisibleForTesting; 24 import androidx.test.InstrumentationRegistry; 25 import androidx.test.uiautomator.UiDevice; 26 27 import com.google.common.base.Verify; 28 29 import java.io.IOException; 30 import java.util.Collections; 31 import java.util.HashMap; 32 import java.util.HashSet; 33 import java.util.Map; 34 import java.util.Set; 35 import java.util.regex.Matcher; 36 import java.util.regex.Pattern; 37 38 /** An {@link ICollectorHelper} for collecting jank metrics for all or a list of processes. */ 39 public class JankCollectionHelper implements ICollectorHelper<Double> { 40 41 private static final String LOG_TAG = JankCollectionHelper.class.getSimpleName(); 42 43 // Prefix for all output metrics that come from the gfxinfo dump. 44 @VisibleForTesting static final String GFXINFO_METRICS_PREFIX = "gfxinfo"; 45 46 @VisibleForTesting 47 static final String FAILED_PACKAGES_COUNT_METRIC = 48 GFXINFO_METRICS_PREFIX + "_failed_packages_count"; 49 // Shell dump commands to get and reset the tracked gfxinfo metrics. 50 @VisibleForTesting static final String GFXINFO_COMMAND_GET = "dumpsys gfxinfo %s"; 51 @VisibleForTesting static final String GFXINFO_COMMAND_RESET = GFXINFO_COMMAND_GET + " reset"; 52 // Pattern matchers and enumerators to verify and pull gfxinfo metrics. 53 // Example: "** Graphics info for pid 853 [com.google.android.leanbacklauncher] **" 54 private static final String GFXINFO_OUTPUT_HEADER = "Graphics info for pid (\\d+) \\[(%s)\\]"; 55 // Note: use the [\\s\\S]* multi-line matcher to support String#matches(). Instead of splitting 56 // the larger sections into more granular lines, we can match across all lines for simplicity. 57 private static final String MULTILINE_MATCHER = "[\\s\\S]*%s[\\s\\S]*"; 58 59 public enum GfxInfoMetric { 60 // Example: "Total frames rendered: 20391" 61 TOTAL_FRAMES( 62 Pattern.compile("Total frames rendered: (\\d+)", Pattern.DOTALL), 63 1, 64 "total_frames"), 65 // Example: "Janky frames: 785 (3.85%)" 66 JANKY_FRAMES_COUNT( 67 Pattern.compile( 68 "Janky frames: (\\d+) \\(([0-9]+[\\.]?[0-9]+)\\%\\)", Pattern.DOTALL), 69 1, 70 "janky_frames_count"), 71 // Example: "Janky frames: 785 (3.85%)" 72 JANKY_FRAMES_PRCNT( 73 Pattern.compile( 74 "Janky frames: (\\d+) \\(([0-9]+[\\.]?[0-9]+)\\%\\)", Pattern.DOTALL), 75 2, 76 "janky_frames_percent"), 77 // Example: "Janky frames (legacy): 785 (3.85%)" 78 JANKY_FRAMES_LEGACY_COUNT( 79 Pattern.compile( 80 "Janky frames \\(legacy\\): (\\d+) \\(([0-9]+[\\.]?[0-9]+)\\%\\)", 81 Pattern.DOTALL), 82 1, 83 "janky_frames_legacy_count"), 84 // Example: "Janky frames (legacy): 785 (3.85%)" 85 JANKY_FRAMES_LEGACY_PRCNT( 86 Pattern.compile( 87 "Janky frames \\(legacy\\): (\\d+) \\(([0-9]+[\\.]?[0-9]+)\\%\\)", 88 Pattern.DOTALL), 89 2, 90 "janky_frames_legacy_percent"), 91 // Example: "50th percentile: 9ms" 92 FRAME_TIME_50TH( 93 Pattern.compile("50th percentile: (\\d+)ms", Pattern.DOTALL), 94 1, 95 "frame_render_time_percentile_50"), 96 // Example: "90th percentile: 9ms" 97 FRAME_TIME_90TH( 98 Pattern.compile("90th percentile: (\\d+)ms", Pattern.DOTALL), 99 1, 100 "frame_render_time_percentile_90"), 101 // Example: "95th percentile: 9ms" 102 FRAME_TIME_95TH( 103 Pattern.compile("95th percentile: (\\d+)ms", Pattern.DOTALL), 104 1, 105 "frame_render_time_percentile_95"), 106 // Example: "99th percentile: 9ms" 107 FRAME_TIME_99TH( 108 Pattern.compile("99th percentile: (\\d+)ms", Pattern.DOTALL), 109 1, 110 "frame_render_time_percentile_99"), 111 // Example: "Number Missed Vsync: 0" 112 NUM_MISSED_VSYNC( 113 Pattern.compile("Number Missed Vsync: (\\d+)", Pattern.DOTALL), 114 1, 115 "missed_vsync"), 116 // Example: "Number High input latency: 0" 117 NUM_HIGH_INPUT_LATENCY( 118 Pattern.compile("Number High input latency: (\\d+)", Pattern.DOTALL), 119 1, 120 "high_input_latency"), 121 // Example: "Number Slow UI thread: 0" 122 NUM_SLOW_UI_THREAD( 123 Pattern.compile("Number Slow UI thread: (\\d+)", Pattern.DOTALL), 124 1, 125 "slow_ui_thread"), 126 // Example: "Number Slow bitmap uploads: 0" 127 NUM_SLOW_BITMAP_UPLOADS( 128 Pattern.compile("Number Slow bitmap uploads: (\\d+)", Pattern.DOTALL), 129 1, 130 "slow_bmp_upload"), 131 // Example: "Number Slow issue draw commands: 0" 132 NUM_SLOW_DRAW( 133 Pattern.compile("Number Slow issue draw commands: (\\d+)", Pattern.DOTALL), 134 1, 135 "slow_issue_draw_cmds"), 136 // Example: "Number Frame deadline missed: 0" 137 NUM_FRAME_DEADLINE_MISSED( 138 Pattern.compile("Number Frame deadline missed: (\\d+)", Pattern.DOTALL), 139 1, 140 "deadline_missed"), 141 // Number Frame deadline missed (legacy): 0 142 NUM_FRAME_DEADLINE_MISSED_LEGACY( 143 Pattern.compile( 144 "Number Frame deadline missed \\(legacy\\): (\\d+)", Pattern.DOTALL), 145 1, 146 "deadline_missed_legacy"), 147 // Example: "50th gpu percentile: 9ms" 148 GPU_FRAME_TIME_50TH( 149 Pattern.compile("50th gpu percentile: (\\d+)ms", Pattern.DOTALL), 150 1, 151 "gpu_frame_render_time_percentile_50"), 152 // Example: "90th gpu percentile: 9ms" 153 GPU_FRAME_TIME_90TH( 154 Pattern.compile("90th gpu percentile: (\\d+)ms", Pattern.DOTALL), 155 1, 156 "gpu_frame_render_time_percentile_90"), 157 // Example: "95th gpu percentile: 9ms" 158 GPU_FRAME_TIME_95TH( 159 Pattern.compile("95th gpu percentile: (\\d+)ms", Pattern.DOTALL), 160 1, 161 "gpu_frame_render_time_percentile_95"), 162 // Example: "99th gpu percentile: 9ms" 163 GPU_FRAME_TIME_99TH( 164 Pattern.compile("99th gpu percentile: (\\d+)ms", Pattern.DOTALL), 165 1, 166 "gpu_frame_render_time_percentile_99"); 167 168 private Pattern mPattern; 169 private int mGroupIndex; 170 private String mMetricId; 171 GfxInfoMetric(Pattern pattern, int groupIndex, String metricId)172 GfxInfoMetric(Pattern pattern, int groupIndex, String metricId) { 173 mPattern = pattern; 174 mGroupIndex = groupIndex; 175 mMetricId = metricId; 176 } 177 parse(String lines)178 public Double parse(String lines) { 179 Matcher matcher = mPattern.matcher(lines); 180 if (matcher.find()) { 181 return Double.valueOf(matcher.group(mGroupIndex)); 182 } else { 183 return null; 184 } 185 } 186 getMetricId()187 public String getMetricId() { 188 return mMetricId; 189 } 190 } 191 192 private Set<String> mTrackedPackages = new HashSet<>(); 193 private UiDevice mDevice; 194 195 /** Clear existing jank metrics, unless explicitly configured. */ 196 @Override startCollecting()197 public boolean startCollecting() { 198 if (mTrackedPackages.isEmpty()) { 199 clearGfxInfo(); 200 } else { 201 int exceptionCount = 0; 202 Exception lastException = null; 203 for (String pkg : mTrackedPackages) { 204 try { 205 clearGfxInfo(pkg); 206 } catch (Exception e) { 207 Log.e(LOG_TAG, "Encountered exception resetting gfxinfo.", e); 208 lastException = e; 209 exceptionCount++; 210 } 211 } 212 // Throw exceptions after to not quit on a single failure. 213 if (exceptionCount > 1) { 214 throw new RuntimeException( 215 "Multiple exceptions were encountered resetting gfxinfo. Reporting the last" 216 + " one only; others are visible in logs.", 217 lastException); 218 } else if (exceptionCount == 1) { 219 throw new RuntimeException( 220 "Encountered exception resetting gfxinfo.", lastException); 221 } 222 } 223 // No exceptions denotes success. 224 return true; 225 } 226 227 /** Collect the {@code gfxinfo} metrics for tracked processes (or all, if unspecified). */ 228 @Override getMetrics()229 public Map<String, Double> getMetrics() { 230 Map<String, Double> result = new HashMap<>(); 231 int failedPackagesCount = 0; 232 if (mTrackedPackages.isEmpty()) { 233 result.putAll(getGfxInfoMetrics()); 234 // No need to update failed packages count here -- we get info for whatever is available 235 // so there are no "failed" packages. 236 } else { 237 for (String pkg : mTrackedPackages) { 238 try { 239 result.putAll(getGfxInfoMetrics(pkg)); 240 } catch (Exception e) { 241 // We log exceptions but continue so that we don't lose information on processes 242 // that were collected successfully. 243 Log.e(LOG_TAG, "Encountered exception getting gfxinfo.", e); 244 failedPackagesCount += 1; 245 } 246 } 247 } 248 result.put(FAILED_PACKAGES_COUNT_METRIC, Double.valueOf(failedPackagesCount)); 249 return result; 250 } 251 252 /** Do nothing, because nothing is needed to disable jank. */ 253 @Override stopCollecting()254 public boolean stopCollecting() { 255 return true; 256 } 257 258 /** Add a package or list of packages to be tracked. */ addTrackedPackages(String... packages)259 public void addTrackedPackages(String... packages) { 260 Collections.addAll(mTrackedPackages, packages); 261 } 262 263 /** Clear the {@code gfxinfo} for all packages. */ 264 @VisibleForTesting clearGfxInfo()265 void clearGfxInfo() { 266 // Not specifying a package will clear everything. 267 clearGfxInfo(""); 268 } 269 270 /** Clear the {@code gfxinfo} for the {@code pkg} specified. */ 271 @VisibleForTesting clearGfxInfo(String pkg)272 void clearGfxInfo(String pkg) { 273 try { 274 if (pkg.isEmpty()) { 275 String command = String.format(GFXINFO_COMMAND_RESET, "--"); 276 String output = getDevice().executeShellCommand(command); 277 // Success if any header (set by passing an empty-string) exists in the output. 278 verifyMatches(output, getHeaderMatcher(""), "No package headers in output."); 279 Log.v(LOG_TAG, "Cleared all gfxinfo."); 280 } else { 281 String command = String.format(GFXINFO_COMMAND_RESET, pkg); 282 String output = getDevice().executeShellCommand(command); 283 // Success if the specified package header exists in the output. 284 verifyMatches(output, getHeaderMatcher(pkg), "No package header in output."); 285 Log.v(LOG_TAG, String.format("Cleared %s gfxinfo.", pkg)); 286 } 287 } catch (IOException e) { 288 throw new RuntimeException("Failed to clear gfxinfo.", e); 289 } 290 } 291 292 /** Return a {@code Map<String, Double>} of {@code gfxinfo} metrics for all processes. */ 293 @VisibleForTesting getGfxInfoMetrics()294 Map<String, Double> getGfxInfoMetrics() { 295 return getGfxInfoMetrics(""); 296 } 297 298 /** Return a {@code Map<String, Double>} of {@code gfxinfo} metrics for {@code pkg}. */ 299 @VisibleForTesting getGfxInfoMetrics(String pkg)300 Map<String, Double> getGfxInfoMetrics(String pkg) { 301 try { 302 String command = String.format(GFXINFO_COMMAND_GET, pkg); 303 String output = getDevice().executeShellCommand(command); 304 verifyMatches(output, getHeaderMatcher(pkg), "Missing package header."); 305 // Split each new section starting with two asterisks '**', and then query and append 306 // all metrics. This method supports both single-package and multi-package outputs. 307 String[] pkgMetricSections = output.split("\n\\*\\*"); 308 Map<String, Double> result = new HashMap<>(); 309 // Skip the 1st section, which contains only header information. 310 for (int i = 1; i < pkgMetricSections.length; i++) { 311 result.putAll(parseGfxInfoMetrics(pkgMetricSections[i])); 312 } 313 return result; 314 } catch (IOException e) { 315 throw new RuntimeException("Failed to get gfxinfo.", e); 316 } 317 } 318 319 /** Parse the {@code output} of {@code gfxinfo} to a {@code Map<String, Double>} of metrics. */ parseGfxInfoMetrics(String output)320 private Map<String, Double> parseGfxInfoMetrics(String output) { 321 Matcher header = Pattern.compile(getHeaderMatcher("")).matcher(output); 322 if (!header.matches()) { 323 throw new RuntimeException("Failed to parse package from gfxinfo output."); 324 } 325 // Package name is the only required field. 326 String packageName = header.group(2); 327 Log.v(LOG_TAG, String.format("Collecting metrics for: %s", packageName)); 328 // Parse each metric from the results via a common pattern. 329 Map<String, Double> results = new HashMap<String, Double>(); 330 for (GfxInfoMetric metric : GfxInfoMetric.values()) { 331 String metricKey = 332 constructKey(GFXINFO_METRICS_PREFIX, packageName, metric.getMetricId()); 333 // Find the metric or log that it's missing. 334 Double value = metric.parse(output); 335 if (value == null) { 336 Log.d(LOG_TAG, String.format("Did not find %s from %s", metricKey, packageName)); 337 } else { 338 results.put(metricKey, value); 339 } 340 } 341 return results; 342 } 343 344 /** 345 * Returns a matcher {@code String} for {@code pkg}'s {@code gfxinfo} headers. 346 * 347 * <p>Note: {@code pkg} may be empty. 348 */ getHeaderMatcher(String pkg)349 private String getHeaderMatcher(String pkg) { 350 return String.format( 351 MULTILINE_MATCHER, 352 String.format(GFXINFO_OUTPUT_HEADER, (pkg.isEmpty() ? ".*" : pkg))); 353 } 354 355 /** Verify the {@code output} matches {@code match}, or throw if not. */ verifyMatches(String output, String match, String message, Object... args)356 private void verifyMatches(String output, String match, String message, Object... args) { 357 Verify.verify(output.matches(match), message, args); 358 } 359 360 /** Returns the {@link UiDevice} under test. */ 361 @VisibleForTesting getDevice()362 protected UiDevice getDevice() { 363 if (mDevice == null) { 364 mDevice = UiDevice.getInstance(InstrumentationRegistry.getInstrumentation()); 365 } 366 return mDevice; 367 } 368 } 369