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