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