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 121 private Pattern mPattern; 122 private int mGroupIndex; 123 private String mMetricId; 124 GfxInfoMetric(Pattern pattern, int groupIndex, String metricId)125 GfxInfoMetric(Pattern pattern, int groupIndex, String metricId) { 126 mPattern = pattern; 127 mGroupIndex = groupIndex; 128 mMetricId = metricId; 129 } 130 parse(String lines)131 public Double parse(String lines) { 132 Matcher matcher = mPattern.matcher(lines); 133 if (matcher.matches()) { 134 return Double.valueOf(matcher.group(mGroupIndex)); 135 } else { 136 return null; 137 } 138 } 139 getMetricId()140 public String getMetricId() { 141 return mMetricId; 142 } 143 } 144 145 private Set<String> mTrackedPackages = new HashSet<>(); 146 private UiDevice mDevice; 147 148 /** Clear existing jank metrics, unless explicitly configured. */ 149 @Override startCollecting()150 public boolean startCollecting() { 151 if (mTrackedPackages.isEmpty()) { 152 clearGfxInfo(); 153 } else { 154 int exceptionCount = 0; 155 Exception lastException = null; 156 for (String pkg : mTrackedPackages) { 157 try { 158 clearGfxInfo(pkg); 159 } catch (Exception e) { 160 Log.e(LOG_TAG, "Encountered exception resetting gfxinfo.", e); 161 lastException = e; 162 exceptionCount++; 163 } 164 } 165 // Throw exceptions after to not quit on a single failure. 166 if (exceptionCount > 1) { 167 throw new RuntimeException( 168 "Multiple exceptions were encountered resetting gfxinfo. Reporting the last" 169 + " one only; others are visible in logs.", 170 lastException); 171 } else if (exceptionCount == 1) { 172 throw new RuntimeException( 173 "Encountered exception resetting gfxinfo.", lastException); 174 } 175 } 176 // No exceptions denotes success. 177 return true; 178 } 179 180 /** Collect the {@code gfxinfo} metrics for tracked processes (or all, if unspecified). */ 181 @Override getMetrics()182 public Map<String, Double> getMetrics() { 183 Map<String, Double> result = new HashMap<>(); 184 if (mTrackedPackages.isEmpty()) { 185 result.putAll(getGfxInfoMetrics()); 186 } else { 187 int exceptionCount = 0; 188 Exception lastException = null; 189 for (String pkg : mTrackedPackages) { 190 try { 191 result.putAll(getGfxInfoMetrics(pkg)); 192 } catch (Exception e) { 193 Log.e(LOG_TAG, "Encountered exception getting gfxinfo.", e); 194 lastException = e; 195 exceptionCount++; 196 } 197 } 198 // Throw exceptions after to ensure all failures are reported. The metrics will still 199 // not be collected at this point, but it will possibly make the issue cause clearer. 200 if (exceptionCount > 1) { 201 throw new RuntimeException( 202 "Multiple exceptions were encountered getting gfxinfo. Reporting the last" 203 + " one only; others are visible in logs.", 204 lastException); 205 } else if (exceptionCount == 1) { 206 throw new RuntimeException("Encountered exception getting gfxinfo.", lastException); 207 } 208 } 209 return result; 210 } 211 212 /** Do nothing, because nothing is needed to disable jank. */ 213 @Override stopCollecting()214 public boolean stopCollecting() { 215 return true; 216 } 217 218 /** Add a package or list of packages to be tracked. */ addTrackedPackages(String... packages)219 public void addTrackedPackages(String... packages) { 220 Collections.addAll(mTrackedPackages, packages); 221 } 222 223 /** Clear the {@code gfxinfo} for all packages. */ 224 @VisibleForTesting clearGfxInfo()225 void clearGfxInfo() { 226 // Not specifying a package will clear everything. 227 clearGfxInfo(""); 228 } 229 230 /** Clear the {@code gfxinfo} for the {@code pkg} specified. */ 231 @VisibleForTesting clearGfxInfo(String pkg)232 void clearGfxInfo(String pkg) { 233 try { 234 String command = String.format(GFXINFO_COMMAND_RESET, pkg); 235 String output = getDevice().executeShellCommand(command); 236 // Success if the (specified package or any if unspecified) header exists in the output. 237 verifyMatches(output, getHeaderMatcher(pkg), "Did not find package header in output."); 238 Log.v(LOG_TAG, String.format("Cleared %s gfxinfo.", pkg.isEmpty() ? "all" : pkg)); 239 } catch (IOException e) { 240 throw new RuntimeException("Failed to clear gfxinfo.", e); 241 } 242 } 243 244 /** Return a {@code Map<String, Double>} of {@code gfxinfo} metrics for all processes. */ 245 @VisibleForTesting getGfxInfoMetrics()246 Map<String, Double> getGfxInfoMetrics() { 247 return getGfxInfoMetrics(""); 248 } 249 250 /** Return a {@code Map<String, Double>} of {@code gfxinfo} metrics for {@code pkg}. */ 251 @VisibleForTesting getGfxInfoMetrics(String pkg)252 Map<String, Double> getGfxInfoMetrics(String pkg) { 253 try { 254 String command = String.format(GFXINFO_COMMAND_GET, pkg); 255 String output = getDevice().executeShellCommand(command); 256 verifyMatches(output, getHeaderMatcher(pkg), "Missing package header."); 257 // Split each new section starting with two asterisks '**', and then query and append 258 // all metrics. This method supports both single-package and multi-package outputs. 259 String[] pkgMetricSections = output.split("\n\\*\\*"); 260 Map<String, Double> result = new HashMap<>(); 261 // Skip the 1st section, which contains only header information. 262 for (int i = 1; i < pkgMetricSections.length; i++) { 263 result.putAll(parseGfxInfoMetrics(pkgMetricSections[i])); 264 } 265 return result; 266 } catch (IOException e) { 267 throw new RuntimeException("Failed to get gfxinfo.", e); 268 } 269 } 270 271 /** Parse the {@code output} of {@code gfxinfo} to a {@code Map<String, Double>} of metrics. */ parseGfxInfoMetrics(String output)272 private Map<String, Double> parseGfxInfoMetrics(String output) { 273 Matcher header = Pattern.compile(getHeaderMatcher("")).matcher(output); 274 if (!header.matches()) { 275 throw new RuntimeException("Failed to parse package from gfxinfo output."); 276 } 277 // Package name is the only required field. 278 String packageName = header.group(2); 279 Log.v(LOG_TAG, String.format("Collecting metrics for: %s", packageName)); 280 // Parse each metric from the results via a common pattern. 281 Map<String, Double> results = new HashMap<String, Double>(); 282 for (GfxInfoMetric metric : GfxInfoMetric.values()) { 283 String metricKey = 284 constructKey(GFXINFO_METRICS_PREFIX, packageName, metric.getMetricId()); 285 // Find the metric or log that it's missing. 286 Double value = metric.parse(output); 287 if (value == null) { 288 Log.d(LOG_TAG, String.format("Did not find %s from %s", metricKey, packageName)); 289 } else { 290 results.put(metricKey, value); 291 } 292 } 293 return results; 294 } 295 296 /** 297 * Returns a matcher {@code String} for {@code pkg}'s {@code gfxinfo} headers. 298 * 299 * <p>Note: {@code pkg} may be empty. 300 */ getHeaderMatcher(String pkg)301 private String getHeaderMatcher(String pkg) { 302 return String.format( 303 MULTILINE_MATCHER, 304 String.format(GFXINFO_OUTPUT_HEADER, (pkg.isEmpty() ? ".*" : pkg))); 305 } 306 307 /** Verify the {@code output} matches {@code match}, or throw if not. */ verifyMatches(String output, String match, String message, Object... args)308 private void verifyMatches(String output, String match, String message, Object... args) { 309 Verify.verify(output.matches(match), message, args); 310 } 311 312 /** Returns the {@link UiDevice} under test. */ 313 @VisibleForTesting getDevice()314 protected UiDevice getDevice() { 315 if (mDevice == null) { 316 mDevice = UiDevice.getInstance(InstrumentationRegistry.getInstrumentation()); 317 } 318 return mDevice; 319 } 320 } 321