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.invoker.logger.InvocationMetricLogger; 21 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationGroupMetricKey; 22 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationMetricKey; 23 import com.android.tradefed.invoker.logger.TfObjectTracker; 24 import com.android.tradefed.invoker.tracing.ActiveTrace; 25 import com.android.tradefed.invoker.tracing.TracingLogger; 26 import com.android.tradefed.log.LogUtil.CLog; 27 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric; 28 import com.android.tradefed.result.FailureDescription; 29 import com.android.tradefed.result.FileInputStreamSource; 30 import com.android.tradefed.result.ILogSaverListener; 31 import com.android.tradefed.result.ITestInvocationListener; 32 import com.android.tradefed.result.InputStreamSource; 33 import com.android.tradefed.result.LogDataType; 34 import com.android.tradefed.result.LogFile; 35 import com.android.tradefed.result.TestDescription; 36 import com.android.tradefed.result.proto.TestRecordProto.FailureStatus; 37 import com.android.tradefed.testtype.suite.ModuleDefinition; 38 import com.android.tradefed.util.SubprocessEventHelper.BaseTestEventInfo; 39 import com.android.tradefed.util.SubprocessEventHelper.FailedTestEventInfo; 40 import com.android.tradefed.util.SubprocessEventHelper.InvocationEndedEventInfo; 41 import com.android.tradefed.util.SubprocessEventHelper.InvocationFailedEventInfo; 42 import com.android.tradefed.util.SubprocessEventHelper.InvocationStartedEventInfo; 43 import com.android.tradefed.util.SubprocessEventHelper.LogAssociationEventInfo; 44 import com.android.tradefed.util.SubprocessEventHelper.SkippedTestEventInfo; 45 import com.android.tradefed.util.SubprocessEventHelper.TestEndedEventInfo; 46 import com.android.tradefed.util.SubprocessEventHelper.TestLogEventInfo; 47 import com.android.tradefed.util.SubprocessEventHelper.TestModuleStartedEventInfo; 48 import com.android.tradefed.util.SubprocessEventHelper.TestRunEndedEventInfo; 49 import com.android.tradefed.util.SubprocessEventHelper.TestRunFailedEventInfo; 50 import com.android.tradefed.util.SubprocessEventHelper.TestRunStartedEventInfo; 51 import com.android.tradefed.util.SubprocessEventHelper.TestStartedEventInfo; 52 import com.android.tradefed.util.proto.TfMetricProtoUtil; 53 54 import com.google.common.base.Splitter; 55 import com.google.common.base.Strings; 56 57 import org.json.JSONException; 58 import org.json.JSONObject; 59 60 import java.io.BufferedReader; 61 import java.io.Closeable; 62 import java.io.File; 63 import java.io.FileNotFoundException; 64 import java.io.FileOutputStream; 65 import java.io.FileReader; 66 import java.io.IOException; 67 import java.io.InputStreamReader; 68 import java.net.ServerSocket; 69 import java.net.Socket; 70 import java.util.ArrayList; 71 import java.util.HashMap; 72 import java.util.HashSet; 73 import java.util.List; 74 import java.util.Map; 75 import java.util.Set; 76 import java.util.concurrent.Semaphore; 77 import java.util.concurrent.TimeUnit; 78 import java.util.regex.Matcher; 79 import java.util.regex.Pattern; 80 81 /** 82 * Extends {@link FileOutputStream} to parse the output before writing to the file so we can 83 * generate the test events on the launcher side. 84 */ 85 public class SubprocessTestResultsParser implements Closeable { 86 87 private ITestInvocationListener mListener; 88 89 private TestDescription mCurrentTestCase = null; 90 private IInvocationContext mCurrentModuleContext = null; 91 private String mCurrentRunName = null; 92 private InvocationFailedEventInfo mReportedInvocationFailedEventInfo = null; 93 94 private Pattern mPattern = null; 95 private Map<String, EventHandler> mHandlerMap = null; 96 private EventReceiverThread mEventReceiver = null; 97 private IInvocationContext mContext = null; 98 private Long mStartTime = null; 99 // Ignore the testLog events, rely only on logAssociation 100 private boolean mIgnoreTestLog = true; 101 // Keep track of which files we received TEST_LOG event from. 102 private Set<String> mTestLogged = new HashSet<>(); 103 104 /** Relevant test status keys. */ 105 public static class StatusKeys { 106 public static final String INVOCATION_FAILED = "INVOCATION_FAILED"; 107 public static final String TEST_ASSUMPTION_FAILURE = "TEST_ASSUMPTION_FAILURE"; 108 public static final String TEST_ENDED = "TEST_ENDED"; 109 public static final String TEST_FAILED = "TEST_FAILED"; 110 public static final String TEST_IGNORED = "TEST_IGNORED"; 111 public static final String TEST_SKIPPED = "TEST_SKIPPED"; 112 public static final String TEST_STARTED = "TEST_STARTED"; 113 public static final String TEST_RUN_ENDED = "TEST_RUN_ENDED"; 114 public static final String TEST_RUN_FAILED = "TEST_RUN_FAILED"; 115 public static final String TEST_RUN_STARTED = "TEST_RUN_STARTED"; 116 public static final String TEST_MODULE_STARTED = "TEST_MODULE_STARTED"; 117 public static final String TEST_MODULE_ENDED = "TEST_MODULE_ENDED"; 118 public static final String TEST_LOG = "TEST_LOG"; 119 public static final String LOG_ASSOCIATION = "LOG_ASSOCIATION"; 120 public static final String INVOCATION_STARTED = "INVOCATION_STARTED"; 121 public static final String INVOCATION_ENDED = "INVOCATION_ENDED"; 122 } 123 124 /** 125 * Internal receiver thread class with a socket. 126 */ 127 private class EventReceiverThread extends Thread { 128 private ServerSocket mSocket; 129 private Socket mClient; 130 // initial state: 1 permit available, joins that don't wait for connection will succeed 131 private Semaphore mSemaphore = new Semaphore(1); 132 private boolean mShouldParse = true; 133 EventReceiverThread()134 public EventReceiverThread() throws IOException { 135 super("EventReceiverThread"); 136 mSocket = new ServerSocket(0); 137 } 138 getLocalPort()139 protected int getLocalPort() { 140 return mSocket.getLocalPort(); 141 } 142 143 /** @return True if parsing completes before timeout (optionally waiting for connection). */ await(long millis, boolean waitForConnection)144 boolean await(long millis, boolean waitForConnection) throws InterruptedException { 145 // As only 1 permit is available prior to connecting, changing the number of permits 146 // requested controls whether the receiver will wait for a connection. 147 int permits = waitForConnection ? 2 : 1; 148 if (mSemaphore.tryAcquire(permits, millis, TimeUnit.MILLISECONDS)) { 149 mSemaphore.release(permits); 150 return true; 151 } 152 return false; 153 } 154 cancel()155 public void cancel() throws IOException { 156 if (mSocket != null) { 157 mSocket.close(); 158 } 159 if (mClient != null) { 160 mClient.close(); 161 } 162 } 163 164 /** 165 * When reaching some issues, we might want to terminate the buffer of the socket to spy 166 * which events are still in the pipe. 167 */ stopParsing()168 public void stopParsing() { 169 mShouldParse = false; 170 } 171 172 @Override run()173 public void run() { 174 BufferedReader in = null; 175 try { 176 mClient = mSocket.accept(); 177 mSemaphore.acquire(); // connected: 0 permits available, all joins will wait 178 in = new BufferedReader(new InputStreamReader(mClient.getInputStream())); 179 String event = null; 180 while ((event = in.readLine()) != null) { 181 try { 182 if (mShouldParse) { 183 CLog.d("received event: '%s'", event); 184 parse(event); 185 } else { 186 CLog.d("Skipping parsing of event: '%s'", event); 187 } 188 } catch (JSONException e) { 189 CLog.e(e); 190 } 191 } 192 } catch (IOException | InterruptedException e) { 193 CLog.e(e); 194 } finally { 195 StreamUtil.close(in); 196 mSemaphore.release(2); // finished: 2 permits available, all joins succeed 197 } 198 CLog.d("EventReceiverThread done."); 199 } 200 } 201 202 /** 203 * Wait for the event receiver to finish processing events. Will wait even if a connection 204 * wasn't established, i.e. processing hasn't begun yet. 205 * 206 * @param millis timeout in milliseconds. 207 * @return True if receiver thread terminate before timeout, False otherwise. 208 */ joinReceiver(long millis)209 public boolean joinReceiver(long millis) { 210 return joinReceiver(millis, true); 211 } 212 213 /** 214 * Wait for the event receiver to finish processing events. 215 * 216 * @param millis timeout in milliseconds. 217 * @param waitForConnection False to skip waiting if a connection was never established. 218 * @return True if receiver thread terminate before timeout, False otherwise. 219 */ joinReceiver(long millis, boolean waitForConnection)220 public boolean joinReceiver(long millis, boolean waitForConnection) { 221 if (mEventReceiver != null) { 222 try { 223 CLog.i("Waiting for events to finish being processed."); 224 if (!mEventReceiver.await(millis, waitForConnection)) { 225 mEventReceiver.stopParsing(); 226 CLog.e("Event receiver thread did not complete. Some events may be missing."); 227 return false; 228 } 229 } catch (InterruptedException e) { 230 CLog.e(e); 231 throw new RuntimeException(e); 232 } 233 } 234 return true; 235 } 236 237 /** 238 * Returns the socket receiver that was open. -1 if none. 239 */ getSocketServerPort()240 public int getSocketServerPort() { 241 if (mEventReceiver != null) { 242 return mEventReceiver.getLocalPort(); 243 } 244 return -1; 245 } 246 247 /** Whether or not to ignore testLog events and only rely on logAssociation. */ setIgnoreTestLog(boolean ignoreTestLog)248 public void setIgnoreTestLog(boolean ignoreTestLog) { 249 mIgnoreTestLog = ignoreTestLog; 250 } 251 252 @Override close()253 public void close() throws IOException { 254 if (mEventReceiver != null) { 255 mEventReceiver.cancel(); 256 } 257 } 258 259 /** 260 * Constructor for the result parser 261 * 262 * @param listener {@link ITestInvocationListener} where to report the results 263 * @param streaming if True, a socket receiver will be open to receive results. 264 * @param context a {@link IInvocationContext} information about the invocation 265 */ SubprocessTestResultsParser( ITestInvocationListener listener, boolean streaming, IInvocationContext context)266 public SubprocessTestResultsParser( 267 ITestInvocationListener listener, boolean streaming, IInvocationContext context) 268 throws IOException { 269 this(listener, context); 270 if (streaming) { 271 mEventReceiver = new EventReceiverThread(); 272 mEventReceiver.start(); 273 } 274 } 275 276 /** 277 * Constructor for the result parser 278 * 279 * @param listener {@link ITestInvocationListener} where to report the results 280 * @param context a {@link IInvocationContext} information about the invocation 281 */ SubprocessTestResultsParser( ITestInvocationListener listener, IInvocationContext context)282 public SubprocessTestResultsParser( 283 ITestInvocationListener listener, IInvocationContext context) { 284 mListener = listener; 285 mContext = context; 286 StringBuilder sb = new StringBuilder(); 287 sb.append(StatusKeys.INVOCATION_FAILED).append("|"); 288 sb.append(StatusKeys.TEST_ASSUMPTION_FAILURE).append("|"); 289 sb.append(StatusKeys.TEST_ENDED).append("|"); 290 sb.append(StatusKeys.TEST_FAILED).append("|"); 291 sb.append(StatusKeys.TEST_IGNORED).append("|"); 292 sb.append(StatusKeys.TEST_STARTED).append("|"); 293 sb.append(StatusKeys.TEST_RUN_ENDED).append("|"); 294 sb.append(StatusKeys.TEST_RUN_FAILED).append("|"); 295 sb.append(StatusKeys.TEST_RUN_STARTED).append("|"); 296 sb.append(StatusKeys.TEST_MODULE_STARTED).append("|"); 297 sb.append(StatusKeys.TEST_MODULE_ENDED).append("|"); 298 sb.append(StatusKeys.TEST_LOG).append("|"); 299 sb.append(StatusKeys.LOG_ASSOCIATION).append("|"); 300 sb.append(StatusKeys.INVOCATION_STARTED).append("|"); 301 sb.append(StatusKeys.INVOCATION_ENDED); 302 String patt = String.format("(.*)(%s)( )(.*)", sb.toString()); 303 mPattern = Pattern.compile(patt); 304 305 // Create Handler map for each event 306 mHandlerMap = new HashMap<String, EventHandler>(); 307 mHandlerMap.put(StatusKeys.INVOCATION_FAILED, new InvocationFailedEventHandler()); 308 mHandlerMap.put(StatusKeys.TEST_ASSUMPTION_FAILURE, 309 new TestAssumptionFailureEventHandler()); 310 mHandlerMap.put(StatusKeys.TEST_ENDED, new TestEndedEventHandler()); 311 mHandlerMap.put(StatusKeys.TEST_FAILED, new TestFailedEventHandler()); 312 mHandlerMap.put(StatusKeys.TEST_IGNORED, new TestIgnoredEventHandler()); 313 mHandlerMap.put(StatusKeys.TEST_SKIPPED, new TestSkippedEventHandler()); 314 mHandlerMap.put(StatusKeys.TEST_STARTED, new TestStartedEventHandler()); 315 mHandlerMap.put(StatusKeys.TEST_RUN_ENDED, new TestRunEndedEventHandler()); 316 mHandlerMap.put(StatusKeys.TEST_RUN_FAILED, new TestRunFailedEventHandler()); 317 mHandlerMap.put(StatusKeys.TEST_RUN_STARTED, new TestRunStartedEventHandler()); 318 mHandlerMap.put(StatusKeys.TEST_MODULE_STARTED, new TestModuleStartedEventHandler()); 319 mHandlerMap.put(StatusKeys.TEST_MODULE_ENDED, new TestModuleEndedEventHandler()); 320 mHandlerMap.put(StatusKeys.TEST_LOG, new TestLogEventHandler()); 321 mHandlerMap.put(StatusKeys.LOG_ASSOCIATION, new LogAssociationEventHandler()); 322 mHandlerMap.put(StatusKeys.INVOCATION_STARTED, new InvocationStartedEventHandler()); 323 mHandlerMap.put(StatusKeys.INVOCATION_ENDED, new InvocationEndedEventHandler()); 324 } 325 parseFile(File file)326 public void parseFile(File file) { 327 BufferedReader reader = null; 328 try { 329 reader = new BufferedReader(new FileReader(file)); 330 } catch (FileNotFoundException e) { 331 CLog.e(e); 332 throw new RuntimeException(e); 333 } 334 ArrayList<String> listString = new ArrayList<String>(); 335 String line = null; 336 try { 337 while ((line = reader.readLine()) != null) { 338 listString.add(line); 339 } 340 reader.close(); 341 } catch (IOException e) { 342 CLog.e(e); 343 throw new RuntimeException(e); 344 } 345 processNewLines(listString.toArray(new String[listString.size()])); 346 } 347 348 /** 349 * call parse on each line of the array to extract the events if any. 350 */ processNewLines(String[] lines)351 public void processNewLines(String[] lines) { 352 for (String line : lines) { 353 try { 354 parse(line); 355 } catch (JSONException e) { 356 CLog.e("Exception while parsing"); 357 CLog.e(e); 358 throw new RuntimeException(e); 359 } 360 } 361 } 362 363 /** 364 * Parse a line, if it matches one of the events, handle it. 365 */ parse(String line)366 private void parse(String line) throws JSONException { 367 Matcher matcher = mPattern.matcher(line); 368 if (matcher.find()) { 369 EventHandler handler = mHandlerMap.get(matcher.group(2)); 370 if (handler != null) { 371 handler.handleEvent(matcher.group(4)); 372 } else { 373 CLog.w("No handler found matching: %s", matcher.group(2)); 374 } 375 } 376 } 377 checkCurrentTestId(String className, String testName)378 private void checkCurrentTestId(String className, String testName) { 379 if (mCurrentTestCase == null) { 380 mCurrentTestCase = new TestDescription(className, testName); 381 CLog.w("Calling a test event without having called testStarted."); 382 } 383 } 384 385 /** 386 * Interface for event handling 387 */ 388 interface EventHandler { handleEvent(String eventJson)389 public void handleEvent(String eventJson) throws JSONException; 390 } 391 392 private class TestRunStartedEventHandler implements EventHandler { 393 @Override handleEvent(String eventJson)394 public void handleEvent(String eventJson) throws JSONException { 395 TestRunStartedEventInfo rsi = new TestRunStartedEventInfo(new JSONObject(eventJson)); 396 if (rsi.mAttempt != null) { 397 mListener.testRunStarted( 398 rsi.mRunName, rsi.mTestCount, rsi.mAttempt, rsi.mStartTime); 399 } else { 400 mListener.testRunStarted(rsi.mRunName, rsi.mTestCount); 401 } 402 mCurrentRunName = rsi.mRunName; 403 } 404 } 405 406 private class TestRunFailedEventHandler implements EventHandler { 407 @Override handleEvent(String eventJson)408 public void handleEvent(String eventJson) throws JSONException { 409 TestRunFailedEventInfo rfi = new TestRunFailedEventInfo(new JSONObject(eventJson)); 410 if (rfi.mFailure != null) { 411 mListener.testRunFailed(rfi.mFailure); 412 } else { 413 mListener.testRunFailed(rfi.mReason); 414 } 415 } 416 } 417 418 private class TestRunEndedEventHandler implements EventHandler { 419 @Override handleEvent(String eventJson)420 public void handleEvent(String eventJson) throws JSONException { 421 try { 422 TestRunEndedEventInfo rei = new TestRunEndedEventInfo(new JSONObject(eventJson)); 423 // TODO: Parse directly as proto. 424 mListener.testRunEnded( 425 rei.mTime, TfMetricProtoUtil.upgradeConvert(rei.mRunMetrics, true)); 426 } finally { 427 mCurrentRunName = null; 428 mCurrentTestCase = null; 429 } 430 } 431 } 432 433 private class InvocationFailedEventHandler implements EventHandler { 434 @Override handleEvent(String eventJson)435 public void handleEvent(String eventJson) throws JSONException { 436 InvocationFailedEventInfo ifi = 437 new InvocationFailedEventInfo(new JSONObject(eventJson)); 438 if (ifi.mFailure != null) { 439 mListener.invocationFailed(ifi.mFailure); 440 } else { 441 mListener.invocationFailed(ifi.mCause); 442 } 443 mReportedInvocationFailedEventInfo = ifi; 444 } 445 } 446 447 private class TestStartedEventHandler implements EventHandler { 448 @Override handleEvent(String eventJson)449 public void handleEvent(String eventJson) throws JSONException { 450 TestStartedEventInfo bti = new TestStartedEventInfo(new JSONObject(eventJson)); 451 mCurrentTestCase = new TestDescription(bti.mClassName, bti.mTestName); 452 if (bti.mStartTime != null) { 453 mListener.testStarted(mCurrentTestCase, bti.mStartTime); 454 } else { 455 mListener.testStarted(mCurrentTestCase); 456 } 457 } 458 } 459 460 private class TestFailedEventHandler implements EventHandler { 461 @Override handleEvent(String eventJson)462 public void handleEvent(String eventJson) throws JSONException { 463 FailedTestEventInfo fti = new FailedTestEventInfo(new JSONObject(eventJson)); 464 checkCurrentTestId(fti.mClassName, fti.mTestName); 465 mListener.testFailed(mCurrentTestCase, fti.mFailure); 466 } 467 } 468 469 private class TestEndedEventHandler implements EventHandler { 470 @Override handleEvent(String eventJson)471 public void handleEvent(String eventJson) throws JSONException { 472 try { 473 TestEndedEventInfo tei = new TestEndedEventInfo(new JSONObject(eventJson)); 474 checkCurrentTestId(tei.mClassName, tei.mTestName); 475 if (tei.mEndTime != null) { 476 mListener.testEnded( 477 mCurrentTestCase, 478 tei.mEndTime, 479 TfMetricProtoUtil.upgradeConvert(tei.mRunMetrics)); 480 } else { 481 mListener.testEnded( 482 mCurrentTestCase, TfMetricProtoUtil.upgradeConvert(tei.mRunMetrics)); 483 } 484 } finally { 485 mCurrentTestCase = null; 486 } 487 } 488 } 489 490 private class TestIgnoredEventHandler implements EventHandler { 491 @Override handleEvent(String eventJson)492 public void handleEvent(String eventJson) throws JSONException { 493 BaseTestEventInfo baseTestIgnored = new BaseTestEventInfo(new JSONObject(eventJson)); 494 checkCurrentTestId(baseTestIgnored.mClassName, baseTestIgnored.mTestName); 495 mListener.testIgnored(mCurrentTestCase); 496 } 497 } 498 499 private class TestSkippedEventHandler implements EventHandler { 500 @Override handleEvent(String eventJson)501 public void handleEvent(String eventJson) throws JSONException { 502 SkippedTestEventInfo skipped = new SkippedTestEventInfo(new JSONObject(eventJson)); 503 checkCurrentTestId(skipped.mClassName, skipped.mTestName); 504 mListener.testSkipped(mCurrentTestCase, skipped.skipReason); 505 } 506 } 507 508 private class TestAssumptionFailureEventHandler implements EventHandler { 509 @Override handleEvent(String eventJson)510 public void handleEvent(String eventJson) throws JSONException { 511 FailedTestEventInfo FailedAssumption = 512 new FailedTestEventInfo(new JSONObject(eventJson)); 513 checkCurrentTestId(FailedAssumption.mClassName, FailedAssumption.mTestName); 514 mListener.testAssumptionFailure(mCurrentTestCase, FailedAssumption.mTrace); 515 } 516 } 517 518 private class TestModuleStartedEventHandler implements EventHandler { 519 @Override handleEvent(String eventJson)520 public void handleEvent(String eventJson) throws JSONException { 521 TestModuleStartedEventInfo module = 522 new TestModuleStartedEventInfo(new JSONObject(eventJson)); 523 mCurrentModuleContext = module.mModuleContext; 524 mListener.testModuleStarted(module.mModuleContext); 525 } 526 } 527 528 private class TestModuleEndedEventHandler implements EventHandler { 529 @Override handleEvent(String eventJson)530 public void handleEvent(String eventJson) throws JSONException { 531 if (mCurrentModuleContext == null) { 532 CLog.w("Calling testModuleEnded when testModuleStarted was not called."); 533 } 534 mListener.testModuleEnded(); 535 mCurrentModuleContext = null; 536 } 537 } 538 539 private class TestLogEventHandler implements EventHandler { 540 @Override handleEvent(String eventJson)541 public void handleEvent(String eventJson) throws JSONException { 542 TestLogEventInfo logInfo = new TestLogEventInfo(new JSONObject(eventJson)); 543 if (mIgnoreTestLog) { 544 FileUtil.deleteFile(logInfo.mDataFile); 545 return; 546 } 547 String name = String.format("subprocess-%s", logInfo.mDataName); 548 try (InputStreamSource data = new FileInputStreamSource(logInfo.mDataFile, true)) { 549 mListener.testLog(name, logInfo.mLogType, data); 550 mTestLogged.add(logInfo.mDataName); 551 } 552 } 553 } 554 555 private class LogAssociationEventHandler implements EventHandler { 556 @Override handleEvent(String eventJson)557 public void handleEvent(String eventJson) throws JSONException { 558 LogAssociationEventInfo assosInfo = 559 new LogAssociationEventInfo(new JSONObject(eventJson)); 560 LogFile file = assosInfo.mLoggedFile; 561 if (Strings.isNullOrEmpty(file.getPath())) { 562 CLog.e("Log '%s' was registered but without a path.", assosInfo.mDataName); 563 return; 564 } 565 File path = new File(file.getPath()); 566 String name = String.format("subprocess-%s", assosInfo.mDataName); 567 if (Strings.isNullOrEmpty(file.getUrl()) && path.exists()) { 568 if (mTestLogged.contains(assosInfo.mDataName)) { 569 CLog.d( 570 "Already called testLog on %s, ignoring the logAssociation.", 571 assosInfo.mDataName); 572 return; 573 } 574 try (InputStreamSource source = new FileInputStreamSource(path)) { 575 LogDataType type = file.getType(); 576 CLog.d("Logging %s from subprocess: %s ", assosInfo.mDataName, file.getPath()); 577 if (ActiveTrace.TRACE_KEY.equals(assosInfo.mDataName) 578 && LogDataType.PERFETTO.equals(type)) { 579 CLog.d("Log the subprocess trace"); 580 TracingLogger.getActiveTrace().addSubprocessTrace(path); 581 } 582 mListener.testLog(name, type, source); 583 } 584 } else { 585 CLog.d( 586 "Logging %s from subprocess. url: %s, path: %s", 587 name, file.getUrl(), file.getPath()); 588 if (mListener instanceof ILogSaverListener) { 589 ((ILogSaverListener) mListener).logAssociation(name, assosInfo.mLoggedFile); 590 } 591 } 592 } 593 } 594 595 private class InvocationStartedEventHandler implements EventHandler { 596 @Override handleEvent(String eventJson)597 public void handleEvent(String eventJson) throws JSONException { 598 InvocationStartedEventInfo eventStart = 599 new InvocationStartedEventInfo(new JSONObject(eventJson)); 600 if (mContext.getTestTag() == null || "stub".equals(mContext.getTestTag())) { 601 mContext.setTestTag(eventStart.mTestTag); 602 } 603 mStartTime = eventStart.mStartTime; 604 } 605 } 606 607 private class InvocationEndedEventHandler implements EventHandler { 608 @Override handleEvent(String eventJson)609 public void handleEvent(String eventJson) throws JSONException { 610 JSONObject json = new JSONObject(eventJson); 611 InvocationEndedEventInfo eventEnd = new InvocationEndedEventInfo(json); 612 // Add build attributes to the primary build (the first build 613 // provider of the running configuration). 614 List<IBuildInfo> infos = mContext.getBuildInfos(); 615 if (!infos.isEmpty()) { 616 Map<String, String> attributes = eventEnd.mBuildAttributes; 617 for (InvocationGroupMetricKey groupKey : InvocationGroupMetricKey.values()) { 618 Set<String> attKeys = new HashSet<>(attributes.keySet()); 619 for (String attKey : attKeys) { 620 if (attKey.startsWith(groupKey.toString() + ":")) { 621 String value = attributes.remove(attKey); 622 String group = attKey.split(":", 2)[1]; 623 if (groupKey.shouldAdd()) { 624 try { 625 InvocationMetricLogger.addInvocationMetrics( 626 groupKey, group, Long.parseLong(value)); 627 } catch (NumberFormatException e) { 628 CLog.d( 629 "Key %s doesn't have a number value, was: %s.", 630 groupKey, value); 631 InvocationMetricLogger.addInvocationMetrics( 632 groupKey, group, value); 633 } 634 } else { 635 InvocationMetricLogger.addInvocationMetrics(groupKey, group, value); 636 } 637 attributes.remove(attKey); 638 } 639 } 640 } 641 for (InvocationMetricKey key : InvocationMetricKey.values()) { 642 if (!attributes.containsKey(key.toString())) { 643 continue; 644 } 645 String val = attributes.remove(key.toString()); 646 if (key.shouldAdd()) { 647 try { 648 InvocationMetricLogger.addInvocationMetrics(key, Long.parseLong(val)); 649 } catch (NumberFormatException e) { 650 CLog.d("Key %s doesn't have a number value, was: %s.", key, val); 651 // If it's not a number then, let the string concatenate 652 InvocationMetricLogger.addInvocationMetrics(key, val); 653 } 654 } else { 655 InvocationMetricLogger.addInvocationMetrics(key, val); 656 } 657 attributes.remove(key.toString()); 658 } 659 if (attributes.containsKey(TfObjectTracker.TF_OBJECTS_TRACKING_KEY)) { 660 String val = attributes.get(TfObjectTracker.TF_OBJECTS_TRACKING_KEY); 661 for (String pair : Splitter.on(",").split(val)) { 662 if (!pair.contains("=")) { 663 continue; 664 } 665 String[] pairSplit = pair.split("="); 666 try { 667 TfObjectTracker.directCount(pairSplit[0], Long.parseLong(pairSplit[1])); 668 } catch (NumberFormatException e) { 669 CLog.e(e); 670 continue; 671 } 672 } 673 attributes.remove(TfObjectTracker.TF_OBJECTS_TRACKING_KEY); 674 } 675 infos.get(0).addBuildAttributes(attributes); 676 } 677 } 678 } 679 680 /** 681 * Returns the start time associated with the invocation start event from the subprocess 682 * invocation. 683 */ getStartTime()684 public Long getStartTime() { 685 return mStartTime; 686 } 687 688 /** Returns the test that is currently in progress. */ getCurrentTest()689 public TestDescription getCurrentTest() { 690 return mCurrentTestCase; 691 } 692 693 /** Returns whether or not an invocation failed was reported. */ reportedInvocationFailed()694 public boolean reportedInvocationFailed() { 695 return (mReportedInvocationFailedEventInfo != null); 696 } 697 698 /** Returns reported invocation failure event info. */ getReportedInvocationFailedEventInfo()699 public InvocationFailedEventInfo getReportedInvocationFailedEventInfo() { 700 return mReportedInvocationFailedEventInfo; 701 } 702 703 /** Complete and close any left open events */ completeModuleEvents()704 public void completeModuleEvents() { 705 if (mCurrentRunName == null && mCurrentModuleContext != null) { 706 String moduleId = 707 mCurrentModuleContext 708 .getAttributes() 709 .getUniqueMap() 710 .get(ModuleDefinition.MODULE_ID); 711 mListener.testRunStarted(moduleId, 0); 712 } 713 if (mCurrentTestCase != null) { 714 FailureDescription failure = 715 FailureDescription.create( 716 "Run was interrupted after starting, results are incomplete."); 717 mListener.testFailed(mCurrentTestCase, failure); 718 mListener.testEnded(mCurrentTestCase, new HashMap<String, Metric>()); 719 } 720 if (mCurrentModuleContext != null || mCurrentRunName != null) { 721 FailureDescription failure = 722 FailureDescription.create( 723 "Run was interrupted after starting, results are incomplete.", 724 FailureStatus.INFRA_FAILURE); 725 mListener.testRunFailed(failure); 726 mListener.testRunEnded(0L, new HashMap<String, Metric>()); 727 mCurrentRunName = null; 728 } 729 if (mCurrentModuleContext != null) { 730 mListener.testModuleEnded(); 731 } 732 } 733 } 734