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.util;
17 
18 import com.android.tradefed.invoker.IInvocationContext;
19 import com.android.tradefed.log.LogUtil.CLog;
20 import com.android.tradefed.result.FileInputStreamSource;
21 import com.android.tradefed.result.ILogSaverListener;
22 import com.android.tradefed.result.ITestInvocationListener;
23 import com.android.tradefed.result.InputStreamSource;
24 import com.android.tradefed.result.TestDescription;
25 import com.android.tradefed.util.SubprocessEventHelper.BaseTestEventInfo;
26 import com.android.tradefed.util.SubprocessEventHelper.FailedTestEventInfo;
27 import com.android.tradefed.util.SubprocessEventHelper.InvocationFailedEventInfo;
28 import com.android.tradefed.util.SubprocessEventHelper.InvocationStartedEventInfo;
29 import com.android.tradefed.util.SubprocessEventHelper.LogAssociationEventInfo;
30 import com.android.tradefed.util.SubprocessEventHelper.TestEndedEventInfo;
31 import com.android.tradefed.util.SubprocessEventHelper.TestLogEventInfo;
32 import com.android.tradefed.util.SubprocessEventHelper.TestModuleStartedEventInfo;
33 import com.android.tradefed.util.SubprocessEventHelper.TestRunEndedEventInfo;
34 import com.android.tradefed.util.SubprocessEventHelper.TestRunFailedEventInfo;
35 import com.android.tradefed.util.SubprocessEventHelper.TestRunStartedEventInfo;
36 import com.android.tradefed.util.SubprocessEventHelper.TestStartedEventInfo;
37 import com.android.tradefed.util.proto.TfMetricProtoUtil;
38 
39 import org.json.JSONException;
40 import org.json.JSONObject;
41 
42 import java.io.BufferedReader;
43 import java.io.Closeable;
44 import java.io.File;
45 import java.io.FileNotFoundException;
46 import java.io.FileOutputStream;
47 import java.io.FileReader;
48 import java.io.IOException;
49 import java.io.InputStreamReader;
50 import java.net.ServerSocket;
51 import java.net.Socket;
52 import java.util.ArrayList;
53 import java.util.HashMap;
54 import java.util.Map;
55 import java.util.concurrent.CountDownLatch;
56 import java.util.concurrent.TimeUnit;
57 import java.util.regex.Matcher;
58 import java.util.regex.Pattern;
59 
60 /**
61  * Extends {@link FileOutputStream} to parse the output before writing to the file so we can
62  * generate the test events on the launcher side.
63  */
64 public class SubprocessTestResultsParser implements Closeable {
65 
66     private ITestInvocationListener mListener;
67 
68     private TestDescription mCurrentTest = null;
69     private IInvocationContext mCurrentModuleContext = null;
70 
71     private Pattern mPattern = null;
72     private Map<String, EventHandler> mHandlerMap = null;
73     private EventReceiverThread mEventReceiver = null;
74     private IInvocationContext mContext = null;
75     private Long mStartTime = null;
76 
77     /** Relevant test status keys. */
78     public static class StatusKeys {
79         public static final String INVOCATION_FAILED = "INVOCATION_FAILED";
80         public static final String TEST_ASSUMPTION_FAILURE = "TEST_ASSUMPTION_FAILURE";
81         public static final String TEST_ENDED = "TEST_ENDED";
82         public static final String TEST_FAILED = "TEST_FAILED";
83         public static final String TEST_IGNORED = "TEST_IGNORED";
84         public static final String TEST_STARTED = "TEST_STARTED";
85         public static final String TEST_RUN_ENDED = "TEST_RUN_ENDED";
86         public static final String TEST_RUN_FAILED = "TEST_RUN_FAILED";
87         public static final String TEST_RUN_STARTED = "TEST_RUN_STARTED";
88         public static final String TEST_MODULE_STARTED = "TEST_MODULE_STARTED";
89         public static final String TEST_MODULE_ENDED = "TEST_MODULE_ENDED";
90         public static final String TEST_LOG = "TEST_LOG";
91         public static final String LOG_ASSOCIATION = "LOG_ASSOCIATION";
92         public static final String INVOCATION_STARTED = "INVOCATION_STARTED";
93     }
94 
95     /**
96      * Internal receiver thread class with a socket.
97      */
98     private class EventReceiverThread extends Thread {
99         private ServerSocket mSocket;
100         private CountDownLatch mCountDown;
101 
EventReceiverThread()102         public EventReceiverThread() throws IOException {
103             super("EventReceiverThread");
104             mSocket = new ServerSocket(0);
105             mCountDown = new CountDownLatch(1);
106         }
107 
getLocalPort()108         protected int getLocalPort() {
109             return mSocket.getLocalPort();
110         }
111 
getCountDown()112         protected CountDownLatch getCountDown() {
113             return mCountDown;
114         }
115 
cancel()116         public void cancel() throws IOException {
117             if (mSocket != null) {
118                 mSocket.close();
119             }
120         }
121 
122         @Override
run()123         public void run() {
124             Socket client = null;
125             BufferedReader in = null;
126             try {
127                 client = mSocket.accept();
128                 in = new BufferedReader(new InputStreamReader(client.getInputStream()));
129                 String event = null;
130                 while ((event = in.readLine()) != null) {
131                     try {
132                         CLog.d("received event: '%s'", event);
133                         parse(event);
134                     } catch (JSONException e) {
135                         CLog.e(e);
136                     }
137                 }
138             } catch (IOException e) {
139                 CLog.e(e);
140             } finally {
141                 StreamUtil.close(in);
142                 mCountDown.countDown();
143             }
144             CLog.d("EventReceiverThread done.");
145         }
146     }
147 
148     /**
149      * If the event receiver is being used, ensure that we wait for it to terminate.
150      * @param millis timeout in milliseconds.
151      * @return True if receiver thread terminate before timeout, False otherwise.
152      */
joinReceiver(long millis)153     public boolean joinReceiver(long millis) {
154         if (mEventReceiver != null) {
155             try {
156                 CLog.i("Waiting for events to finish being processed.");
157                 if (!mEventReceiver.getCountDown().await(millis, TimeUnit.MILLISECONDS)) {
158                     CLog.e("Event receiver thread did not complete. Some events may be missing.");
159                     return false;
160                 }
161             } catch (InterruptedException e) {
162                 CLog.e(e);
163                 throw new RuntimeException(e);
164             }
165         }
166         return true;
167     }
168 
169     /**
170      * Returns the socket receiver that was open. -1 if none.
171      */
getSocketServerPort()172     public int getSocketServerPort() {
173         if (mEventReceiver != null) {
174             return mEventReceiver.getLocalPort();
175         }
176         return -1;
177     }
178 
179     @Override
close()180     public void close() throws IOException {
181         if (mEventReceiver != null) {
182             mEventReceiver.cancel();
183         }
184     }
185 
186     /**
187      * Constructor for the result parser
188      *
189      * @param listener {@link ITestInvocationListener} where to report the results
190      * @param streaming if True, a socket receiver will be open to receive results.
191      * @param context a {@link IInvocationContext} information about the invocation
192      */
SubprocessTestResultsParser( ITestInvocationListener listener, boolean streaming, IInvocationContext context)193     public SubprocessTestResultsParser(
194             ITestInvocationListener listener, boolean streaming, IInvocationContext context)
195             throws IOException {
196         this(listener, context);
197         if (streaming) {
198             mEventReceiver = new EventReceiverThread();
199             mEventReceiver.start();
200         }
201     }
202 
203     /**
204      * Constructor for the result parser
205      *
206      * @param listener {@link ITestInvocationListener} where to report the results
207      * @param context a {@link IInvocationContext} information about the invocation
208      */
SubprocessTestResultsParser( ITestInvocationListener listener, IInvocationContext context)209     public SubprocessTestResultsParser(
210             ITestInvocationListener listener, IInvocationContext context) {
211         mListener = listener;
212         mContext = context;
213         StringBuilder sb = new StringBuilder();
214         sb.append(StatusKeys.INVOCATION_FAILED).append("|");
215         sb.append(StatusKeys.TEST_ASSUMPTION_FAILURE).append("|");
216         sb.append(StatusKeys.TEST_ENDED).append("|");
217         sb.append(StatusKeys.TEST_FAILED).append("|");
218         sb.append(StatusKeys.TEST_IGNORED).append("|");
219         sb.append(StatusKeys.TEST_STARTED).append("|");
220         sb.append(StatusKeys.TEST_RUN_ENDED).append("|");
221         sb.append(StatusKeys.TEST_RUN_FAILED).append("|");
222         sb.append(StatusKeys.TEST_RUN_STARTED).append("|");
223         sb.append(StatusKeys.TEST_MODULE_STARTED).append("|");
224         sb.append(StatusKeys.TEST_MODULE_ENDED).append("|");
225         sb.append(StatusKeys.TEST_LOG).append("|");
226         sb.append(StatusKeys.LOG_ASSOCIATION).append("|");
227         sb.append(StatusKeys.INVOCATION_STARTED);
228         String patt = String.format("(.*)(%s)( )(.*)", sb.toString());
229         mPattern = Pattern.compile(patt);
230 
231         // Create Handler map for each event
232         mHandlerMap = new HashMap<String, EventHandler>();
233         mHandlerMap.put(StatusKeys.INVOCATION_FAILED, new InvocationFailedEventHandler());
234         mHandlerMap.put(StatusKeys.TEST_ASSUMPTION_FAILURE,
235                 new TestAssumptionFailureEventHandler());
236         mHandlerMap.put(StatusKeys.TEST_ENDED, new TestEndedEventHandler());
237         mHandlerMap.put(StatusKeys.TEST_FAILED, new TestFailedEventHandler());
238         mHandlerMap.put(StatusKeys.TEST_IGNORED, new TestIgnoredEventHandler());
239         mHandlerMap.put(StatusKeys.TEST_STARTED, new TestStartedEventHandler());
240         mHandlerMap.put(StatusKeys.TEST_RUN_ENDED, new TestRunEndedEventHandler());
241         mHandlerMap.put(StatusKeys.TEST_RUN_FAILED, new TestRunFailedEventHandler());
242         mHandlerMap.put(StatusKeys.TEST_RUN_STARTED, new TestRunStartedEventHandler());
243         mHandlerMap.put(StatusKeys.TEST_MODULE_STARTED, new TestModuleStartedEventHandler());
244         mHandlerMap.put(StatusKeys.TEST_MODULE_ENDED, new TestModuleEndedEventHandler());
245         mHandlerMap.put(StatusKeys.TEST_LOG, new TestLogEventHandler());
246         mHandlerMap.put(StatusKeys.LOG_ASSOCIATION, new LogAssociationEventHandler());
247         mHandlerMap.put(StatusKeys.INVOCATION_STARTED, new InvocationStartedEventHandler());
248     }
249 
parseFile(File file)250     public void parseFile(File file) {
251         BufferedReader reader = null;
252         try {
253             reader = new BufferedReader(new FileReader(file));
254         } catch (FileNotFoundException e) {
255             CLog.e(e);
256             throw new RuntimeException(e);
257         }
258         ArrayList<String> listString = new ArrayList<String>();
259         String line = null;
260         try {
261             while ((line = reader.readLine()) != null) {
262                 listString.add(line);
263             }
264             reader.close();
265         } catch (IOException e) {
266             CLog.e(e);
267             throw new RuntimeException(e);
268         }
269         processNewLines(listString.toArray(new String[listString.size()]));
270     }
271 
272     /**
273      * call parse on each line of the array to extract the events if any.
274      */
processNewLines(String[] lines)275     public void processNewLines(String[] lines) {
276         for (String line : lines) {
277             try {
278                 parse(line);
279             } catch (JSONException e) {
280                 CLog.e("Exception while parsing");
281                 CLog.e(e);
282                 throw new RuntimeException(e);
283             }
284         }
285     }
286 
287     /**
288      * Parse a line, if it matches one of the events, handle it.
289      */
parse(String line)290     private void parse(String line) throws JSONException {
291         Matcher matcher = mPattern.matcher(line);
292         if (matcher.find()) {
293             EventHandler handler = mHandlerMap.get(matcher.group(2));
294             if (handler != null) {
295                 handler.handleEvent(matcher.group(4));
296             } else {
297                 CLog.w("No handler found matching: %s", matcher.group(2));
298             }
299         }
300     }
301 
checkCurrentTestId(String className, String testName)302     private void checkCurrentTestId(String className, String testName) {
303         if (mCurrentTest == null) {
304             mCurrentTest = new TestDescription(className, testName);
305             CLog.w("Calling a test event without having called testStarted.");
306         }
307     }
308 
309     /**
310      * Interface for event handling
311      */
312     interface EventHandler {
handleEvent(String eventJson)313         public void handleEvent(String eventJson) throws JSONException;
314     }
315 
316     private class TestRunStartedEventHandler implements EventHandler {
317         @Override
handleEvent(String eventJson)318         public void handleEvent(String eventJson) throws JSONException {
319             TestRunStartedEventInfo rsi = new TestRunStartedEventInfo(new JSONObject(eventJson));
320             mListener.testRunStarted(rsi.mRunName, rsi.mTestCount);
321         }
322     }
323 
324     private class TestRunFailedEventHandler implements EventHandler {
325         @Override
handleEvent(String eventJson)326         public void handleEvent(String eventJson) throws JSONException {
327             TestRunFailedEventInfo rfi = new TestRunFailedEventInfo(new JSONObject(eventJson));
328             mListener.testRunFailed(rfi.mReason);
329         }
330     }
331 
332     private class TestRunEndedEventHandler implements EventHandler {
333         @Override
handleEvent(String eventJson)334         public void handleEvent(String eventJson) throws JSONException {
335             try {
336                 TestRunEndedEventInfo rei = new TestRunEndedEventInfo(new JSONObject(eventJson));
337                 // TODO: Parse directly as proto.
338                 mListener.testRunEnded(
339                         rei.mTime, TfMetricProtoUtil.upgradeConvert(rei.mRunMetrics));
340             } finally {
341                 mCurrentTest = null;
342             }
343         }
344     }
345 
346     private class InvocationFailedEventHandler implements EventHandler {
347         @Override
handleEvent(String eventJson)348         public void handleEvent(String eventJson) throws JSONException {
349             InvocationFailedEventInfo ifi =
350                     new InvocationFailedEventInfo(new JSONObject(eventJson));
351             mListener.invocationFailed(ifi.mCause);
352         }
353     }
354 
355     private class TestStartedEventHandler implements EventHandler {
356         @Override
handleEvent(String eventJson)357         public void handleEvent(String eventJson) throws JSONException {
358             TestStartedEventInfo bti = new TestStartedEventInfo(new JSONObject(eventJson));
359             mCurrentTest = new TestDescription(bti.mClassName, bti.mTestName);
360             if (bti.mStartTime != null) {
361                 mListener.testStarted(mCurrentTest, bti.mStartTime);
362             } else {
363                 mListener.testStarted(mCurrentTest);
364             }
365         }
366     }
367 
368     private class TestFailedEventHandler implements EventHandler {
369         @Override
handleEvent(String eventJson)370         public void handleEvent(String eventJson) throws JSONException {
371             FailedTestEventInfo fti = new FailedTestEventInfo(new JSONObject(eventJson));
372             checkCurrentTestId(fti.mClassName, fti.mTestName);
373             mListener.testFailed(mCurrentTest, fti.mTrace);
374         }
375     }
376 
377     private class TestEndedEventHandler implements EventHandler {
378         @Override
handleEvent(String eventJson)379         public void handleEvent(String eventJson) throws JSONException {
380             try {
381                 TestEndedEventInfo tei = new TestEndedEventInfo(new JSONObject(eventJson));
382                 checkCurrentTestId(tei.mClassName, tei.mTestName);
383                 if (tei.mEndTime != null) {
384                     mListener.testEnded(
385                             mCurrentTest,
386                             tei.mEndTime,
387                             TfMetricProtoUtil.upgradeConvert(tei.mRunMetrics));
388                 } else {
389                     mListener.testEnded(
390                             mCurrentTest, TfMetricProtoUtil.upgradeConvert(tei.mRunMetrics));
391                 }
392             } finally {
393                 mCurrentTest = null;
394             }
395         }
396     }
397 
398     private class TestIgnoredEventHandler implements EventHandler {
399         @Override
handleEvent(String eventJson)400         public void handleEvent(String eventJson) throws JSONException {
401             BaseTestEventInfo baseTestIgnored = new BaseTestEventInfo(new JSONObject(eventJson));
402             checkCurrentTestId(baseTestIgnored.mClassName, baseTestIgnored.mTestName);
403             mListener.testIgnored(mCurrentTest);
404         }
405     }
406 
407     private class TestAssumptionFailureEventHandler implements EventHandler {
408         @Override
handleEvent(String eventJson)409         public void handleEvent(String eventJson) throws JSONException {
410             FailedTestEventInfo FailedAssumption =
411                     new FailedTestEventInfo(new JSONObject(eventJson));
412             checkCurrentTestId(FailedAssumption.mClassName, FailedAssumption.mTestName);
413             mListener.testAssumptionFailure(mCurrentTest, FailedAssumption.mTrace);
414         }
415     }
416 
417     private class TestModuleStartedEventHandler implements EventHandler {
418         @Override
handleEvent(String eventJson)419         public void handleEvent(String eventJson) throws JSONException {
420             TestModuleStartedEventInfo module =
421                     new TestModuleStartedEventInfo(new JSONObject(eventJson));
422             mCurrentModuleContext = module.mModuleContext;
423             mListener.testModuleStarted(module.mModuleContext);
424         }
425     }
426 
427     private class TestModuleEndedEventHandler implements EventHandler {
428         @Override
handleEvent(String eventJson)429         public void handleEvent(String eventJson) throws JSONException {
430             if (mCurrentModuleContext == null) {
431                 CLog.w("Calling testModuleEnded when testModuleStarted was not called.");
432             }
433             mListener.testModuleEnded();
434             mCurrentModuleContext = null;
435         }
436     }
437 
438     private class TestLogEventHandler implements EventHandler {
439         @Override
handleEvent(String eventJson)440         public void handleEvent(String eventJson) throws JSONException {
441             TestLogEventInfo logInfo = new TestLogEventInfo(new JSONObject(eventJson));
442             String name = String.format("subprocess-%s", logInfo.mDataName);
443             try {
444                 InputStreamSource data = new FileInputStreamSource(logInfo.mDataFile);
445                 mListener.testLog(name, logInfo.mLogType, data);
446             } finally {
447                 FileUtil.deleteFile(logInfo.mDataFile);
448             }
449         }
450     }
451 
452     private class LogAssociationEventHandler implements EventHandler {
453         @Override
handleEvent(String eventJson)454         public void handleEvent(String eventJson) throws JSONException {
455             LogAssociationEventInfo assosInfo =
456                     new LogAssociationEventInfo(new JSONObject(eventJson));
457             if (mListener instanceof ILogSaverListener) {
458                 ((ILogSaverListener) mListener)
459                         .logAssociation(assosInfo.mDataName, assosInfo.mLoggedFile);
460             }
461         }
462     }
463 
464     private class InvocationStartedEventHandler implements EventHandler {
465         @Override
handleEvent(String eventJson)466         public void handleEvent(String eventJson) throws JSONException {
467             InvocationStartedEventInfo eventStart =
468                     new InvocationStartedEventInfo(new JSONObject(eventJson));
469             if (mContext.getTestTag() == null || "stub".equals(mContext.getTestTag())) {
470                 mContext.setTestTag(eventStart.mTestTag);
471             }
472             mStartTime = eventStart.mStartTime;
473         }
474     }
475 
476     /**
477      * Returns the start time associated with the invocation start event from the subprocess
478      * invocation.
479      */
getStartTime()480     public Long getStartTime() {
481         return mStartTime;
482     }
483 
484     /** Returns the test that is currently in progress. */
getCurrentTest()485     public TestDescription getCurrentTest() {
486         return mCurrentTest;
487     }
488 }
489