Expected: 20 But was: 10 at EventStoreSynchroniser.Tests.SynchronizationTests.CheckEventsAreEquivalent(IReadOnlyCollection`1 eventsFromReplication, IReadOnlyCollection`1 eventsFromSource) in C:\root\Utilities\Hscic.EventStore.Synchroniser.Service\trunk\src\EventStoreSynchroniser.Tests\SynchronizationTests.cs:line 191 at EventStoreSynchroniser.Tests.SynchronizationTests.IfRecordsOnSourceNotOnReplication_ReplicationIsUpdated_EvenWhenSourceClusterDropsOut() in C:\root\Utilities\Hscic.EventStore.Synchroniser.Service\trunk\src\EventStoreSynchroniser.Tests\SynchronizationTests.cs:line 120 11/05/2016 15:50:22 - TEST CODE:: Posted 10 new events to source 11/05/2016 15:50:22 - TEST CODE:: Synchroniser service starting 11/05/2016 15:50:22: Trying to connect to source [10,14:50:22.510,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.StartConnectionMessage.. [16,14:50:22.510,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': StartConnection. [16,14:50:22.510,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': DiscoverEndPoint. [20,14:50:22.515,INFO] Discovering: found best choice [127.0.0.1:60112,n/a] (Master). [20,14:50:22.515,INFO] Discovering attempt 1/10 successful: best candidate is [127.0.0.1:60112, n/a]. [20,14:50:22.515,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.EstablishTcpConnectionMessage.. [04,14:50:22.515,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': EstablishTcpConnection to [127.0.0.1:60112]. [10,14:50:22.516,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartConnectionMessage.. [04,14:50:22.516,DEBUG] TcpPackageConnection: connected to [127.0.0.1:60112, L127.0.0.1:16249, {ab7bba12-354f-4644-9765-757d28eca85e}]. [16,14:50:22.516,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartConnection. [16,14:50:22.516,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': DiscoverEndPoint. [04,14:50:22.516,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionEstablishedMessage.. [04,14:50:22.516,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': TCP connection to [127.0.0.1:60112, L127.0.0.1:16249, {ab7bba12-354f-4644-9765-757d28eca85e}] established.. [16,14:50:22.516,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.EstablishTcpConnectionMessage.. [16,14:50:22.516,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': EstablishTcpConnection to [127.0.0.1:64112]. [16,14:50:22.517,DEBUG] TcpPackageConnection: connected to [127.0.0.1:64112, L127.0.0.1:16250, {5e9bd979-5599-49fa-a7b6-65cdab27ef30}]. [16,14:50:22.517,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionEstablishedMessage.. [16,14:50:22.517,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': TCP connection to [127.0.0.1:64112, L127.0.0.1:16250, {5e9bd979-5599-49fa-a7b6-65cdab27ef30}] established.. [17,14:50:22.518,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.518,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package Authenticated, 532b0905-4e86-4a96-bf30-98f57e0e805a.. 11/05/2016 15:50:22: Subscribing to event store source streams 11/05/2016 15:50:22: setting up processing of 288984f0-1f52-4482-a575-d11242cc2014 [16,14:50:22.523,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [20,14:50:22.524,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation enqueue ReadEventOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, -1, 00:00:02.. [20,14:50:22.524,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': EnqueueOperation WAITING for Operation ReadEventOperation (ee1533c6-9cc7-428d-81db-28cb307b5ecd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:22.524, last updated: 14:50:22.524.. [17,14:50:22.560,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:22.560,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package Authenticated, 68526bdb-b40c-40a4-976a-a97f62a3d027.. [04,14:50:22.733,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package ReadEvent, ee1533c6-9cc7-428d-81db-28cb307b5ecd, Operation ReadEventOperation (ee1533c6-9cc7-428d-81db-28cb307b5ecd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:22.524, last updated: 14:50:22.730.. [17,14:50:22.854,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:22.854,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package ReadEventCompleted, ee1533c6-9cc7-428d-81db-28cb307b5ecd.. 11/05/2016 15:50:22: Processing stream 288984f0-1f52-4482-a575-d11242cc2014 from the start. [04,14:50:22.865,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: starting... 11/05/2016 15:50:22: Connection established [04,14:50:22.865,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (NoStream), Operation ReadEventOperation (ee1533c6-9cc7-428d-81db-28cb307b5ecd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:22.524, last updated: 14:50:22.730. [04,14:50:22.865,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation ReadEventOperation (ee1533c6-9cc7-428d-81db-28cb307b5ecd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:22.524, last updated: 14:50:22.730. [16,14:50:22.866,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: running... [16,14:50:22.866,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: pulling events... [16,14:50:22.867,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [04,14:50:22.868,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': StartOperation schedule ReadStreamEventsForwardOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 0, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, -1, 00:00:02.. [04,14:50:22.869,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': ExecuteOperation package ReadStreamEventsForward, f408eae7-fa39-477b-9230-8fcdc8e95e50, Operation ReadStreamEventsForwardOperation (f408eae7-fa39-477b-9230-8fcdc8e95e50): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 0, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:22.868, last updated: 14:50:22.868.. [17,14:50:22.884,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.884,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package ReadStreamEventsForwardCompleted, f408eae7-fa39-477b-9230-8fcdc8e95e50.. [16,14:50:22.895,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation ReadStreamEventsForwardOperation (f408eae7-fa39-477b-9230-8fcdc8e95e50): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 0, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:22.868, last updated: 14:50:22.868. [16,14:50:22.895,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': RemoveOperation SUCCEEDED for Operation ReadStreamEventsForwardOperation (f408eae7-fa39-477b-9230-8fcdc8e95e50): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 0, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:22.868, last updated: 14:50:22.868. 11/05/2016 15:50:22: Processing event number 0 (4d1f0199-5749-4876-bd41-9d433b2c117d) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.899,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.899,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.899,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, edddb0f0-cc48-4e34-98a4-b8e6b88b2f7f, Operation AppendToStreamOperation (edddb0f0-cc48-4e34-98a4-b8e6b88b2f7f): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.899, last updated: 14:50:22.899.. [17,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, edddb0f0-cc48-4e34-98a4-b8e6b88b2f7f.. [04,14:50:22.923,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 0, test @ 0). [16,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (edddb0f0-cc48-4e34-98a4-b8e6b88b2f7f): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.899, last updated: 14:50:22.899. 11/05/2016 15:50:22: Processing event number 1 (eed2d7d3-4977-442b-b2ac-fb66ff6f10fe) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (edddb0f0-cc48-4e34-98a4-b8e6b88b2f7f): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.899, last updated: 14:50:22.899. [16,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.923,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, 426742b5-9cb3-4aa0-bf50-206330d6464e, Operation AppendToStreamOperation (426742b5-9cb3-4aa0-bf50-206330d6464e): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.923, last updated: 14:50:22.923.. [17,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, 426742b5-9cb3-4aa0-bf50-206330d6464e.. [04,14:50:22.924,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 1, test @ 1). [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (426742b5-9cb3-4aa0-bf50-206330d6464e): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.923, last updated: 14:50:22.923. 11/05/2016 15:50:22: Processing event number 2 (ea260248-a965-4e9c-8849-fa0cec52c2df) from stream 288984f0-1f52-4482-a575-d11242cc2014 [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (426742b5-9cb3-4aa0-bf50-206330d6464e): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.923, last updated: 14:50:22.923. [04,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, 0d8bf557-1974-45f4-8c47-ede0fcc5dd9d, Operation AppendToStreamOperation (0d8bf557-1974-45f4-8c47-ede0fcc5dd9d): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.924, last updated: 14:50:22.924.. [17,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, 0d8bf557-1974-45f4-8c47-ede0fcc5dd9d.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (0d8bf557-1974-45f4-8c47-ede0fcc5dd9d): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.924, last updated: 14:50:22.924. [04,14:50:22.924,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 2, test @ 2). [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (0d8bf557-1974-45f4-8c47-ede0fcc5dd9d): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.924, last updated: 14:50:22.924. 11/05/2016 15:50:22: Processing event number 3 (fc5acb01-7c5c-4fce-b442-1253320ab4ad) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.924,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, c7f511b8-0ff7-4831-9f5f-8f95740f2bcd, Operation AppendToStreamOperation (c7f511b8-0ff7-4831-9f5f-8f95740f2bcd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.924, last updated: 14:50:22.924.. [17,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, c7f511b8-0ff7-4831-9f5f-8f95740f2bcd.. [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (c7f511b8-0ff7-4831-9f5f-8f95740f2bcd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.924, last updated: 14:50:22.924. [04,14:50:22.925,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 3, test @ 3). [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (c7f511b8-0ff7-4831-9f5f-8f95740f2bcd): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.924, last updated: 14:50:22.924. 11/05/2016 15:50:22: Processing event number 4 (1c156315-eca7-40cb-9b44-d28d2a23a7b0) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, f9409345-f479-4cf8-98d0-bdbae2005466, Operation AppendToStreamOperation (f9409345-f479-4cf8-98d0-bdbae2005466): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.925, last updated: 14:50:22.925.. [17,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, f9409345-f479-4cf8-98d0-bdbae2005466.. [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (f9409345-f479-4cf8-98d0-bdbae2005466): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.925, last updated: 14:50:22.925. [04,14:50:22.925,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 4, test @ 4). [16,14:50:22.925,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (f9409345-f479-4cf8-98d0-bdbae2005466): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.925, last updated: 14:50:22.925. 11/05/2016 15:50:22: Processing event number 5 (028e74b4-9918-4eea-ba7a-859a3a943c2d) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, ece725d8-26aa-4b72-b3c6-f16063e899ec, Operation AppendToStreamOperation (ece725d8-26aa-4b72-b3c6-f16063e899ec): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.926, last updated: 14:50:22.926.. [17,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, ece725d8-26aa-4b72-b3c6-f16063e899ec.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (ece725d8-26aa-4b72-b3c6-f16063e899ec): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.926, last updated: 14:50:22.926. [04,14:50:22.926,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 5, test @ 5). [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (ece725d8-26aa-4b72-b3c6-f16063e899ec): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.926, last updated: 14:50:22.926. 11/05/2016 15:50:22: Processing event number 6 (a0d8923e-5053-4e95-94eb-8b031a6827d5) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, a2c7a915-7613-41ad-a41f-9acf2fb066ad, Operation AppendToStreamOperation (a2c7a915-7613-41ad-a41f-9acf2fb066ad): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.926, last updated: 14:50:22.926.. [17,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, a2c7a915-7613-41ad-a41f-9acf2fb066ad.. [16,14:50:22.926,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (a2c7a915-7613-41ad-a41f-9acf2fb066ad): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.926, last updated: 14:50:22.926. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (a2c7a915-7613-41ad-a41f-9acf2fb066ad): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.926, last updated: 14:50:22.926. [04,14:50:22.926,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 6, test @ 6). 11/05/2016 15:50:22: Processing event number 7 (93aa64cb-0f39-4e12-86a3-0735110e7ad1) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, dd6fb39b-2811-417c-a218-e85986b400c3, Operation AppendToStreamOperation (dd6fb39b-2811-417c-a218-e85986b400c3): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.927, last updated: 14:50:22.927.. [17,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, dd6fb39b-2811-417c-a218-e85986b400c3.. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (dd6fb39b-2811-417c-a218-e85986b400c3): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.927, last updated: 14:50:22.927. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (dd6fb39b-2811-417c-a218-e85986b400c3): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.927, last updated: 14:50:22.927. [04,14:50:22.927,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 7, test @ 7). 11/05/2016 15:50:22: Processing event number 8 (3096e9ca-432d-4def-b82d-9f8a402425c1) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.927,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, f9bde0d3-8493-4ec2-b12c-405426b64ee3, Operation AppendToStreamOperation (f9bde0d3-8493-4ec2-b12c-405426b64ee3): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.927, last updated: 14:50:22.927.. [17,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, f9bde0d3-8493-4ec2-b12c-405426b64ee3.. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (f9bde0d3-8493-4ec2-b12c-405426b64ee3): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.927, last updated: 14:50:22.927. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (f9bde0d3-8493-4ec2-b12c-405426b64ee3): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.927, last updated: 14:50:22.927. [04,14:50:22.928,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 8, test @ 8). 11/05/2016 15:50:22: Processing event number 9 (44c143c5-9d8f-452b-84a1-8e606346cc1c) from stream 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': StartOperation schedule AppendToStreamOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, -1, 00:00:02.. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': ExecuteOperation package WriteEvents, b2ce26ac-8e56-4ca1-a906-db7032350697, Operation AppendToStreamOperation (b2ce26ac-8e56-4ca1-a906-db7032350697): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.928, last updated: 14:50:22.928.. [17,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package WriteEventsCompleted, b2ce26ac-8e56-4ca1-a906-db7032350697.. [04,14:50:22.928,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processed event (288984f0-1f52-4482-a575-d11242cc2014, 9, test @ 9). [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation AppendToStreamOperation (b2ce26ac-8e56-4ca1-a906-db7032350697): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.928, last updated: 14:50:22.928. [04,14:50:22.928,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: finished reading events, nextReadEventNumber = 10. [16,14:50:22.928,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': RemoveOperation SUCCEEDED for Operation AppendToStreamOperation (b2ce26ac-8e56-4ca1-a906-db7032350697): Stream: 288984f0-1f52-4482-a575-d11242cc2014, ExpectedVersion: -2, retry count: 0, created: 14:50:22.928, last updated: 14:50:22.928. [16,14:50:22.930,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: subscribing... [16,14:50:22.930,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.StartSubscriptionMessage.. [04,14:50:22.933,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': StartSubscription fire VolatileSubscriptionOperation, EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, -1, 00:00:02.. [04,14:50:22.936,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': StartSubscription SUBSCRIBING Subscription VolatileSubscriptionOperation (6fccd5eb-9129-45c9-ab2f-edd5a38f03b3): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: False, retry count: 0, created: 14:50:22.933, last updated: 14:50:22.934.. [17,14:50:22.941,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.941,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package SubscriptionConfirmation, 6fccd5eb-9129-45c9-ab2f-edd5a38f03b3.. [16,14:50:22.947,DEBUG] Subscription {6fccd5eb-9129-45c9-ab2f-edd5a38f03b3} to 288984f0-1f52-4482-a575-d11242cc2014: subscribed at CommitPosition: 2540, EventNumber: 9. [16,14:50:22.948,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage SUBSCRIPTION DECISION Subscribed (SubscriptionConfirmation), Subscription VolatileSubscriptionOperation (6fccd5eb-9129-45c9-ab2f-edd5a38f03b3): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: False, retry count: 0, created: 14:50:22.933, last updated: 14:50:22.934. [04,14:50:22.949,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: pulling events (if left)... [04,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [04,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': StartOperation schedule ReadStreamEventsForwardOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 10, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, -1, 00:00:02.. [04,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': ExecuteOperation package ReadStreamEventsForward, 9cf34de9-6ea4-4e96-a128-f1790f9b8444, Operation ReadStreamEventsForwardOperation (9cf34de9-6ea4-4e96-a128-f1790f9b8444): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 10, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:22.949, last updated: 14:50:22.949.. [17,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package ReadStreamEventsForwardCompleted, 9cf34de9-6ea4-4e96-a128-f1790f9b8444.. [16,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation ReadStreamEventsForwardOperation (9cf34de9-6ea4-4e96-a128-f1790f9b8444): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 10, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:22.949, last updated: 14:50:22.949. [04,14:50:22.949,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: finished reading events, nextReadEventNumber = 10. [16,14:50:22.949,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': RemoveOperation SUCCEEDED for Operation ReadStreamEventsForwardOperation (9cf34de9-6ea4-4e96-a128-f1790f9b8444): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 10, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:22.949, last updated: 14:50:22.949. [04,14:50:22.951,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processing live events... [04,14:50:22.951,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: hooking to connection.Connected [17,14:50:24.119,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [21,14:50:24.119,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package HeartbeatResponseCommand, b5462025-c120-4a7c-948c-60a51cda15d4.. [24,14:50:24.146,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [22,14:50:24.146,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package HeartbeatResponseCommand, 36287ee1-49b6-433f-8d60-60fa255df401.. [24,14:50:26.519,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:26.519,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package HeartbeatRequestCommand, 08d75f62-5043-43ea-8d3e-b8d65e481b37.. [24,14:50:26.519,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:26.519,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package HeartbeatRequestCommand, b67b709c-c9b3-4b91-a202-4b7f428afe83.. [23,14:50:27.407,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:27.407,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': HandleTcpPackage connId ab7bba12-354f-4644-9765-757d28eca85e, package HeartbeatResponseCommand, d5f3d44e-48c1-479d-996d-4348f0a3f54f.. [24,14:50:27.467,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:27.467,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package HeartbeatResponseCommand, 1e3288ec-7941-415b-b061-d7d74e9032b4.. 11/05/2016 15:50:27 - TEST CODE:: killed all 3 nodes [24,14:50:27.550,INFO] ClientAPI TcpConnection closed [14:50:27.550: N127.0.0.1:60112, L127.0.0.1:16249, {ab7bba12-354f-4644-9765-757d28eca85e}]: Received bytes: 1726, Sent bytes: 348 Send calls: 7, callbacks: 7 Receive calls: 8, callbacks: 8 Close reason: [ConnectionReset] Socket receive error [24,14:50:27.550,DEBUG] TcpPackageConnection: connection [127.0.0.1:60112, L127.0.0.1:16249, {ab7bba12-354f-4644-9765-757d28eca85e}] was closed with error: ConnectionReset. [24,14:50:27.550,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionClosedMessage.. [04,14:50:27.558,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': TCP connection to [127.0.0.1:60112, L127.0.0.1:16249, {ab7bba12-354f-4644-9765-757d28eca85e}] closed.. [04,14:50:27.560,DEBUG] Subscription {6fccd5eb-9129-45c9-ab2f-edd5a38f03b3} to 288984f0-1f52-4482-a575-d11242cc2014: closing subscription, reason: ConnectionClosed, exception: EventStore.ClientAPI.Exceptions.ConnectionClosedException: Connection was closed.... [04,14:50:27.567,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: dropping subscription, reason: ConnectionClosed EventStore.ClientAPI.Exceptions.ConnectionClosedException: Connection was closed.. [04,14:50:27.568,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: requesting stop... [04,14:50:27.568,DEBUG] Catch-up Subscription to {0}: unhooking from connection.Connected. 11/05/2016 15:50:27: Subscription dropped because ConnectionClosed, exception: Connection was closed. [20,14:50:28.294,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': TimerTick checking reconnection.... [20,14:50:28.295,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': CloseConnection, reason Reconnection limit reached., exception .. [20,14:50:28.303,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': CloseTcpConnection. [20,14:50:28.303,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': IGNORED (_state: Closed, _conn.ID: {ab7bba12-354f-4644-9765-757d28eca85e}, conn.ID: {ab7bba12-354f-4644-9765-757d28eca85e}): TCP connection to [127.0.0.1:60112, L127.0.0.1:16249] closed.. [20,14:50:28.304,INFO] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': Closed. Reason: Reconnection limit reached... 11/05/2016 15:50:28: disconnected from source. Disposing source connection. [20,14:50:28.305,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': enqueueing message EventStore.ClientAPI.Internal.CloseConnectionMessage.. 11/05/2016 15:50:29: Trying to connect to source [20,14:50:29.305,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.StartConnectionMessage.. [24,14:50:29.521,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [21,14:50:30.294,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': StartConnection. [21,14:50:30.294,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': DiscoverEndPoint. [24,14:50:30.569,INFO] ClientAPI TcpConnection closed [14:50:30.569: N127.0.0.1:64112, L127.0.0.1:16250, {5e9bd979-5599-49fa-a7b6-65cdab27ef30}]: Received bytes: 476, Sent bytes: 1839 Send calls: 15, callbacks: 15 Receive calls: 17, callbacks: 17 Close reason: [Success] Socket closed [24,14:50:30.569,DEBUG] TcpPackageConnection: connection [127.0.0.1:64112, L127.0.0.1:16250, {5e9bd979-5599-49fa-a7b6-65cdab27ef30}] was closed cleanly. [24,14:50:30.569,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionClosedMessage.. [16,14:50:31.295,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': HandleTcpPackage connId 5e9bd979-5599-49fa-a7b6-65cdab27ef30, package HeartbeatRequestCommand, 14ab8415-5f55-45b6-9911-a3807b53fe8c.. [16,14:50:31.295,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': TCP connection to [127.0.0.1:64112, L127.0.0.1:16250, {5e9bd979-5599-49fa-a7b6-65cdab27ef30}] closed.. [16,14:50:31.496,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': TimerTick checking reconnection.... [16,14:50:31.496,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': CloseConnection, reason Reconnection limit reached., exception .. [16,14:50:31.496,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': CloseTcpConnection. [16,14:50:31.496,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': IGNORED (_state: Closed, _conn.ID: {5e9bd979-5599-49fa-a7b6-65cdab27ef30}, conn.ID: {5e9bd979-5599-49fa-a7b6-65cdab27ef30}): TCP connection to [127.0.0.1:64112, L127.0.0.1:16250] closed.. [16,14:50:31.496,INFO] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': Closed. Reason: Reconnection limit reached... [16,14:50:31.496,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': enqueueing message EventStore.ClientAPI.Internal.CloseConnectionMessage.. [16,14:50:31.496,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.StartConnectionMessage.. [25,14:50:32.294,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': StartConnection. [25,14:50:32.294,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': DiscoverEndPoint. [25,14:50:32.294,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.EstablishTcpConnectionMessage.. [16,14:50:32.295,DEBUG] EventStoreConnection 'ES-3b00fcc5-dbf7-45bb-bd95-d6ab747b2fd6': CloseConnection IGNORED because is ESConnection is CLOSED, reason Connection close requested by client., exception .. [16,14:50:32.295,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': EstablishTcpConnection to [127.0.0.1:64112]. [16,14:50:32.295,DEBUG] TcpPackageConnection: connected to [127.0.0.1:64112, L127.0.0.1:16253, {80f9daa6-9d59-47d0-a26f-56150b193d3b}]. [16,14:50:32.295,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionEstablishedMessage.. [16,14:50:32.295,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': TCP connection to [127.0.0.1:64112, L127.0.0.1:16253, {80f9daa6-9d59-47d0-a26f-56150b193d3b}] established.. [24,14:50:32.298,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [25,14:50:32.298,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package Authenticated, b00505d6-2aca-4141-9107-0c8d4e1e0283.. 11/05/2016 15:50:32 - TEST CODE:: restarted all 3 nodes [21,14:50:33.392,INFO] Discovering attempt 1/10 failed: no candidate found. [23,14:50:33.972,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [27,14:50:33.972,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, 04f2f325-c9d5-40b6-8bbb-8e1ddfb03010.. [21,14:50:35.970,INFO] Discovering: found best choice [127.0.0.1:60112,n/a] (Unknown). [21,14:50:35.970,INFO] Discovering attempt 2/10 successful: best candidate is [127.0.0.1:60112, n/a]. [21,14:50:35.970,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.EstablishTcpConnectionMessage.. [21,14:50:35.970,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': EstablishTcpConnection to [127.0.0.1:60112]. [20,14:50:35.970,DEBUG] EventStoreConnection 'ES-d5055163-7a68-41ca-a8a2-e09dd5c91430': CloseConnection IGNORED because is ESConnection is CLOSED, reason Connection close requested by client., exception .. [21,14:50:35.970,DEBUG] TcpPackageConnection: connected to [127.0.0.1:60112, L127.0.0.1:16293, {c5ee97e2-df33-4bda-b23e-3aa71f1aea60}]. [21,14:50:35.970,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionEstablishedMessage.. [21,14:50:35.970,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': TCP connection to [127.0.0.1:60112, L127.0.0.1:16293, {c5ee97e2-df33-4bda-b23e-3aa71f1aea60}] established.. [23,14:50:36.326,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [21,14:50:36.326,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatRequestCommand, ff9a6741-b009-4838-8eae-53021c00c357.. [23,14:50:36.341,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [26,14:50:36.349,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId c5ee97e2-df33-4bda-b23e-3aa71f1aea60, package NotAuthenticated, d9db29c2-a650-46bc-bd26-88526a2c3cb1.. 11/05/2016 15:50:36: Connection established [23,14:50:37.470,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [25,14:50:37.470,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, c332743a-0210-40e0-8a32-90de60a8085f.. 11/05/2016 15:50:37: Attempting to resub for 288984f0-1f52-4482-a575-d11242cc2014 11/05/2016 15:50:37: setting up processing of 288984f0-1f52-4482-a575-d11242cc2014 [04,14:50:37.643,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [28,14:50:37.643,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': StartOperation schedule ReadEventOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, -1, 00:00:02.. [28,14:50:37.643,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': ExecuteOperation package ReadEvent, 2085dce8-da34-4cf5-9b07-b52c211045eb, Operation ReadEventOperation (2085dce8-da34-4cf5-9b07-b52c211045eb): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:37.643, last updated: 14:50:37.643.. [24,14:50:37.650,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [20,14:50:37.650,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package ReadEventCompleted, 2085dce8-da34-4cf5-9b07-b52c211045eb.. 11/05/2016 15:50:37: Processing stream 288984f0-1f52-4482-a575-d11242cc2014 -> Next event is 10. [20,14:50:37.650,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: starting... [04,14:50:37.650,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: running... [04,14:50:37.650,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: pulling events... [04,14:50:37.650,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [04,14:50:37.650,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': StartOperation schedule ReadStreamEventsForwardOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, -1, 00:00:02.. [04,14:50:37.650,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': ExecuteOperation package ReadStreamEventsForward, a2a577f9-addc-4d1c-b71e-c3d9930fd021, Operation ReadStreamEventsForwardOperation (a2a577f9-addc-4d1c-b71e-c3d9930fd021): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.650, last updated: 14:50:37.650.. [20,14:50:37.651,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation ReadEventOperation (2085dce8-da34-4cf5-9b07-b52c211045eb): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:37.643, last updated: 14:50:37.643. [20,14:50:37.651,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': RemoveOperation SUCCEEDED for Operation ReadEventOperation (2085dce8-da34-4cf5-9b07-b52c211045eb): Stream: 288984f0-1f52-4482-a575-d11242cc2014, EventNumber: -1, ResolveLinkTo: False, RequireMaster: True, retry count: 0, created: 14:50:37.643, last updated: 14:50:37.643. [24,14:50:37.738,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:37.738,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId c5ee97e2-df33-4bda-b23e-3aa71f1aea60, package NotHandled, a2a577f9-addc-4d1c-b71e-c3d9930fd021.. [04,14:50:37.747,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage OPERATION DECISION Reconnect (NotHandled - NotMaster), Operation ReadStreamEventsForwardOperation (a2a577f9-addc-4d1c-b71e-c3d9930fd021): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.650, last updated: 14:50:37.650. [04,14:50:37.748,INFO] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': going to reconnect to [127.0.0.1:62112]. Current endpoint: [127.0.0.1:60112, L127.0.0.1:16293]. [04,14:50:37.748,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': CloseTcpConnection. [04,14:50:37.748,INFO] ClientAPI TcpConnection closed [14:50:37.748: N127.0.0.1:60112, L127.0.0.1:16293, {c5ee97e2-df33-4bda-b23e-3aa71f1aea60}]: Received bytes: 90, Sent bytes: 121 Send calls: 2, callbacks: 2 Receive calls: 3, callbacks: 2 Close reason: [Success] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': going to reconnect to [127.0.0.1:62112]. Current endpoint: [127.0.0.1:60112, L127.0.0.1:16293]. [04,14:50:37.748,DEBUG] TcpPackageConnection: connection [127.0.0.1:60112, L127.0.0.1:16293, {c5ee97e2-df33-4bda-b23e-3aa71f1aea60}] was closed cleanly. [04,14:50:37.748,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionClosedMessage.. [04,14:50:37.748,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': TCP connection to [127.0.0.1:60112, L127.0.0.1:16293, {c5ee97e2-df33-4bda-b23e-3aa71f1aea60}] closed.. [04,14:50:37.748,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': EstablishTcpConnection to [127.0.0.1:62112]. [04,14:50:37.749,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': RemoveOperation SUCCEEDED for Operation ReadStreamEventsForwardOperation (a2a577f9-addc-4d1c-b71e-c3d9930fd021): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.650, last updated: 14:50:37.650. [04,14:50:37.749,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': ScheduleOperationRetry for Operation ReadStreamEventsForwardOperation (a2a577f9-addc-4d1c-b71e-c3d9930fd021): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.650, last updated: 14:50:37.650. [04,14:50:37.749,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': IGNORED (_state: Connecting, _conn.ID: {748e5a8c-2469-4a93-a6f9-35f93592533e}, conn.ID: {c5ee97e2-df33-4bda-b23e-3aa71f1aea60}): TCP connection to [127.0.0.1:60112, L127.0.0.1:16293] closed.. [04,14:50:37.749,DEBUG] TcpPackageConnection: connected to [127.0.0.1:62112, L127.0.0.1:16306, {748e5a8c-2469-4a93-a6f9-35f93592533e}]. [04,14:50:37.749,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionEstablishedMessage.. [04,14:50:37.749,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': TCP connection to [127.0.0.1:62112, L127.0.0.1:16306, {748e5a8c-2469-4a93-a6f9-35f93592533e}] established.. [24,14:50:37.825,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [22,14:50:37.825,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package Authenticated, e950dd6d-efb4-47ab-89f5-3839231892cc.. 11/05/2016 15:50:37: Connection established [22,14:50:37.826,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': retrying, old corrId a2a577f9-addc-4d1c-b71e-c3d9930fd021, operation Operation ReadStreamEventsForwardOperation (8c1cc01f-1c88-4510-a015-470c617f6957): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 1, created: 14:50:37.650, last updated: 14:50:37.650.. [22,14:50:37.826,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': ExecuteOperation package ReadStreamEventsForward, 8c1cc01f-1c88-4510-a015-470c617f6957, Operation ReadStreamEventsForwardOperation (8c1cc01f-1c88-4510-a015-470c617f6957): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 1, created: 14:50:37.650, last updated: 14:50:37.826.. [24,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [28,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package ReadStreamEventsForwardCompleted, 8c1cc01f-1c88-4510-a015-470c617f6957.. [20,14:50:37.836,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: finished reading events, nextReadEventNumber = 9. [20,14:50:37.836,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: subscribing... [20,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.StartSubscriptionMessage.. [28,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage OPERATION DECISION EndOperation (NoStream), Operation ReadStreamEventsForwardOperation (8c1cc01f-1c88-4510-a015-470c617f6957): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 1, created: 14:50:37.650, last updated: 14:50:37.826. [28,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': RemoveOperation SUCCEEDED for Operation ReadStreamEventsForwardOperation (8c1cc01f-1c88-4510-a015-470c617f6957): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 1, created: 14:50:37.650, last updated: 14:50:37.826. [28,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': StartSubscription fire VolatileSubscriptionOperation, EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, -1, 00:00:02.. [28,14:50:37.836,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': StartSubscription SUBSCRIBING Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: False, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836.. [24,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package SubscriptionConfirmation, ca96555a-a082-4b13-badd-c05ce55b057f.. [04,14:50:37.844,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: subscribed at CommitPosition: 773, EventNumber: -1. [04,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION Subscribed (SubscriptionConfirmation), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: False, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [04,14:50:37.844,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: pulling events (if left)... [04,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.StartOperationMessage.. [04,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': StartOperation schedule ReadStreamEventsForwardOperation, Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, -1, 00:00:02.. [04,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': ExecuteOperation package ReadStreamEventsForward, 80eff0ca-d27d-421b-a194-36a37dc64749, Operation ReadStreamEventsForwardOperation (80eff0ca-d27d-421b-a194-36a37dc64749): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.844, last updated: 14:50:37.844.. [24,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [20,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package ReadStreamEventsForwardCompleted, 80eff0ca-d27d-421b-a194-36a37dc64749.. [20,14:50:37.844,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage OPERATION DECISION EndOperation (NoStream), Operation ReadStreamEventsForwardOperation (80eff0ca-d27d-421b-a194-36a37dc64749): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.844, last updated: 14:50:37.844. [20,14:50:37.845,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': RemoveOperation SUCCEEDED for Operation ReadStreamEventsForwardOperation (80eff0ca-d27d-421b-a194-36a37dc64749): Stream: 288984f0-1f52-4482-a575-d11242cc2014, FromEventNumber: 9, MaxCount: 500, ResolveLinkTos: False, RequireMaster: True, retry count: 0, created: 14:50:37.844, last updated: 14:50:37.844. [20,14:50:37.845,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: finished reading events, nextReadEventNumber = 9. [20,14:50:37.845,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: processing live events... [20,14:50:37.845,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: hooking to connection.Connected [23,14:50:39.359,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [22,14:50:39.359,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatResponseCommand, 3104d239-8c12-461c-bc96-7082b10feeb5.. 11/05/2016 15:50:39 - TEST CODE:: Posted 10 new events to source [23,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [26,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [23,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.657,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.658,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.658,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.658,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [23,14:50:39.658,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [26,14:50:39.661,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 0, test @ 875/875). [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.661,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 1, test @ 1060/1060). [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.661,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 2, test @ 1245/1245). [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.661,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 3, test @ 1430/1430). [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.661,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 4, test @ 1615/1615). [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.661,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 5, test @ 1800/1800). [26,14:50:39.661,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.662,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 6, test @ 1985/1985). [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.662,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 7, test @ 2170/2170). [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.662,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 8, test @ 2355/2355). [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package StreamEventAppeared, ca96555a-a082-4b13-badd-c05ce55b057f.. [26,14:50:39.662,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 9, test @ 2540/2540). [26,14:50:39.662,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage SUBSCRIPTION DECISION DoNothing (StreamEventAppeared), Subscription VolatileSubscriptionOperation (ca96555a-a082-4b13-badd-c05ce55b057f): EventStore.ClientAPI.ClientOperations.VolatileSubscriptionOperation, is subscribed: True, retry count: 0, created: 14:50:37.836, last updated: 14:50:37.836. [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 0, test @ 875/875). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 1, test @ 1060/1060). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 2, test @ 1245/1245). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 3, test @ 1430/1430). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 4, test @ 1615/1615). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 5, test @ 1800/1800). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 0, test @ 0). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 6, test @ 1985/1985). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 1, test @ 1). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 2, test @ 2). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 3, test @ 3). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 4, test @ 4). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 5, test @ 5). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 7, test @ 2170/2170). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 6, test @ 6). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 8, test @ 2355/2355). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 7, test @ 7). [04,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: event appeared (288984f0-1f52-4482-a575-d11242cc2014, 9, test @ 2540/2540). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 8, test @ 8). [22,14:50:39.662,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: skipping event (288984f0-1f52-4482-a575-d11242cc2014, 9, test @ 9). [33,14:50:39.993,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [28,14:50:39.993,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, c6085853-34dc-4fec-9855-a9d2556c9c42.. [33,14:50:41.751,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [28,14:50:41.751,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatRequestCommand, 25672e2c-a454-4f53-9c2f-ec61b29b0f1d.. [33,14:50:42.450,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [22,14:50:42.450,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, f4160033-d345-4451-a966-0d4c9d36d09f.. [33,14:50:42.651,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [26,14:50:42.651,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatResponseCommand, 6894d5f6-38ca-4cc8-b5b6-3409839dc3cf.. [24,14:50:44.752,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [29,14:50:44.753,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatRequestCommand, 11db25b7-d384-432c-9d54-71bc0bdff05a.. [33,14:50:44.929,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [29,14:50:44.929,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, 550b3884-d6ed-4ed2-9f56-0081052b0aff.. [33,14:50:45.960,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [21,14:50:45.960,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatResponseCommand, beba2e34-bca9-4045-803f-b923f3ccf0d0.. [33,14:50:47.336,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [29,14:50:47.336,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatRequestCommand, 19846a0a-5ce0-41d9-b40b-4fe0452ee9d8.. [33,14:50:48.225,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [25,14:50:48.225,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, 0bfaf1bb-f386-44ef-9125-2f7ac887353c.. [33,14:50:48.440,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [27,14:50:48.440,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatResponseCommand, c86df7de-c416-4f26-a954-3dca82c22990.. [24,14:50:50.337,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [16,14:50:50.337,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatRequestCommand, 24ac1a6a-045e-4b77-bb1d-c1d9eae4058c.. [24,14:50:50.922,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [21,14:50:50.922,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatResponseCommand, 0ab6987b-b8ab-4eb1-bcb4-3cad17ad115e.. [24,14:50:51.548,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [26,14:50:51.548,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, 6c16813d-a742-44a6-a26e-221ff24ea383.. [24,14:50:53.415,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [27,14:50:53.415,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': HandleTcpPackage connId 748e5a8c-2469-4a93-a6f9-35f93592533e, package HeartbeatResponseCommand, b38c9ef9-318c-4a2c-ab4b-272167e9f631.. [24,14:50:54.038,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.HandleTcpPackageMessage.. [04,14:50:54.038,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': HandleTcpPackage connId 80f9daa6-9d59-47d0-a26f-56150b193d3b, package HeartbeatResponseCommand, be035def-ee42-4e80-b79a-cb457e319563.. 11/05/2016 15:50:54 - TEST CODE:: Got events from replication. Comparing to source. [33,14:50:54.682,INFO] ClientAPI TcpConnection closed [14:50:54.682: N127.0.0.1:62112, L127.0.0.1:16306, {748e5a8c-2469-4a93-a6f9-35f93592533e}]: Received bytes: 2161, Sent bytes: 458 Send calls: 12, callbacks: 12 Receive calls: 16, callbacks: 16 Close reason: [ConnectionReset] Socket receive error [33,14:50:54.682,DEBUG] TcpPackageConnection: connection [127.0.0.1:62112, L127.0.0.1:16306, {748e5a8c-2469-4a93-a6f9-35f93592533e}] was closed with error: ConnectionReset. [33,14:50:54.682,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionClosedMessage.. [24,14:50:54.704,INFO] ClientAPI TcpConnection closed [14:50:54.704: N127.0.0.1:64112, L127.0.0.1:16253, {80f9daa6-9d59-47d0-a26f-56150b193d3b}]: Received bytes: 443, Sent bytes: 354 Send calls: 13, callbacks: 13 Receive calls: 14, callbacks: 14 Close reason: [ConnectionReset] Socket receive error [24,14:50:54.704,DEBUG] TcpPackageConnection: connection [127.0.0.1:64112, L127.0.0.1:16253, {80f9daa6-9d59-47d0-a26f-56150b193d3b}] was closed with error: ConnectionReset. [24,14:50:54.704,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': enqueueing message EventStore.ClientAPI.Internal.TcpConnectionClosedMessage.. [28,14:50:54.739,DEBUG] EventStoreConnection 'ES-c7c3e629-85a7-440a-a4e2-1a1ad36c44a2': TCP connection to [127.0.0.1:62112, L127.0.0.1:16306, {748e5a8c-2469-4a93-a6f9-35f93592533e}] closed.. [28,14:50:54.739,DEBUG] Subscription {ca96555a-a082-4b13-badd-c05ce55b057f} to 288984f0-1f52-4482-a575-d11242cc2014: closing subscription, reason: ConnectionClosed, exception: EventStore.ClientAPI.Exceptions.ConnectionClosedException: Connection was closed.... [28,14:50:54.739,DEBUG] EventStoreConnection 'ES-3bd81714-5a2d-4a97-80c8-4c6c33350f38': TCP connection to [127.0.0.1:64112, L127.0.0.1:16253, {80f9daa6-9d59-47d0-a26f-56150b193d3b}] closed.. [28,14:50:54.739,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: dropping subscription, reason: ConnectionClosed EventStore.ClientAPI.Exceptions.ConnectionClosedException: Connection was closed.. [28,14:50:54.739,DEBUG] Catch-up Subscription to 288984f0-1f52-4482-a575-d11242cc2014: requesting stop... [28,14:50:54.739,DEBUG] Catch-up Subscription to {0}: unhooking from connection.Connected. 11/05/2016 15:50:54: Subscription dropped because ConnectionClosed, exception: Connection was closed.