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 package android.device.collectors;
17 
18 import android.device.collectors.annotations.MetricOption;
19 import android.device.collectors.annotations.OptionClass;
20 import android.device.collectors.util.SendToInstrumentation;
21 import android.os.Bundle;
22 import android.os.Environment;
23 import android.os.ParcelFileDescriptor;
24 import android.os.Trace;
25 import androidx.annotation.VisibleForTesting;
26 import android.util.Log;
27 
28 import androidx.test.InstrumentationRegistry;
29 import androidx.test.internal.runner.listener.InstrumentationRunListener;
30 
31 import org.junit.runner.Description;
32 import org.junit.runner.Result;
33 import org.junit.runner.notification.Failure;
34 
35 import java.io.ByteArrayOutputStream;
36 import java.io.File;
37 import java.io.IOException;
38 import java.io.InputStream;
39 import java.io.OutputStream;
40 import java.io.PrintStream;
41 import java.nio.charset.StandardCharsets;
42 import java.util.ArrayList;
43 import java.util.Arrays;
44 import java.util.HashMap;
45 import java.util.HashSet;
46 import java.util.Map;
47 import java.util.List;
48 import java.util.Set;
49 
50 /**
51  * Base implementation of a device metric listener that will capture and output metrics for each
52  * test run or test cases. Collectors will have access to {@link DataRecord} objects where they
53  * can put results and the base class ensure these results will be send to the instrumentation.
54  *
55  * Unless the shell is used to write files, any subclass that uses the directory created with
56  * {@link #createAndEmptyDirectory(String)} needs external storage permission. So to use this class
57  * at runtime in such subclasses, your test need to
58  * <a href="{@docRoot}training/basics/data-storage/files.html#GetWritePermission">have storage
59  * permission enabled</a>, and preferably granted at install time (to avoid interrupting the test).
60  * For testing at desk, run adb install -r -g testpackage.apk
61  * "-g" grants all required permission at install time.
62  *
63  * Filtering:
64  * You can annotate any test method (@Test) with {@link MetricOption} and specify an arbitrary
65  * group name that the test will be part of. It is possible to trigger the collection only against
66  * test part of a group using '--include-filter-group [group name]' or to exclude a particular
67  * group using '--exclude-filter-group [group name]'.
68  * Several group name can be passed using a comma separated argument.
69  *
70  */
71 public class BaseMetricListener extends InstrumentationRunListener {
72 
73     public static final int BUFFER_SIZE = 1024;
74     // Default collect iteration interval.
75     private static final int DEFAULT_COLLECT_INTERVAL = 1;
76 
77     // Default skip metric until iteration count.
78     private static final int SKIP_UNTIL_DEFAULT_ITERATION = 0;
79 
80     /** Options keys that the collector can receive. */
81     // Filter groups, comma separated list of group name to be included or excluded
82     public static final String INCLUDE_FILTER_GROUP_KEY = "include-filter-group";
83     public static final String EXCLUDE_FILTER_GROUP_KEY = "exclude-filter-group";
84     // Argument passed to AndroidJUnitRunner to make it log-only, we shouldn't collect on log only.
85     public static final String ARGUMENT_LOG_ONLY = "log";
86     // Collect metric every nth iteration of a test with the same name.
87     public static final String COLLECT_ITERATION_INTERVAL = "collect_iteration_interval";
88 
89     // Skip metric collection until given n iteration. Uses 1 indexing here.
90     // For example if overall iteration is 10 and skip until iteration is set
91     // to 3. Metric will not be collected for 1st,2nd and 3rd iteration.
92     public static final String SKIP_METRIC_UNTIL_ITERATION = "skip_metric_until_iteration";
93 
94     private static final String NAMESPACE_SEPARATOR = ":";
95 
96     private DataRecord mRunData;
97     private DataRecord mTestData;
98 
99     private Bundle mArgsBundle = null;
100     private final List<String> mIncludeFilters;
101     private final List<String> mExcludeFilters;
102     private boolean mLogOnly = false;
103     // Store the method name and invocation count.
104     private Map<String, Integer> mTestIdInvocationCount = new HashMap<>();
105     private int mCollectIterationInterval = 1;
106     private int mSkipMetricUntilIteration = 0;
107 
108     // Whether to report the results as instrumentation results. Used by metric collector rules,
109     // which do not have the information to invoke InstrumentationRunFinished() to report metrics.
110     private boolean mReportAsInstrumentationResults = false;
111 
BaseMetricListener()112     public BaseMetricListener() {
113         mIncludeFilters = new ArrayList<>();
114         mExcludeFilters = new ArrayList<>();
115     }
116 
117     /**
118      * Constructor to simulate receiving the instrumentation arguments. Should not be used except
119      * for testing.
120      */
121     @VisibleForTesting
BaseMetricListener(Bundle argsBundle)122     protected BaseMetricListener(Bundle argsBundle) {
123         this();
124         mArgsBundle = argsBundle;
125     }
126 
127     @Override
testRunStarted(Description description)128     public final void testRunStarted(Description description) throws Exception {
129         Trace.beginSection(this.getClass().getSimpleName() + ":testRunStarted");
130         setUp();
131         if (!mLogOnly) {
132             try {
133                 mRunData = createDataRecord();
134                 onTestRunStart(mRunData, description);
135             } catch (RuntimeException e) {
136                 // Prevent exception from reporting events.
137                 Log.e(getTag(), "Exception during onTestRunStart.", e);
138             }
139         }
140         super.testRunStarted(description);
141         Trace.endSection();
142     }
143 
144     @Override
testRunFinished(Result result)145     public final void testRunFinished(Result result) throws Exception {
146         Trace.beginSection(this.getClass().getSimpleName() + ":testRunFinished");
147         if (!mLogOnly) {
148             try {
149                 onTestRunEnd(mRunData, result);
150             } catch (RuntimeException e) {
151                 // Prevent exception from reporting events.
152                 Log.e(getTag(), "Exception during onTestRunEnd.", e);
153             }
154         }
155         cleanUp();
156         super.testRunFinished(result);
157         Trace.endSection();
158     }
159 
160     @Override
testStarted(Description description)161     public final void testStarted(Description description) throws Exception {
162         Trace.beginSection(this.getClass().getSimpleName() + ":testStarted");
163         // Update the current invocation before proceeding with metric collection.
164         // mTestIdInvocationCount uses 1 indexing.
165         mTestIdInvocationCount.compute(description.toString(),
166                 (key, value) -> (value == null) ? 1 : value + 1);
167 
168         if (shouldRun(description)) {
169             try {
170                 mTestData = createDataRecord();
171                 onTestStart(mTestData, description);
172             } catch (RuntimeException e) {
173                 // Prevent exception from reporting events.
174                 Log.e(getTag(), "Exception during onTestStart.", e);
175             }
176         }
177         super.testStarted(description);
178         Trace.endSection();
179     }
180 
181     @Override
testFailure(Failure failure)182     public final void testFailure(Failure failure) throws Exception {
183         Description description = failure.getDescription();
184         if (shouldRun(description)) {
185             try {
186                 onTestFail(mTestData, description, failure);
187             } catch (RuntimeException e) {
188                 // Prevent exception from reporting events.
189                 Log.e(getTag(), "Exception during onTestFail.", e);
190             }
191         }
192         super.testFailure(failure);
193     }
194 
195     @Override
testFinished(Description description)196     public final void testFinished(Description description) throws Exception {
197         Trace.beginSection(this.getClass().getSimpleName() + ":testFinished");
198         if (shouldRun(description)) {
199             try {
200                 onTestEnd(mTestData, description);
201             } catch (RuntimeException e) {
202                 // Prevent exception from reporting events.
203                 Log.e(getTag(), "Exception during onTestEnd.", e);
204             }
205             if (mTestData.hasMetrics()) {
206                 // Only send the status progress if there are metrics
207                 if (mReportAsInstrumentationResults) {
208                     getInstrumentation().addResults(mTestData.createBundleFromMetrics());
209                 } else {
210                 SendToInstrumentation.sendBundle(getInstrumentation(),
211                         mTestData.createBundleFromMetrics());
212             }
213             }
214         }
215         super.testFinished(description);
216         Trace.endSection();
217     }
218 
219     @Override
instrumentationRunFinished( PrintStream streamResult, Bundle resultBundle, Result junitResults)220     public void instrumentationRunFinished(
221             PrintStream streamResult, Bundle resultBundle, Result junitResults) {
222         // Test Run data goes into the INSTRUMENTATION_RESULT
223         if (mRunData != null) {
224             resultBundle.putAll(mRunData.createBundleFromMetrics());
225         }
226     }
227 
228     /**
229      * Set up the metric collector.
230      *
231      * <p>If another class is invoking the metric collector's callbacks directly, it should call
232      * this method to make sure that the metric collector is set up properly.
233      */
setUp()234     public final void setUp() {
235         parseArguments();
236         setupAdditionalArgs();
237         onSetUp();
238     }
239 
240     /**
241      * Clean up the metric collector.
242      *
243      * <p>If another class is invoking the metric collector's callbacks directly, it should call
244      * this method to make sure that the metric collector is cleaned up properly after collection.
245      */
cleanUp()246     public final void cleanUp() {
247         onCleanUp();
248     }
249 
250     /**
251      * Create a {@link DataRecord}. Exposed for testing.
252      */
253     @VisibleForTesting
createDataRecord()254     DataRecord createDataRecord() {
255         return new DataRecord();
256     }
257 
258     // ---------- Interfaces that can be implemented to set up and clean up metric collection.
259 
260     /** Called if custom set-up is needed for this metric collector. */
onSetUp()261     protected void onSetUp() {
262         // Does nothing by default.
263     }
264 
onCleanUp()265     protected void onCleanUp() {
266         // Does nothing by default.
267     }
268 
269     // ---------- Interfaces that can be implemented to take action on each test state.
270 
271     /**
272      * Called when {@link #testRunStarted(Description)} is called.
273      *
274      * @param runData structure where metrics can be put.
275      * @param description the {@link Description} for the run about to start.
276      */
onTestRunStart(DataRecord runData, Description description)277     public void onTestRunStart(DataRecord runData, Description description) {
278         // Does nothing
279     }
280 
281     /**
282      * Called when {@link #testRunFinished(Result result)} is called.
283      *
284      * @param runData structure where metrics can be put.
285      * @param result the {@link Result} for the run coming from the runner.
286      */
onTestRunEnd(DataRecord runData, Result result)287     public void onTestRunEnd(DataRecord runData, Result result) {
288         // Does nothing
289     }
290 
291     /**
292      * Called when {@link #testStarted(Description)} is called.
293      *
294      * @param testData structure where metrics can be put.
295      * @param description the {@link Description} for the test case about to start.
296      */
onTestStart(DataRecord testData, Description description)297     public void onTestStart(DataRecord testData, Description description) {
298         // Does nothing
299     }
300 
301     /**
302      * Called when {@link #testFailure(Failure)} is called.
303      *
304      * @param testData structure where metrics can be put.
305      * @param description the {@link Description} for the test case that just failed.
306      * @param failure the {@link Failure} describing the failure.
307      */
onTestFail(DataRecord testData, Description description, Failure failure)308     public void onTestFail(DataRecord testData, Description description, Failure failure) {
309         // Does nothing
310     }
311 
312     /**
313      * Called when {@link #testFinished(Description)} is called.
314      *
315      * @param testData structure where metrics can be put.
316      * @param description the {@link Description} of the test coming from the runner.
317      */
onTestEnd(DataRecord testData, Description description)318     public void onTestEnd(DataRecord testData, Description description) {
319         // Does nothing
320     }
321 
322     /**
323      * To add listener-specific extra args, implement this method in the sub class and add the
324      * listener specific args.
325      */
setupAdditionalArgs()326     public void setupAdditionalArgs() {
327         // NO-OP by default
328     }
329 
330     /**
331      * Turn executeShellCommand into a blocking operation.
332      *
333      * @param command shell command to be executed.
334      * @return byte array of execution result
335      */
executeCommandBlocking(String command)336     public byte[] executeCommandBlocking(String command) {
337         try (
338                 InputStream is = new ParcelFileDescriptor.AutoCloseInputStream(
339                         getInstrumentation().getUiAutomation().executeShellCommand(command));
340                 ByteArrayOutputStream out = new ByteArrayOutputStream()
341         ) {
342             byte[] buf = new byte[BUFFER_SIZE];
343             int length;
344             while ((length = is.read(buf)) >= 0) {
345                 out.write(buf, 0, length);
346             }
347             return out.toByteArray();
348         } catch (IOException e) {
349             Log.e(getTag(), "Error executing: " + command, e);
350             return null;
351         }
352     }
353 
fileExists(File file)354     private boolean fileExists(File file) {
355         final byte[] cmdOut = executeCommandBlocking("ls -d " + file.getAbsolutePath());
356         return cmdOut != null && cmdOut.length > 0;
357     }
358 
359     /**
360      * Create a directory inside external storage, and optionally empty it.
361      *
362      * @param dir full path to the dir to be created.
363      * @param empty whether to empty the new dirctory.
364      * @return directory file created
365      */
createDirectory(String dir, boolean empty)366     public File createDirectory(String dir, boolean empty) {
367         File rootDir = Environment.getExternalStorageDirectory();
368         File destDir = new File(rootDir, dir);
369         if (empty) {
370             executeCommandBlocking("rm -rf " + destDir.getAbsolutePath());
371         }
372         if (!fileExists(destDir)) {
373             executeCommandBlocking("mkdir -p " + destDir.getAbsolutePath());
374         }
375         if (!fileExists(destDir)) {
376             Log.e(getTag(), "Unable to create dir: " + destDir.getAbsolutePath());
377             return null;
378         }
379         return destDir;
380     }
381 
382     /**
383      * Create a directory inside external storage, and empty it.
384      *
385      * @param dir full path to the dir to be created.
386      * @return directory file created
387      */
createAndEmptyDirectory(String dir)388     public File createAndEmptyDirectory(String dir) {
389         return createDirectory(dir, true);
390     }
391 
392     /**
393      * Get an OutputStream to a file using the shell.
394      *
395      * This allows tests to write to files without requiring storage permissions, which is in
396      * particular useful when testing apps that should not have the permission.
397      * @param file The file where the OutputStream should write to. Will be deleted if existing.
398      * @return A stream to write to the file.
399      */
getOutputStreamViaShell(File file)400     public OutputStream getOutputStreamViaShell(File file) throws IOException {
401         if (fileExists(file)) {
402             Log.w(getTag(), String.format("File exists: %s", file.getAbsolutePath()));
403             recursiveDelete(file);
404         }
405 
406         final ParcelFileDescriptor[] fds = getInstrumentation().getUiAutomation()
407             .executeShellCommandRw("sh");
408 
409         fds[0].close();
410         final ParcelFileDescriptor stdin = fds[1];
411         final OutputStream os = new ParcelFileDescriptor.AutoCloseOutputStream(stdin);
412 
413         final String cmd = "cat > " + file.getAbsolutePath() + "\n";
414         os.write(cmd.getBytes(StandardCharsets.UTF_8));
415 
416         return os;
417     }
418 
419     /**
420      * Delete a directory and all the files inside.
421      *
422      * @param rootDir the {@link File} directory or file to delete.
423      */
recursiveDelete(File rootDir)424     public void recursiveDelete(File rootDir) {
425         if (rootDir != null) {
426             executeCommandBlocking("rm -r " + rootDir.getAbsolutePath());
427         }
428     }
429 
430     /** Sets whether metrics should be reported directly to instrumentation results. */
setReportAsInstrumentationResults(boolean enabled)431     public final void setReportAsInstrumentationResults(boolean enabled) {
432         mReportAsInstrumentationResults = enabled;
433     }
434 
435     /**
436      * Returns the name of the current class to be used as a logging tag.
437      */
getTag()438     String getTag() {
439         return this.getClass().getName();
440     }
441 
442     /**
443      * Returns the bundle containing the instrumentation arguments.
444      */
getArgsBundle()445     protected final Bundle getArgsBundle() {
446         if (mArgsBundle == null) {
447             mArgsBundle = InstrumentationRegistry.getArguments();
448         }
449         return mArgsBundle;
450     }
451 
parseArguments()452     protected void parseArguments() {
453         Bundle args = getArgsBundle();
454         // First filter the arguments with the alias
455         filterAlias(args);
456         // Handle filtering
457         String includeGroup = args.getString(INCLUDE_FILTER_GROUP_KEY);
458         String excludeGroup = args.getString(EXCLUDE_FILTER_GROUP_KEY);
459         if (includeGroup != null) {
460             mIncludeFilters.addAll(Arrays.asList(includeGroup.split(",")));
461         }
462         if (excludeGroup != null) {
463             mExcludeFilters.addAll(Arrays.asList(excludeGroup.split(",")));
464         }
465         mCollectIterationInterval = Integer.parseInt(args.getString(
466                 COLLECT_ITERATION_INTERVAL, String.valueOf(DEFAULT_COLLECT_INTERVAL)));
467         mSkipMetricUntilIteration = Integer.parseInt(args.getString(
468                 SKIP_METRIC_UNTIL_ITERATION, String.valueOf(SKIP_UNTIL_DEFAULT_ITERATION)));
469 
470         if (mCollectIterationInterval < 1) {
471             Log.i(getTag(), "Metric collection iteration interval cannot be less than 1."
472                     + "Switching to collect for all the iterations.");
473             // Reset to collect for all the iterations.
474             mCollectIterationInterval = 1;
475         }
476         String logOnly = args.getString(ARGUMENT_LOG_ONLY);
477         if (logOnly != null) {
478             mLogOnly = Boolean.parseBoolean(logOnly);
479         }
480     }
481 
482     /**
483      * Filter the alias-ed options from the bundle, each implementation of BaseMetricListener will
484      * have its own list of arguments.
485      * TODO: Split the filtering logic outside the collector class in a utility/helper.
486      */
filterAlias(Bundle bundle)487     private void filterAlias(Bundle bundle) {
488         Set<String> keySet = new HashSet<>(bundle.keySet());
489         OptionClass optionClass = this.getClass().getAnnotation(OptionClass.class);
490         if (optionClass == null) {
491             // No @OptionClass was specified, remove all alias-ed options.
492             for (String key : keySet) {
493                 if (key.indexOf(NAMESPACE_SEPARATOR) != -1) {
494                     bundle.remove(key);
495                 }
496             }
497             return;
498         }
499         // Alias is a required field so if OptionClass is set, alias is set.
500         String alias = optionClass.alias();
501         for (String key : keySet) {
502             if (key.indexOf(NAMESPACE_SEPARATOR) == -1) {
503                 continue;
504             }
505             String optionAlias = key.split(NAMESPACE_SEPARATOR)[0];
506             if (alias.equals(optionAlias)) {
507                 // Place the option again, without alias.
508                 String optionName = key.split(NAMESPACE_SEPARATOR)[1];
509                 bundle.putString(optionName, bundle.getString(key));
510                 bundle.remove(key);
511             } else {
512                 // Remove other aliases.
513                 bundle.remove(key);
514             }
515         }
516     }
517 
518     /**
519      * Helper to decide whether the collector should run or not against the test case.
520      *
521      * @param desc The {@link Description} of the method.
522      * @return True if the collector should run.
523      */
shouldRun(Description desc)524     private boolean shouldRun(Description desc) {
525         if (mLogOnly) {
526             return false;
527         }
528 
529         MetricOption annotation = desc.getAnnotation(MetricOption.class);
530         List<String> groups = new ArrayList<>();
531         if (annotation != null) {
532             String group = annotation.group();
533             groups.addAll(Arrays.asList(group.split(",")));
534         }
535         if (!mExcludeFilters.isEmpty()) {
536             for (String group : groups) {
537                 // Exclude filters has priority, if any of the group is excluded, exclude the method
538                 if (mExcludeFilters.contains(group)) {
539                     return false;
540                 }
541             }
542         }
543         // If we have include filters, we can only run what's part of them.
544         if (!mIncludeFilters.isEmpty()) {
545             for (String group : groups) {
546                 if (mIncludeFilters.contains(group)) {
547                     return true;
548                 }
549             }
550             // We have include filter and did not match them.
551             return false;
552         }
553 
554         // Skip metric collection if current iteration is lesser than or equal to
555         // given skip until iteration count.
556         // mTestIdInvocationCount uses 1 indexing.
557         if (mTestIdInvocationCount.containsKey(desc.toString())
558                 && mTestIdInvocationCount.get(desc.toString()) <= mSkipMetricUntilIteration) {
559             Log.i(getTag(), String.format("Skipping metric collection. Current iteration is %d."
560                     + "Requested to skip metric until %d",
561                     mTestIdInvocationCount.get(desc.toString()),
562                     mSkipMetricUntilIteration));
563             return false;
564         }
565 
566         // Check for iteration interval metric collection criteria.
567         if (mTestIdInvocationCount.containsKey(desc.toString())
568                 && (mTestIdInvocationCount.get(desc.toString()) % mCollectIterationInterval != 0)) {
569             return false;
570         }
571         return true;
572     }
573 }
574