1 /*
2  * Copyright (C) 2018 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.result;
17 
18 import com.android.loganalysis.item.JavaCrashItem;
19 import com.android.loganalysis.item.LogcatItem;
20 import com.android.loganalysis.parser.LogcatParser;
21 import com.android.tradefed.device.ITestDevice;
22 import com.android.tradefed.log.LogUtil.CLog;
23 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric;
24 import com.android.tradefed.result.error.DeviceErrorIdentifier;
25 import com.android.tradefed.result.proto.TestRecordProto.FailureStatus;
26 import com.android.tradefed.util.StreamUtil;
27 
28 import java.io.IOException;
29 import java.util.ArrayList;
30 import java.util.Arrays;
31 import java.util.HashMap;
32 import java.util.LinkedHashSet;
33 import java.util.List;
34 
35 /**
36  * Special listener: on failures (instrumentation process crashing) it will attempt to extract from
37  * the logcat the crash and adds it to the failure message associated with the test.
38  */
39 public class LogcatCrashResultForwarder extends ResultForwarder {
40 
41     /** Special error message from the instrumentation when something goes wrong on device side. */
42     public static final String ERROR_MESSAGE = "Process crashed.";
43     public static final String SYSTEM_CRASH_MESSAGE = "System has crashed.";
44 
45     public static final int MAX_NUMBER_CRASH = 3;
46 
47     private Long mStartTime = null;
48     private Long mLastStartTime = null;
49     private ITestDevice mDevice;
50     private LogcatItem mLogcatItem = null;
51 
LogcatCrashResultForwarder(ITestDevice device, ITestInvocationListener... listeners)52     public LogcatCrashResultForwarder(ITestDevice device, ITestInvocationListener... listeners) {
53         super(listeners);
54         mDevice = device;
55     }
56 
getDevice()57     public ITestDevice getDevice() {
58         return mDevice;
59     }
60 
61     @Override
testStarted(TestDescription test, long startTime)62     public void testStarted(TestDescription test, long startTime) {
63         mStartTime = startTime;
64         super.testStarted(test, startTime);
65     }
66 
67     @Override
testFailed(TestDescription test, String trace)68     public void testFailed(TestDescription test, String trace) {
69         // If the test case was detected as crashing the instrumentation, we add the crash to it.
70         trace = extractCrashAndAddToMessage(trace, mStartTime);
71         super.testFailed(test, trace);
72     }
73 
74     @Override
testFailed(TestDescription test, FailureDescription failure)75     public void testFailed(TestDescription test, FailureDescription failure) {
76         // If the test case was detected as crashing the instrumentation, we add the crash to it.
77         String trace = extractCrashAndAddToMessage(failure.getErrorMessage(), mStartTime);
78         failure.setErrorMessage(trace);
79         super.testFailed(test, failure);
80     }
81 
82     @Override
testEnded(TestDescription test, long endTime, HashMap<String, Metric> testMetrics)83     public void testEnded(TestDescription test, long endTime, HashMap<String, Metric> testMetrics) {
84         super.testEnded(test, endTime, testMetrics);
85         mLastStartTime = mStartTime;
86         mStartTime = null;
87     }
88 
89     @Override
testRunFailed(String errorMessage)90     public void testRunFailed(String errorMessage) {
91         testRunFailed(FailureDescription.create(errorMessage, FailureStatus.TEST_FAILURE));
92     }
93 
94     @Override
testRunFailed(FailureDescription error)95     public void testRunFailed(FailureDescription error) {
96         // Also add the failure to the run failure if the testFailed generated it.
97         // A Process crash would end the instrumentation, so a testRunFailed is probably going to
98         // be raised for the same reason.
99         String errorMessage = error.getErrorMessage();
100         if (mLogcatItem != null) {
101             errorMessage = addJavaCrashToString(mLogcatItem, errorMessage);
102             mLogcatItem = null;
103         } else {
104             errorMessage = extractCrashAndAddToMessage(errorMessage, mLastStartTime);
105         }
106         error.setErrorMessage(errorMessage);
107         if (isCrash(errorMessage)) {
108             error.setErrorIdentifier(DeviceErrorIdentifier.INSTRUMENATION_CRASH);
109         }
110         super.testRunFailed(error);
111     }
112 
113     @Override
testRunEnded(long elapsedTime, HashMap<String, Metric> runMetrics)114     public void testRunEnded(long elapsedTime, HashMap<String, Metric> runMetrics) {
115         super.testRunEnded(elapsedTime, runMetrics);
116         mLastStartTime = null;
117     }
118 
119     /** Attempt to extract the crash from the logcat if the test was seen as started. */
extractCrashAndAddToMessage(String errorMessage, Long startTime)120     private String extractCrashAndAddToMessage(String errorMessage, Long startTime) {
121         if (isCrash(errorMessage) && startTime != null) {
122             mLogcatItem = extractLogcat(mDevice, startTime);
123             errorMessage = addJavaCrashToString(mLogcatItem, errorMessage);
124         }
125         return errorMessage;
126     }
127 
isCrash(String errorMessage)128     private boolean isCrash(String errorMessage) {
129         return errorMessage.contains(ERROR_MESSAGE) || errorMessage.contains(SYSTEM_CRASH_MESSAGE);
130     }
131 
132     /**
133      * Extract a formatted object from the logcat snippet.
134      *
135      * @param device The device from which to pull the logcat.
136      * @param startTime The beginning time of the last tests.
137      * @return A {@link LogcatItem} that contains the information inside the logcat.
138      */
extractLogcat(ITestDevice device, long startTime)139     private LogcatItem extractLogcat(ITestDevice device, long startTime) {
140         try (InputStreamSource logSource = device.getLogcatSince(startTime)) {
141             if (logSource.size() == 0L) {
142                 return null;
143             }
144             String message = StreamUtil.getStringFromStream(logSource.createInputStream());
145             LogcatParser parser = new LogcatParser();
146             List<String> lines = Arrays.asList(message.split("\n"));
147             return parser.parse(lines);
148         } catch (IOException e) {
149             CLog.e(e);
150         }
151         return null;
152     }
153 
154     /** Append the Java crash information to the failure message. */
addJavaCrashToString(LogcatItem item, String errorMsg)155     private String addJavaCrashToString(LogcatItem item, String errorMsg) {
156         if (item == null) {
157             return errorMsg;
158         }
159         List<String> crashes = dedupCrash(item.getJavaCrashes());
160         int displayed = Math.min(crashes.size(), MAX_NUMBER_CRASH);
161         for (int i = 0; i < displayed; i++) {
162             errorMsg = String.format("%s\nCrash Message:%s\n", errorMsg, crashes.get(i));
163         }
164         return errorMsg;
165     }
166 
167     /** Remove identical crash from the list of errors. */
dedupCrash(List<JavaCrashItem> origList)168     private List<String> dedupCrash(List<JavaCrashItem> origList) {
169         LinkedHashSet<String> dedupList = new LinkedHashSet<>();
170         for (JavaCrashItem item : origList) {
171             dedupList.add(String.format("%s\n%s", item.getMessage(), item.getStack()));
172         }
173         return new ArrayList<>(dedupList);
174     }
175 }
176