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.result;
17 
18 import com.android.tradefed.config.Option;
19 import com.android.tradefed.invoker.IInvocationContext;
20 import com.android.tradefed.invoker.logger.InvocationMetricLogger;
21 import com.android.tradefed.log.LogUtil.CLog;
22 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric;
23 import com.android.tradefed.result.retry.ISupportGranularResults;
24 import com.android.tradefed.util.FileUtil;
25 import com.android.tradefed.util.StreamUtil;
26 import com.android.tradefed.util.SubprocessEventHelper.BaseTestEventInfo;
27 import com.android.tradefed.util.SubprocessEventHelper.FailedTestEventInfo;
28 import com.android.tradefed.util.SubprocessEventHelper.InvocationEndedEventInfo;
29 import com.android.tradefed.util.SubprocessEventHelper.InvocationFailedEventInfo;
30 import com.android.tradefed.util.SubprocessEventHelper.InvocationStartedEventInfo;
31 import com.android.tradefed.util.SubprocessEventHelper.LogAssociationEventInfo;
32 import com.android.tradefed.util.SubprocessEventHelper.TestEndedEventInfo;
33 import com.android.tradefed.util.SubprocessEventHelper.TestLogEventInfo;
34 import com.android.tradefed.util.SubprocessEventHelper.TestModuleStartedEventInfo;
35 import com.android.tradefed.util.SubprocessEventHelper.TestRunEndedEventInfo;
36 import com.android.tradefed.util.SubprocessEventHelper.TestRunFailedEventInfo;
37 import com.android.tradefed.util.SubprocessEventHelper.TestRunStartedEventInfo;
38 import com.android.tradefed.util.SubprocessEventHelper.TestStartedEventInfo;
39 import com.android.tradefed.util.SubprocessTestResultsParser;
40 import com.android.tradefed.util.proto.TfMetricProtoUtil;
41 
42 import org.json.JSONObject;
43 
44 import java.io.File;
45 import java.io.FileWriter;
46 import java.io.IOException;
47 import java.io.PrintWriter;
48 import java.net.Socket;
49 import java.util.HashMap;
50 import java.util.Map;
51 
52 /**
53  * Implements {@link ITestInvocationListener} to be specified as a result_reporter and forward from
54  * the subprocess the results of tests, test runs, test invocations.
55  */
56 public class SubprocessResultsReporter
57         implements ITestInvocationListener,
58                 ILogSaverListener,
59                 AutoCloseable,
60                 ISupportGranularResults {
61 
62     @Option(
63             name = "enable-granular-attempts",
64             description = "Whether to allow SubprocessResultsReporter receiving granular attempts.")
65     private boolean mGranularAttempts = true;
66 
67     @Option(name = "subprocess-report-file", description = "the file where to log the events.")
68     private File mReportFile = null;
69 
70     @Option(name = "subprocess-report-port", description = "the port where to connect to send the"
71             + "events.")
72     private Integer mReportPort = null;
73 
74     @Option(name = "output-test-log", description = "Option to report test logs to parent process.")
75     private boolean mOutputTestlog = false;
76 
77     private IInvocationContext mContext = null;
78     private Socket mReportSocket = null;
79     private Object mLock = new Object();
80     private PrintWriter mPrintWriter = null;
81 
82     private boolean mPrintWarning = true;
83     private boolean mCancelled = false;
84 
85     @Override
supportGranularResults()86     public boolean supportGranularResults() {
87         return mGranularAttempts;
88     }
89 
90     /** {@inheritDoc} */
91     @Override
testAssumptionFailure(TestDescription testId, String trace)92     public void testAssumptionFailure(TestDescription testId, String trace) {
93         FailedTestEventInfo info =
94                 new FailedTestEventInfo(testId.getClassName(), testId.getTestName(), trace);
95         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_ASSUMPTION_FAILURE, info);
96     }
97 
98     /** {@inheritDoc} */
99     @Override
testEnded(TestDescription testId, HashMap<String, Metric> metrics)100     public void testEnded(TestDescription testId, HashMap<String, Metric> metrics) {
101         testEnded(testId, System.currentTimeMillis(), metrics);
102     }
103 
104     /** {@inheritDoc} */
105     @Override
testEnded(TestDescription testId, long endTime, HashMap<String, Metric> metrics)106     public void testEnded(TestDescription testId, long endTime, HashMap<String, Metric> metrics) {
107         // TODO: transfer the proto metrics instead of string metrics
108         TestEndedEventInfo info =
109                 new TestEndedEventInfo(
110                         testId.getClassName(),
111                         testId.getTestName(),
112                         endTime,
113                         TfMetricProtoUtil.compatibleConvert(metrics));
114         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_ENDED, info);
115     }
116 
117     /** {@inheritDoc} */
118     @Override
testFailed(TestDescription testId, String reason)119     public void testFailed(TestDescription testId, String reason) {
120         FailedTestEventInfo info =
121                 new FailedTestEventInfo(testId.getClassName(), testId.getTestName(), reason);
122         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_FAILED, info);
123     }
124 
125     /** {@inheritDoc} */
126     @Override
testIgnored(TestDescription testId)127     public void testIgnored(TestDescription testId) {
128         BaseTestEventInfo info = new BaseTestEventInfo(testId.getClassName(), testId.getTestName());
129         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_IGNORED, info);
130     }
131 
132     /** {@inheritDoc} */
133     @Override
testRunEnded(long time, HashMap<String, Metric> runMetrics)134     public void testRunEnded(long time, HashMap<String, Metric> runMetrics) {
135         // TODO: Transfer the full proto instead of just Strings.
136         TestRunEndedEventInfo info =
137                 new TestRunEndedEventInfo(time, TfMetricProtoUtil.compatibleConvert(runMetrics));
138         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_RUN_ENDED, info);
139     }
140 
141     /** {@inheritDoc} */
142     @Override
testRunFailed(String reason)143     public void testRunFailed(String reason) {
144         TestRunFailedEventInfo info = new TestRunFailedEventInfo(reason);
145         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_RUN_FAILED, info);
146     }
147 
148     /** {@inheritDoc} */
149     @Override
testRunFailed(FailureDescription failure)150     public void testRunFailed(FailureDescription failure) {
151         TestRunFailedEventInfo info = new TestRunFailedEventInfo(failure);
152         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_RUN_FAILED, info);
153     }
154 
155     /** {@inheritDoc} */
156     @Override
testRunStarted(String runName, int testCount)157     public void testRunStarted(String runName, int testCount) {
158         testRunStarted(runName, testCount, 0);
159     }
160 
161     /** {@inheritDoc} */
162     @Override
testRunStarted(String runName, int testCount, int attemptNumber)163     public void testRunStarted(String runName, int testCount, int attemptNumber) {
164         testRunStarted(runName, testCount, attemptNumber, System.currentTimeMillis());
165     }
166 
167     /** {@inheritDoc} */
168     @Override
testRunStarted(String runName, int testCount, int attemptNumber, long startTime)169     public void testRunStarted(String runName, int testCount, int attemptNumber, long startTime) {
170         TestRunStartedEventInfo info =
171                 new TestRunStartedEventInfo(runName, testCount, attemptNumber, startTime);
172         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_RUN_STARTED, info);
173     }
174 
175     /**
176      * {@inheritDoc}
177      */
178     @Override
testRunStopped(long arg0)179     public void testRunStopped(long arg0) {
180         // ignore
181     }
182 
183     /** {@inheritDoc} */
184     @Override
testStarted(TestDescription testId)185     public void testStarted(TestDescription testId) {
186         testStarted(testId, System.currentTimeMillis());
187     }
188 
189     /** {@inheritDoc} */
190     @Override
testStarted(TestDescription testId, long startTime)191     public void testStarted(TestDescription testId, long startTime) {
192         TestStartedEventInfo info =
193                 new TestStartedEventInfo(testId.getClassName(), testId.getTestName(), startTime);
194         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_STARTED, info);
195     }
196 
197     /**
198      * {@inheritDoc}
199      */
200     @Override
invocationStarted(IInvocationContext context)201     public void invocationStarted(IInvocationContext context) {
202         InvocationStartedEventInfo info =
203                 new InvocationStartedEventInfo(context.getTestTag(), System.currentTimeMillis());
204         printEvent(SubprocessTestResultsParser.StatusKeys.INVOCATION_STARTED, info);
205         // Save off the context so that we can parse it later during invocation ended.
206         mContext = context;
207     }
208 
209     /** {@inheritDoc} */
210     @Override
testLog(String dataName, LogDataType dataType, InputStreamSource dataStream)211     public void testLog(String dataName, LogDataType dataType, InputStreamSource dataStream) {
212         if (!mOutputTestlog || (mReportPort == null && mReportFile == null)) {
213             return;
214         }
215         if (dataStream != null && dataStream.size() != 0) {
216             File tmpFile = null;
217             try {
218                 // put 'subprocess' in front to identify the files.
219                 tmpFile =
220                         FileUtil.createTempFile(
221                                 "subprocess-" + dataName, "." + dataType.getFileExt());
222                 FileUtil.writeToFile(dataStream.createInputStream(), tmpFile);
223                 TestLogEventInfo info = new TestLogEventInfo(dataName, dataType, tmpFile);
224                 printEvent(SubprocessTestResultsParser.StatusKeys.TEST_LOG, info);
225             } catch (IOException e) {
226                 CLog.e(e);
227                 FileUtil.deleteFile(tmpFile);
228             }
229         }
230     }
231 
232     /** {@inheritDoc} */
233     @Override
logAssociation(String dataName, LogFile logFile)234     public void logAssociation(String dataName, LogFile logFile) {
235         LogAssociationEventInfo info = new LogAssociationEventInfo(dataName, logFile);
236         printEvent(SubprocessTestResultsParser.StatusKeys.LOG_ASSOCIATION, info);
237     }
238 
239     /**
240      * {@inheritDoc}
241      */
242     @Override
invocationEnded(long elapsedTime)243     public void invocationEnded(long elapsedTime) {
244         if (mContext == null) {
245             return;
246         }
247 
248         Map<String, String> metrics = mContext.getAttributes().getUniqueMap();
249         // All the invocation level metrics collected
250         metrics.putAll(InvocationMetricLogger.getInvocationMetrics());
251         InvocationEndedEventInfo eventEnd = new InvocationEndedEventInfo(metrics);
252         printEvent(SubprocessTestResultsParser.StatusKeys.INVOCATION_ENDED, eventEnd);
253         // Upon invocation ended, trigger the end of the socket when the process finishes
254         SocketFinisher thread = new SocketFinisher();
255         Runtime.getRuntime().addShutdownHook(thread);
256     }
257 
258     /**
259      * {@inheritDoc}
260      */
261     @Override
invocationFailed(Throwable cause)262     public void invocationFailed(Throwable cause) {
263         InvocationFailedEventInfo info = new InvocationFailedEventInfo(cause);
264         printEvent(SubprocessTestResultsParser.StatusKeys.INVOCATION_FAILED, info);
265     }
266 
267     /** {@inheritDoc} */
268     @Override
invocationFailed(FailureDescription failure)269     public void invocationFailed(FailureDescription failure) {
270         InvocationFailedEventInfo info = new InvocationFailedEventInfo(failure);
271         printEvent(SubprocessTestResultsParser.StatusKeys.INVOCATION_FAILED, info);
272     }
273 
274     /** {@inheritDoc} */
275     @Override
testModuleStarted(IInvocationContext moduleContext)276     public void testModuleStarted(IInvocationContext moduleContext) {
277         TestModuleStartedEventInfo info = new TestModuleStartedEventInfo(moduleContext);
278         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_MODULE_STARTED, info);
279     }
280 
281     /** {@inheritDoc} */
282     @Override
testModuleEnded()283     public void testModuleEnded() {
284         printEvent(SubprocessTestResultsParser.StatusKeys.TEST_MODULE_ENDED, new JSONObject());
285     }
286 
287     /**
288      * {@inheritDoc}
289      */
290     @Override
getSummary()291     public TestSummary getSummary() {
292         return null;
293     }
294 
295     /**
296      * Helper to print the event key and then the json object.
297      */
printEvent(String key, Object event)298     public void printEvent(String key, Object event) {
299         if (mReportFile != null) {
300             if (mReportFile.canWrite()) {
301                 try {
302                     try (FileWriter fw = new FileWriter(mReportFile, true)) {
303                         String eventLog = String.format("%s %s\n", key, event.toString());
304                         fw.append(eventLog);
305                         fw.flush();
306                     }
307                 } catch (IOException e) {
308                     throw new RuntimeException(e);
309                 }
310             } else {
311                 throw new RuntimeException(
312                         String.format("report file: %s is not writable",
313                                 mReportFile.getAbsolutePath()));
314             }
315         }
316         if(mReportPort != null) {
317             try {
318                 if (mCancelled) {
319                     return;
320                 }
321                 synchronized (mLock) {
322                     if (mReportSocket == null) {
323                         mReportSocket = new Socket("localhost", mReportPort.intValue());
324                         mPrintWriter = new PrintWriter(mReportSocket.getOutputStream(), true);
325                     }
326                     if (!mReportSocket.isConnected()) {
327                         throw new RuntimeException("Reporter Socket is not connected");
328                     }
329                     String eventLog = String.format("%s %s\n", key, event.toString());
330                     mPrintWriter.print(eventLog);
331                     mPrintWriter.flush();
332                 }
333             } catch (IOException e) {
334                 throw new RuntimeException(e);
335             }
336         }
337         if (mReportFile == null && mReportPort == null) {
338             if (mPrintWarning) {
339                 // Only print the warning the first time.
340                 mPrintWarning = false;
341                 CLog.w("No report file or socket has been configured, skipping this reporter.");
342             }
343         }
344     }
345 
346     /** {@inheritDoc} */
347     @Override
close()348     public void close() {
349         mCancelled = true;
350         synchronized (mLock) {
351             if (mPrintWriter != null) {
352                 mPrintWriter.flush();
353             }
354             StreamUtil.close(mPrintWriter);
355             mPrintWriter = null;
356             StreamUtil.close(mReportSocket);
357             mReportSocket = null;
358         }
359     }
360 
361     /** Sets whether or not we should output the test logged or not. */
setOutputTestLog(boolean outputTestLog)362     public void setOutputTestLog(boolean outputTestLog) {
363         mOutputTestlog = outputTestLog;
364     }
365 
366     /** Threads that help terminating the socket. */
367     private class SocketFinisher extends Thread {
368 
SocketFinisher()369         public SocketFinisher() {
370             super();
371             setName("SubprocessResultsReporter-socket-finisher");
372         }
373 
374         @Override
run()375         public void run() {
376             close();
377         }
378     }
379 }
380