From 8cb2f9ce08c9d2cf8b0a302c4a8467dd66c4ac06 Mon Sep 17 00:00:00 2001
From: vadimt <vadimt@google.com>
Date: Thu, 9 Apr 2020 13:02:34 -0700
Subject: [PATCH] Adding tracing for apparently skipping verifiable events

Bug: 153670015
Change-Id: I481c095f1245ba4252eb07e08b4130c857dd6e72
---
 .../com/android/launcher3/tapl/LogEventChecker.java  | 12 +++++++++---
 1 file changed, 9 insertions(+), 3 deletions(-)

diff --git a/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java b/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java
index 49901ea868..78dfc361f6 100644
--- a/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java
+++ b/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java
@@ -44,6 +44,7 @@ public class LogEventChecker {
 
     private static final String START_PREFIX = "START_READER ";
     private static final String FINISH_PREFIX = "FINISH_READER ";
+    private static final String SKIP_EVENTS_TAG = "b/153670015";
 
     private volatile CountDownLatch mFinished;
 
@@ -72,6 +73,7 @@ public class LogEventChecker {
             mFinished = null;
         }
         mEvents.clear();
+        Log.d(SKIP_EVENTS_TAG, "Cleared events");
         mExpectedEvents.clear();
         mEventsCounter.drainPermits();
         final String id = UUID.randomUUID().toString();
@@ -89,27 +91,30 @@ public class LogEventChecker {
 
             try (BufferedReader reader = new BufferedReader(new InputStreamReader(
                     Runtime.getRuntime().exec(cmd).getInputStream()))) {
-                for (;;) {
+                for (; ; ) {
                     // Skip everything before the next start command.
-                    for (;;) {
+                    for (; ; ) {
                         final String event = reader.readLine();
                         if (event.contains(TestProtocol.TAPL_EVENTS_TAG)
                                 && event.contains(mStartCommand)) {
+                            Log.d(SKIP_EVENTS_TAG, "Read start: " + event);
                             break;
                         }
                     }
 
                     // Store all actual events until the finish command.
-                    for (;;) {
+                    for (; ; ) {
                         final String event = reader.readLine();
                         if (event.contains(TestProtocol.TAPL_EVENTS_TAG)) {
                             if (event.contains(mFinishCommand)) {
                                 mFinished.countDown();
+                                Log.d(SKIP_EVENTS_TAG, "Read finish: " + event);
                                 break;
                             } else {
                                 final Matcher matcher = EVENT_LOG_ENTRY.matcher(event);
                                 if (matcher.find()) {
                                     mEvents.add(matcher.group("sequence"), matcher.group("event"));
+                                    Log.d(SKIP_EVENTS_TAG, "Read event: " + event);
                                     mEventsCounter.release();
                                 }
                             }
@@ -154,6 +159,7 @@ public class LogEventChecker {
             String sequence = expectedEvents.getKey();
 
             List<String> actual = new ArrayList<>(mEvents.getNonNull(sequence));
+            Log.d(SKIP_EVENTS_TAG, "Verifying events");
             final int mismatchPosition = getMismatchPosition(expectedEvents.getValue(), actual);
             hasMismatches = hasMismatches || mismatchPosition != -1;
             formatSequenceWithMismatch(