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