EventStore.append_to_stream is not able to append more than 1000 events to a new stream.

[thomasdziedzic]

While investigating the cause for commanded/commanded#554 I discovered that the issue might be deeper in the stack. So I wrote a test case for EventStore and was able to reproduce that issue in this project.

I wrote the following reproducible test case:

diff --git a/test/append_to_stream_test.exs b/test/append_to_stream_test.exs
index d3c3e9c..bd6d625 100644
--- a/test/append_to_stream_test.exs
+++ b/test/append_to_stream_test.exs
@@ -15,6 +15,16 @@ defmodule EventStore.AppendToStreamTest do
       assert length(events) == 3
     end
 
+    test "should handle more than 1000 events" do
+      stream_uuid = UUID.uuid4()
+      events = EventFactory.create_events(1001)
+
+      assert :ok = EventStore.append_to_stream(stream_uuid, :any_version, events)
+
+      assert {:ok, events} = EventStore.read_stream_forward(stream_uuid)
+      assert length(events) == 1001
+    end
+
     test "concurrently should succeed" do
       stream_uuid = UUID.uuid4()
       events = EventFactory.create_events(1)

This fails with:

$ mix test test/append_to_stream_test.exs:18
Excluding tags: [:test]
Including tags: [location: {"test/append_to_stream_test.exs", 18}]



  1) test append to new stream using `:any_version` should handle more than 1000 events (EventStore.AppendToStreamTest)
     test/append_to_stream_test.exs:18
     match (=) failed
     code:  assert :ok = EventStore.append_to_stream(stream_uuid, :any_version, events)
     left:  :ok
     right: {:error, :already_retried_once}
     stacktrace:
       test/append_to_stream_test.exs:22: (test)

     The following output was logged:
     
     09:54:49.482 [warning] Failed to append events to stream "689078a4-9a9b-46e8-b67e-917c13540a33" due to: :duplicate_stream_uuid
     
     09:54:49.529 [warning] Failed to append events to stream "689078a4-9a9b-46e8-b67e-917c13540a33" due to: :duplicate_stream_uuid
     

Finished in 0.3 seconds (0.00s async, 0.3s sync)
13 tests, 1 failure, 12 excluded

[thomasdziedzic]

In fact I didn't need to write a test, I found an already failing test in the suite:
Note the line number is off due to my patch above. The actual test is located here: https://github.com/commanded/eventstore/blob/master/test/append_to_stream_test.exs#L166

$ mix test test/append_to_stream_test.exs:176
Excluding tags: [:test]
Including tags: [location: {"test/append_to_stream_test.exs", 176}]



  1) test should append many events to a stream (EventStore.AppendToStreamTest)
     test/append_to_stream_test.exs:176
     match (=) failed
     code:  assert :ok = EventStore.append_to_stream(stream_uuid, 0, events, timeout: :infinity)
     left:  :ok
     right: {:error, :already_retried_once}
     stacktrace:
       test/append_to_stream_test.exs:180: (test)

     The following output was logged:
     
     10:00:55.951 [warning] Failed to append events to stream "7afe5369-4386-4f81-823c-22e8ced37697" due to: :duplicate_stream_uuid
     
     10:00:56.029 [warning] Failed to append events to stream "7afe5369-4386-4f81-823c-22e8ced37697" due to: :duplicate_stream_uuid
     

Finished in 0.4 seconds (0.00s async, 0.4s sync)
13 tests, 1 failure, 12 excluded

[thomasdziedzic]

I think I found out why this regression was introduced. CI runs mix test.all but I didn't see any logs of the slow tests being run in CI. I tried running mix test.all locally and indeed they all pass because the slow tests don't run. I tried to narrow the problem down and found that if I have test.all defined as "test.all": ["test", "test --only slow"], then the slow tests don't run. But if I have "test.all": ["test --only slow"], then the slow tests do run and the expected failure shows up. I'm not exactly sure why the slow tests get skipped when there's a previous test that gets run.