Closed fabiocarneiro closed 3 months ago
I will look into this. I am currently sick, so it may take a couple of days.
Any news on this issue. I'am running into exactly the same problem with EventStore 21.10
. It looks like the problem only occurs when the end of the all stream is reached.
{"message":"Catch-up Subscription to <all>: skipping event ($projections-projector-condition-fact, 1, $ProjectionUpdated @ C:473581341/P:473581341)","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.053059+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': enqueuing message StartOperationMessage","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.053656+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': StartOperation schedule ReadAllEventsForward, Position: C:473582662/P:0, MaxCount: 100, ResolveLinkTos: no, RequireMaster: no, 10, 7000","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.053856+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': ExecuteOperation package ReadAllEventsForward, 050de963dddf9c4a8a076ceb27edea59, Operation ReadAllEventsForward (050de963dddf9c4a8a076ceb27edea59): Position: C:473582662/P:0, MaxCount: 100, ResolveLinkTos: no, RequireMaster: no, retry count: 0, created: 2022-07-26T07:46:49.054005+00:00, last updated: 2022-07-26T07:46:49.054138+00:00","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.055390+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation ReadAllEventsForward (67eb9c6a2249b046b269ddb48a949ebb): Position: C:473581341/P:473581341, MaxCount: 100, ResolveLinkTos: no, RequireMaster: no, retry count: 0, created: 2022-07-26T07:46:48.105593+00:00, last updated: 2022-07-26T07:46:48.963090+00:00","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.064897+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': RemoveOperation SUCCEEDED for Operation ReadAllEventsForward (67eb9c6a2249b046b269ddb48a949ebb): Position: C:473581341/P:473581341, MaxCount: 100, ResolveLinkTos: no, RequireMaster: no, retry count: 0, created: 2022-07-26T07:46:48.105593+00:00, last updated: 2022-07-26T07:46:48.963090+00:00","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.065108+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': enqueuing message HandleTcpPackageMessage","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.094261+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': HandleTcpPackage connId c52b892ae7c8804c80bb243cf45c0889, package ReadAllEventsForwardCompleted, 050de963dddf9c4a8a076ceb27edea59","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.094505+00:00","extra":{}}
{"message":"Catch-up Subscription to <all>: finished reading events, nextReadPosition = C:473582662/P:0","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.095615+00:00","extra":{}}
{"message":"Catch-up Subscription to <all>: subscribing...","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.095893+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': enqueuing message StartSubscriptionMessage","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.101414+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': StartSubscription fire VolatileSubscription, StreamId: , ResolveLinkTos: no, MaxRetries: 10, Timeout: 7000","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.117024+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': StartSubscription SUBSCRIBING Subscription VolatileSubscription (0e8159e815a0a64da3ba90e0fd955de0): StreamId: , ResolveLinkTos: no, is subscribed: no, retry count: 0, created: 2022-07-26T07:46:49.127428+00:00, last updated: 2022-07-26T07:46:49.127656+00:00","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.133801+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': HandleTcpPackage OPERATION DECISION EndOperation (Success), Operation ReadAllEventsForward (050de963dddf9c4a8a076ceb27edea59): Position: C:473582662/P:0, MaxCount: 100, ResolveLinkTos: no, RequireMaster: no, retry count: 0, created: 2022-07-26T07:46:49.054005+00:00, last updated: 2022-07-26T07:46:49.054138+00:00","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.134221+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': RemoveOperation SUCCEEDED for Operation ReadAllEventsForward (050de963dddf9c4a8a076ceb27edea59): Position: C:473582662/P:0, MaxCount: 100, ResolveLinkTos: no, RequireMaster: no, retry count: 0, created: 2022-07-26T07:46:49.054005+00:00, last updated: 2022-07-26T07:46:49.054138+00:00","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.134420+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': enqueuing message HandleTcpPackageMessage","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.161528+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': HandleTcpPackage connId c52b892ae7c8804c80bb243cf45c0889, package BadRequest, 0e8159e815a0a64da3ba90e0fd955de0","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.162172+00:00","extra":{}}
{"message":"Subscription 0e8159e815a0a64da3ba90e0fd955de0 to <all>: closing subscription, reason: ServerError, exception: Server error...","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.205194+00:00","extra":{}}
{"message":"Catch-up Subscription to <all>: dropped subscription, reason: CatchUpError Server error","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.205866+00:00","extra":{}}
{"message":"Dropped","context":{},"level":200,"level_name":"INFO","channel":"test","datetime":"2022-07-26T07:46:49.206084+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': HandleTcpPackage 0e8159e815a0a64da3ba90e0fd955de0 SUBSCRIPTION DECISION EndOperation (BadRequest), ","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.206946+00:00","extra":{}}
{"message":"EventStoreNodeConnection 'c2998afc9e8d2e44874dcb8a3c646c57': RemoveSubscription Subscription VolatileSubscription (0e8159e815a0a64da3ba90e0fd955de0): StreamId: , ResolveLinkTos: no, is subscribed: no, retry count: 0, created: 2022-07-26T07:46:49.127428+00:00, last updated: 2022-07-26T07:46:49.127656+00:00, result yes","context":{},"level":100,"level_name":"DEBUG","channel":"test","datetime":"2022-07-26T07:46:49.207395+00:00","extra":{}}
It looks like an authentication issue. I get the following response from the server:
Error while processing package. Error: System.ArgumentNullException: Value cannot be null. (Parameter 'value')
at EventStore.Plugins.Authorization.Operations.Streams.Parameters.StreamId(String streamId)
at EventStore.Core.Services.AuthorizationGateway.Authorize(SubscribeToStream msg, IPublisher destination) in /home/runner/work/TrainStation/TrainStation/build/oss-eventstore/src/EventStore.Core/Services/AuthorizationGateway.cs:line 248
at EventStore.Core.Services.Transport.Tcp.TcpConnectionManager.ProcessPackage(TcpPackage package) in /home/runner/work/TrainStation/TrainStation/build/oss-eventstore/src/EventStore.Core/Services/Transport/Tcp/TcpConnectionManager.cs:line 322
at EventStore.Core.Services.Transport.Tcp.TcpConnectionManager.OnPackageReceived(TcpPackage package) in /home/runner/work/TrainStation/TrainStation/build/oss-eventstore/src/EventStore.Core/Services/Transport/Tcp/TcpConnectionManager.cs:line 250
@fabiocarneiro @tomtimmerman can you confirm this error with the latest master branch? If so, would you be able to setup a test case that fails? I'll try to look into it and to resolve the issue.
Since there is no additional feedback, I assume this issue is resolved in current master branch. Feel free to reopen.
When using the example for
subscribetoAllAsync
with EventStore20.10.0
it fails with BadRequest.Logs: