Hi All,
Hoping someone has seen this particular issue before and can give some guidance. We are currently running version 3.2.1.0 and our projections have been periodically entering a faulted state. We have attempted to kill the master and fall to a slave which seems to briefly reset the state of the projections and then it quickly returns to the “Faulted/Initial (Enabled)” state again. Note that we do NOT have $by_event_type, $stream_by_category and $streams enabled intentionally. We are currently utilizing only the $by_category stream.
Here is the error log from the newly elected master after our last kill/failover event:
[PID:02864:016 2016.07.08 16:00:40.379 ERROR QueuedHandlerMRES ] Error while processing message EventStore.Projections.Core.Messages.ReaderSubscriptionManagement+Unsubscribe in queued handler ‘Projection Core #1’.
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at EventStore.Projections.Core.Services.Processing.EventReaderCoreService.Handle(Unsubscribe message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\EventReaderCoreService.cs:line 132
at EventStore.Core.Bus.MessageHandler`1.TryHandle(Message message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\MessageHandler.cs:line 33
at EventStore.Core.Bus.InMemoryBus.Publish(Message message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\InMemoryBus.cs:line 324
at EventStore.Core.Bus.QueuedHandlerMRES.ReadFromQueue(Object o) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\QueuedHandlerMRES.cs:line 122
[PID:02864:013 2016.07.08 16:00:43.426 ERROR ProjectionManager ] The ‘$by_event_type’ projection faulted due to ‘Unexpected ‘PREPARED’ message in LoadingStateState’
[PID:02864:013 2016.07.08 16:00:43.426 ERROR ProjectionManager ] The ‘$stream_by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in LoadingStateState’
[PID:02864:013 2016.07.08 16:00:43.426 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in StartingState’
[PID:02864:013 2016.07.08 16:00:43.442 ERROR ProjectionManager ] The ‘$stream_by_category’ projection faulted due to ‘Unexpected ‘STOPPED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.442 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘STARTED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.458 ERROR ProjectionManager ] The ‘$streams’ projection faulted due to ‘Unexpected ‘PREPARED’ message in LoadingStateState’
[PID:02864:013 2016.07.08 16:00:43.458 ERROR ProjectionManager ] The ‘$stream_by_category’ projection faulted due to ‘Unexpected ‘STOPPED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.458 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘STARTED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.473 ERROR ProjectionManager ] The ‘$by_event_type’ projection faulted due to ‘Unexpected ‘STOPPED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.473 ERROR ProjectionManager ] The ‘$by_event_type’ projection faulted due to ‘Unexpected ‘STOPPED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.567 ERROR ProjectionManager ] The ‘$streams’ projection faulted due to ‘Unexpected ‘STOPPED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:00:43.567 ERROR ProjectionManager ] The ‘$streams’ projection faulted due to ‘Unexpected ‘STOPPED’ message in FaultedState’
[PID:02864:013 2016.07.08 16:06:22.435 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:017 2016.07.08 16:07:08.450 ERROR QueuedHandlerMRES ] Error while processing message EventStore.Projections.Core.Messages.CoreProjectionManagementMessage+GetState in queued handler ‘Projection Core #2’.
System.Exception: Current state is Initial. Expected states are: Running, Stopping, Stopped, FaultedStopping, Faulted, CompletingPhase, PhaseCompleted
at EventStore.Projections.Core.Services.Processing.CoreProjection.EnsureState(State expectedStates) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\CoreProjection.cs:line 616
at EventStore.Projections.Core.Services.Processing.CoreProjection.Handle(GetState message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\CoreProjection.cs:line 263
at EventStore.Projections.Core.Services.Processing.ProjectionCoreService.Handle(GetState message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\ProjectionCoreService.cs:line 270
at EventStore.Core.Bus.MessageHandler`1.TryHandle(Message message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\MessageHandler.cs:line 33
at EventStore.Core.Bus.InMemoryBus.Publish(Message message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\InMemoryBus.cs:line 324
at EventStore.Core.Bus.QueuedHandlerMRES.ReadFromQueue(Object o) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\QueuedHandlerMRES.cs:line 122
[PID:02864:017 2016.07.08 16:07:08.466 ERROR QueuedHandlerMRES ] Error while processing message EventStore.Projections.Core.Messages.CoreProjectionManagementMessage+GetResult in queued handler ‘Projection Core #2’.
System.Exception: Current state is Initial. Expected states are: Running, Stopping, Stopped, FaultedStopping, Faulted, CompletingPhase, PhaseCompleted
at EventStore.Projections.Core.Services.Processing.CoreProjection.EnsureState(State expectedStates) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\CoreProjection.cs:line 616
at EventStore.Projections.Core.Services.Processing.CoreProjection.Handle(GetResult message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\CoreProjection.cs:line 280
at EventStore.Projections.Core.Services.Processing.ProjectionCoreService.Handle(GetResult message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Projections.Core\Services\Processing\ProjectionCoreService.cs:line 277
at EventStore.Core.Bus.MessageHandler`1.TryHandle(Message message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\MessageHandler.cs:line 33
at EventStore.Core.Bus.InMemoryBus.Publish(Message message) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\InMemoryBus.cs:line 324
at EventStore.Core.Bus.QueuedHandlerMRES.ReadFromQueue(Object o) in c:\buildAgent\work\47590a33512c319d\src\EventStore.Core\Bus\QueuedHandlerMRES.cs:line 122
[PID:02864:013 2016.07.08 16:25:02.976 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 16:30:00.142 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 16:43:29.610 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 17:01:25.246 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 17:06:16.912 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 17:17:14.868 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 17:35:56.174 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 17:40:41.708 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 17:49:58.463 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 18:09:41.018 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 18:15:15.448 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
[PID:02864:013 2016.07.08 18:24:20.703 ERROR ProjectionManager ] The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’
The trace starting at [PID:02864:017 2016.07.08 16:07:08.450 ERROR QueuedHandlerMRES ] is typical of what we are seeing periodically. The 'The ‘$by_category’ projection faulted due to ‘Unexpected ‘PREPARED’ message in PreparedState’ error is occurring regularly as well, about every 5-15 minutes.
I have seen others cite a similar error related to a bug in an earlier version, 3.0.1, I believe, and perhaps this is in a similar vein. We are not seeing any other logged errors outside of this, and our nodes are up and accepting writes at this point. I’d love to get to a root cause on this though - any insight would be appreciated!
Thank you!