1 /*
2  * Copyright (C) 2016 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 com.android.tradefed.testtype.suite;
17 
18 import com.android.tradefed.device.DeviceNotAvailableException;
19 import com.android.tradefed.device.ITestDevice;
20 import com.android.tradefed.log.ITestLogger;
21 import com.android.tradefed.log.LogUtil.CLog;
22 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric;
23 import com.android.tradefed.result.ITestInvocationListener;
24 import com.android.tradefed.result.InputStreamSource;
25 import com.android.tradefed.result.LogDataType;
26 import com.android.tradefed.result.TestDescription;
27 import com.android.tradefed.util.IRunUtil;
28 import com.android.tradefed.util.RunUtil;
29 
30 import com.google.common.annotations.VisibleForTesting;
31 
32 import java.util.ArrayList;
33 import java.util.HashMap;
34 import java.util.List;
35 import java.util.Map;
36 
37 /**
38  * Listener used to take action such as screenshot, bugreport, logcat collection upon a test failure
39  * when requested.
40  */
41 public class TestFailureListener implements ITestInvocationListener {
42 
43     private static final int DEFAULT_MAX_LOGCAT_BYTES = 500 * 1024; // 500K
44     /* Arbitrary upper limit for mMaxLogcatBytes to avoid un-reasonably high limit */
45     private static final int LOGCAT_BYTE_LIMIT = 20 * 1024 * 1024; // 20 MB
46     private static final String LOGCAT_ON_FAILURE_SIZE_OPTION = "logcat-on-failure-size";
47     private static final long LOGCAT_CAPTURE_TIMEOUT = 2 * 60 * 1000;
48 
49     private List<ITestDevice> mListDevice;
50     private ITestLogger mLogger;
51     // Settings for the whole invocation
52     private boolean mBugReportOnFailure;
53     private boolean mLogcatOnFailure;
54     private boolean mScreenshotOnFailure;
55     private boolean mRebootOnFailure;
56 
57     // module specific values
58     private boolean mModuleBugReportOnFailure = true;
59     private boolean mModuleLogcatOnFailure = true;
60     private boolean mModuleScreenshotOnFailure = true;
61 
62     private int mMaxLogcatBytes;
63     private Map<TestDescription, Long> mTrackStartTime = new HashMap<>();
64     private List<Thread> mLogcatThreads = new ArrayList<>();
65 
TestFailureListener( List<ITestDevice> devices, boolean bugReportOnFailure, boolean logcatOnFailure, boolean screenshotOnFailure, boolean rebootOnFailure, int maxLogcatBytes)66     public TestFailureListener(
67             List<ITestDevice> devices,
68             boolean bugReportOnFailure,
69             boolean logcatOnFailure,
70             boolean screenshotOnFailure,
71             boolean rebootOnFailure,
72             int maxLogcatBytes) {
73         mListDevice = devices;
74         mBugReportOnFailure = bugReportOnFailure;
75         mLogcatOnFailure = logcatOnFailure;
76         mScreenshotOnFailure = screenshotOnFailure;
77         mRebootOnFailure = rebootOnFailure;
78         if (maxLogcatBytes < 0 ) {
79             CLog.w("FailureListener could not set %s to '%d', using default value %d",
80                     LOGCAT_ON_FAILURE_SIZE_OPTION, maxLogcatBytes,
81                     DEFAULT_MAX_LOGCAT_BYTES);
82             mMaxLogcatBytes = DEFAULT_MAX_LOGCAT_BYTES;
83         } else if (maxLogcatBytes > LOGCAT_BYTE_LIMIT) {
84             CLog.w("Value %d for %s exceeds limit %d, using limit value", maxLogcatBytes,
85                     LOGCAT_ON_FAILURE_SIZE_OPTION, LOGCAT_BYTE_LIMIT);
86             mMaxLogcatBytes = LOGCAT_BYTE_LIMIT;
87         } else {
88             mMaxLogcatBytes = maxLogcatBytes;
89         }
90     }
91 
92     /** We override testStarted in order to track the start time. */
93     @Override
testStarted(TestDescription test)94     public void testStarted(TestDescription test) {
95         if (mLogcatOnFailure) {
96             try {
97                 mTrackStartTime.put(test, mListDevice.get(0).getDeviceDate());
98             } catch (DeviceNotAvailableException e) {
99                 CLog.e(e);
100                 // we fall back to logcat dump on null.
101                 mTrackStartTime.put(test, null);
102             }
103         }
104     }
105 
106     /** Make sure we clean the map when test end to avoid too much overhead. */
107     @Override
testEnded(TestDescription test, HashMap<String, Metric> testMetrics)108     public void testEnded(TestDescription test, HashMap<String, Metric> testMetrics) {
109         if (mLogcatOnFailure) {
110             mTrackStartTime.remove(test);
111         }
112     }
113 
114     /** {@inheritDoc} */
115     @Override
testFailed(TestDescription test, String trace)116     public void testFailed(TestDescription test, String trace) {
117         CLog.i("FailureListener.testFailed %s %b %b %b", test.toString(), mBugReportOnFailure,
118                 mLogcatOnFailure, mScreenshotOnFailure);
119         for (ITestDevice device : mListDevice) {
120             captureFailure(device, test);
121         }
122     }
123 
124     /** Capture the appropriate logs for one device for one test failure. */
captureFailure(ITestDevice device, TestDescription test)125     private void captureFailure(ITestDevice device, TestDescription test) {
126         String serial = device.getSerialNumber();
127         if (mScreenshotOnFailure && mModuleScreenshotOnFailure) {
128             try {
129                 try (InputStreamSource screenSource = device.getScreenshot()) {
130                     testLogForward(
131                             String.format("%s-%s-screenshot", test.toString(), serial),
132                             LogDataType.PNG,
133                             screenSource);
134                 }
135             } catch (DeviceNotAvailableException e) {
136                 CLog.e(e);
137                 CLog.e("Device %s became unavailable while capturing screenshot", serial);
138             }
139         }
140         if (mBugReportOnFailure && mModuleBugReportOnFailure) {
141             if (!device.logBugreport(
142                     String.format("%s-%s-bugreport", test.toString(), serial), mLogger)) {
143                 CLog.e("Failed to capture bugreport for %s failure on %s.", test, serial);
144             }
145         }
146         if (mLogcatOnFailure && mModuleLogcatOnFailure) {
147             Runnable captureLogcat =
148                     new Runnable() {
149                         @Override
150                         public void run() {
151                             Long startTime = mTrackStartTime.remove(test);
152                             if (startTime != null) {
153                                 try (InputStreamSource logSource =
154                                         device.getLogcatSince(startTime)) {
155                                     testLogForward(
156                                             String.format("%s-%s-logcat", test.toString(), serial),
157                                             LogDataType.LOGCAT,
158                                             logSource);
159                                 }
160                             } else {
161                                 // sleep 2s to ensure test failure stack trace makes it into the
162                                 // logcat capture
163                                 getRunUtil().sleep(2 * 1000);
164                                 try (InputStreamSource logSource =
165                                         device.getLogcat(mMaxLogcatBytes)) {
166                                     testLogForward(
167                                             String.format("%s-%s-logcat", test.toString(), serial),
168                                             LogDataType.LOGCAT,
169                                             logSource);
170                                 }
171                             }
172                         }
173                     };
174             if (mRebootOnFailure) {
175                 captureLogcat.run();
176             } else {
177                 // If no reboot will be done afterward capture asynchronously the logcat.
178                 Thread captureThread =
179                         new Thread(captureLogcat, String.format("Capture failure logcat %s", test));
180                 captureThread.setDaemon(true);
181                 mLogcatThreads.add(captureThread);
182                 captureThread.start();
183             }
184         }
185         if (mRebootOnFailure) {
186             try {
187                 // Rebooting on all failures can hide legitimate issues and platform instabilities,
188                 // therefore only allowed on "user-debug" and "eng" builds.
189                 if ("user".equals(device.getProperty("ro.build.type"))) {
190                     CLog.e("Reboot-on-failure should only be used during development," +
191                             " this is a\" user\" build device");
192                 } else {
193                     device.reboot();
194                 }
195             } catch (DeviceNotAvailableException e) {
196                 CLog.e(e);
197                 CLog.e("Device %s became unavailable while rebooting", serial);
198             }
199         }
200     }
201 
202     /** Join on all the logcat capturing threads to ensure they terminate. */
join()203     public void join() {
204         // Reset the module config to use the invocation settings by default.
205         mModuleBugReportOnFailure = true;
206         mModuleLogcatOnFailure = true;
207         mModuleScreenshotOnFailure = true;
208         synchronized (mLogcatThreads) {
209             for (Thread t : mLogcatThreads) {
210                 if (!t.isAlive()) {
211                     continue;
212                 }
213                 try {
214                     t.join(LOGCAT_CAPTURE_TIMEOUT);
215                 } catch (InterruptedException e) {
216                     CLog.e(e);
217                 }
218             }
219             mLogcatThreads.clear();
220         }
221     }
222 
223     /**
224      * Forward the log to the logger, do not do it from whitin the #testLog callback as if
225      * TestFailureListener is part of the chain, it will results in an infinite loop.
226      */
testLogForward( String dataName, LogDataType dataType, InputStreamSource dataStream)227     public void testLogForward(
228             String dataName, LogDataType dataType, InputStreamSource dataStream) {
229         mLogger.testLog(dataName, dataType, dataStream);
230     }
231 
232     @Override
testLog(String dataName, LogDataType dataType, InputStreamSource dataStream)233     public void testLog(String dataName, LogDataType dataType, InputStreamSource dataStream) {
234         // Explicitly do nothing on testLog
235     }
236 
237     /**
238      * Get the default {@link IRunUtil} instance
239      */
240     @VisibleForTesting
getRunUtil()241     IRunUtil getRunUtil() {
242         return RunUtil.getDefault();
243     }
244 
245     /**
246      * Allows to override the invocation settings of capture on failure by the module specific
247      * configurations.
248      *
249      * @param bugreportOnFailure true to capture a bugreport on test failure. False otherwise.
250      * @param logcatOnfailure true to capture a logcat on test failure. False otherwise.
251      * @param screenshotOnFailure true to capture a screenshot on failure. False otherwise.
252      */
applyModuleConfiguration( boolean bugreportOnFailure, boolean logcatOnfailure, boolean screenshotOnFailure)253     public void applyModuleConfiguration(
254             boolean bugreportOnFailure, boolean logcatOnfailure, boolean screenshotOnFailure) {
255         mModuleBugReportOnFailure = bugreportOnFailure;
256         mModuleLogcatOnFailure = logcatOnfailure;
257         mModuleScreenshotOnFailure = screenshotOnFailure;
258     }
259 
260     /** Sets where the logs should be saved. */
setLogger(ITestLogger logger)261     public void setLogger(ITestLogger logger) {
262         mLogger = logger;
263     }
264 }
265