Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

examples/demo-subscribe-to-all.php throwing exception #103

Closed
burzum opened this issue Sep 26, 2019 · 2 comments
Closed

examples/demo-subscribe-to-all.php throwing exception #103

burzum opened this issue Sep 26, 2019 · 2 comments

Comments

@burzum
Copy link

burzum commented Sep 26, 2019

When running this script I'm getting the error below. https://github.com/prooph/event-store-client/blob/master/examples/demo-subscribe-to-all.php

This happens with Event Store V4 and V5. I've also tried the suggestion here #86 to change the server config #86

connection closed
PHP Fatal error:  Uncaught Prooph\EventStore\Exception\ConnectionClosed: Connection 'e5bbacd6a74b5e45b71a200d97e6efbe' was closed in C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store\src\Exception\ConnectionClosed.php:20
Stack trace:
#0 C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store-client\src\Internal\SubscriptionsManager.php(54): Prooph\EventStore\Exception\ConnectionClosed::withName('e5bbacd6a74b5e4...')
#1 C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store-client\src\Internal\EventStoreConnectionLogicHandler.php(284): Prooph\EventStoreClient\Internal\SubscriptionsManager->cleanUp()
#2 C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store-client\src\Internal\EventStoreConnectionLogicHandler.php(526): Prooph\EventStoreClient\Internal\EventStoreConnectionLogicHandler->closeConnection('Reconnection li...')
#3 C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store-client\src\Internal\EventStoreConnectionLogicHandler.php(200): Prooph\EventStoreClient\Internal\EventStoreConnectionLogicHandler->timerTick()
#4 C:\xampp in C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store\src\Exception\ConnectionClosed.php on line 20

Fatal error: Uncaught Prooph\EventStore\Exception\ConnectionClosed: Connection 'e5bbacd6a74b5e45b71a200d97e6efbe' was closed in C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store\src\Exception\ConnectionClosed.php on line 20

Prooph\EventStore\Exception\ConnectionClosed: Connection 'e5bbacd6a74b5e45b71a200d97e6efbe' was closed in C:\xampp\htdocs\wa-next-app\vendor\prooph\event-store\src\Exception\ConnectionClosed.php on line 20

Call Stack:
    0.0004     421328   1. {main}() C:\xampp\htdocs\wa-next-app\all_stream.php:0
    0.0168    1720488   2. Amp\Loop::run() C:\xampp\htdocs\wa-next-app\all_stream.php:60
    0.0172    1731304   3. Amp\Loop\NativeDriver->run() C:\xampp\htdocs\wa-next-app\vendor\amphp\amp\lib\Loop.php:84
    2.4435    6141976   4. Amp\Loop\NativeDriver->tick() C:\xampp\htdocs\wa-next-app\vendor\amphp\amp\lib\Loop\Driver.php:72
    2.4436    6138776   5. Amp\Loop\NativeDriver->error() C:\xampp\htdocs\wa-next-app\vendor\amphp\amp\lib\Loop\Driver.php:130

C:\xampp\htdocs\wa-next-app [accounting-domain +0 ~0 -1 | +7 ~7 -0 !]

Here is the log from the event store:

{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.025100Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "\n{description,-25} {version} ({branch}\/{hashtag}, {timestamp})", "EventProperties": { "description": "ES VERSION:", "version": "5.0.2.0", "branch": "oss-v5.0.2", "hashtag": "5b3d4b0680e938e497673146eaafe290f53726a3", "timestamp": "Thu, 18 Jul 2019 09:14:15 +0400" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.055020Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "{description,-25} {osFlavor} ({osVersion})", "EventProperties": { "description": "OS:", "osFlavor": "Windows", "osVersion": "Microsoft Windows NT 6.2.9200.0" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.055020Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "{description,-25} {osRuntimeVersion} ({architecture}-bit)", "EventProperties": { "description": "RUNTIME:", "osRuntimeVersion": ".NET 4.0.30319.42000", "architecture": 64 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.055020Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "{description,-25} {maxGeneration}", "EventProperties": { "description": "GC:", "maxGeneration": "3 GENERATIONS" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.055020Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "{description,-25} {logsDirectory}", "EventProperties": { "description": "LOGS:", "logsDirectory": "C:\\webstack\\event-store-5\\logs" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.089926Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "{@esOptions}", "EventProperties": { "esOptions": {"defaults":{"Help":"False","Version":"False","Log":"C:\\webstack\\event-store-5\\logs","Config":"","Defines":"System.String[]","WhatIf":"False","DisableHTTPCaching":"False","MonoMinThreadpoolSize":"10","IntIp":"127.0.0.1","ExtIp":"127.0.0.1","IntHttpPort":"2112","ExtHttpPort":"2113","IntTcpPort":"1112","IntSecureTcpPort":"0","ExtTcpPort":"1113","ExtSecureTcpPortAdvertiseAs":"0","ExtSecureTcpPort":"0","ExtIpAdvertiseAs":null,"ExtTcpPortAdvertiseAs":"0","ExtHttpPortAdvertiseAs":"0","IntIpAdvertiseAs":null,"IntSecureTcpPortAdvertiseAs":"0","IntTcpPortAdvertiseAs":"0","IntHttpPortAdvertiseAs":"0","IntTcpHeartbeatTimeout":"700","ExtTcpHeartbeatTimeout":"1000","IntTcpHeartbeatInterval":"700","ExtTcpHeartbeatInterval":"2000","GossipOnSingleNode":"False","Force":"False","ClusterSize":"1","NodePriority":"0","MinFlushDelayMs":"2","CommitCount":"-1","PrepareCount":"-1","AdminOnExt":"True","StatsOnExt":"True","GossipOnExt":"True","DisableScavengeMerging":"False","ScavengeHistoryMaxAge":"30","DiscoverViaDns":"True","ClusterDns":"fake.dns","ClusterGossipPort":"30777","GossipSeed":"System.Net.IPEndPoint[]","StatsPeriodSec":"30","CachedChunks":"-1","ReaderThreadsCount":"4","ChunksCacheSize":"536871424","MaxMemTableSize":"1000000","HashCollisionReadLimit":"100","Db":"C:\\webstack\\event-store-5\\data","Index":null,"MemDb":"False","SkipDbVerify":"False","WriteThrough":"False","Unbuffered":"False","ChunkInitialReaderCount":"5","ProjectionThreads":"3","WorkerThreads":"5","ProjectionsQueryExpiry":"5","FaultOutOfOrderProjections":"False","IntHttpPrefixes":"System.String[]","ExtHttpPrefixes":"System.String[]","EnableTrustedAuth":"False","AddInterfacePrefixes":"True","CertificateStoreLocation":"","CertificateStoreName":"","CertificateSubjectName":"","CertificateThumbprint":"","CertificateFile":"","CertificatePassword":"","UseInternalSsl":"False","DisableInsecureTCP":"False","SslTargetHost":"n\/a","SslValidateServer":"True","AuthenticationType":"internal","AuthenticationConfig":"","DisableFirstLevelHttpAuthorization":"False","PrepareTimeoutMs":"2000","CommitTimeoutMs":"2000","UnsafeDisableFlushToDisk":"False","BetterOrdering":"False","UnsafeIgnoreHardDelete":"False","SkipIndexVerify":"False","IndexCacheDepth":"16","OptimizeIndexMerge":"False","GossipIntervalMs":"1000","GossipAllowedDifferenceMs":"60000","GossipTimeoutMs":"500","EnableHistograms":"False","LogHttpRequests":"False","AlwaysKeepScavenged":"False","SkipIndexScanOnReads":"False","ReduceFileCachePressure":"False","InitializationThreads":"1","StructuredLog":"True","MaxAutoMergeIndexLevel":"2147483647"},"modified":{"RunProjections":"all","StartStandardProjections":"true","ConnectionPendingSendBytesThreshold":"50485760"}} } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.099900Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "Quorum size set to {quorum}", "EventProperties": { "quorum": 1 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.099900Z", "Level": "Info", "Logger": "ProgramBase`1", "Message": "Cannot find plugins path: {pluginsDirectory}", "EventProperties": { "pluginsDirectory": "C:\\webstack\\event-store-5\\plugins" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.192652Z", "Level": "Info", "Logger": "VNodeBuilder", "Message": "{description,-25} {instanceId}", "EventProperties": { "description": "INSTANCE ID:", "instanceId": "e12611a3-653e-41c4-8934-acc674b75b90" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.192652Z", "Level": "Info", "Logger": "VNodeBuilder", "Message": "{description,-25} {path}", "EventProperties": { "description": "DATABASE:", "path": "C:\\webstack\\event-store-5\\data" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.192652Z", "Level": "Info", "Logger": "VNodeBuilder", "Message": "{description,-25} {writerCheckpoint} (0x{writerCheckpoint:X})", "EventProperties": { "description": "WRITER CHECKPOINT:", "writerCheckpoint": 138418629 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.192652Z", "Level": "Info", "Logger": "VNodeBuilder", "Message": "{description,-25} {chaserCheckpoint} (0x{chaserCheckpoint:X})", "EventProperties": { "description": "CHASER CHECKPOINT:", "chaserCheckpoint": 138418629 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.192652Z", "Level": "Info", "Logger": "VNodeBuilder", "Message": "{description,-25} {epochCheckpoint} (0x{epochCheckpoint:X})", "EventProperties": { "description": "EPOCH CHECKPOINT:", "epochCheckpoint": 138323389 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.192652Z", "Level": "Info", "Logger": "VNodeBuilder", "Message": "{description,-25} {truncateCheckpoint} (0x{truncateCheckpoint:X})", "EventProperties": { "description": "TRUNCATE CHECKPOINT:", "truncateCheckpoint": -1 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.246508Z", "Level": "Trace", "Logger": "MessageHierarchy", "Message": "MessageHierarchy initialization took {elapsed}.", "EventProperties": { "elapsed": "00:00:00.0264326" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.610907Z", "Level": "Trace", "Logger": "TFChunk", "Message": "Opened ongoing {chunk} as version {version}", "EventProperties": { "chunk": "C:\\webstack\\event-store-5\\data\\chunk-000000.000000", "version": 3 } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.701594Z", "Level": "Trace", "Logger": "TFChunk", "Message": "CACHED TFChunk {chunk} in {elapsed}.", "EventProperties": { "chunk": "#0-0 (chunk-000000.000000)", "elapsed": "00:00:00.0851156" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.921410Z", "Level": "Info", "Logger": "MiniWeb", "Message": "Starting MiniWeb for {localWebRootPath} ==> {fileSystemRoot}", "EventProperties": { "localWebRootPath": "\/web\/es\/js\/projections", "fileSystemRoot": "C:\\webstack\\event-store-5\\projections" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.921410Z", "Level": "Info", "Logger": "MiniWeb", "Message": "Starting MiniWeb for {localWebRootPath} ==> {fileSystemRoot}", "EventProperties": { "localWebRootPath": "\/web\/es\/js\/projections\/v8\/Prelude", "fileSystemRoot": "C:\\webstack\\event-store-5\\Prelude" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.921410Z", "Level": "Trace", "Logger": "MiniWeb", "Message": "Binding MiniWeb to {path}", "EventProperties": { "path": "\/web\/es\/js\/projections\/{*remaining_path}" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.921410Z", "Level": "Trace", "Logger": "MiniWeb", "Message": "Binding MiniWeb to {path}", "EventProperties": { "path": "\/web\/es\/js\/projections\/v8\/Prelude\/{*remaining_path}" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.933379Z", "Level": "Info", "Logger": "MiniWeb", "Message": "Starting MiniWeb for {localWebRootPath} ==> {fileSystemRoot}", "EventProperties": { "localWebRootPath": "\/web", "fileSystemRoot": "C:\\webstack\\event-store-5\\clusternode-web" } }
{ "PID": "23940", "ThreadID": "1", "Date": "2019-09-26T10:58:57.933379Z", "Level": "Trace", "Logger": "MiniWeb", "Message": "Binding MiniWeb to {path}", "EventProperties": { "path": "\/web\/{*remaining_path}" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:57.933379Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] SYSTEM INIT...", "EventProperties": { "internalHttp": "127.0.0.1:2112" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:57.933379Z", "Level": "Info", "Logger": "TcpServerListener", "Message": "Starting {securityType} TCP listening on TCP endpoint: {serverEndPoint}.", "EventProperties": { "securityType": "Normal", "serverEndPoint": "127.0.0.1:1113" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:57.933379Z", "Level": "Info", "Logger": "HttpAsyncServer", "Message": "Starting HTTP server on [{listenPrefixes}]...", "EventProperties": { "listenPrefixes": "http:\/\/127.0.0.1:2113\/,http:\/\/localhost:2113\/" } }
{ "PID": "23940", "ThreadID": "21", "Date": "2019-09-26T10:58:57.942354Z", "Level": "Info", "Logger": "IndexCommitter", "Message": "TableIndex initialization...", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:57.942354Z", "Level": "Info", "Logger": "HttpAsyncServer", "Message": "HTTP server is up and listening on [{listenPrefixes}]", "EventProperties": { "listenPrefixes": "http:\/\/127.0.0.1:2113\/,http:\/\/localhost:2113\/" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:57.942354Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] Service '{service}' initialized.", "EventProperties": { "internalHttp": "127.0.0.1:2112", "service": "StorageReader" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:57.942354Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] Service '{service}' initialized.", "EventProperties": { "internalHttp": "127.0.0.1:2112", "service": "StorageWriter" } }
{ "PID": "23940", "ThreadID": "21", "Date": "2019-09-26T10:58:57.942354Z", "Level": "Info", "Logger": "IndexCommitter", "Message": "ReadIndex building...", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "21", "Date": "2019-09-26T10:58:58.021147Z", "Level": "Debug", "Logger": "IndexCommitter", "Message": "ReadIndex rebuilding done: total processed {processed} records, time elapsed: {elapsed}.", "EventProperties": { "processed": 8209, "elapsed": "00:00:00.0718118" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.021147Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] Service '{service}' initialized.", "EventProperties": { "internalHttp": "127.0.0.1:2112", "service": "StorageChaser" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.021147Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] SYSTEM START...", "EventProperties": { "internalHttp": "127.0.0.1:2112" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.021147Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] IS UNKNOWN...", "EventProperties": { "internalHttp": "127.0.0.1:2112" } }
{ "PID": "23940", "ThreadID": "9", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "PersistentSubscriptionService", "Message": "Persistent subscriptions received state change to {state}. Stopping listening", "EventProperties": { "state": "Unknown" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: STARTING ELECTIONS.", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={view}) SHIFT TO LEADER ELECTION.", "EventProperties": { "view": 0 } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={view}) VIEWCHANGE FROM [{serverInternalHttp}, {serverId:B}].", "EventProperties": { "view": 0, "serverInternalHttp": "127.0.0.1:2112", "serverId": "e12611a3-653e-41c4-8934-acc674b75b90" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={view}) MAJORITY OF VIEWCHANGE.", "EventProperties": { "view": 0 } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={lastAttemptedView}) SHIFT TO PREPARE PHASE.", "EventProperties": { "lastAttemptedView": 0 } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={view}) PREPARE_OK FROM {nodeInfo}.", "EventProperties": { "view": 0, "nodeInfo": "[127.0.0.1:2112,{e12611a3-653e-41c4-8934-acc674b75b90}](L=138400384,W=138418629,C=138418629,E2@138323389:{fe493248-9ce1-458e-a335-a0f583c58a65})" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={lastAttemptedView}) SHIFT TO REG_LEADER.", "EventProperties": { "lastAttemptedView": 0 } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={lastAttemptedView}) SENDING PROPOSAL CANDIDATE: {formatNodeInfo}, ME: {ownInfo}.", "EventProperties": { "lastAttemptedView": 0, "formatNodeInfo": "[127.0.0.1:2112,{e12611a3-653e-41c4-8934-acc674b75b90}](L=138400384,W=138418629,C=138418629,E2@138323389:{fe493248-9ce1-458e-a335-a0f583c58a65})", "ownInfo": "[127.0.0.1:2112,{e12611a3-653e-41c4-8934-acc674b75b90}](L=138400384,W=138418629,C=138418629,E2@138323389:{fe493248-9ce1-458e-a335-a0f583c58a65})" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Debug", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={view}) ACCEPT FROM [{serverInternalHttp},{serverId:B}] M=[{masterInternalHttp},{masterId:B}]).", "EventProperties": { "view": 0, "serverInternalHttp": "127.0.0.1:2112", "serverId": "e12611a3-653e-41c4-8934-acc674b75b90", "masterInternalHttp": "127.0.0.1:2112", "masterId": "e12611a3-653e-41c4-8934-acc674b75b90" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.037105Z", "Level": "Info", "Logger": "ElectionsService", "Message": "ELECTIONS: (V={view}) DONE. ELECTED MASTER = {masterInfo}. ME={ownInfo}.", "EventProperties": { "view": 0, "masterInfo": "[127.0.0.1:2112,{e12611a3-653e-41c4-8934-acc674b75b90}](L=138400384,W=138418629,C=138418629,E2@138323389:{fe493248-9ce1-458e-a335-a0f583c58a65})", "ownInfo": "[127.0.0.1:2112,{e12611a3-653e-41c4-8934-acc674b75b90}](L=138400384,W=138418629,C=138418629,E2@138323389:{fe493248-9ce1-458e-a335-a0f583c58a65})" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.053061Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] PRE-MASTER STATE, WAITING FOR CHASER TO CATCH UP...", "EventProperties": { "internalHttp": "127.0.0.1:2112" } }
{ "PID": "23940", "ThreadID": "17", "Date": "2019-09-26T10:58:58.053061Z", "Level": "Debug", "Logger": "PersistentSubscriptionService", "Message": "Persistent subscriptions received state change to {state}. Stopping listening", "EventProperties": { "state": "PreMaster" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.053061Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] IS MASTER... SPARTA!", "EventProperties": { "internalHttp": "127.0.0.1:2112" } }
{ "PID": "23940", "ThreadID": "11", "Date": "2019-09-26T10:58:58.053061Z", "Level": "Debug", "Logger": "PersistentSubscriptionService", "Message": "Persistent subscriptions Became Master so now handling subscriptions", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.053061Z", "Level": "Debug", "Logger": "StorageScavenger", "Message": "Searching for incomplete scavenges on node {nodeEndPoint}.", "EventProperties": { "nodeEndPoint": "127.0.0.1:2113" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.080987Z", "Level": "Debug", "Logger": "StorageScavenger", "Message": "No incomplete scavenges found on node {nodeEndPoint}.", "EventProperties": { "nodeEndPoint": "127.0.0.1:2113" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "StorageScavenger", "Message": "Max age and $ops read permission already set for the {stream} stream.", "EventProperties": { "stream": "$scavenges" } }
{ "PID": "23940", "ThreadID": "18", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "EpochManager", "Message": "=== Writing E{epochNumber}@{epochPosition}:{epochId:B} (previous epoch at {lastEpochPosition}).", "EventProperties": { "epochNumber": 3, "epochPosition": 138418629, "epochId": "100cad82-3693-44b6-ae49-9669474167b2", "lastEpochPosition": 138323389 } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: Starting Projections Core Coordinator. (Node State : {state})", "EventProperties": { "state": "Master" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "PROJECTIONS: Starting Projections Manager. (Node State : {state})", "EventProperties": { "state": "Master" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Starting Projection Manager Response Reader (reads from $projections-$master)", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "18", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "EpochManager", "Message": "=== Update Last Epoch E{epochNumber}@{epochPosition}:{epochId:B} (previous epoch at {lastEpochPosition}).", "EventProperties": { "epochNumber": 3, "epochPosition": 138418629, "epochId": "100cad82-3693-44b6-ae49-9669474167b2", "lastEpochPosition": 138323389 } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Starting Projection Core Reader (reads from $projections-${coreServiceId})", "EventProperties": { "coreServiceId": "df59b5a450434bc3910a0d155ebacbae" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Starting Projection Core Reader (reads from $projections-${coreServiceId})", "EventProperties": { "coreServiceId": "87b7b512b05d43c48393fa958330232d" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.082990Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Starting Projection Core Reader (reads from $projections-${coreServiceId})", "EventProperties": { "coreServiceId": "041026d75e9542d09a0b658bbb00817f" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Resetting Worker Writer", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Resetting Master Writer", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Resetting Master Writer", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "EventReaderCoreService" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "EventReaderCoreService" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "EventReaderCoreService" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "ProjectionCoreService" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "ProjectionCoreService" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "ProjectionCoreService" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.101933Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Resetting Master Writer", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-${coreServiceId})", "EventProperties": { "coreServiceId": "041026d75e9542d09a0b658bbb00817f" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-${coreServiceId})", "EventProperties": { "coreServiceId": "87b7b512b05d43c48393fa958330232d" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-${coreServiceId})", "EventProperties": { "coreServiceId": "df59b5a450434bc3910a0d155ebacbae" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "ProjectionCoreServiceCommandReader" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "ProjectionCoreServiceCommandReader" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Finished Starting Projection Manager Response Reader (reads from $projections-$master)", "EventProperties": {  } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreCoordinator", "Message": "PROJECTIONS: SubComponent Started: {subComponent}", "EventProperties": { "subComponent": "ProjectionCoreServiceCommandReader" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Starting read {stream}", "EventProperties": { "stream": "$projections-$control-100cad82-3693-44b6-ae49-9669474167b2" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Starting read {stream}", "EventProperties": { "stream": "$projections-$control-100cad82-3693-44b6-ae49-9669474167b2" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Starting read {stream}", "EventProperties": { "stream": "$projections-$control-100cad82-3693-44b6-ae49-9669474167b2" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 402, "command": "$response-reader-starting" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 403, "command": "$projection-worker-started" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 404, "command": "$projection-worker-started" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 405, "command": "$projection-worker-started" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.147811Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "PROJECTIONS: Reading Existing Projections from {stream}", "EventProperties": { "stream": "$projections-$all" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "PROJECTIONS: Found the following projections in {stream}: {@projections}", "EventProperties": { "stream": "$projections-$all", "projections": ["$streams","$stream_by_category","$by_event_type","$by_category","$by_correlation_id"] } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "Adding projection {projectionCorrelationId}@{projection} to list", "EventProperties": { "projectionCorrelationId": "d7246104-1a38-4436-9546-78925579a8ce", "projection": "$streams" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "Adding projection {projectionCorrelationId}@{projection} to list", "EventProperties": { "projectionCorrelationId": "9892404c-cd41-432f-ad9f-59cbd0138921", "projection": "$stream_by_category" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "Adding projection {projectionCorrelationId}@{projection} to list", "EventProperties": { "projectionCorrelationId": "ea127e9a-341a-4482-9c04-b01cc9b6855d", "projection": "$by_event_type" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "Adding projection {projectionCorrelationId}@{projection} to list", "EventProperties": { "projectionCorrelationId": "5050e99a-58c3-4c86-80d8-f2f62bfd755b", "projection": "$by_category" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Debug", "Logger": "ProjectionManager", "Message": "Adding projection {projectionCorrelationId}@{projection} to list", "EventProperties": { "projectionCorrelationId": "b4289f98-59fc-4c33-bb9e-77de61a1bf0f", "projection": "$by_correlation_id" } }
{ "PID": "23940", "ThreadID": "20", "Date": "2019-09-26T10:58:58.167757Z", "Level": "Info", "Logger": "ClusterVNodeController", "Message": "========== [{internalHttp}] Sub System '{subSystemName}' initialized.", "EventProperties": { "internalHttp": "127.0.0.1:2112", "subSystemName": "Projections" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.204659Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$create-and-prepare", "workerId": "$projections-$df59b5a4-5043-4bc3-910a-0d155ebacbae", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$create-and-prepare", "workerId": "$projections-$87b7b512-b05d-43c4-8393-fa958330232d", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$create-and-prepare", "workerId": "$projections-$041026d7-5e95-42d0-9a0b-658bbb00817f", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$create-and-prepare", "workerId": "$projections-$df59b5a4-5043-4bc3-910a-0d155ebacbae", "isBusy": true } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$create-and-prepare", "workerId": "$projections-$041026d7-5e95-42d0-9a0b-658bbb00817f", "isBusy": true } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$df59b5a450434bc3910a0d155ebacbae", "eventType": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$87b7b512b05d43c48393fa958330232d", "eventType": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$041026d75e9542d09a0b658bbb00817f", "eventType": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$df59b5a450434bc3910a0d155ebacbae", "eventType": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 0, "command": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 0, "command": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 0, "command": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.213635Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$041026d75e9542d09a0b658bbb00817f", "eventType": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$prepared", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$prepared", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$prepared", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 1, "command": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 1, "command": "$create-and-prepare" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$prepared", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$prepared", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 409, "command": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$start", "workerId": "$projections-$87b7b512-b05d-43c4-8393-fa958330232d", "isBusy": false } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$prepared" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$prepared" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$prepared" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.257517Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 410, "command": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 412, "command": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 413, "command": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 415, "command": "$prepared" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$start", "workerId": "$projections-$041026d7-5e95-42d0-9a0b-658bbb00817f", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$start", "workerId": "$projections-$041026d7-5e95-42d0-9a0b-658bbb00817f", "isBusy": true } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$start", "workerId": "$projections-$df59b5a4-5043-4bc3-910a-0d155ebacbae", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {workerId}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$start", "workerId": "$projections-$df59b5a4-5043-4bc3-910a-0d155ebacbae", "isBusy": true } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$87b7b512b05d43c48393fa958330232d", "eventType": "$start" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 1, "command": "$start" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$041026d75e9542d09a0b658bbb00817f", "eventType": "$start" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 2, "command": "$start" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$df59b5a450434bc3910a0d155ebacbae", "eventType": "$start" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 2, "command": "$start" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$041026d75e9542d09a0b658bbb00817f", "eventType": "$start" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.270482Z", "Level": "Debug", "Logger": "MultiStreamMessageWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$df59b5a450434bc3910a0d155ebacbae", "eventType": "$start" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.297410Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 3, "command": "$start" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.297410Z", "Level": "Debug", "Logger": "ProjectionCoreServiceCommandReader", "Message": "PROJECTIONS: Command received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 3, "command": "$start" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.304393Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$started", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.304393Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$started", "stream": "$projections-$master", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.304393Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 422, "command": "$started" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.304393Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 423, "command": "$started" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.323341Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$started", "stream": "$projections-$master", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.323341Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 427, "command": "$started" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.333314Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$started" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.360243Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$started" } }
{ "PID": "23940", "ThreadID": "27", "Date": "2019-09-26T10:58:58.360243Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$started" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.433048Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$started", "stream": "$projections-$master", "isBusy": true } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.454990Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Scheduling the writing of {command} to {stream}. Current status of Writer: Busy: {isBusy}", "EventProperties": { "command": "$started", "stream": "$projections-$master", "isBusy": false } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.482914Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 435, "command": "$started" } }
{ "PID": "23940", "ThreadID": "24", "Date": "2019-09-26T10:58:58.482914Z", "Level": "Debug", "Logger": "ProjectionManagerResponseReader", "Message": "PROJECTIONS: Response received: {eventNumber}@{command}", "EventProperties": { "eventNumber": 438, "command": "$started" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:58.563698Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$started" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:58.563698Z", "Level": "Debug", "Logger": "ResponseWriter", "Message": "PROJECTIONS: Finished writing events to {stream}: {eventType}", "EventProperties": { "stream": "$projections-$master", "eventType": "$started" } }
{ "PID": "23940", "ThreadID": "8", "Date": "2019-09-26T10:58:58.849932Z", "Level": "Trace", "Logger": "QueuedHandlerThreadPool", "Message": "SLOW QUEUE MSG [{queue}]: {message} - {elapsed}ms. Q: {prevQueueCount}\/{curQueueCount}.", "EventProperties": { "queue": "MonitoringQueue", "message": "SystemInit", "elapsed": 911, "prevQueueCount": 0, "curQueueCount": 3 } }
{ "PID": "23940", "ThreadID": "5", "Date": "2019-09-26T10:58:58.867884Z", "Level": "Trace", "Logger": "MonitoringService", "Message": "Created stats stream '{stream}', code = {result}", "EventProperties": { "stream": "$stats-127.0.0.1:2113", "result": "WrongExpectedVersion" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:59.055383Z", "Level": "Trace", "Logger": "InMemoryBus", "Message": "SLOW BUS MSG [{bus}]: {message} - {elapsed}ms. Handler: {handler}.", "EventProperties": { "bus": "bus", "message": "UnwrapEnvelopeMessage", "elapsed": 49, "handler": "UnwrapEnvelopeHandler" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:59.055383Z", "Level": "Trace", "Logger": "QueuedHandlerMRES", "Message": "SLOW QUEUE MSG [{queue}]: {message} - {elapsed}ms. Q: {prevQueueCount}\/{curQueueCount}.", "EventProperties": { "queue": "Projection Core #0", "message": "UnwrapEnvelopeMessage", "elapsed": 49, "prevQueueCount": 322, "curQueueCount": 575 } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:59.374530Z", "Level": "Trace", "Logger": "InMemoryBus", "Message": "SLOW BUS MSG [{bus}]: {message} - {elapsed}ms. Handler: {handler}.", "EventProperties": { "bus": "bus", "message": "UnwrapEnvelopeMessage", "elapsed": 60, "handler": "UnwrapEnvelopeHandler" } }
{ "PID": "23940", "ThreadID": "26", "Date": "2019-09-26T10:58:59.374530Z", "Level": "Trace", "Logger": "QueuedHandlerMRES", "Message": "SLOW QUEUE MSG [{queue}]: {message} - {elapsed}ms. Q: {prevQueueCount}\/{curQueueCount}.", "EventProperties": { "queue": "Projection Core #1", "message": "UnwrapEnvelopeMessage", "elapsed": 60, "prevQueueCount": 481, "curQueueCount": 736 } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:59.387495Z", "Level": "Trace", "Logger": "InMemoryBus", "Message": "SLOW BUS MSG [{bus}]: {message} - {elapsed}ms. Handler: {handler}.", "EventProperties": { "bus": "bus", "message": "UnwrapEnvelopeMessage", "elapsed": 61, "handler": "UnwrapEnvelopeHandler" } }
{ "PID": "23940", "ThreadID": "25", "Date": "2019-09-26T10:58:59.387495Z", "Level": "Trace", "Logger": "QueuedHandlerMRES", "Message": "SLOW QUEUE MSG [{queue}]: {message} - {elapsed}ms. Q: {prevQueueCount}\/{curQueueCount}.", "EventProperties": { "queue": "Projection Core #0", "message": "UnwrapEnvelopeMessage", "elapsed": 62, "prevQueueCount": 386, "curQueueCount": 642 } }
@prolic
Copy link
Member

prolic commented Sep 26, 2019 via email

@prolic
Copy link
Member

prolic commented Nov 25, 2019

Cannot reproduce. Maybe it's fixed by another commit already. Feel free to reopen, if it occurs again.

@prolic prolic closed this as completed Nov 25, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants