Duplicate reads

[callistino]

When reading from a stream with the client's readEventsForward I'm getting duplicates.

With the following examples/write5.php example file:

<?php

use EventLoop\EventLoop;
use Ramsey\Uuid\Uuid;
use Rxnet\EventStore\Data\WriteEventsCompleted;
use Rxnet\EventStore\NewEvent\JsonEvent;

require __DIR__ . '/../vendor/autoload.php';

$eventStore = new \Rxnet\EventStore\EventStore();
$eventStore->connect()
    ->subscribe(
        function () use ($eventStore) {
            echo "connected \n";
            \Rx\Observable::range(0, 5)
                ->flatMap(
                    function () use ($eventStore) {
                        echo 'Write: ';

                        return $eventStore->write('domain-test.fr', [
                            new JsonEvent('/truc/chose', ['id' => Uuid::uuid4()]),
                        ]);
                    }
                )
                ->flatMap(
                    function (WriteEventsCompleted $eventsCompleted) {
                        echo "Last event number {$eventsCompleted->getLastEventNumber()} on commit position {$eventsCompleted->getCommitPosition()} \n";

                        return \Rx\Observable::of($eventsCompleted);
                    }
                )
                // Wait for all writes
                ->toArray()
                ->do(
                    function (array $eventsCompleted) {
                        echo 'Wrote: ' . count($eventsCompleted) . " events.\n";
                    }
                )->subscribe(
                    function () {
                        echo "stopping\n";
                        EventLoop::getLoop()->stop();
                    },
                    function ($e) {
                        echo $e->getMessage();
                    },
                    function () {
                        EventLoop::getLoop()->stop();
                    }
                );

        });

EventLoop::getLoop()->run();

When you run:

➜ php examples/write5.php
connected
received 38790828d77e4b14a9da5764834bf0d9  0@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received bce894abdbce41d3a1a18da176bb5d7e  1@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 4bd2565eb577446dab8661330d732e33  2@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 3211ebce47704b24af9d853f6a52f0a2  3@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 9ced39cb506e4d26a9508ad519210648  4@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 38790828d77e4b14a9da5764834bf0d9  0@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received bce894abdbce41d3a1a18da176bb5d7e  1@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 4bd2565eb577446dab8661330d732e33  2@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 3211ebce47704b24af9d853f6a52f0a2  3@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 9ced39cb506e4d26a9508ad519210648  4@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
Read: 10 events.
stopping

If we then do a readAll we'll get 10 events back instead of 5:

➜ php examples/readAll.php
connected
received 38790828d77e4b14a9da5764834bf0d9  0@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received bce894abdbce41d3a1a18da176bb5d7e  1@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 4bd2565eb577446dab8661330d732e33  2@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 3211ebce47704b24af9d853f6a52f0a2  3@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 9ced39cb506e4d26a9508ad519210648  4@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 50584da0e0254d50b3dbca0d5e7f45cd  5@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received cfe7f6bf008b460a8847abe8001fed01  6@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received ee52820d8cd347a0afeb828b9572062e  7@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received 8153964af7d342c493008059ce1c6b6d  8@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received a5f0755126544ca480a73ce836dbe6ca  9@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received 38790828d77e4b14a9da5764834bf0d9  0@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received bce894abdbce41d3a1a18da176bb5d7e  1@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 4bd2565eb577446dab8661330d732e33  2@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 3211ebce47704b24af9d853f6a52f0a2  3@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 9ced39cb506e4d26a9508ad519210648  4@domain-test.fr /truc/chose created at 2018-08-29T20:06:18+00:00
received 50584da0e0254d50b3dbca0d5e7f45cd  5@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received cfe7f6bf008b460a8847abe8001fed01  6@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received ee52820d8cd347a0afeb828b9572062e  7@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received 8153964af7d342c493008059ce1c6b6d  8@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00
received a5f0755126544ca480a73ce836dbe6ca  9@domain-test.fr /truc/chose created at 2018-08-29T20:10:57+00:00

[Th3Mouk]

Hello @callistino

Is this issue still topical ? I can't reproduce the case on 3.0

[callistino]

thanks for taking a look @Th3Mouk. I have some local changes made in the mean time but I'll go back and do a test from scratch again and post results. Just give me at least today.

[callistino]

I can't reproduce either on 2.3, I'm on 7.1 and I can't upgrade at the moment since we are going through a product launch. I'll be closing.

[callistino]

Further tests in prod revealed that this issue still exists in 2.x branch and posibly 3.x too. I've drilled down the issue to this line src/Rxnet/EventStore/EventStore.php:570 when it reads the last page. I've deleted the line and the issue doesn't happen. I don't want to assume anything about observables since I learn more about them everyday. The duplicates only happen on the last page.

I'm using a catchup subscription to read events and it works fine as long as it get's to the first "catchup" point. If I try to write more events while the catchup is running, that's when I see the issue AND the subscription completes too which is not what I thought it should do and please correct me if I'm wrong.

How to reproduce:

1. Write some events with the examples/write.php script. I modified to only write 50 events.
2. Start the catchup subscription script in examples/catchup.php script and let it finish.
3. Write some more events.

Issues

• There will be duplicate reads. You can find then on the first read and even harder to find on read while writing. On my prod system, duplicates are not back to back and on big reads they are sparse enough that it's be hard to find them with the eye. I had to write to a file and sort the lines to easily show.

  ...
  received b1dc207b53a248bf86695708ea214872  98@domain-test.fr /foo/bar created at 2019-04-08T12:27:11+00:00
  received e9b7d7787cec432793354761d003e371  99@domain-test.fr /foo/pub created at 2019-04-08T12:27:11+00:00
  received 8d3bfe1900114f13baaf14ed0c528c06  0@domain-test.fr /foo/bar created at 2019-04-08T12:27:11+00:00
  received 944d09670f3644108abe5b8fe10d9f78  1@domain-test.fr /foo/pub created at 2019-04-08T12:27:11+00:00
  ...

• Catchup subscription exits. Sometimes it even exits before reading all available events.
• Starting the subscription again will read all events in order without duplicating them. But then it will duplicate new events after more writes before stoping again.

Posible solution

Like I mentioned before, I commented out this src/Rxnet/EventStore/EventStore.php:570 and all works fine. I don't know what other places this may break but I haven't seen an issue anywhere else.

This still doesn't fix the issue of the stopping subscription, I've had to add the script to supervisor in order to restart it.

[morrislaptop]

FWIW I'm experiencing this as well