I see failures to start projections just after start up: The ‘CreateSamosaTemplateProjection’ projection faulted due to 'Cannot create a projection state handler.
The projection creation seems out of sync. Any ideas, I have the log below. EventStore version 2.0x
[PID:04268:009 2015.03.04 07:00:10.713 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:52338, {097f99d1-73fd-47fc-a484-08a31f20c38d}] closed: Success.
[PID:06276:001 2015.03.04 07:13:48.840 INFO ProgramBase`1 ]
ES VERSION: 2.0.1.0 (master/549d96219418572625b2f68d46ec809d9e86f7df, Thu, 1 Aug 2013 18:26:54 +0100)
OS: Windows (Microsoft Windows NT 6.1.7601 Service Pack 1)
RUNTIME: .NET 4.0.30319.18063 (64-bit)
GC: 3 GENERATIONS
LOGS: F:\apps\PatakTechnologies\SecureData\App_Data\EventStoreDb\Production-logs
SHOW HELP: False ()
SHOW VERSION: False ()
LOGS DIR: ()
CONFIGS: ()
DEFINES: ()
IP: 127.0.0.1 (–ip from command line)
TCP PORT: 1113 (–tcp-port from command line)
SECURE TCP PORT: 0 ()
HTTP PORT: 2113 (–http-port from command line)
STATS PERIOD SEC: 30 (–stats-period-sec from command line)
CACHED CHUNKS: 1 (–cached-chunks from command line)
CHUNKS CACHE SIZE: 256 (–chunks-cache-size from command line)
MIN FLUSH DELAY MS: 2 ()
DB PATH: F:\apps\PatakTechnologies\SecureData\App_Data\EventStoreDb\Production (–db from command line)
SKIP DB VERIFY: False ()
RUN PROJECTIONS: All (–run-projections from command line)
PROJECTION THREADS: 3 ()
WORKER THREADS: 5 ()
HTTP PREFIXES: ()
ENABLE TRUSTED AUTH: False ()
CERTIFICATE STORE: ()
CERTIFICATE NAME: ()
CERTIFICATE FILE: ()
CERTIFICATE PASSWORD: ()
PREPARE TIMEOUT MS: 2000 ()
COMMIT TIMEOUT MS: 2000 ()
FORCE: False ()
[PID:06276:001 2015.03.04 07:13:49.261 INFO ProgramBase`1 ]
DATABASE: F:\apps\PatakTechnologies\SecureData\App_Data\EventStoreDb\Production
WRITER CHECKPOINT: 1399505430 (0x536AC216)
CHASER CHECKPOINT: 1399505430 (0x536AC216)
EPOCH CHECKPOINT: 1381922170 (0x525E757A)
TRUNCATE CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)
[PID:06276:001 2015.03.04 07:13:56.718 TRACE MessageHierarchy ] MessageHierarchy initialization took 00:00:07.3988595.
[PID:06276:008 2015.03.04 07:14:01.742 TRACE TFChunk ] Verifying hash for TFChunk ‘F:\apps\Data\App_Data\EventStoreDb\Production\chunk-000003.000000’…
[PID:06276:001 2015.03.04 07:14:01.773 TRACE TFChunk ] CACHED TFChunk #5-5 (chunk-000005.000000) in 00:00:00.0489388.
[PID:06276:001 2015.03.04 07:14:03.536 INFO MiniWeb ] Starting MiniWeb for /web/es/js/projections ==> E:\apps\prod_2.6.5\ThirdParty\EventStore\singlenode-web\js\projections
[PID:06276:001 2015.03.04 07:14:03.536 INFO MiniWeb ] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> E:\apps\prod_2.6.5\ThirdParty\EventStore\Prelude
[PID:06276:001 2015.03.04 07:14:03.536 INFO MiniWeb ] Starting MiniWeb for /web/es/js/projections/resources ==> E:\apps\Patak\Samosa2.6.5\ThirdParty\EventStore\web-resources\js
[PID:06276:001 2015.03.04 07:14:03.551 TRACE MiniWeb ] Binding MiniWeb to /web/es/js/projections/{*remaining_path}
[PID:06276:001 2015.03.04 07:14:03.551 TRACE MiniWeb ] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*remaining_path}
[PID:06276:001 2015.03.04 07:14:03.551 TRACE MiniWeb ] Binding MiniWeb to /web/es/js/projections/resources/{*remaining_path}
[PID:06276:001 2015.03.04 07:14:03.551 INFO MiniWeb ] Starting MiniWeb for /web ==> E:\apps\Patak\Samosa2.6.5\ThirdParty\EventStore\singlenode-web
[PID:06276:001 2015.03.04 07:14:03.551 INFO MiniWeb ] Starting MiniWeb for /web/es ==> E:\apps\Patak\Samosa2.6.5\ThirdParty\EventStore\es-common-web
[PID:06276:001 2015.03.04 07:14:03.551 TRACE MiniWeb ] Binding MiniWeb to /web/{*remaining_path}
[PID:06276:001 2015.03.04 07:14:03.551 TRACE MiniWeb ] Binding MiniWeb to /web/es/{*remaining_path}
[PID:06276:001 2015.03.04 07:14:03.567 INFO MiniWeb ] Starting MiniWeb for /web/users ==> E:\apps\Patak\Samosa2.6.5\ThirdParty\EventStore\Users\web
[PID:06276:001 2015.03.04 07:14:03.567 TRACE MiniWeb ] Binding MiniWeb to /web/users/{*remaining_path}
[PID:06276:012 2015.03.04 07:14:03.582 INFO SingleVNodeControlle] ========== [127.0.0.1:2113] SYSTEM INIT…
[PID:06276:012 2015.03.04 07:14:03.614 INFO TcpServerListener ] Starting Normal TCP listening on TCP endpoint: 127.0.0.1:1113.
[PID:06276:010 2015.03.04 07:14:03.629 INFO ReadIndex ] TableIndex initialization…
[PID:06276:012 2015.03.04 07:14:03.645 INFO HttpAsyncServer ] Starting HTTP server on [http://127.0.0.1:2113/]…
[PID:06276:012 2015.03.04 07:14:03.645 INFO HttpAsyncServer ] HTTP server is up and listening on [http://127.0.0.1:2113/]
[PID:06276:012 2015.03.04 07:14:03.660 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [MainQueue]: SystemInit - 78ms. Q: 0/3.
[PID:06276:010 2015.03.04 07:14:03.707 INFO ReadIndex ] ReadIndex building…
[PID:06276:010 2015.03.04 07:14:08.715 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 4775 records (0.3%).
[PID:06276:013 2015.03.04 07:14:12.444 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [MonitoringQueue]: SystemInit - 8861ms. Q: 0/0.
[PID:06276:010 2015.03.04 07:14:13.723 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 9764 records (0.5%).
[PID:06276:008 2015.03.04 07:14:17.888 TRACE TFChunk ] Verifying hash for TFChunk ‘F:\apps\PatakTechnologies\SecureData\App_Data\EventStoreDb\Production\chunk-000002.000000’…
[PID:06276:010 2015.03.04 07:14:18.731 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 15888 records (0.9%).
[PID:06276:010 2015.03.04 07:14:23.738 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 22594 records (1.2%).
[PID:06276:010 2015.03.04 07:14:28.746 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 28824 records (1.6%).
[PID:06276:010 2015.03.04 07:14:33.754 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 36531 records (2.0%).
[PID:06276:008 2015.03.04 07:14:34.378 TRACE TFChunk ] Verifying hash for TFChunk ‘F:\apps\PatakTechnologies\SecureData\App_Data\EventStoreDb\Production\chunk-000001.000000’…
[PID:06276:010 2015.03.04 07:14:38.793 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 42408 records (2.2%).
[PID:06276:010 2015.03.04 07:14:43.801 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 49143 records (2.6%).
[PID:06276:008 2015.03.04 07:14:48.621 TRACE TFChunk ] Verifying hash for TFChunk ‘F:\apps\PatakTechnologies\SecureData\App_Data\EventStoreDb\Production\chunk-000000.000000’…
[PID:06276:010 2015.03.04 07:14:48.824 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 57342 records (3.0%).
[PID:06276:010 2015.03.04 07:14:53.224 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 100000 records (10.5%).
[PID:06276:010 2015.03.04 07:14:58.231 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 136299 records (17.1%).
[PID:06276:010 2015.03.04 07:15:00.103 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 200000 records (45.6%).
[PID:06276:010 2015.03.04 07:15:05.127 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 276529 records (77.1%).
[PID:06276:010 2015.03.04 07:15:10.150 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 277117 records (77.5%).
[PID:06276:010 2015.03.04 07:15:15.205 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 277497 records (77.7%).
[PID:06276:010 2015.03.04 07:15:20.228 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 277792 records (77.9%).
[PID:06276:010 2015.03.04 07:15:25.236 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 278033 records (78.0%).
[PID:06276:010 2015.03.04 07:15:30.244 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 278253 records (78.2%).
[PID:06276:010 2015.03.04 07:15:35.252 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 278585 records (78.4%).
[PID:06276:010 2015.03.04 07:15:40.306 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 278927 records (78.6%).
[PID:06276:010 2015.03.04 07:15:45.314 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 279353 records (78.8%).
[PID:06276:010 2015.03.04 07:15:50.322 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 279863 records (79.1%).
[PID:06276:010 2015.03.04 07:15:55.329 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 280541 records (79.5%).
[PID:06276:010 2015.03.04 07:16:00.337 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 281069 records (79.8%).
[PID:06276:010 2015.03.04 07:16:05.345 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 281898 records (80.2%).
[PID:06276:010 2015.03.04 07:16:10.353 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 284239 records (80.5%).
[PID:06276:010 2015.03.04 07:16:15.361 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 289685 records (80.8%).
[PID:06276:010 2015.03.04 07:16:20.368 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 294405 records (81.0%).
[PID:06276:010 2015.03.04 07:16:25.376 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 298376 records (81.2%).
[PID:06276:010 2015.03.04 07:16:27.560 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 300000 records (81.3%).
[PID:06276:010 2015.03.04 07:16:32.568 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 303052 records (81.6%).
[PID:06276:010 2015.03.04 07:16:37.576 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 303548 records (81.9%).
[PID:06276:010 2015.03.04 07:16:42.584 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 304281 records (82.4%).
[PID:06276:010 2015.03.04 07:16:47.779 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 304803 records (82.7%).
[PID:06276:010 2015.03.04 07:16:52.802 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 305111 records (82.8%).
[PID:06276:010 2015.03.04 07:16:57.872 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 305663 records (83.2%).
[PID:06276:010 2015.03.04 07:17:02.880 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 305739 records (83.2%).
[PID:06276:010 2015.03.04 07:17:07.888 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 306614 records (83.6%).
[PID:06276:010 2015.03.04 07:17:12.896 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 308289 records (84.1%).
[PID:06276:010 2015.03.04 07:17:17.903 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 309218 records (84.6%).
[PID:06276:010 2015.03.04 07:17:22.911 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 310113 records (85.0%).
[PID:06276:010 2015.03.04 07:17:27.919 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 310957 records (85.5%).
[PID:06276:010 2015.03.04 07:17:32.958 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 311931 records (86.1%).
[PID:06276:010 2015.03.04 07:17:37.966 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 312613 records (86.5%).
[PID:06276:010 2015.03.04 07:17:42.974 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 313073 records (86.7%).
[PID:06276:010 2015.03.04 07:17:48.028 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 313475 records (87.0%).
[PID:06276:010 2015.03.04 07:17:53.036 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 314193 records (87.4%).
[PID:06276:010 2015.03.04 07:17:58.044 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 315149 records (88.0%).
[PID:06276:010 2015.03.04 07:18:03.052 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 315877 records (88.4%).
[PID:06276:010 2015.03.04 07:18:08.075 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 316487 records (88.8%).
[PID:06276:010 2015.03.04 07:18:13.083 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 317307 records (89.3%).
[PID:06276:010 2015.03.04 07:18:18.122 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 317876 records (89.6%).
[PID:06276:010 2015.03.04 07:18:23.130 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 318537 records (90.0%).
[PID:06276:010 2015.03.04 07:18:28.137 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 319223 records (90.4%).
[PID:06276:010 2015.03.04 07:18:33.145 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 319971 records (90.9%).
[PID:06276:010 2015.03.04 07:18:38.153 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 320591 records (91.2%).
[PID:06276:010 2015.03.04 07:18:43.192 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 321406 records (91.7%).
[PID:06276:010 2015.03.04 07:18:48.215 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 321900 records (92.0%).
[PID:06276:003 2015.03.04 07:18:51.928 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:52710, L127.0.0.1:1113, {46d36ba0-7d05-4cc3-af5a-afa08fc3833a}].
[PID:06276:010 2015.03.04 07:18:53.239 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 322468 records (92.3%).
[PID:06276:010 2015.03.04 07:18:58.247 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 322792 records (92.5%).
[PID:06276:010 2015.03.04 07:19:03.270 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 323302 records (92.8%).
[PID:06276:010 2015.03.04 07:19:08.278 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 323862 records (93.1%).
[PID:06276:010 2015.03.04 07:19:13.286 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 324240 records (93.3%).
[PID:06276:010 2015.03.04 07:19:18.293 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 324922 records (93.8%).
[PID:06276:007 2015.03.04 07:19:22.895 TRACE InMemoryBus ] SLOW BUS MSG [Worker #1 Bus]: ReadStreamEventsBackwardCompleted - 343ms. Handler: RequestResponseDispatcher`2.
[PID:06276:007 2015.03.04 07:19:22.911 TRACE QueuedHandlerThreadP] SLOW QUEUE MSG [Worker #1]: ReadStreamEventsBackwardCompleted - 358ms. Q: 0/1.
[PID:06276:010 2015.03.04 07:19:23.504 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 325656 records (94.2%).
[PID:06276:010 2015.03.04 07:19:28.590 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 326010 records (94.4%).
[PID:06276:010 2015.03.04 07:19:33.785 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 326576 records (94.7%).
[PID:06276:010 2015.03.04 07:19:38.792 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 326922 records (94.9%).
[PID:06276:010 2015.03.04 07:19:43.800 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 327403 records (95.1%).
[PID:06276:010 2015.03.04 07:19:48.886 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 328158 records (95.4%).
[PID:06276:010 2015.03.04 07:19:53.894 DEBUG ReadIndex ] ReadIndex Rebuilding: processed 328740 records (95.8%).
[PID:06276:010 2015.03.04 07:19:55.126 DEBUG ReadIndex ] ReadIndex Rebuilding Done: total processed 338107 records, time elapsed: 00:05:51.4191156.
[PID:06276:010 2015.03.04 07:19:55.126 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: SystemInit - 351543ms. Q: 0/0.
[PID:06276:012 2015.03.04 07:19:55.126 INFO SingleVNodeControlle] ========== [127.0.0.1:2113] SYSTEM START…
[PID:06276:012 2015.03.04 07:19:55.142 INFO SingleVNodeControlle] ========== [127.0.0.1:2113] PRE-MASTER STATE, WAITING FOR CHASER TO CATCH UP…
[PID:06276:012 2015.03.04 07:19:55.142 INFO SingleVNodeControlle] ========== [127.0.0.1:2113] IS WORKING!!! SPARTA!!!
[PID:06276:010 2015.03.04 07:19:55.220 DEBUG EpochManager ] === Writing E21@1399505430:{5dfedac7-60ed-46ec-be94-c8a58b1a002f} (previous epoch at 1381922170).
[PID:06276:017 2015.03.04 07:19:56.530 ERROR ProjectionManager ] The ‘CreateSamosaProjection’ projection faulted due to 'Cannot create a projection state handler.
Handler type: JS
Query:
fromAll()
.when({
SamosaFromReceiptCreated: function (s, e) {
linkTo(‘Receipt-’ + e.body.ReceiptId + ‘-SamosaCreated’, e);
},
ReceiptDiscarded: function (s, e) {
linkTo(‘Receipt-’ + e.body.Id.Id + ‘-SamosaCreated’, e);
}
});
Message:
Failed to compile script. Terminated?’
EventStore.Projections.Core.v8.Js1Exception: Failed to compile script. Terminated?
at EventStore.Projections.Core.v8.CompiledScript.CheckResult(IntPtr scriptHandle, Boolean terminated, Boolean disposeScriptOnException) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\v8\CompiledScript.cs:line 78
at EventStore.Projections.Core.v8.PreludeScript…ctor(String script, String fileName, Func2 getModuleSourceAndFileName, Action2 cancelCallbackFactory, Action`1 logger) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\v8\PreludeScript.cs:line 69
at EventStore.Projections.Core.Services.v8.V8ProjectionStateHandler…ctor(String preludeName, String querySource, Func2 getModuleSource, Action1 logger, Action`2 cancelCallbackFactory) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\v8\V8ProjectionStateHandler.cs:line 54
at EventStore.Projections.Core.Services.Management.ProjectionStateHandlerFactory.Create(String factoryType, String source, Action2 cancelCallbackFactory, Action1 logger) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Management\ProjectionStateHandlerFactory.cs:line 75
at EventStore.Projections.Core.Services.Management.ManagedProjection.<>c__DisplayClass42.b__41() in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Management\ManagedProjection.cs:line 741
[PID:06276:016 2015.03.04 07:19:56.530 ERROR ProjectionManager ] The ‘CreateSamosaTemplateProjection’ projection faulted due to 'Cannot create a projection state handler.
Handler type: JS
Query:
fromAll()
.when({
SamosaTemplateCreated: function (s, e) {
linkTo(‘Receipt-’ + e.body.ReceiptId + ‘-SamosaTemplateCreated’, e);
},
SamosaTemplateCreated_V2: function (s, e) {
linkTo(‘Receipt-’ + e.body.ReceiptId + ‘-SamosaTemplateCreated’, e);
},
ReceiptDiscarded: function (s, e) {
linkTo(‘Receipt-’ + e.body.Id.Id + ‘-SamosaTemplateCreated’, e);
}
});
Message:
Failed to compile script. Terminated?’
EventStore.Projections.Core.v8.Js1Exception: Failed to compile script. Terminated?
at EventStore.Projections.Core.v8.CompiledScript.CheckResult(IntPtr scriptHandle, Boolean terminated, Boolean disposeScriptOnException) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\v8\CompiledScript.cs:line 78
at EventStore.Projections.Core.v8.PreludeScript…ctor(String script, String fileName, Func2 getModuleSourceAndFileName, Action2 cancelCallbackFactory, Action`1 logger) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\v8\PreludeScript.cs:line 69
at EventStore.Projections.Core.Services.v8.V8ProjectionStateHandler…ctor(String preludeName, String querySource, Func2 getModuleSource, Action1 logger, Action`2 cancelCallbackFactory) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\v8\V8ProjectionStateHandler.cs:line 54
at EventStore.Projections.Core.Services.Management.ProjectionStateHandlerFactory.Create(String factoryType, String source, Action2 cancelCallbackFactory, Action1 logger) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Management\ProjectionStateHandlerFactory.cs:line 75
at EventStore.Projections.Core.Services.Management.ManagedProjection.<>c__DisplayClass42.b__41() in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Management\ManagedProjection.cs:line 741
[PID:06276:015 2015.03.04 07:19:56.530 ERROR ProjectionManager ] The ‘PendingCompleteReceiptGaathas’ projection faulted due to 'Cannot create a projection state handler.
Handler type: JS
Query:
fromAll()
.when({
$init: function () {
return { ids: [] }; // initial state
},
CompleteReceiptStarted: function (s, e) {
s.ids.push(e.body.Id.Id);
emit(‘PendingGaathas’, ‘GaathasChanged’, { ids: s.ids, cause: 'started ’ + e.body.Id.Id });
return s;
},
CompleteReceiptSucceeded: function (s, e) {
var index = s.ids.indexOf(e.body.Id.Id);
s.ids.splice(index, 1);
emit(‘PendingGaathas’, ‘GaathasChanged’, { ids: s.ids, cause: 'succeeded ’ + e.body.Id.Id });
return s;
},
CompleteReceiptReverted: function (s, e) {
var index = s.ids.indexOf(e.body.Id.Id);
s.ids.splice(index, 1);
emit(‘PendingGaathas’, ‘GaathasChanged’, { ids: s.ids, cause: 'reverted ’ + e.body.Id.Id });
return s;
}
});
Message:
Failed to compile script. Terminated?’
EventStore.Projections.Core.v8.Js1Exception: Failed to compile script. Terminated?
at EventStore.Projections.Core.v8.CompiledScript.CheckResult(IntPtr scriptHandle, Boolean terminated, Boolean disposeScriptOnException) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\v8\CompiledScript.cs:line 78
at EventStore.Projections.Core.v8.PreludeScript…ctor(String script, String fileName, Func2 getModuleSourceAndFileName, Action2 cancelCallbackFactory, Action`1 logger) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\v8\PreludeScript.cs:line 69
at EventStore.Projections.Core.Services.v8.V8ProjectionStateHandler…ctor(String preludeName, String querySource, Func2 getModuleSource, Action1 logger, Action`2 cancelCallbackFactory) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\v8\V8ProjectionStateHandler.cs:line 54
at EventStore.Projections.Core.Services.Management.ProjectionStateHandlerFactory.Create(String factoryType, String source, Action2 cancelCallbackFactory, Action1 logger) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Management\ProjectionStateHandlerFactory.cs:line 75
at EventStore.Projections.Core.Services.Management.ManagedProjection.<>c__DisplayClass42.b__41() in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Management\ManagedProjection.cs:line 741
[PID:06276:010 2015.03.04 07:19:56.562 DEBUG EpochManager ] === Update Last Epoch E21@1399505430:{5dfedac7-60ed-46ec-be94-c8a58b1a002f} (previous epoch at 1381922170).
[PID:06276:013 2015.03.04 07:19:57.591 DEBUG MonitoringService ] Failed to create stats stream ‘$stats-127.0.0.1:2113’. Reason : PrepareTimeout(Prepare phase timeout.). Retrying…
[PID:06276:013 2015.03.04 07:19:57.810 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [MonitoringQueue]: WriteEventsCompleted - 234ms. Q: 0/0.
[PID:06276:017 2015.03.04 07:19:57.810 TRACE InMemoryBus ] SLOW BUS MSG [bus]: CreateAndPrepare - 2558ms. Handler: ProjectionCoreService.
[PID:06276:017 2015.03.04 07:19:57.810 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [Projection Core #2]: CreateAndPrepare - 2558ms. Q: 0/3.
[PID:06276:014 2015.03.04 07:19:57.810 ERROR ProjectionManager ] The ‘CreateSamosaProjection’ projection faulted due to ‘Failed to compile script. Terminated?’
[PID:06276:014 2015.03.04 07:19:57.810 ERROR ProjectionManager ] The ‘PendingCompleteReceiptGaathas’ projection faulted due to ‘Failed to compile script. Terminated?’
[PID:06276:016 2015.03.04 07:19:57.810 TRACE InMemoryBus ] SLOW BUS MSG [bus]: CreateAndPrepare - 2558ms. Handler: ProjectionCoreService.
[PID:06276:016 2015.03.04 07:19:57.810 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [Projection Core #1]: CreateAndPrepare - 2558ms. Q: 2/5.
[PID:06276:014 2015.03.04 07:19:57.810 ERROR ProjectionManager ] The ‘CreateSamosaTemplateProjection’ projection faulted due to ‘Failed to compile script. Terminated?’
[PID:06276:015 2015.03.04 07:19:57.810 TRACE InMemoryBus ] SLOW BUS MSG [bus]: CreateAndPrepare - 2589ms. Handler: ProjectionCoreService.
[PID:06276:015 2015.03.04 07:19:57.810 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [Projection Core #0]: CreateAndPrepare - 2589ms. Q: 0/7.
[PID:06276:010 2015.03.04 07:19:57.810 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: BecomeMaster - 2667ms. Q: 0/1.
[PID:06276:016 2015.03.04 07:19:57.856 ERROR QueuedHandlerMRES ] Error while processing message EventStore.Projections.Core.Messages.CoreProjectionManagementMessage+Start in queued handler ‘Projection Core #1’.
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at EventStore.Projections.Core.Services.Processing.ProjectionCoreService.Handle(Start message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Processing\ProjectionCoreService.cs:line 190
at EventStore.Core.Bus.MessageHandler`1.TryHandle(Message message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\MessageHandler.cs:line 60
at EventStore.Core.Bus.InMemoryBus.Publish(Message message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\InMemoryBus.cs:line 350
at EventStore.Core.Bus.QueuedHandlerMRES.ReadFromQueue(Object o) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\QueuedHandlerMRES.cs:line 141
[PID:06276:017 2015.03.04 07:19:57.856 ERROR QueuedHandlerMRES ] Error while processing message EventStore.Projections.Core.Messages.CoreProjectionManagementMessage+Start in queued handler ‘Projection Core #2’.
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at EventStore.Projections.Core.Services.Processing.ProjectionCoreService.Handle(Start message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Processing\ProjectionCoreService.cs:line 190
at EventStore.Core.Bus.MessageHandler`1.TryHandle(Message message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\MessageHandler.cs:line 60
at EventStore.Core.Bus.InMemoryBus.Publish(Message message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\InMemoryBus.cs:line 350
at EventStore.Core.Bus.QueuedHandlerMRES.ReadFromQueue(Object o) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\QueuedHandlerMRES.cs:line 141
[PID:06276:015 2015.03.04 07:19:57.856 ERROR QueuedHandlerMRES ] Error while processing message EventStore.Projections.Core.Messages.CoreProjectionManagementMessage+Start in queued handler ‘Projection Core #0’.
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at EventStore.Projections.Core.Services.Processing.ProjectionCoreService.Handle(Start message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Projections.Core\Services\Processing\ProjectionCoreService.cs:line 190
at EventStore.Core.Bus.MessageHandler`1.TryHandle(Message message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\MessageHandler.cs:line 60
at EventStore.Core.Bus.InMemoryBus.Publish(Message message) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\InMemoryBus.cs:line 350
at EventStore.Core.Bus.QueuedHandlerMRES.ReadFromQueue(Object o) in c:\BuildAgent1\work\oss\windows\releasebuilds\src\EventStore\EventStore.Core\Bus\QueuedHandlerMRES.cs:line 141
[PID:06276:013 2015.03.04 07:19:57.903 TRACE MonitoringService ] Created stats stream ‘$stats-127.0.0.1:2113’, code = WrongExpectedVersion
[PID:06276:013 2015.03.04 07:19:58.543 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [MonitoringQueue]: WriteEventsCompleted - 639ms. Q: 0/0.
[PID:06276:015 2015.03.04 07:19:58.590 TRACE EventReorderingReade] Creating an event distribution point at ‘C:0/P:-1’
[PID:06276:017 2015.03.04 07:19:58.590 TRACE EventReorderingReade] Creating an event distribution point at ‘C:0/P:-1’
[PID:06276:016 2015.03.04 07:19:58.590 TRACE EventReorderingReade] Creating an event distribution point at 'C:1391942722/P:1391926022; $UserCreated: -1; ’
[PID:06276:015 2015.03.04 07:19:58.605 TRACE ProjectionCoreServic] The ‘2df834ed-1941-472e-89f3-625008c3660d’ projection subscribed to the ‘f765113e-1a06-4f31-aedd-0328d205adbc’ distribution point
[PID:06276:016 2015.03.04 07:19:58.605 TRACE ProjectionCoreServic] The ‘264fe579-0b23-49e8-a70d-3f38919c7ef6’ projection subscribed to the ‘5488305f-3e8f-4f4f-a0c6-9f253cfdfe42’ distribution point
[PID:06276:017 2015.03.04 07:19:58.605 TRACE ProjectionCoreServic] The ‘542ec9d6-ba53-4c5c-a0e1-7045cbd03dc5’ projection subscribed to the ‘d972cf4b-4e47-4098-bef2-15b5be1a720c’ distribution point
[PID:06276:015 2015.03.04 07:19:58.605 TRACE EventReorderingReade] Creating an event distribution point at ‘C:0/P:-1’
[PID:06276:015 2015.03.04 07:19:58.605 TRACE ProjectionCoreServic] The ‘d208c31b-d475-4139-a820-55a720a6388e’ projection subscribed to the ‘de4f86b7-d99d-4110-9fe6-ed9ffa1ec52d’ distribution point
[PID:06276:016 2015.03.04 07:19:58.621 TRACE EventReorderingReade] Creating an event distribution point at ‘C:0/P:-1’
[PID:06276:016 2015.03.04 07:19:58.621 TRACE ProjectionCoreServic] The ‘204b933d-631e-44c8-b296-b760e3e68163’ projection subscribed to the ‘19477356-91a7-480e-b238-625288f5524d’ distribution point
[PID:06276:017 2015.03.04 07:19:58.683 TRACE ProjectionCoreServic] The ‘542ec9d6-ba53-4c5c-a0e1-7045cbd03dc5’ subscription has unsubscribed (reader: d972cf4b-4e47-4098-bef2-15b5be1a720c)
[PID:06276:016 2015.03.04 07:19:58.683 TRACE ProjectionCoreServic] The ‘204b933d-631e-44c8-b296-b760e3e68163’ subscription has unsubscribed (reader: 19477356-91a7-480e-b238-625288f5524d)
[PID:06276:015 2015.03.04 07:19:58.683 TRACE ProjectionCoreServic] The ‘2df834ed-1941-472e-89f3-625008c3660d’ subscription has unsubscribed (reader: f765113e-1a06-4f31-aedd-0328d205adbc)
[PID:06276:015 2015.03.04 07:19:58.683 TRACE ProjectionCoreServic] The ‘d208c31b-d475-4139-a820-55a720a6388e’ subscription has unsubscribed (reader: de4f86b7-d99d-4110-9fe6-ed9ffa1ec52d)
[PID:06276:010 2015.03.04 07:20:13.816 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WritePrepares - 826ms. Q: 0/1.
[PID:06276:016 2015.03.04 07:20:14.034 TRACE HeadingEventReader ] The ‘264fe579-0b23-49e8-a70d-3f38919c7ef6’ subscription has joined the heading distribution point at ‘1399522461’
[PID:06276:016 2015.03.04 07:20:14.034 TRACE HeadingEventReader ] The ‘264fe579-0b23-49e8-a70d-3f38919c7ef6’ projection subscribed to the ‘0f3d501f-1bbf-4c77-98bf-97dae4531bec’ heading distribution point
[PID:06276:016 2015.03.04 07:20:14.034 TRACE ProjectionCoreServic] The ‘264fe579-0b23-49e8-a70d-3f38919c7ef6’ is subscribing to the heading distribution point with TF-EOF marker event at ‘1399522461’
[PID:06276:010 2015.03.04 07:26:45.797 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WritePrepares - 1060ms. Q: 0/1.
[PID:06276:010 2015.03.04 07:26:46.639 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WriteCommit - 842ms. Q: 0/0.
[PID:06276:010 2015.03.04 07:27:46.576 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WriteCommit - 1310ms. Q: 0/0.
[PID:06276:010 2015.03.04 07:31:15.952 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WriteCommit - 811ms. Q: 0/0.
[PID:06276:010 2015.03.04 08:11:17.056 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WritePrepares - 795ms. Q: 0/1.
[PID:06276:010 2015.03.04 08:11:48.959 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WritePrepares - 2683ms. Q: 0/1.
[PID:06276:010 2015.03.04 08:11:53.655 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WriteCommit - 4695ms. Q: 0/0.
[PID:06276:010 2015.03.04 08:47:48.160 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [StorageWriterQueue]: WritePrepares - 686ms. Q: 0/1.
[PID:06276:016 2015.03.04 12:18:55.473 TRACE CoreProjectionCheckp] Writing checkpoint for $users at C:1409525959/P:1409509281; $UserCreated: -1; with expected version number 130
[PID:06276:016 2015.03.04 12:18:55.473 TRACE CoreProjectionCheckp] Checkpoint has be written for projection $users at sequence number 131 (current)
[PID:06276:019 2015.03.04 12:45:33.131 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:52905, L127.0.0.1:1113, {dfb53342-a738-4e9b-8392-374fb25b150e}].
[PID:06276:016 2015.03.04 17:17:05.628 TRACE CoreProjectionCheckp] Writing checkpoint for $users at C:1419528726/P:1419512045; $UserCreated: -1; with expected version number 131
[PID:06276:016 2015.03.04 17:17:05.628 TRACE CoreProjectionCheckp] Checkpoint has be written for projection $users at sequence number 132 (current)
[PID:06276:016 2015.03.04 21:46:44.183 TRACE CoreProjectionCheckp] Writing checkpoint for $users at C:1429538857/P:1429522130; $UserCreated: -1; with expected version number 132
[PID:06276:016 2015.03.04 21:46:44.183 TRACE CoreProjectionCheckp] Checkpoint has be written for projection $users at sequence number 133 (current)
[PID:06276:031 2015.03.04 22:08:48.268 INFO TcpConnection ] [22:08:48.253: N127.0.0.1:52905, L127.0.0.1:1113, {dfb53342-a738-4e9b-8392-374fb25b150e}]:
Received bytes: 1309679, Sent bytes: 22977942
Send calls: 17136, callbacks: 17136
Receive calls: 15287, callbacks: 15287
