We noticed one of our subscriptions against a category stream ($ce-xxxx) was being sent the same events many times but cannot explain why it’s happening. It seems to be the event store retry mechanism as the subscription is set with a retry count of 10 and we typically see each event 11 times total.
We added debug/trace logs to the eventAppeared method on the subscription, starting a Stopwatch right at the beginning of the method and measuring the time taken to reach the Acknowledge call for the event (note we aren’t using auto ack) and then logging it, and we mostly see <100ms total time, yet our logs show that same event turning up again about 30 seconds later.
Note the timeout setting on the subscription is 10000ms, if we increase it enough (say 30000ms) the retries stop happening.
Its worth saying that there are occasional events that do take maybe a couple of seconds to process, but we don’t understand why that would cause events that we process quickly to be “timed out” and retried by ES. Indeed, we tried replacing our event processing code entirely with Task.Delay(40) and still see the same event more than once.
Could there be some way the Ack isn’t processed in time on the server leading to these retries? Are there any detailed logs we can look at further (even to confirm what we are seeing is timeout & retry)?