gRPC - GetStatusAsync throws DeadlineExceeded exception after cleaning EventStore

[Keethanjan]

Describe the bug
After cleaning and restarting the EventStore service (with 3 nodes) the calls to EventStore fails with DeadlineExceeded. Even with multiple retries, increasing the timeout for each call and waiting 30 seconds after EventStore is started does not resolve this issue.

To Reproduce
Steps to reproduce the behavior:

1. Stop the EventStore Service on all 3 nodes
2. Delete the log & data folders so EventStore is 'clean'
3. Start the service on all 3 nodes
4. Make a gRPC request to GetStatusAsync.

The line which makes this call is:
var projectionDetails = await _client.GetStatusAsync(name, userCredentials: new UserCredentials(userCredentials.UserName, userCredentials.Password), deadline: TimeSpan.FromMinutes(1)).ConfigureAwait(false);

Expected behavior
The status is returned so we can verify if the projections should be started/stopped.

Actual behavior
Sometimes an exception is thrown. The exception client side is DeadlineExceeded. See screenshot for the exception on the server side.

Config/Logs/Screenshots

The error log:

EventStore details

• EventStore server version: 22.10.0
• Operating system: Windows Server 2019 Version 1809
• EventStore client version (if applicable): 22.0.0

Additional context
Our final goal is to start with EventStore from scratch. And after EventStore has been started the system projection 'by_category' should be enabled. The other system projections should be disabled.
We've also tried to just make the call to disable/enable the projections without receiving the status first. This however resulted in the same exception.

The stacktrace on client side:

Grpc.Core.RpcException:
at EventStore.Client.Interceptors.TypedExceptionInterceptor+AsyncStreamReader1+<MoveNext>d__3.MoveNext (EventStore.Client, Version=22.0.0.0, Culture=neutral, PublicKeyToken=null) at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at EventStore.Client.AsyncStreamReaderExtensions+<ReadAllAsync>d__01.MoveNext (EventStore.Client.ProjectionManagement, Version=22.0.0.0, Culture=neutral, PublicKeyToken=null)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore1.ThrowForFailedGetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore1.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at EventStore.Client.AsyncStreamReaderExtensions+d__01.System.Threading.Tasks.Sources.IValueTaskSource<System.Boolean>.GetResult (EventStore.Client.ProjectionManagement, Version=22.0.0.0, Culture=neutral, PublicKeyToken=null) at System.Linq.AsyncEnumerable+SelectEnumerableAsyncIterator2+d__7.MoveNext (System.Linq.Async, Version=6.0.0.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263: //Ix.NET/Source/System.Linq.Async/System/Linq/Operators/Select.cs:221)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.ConfiguredValueTaskAwaitable1+ConfiguredValueTaskAwaiter.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Linq.AsyncIteratorBase1+d__8.MoveNext (System.Linq.Async, Version=6.0.0.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263: //Ix.NET/Source/System.Linq.Async/System/Linq/AsyncIterator.cs:70)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Linq.AsyncIteratorBase1+<MoveNextAsync>d__8.MoveNext (System.Linq.Async, Version=6.0.0.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263: /_/Ix.NET/Source/System.Linq.Async/System/Linq/AsyncIterator.cs:75) at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at EventStore.Client.EventStoreProjectionManagementClient+<ListInternalAsync>d__23.MoveNext (EventStore.Client.ProjectionManagement, Version=22.0.0.0, Culture=neutral, PublicKeyToken=null) at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at EventStore.Client.EventStoreProjectionManagementClient+<ListInternalAsync>d__23.MoveNext (EventStore.Client.ProjectionManagement, Version=22.0.0.0, Culture=neutral, PublicKeyToken=null) at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore1.ThrowForFailedGetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore1.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at EventStore.Client.EventStoreProjectionManagementClient+<ListInternalAsync>d__23.System.Threading.Tasks.Sources.IValueTaskSource<System.Boolean>.GetResult (EventStore.Client.ProjectionManagement, Version=22.0.0.0, Culture=neutral, PublicKeyToken=null) at System.Linq.AsyncEnumerable+<<TryGetFirst>g__Core|95_0>d1.MoveNext (System.Linq.Async, Version=6.0.0.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263: //Ix.NET/Source/System.Linq.Async/System/Linq/Operators/FirstOrDefault.cs:130)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Linq.AsyncEnumerable+<g__Core|95_0>d1.MoveNext (System.Linq.Async, Version=6.0.0.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263: /_/Ix.NET/Source/System.Linq.Async/System/Linq/Operators/FirstOrDefault.cs:132) at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Threading.Tasks.ValueTask1.get_Result (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.ConfiguredValueTaskAwaitable1+ConfiguredValueTaskAwaiter.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e) at System.Linq.AsyncEnumerable+<<FirstOrDefaultAsync>g__Core|91_0>d1.MoveNext (System.Linq.Async, Version=6.0.0.0, Culture=neutral, PublicKeyToken=94bc3704cddfc263: //Ix.NET/Source/System.Linq.Async/System/Linq/Operators/FirstOrDefault.cs:30)

[hayley-jean]

Hi @Keethanjan , could you confirm that the cluster has started correctly?

You can do this by ensuring that there is 1 Leader and 2 Followers in the cluster either through the admin UI or through the HTTP gossip endpoint (https://{node_address}:2113/gossip).

If the cluster is stable, then can you ensure that the projections subsystem has started correctly? You can do that a couple of ways:

1. Check the projections page of the admin UI
2. Check the logs on the Leader node for the following messages:

========== ["127.0.0.1:2113"] Sub System '"Projections"' initialized.
....
Adding projection e1dab134-e3de-4154-b95a-cb491697da04@"$streams" to list
Adding projection b4ca2442-c83d-4b01-82c5-35e5cc8db6b6@"$stream_by_category" to list
Adding projection aabbe701-e149-4a05-ac15-93c3bf43003d@"$by_category" to list
Adding projection 3476c89c-34e4-46e9-b50f-a442686f468f@"$by_event_type" to list
Adding projection 0e109271-67cd-4399-81aa-cf6409b92f7e@"$by_correlation_id" to list

[Keethanjan]

In the admin UI all the nodes are up and running and alive

The projections are also running

In the log file I can't find the line Sub System '"Projections"'. However I can find the following line:

{"@t":"2023-03-07T07:24:59.0045348+00:00","@mt":"========== [{httpEndPoint}] Sub System '{subSystemName}' initialized.","@l":"Information","@i":1147237149,"httpEndPoint":"IPADDRESS:2113","subSystemName":"Projections"

And in the error file the following line is visible:
{"@t":"2023-03-07T07:20:04.4365161+00:00","@mt":"Failed to write the $maxAge of {days} days and set $ops permission for the {stream} stream. Reason: {reason}","@l":"Error","@i":3084892194,"days":30,"stream":"$scavenges","reason":"ForwardTimeout","SourceContext":"EventStore.Core.Services.Storage.StorageScavenger","ProcessId":5872,"ThreadId":14}

[ylorph]

Did you ever figure this out @Keethanjan ?