Add framework for reliably reproducing race conditions.
Bug: 120628042
Test: RaceConditionReproducerTest
Change-Id: Id658e2b0da6af186b76501ff16edbd135dda3c9b
diff --git a/src/com/android/launcher3/util/RaceConditionTracker.java b/src/com/android/launcher3/util/RaceConditionTracker.java
new file mode 100644
index 0000000..8eafb55
--- /dev/null
+++ b/src/com/android/launcher3/util/RaceConditionTracker.java
@@ -0,0 +1,38 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.launcher3.util;
+
+/**
+ * Event tracker for reliably reproducing race conditions in tests.
+ * The app should call onEvent() for events that the test will try to reproduce in all possible
+ * orders.
+ */
+public class RaceConditionTracker {
+ public interface EventProcessor {
+ void onEvent(String eventName);
+ }
+
+ private static EventProcessor sEventProcessor;
+
+ static void setEventProcessor(EventProcessor eventProcessor) {
+ sEventProcessor = eventProcessor;
+ }
+
+ public static void onEvent(String eventName) {
+ if (sEventProcessor != null) sEventProcessor.onEvent(eventName);
+ }
+}
diff --git a/tests/src/com/android/launcher3/util/RaceConditionReproducer.java b/tests/src/com/android/launcher3/util/RaceConditionReproducer.java
new file mode 100644
index 0000000..c4350de
--- /dev/null
+++ b/tests/src/com/android/launcher3/util/RaceConditionReproducer.java
@@ -0,0 +1,406 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.launcher3.util;
+
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
+
+import android.os.Handler;
+import android.os.HandlerThread;
+import android.util.Log;
+
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.Collection;
+import java.util.HashMap;
+import java.util.HashSet;
+import java.util.List;
+import java.util.Map;
+import java.util.Set;
+import java.util.concurrent.Semaphore;
+import java.util.concurrent.TimeUnit;
+
+/**
+ * Event processor for reliably reproducing multithreaded apps race conditions in tests.
+ *
+ * The app notifies us about “events” that happen in its threads. The race condition test runs the
+ * test action multiple times (aka iterations), trying to generate all possible permutations of
+ * these events. It keeps a set of all seen event sequences and steers the execution towards
+ * executing events in previously unseen order. It does it by postponing execution of threads that
+ * would lead to an already seen sequence.
+ *
+ * Each iteration has 3 parts (phases).
+ * Phase 1. Picking a previously seen event subsequence that we believe can have previously unseen
+ * continuations. Reproducing this sequence by pausing threads that would lead to other sequences.
+ * Phase 2. Trying to generate previously unseen continuation of the sequence from Phase 1. We need
+ * one new event after that sequence. All threads leading to seen continuations will be postponed
+ * for some short period of time. The phase ends once the new event is registered, or after the
+ * period of time ends (in which case we declare that the sequence can’t have new continuations).
+ * Phase 3. Releasing all threads and letting the test iteration run till its end.
+ *
+ * The iterations end when all seen paths have been declared “uncontinuable”.
+ */
+public class RaceConditionReproducer implements RaceConditionTracker.EventProcessor {
+ private static final String TAG = "RaceConditionReproducer";
+ private static final long SHORT_TIMEOUT_MS = 2000;
+ private static final long LONG_TIMEOUT_MS = 60000;
+ // Handler used to resume postponed events.
+ private static final Handler POSTPONED_EVENT_RESUME_HANDLER = createEventResumeHandler();
+
+ private static Handler createEventResumeHandler() {
+ final HandlerThread thread = new HandlerThread("RaceConditionEventResumer");
+ thread.start();
+ return new Handler(thread.getLooper());
+ }
+
+ /**
+ * Event in a particular sequence of events. A node in the prefix tree of all seen event
+ * sequences.
+ */
+ private class EventNode {
+ // Events that were seen just after this event.
+ private final Map<String, EventNode> mNextEvents = new HashMap<>();
+ // Whether we believe that further iterations will not be able to add more events to
+ // mNextEvents.
+ private boolean mStoppedAddingChildren = false;
+
+ private void debugDump(StringBuilder sb, int indent, String name) {
+ for (int i = 0; i < indent; ++i) sb.append('.');
+ sb.append(!mStoppedAddingChildren ? "+" : "-");
+ sb.append(" : ");
+ sb.append(name);
+ if (mLastRegisteredEvent == this) sb.append(" <");
+ sb.append('\n');
+
+ for (String key : mNextEvents.keySet()) {
+ mNextEvents.get(key).debugDump(sb, indent + 2, key);
+ }
+ }
+
+ /** Number of leaves in the subtree with this node as a root. */
+ private int numberOfLeafNodes() {
+ if (mNextEvents.isEmpty()) return 1;
+
+ int leaves = 0;
+ for (String event : mNextEvents.keySet()) {
+ leaves += mNextEvents.get(event).numberOfLeafNodes();
+ }
+ return leaves;
+ }
+
+ /**
+ * Whether we believe that further iterations will not be able add nodes to the subtree with
+ * this node as a root.
+ */
+ private boolean stoppedAddingChildrenToTree() {
+ if (!mStoppedAddingChildren) return false;
+
+ for (String event : mNextEvents.keySet()) {
+ if (!mNextEvents.get(event).stoppedAddingChildrenToTree()) return false;
+ }
+ return true;
+ }
+
+ /**
+ * In the subtree with this node as a root, tries finding a node where we may have a
+ * chance to add new children.
+ * If succeeds, returns true and fills 'path' with the sequence of events to that node;
+ * otherwise returns false.
+ */
+ private boolean populatePathToGrowthPoint(List<String> path) {
+ for (String event : mNextEvents.keySet()) {
+ if (mNextEvents.get(event).populatePathToGrowthPoint(path)) {
+ path.add(0, event);
+ return true;
+ }
+ }
+ if (!mStoppedAddingChildren) {
+ mStoppedAddingChildren = true;
+ return true;
+ }
+ return false;
+ }
+ }
+
+ // Starting point of all event sequences; the root of the prefix tree representation all
+ // sequences generated by test iterations. A test iteration can add nodes int it.
+ private EventNode mRoot = new EventNode();
+ // During a test iteration, the last event that was registered.
+ private EventNode mLastRegisteredEvent;
+ // Length of the current sequence of registered events for the current test iteration.
+ private int mRegisteredEventCount = 0;
+ // During the first part of a test iteration, we go to a specific node under mRoot by
+ // 'playing back' mSequenceToFollow. During this part, all events that don't belong to this
+ // sequence get postponed.
+ private List<String> mSequenceToFollow = new ArrayList<>();
+ // Collection of events that got postponed, with corresponding wait objects used to let them go.
+ private Map<String, Semaphore> mPostponedEvents = new HashMap<>();
+ // Callback to run by POSTPONED_EVENT_RESUME_HANDLER, used to let go of all currently
+ // postponed events.
+ private Runnable mResumeAllEventsCallback;
+ // String representation of the sequence of events registered so far for the current test
+ // iteration. After registering any event, we output it to the log. The last output before
+ // the test failure can be later played back to reliable reproduce the exact sequence of
+ // events that broke the test.
+ // Format: EV1|EV2|...\EVN
+ private StringBuilder mCurrentSequence;
+ // When not null, we are in a repro mode. We run only one test iteration, and are trying to
+ // reproduce the event sequence represented by this string. The format is same as for
+ // mCurrentSequence.
+ private final String mReproString;
+
+ /* Constructor for a normal test. */
+ public RaceConditionReproducer() {
+ mReproString = null;
+ }
+
+ /**
+ * Constructor for reliably reproducing a race condition failure. The developer should find in
+ * the log the latest "Repro sequence:" record and locally modify the test by passing that
+ * string to the constructor. Running the test will have only one iteration that will reliably
+ * "play back" that sequence.
+ */
+ public RaceConditionReproducer(String reproString) {
+ mReproString = reproString;
+ }
+
+ public synchronized String getCurrentSequenceString() {
+ return mCurrentSequence.toString();
+ }
+
+ /**
+ * Starts a new test iteration. Events reported via RaceConditionTracker.onEvent before this
+ * call will be ignored.
+ */
+ public synchronized void startIteration() {
+ mLastRegisteredEvent = mRoot;
+ mRegisteredEventCount = 0;
+ mCurrentSequence = new StringBuilder();
+ Log.d(TAG, "Repro sequence: " + mCurrentSequence);
+ mSequenceToFollow = mReproString != null ?
+ parseReproString(mReproString) : generateSequenceToFollowLocked();
+ Log.e(TAG, "---- Start of iteration; state:\n" + dumpStateLocked());
+ checkIfCompletedSequenceToFollowLocked();
+ RaceConditionTracker.setEventProcessor(this);
+ }
+
+ /**
+ * Ends a new test iteration. Events reported via RaceConditionTracker.onEvent after this call
+ * will be ignored.
+ * Returns whether we need more iterations.
+ */
+ public synchronized boolean finishIteration() {
+ RaceConditionTracker.setEventProcessor(null);
+ runResumeAllEventsCallbackLocked();
+ assertTrue("Non-empty postponed events", mPostponedEvents.isEmpty());
+
+ // No events came after mLastRegisteredEvent. It doesn't make sense to come to it again
+ // because we won't see new continuations.
+ mLastRegisteredEvent.mStoppedAddingChildren = true;
+ Log.e(TAG, "---- End of iteration; state:\n" + dumpStateLocked());
+ if (mReproString != null) {
+ assertTrue("Repro mode: failed to reproduce the sequence",
+ mCurrentSequence.toString().startsWith(mReproString));
+ }
+ // If we are in a repro mode, we need only one iteration. Otherwise, continue if the tree
+ // has prospective growth points.
+ return mReproString == null && !mRoot.stoppedAddingChildrenToTree();
+ }
+
+ private static List<String> parseReproString(String reproString) {
+ return Arrays.asList(reproString.split("\\|"));
+ }
+
+ /**
+ * Called when the app issues an event.
+ */
+ @Override
+ public void onEvent(String event) {
+ final Semaphore waitObject = tryRegisterEvent(event);
+ if (waitObject != null) {
+ waitUntilCanRegister(event, waitObject);
+ }
+ }
+
+ /**
+ * Registers an event issued by the app and returns null or decides that the event must be
+ * postponed, and returns an object to wait on.
+ */
+ private synchronized Semaphore tryRegisterEvent(String event) {
+ Log.d(TAG, "Event issued by the app: " + event);
+
+ if (mRegisteredEventCount < mSequenceToFollow.size()) {
+ // We are in the first part of the iteration. We only register events that follow the
+ // mSequenceToFollow and postponing all other events.
+ if (event.equals(mSequenceToFollow.get(mRegisteredEventCount))) {
+ // The event is the next one expected in the sequence. Register it.
+ registerEventLocked(event);
+
+ // If there are postponed events that could continue the sequence, register them.
+ while (mRegisteredEventCount < mSequenceToFollow.size() &&
+ mPostponedEvents.containsKey(
+ mSequenceToFollow.get(mRegisteredEventCount))) {
+ registerPostponedEventLocked(mSequenceToFollow.get(mRegisteredEventCount));
+ }
+
+ // Perhaps we just completed the required sequence...
+ checkIfCompletedSequenceToFollowLocked();
+ } else {
+ // The event is not the next one in the sequence. Postpone it.
+ return createWaitObjectForPostponedEventLocked(event);
+ }
+ } else if (mRegisteredEventCount == mSequenceToFollow.size()) {
+ // The second phase of the iteration. We have just registered the whole
+ // mSequenceToFollow, and want to add previously not seen continuations for the last
+ // node in the sequence aka 'growth point'.
+ if (!mLastRegisteredEvent.mNextEvents.containsKey(event) || mReproString != null) {
+ // The event was never seen as a continuation for the current node.
+ // Or we are in repro mode, in which case we are not in business of generating
+ // new sequences after we've played back the required sequence.
+ // Register it immediately.
+ registerEventLocked(event);
+ } else {
+ // The event was seen as a continuation for the current node. Postpone it, hoping
+ // that a new event will come from other threads.
+ return createWaitObjectForPostponedEventLocked(event);
+ }
+ } else {
+ // The second phase of the iteration. We are past the growth point and register
+ // everything that comes.
+ registerEventLocked(event);
+ }
+ return null;
+ }
+
+ /** Called when there are chances that we just have registered the whole mSequenceToFollow. */
+ private void checkIfCompletedSequenceToFollowLocked() {
+ if (mRegisteredEventCount == mSequenceToFollow.size()) {
+ // We just entered the second phase of the iteration. We have just registered the
+ // whole mSequenceToFollow, and want to add previously not seen continuations for the
+ // last node in the sequence aka 'growth point'. All seen continuations will be
+ // postponed for SHORT_TIMEOUT_MS. At the end of this time period, we'll let them go.
+ scheduleResumeAllEventsLocked();
+
+ // Among the events that were postponed during the first stage, there may be an event
+ // that wasn't seen after the current. If so, register it immediately because this
+ // creates a new sequence.
+ final Set<String> keys = new HashSet<>(mPostponedEvents.keySet());
+ keys.removeAll(mLastRegisteredEvent.mNextEvents.keySet());
+ if (!keys.isEmpty()) {
+ registerPostponedEventLocked(keys.iterator().next());
+ }
+ }
+ }
+
+ private Semaphore createWaitObjectForPostponedEventLocked(String event) {
+ final Semaphore waitObject = new Semaphore(0);
+ assertTrue("Event already postponed: " + event, !mPostponedEvents.containsKey(event));
+ mPostponedEvents.put(event, waitObject);
+ return waitObject;
+ }
+
+ private void waitUntilCanRegister(String event, Semaphore waitObject) {
+ try {
+ assertTrue("Never registered event: " + event,
+ waitObject.tryAcquire(LONG_TIMEOUT_MS, TimeUnit.MILLISECONDS));
+ } catch (InterruptedException e) {
+ fail("Wait was interrupted");
+ }
+ }
+
+ /** Schedules resuming all postponed events after SHORT_TIMEOUT_MS */
+ private void scheduleResumeAllEventsLocked() {
+ assertTrue(mResumeAllEventsCallback == null);
+ mResumeAllEventsCallback = this::allEventsResumeCallback;
+ POSTPONED_EVENT_RESUME_HANDLER.postDelayed(mResumeAllEventsCallback, SHORT_TIMEOUT_MS);
+ }
+
+ private synchronized void allEventsResumeCallback() {
+ assertTrue("In callback, but callback is not set", mResumeAllEventsCallback != null);
+ mResumeAllEventsCallback = null;
+ registerPostponedEventsLocked(new HashSet<>(mPostponedEvents.keySet()));
+ }
+
+ private void registerPostponedEventsLocked(Collection<String> events) {
+ for (String event : events) {
+ registerPostponedEventLocked(event);
+ }
+ }
+
+ private void registerPostponedEventLocked(String event) {
+ mPostponedEvents.remove(event).release();
+ registerEventLocked(event);
+ }
+
+ private void registerEventLocked(String event) {
+ Log.d(TAG, "Actually registering event: " + event);
+ EventNode next = mLastRegisteredEvent.mNextEvents.get(event);
+ if (next == null) {
+ // This event wasn't seen after mLastRegisteredEvent.
+ next = new EventNode();
+ mLastRegisteredEvent.mNextEvents.put(event, next);
+ mLastRegisteredEvent.mStoppedAddingChildren = false;
+ }
+
+ mLastRegisteredEvent = next;
+ mRegisteredEventCount++;
+
+ if (mCurrentSequence.length() > 0) mCurrentSequence.append("|");
+ mCurrentSequence.append(event);
+ Log.d(TAG, "Repro sequence: " + mCurrentSequence);
+
+ if (mRegisteredEventCount == mSequenceToFollow.size() + 1) {
+ // We just entered the third phase of the iteration, i.e. registered an event after
+ // the growth point. Now we can let go of all postponed events.
+ runResumeAllEventsCallbackLocked();
+ }
+ }
+
+ private void runResumeAllEventsCallbackLocked() {
+ if (mResumeAllEventsCallback != null) {
+ POSTPONED_EVENT_RESUME_HANDLER.removeCallbacks(mResumeAllEventsCallback);
+ mResumeAllEventsCallback.run();
+ }
+ }
+
+ private CharSequence dumpStateLocked() {
+ StringBuilder sb = new StringBuilder();
+
+ sb.append("Sequence to follow: ");
+ for (String event : mSequenceToFollow) sb.append(" " + event);
+ sb.append(".\n");
+ sb.append("Registered event count: " + mRegisteredEventCount);
+
+ sb.append("\nPostponed events: ");
+ for (String event : mPostponedEvents.keySet()) sb.append(" " + event);
+ sb.append(".");
+
+ sb.append("\nNodes: \n");
+ mRoot.debugDump(sb, 0, "");
+ return sb;
+ }
+
+ public int numberOfLeafNodes() {
+ return mRoot.numberOfLeafNodes();
+ }
+
+ private List<String> generateSequenceToFollowLocked() {
+ ArrayList<String> sequence = new ArrayList<>();
+ mRoot.populatePathToGrowthPoint(sequence);
+ return sequence;
+ }
+}
diff --git a/tests/src/com/android/launcher3/util/RaceConditionReproducerTest.java b/tests/src/com/android/launcher3/util/RaceConditionReproducerTest.java
new file mode 100644
index 0000000..7dde5cc
--- /dev/null
+++ b/tests/src/com/android/launcher3/util/RaceConditionReproducerTest.java
@@ -0,0 +1,125 @@
+/*
+ * Copyright (C) 2018 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.launcher3.util;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
+
+import androidx.test.filters.LargeTest;
+import androidx.test.runner.AndroidJUnit4;
+
+import org.junit.Ignore;
+import org.junit.Test;
+import org.junit.runner.RunWith;
+
+@LargeTest
+@RunWith(AndroidJUnit4.class)
+public class RaceConditionReproducerTest {
+ private final static String SOME_VALID_SEQUENCE_3_3 = "B1|A1|A2|B2|A3|B3";
+
+ private static int factorial(int n) {
+ int res = 1;
+ for (int i = 2; i <= n; ++i) res *= i;
+ return res;
+ }
+
+ private static void run3_3_TestAction() throws InterruptedException {
+ Thread tb = new Thread(() -> {
+ RaceConditionTracker.onEvent("B1");
+ RaceConditionTracker.onEvent("B2");
+ RaceConditionTracker.onEvent("B3");
+ });
+ tb.start();
+
+ RaceConditionTracker.onEvent("A1");
+ RaceConditionTracker.onEvent("A2");
+ RaceConditionTracker.onEvent("A3");
+
+ tb.join();
+ }
+
+ @Test
+ @Ignore // The test is too long for continuous testing.
+ // 2 threads, 3 events each.
+ public void test3_3() throws Exception {
+ final RaceConditionReproducer eventProcessor = new RaceConditionReproducer();
+ boolean sawTheValidSequence = false;
+
+ for (; ; ) {
+ eventProcessor.startIteration();
+ run3_3_TestAction();
+ final boolean needMoreIterations = eventProcessor.finishIteration();
+
+ sawTheValidSequence = sawTheValidSequence ||
+ SOME_VALID_SEQUENCE_3_3.equals(eventProcessor.getCurrentSequenceString());
+
+ if (!needMoreIterations) break;
+ }
+
+ assertEquals("Wrong number of leaf nodes",
+ factorial(3 + 3) / (factorial(3) * factorial(3)),
+ eventProcessor.numberOfLeafNodes());
+ assertTrue(sawTheValidSequence);
+ }
+
+ @Test
+ // 2 threads, 3 events each; reproducing a particular event sequence.
+ public void test3_3_ReproMode() throws Exception {
+ final RaceConditionReproducer eventProcessor = new RaceConditionReproducer(
+ SOME_VALID_SEQUENCE_3_3);
+
+ eventProcessor.startIteration();
+ run3_3_TestAction();
+ assertTrue(!eventProcessor.finishIteration());
+ assertEquals(SOME_VALID_SEQUENCE_3_3, eventProcessor.getCurrentSequenceString());
+
+ assertEquals("Wrong number of leaf nodes", 1, eventProcessor.numberOfLeafNodes());
+ }
+
+ @Test
+ @Ignore // The test is too long for continuous testing.
+ // 2 threads with 2 events; 1 thread with 1 event.
+ public void test2_1_2() throws Exception {
+ final RaceConditionReproducer eventProcessor = new RaceConditionReproducer();
+
+ for (; ; ) {
+ eventProcessor.startIteration();
+ Thread tb = new Thread(() -> {
+ RaceConditionTracker.onEvent("B1");
+ RaceConditionTracker.onEvent("B2");
+ });
+ tb.start();
+
+ Thread tc = new Thread(() -> {
+ RaceConditionTracker.onEvent("C1");
+ });
+ tc.start();
+
+ RaceConditionTracker.onEvent("A1");
+ RaceConditionTracker.onEvent("A2");
+
+ tb.join();
+ tc.join();
+
+ if (!eventProcessor.finishIteration()) break;
+ }
+
+ assertEquals("Wrong number of leaf nodes",
+ factorial(2 + 2 + 1) / (factorial(2) * factorial(2) * factorial(1)),
+ eventProcessor.numberOfLeafNodes());
+ }
+}