• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2010 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;
17 
18 import com.android.ddmlib.IShellOutputReceiver;
19 import com.android.ddmlib.MultiLineReceiver;
20 import com.android.tradefed.log.LogUtil.CLog;
21 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric;
22 import com.android.tradefed.result.ITestInvocationListener;
23 import com.android.tradefed.result.TestDescription;
24 
25 import com.google.common.base.Joiner;
26 
27 import java.util.ArrayList;
28 import java.util.Arrays;
29 import java.util.Collection;
30 import java.util.HashMap;
31 import java.util.List;
32 import java.util.Map;
33 import java.util.regex.Matcher;
34 import java.util.regex.Pattern;
35 
36 /**
37  * Parses the 'raw output mode' results of native tests using GTest that run from shell, and informs
38  * a ITestInvocationListener of the results.
39  *
40  * <p>Sample format of output expected:
41  *
42  * <pre>
43  * [==========] Running 15 tests from 1 test case.
44  * [----------] Global test environment set-up.
45  * [----------] 15 tests from MessageTest
46  * [ RUN      ] MessageTest.DefaultConstructor
47  * [       OK ] MessageTest.DefaultConstructor (1 ms)
48  * [ RUN      ] MessageTest.CopyConstructor
49  * external/gtest/test/gtest-message_test.cc:67: Failure
50  * Value of: 5
51  * Expected: 2
52  * external/gtest/test/gtest-message_test.cc:68: Failure
53  * Value of: 1 == 1
54  * Actual: true
55  * Expected: false
56  * [  FAILED  ] MessageTest.CopyConstructor (2 ms)
57  *  ...
58  * [ RUN      ] MessageTest.DoesNotTakeUpMuchStackSpace
59  * [       OK ] MessageTest.DoesNotTakeUpMuchStackSpace (0 ms)
60  * [----------] 15 tests from MessageTest (26 ms total)
61  *
62  * [----------] Global test environment tear-down
63  * [==========] 15 tests from 1 test case ran. (26 ms total)
64  * [  PASSED  ] 6 tests.
65  * [  FAILED  ] 9 tests, listed below:
66  * [  FAILED  ] MessageTest.CopyConstructor
67  * [  FAILED  ] MessageTest.ConstructsFromCString
68  * [  FAILED  ] MessageTest.StreamsCString
69  * [  FAILED  ] MessageTest.StreamsNullCString
70  * [  FAILED  ] MessageTest.StreamsString
71  * [  FAILED  ] MessageTest.StreamsStringWithEmbeddedNUL
72  * [  FAILED  ] MessageTest.StreamsNULChar
73  * [  FAILED  ] MessageTest.StreamsInt
74  * [  FAILED  ] MessageTest.StreamsBasicIoManip
75  * 9 FAILED TESTS
76  * </pre>
77  *
78  * <p>where the following tags are used to signal certain events:
79  *
80  * <pre>
81  * [==========]: the first occurrence indicates a new run started, including the number of tests
82  *                  to be expected in this run
83  * [ RUN      ]: indicates a new test has started to run; a series of zero or more lines may
84  *                  follow a test start, and will be captured in case of a test failure or error
85  * [       OK ]: the preceding test has completed successfully, optionally including the time it
86  *                  took to run (in ms)
87  * [  FAILED  ]: the preceding test has failed, optionally including the time it took to run (in ms)
88  * [==========]: the preceding test run has completed, optionally including the time it took to run
89  *                  (in ms)
90  * </pre>
91  *
92  * All other lines are ignored.
93  */
94 public class GTestResultParser extends MultiLineReceiver {
95     // Variables to keep track of state
96     private TestResult mCurrentTestResult = null;
97     private int mNumTestsRun = 0;
98     private int mNumTestsExpected = 0;
99     private long mTotalRunTime = 0;
100     private boolean mTestInProgress = false;
101     private boolean mTestRunInProgress = false;
102     private final String mTestRunName;
103     private final Collection<ITestInvocationListener> mTestListeners;
104 
105     /** True if start of test has already been reported to listener. */
106     private boolean mTestRunStartReported = false;
107 
108     /** True if at least one testRunStart has been reported. */
109     private boolean mSeenOneTestRunStart = false;
110     /**
111      * Track all the log lines before the testRunStart is made, it is helpful on an early failure to
112      * report those logs.
113      */
114     private List<String> mTrackLogsBeforeRunStart = new ArrayList<>();
115 
116     /** True if current test run has been canceled by user. */
117     private boolean mIsCancelled = false;
118 
119     /** Whether or not to prepend filename to classname. */
120     private boolean mPrependFileName = false;
121 
122     /** The final status of the test. */
123     enum TestStatus {
124         OK,
125         FAILED,
126         SKIPPED
127     }
128 
setPrependFileName(boolean prepend)129     public void setPrependFileName(boolean prepend) {
130         mPrependFileName = prepend;
131     }
132 
getPrependFileName()133     public boolean getPrependFileName() {
134         return mPrependFileName;
135     }
136 
137     /**
138      * Test result data
139      */
140     private static class TestResult {
141         private String mTestName = null;
142         private String mTestClass = null;
143         private StringBuilder mStackTrace = null;
144         @SuppressWarnings("unused")
145         private Long mRunTime = null;
146 
147         /** Returns whether expected values have been parsed
148          *
149          * @return true if all expected values have been parsed
150          */
isComplete()151         boolean isComplete() {
152             return mTestName != null && mTestClass != null;
153         }
154 
155         /** Returns whether there is currently a stack trace
156          *
157          * @return true if there is currently a stack trace, false otherwise
158          */
hasStackTrace()159         boolean hasStackTrace() {
160             return mStackTrace != null;
161         }
162 
163         /**
164          * Returns the stack trace of the current test.
165          *
166          * @return a String representation of the current test's stack trace; if there is not
167          * a current stack trace, it returns an error string. Use {@link TestResult#hasStackTrace}
168          * if you need to know whether there is a stack trace.
169          */
getTrace()170         String getTrace() {
171             if (hasStackTrace()) {
172                 return mStackTrace.toString();
173             } else {
174                 CLog.e("Could not find stack trace for failed test");
175                 return new Throwable("Unknown failure").toString();
176             }
177         }
178 
179         /** Provides a more user readable string for TestResult, if possible */
180         @Override
toString()181         public String toString() {
182             StringBuilder output = new StringBuilder();
183             if (mTestClass != null ) {
184                 output.append(mTestClass);
185                 output.append('#');
186             }
187             if (mTestName != null) {
188                 output.append(mTestName);
189             }
190             if (output.length() > 0) {
191                 return output.toString();
192             }
193             return "unknown result";
194         }
195     }
196 
197     /** Internal helper struct to store parsed test info. */
198     private static class ParsedTestInfo {
199         String mTestName = null;
200         String mTestClassName = null;
201         String mTestRunTime = null;
202 
ParsedTestInfo(String testName, String testClassName, String testRunTime)203         public ParsedTestInfo(String testName, String testClassName, String testRunTime) {
204             mTestName = testName;
205             mTestClassName = testClassName;
206             mTestRunTime = testRunTime;
207         }
208     }
209 
210     /** Prefixes used to demarcate and identify output. */
211     private static class Prefixes {
212         @SuppressWarnings("unused")
213         private static final String INFORMATIONAL_MARKER = "[----------]";
214         private static final String START_TEST_RUN_MARKER = "[==========] Running";
215         private static final String TEST_RUN_MARKER = "[==========]";
216         private static final String START_TEST_MARKER = "[ RUN      ]"; // GTest format
217         private static final String OK_TEST_MARKER = "[       OK ]"; // GTest format
218         private static final String SKIPPED_TEST_MARKER = "[  SKIPPED ]"; // GTest format
219         private static final String FAILED_TEST_MARKER = "[  FAILED  ]";
220         // Alternative non GTest format can be generated from Google Test AOSP and respond to
221         // different needs (parallelism of tests) that the GTest format can't describe well.
222         private static final String ALT_OK_MARKER = "[    OK    ]"; // Non GTest format
223         private static final String TIMEOUT_MARKER = "[ TIMEOUT  ]"; // Non GTest format
224     }
225 
226     /**
227      * Creates the GTestResultParser.
228      *
229      * @param testRunName the test run name to provide to {@link
230      *     ITestInvocationListener#testRunStarted(String, int)}
231      * @param listeners informed of test results as the tests are executing
232      */
GTestResultParser(String testRunName, Collection<ITestInvocationListener> listeners)233     public GTestResultParser(String testRunName, Collection<ITestInvocationListener> listeners) {
234         mTestRunName = testRunName;
235         mTestListeners = new ArrayList<>(listeners);
236     }
237 
238     /**
239      * Creates the GTestResultParser for a single listener.
240      *
241      * @param testRunName the test run name to provide to {@link
242      *     ITestInvocationListener#testRunStarted(String, int)}
243      * @param listener informed of test results as the tests are executing
244      */
GTestResultParser(String testRunName, ITestInvocationListener listener)245     public GTestResultParser(String testRunName, ITestInvocationListener listener) {
246         mTestRunName = testRunName;
247         mTestListeners = new ArrayList<>(1);
248         mTestListeners.add(listener);
249     }
250 
251     /**
252      * Returns the current TestResult for test in progress, or a new default one.
253      *
254      * @return The TestResult for the current test run
255      */
getCurrentTestResult()256     private TestResult getCurrentTestResult() {
257         if (mCurrentTestResult == null) {
258             mCurrentTestResult = new TestResult();
259         }
260         return mCurrentTestResult;
261     }
262 
263 
264     /**
265      * Clears out the current TestResult.
266      */
clearCurrentTestResult()267     private void clearCurrentTestResult() {
268         mCurrentTestResult = null;
269     }
270 
271     /**
272      * {@inheritDoc}
273      */
274     @Override
processNewLines(String[] lines)275     public void processNewLines(String[] lines) {
276         if (!mSeenOneTestRunStart) {
277             mTrackLogsBeforeRunStart.addAll(Arrays.asList(lines));
278         }
279 
280         for (String line : lines) {
281             parse(line);
282             // in verbose mode, dump all adb output to log
283             CLog.v(line);
284         }
285     }
286 
287     /**
288      * Parse an individual output line.
289      *
290      * @param line  Text output line
291      */
parse(String line)292     private void parse(String line) {
293         String message = null;
294 
295         if (mTestRunInProgress || line.startsWith(Prefixes.TEST_RUN_MARKER)) {
296             if (line.startsWith(Prefixes.START_TEST_MARKER)) {
297                 // Individual test started
298                 message = line.substring(Prefixes.START_TEST_MARKER.length()).trim();
299                 processTestStartedTag(message);
300             } else if (line.contains(Prefixes.SKIPPED_TEST_MARKER)) {
301                 // Individual test was skipped.
302                 // Logs from test could offset the SKIPPED marker
303                 message =
304                         line.substring(
305                                         line.indexOf(Prefixes.SKIPPED_TEST_MARKER)
306                                                 + Prefixes.SKIPPED_TEST_MARKER.length())
307                                 .trim();
308                 if (!testInProgress()) {
309                     // Alternative format does not have a RUN tag, so we fake it.
310                     fakeRunMarker(message);
311                 }
312                 processSkippedTag(message);
313                 clearCurrentTestResult();
314             }
315             else if (line.contains(Prefixes.OK_TEST_MARKER)) {
316                 // Individual test completed successfully
317                 // Logs from test could offset the OK marker
318                 message = line.substring(line.indexOf(Prefixes.OK_TEST_MARKER) +
319                         Prefixes.OK_TEST_MARKER.length()).trim();
320                 if (!testInProgress()) {
321                     // If we are missing the RUN tag, skip it wrong format
322                     CLog.e("Found %s without %s before, Ensure you are using GTest format",
323                             line, Prefixes.START_TEST_MARKER);
324                     return;
325                 }
326                 processOKTag(message);
327                 clearCurrentTestResult();
328             }
329             else if (line.contains(Prefixes.ALT_OK_MARKER)) {
330                 message = line.substring(line.indexOf(Prefixes.ALT_OK_MARKER) +
331                         Prefixes.ALT_OK_MARKER.length()).trim();
332                 // This alternative format does not have a RUN tag, so we fake it.
333                 fakeRunMarker(message);
334                 processOKTag(message);
335                 clearCurrentTestResult();
336             }
337             else if (line.contains(Prefixes.FAILED_TEST_MARKER)) {
338                 // Individual test completed with failure
339                 message = line.substring(line.indexOf(Prefixes.FAILED_TEST_MARKER) +
340                         Prefixes.FAILED_TEST_MARKER.length()).trim();
341                 if (!testInProgress()) {
342                     // If we are missing the RUN tag (ALT format)
343                     fakeRunMarker(message);
344                 }
345                 processFailedTag(message);
346                 clearCurrentTestResult();
347             }
348             else if (line.contains(Prefixes.TIMEOUT_MARKER)) {
349                 // Individual test timeout is considered a failure
350                 message = line.substring(line.indexOf(Prefixes.TIMEOUT_MARKER) +
351                         Prefixes.TIMEOUT_MARKER.length()).trim();
352                 fakeRunMarker(message);
353                 processFailedTag(message);
354                 clearCurrentTestResult();
355             }
356             else if (line.startsWith(Prefixes.START_TEST_RUN_MARKER)) {
357                 // Test run started
358                 // Make sure to leave the "Running" in the string
359                 message = line.substring(Prefixes.TEST_RUN_MARKER.length()).trim();
360                 processRunStartedTag(message);
361             }
362             else if (line.startsWith(Prefixes.TEST_RUN_MARKER)) {
363                 // Test run ended
364                 // This is for the end of the test suite run, so make sure this else-if is after the
365                 // check for START_TEST_SUITE_MARKER
366                 message = line.substring(Prefixes.TEST_RUN_MARKER.length()).trim();
367                 processRunCompletedTag(message);
368             }
369             else if (testInProgress()) {
370                 // Note this does not handle the case of an error outside an actual test run
371                 appendTestOutputLine(line);
372             }
373         }
374     }
375 
376     /**
377      * Returns true if test run canceled.
378      *
379      * @see IShellOutputReceiver#isCancelled()
380      */
381     @Override
isCancelled()382     public boolean isCancelled() {
383         return mIsCancelled;
384     }
385 
386     /**
387      * Create a fake run marker for alternative format that doesn't have it.
388      * @param message
389      */
fakeRunMarker(String message)390     private void fakeRunMarker(String message) {
391         // Remove everything after the test name.
392         String fakeRunMaker = message.split(" +")[0];
393         // Do as if we had found a [RUN] tag.
394         processTestStartedTag(fakeRunMaker);
395     }
396 
397     /**
398      * Requests cancellation of test run.
399      */
cancel()400     public void cancel() {
401         mIsCancelled = true;
402     }
403 
404     /**
405      * Returns whether we're in the middle of running a test.
406      *
407      * @return True if a test was started, false otherwise
408      */
testInProgress()409     private boolean testInProgress() {
410         return mTestInProgress;
411     }
412 
413     /**
414      * Set state to indicate we've started running a test.
415      *
416      */
setTestStarted()417     private void setTestStarted() {
418         mTestInProgress = true;
419     }
420 
421     /**
422      * Set state to indicate we've started running a test.
423      *
424      */
setTestEnded()425     private void setTestEnded() {
426         mTestInProgress = false;
427     }
428 
429     /**
430      * Reports the start of a test run, and the total test count, if it has not been previously
431      * reported.
432      */
reportTestRunStarted()433     private void reportTestRunStarted() {
434         // if start test run not reported yet
435         if (!mTestRunStartReported) {
436             for (ITestInvocationListener listener : mTestListeners) {
437                 listener.testRunStarted(mTestRunName, mNumTestsExpected);
438             }
439             mTestRunStartReported = true;
440             mSeenOneTestRunStart = true;
441         }
442     }
443 
444     /**
445      * Reports the end of a test run, and resets that test
446      */
reportTestRunEnded()447     private void reportTestRunEnded() {
448         for (ITestInvocationListener listener : mTestListeners) {
449             listener.testRunEnded(mTotalRunTime, getRunMetrics());
450         }
451         mTestRunStartReported = false;
452     }
453 
454     /**
455      * Create the run metrics {@link Map} to report.
456      *
457      * @return a {@link Map} of run metrics data
458      */
getRunMetrics()459     private HashMap<String, Metric> getRunMetrics() {
460         HashMap<String, Metric> metricsMap = new HashMap<>();
461         return metricsMap;
462     }
463 
464     /**
465      * Parse the test identifier (class and test name), and optional time info.
466      *
467      * @param identifier Raw identifier of the form classname.testname, with an optional time
468      *          element in the format of (XX ms) at the end
469      * @return A ParsedTestInfo representing the parsed info from the identifier string.
470      *
471      *          If no time tag was detected, then the third element in the array (time_in_ms) will
472      *          be null. If the line failed to parse properly (eg: could not determine name of
473      *          test/class) then an "UNKNOWN" string value will be returned for the classname and
474      *          testname. This method guarantees a string will always be returned for the class and
475      *          test names (but not for the time value).
476      */
parseTestDescription(String identifier)477     private ParsedTestInfo parseTestDescription(String identifier) {
478         ParsedTestInfo returnInfo = new ParsedTestInfo("UNKNOWN_CLASS", "UNKNOWN_TEST", null);
479 
480         Pattern timePattern = Pattern.compile(".*(\\((\\d+) ms\\))");  // eg: (XX ms)
481         Matcher time = timePattern.matcher(identifier);
482 
483         // Try to find a time
484         if (time.find()) {
485             String timeString = time.group(2);  // the "XX" in "(XX ms)"
486             String discardPortion = time.group(1);  // everything after the test class/name
487             identifier = identifier.substring(0, identifier.lastIndexOf(discardPortion)).trim();
488             returnInfo.mTestRunTime = timeString;
489         }
490 
491         String[] testId = identifier.split("\\.");
492         if (testId.length < 2) {
493             CLog.e("Could not detect the test class and test name, received: %s", identifier);
494         }
495         else {
496             returnInfo.mTestClassName = testId[0];
497             returnInfo.mTestName = testId[1];
498         }
499         return returnInfo;
500     }
501 
502     /**
503      * Parses and stores the test identifier (class and test name).
504      *
505      * @param identifier Raw identifier
506      */
processRunStartedTag(String identifier)507     private void processRunStartedTag(String identifier) {
508         // eg: (Running XX tests from 1 test case.)
509         Pattern numTestsPattern = Pattern.compile("Running (\\d+) test[s]? from .*");
510         Matcher numTests = numTestsPattern.matcher(identifier);
511 
512         // Try to find number of tests
513         if (numTests.find()) {
514             try {
515                 mNumTestsExpected = Integer.parseInt(numTests.group(1));
516             }
517             catch (NumberFormatException e) {
518                 CLog.e(
519                         "Unable to determine number of tests expected, received: %s",
520                         numTests.group(1));
521             }
522         }
523         if (mNumTestsExpected > 0) {
524             reportTestRunStarted();
525             mNumTestsRun = 0;
526             mTestRunInProgress = true;
527         } else if (mNumTestsExpected == 0) {
528             reportTestRunStarted();
529         }
530     }
531 
532     /**
533      * Processes and informs listener when we encounter a tag indicating that a test suite is done.
534      *
535      * @param identifier Raw log output from the suite ended tag
536      */
processRunCompletedTag(String identifier)537     private void processRunCompletedTag(String identifier) {
538         Pattern timePattern = Pattern.compile(".*\\((\\d+) ms total\\)");  // eg: (XX ms total)
539         Matcher time = timePattern.matcher(identifier);
540 
541         // Try to find the total run time
542         if (time.find()) {
543             try {
544                 mTotalRunTime = Long.parseLong(time.group(1));
545             }
546             catch (NumberFormatException e) {
547                 CLog.e("Unable to determine the total running time, received: %s", time.group(1));
548             }
549         }
550         reportTestRunEnded();
551         mTestRunInProgress = false;
552     }
553 
getTestClass(TestResult testResult)554     private String getTestClass(TestResult testResult) {
555 
556         if (mPrependFileName) {
557             StringBuilder sb = new StringBuilder();
558             sb.append(mTestRunName);
559             sb.append(".");
560             sb.append(testResult.mTestClass);
561             return sb.toString();
562         }
563         return testResult.mTestClass;
564     }
565 
566     /**
567      * Processes and informs listener when we encounter a tag indicating that a test has started.
568      *
569      * @param identifier Raw log output of the form classname.testname, with an optional time (x ms)
570      */
processTestStartedTag(String identifier)571     private void processTestStartedTag(String identifier) {
572         ParsedTestInfo parsedResults = parseTestDescription(identifier);
573         TestResult testResult = getCurrentTestResult();
574         testResult.mTestClass = parsedResults.mTestClassName;
575         testResult.mTestName = parsedResults.mTestName;
576         TestDescription testId = null;
577         if (getTestClass(testResult) !=null && testResult.mTestName !=null) {
578             testId = new TestDescription(getTestClass(testResult), testResult.mTestName);
579         } else {
580             CLog.e("Error during parsing, className: %s and testName: %s, should both be not null",
581                     getTestClass(testResult), testResult.mTestName);
582             return;
583         }
584 
585         for (ITestInvocationListener listener : mTestListeners) {
586             listener.testStarted(testId);
587         }
588         setTestStarted();
589     }
590 
591     /**
592      * Helper method to do the work necessary when a test has ended.
593      *
594      * @param identifier Raw log output of the form "classname.testname" with an optional (XX ms) at
595      *     the end indicating the running time.
596      * @param testStatus Indicates the final test status.
597      */
doTestEnded(String identifier, TestStatus testStatus)598     private void doTestEnded(String identifier, TestStatus testStatus) {
599         ParsedTestInfo parsedResults = parseTestDescription(identifier);
600         TestResult testResult = getCurrentTestResult();
601         TestDescription testId = null;
602         if (getTestClass(testResult) !=null && testResult.mTestName !=null) {
603             testId = new TestDescription(getTestClass(testResult), testResult.mTestName);
604         } else {
605             CLog.e("Error during parsing, className: %s and testName: %s, should both be not null",
606                     getTestClass(testResult), testResult.mTestName);
607             return;
608         }
609 
610         // Error - trying to end a test when one isn't in progress
611         if (!testInProgress()) {
612             CLog.e("Test currently not in progress when trying to end test: %s", identifier);
613             return;
614         }
615 
616         // Save the run time for this test if one exists
617         if (parsedResults.mTestRunTime != null) {
618             try {
619                 testResult.mRunTime = Long.valueOf(parsedResults.mTestRunTime);
620             } catch (NumberFormatException e) {
621                 CLog.e("Test run time value is invalid, received: %s", parsedResults.mTestRunTime);
622             }
623         }
624 
625         // Check that the test result is for the same test/class we're expecting it to be for
626         boolean encounteredUnexpectedTest = false;
627         if (!testResult.isComplete()) {
628             CLog.e("No test/class name is currently recorded as running!");
629         }
630         else {
631             if (testResult.mTestClass.compareTo(parsedResults.mTestClassName) != 0) {
632                 CLog.e(
633                         "Name for current test class does not match class we started with, "
634                                 + "expected: %s but got:%s ",
635                         testResult.mTestClass, parsedResults.mTestClassName);
636                 encounteredUnexpectedTest = true;
637             }
638             if (testResult.mTestName.compareTo(parsedResults.mTestName) != 0) {
639                 CLog.e(
640                         "Name for current test does not match test we started with, expected: %s "
641                                 + " but got: %s",
642                         testResult.mTestName, parsedResults.mTestName);
643                 encounteredUnexpectedTest = true;
644             }
645         }
646 
647         if (encounteredUnexpectedTest) {
648             // If the test name of the result changed from what we started with, report that
649             // the last known test failed, regardless of whether we received a pass or fail tag.
650             for (ITestInvocationListener listener : mTestListeners) {
651                 listener.testFailed(testId, mCurrentTestResult.getTrace());
652             }
653         } else if (TestStatus.FAILED.equals(testStatus)) { // test failed
654             for (ITestInvocationListener listener : mTestListeners) {
655                 listener.testFailed(testId, mCurrentTestResult.getTrace());
656             }
657         } else if (TestStatus.SKIPPED.equals(testStatus)) { // test was skipped
658             for (ITestInvocationListener listener : mTestListeners) {
659                 listener.testIgnored(testId);
660             }
661         }
662 
663         // For all cases (pass or fail), we ultimately need to report test has ended
664         HashMap<String, Metric> emptyMap = new HashMap<>();
665         for (ITestInvocationListener listener : mTestListeners) {
666             // @TODO: Add reporting of test run time to ITestInvocationListener
667             listener.testEnded(testId, emptyMap);
668         }
669 
670         setTestEnded();
671         ++mNumTestsRun;
672     }
673 
674     /**
675      * Processes and informs listener when we encounter the OK tag.
676      *
677      * @param identifier Raw log output of the form "classname.testname" with an optional (XX ms)
678      *          at the end indicating the running time.
679      */
processOKTag(String identifier)680     private void processOKTag(String identifier) {
681         doTestEnded(identifier, TestStatus.OK);
682     }
683 
684     /**
685      * Processes and informs listener when we encounter the FAILED tag.
686      *
687      * @param identifier Raw log output of the form "classname.testname" with an optional (XX ms)
688      *          at the end indicating the running time.
689      */
processFailedTag(String identifier)690     private void processFailedTag(String identifier) {
691         doTestEnded(identifier, TestStatus.FAILED);
692     }
693 
694     /**
695      * Processes and informs listener when we encounter the SKIPPED tag.
696      *
697      * @param identifier Raw log output of the form "classname.testname" with an optional (XX ms) at
698      *     the end indicating the running time.
699      */
processSkippedTag(String identifier)700     private void processSkippedTag(String identifier) {
701         doTestEnded(identifier, TestStatus.SKIPPED);
702     }
703 
704 
705     /**
706      * Appends the test output to the current TestResult.
707      *
708      * @param line Raw test result line of output.
709      */
appendTestOutputLine(String line)710     private void appendTestOutputLine(String line) {
711         TestResult testResult = getCurrentTestResult();
712         if (testResult.mStackTrace == null) {
713             testResult.mStackTrace = new StringBuilder();
714         }
715         else {
716             testResult.mStackTrace.append("\r\n");
717         }
718         testResult.mStackTrace.append(line);
719     }
720 
721     /**
722      * Process an instrumentation run failure
723      *
724      * @param errorMsg The message to output about the nature of the error
725      */
handleTestRunFailed(String errorMsg)726     private void handleTestRunFailed(String errorMsg) {
727         errorMsg = (errorMsg == null ? "Unknown error" : errorMsg);
728         CLog.i("Test run failed: %s", errorMsg);
729         String testRunStackTrace = "";
730 
731         // Report that the last known test failed
732         if ((mCurrentTestResult != null) && (mCurrentTestResult.isComplete())) {
733             // current test results are cleared out after every complete test run,
734             // if it's not null, assume the last test caused this and report as a test failure
735             TestDescription testId =
736                     new TestDescription(
737                             getTestClass(mCurrentTestResult), mCurrentTestResult.mTestName);
738 
739             // If there was any stack trace during the test run, append it to the "test failed"
740             // error message so we have an idea of what caused the crash/failure.
741             HashMap<String, Metric> emptyMap = new HashMap<>();
742             if (mCurrentTestResult.hasStackTrace()) {
743                 testRunStackTrace = mCurrentTestResult.getTrace();
744             }
745             for (ITestInvocationListener listener : mTestListeners) {
746                 listener.testFailed(testId,
747                         "No test results.\r\n" + testRunStackTrace);
748                 listener.testEnded(testId, emptyMap);
749             }
750             clearCurrentTestResult();
751         }
752         // Report the test run failed
753         for (ITestInvocationListener listener : mTestListeners) {
754             listener.testRunFailed(errorMsg);
755             listener.testRunEnded(mTotalRunTime, getRunMetrics());
756         }
757     }
758 
759     /**
760      * Called by parent when adb session is complete.
761      */
762     @Override
done()763     public void done() {
764         super.done();
765         if (mNumTestsExpected > mNumTestsRun) {
766             handleTestRunFailed(String.format("Test run incomplete. Expected %d tests, received %d",
767                     mNumTestsExpected, mNumTestsRun));
768         } else if (mTestRunInProgress) {
769             handleTestRunFailed("No test results");
770         } else if (!mSeenOneTestRunStart) {
771             for (ITestInvocationListener listener : mTestListeners) {
772                 listener.testRunStarted(mTestRunName, 0);
773                 listener.testRunFailed(
774                         String.format(
775                                 "%s did not report any run:\n%s",
776                                 mTestRunName, Joiner.on("\n").join(mTrackLogsBeforeRunStart)));
777                 listener.testRunEnded(0L, new HashMap<String, Metric>());
778             }
779         }
780     }
781 }
782