ddms/libs/ddmlib/src/com/android/ddmlib/testrunner/InstrumentationResultParser.java

   1 /*
   2  * Copyright (C) 2008 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
  17 package com.android.ddmlib.testrunner;
  18
  19 import com.android.ddmlib.IShellOutputReceiver;
  20 import com.android.ddmlib.Log;
  21 import com.android.ddmlib.MultiLineReceiver;
  22
  23 import java.util.ArrayList;
  24 import java.util.Collection;
  25
  26 /**
  27  * Parses the 'raw output mode' results of an instrumentation test run from shell and informs a
  28  * ITestRunListener of the results.
  29  *
  30  * <p>Expects the following output:
  31  *
  32  * <p>If fatal error occurred when attempted to run the tests:
  33  * <pre>
  34  * INSTRUMENTATION_STATUS: Error=error Message
  35  * INSTRUMENTATION_FAILED:
  36  * </pre>
  37  * <p>or
  38  * <pre>
  39  * INSTRUMENTATION_RESULT: shortMsg=error Message
  40  * </pre>
  41  *
  42  * <p>Otherwise, expect a series of test results, each one containing a set of status key/value
  43  * pairs, delimited by a start(1)/pass(0)/fail(-2)/error(-1) status code result. At end of test
  44  * run, expects that the elapsed test time in seconds will be displayed
  45  *
  46  * <p>For example:
  47  * <pre>
  48  * INSTRUMENTATION_STATUS_CODE: 1
  49  * INSTRUMENTATION_STATUS: class=com.foo.FooTest
  50  * INSTRUMENTATION_STATUS: test=testFoo
  51  * INSTRUMENTATION_STATUS: numtests=2
  52  * INSTRUMENTATION_STATUS: stack=com.foo.FooTest#testFoo:312
  53  *    com.foo.X
  54  * INSTRUMENTATION_STATUS_CODE: -2
  55  * ...
  56  *
  57  * Time: X
  58  * </pre>
  59  * <p>Note that the "value" portion of the key-value pair may wrap over several text lines
  60  */
  61 public class InstrumentationResultParser extends MultiLineReceiver {
  62
  63     /** Relevant test status keys. */
  64     private static class StatusKeys {
  65         private static final String TEST = "test";
  66         private static final String CLASS = "class";
  67         private static final String STACK = "stack";
  68         private static final String NUMTESTS = "numtests";
  69         private static final String ERROR = "Error";
  70         private static final String SHORTMSG = "shortMsg";
  71     }
  72
  73     /** Test result status codes. */
  74     private static class StatusCodes {
  75         private static final int FAILURE = -2;
  76         private static final int START = 1;
  77         private static final int ERROR = -1;
  78         private static final int OK = 0;
  79     }
  80
  81     /** Prefixes used to identify output. */
  82     private static class Prefixes {
  83         private static final String STATUS = "INSTRUMENTATION_STATUS: ";
  84         private static final String STATUS_CODE = "INSTRUMENTATION_STATUS_CODE: ";
  85         private static final String STATUS_FAILED = "INSTRUMENTATION_FAILED: ";
  86         private static final String CODE = "INSTRUMENTATION_CODE: ";
  87         private static final String RESULT = "INSTRUMENTATION_RESULT: ";
  88         private static final String TIME_REPORT = "Time: ";
  89     }
  90
  91     private final Collection<ITestRunListener> mTestListeners;
  92
  93     /**
  94      * Test result data
  95      */
  96     private static class TestResult {
  97         private Integer mCode = null;
  98         private String mTestName = null;
  99         private String mTestClass = null;
 100         private String mStackTrace = null;
 101         private Integer mNumTests = null;
 102
 103         /** Returns true if all expected values have been parsed */
 104         boolean isComplete() {
 105             return mCode != null && mTestName != null && mTestClass != null;
 106         }
 107
 108         /** Provides a more user readable string for TestResult, if possible */
 109         @Override
 110         public String toString() {
 111             StringBuilder output = new StringBuilder();
 112             if (mTestClass != null ) {
 113                 output.append(mTestClass);
 114                 output.append('#');
 115             }
 116             if (mTestName != null) {
 117                 output.append(mTestName);
 118             }
 119             if (output.length() > 0) {
 120                 return output.toString();
 121             }
 122             return "unknown result";
 123         }
 124     }
 125
 126     /** Stores the status values for the test result currently being parsed */
 127     private TestResult mCurrentTestResult = null;
 128
 129     /** Stores the current "key" portion of the status key-value being parsed. */
 130     private String mCurrentKey = null;
 131
 132     /** Stores the current "value" portion of the status key-value being parsed. */
 133     private StringBuilder mCurrentValue = null;
 134
 135     /** True if start of test has already been reported to listener. */
 136     private boolean mTestStartReported = false;
 137
 138     /** True if test run failure has already been reported to listener. */
 139     private boolean mTestRunFailReported = false;
 140
 141     /** The elapsed time of the test run, in milliseconds. */
 142     private long mTestTime = 0;
 143
 144     /** True if current test run has been canceled by user. */
 145     private boolean mIsCancelled = false;
 146
 147     /** The number of tests currently run  */
 148     private int mNumTestsRun = 0;
 149
 150     /** The number of tests expected to run  */
 151     private int mNumTestsExpected = 0;
 152
 153     private static final String LOG_TAG = "InstrumentationResultParser";
 154
 155     /**
 156      * Creates the InstrumentationResultParser.
 157      *
 158      * @param listeners informed of test results as the tests are executing
 159      */
 160     public InstrumentationResultParser(Collection<ITestRunListener> listeners) {
 161         mTestListeners = new ArrayList<ITestRunListener>(listeners);
 162     }
 163
 164     /**
 165      * Creates the InstrumentationResultParser for a single listener.
 166      *
 167      * @param listener informed of test results as the tests are executing
 168      */
 169     public InstrumentationResultParser(ITestRunListener listener) {
 170         mTestListeners = new ArrayList<ITestRunListener>(1);
 171         mTestListeners.add(listener);
 172     }
 173
 174     /**
 175      * Processes the instrumentation test output from shell.
 176      *
 177      * @see MultiLineReceiver#processNewLines
 178      */
 179     @Override
 180     public void processNewLines(String[] lines) {
 181         for (String line : lines) {
 182             parse(line);
 183             // in verbose mode, dump all adb output to log
 184             Log.v(LOG_TAG, line);
 185         }
 186     }
 187
 188     /**
 189      * Parse an individual output line. Expects a line that is one of:
 190      * <ul>
 191      * <li>
 192      * The start of a new status line (starts with Prefixes.STATUS or Prefixes.STATUS_CODE),
 193      * and thus there is a new key=value pair to parse, and the previous key-value pair is
 194      * finished.
 195      * </li>
 196      * <li>
 197      * A continuation of the previous status (the "value" portion of the key has wrapped
 198      * to the next line).
 199      * </li>
 200      * <li> A line reporting a fatal error in the test run (Prefixes.STATUS_FAILED) </li>
 201      * <li> A line reporting the total elapsed time of the test run. (Prefixes.TIME_REPORT) </li>
 202      * </ul>
 203      *
 204      * @param line  Text output line
 205      */
 206     private void parse(String line) {
 207         if (line.startsWith(Prefixes.STATUS_CODE)) {
 208             // Previous status key-value has been collected. Store it.
 209             submitCurrentKeyValue();
 210             parseStatusCode(line);
 211         } else if (line.startsWith(Prefixes.STATUS)) {
 212             // Previous status key-value has been collected. Store it.
 213             submitCurrentKeyValue();
 214             parseKey(line, Prefixes.STATUS.length());
 215         } else if (line.startsWith(Prefixes.RESULT)) {
 216             // Previous status key-value has been collected. Store it.
 217             submitCurrentKeyValue();
 218             parseKey(line, Prefixes.RESULT.length());
 219         } else if (line.startsWith(Prefixes.STATUS_FAILED) ||
 220                    line.startsWith(Prefixes.CODE)) {
 221             // Previous status key-value has been collected. Store it.
 222             submitCurrentKeyValue();
 223             // just ignore the remaining data on this line
 224         } else if (line.startsWith(Prefixes.TIME_REPORT)) {
 225             parseTime(line, Prefixes.TIME_REPORT.length());
 226         } else {
 227             if (mCurrentValue != null) {
 228                 // this is a value that has wrapped to next line.
 229                 mCurrentValue.append("\r\n");
 230                 mCurrentValue.append(line);
 231             } else {
 232                 Log.i(LOG_TAG, "unrecognized line " + line);
 233             }
 234         }
 235     }
 236
 237     /**
 238      * Stores the currently parsed key-value pair into mCurrentTestInfo.
 239      */
 240     private void submitCurrentKeyValue() {
 241         if (mCurrentKey != null && mCurrentValue != null) {
 242             TestResult testInfo = getCurrentTestInfo();
 243             String statusValue = mCurrentValue.toString();
 244
 245             if (mCurrentKey.equals(StatusKeys.CLASS)) {
 246                 testInfo.mTestClass = statusValue.trim();
 247             } else if (mCurrentKey.equals(StatusKeys.TEST)) {
 248                 testInfo.mTestName = statusValue.trim();
 249             } else if (mCurrentKey.equals(StatusKeys.NUMTESTS)) {
 250                 try {
 251                     testInfo.mNumTests = Integer.parseInt(statusValue);
 252                 } catch (NumberFormatException e) {
 253                     Log.e(LOG_TAG, "Unexpected integer number of tests, received " + statusValue);
 254                 }
 255             } else if (mCurrentKey.equals(StatusKeys.ERROR) ||
 256                     mCurrentKey.equals(StatusKeys.SHORTMSG)) {
 257                 // test run must have failed
 258                 handleTestRunFailed(statusValue);
 259             } else if (mCurrentKey.equals(StatusKeys.STACK)) {
 260                 testInfo.mStackTrace = statusValue;
 261             }
 262
 263             mCurrentKey = null;
 264             mCurrentValue = null;
 265         }
 266     }
 267
 268     private TestResult getCurrentTestInfo() {
 269         if (mCurrentTestResult == null) {
 270             mCurrentTestResult = new TestResult();
 271         }
 272         return mCurrentTestResult;
 273     }
 274
 275     private void clearCurrentTestInfo() {
 276         mCurrentTestResult = null;
 277     }
 278
 279     /**
 280      * Parses the key from the current line.
 281      * Expects format of "key=value".
 282      *
 283      * @param line full line of text to parse
 284      * @param keyStartPos the starting position of the key in the given line
 285      */
 286     private void parseKey(String line, int keyStartPos) {
 287         int endKeyPos = line.indexOf('=', keyStartPos);
 288         if (endKeyPos != -1) {
 289             mCurrentKey = line.substring(keyStartPos, endKeyPos).trim();
 290             parseValue(line, endKeyPos + 1);
 291         }
 292     }
 293
 294     /**
 295      * Parses the start of a key=value pair.
 296      *
 297      * @param line - full line of text to parse
 298      * @param valueStartPos - the starting position of the value in the given line
 299      */
 300     private void parseValue(String line, int valueStartPos) {
 301         mCurrentValue = new StringBuilder();
 302         mCurrentValue.append(line.substring(valueStartPos));
 303     }
 304
 305     /**
 306      * Parses out a status code result.
 307      */
 308     private void parseStatusCode(String line) {
 309         String value = line.substring(Prefixes.STATUS_CODE.length()).trim();
 310         TestResult testInfo = getCurrentTestInfo();
 311         try {
 312             testInfo.mCode = Integer.parseInt(value);
 313         } catch (NumberFormatException e) {
 314             Log.e(LOG_TAG, "Expected integer status code, received: " + value);
 315         }
 316
 317         // this means we're done with current test result bundle
 318         reportResult(testInfo);
 319         clearCurrentTestInfo();
 320     }
 321
 322     /**
 323      * Returns true if test run canceled.
 324      *
 325      * @see IShellOutputReceiver#isCancelled()
 326      */
 327     public boolean isCancelled() {
 328         return mIsCancelled;
 329     }
 330
 331     /**
 332      * Requests cancellation of test run.
 333      */
 334     public void cancel() {
 335         mIsCancelled = true;
 336     }
 337
 338     /**
 339      * Reports a test result to the test run listener. Must be called when a individual test
 340      * result has been fully parsed.
 341      *
 342      * @param statusMap key-value status pairs of test result
 343      */
 344     private void reportResult(TestResult testInfo) {
 345         if (!testInfo.isComplete()) {
 346             Log.w(LOG_TAG, "invalid instrumentation status bundle " + testInfo.toString());
 347             return;
 348         }
 349         reportTestRunStarted(testInfo);
 350         TestIdentifier testId = new TestIdentifier(testInfo.mTestClass, testInfo.mTestName);
 351
 352         switch (testInfo.mCode) {
 353             case StatusCodes.START:
 354                 for (ITestRunListener listener : mTestListeners) {
 355                     listener.testStarted(testId);
 356                 }
 357                 break;
 358             case StatusCodes.FAILURE:
 359                 for (ITestRunListener listener : mTestListeners) {
 360                     listener.testFailed(ITestRunListener.TestFailure.FAILURE, testId,
 361                         getTrace(testInfo));
 362
 363                     listener.testEnded(testId);
 364                 }
 365                 mNumTestsRun++;
 366                 break;
 367             case StatusCodes.ERROR:
 368                 for (ITestRunListener listener : mTestListeners) {
 369                     listener.testFailed(ITestRunListener.TestFailure.ERROR, testId,
 370                         getTrace(testInfo));
 371                     listener.testEnded(testId);
 372                 }
 373                 mNumTestsRun++;
 374                 break;
 375             case StatusCodes.OK:
 376                 for (ITestRunListener listener : mTestListeners) {
 377                     listener.testEnded(testId);
 378                 }
 379                 mNumTestsRun++;
 380                 break;
 381             default:
 382                 Log.e(LOG_TAG, "Unknown status code received: " + testInfo.mCode);
 383                 for (ITestRunListener listener : mTestListeners) {
 384                     listener.testEnded(testId);
 385                 }
 386                 mNumTestsRun++;
 387             break;
 388         }
 389
 390     }
 391
 392     /**
 393      * Reports the start of a test run, and the total test count, if it has not been previously
 394      * reported.
 395      *
 396      * @param testInfo current test status values
 397      */
 398     private void reportTestRunStarted(TestResult testInfo) {
 399         // if start test run not reported yet
 400         if (!mTestStartReported && testInfo.mNumTests != null) {
 401             for (ITestRunListener listener : mTestListeners) {
 402                 listener.testRunStarted(testInfo.mNumTests);
 403             }
 404             mNumTestsExpected = testInfo.mNumTests;
 405             mTestStartReported = true;
 406         }
 407     }
 408
 409     /**
 410      * Returns the stack trace of the current failed test, from the provided testInfo.
 411      */
 412     private String getTrace(TestResult testInfo) {
 413         if (testInfo.mStackTrace != null) {
 414             return testInfo.mStackTrace;
 415         } else {
 416             Log.e(LOG_TAG, "Could not find stack trace for failed test ");
 417             return new Throwable("Unknown failure").toString();
 418         }
 419     }
 420
 421     /**
 422      * Parses out and store the elapsed time.
 423      */
 424     private void parseTime(String line, int startPos) {
 425         String timeString = line.substring(startPos);
 426         try {
 427             float timeSeconds = Float.parseFloat(timeString);
 428             mTestTime = (long) (timeSeconds * 1000);
 429         } catch (NumberFormatException e) {
 430             Log.e(LOG_TAG, "Unexpected time format " + timeString);
 431         }
 432     }
 433
 434     /**
 435      * Process a instrumentation run failure
 436      */
 437     private void handleTestRunFailed(String errorMsg) {
 438         Log.i(LOG_TAG, String.format("test run failed %s", errorMsg));
 439         for (ITestRunListener listener : mTestListeners) {
 440             listener.testRunFailed(errorMsg == null ? "Unknown error" : errorMsg);
 441         }
 442         mTestRunFailReported = true;
 443     }
 444
 445     /**
 446      * Called by parent when adb session is complete.
 447      */
 448     @Override
 449     public void done() {
 450         super.done();
 451         if (!mTestRunFailReported && mNumTestsExpected > mNumTestsRun) {
 452             final String message =
 453                 String.format("Test run incomplete. Expected %d tests, received %d",
 454                         mNumTestsExpected, mNumTestsRun);
 455             Log.w(LOG_TAG, message);
 456             for (ITestRunListener listener : mTestListeners) {
 457                 listener.testRunFailed(message);
 458             }
 459         } else {
 460             for (ITestRunListener listener : mTestListeners) {
 461                 listener.testRunEnded(mTestTime);
 462             }
 463         }
 464     }
 465 }