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