commit 8cb2f9ce08c9d2cf8b0a302c4a8467dd66c4ac06
author vadimt <vadimt@google.com> Thu Apr 09 13:02:34 2020 -0700
committer vadimt <vadimt@google.com> Thu Apr 09 13:02:48 2020 -0700
tree ef075f58e227c429e2be6552c2d0bce6ac06c5d1
parent e8fade91407da6722329fa2a36204618804692de

Adding tracing for apparently skipping verifiable events

Bug: 153670015
Change-Id: I481c095f1245ba4252eb07e08b4130c857dd6e72

tests/tapl/com/android/launcher3/tapl/LogEventChecker.java

diff --git a/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java b/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java
index 49901ea..78dfc36 100644
--- a/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java
+++ b/tests/tapl/com/android/launcher3/tapl/LogEventChecker.java
@@ -44,6 +44,7 @@
 
     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 @@
             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 @@
 
             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 @@
             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(