EventSorter: Don't eagerly process events after satisfying deps

The previous EventSorter incorrectly handled a much later event having
a dependency on a much earlier event. For example, with a set of events
in the following natural order:

 E1, E2, ..., E50

Say E50 depends on E1. The old sort algorithm would emit E1, see that
E50 now has no outstanding dependencies, and immediately emit E50,
before emitting E2. This is topologically correct but really screws
with the natural order.

This interacts very poorly with the later code that ensures commits in
the NoteDb graph have monotonic timestamps. One realistic scenario,
using the example above, is if E1 and E2 are PatchSetEvents and E50 is a
ChangeMessageEvent on PS1. The sorted result was [E1, E50, E2, ...],
and E2's timestamp would be squashed to be after E50's, which is way
off from the original timestamp of the ReviewDb PatchSet.

Fix this by not eagerly processing dependant events (E50) eagerly.
Instead, just insert them back in the queue for later processing.
Additionally, use a PriorityQueue to preserve the original order as
much as possible.

In addition to more comprehensive small tests in EventSorterTest, add a
real test in ChangeRebuilderIT with a scenario like the one described
above with data very much like we've observed in the wild.

Change-Id: Ia57fa7a72c3f48c1c87b43d0de45bc73f11f8fba

gerrit-acceptance-tests/src/test/java/com/google/gerrit/acceptance/server/notedb/ChangeRebuilderIT.java

@@ -72,6 +72,7 @@ import com.google.gerrit.server.notedb.NoteDbUpdateManager;
 import com.google.gerrit.server.notedb.TestChangeRebuilderWrapper;
 import com.google.gerrit.server.notedb.rebuild.ChangeRebuilder.NoPatchSetsException;
 import com.google.gerrit.server.project.Util;
+import com.google.gerrit.server.query.change.ChangeData;
 import com.google.gerrit.testutil.ConfigSuite;
 import com.google.gerrit.testutil.NoteDbChecker;
 import com.google.gerrit.testutil.NoteDbMode;
@@ -1071,6 +1072,22 @@ public class ChangeRebuilderIT extends AbstractDaemonTest {
     assertThat(pub.get(1).getRealAuthor()).isEqualTo(admin.id);
   }
 
+  @Test
+  public void laterEventsDependingOnEarlierPatchSetDontIntefereWithOtherPatchSets()
+      throws Exception {
+    PushOneCommit.Result r1 = createChange();
+    ChangeData cd = r1.getChange();
+    Change.Id id = cd.getId();
+    amendChange(cd.change().getKey().get());
+    TestTimeUtil.incrementClock(90, TimeUnit.DAYS);
+
+    ReviewInput rin = ReviewInput.approve();
+    rin.message = "Some very late message on PS1";
+    gApi.changes().id(id.get()).revision(1).review(rin);
+
+    checker.rebuildAndCheckChanges(id);
+  }
+
   private void assertChangesReadOnly(RestApiException e) throws Exception {
     Throwable cause = e.getCause();
     assertThat(cause).isInstanceOf(UpdateException.class);

gerrit-server/src/main/java/com/google/gerrit/server/notedb/rebuild/Event.java

@@ -40,7 +40,13 @@ abstract class Event implements Comparable<Event> {
   final Account.Id realUser;
   final String tag;
   final boolean predatesChange;
+
+  /**
+   * Dependencies of this event; other events that must happen before this
+   * one.
+   */
   final List<Event> deps;
+
   Timestamp when;
   PatchSet.Id psId;
 

gerrit-server/src/main/java/com/google/gerrit/server/notedb/rebuild/EventSorter.java

@@ -25,6 +25,7 @@ import com.google.common.collect.SetMultimap;
 import java.util.Collections;
 import java.util.LinkedHashSet;
 import java.util.List;
+import java.util.PriorityQueue;
 
 /**
  * Helper to sort a list of events.
@@ -63,12 +64,12 @@ class EventSorter {
 
   void sort() {
     // First pass: sort by natural order.
-    Collections.sort(out);
+    PriorityQueue<Event> todo = new PriorityQueue<>(out);
 
     // Populate waiting map after initial sort to preserve natural order.
     waiting = ArrayListMultimap.create();
     deps = HashMultimap.create();
-    for (Event e : out) {
+    for (Event e : todo) {
       for (Event d : e.deps) {
         deps.put(e, d);
         waiting.put(d, e);
@@ -77,8 +78,8 @@ class EventSorter {
 
     // Second pass: enforce dependencies.
     int size = out.size();
-    for (Event e : out) {
+    while (!todo.isEmpty()) {
-      process(e);
+      process(todo.remove(), todo);
     }
     checkState(sorted.size() == size,
         "event sort expected %s elements, got %s", size, sorted.size());
@@ -88,20 +89,26 @@ class EventSorter {
     out.addAll(sorted);
   }
 
-  void process(Event e) {
+  void process(Event e, PriorityQueue<Event> todo) {
     if (sorted.contains(e)) {
+      return; // Already emitted.
+    }
+    if (!deps.get(e).isEmpty()) {
+      // Not all events that e depends on have been emitted yet. Ignore e for
+      // now; it will get added back to the queue in the block below once its
+      // last dependency is processed.
       return;
     }
-    // If all events that e depends on have been emitted:
+
-    //  - e can be emitted.
+    // All events that e depends on have been emitted, so e can be emitted.
-    //  - remove e from the dependency set of all events waiting on e, and then
+    sorted.add(e);
-    //    re-process those events in case they can now be emitted.
+
-    if (deps.get(e).isEmpty()) {
+    // Remove e from the dependency set of all events waiting on e, and add
-      sorted.add(e);
+    // those events back to the queue in the original priority order for
-      for (Event w : waiting.get(e)) {
+    // reconsideration.
-        deps.get(w).remove(e);
+    for (Event w : waiting.get(e)) {
-        process(w);
+      deps.get(w).remove(e);
-      }
+      todo.add(w);
     }
   }
 }

gerrit-server/src/test/java/com/google/gerrit/server/notedb/rebuild/EventSorterTest.java

@@ -15,8 +15,10 @@
 package com.google.gerrit.server.notedb.rebuild;
 
 import static com.google.common.truth.Truth.assertThat;
+import static java.util.stream.Collectors.toList;
 import static org.junit.Assert.fail;
 
+import com.google.common.collect.Collections2;
 import com.google.common.collect.Lists;
 import com.google.gerrit.common.TimeUtil;
 import com.google.gerrit.reviewdb.client.Account;
@@ -29,8 +31,10 @@ import org.junit.Before;
 import org.junit.Test;
 
 import java.sql.Timestamp;
+import java.util.ArrayList;
 import java.util.List;
 import java.util.concurrent.TimeUnit;
+import java.util.stream.Stream;
 
 public class EventSorterTest {
   private class TestEvent extends Event {
@@ -50,6 +54,12 @@ public class EventSorterTest {
     void apply(ChangeUpdate update) {
       throw new UnsupportedOperationException();
     }
+
+    @SuppressWarnings("deprecation")
+    @Override
+    public String toString() {
+      return "E{" + when.getSeconds() + '}';
+    }
   }
 
   private Timestamp changeCreatedOn;
@@ -66,33 +76,73 @@ public class EventSorterTest {
     Event e2 = new TestEvent(TimeUtil.nowTs());
     Event e3 = new TestEvent(TimeUtil.nowTs());
 
-    List<Event> events = events(e2, e1, e3);
+    for (List<Event> events : Collections2.permutations(events(e1, e2, e3))) {
-    new EventSorter(events).sort();
+      assertSorted(events, events(e1, e2, e3));
-    assertThat(events).containsExactly(e1, e2, e3).inOrder();
+    }
-  }
-
-  @Test
-  public void topoSortNoChange() {
-    Event e1 = new TestEvent(TimeUtil.nowTs());
-    Event e2 = new TestEvent(TimeUtil.nowTs());
-    Event e3 = new TestEvent(TimeUtil.nowTs());
-    e2.addDep(e1);
-
-    List<Event> events = events(e2, e1, e3);
-    new EventSorter(events).sort();
-    assertThat(events).containsExactly(e1, e2, e3).inOrder();
   }
 
   @Test
   public void topoSortOneDep() {
-    Event e1 = new TestEvent(TimeUtil.nowTs());
+    List<Event> es;
-    Event e2 = new TestEvent(TimeUtil.nowTs());
-    Event e3 = new TestEvent(TimeUtil.nowTs());
-    e1.addDep(e2);
 
-    List<Event> events = events(e2, e3, e1);
+    // Input list is 0,1,2
-    new EventSorter(events).sort();
+
-    assertThat(events).containsExactly(e2, e1, e3).inOrder();
+    // 0 depends on 1 => 1,0,2
+    es = threeEventsOneDep(0, 1);
+    assertSorted(es, events(es, 1, 0, 2));
+
+    // 1 depends on 0 => 0,1,2
+    es = threeEventsOneDep(1, 0);
+    assertSorted(es, events(es, 0, 1, 2));
+
+    // 0 depends on 2 => 1,2,0
+    es = threeEventsOneDep(0, 2);
+    assertSorted(es, events(es, 1, 2, 0));
+
+    // 2 depends on 0 => 0,1,2
+    es = threeEventsOneDep(2, 0);
+    assertSorted(es, events(es, 0, 1, 2));
+
+    // 1 depends on 2 => 0,2,1
+    es = threeEventsOneDep(1, 2);
+    assertSorted(es, events(es, 0, 2, 1));
+
+    // 2 depends on 1 => 0,1,2
+    es = threeEventsOneDep(2, 1);
+    assertSorted(es, events(es, 0, 1, 2));
+  }
+
+  private List<Event> threeEventsOneDep(int depFromIdx, int depOnIdx) {
+    List<Event> events = Lists.newArrayList(
+        new TestEvent(TimeUtil.nowTs()),
+        new TestEvent(TimeUtil.nowTs()),
+        new TestEvent(TimeUtil.nowTs()));
+    events.get(depFromIdx).addDep(events.get(depOnIdx));
+    return events;
+  }
+
+  @Test
+  public void lastEventDependsOnFirstEvent() {
+    List<Event> events = new ArrayList<>();
+    for (int i = 0; i < 20; i++) {
+      events.add(new TestEvent(TimeUtil.nowTs()));
+    }
+    events.get(events.size() - 1).addDep(events.get(0));
+    assertSorted(events, events);
+  }
+
+  @Test
+  public void firstEventDependsOnLastEvent() {
+    List<Event> events = new ArrayList<>();
+    for (int i = 0; i < 20; i++) {
+      events.add(new TestEvent(TimeUtil.nowTs()));
+    }
+    events.get(0).addDep(events.get(events.size() - 1));
+
+    List<Event> expected = new ArrayList<>();
+    expected.addAll(events.subList(1, events.size()));
+    expected.add(events.get(0));
+    assertSorted(events, expected);
   }
 
   @Test
@@ -105,9 +155,9 @@ public class EventSorterTest {
     e2.addDep(e3);
     e3.addDep(e4);
 
-    List<Event> events = events(e1, e2, e3, e4);
+    assertSorted(
-    new EventSorter(events).sort();
+        events(e1, e2, e3, e4),
-    assertThat(events).containsExactly(e4, e3, e2, e1).inOrder();
+        events(e4, e3, e2, e1));
   }
 
   @Test
@@ -121,9 +171,9 @@ public class EventSorterTest {
     e2.addDep(e3);
 
     // Processing 3 pops 2, processing 4 pops 1.
-    List<Event> events = events(e2, e3, e1, e4);
+    assertSorted(
-    new EventSorter(events).sort();
+        events(e2, e3, e1, e4),
-    assertThat(events).containsExactly(e3, e2, e4, e1).inOrder();
+        events(e3, e2, e4, e1));
   }
 
   @Test
@@ -137,9 +187,9 @@ public class EventSorterTest {
     e3.addDep(e4);
 
     // Processing 4 pops 1, 2, 3 in natural order.
-    List<Event> events = events(e4, e3, e2, e1);
+    assertSorted(
-    new EventSorter(events).sort();
+        events(e4, e3, e2, e1),
-    assertThat(events).containsExactly(e4, e1, e2, e3).inOrder();
+        events(e4, e1, e2, e3));
   }
 
   @Test
@@ -150,9 +200,9 @@ public class EventSorterTest {
     // Implementation is not really defined, but infinite looping would be bad.
     // According to current implementation details, 2 pops 1, 1 pops 2 which was
     // already seen.
-    List<Event> events = events(e2, e1);
+    assertSorted(
-    new EventSorter(events).sort();
+        events(e2, e1),
-    assertThat(events).containsExactly(e1, e2).inOrder();
+        events(e1, e2));
   }
 
   @Test
@@ -171,7 +221,19 @@ public class EventSorterTest {
     }
   }
 
-  private List<Event> events(Event... es) {
+  private static List<Event> events(Event... es) {
     return Lists.newArrayList(es);
   }
+
+  private static List<Event> events(List<Event> in, Integer... indexes) {
+    return Stream.of(indexes).map(in::get).collect(toList());
+  }
+
+  private static void assertSorted(List<Event> unsorted, List<Event> expected) {
+    List<Event> actual = new ArrayList<>(unsorted);
+    new EventSorter(actual).sort();
+    assertThat(actual)
+        .named("sorted" + unsorted)
+        .isEqualTo(expected);
+  }
 }