1 /* 2 * Copyright (C) 2017 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.tradefed.device.metric; 18 19 import com.android.ddmlib.NullOutputReceiver; 20 import com.android.tradefed.config.Option; 21 import com.android.tradefed.config.OptionClass; 22 import com.android.tradefed.device.CollectingOutputReceiver; 23 import com.android.tradefed.device.DeviceNotAvailableException; 24 import com.android.tradefed.device.DeviceRuntimeException; 25 import com.android.tradefed.device.ITestDevice; 26 import com.android.tradefed.log.LogUtil.CLog; 27 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric; 28 import com.android.tradefed.result.FileInputStreamSource; 29 import com.android.tradefed.result.LogDataType; 30 import com.android.tradefed.result.TestDescription; 31 import com.android.tradefed.result.error.DeviceErrorIdentifier; 32 import com.android.tradefed.util.CommandResult; 33 import com.android.tradefed.util.FileUtil; 34 import com.android.tradefed.util.IRunUtil; 35 import com.android.tradefed.util.RunUtil; 36 37 import com.google.common.annotations.VisibleForTesting; 38 39 import java.io.File; 40 import java.nio.file.Paths; 41 import java.util.ArrayList; 42 import java.util.List; 43 import java.util.Map; 44 import java.util.concurrent.TimeUnit; 45 import java.util.regex.Matcher; 46 import java.util.regex.Pattern; 47 48 /** 49 * A {@link IMetricCollector} that runs atrace during a test and collects the result and log 50 * them to the invocation. 51 */ 52 @OptionClass(alias = "atrace") 53 public class AtraceCollector extends BaseDeviceMetricCollector { 54 55 @Option(name = "categories", 56 description = "the tracing categories atrace will capture") 57 private List<String> mCategories = new ArrayList<>(); 58 59 @Option( 60 name = "log-path", 61 description = "the temporary location the trace log will be saved to on device" 62 ) 63 private String mLogPath = "/data/local/tmp/"; 64 65 @Option( 66 name = "log-filename", 67 description = "the temporary location the trace log will be saved to on device" 68 ) 69 private String mLogFilename = "atrace"; 70 71 @Option(name = "preserve-ondevice-log", 72 description = "delete the trace log on the target device after the host collects it") 73 private boolean mPreserveOndeviceLog = false; 74 75 @Option(name = "compress-dump", 76 description = "produce a compressed trace dump") 77 private boolean mCompressDump = true; 78 79 @Option(name = "atrace-on-boot", 80 description = "enable atrace collection for bootup") 81 private boolean mTraceOnBoot = false; 82 83 @Option(name = "skip-atrace-start", 84 description = "Skip atrace start if the option is enabled. Needed when atrace is" 85 + "enabled through fastboot option.") 86 private boolean mSkipAtraceStart = false; 87 88 /* These options will arrange a post processing executable binary to be ran on the collected 89 * trace. 90 * E.G. 91 * <option name="post-process-binary" value="/path/to/analyzer.par"/> 92 * <option name="post-process-input-file-key" value="TRACE_FILE"/> 93 * <option name="post-process-args" value="--input_file TRACE_FILE --arg1 --arg2"/> 94 * Will be executed as 95 * /path/to/analyzer.par --input_file TRACE_FILE --arg1 --arg2 96 */ 97 @Option( 98 name = "post-process-input-file-key", 99 description = 100 "The string that will be replaced with the absolute path to the trace file " 101 + "in post-process-args" 102 ) 103 private String mLogProcessingTraceInput = "TRACE_FILE"; 104 105 @Option( 106 name = "post-process-binary", 107 description = "a self-contained binary that will be executed on the trace file" 108 ) 109 private File mLogProcessingBinary = null; 110 111 @Option(name = "post-process-args", description = "args for the binary") 112 private List<String> mLogProcessingArgs = new ArrayList<>(); 113 114 @Option( 115 name = "post-process-timeout", 116 isTimeVal = true, 117 description = 118 "The amount of time (eg, 1m2s) that Tradefed will wait for the " 119 + "postprocessing subprocess to finish" 120 ) 121 private long mLogProcessingTimeoutMilliseconds = 0; 122 123 /* If the tool is producing files to upload, this can be used to key in to which files are 124 * produced and upload them. 125 * The first matching group in the regex is treated as a file and uploaded. 126 * Eg, if this output is produced by the postprocessing binary: 127 * 128 * my-metric-name /tmp/a.txt 129 * 130 * then setting this option to: "my-metric-name (.*txt)" will upload /tmp/a.txt 131 * 132 * If not set, or the file cannot be found, the tool will still upload its stdout and stderr. 133 * Can be specified multiple times. 134 */ 135 @Option( 136 name = "post-process-output-file-regex", 137 description = 138 "A regex that will be applied to the stdout of the post processing program." 139 + "the first matching group will be treated as a file and uploaded as " 140 + "a test log.") 141 private List<String> mLogProcessingOutputRegex = new ArrayList<>(); 142 143 private IRunUtil mRunUtil = RunUtil.getDefault(); 144 145 private Thread mThread; 146 147 private static final long DEVICE_OFFLINE_TIMEOUT_MS = 60 * 1000; 148 private static final long DEVICE_ONLINE_TIMEOUT_MS = 60 * 1000; 149 fullLogPath()150 protected String fullLogPath() { 151 return Paths.get(mLogPath, mLogFilename + "." + getLogType().getFileExt()).toString(); 152 } 153 getLogType()154 protected LogDataType getLogType() { 155 if (mCompressDump) { 156 return LogDataType.ATRACE; 157 } else { 158 return LogDataType.TEXT; 159 } 160 } 161 startTracing(ITestDevice device)162 protected void startTracing(ITestDevice device) throws DeviceNotAvailableException { 163 //atrace --async_start will set a variety of sysfs entries, and then exit. 164 String cmd = "atrace --async_start "; 165 if (mCompressDump) { 166 cmd += "-z "; 167 } 168 cmd += String.join(" ", mCategories); 169 CollectingOutputReceiver c = new CollectingOutputReceiver(); 170 CLog.i("issuing command : %s to device: %s", cmd, device.getSerialNumber()); 171 device.executeShellCommand(cmd, c, 1, TimeUnit.SECONDS, 1); 172 CLog.i("command output: %s", c.getOutput()); 173 } 174 175 @Override onTestStart(DeviceMetricData testData)176 public void onTestStart(DeviceMetricData testData) throws DeviceNotAvailableException { 177 if(mSkipAtraceStart) { 178 CLog.d("Skip atrace start because tracing is enabled through fastboot option"); 179 return; 180 } 181 if (mCategories.isEmpty()) { 182 CLog.d("no categories specified to trace, not running AtraceMetricCollector"); 183 return; 184 } 185 186 if (mTraceOnBoot) { 187 mThread = new Thread(() -> { 188 try { 189 for (ITestDevice device : getDevices()) { 190 // wait for device reboot 191 device.waitForDeviceNotAvailable(DEVICE_OFFLINE_TIMEOUT_MS); 192 device.waitForDeviceOnline(DEVICE_ONLINE_TIMEOUT_MS); 193 // wait for device to be in root 194 device.waitForDeviceNotAvailable(DEVICE_OFFLINE_TIMEOUT_MS); 195 device.waitForDeviceOnline(); 196 startTracing(device); 197 } 198 } catch (DeviceNotAvailableException e) { 199 CLog.e("Error starting atrace"); 200 CLog.e(e); 201 } 202 }); 203 mThread.setDaemon(true); 204 mThread.setName("AtraceCollector-on-boot"); 205 mThread.start(); 206 } else { 207 for (ITestDevice device : getDevices()) { 208 startTracing(device); 209 } 210 } 211 } 212 stopTracing(ITestDevice device)213 protected void stopTracing(ITestDevice device) throws DeviceNotAvailableException { 214 CLog.i("collecting atrace log from device: %s", device.getSerialNumber()); 215 device.executeShellCommand( 216 "atrace --async_stop -z -c -o " + fullLogPath(), 217 new NullOutputReceiver(), 218 300, 219 TimeUnit.SECONDS, 220 1); 221 CLog.d("Trace collected successfully."); 222 } 223 postProcess(File trace)224 private void postProcess(File trace) { 225 if (mLogProcessingBinary == null 226 || !mLogProcessingBinary.exists() 227 || !mLogProcessingBinary.canExecute()) { 228 CLog.w("No trace postprocessor specified. Skipping trace postprocessing."); 229 return; 230 } 231 232 List<String> commandLine = new ArrayList<String>(); 233 commandLine.add(mLogProcessingBinary.getAbsolutePath()); 234 for (String entry : mLogProcessingArgs) { 235 commandLine.add(entry.replaceAll(mLogProcessingTraceInput, trace.getAbsolutePath())); 236 } 237 238 String[] commandLineArr = new String[commandLine.size()]; 239 commandLine.toArray(commandLineArr); 240 CommandResult result = 241 mRunUtil.runTimedCmd(mLogProcessingTimeoutMilliseconds, commandLineArr); 242 243 CLog.v( 244 "Trace postprocessing status: %s\nstdout: %s\nstderr: ", 245 result.getStatus(), result.getStdout(), result.getStderr()); 246 if (result.getStdout() == null) { 247 return; 248 } 249 250 for (String regex : mLogProcessingOutputRegex) { 251 Pattern pattern = Pattern.compile(regex); 252 for (String line : result.getStdout().split("\n")) { 253 Matcher m = pattern.matcher(line); 254 if (m.find() && m.groupCount() == 1) { 255 File f = new File(m.group(1)); 256 if (f.exists() && !f.isDirectory()) { 257 LogDataType type; 258 switch (FileUtil.getExtension(f.getName())) { 259 case ".png": 260 type = LogDataType.PNG; 261 break; 262 case ".txt": 263 type = LogDataType.TEXT; 264 break; 265 default: 266 type = LogDataType.UNKNOWN; 267 break; 268 } 269 try (FileInputStreamSource stream = new FileInputStreamSource(f)) { 270 testLog(FileUtil.getBaseName(f.getName()), type, stream); 271 } 272 } 273 } 274 } 275 } 276 } 277 278 @Override onTestEnd( DeviceMetricData testData, final Map<String, Metric> currentTestCaseMetrics, TestDescription test)279 public void onTestEnd( 280 DeviceMetricData testData, 281 final Map<String, Metric> currentTestCaseMetrics, 282 TestDescription test) 283 throws DeviceNotAvailableException { 284 285 286 if (!mSkipAtraceStart && mCategories.isEmpty()) { 287 return; 288 } 289 290 // Stop and collect the atrace only if the atrace start is skipped which 291 // then uses the default categories or if the categories are explicitly 292 // passed. 293 for (ITestDevice device : getDevices()) { 294 try { 295 stopTracing(device); 296 297 File trace = device.pullFile(fullLogPath()); 298 if (trace != null) { 299 CLog.i("Log size: %s bytes", String.valueOf(trace.length())); 300 301 try (FileInputStreamSource streamSource = new FileInputStreamSource(trace)) { 302 testLog( 303 mLogFilename + "_" + test + device.getSerialNumber() + "_", 304 getLogType(), 305 streamSource); 306 } 307 308 postProcess(trace); 309 trace.delete(); 310 } else { 311 throw new DeviceRuntimeException( 312 String.format("failed to pull log: %s", fullLogPath()), 313 DeviceErrorIdentifier.FAIL_PULL_FILE); 314 } 315 316 if (!mPreserveOndeviceLog) { 317 device.deleteFile(fullLogPath()); 318 } 319 else { 320 CLog.w("preserving ondevice atrace log: %s", fullLogPath()); 321 } 322 } catch (DeviceRuntimeException e) { 323 CLog.e("Error retrieving atrace log! device not available:"); 324 CLog.e(e); 325 } 326 } 327 } 328 329 @VisibleForTesting setRunUtil(IRunUtil util)330 void setRunUtil(IRunUtil util) { 331 mRunUtil = util; 332 } 333 } 334