Projections faulting

EventStoreDB
1

I’m seeing my projections fault occasionally with the message: “Message: Failed to compile script. Script execution terminated. Timeout expired. (1)”

I’ve just been restarting them which seems to work fine but is not a great solution.

They are not doing anything complicated but I think maybe the length of the projection is causing the compiler to complain? Heres an example - all it does it link events my elastic consumer is interested in to a unique stream for them to compete consume from.

fromStreams([
‘$et-event1, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event2, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event3, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,

‘$et-event4, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event5, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event6, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event7, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event8, Models, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event9, Models, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event10, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event11, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event12, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event13, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event14, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event15, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event16, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event17, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event18, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’,
‘$et-event19, Library, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null’])
.when({

‘event1, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event2, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event3, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event4, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event5, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event6, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event7, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event8, Models, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event9, Models, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event10, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event11, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event12, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event13, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event14, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event15, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event16, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event17, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event18, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); },

‘event19, Library, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null’: function(s,e) { linkTo(‘application.elastic.development.0.1.0.0’, e); }

});

``

While processing these projections my instance is running about 3-5k (peak 11k) items a second, 3 of these projections each writing ~30 events / second, and each with 4 pinned consumers. In my eventstore instance i’ve given it 12 cores and upped the thread counts in the config. WorkerThreads: 8, ProjectionThreads: 4, CachedChunks: 8, and ChunksCacheSize: 4294967296

It runs at ~50% cpu sometimes spiking up to 100% for a few moments

Anything look out of place? I don’t know if the projection itself is the wisest thing actually it just makes sense given my consumers don’t need to see everything in $all

2

Should mention this is ES 3.9.3 and the log files are not very interesting but I’ll post a segment:

[PID:11185:069 2016.12.17 21:31:25.650 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-domain.development.0.1.0.0::domain.development.0.1.0.0.sub-checkpoint: 113168

[PID:11185:014 2016.12.17 21:31:25.689 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-application.riak.development.0.1.0.0::application.riak.development.0.1.0.0.sub-checkpoint

[PID:11185:014 2016.12.17 21:31:25.689 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-domain.development.0.1.0.0::domain.development.0.1.0.0.sub-checkpoint

[PID:11185:027 2016.12.17 21:31:30.725 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-application.riak.development.0.1.0.0::application.riak.development.0.1.0.0.sub-checkpoint: 94851

[PID:11185:014 2016.12.17 21:31:30.787 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-application.riak.development.0.1.0.0::application.riak.development.0.1.0.0.sub-checkpoint

[PID:11185:038 2016.12.17 21:31:33.833 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-domain.development.0.1.0.0::domain.development.0.1.0.0.sub-checkpoint: 113228

[PID:11185:014 2016.12.17 21:31:33.874 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-domain.development.0.1.0.0::domain.development.0.1.0.0.sub-checkpoint

[PID:11185:126 2016.12.17 21:31:34.085 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-domain.development.0.1.0.0::domain.development.0.1.0.0.sub-checkpoint: 114393

[PID:11185:014 2016.12.17 21:31:34.267 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-domain.development.0.1.0.0::domain.development.0.1.0.0.sub-checkpoint

[PID:11185:020 2016.12.17 21:31:34.299 ERROR ProcessingStrategySe] The domain.development.0.1.0.0 projection failed to process an event.^M

Handler: EventStore.Projections.Core.Services.v8.DefaultV8ProjectionStateHandler^M

Event Position: $et-event1, Domain.Infrastructure, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null: -1; $et-event2, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null: 74690; $et-event3, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null: 39086; $et-event4,… ^M

^M

Message:^M

^M

Failed to compile script. Script execution terminated. Timeout expired. (1)

EventStore.Projections.Core.v8.Js1Exception: Failed to compile script. Script execution terminated. Timeout expired. (1)

at EventStore.Projections.Core.v8.CompiledScript.CheckResult (System.IntPtr scriptHandle, System.Boolean terminated, System.Boolean disposeScriptOnException) [0x00018] in <72779fb29bbd4646b3f179bf0f55712c>:0

at EventStore.Projections.Core.v8.QueryScript.ExecuteHandler (System.IntPtr commandHandlerHandle, System.String json, System.String[] other, System.String& newSharedState) [0x00059] in <72779fb29bbd4646b3f179bf0f55712c>:0

at EventStore.Projections.Core.v8.QueryScript+c__AnonStorey1.<>m__3 (System.String json, System.String[] other) [0x00000] in <72779fb29bbd4646b3f179bf0f55712c>:0

at EventStore.Projections.Core.v8.QueryScript.Push (System.String json, System.String[] other) [0x00016] in <72779fb29bbd4646b3f179bf0f55712c>:0

at EventStore.Projections.Core.Services.v8.V8ProjectionStateHandler.ProcessEvent (System.String partition, EventStore.Projections.Core.Services.Processing.CheckpointTag eventPosition, System.String category, EventStore.Projections.Core.Services.Processing.ResolvedEvent data, System.String& newState, System.String& newSharedState, EventStore.Projections.Core.Services.Processing.EmittedEventEnvelope[]& emittedEvents) [0x000b6] in <72779fb29bbd4646b3f179bf0f55712c>:0

at EventStore.Projections.Core.Services.Processing.EventProcessingProjectionProcessingPhase.ProcessEventByHandler (System.String partition, EventStore.Projections.Core.Messages.EventReaderSubscriptionMessage+CommittedEventReceived message, System.String& newState, System.String& newSharedState, System.String& projectionResult, EventStore.Projections.Core.Services.Processing.EmittedEventEnvelope[]& emittedEvents) [0x00053] in <72779fb29bbd4646b3f179bf0f55712c>:0

at EventStore.Projections.Core.Services.Processing.EventProcessingProjectionProcessingPhase.SafeProcessEventByHandler (System.String partition, EventStore.Projections.Core.Messages.EventReaderSubscriptionMessage+CommittedEventReceived message, System.String& newState, System.String& newSharedState, System.String& projectionResult, EventStore.Projections.Core.Services.Processing.EmittedEventEnvelope[]& emittedEvents) [0x00004] in <72779fb29bbd4646b3f179bf0f55712c>:0

[PID:11185:020 2016.12.17 21:31:34.676 DEBUG ResponseWriter ] PROJECTIONS: Scheduling the writing of $faulted to $projections-$master. Current status of Writer: Busy: True

[PID:11185:009 2016.12.17 21:31:34.849 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-application.elastic.development.0.1.0.0::application.elastic.development.0.1.0.0.sub-checkpoint: 121076

[PID:11185:014 2016.12.17 21:31:34.851 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-application.elastic.development.0.1.0.0::application.elastic.development.0.1.0.0.sub-checkpoint

[PID:11185:020 2016.12.17 21:31:35.655 DEBUG ResponseWriter ] PROJECTIONS: Finished writing events to $projections-$master: $faulted

[PID:11185:017 2016.12.17 21:31:35.728 DEBUG ProjectionManagerRes] PROJECTIONS: Response received: 13546@$faulted

[PID:11185:017 2016.12.17 21:31:35.730 ERROR ProjectionManager ] The ‘domain.development.0.1.0.0’ projection faulted due to 'The domain.development.0.1.0.0 projection failed to process an event.^M

Handler: EventStore.Projections.Core.Services.v8.DefaultV8ProjectionStateHandler^M

Event Position: $et-event1, Domain.Infrastructure, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null: -1; $et-event2, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null: 74690; $et-event3, Domain.Messages, Version=0.1.0.0, Culture=neutral, PublicKeyToken=null: 39086; $et-event4,… ^M
^M

Message:^M

^M

Failed to compile script. Script execution terminated. Timeout expired. (1)’

[PID:11185:129 2016.12.17 21:31:35.852 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-application.riak.development.0.1.0.0::application.riak.development.0.1.0.0.sub-checkpoint: 95008

[PID:11185:014 2016.12.17 21:31:36.102 DEBUG PersistentSubscripti] Checkpoint write successful for $persistentsubscription-application.riak.development.0.1.0.0::application.riak.development.0.1.0.0.sub-checkpoint

[PID:11185:126 2016.12.17 21:31:36.875 DEBUG PersistentSubscripti] Publishing checkpoint for $persistentsubscription-application.elastic.development.0.1.0.0::application.elastic.development.0.1.0.0.sub-checkpoint: 121211

``

3

Is the cutoff

Version=0.1.0.0, Culture=neutral, PublicKeyToken=null: 74690;
$et-event3, Domain.Messages, Version=0.1.0.0, Culture=neutral,
PublicKeyToken=null: 39086; $et-event4,... ^M
^M
Message:^M
^M

In your log as well?

4

No it goes on to list all the positions of each event type I just didnt want to sanitize all the names so I put …
Is that important info?