ES 4.02 Some servers don't start/enable default projections

We are currently struggling with missing default projections.
Identical EventStore + config servers act differently.

Some have the 4 default projections (that we rely on) while other machines do not have any projections (after ES service restart and database deleted).

All configs have the runProjections=“ALL” set ???

  1. Are these single nodes or clustered event stores?
  2. Do you have logs for the nodes which don’t have the projections started up?

Single nodes:

[PID:07640:001 2017.08.23 11:06:30.792 INFO ProgramBase`1 ]

ES VERSION: 4.0.2.2 (oss-v4.0.2/ec8ec115d14ca59ec3677209fb81942ce81d314b, Wed, 16 Aug 2017 11:03:48 +0100)

[PID:07640:001 2017.08.23 11:06:30.803 INFO ProgramBase`1 ] OS: Windows (Microsoft Windows NT 6.2.9200.0)

[PID:07640:001 2017.08.23 11:06:30.803 INFO ProgramBase`1 ] RUNTIME: .NET 4.0.30319.42000 (64-bit)

[PID:07640:001 2017.08.23 11:06:30.803 INFO ProgramBase`1 ] GC: 3 GENERATIONS

[PID:07640:001 2017.08.23 11:06:30.803 INFO ProgramBase`1 ] LOGS: C:\eventstore\ESData-logs

[PID:07640:001 2017.08.23 11:06:30.803 INFO ProgramBase`1 ] MODIFIED OPTIONS:

LOG: C:\eventstore\ESData-logs (Command Line)

DB: C:\EventStore\ESData (Command Line)

RUN PROJECTIONS: ALL (Command Line)

INT HTTP PREFIXES: http://127.0.0.1:2113/ (Command Line)

EXT HTTP PREFIXES: http://localhost:2113/ (Command Line)

INT TCP HEARTBEAT TIMEOUT: 15000 (Command Line)

INT TCP HEARTBEAT INTERVAL: 15000 (Command Line)

EXT TCP HEARTBEAT TIMEOUT: 15000 (Command Line)

EXT TCP HEARTBEAT INTERVAL: 15000 (Command Line)

EXT IP: 127.0.0.1 (Command Line)

INT IP: 192.168.16.71 (Command Line)

DEFAULT OPTIONS:

HELP: False ()

VERSION: False ()

CONFIG: ()

DEFINES: ()

WHAT IF: False ()

START STANDARD PROJECTIONS: False ()

DISABLE HTTP CACHING: False ()

MONO MIN THREADPOOL SIZE: 10 ()

INT HTTP PORT: 2112 ()

EXT HTTP PORT: 2113 ()

INT TCP PORT: 1112 ()

INT SECURE TCP PORT: 0 ()

EXT TCP PORT: 1113 ()

EXT SECURE TCP PORT ADVERTISE AS: 0 ()

EXT SECURE TCP PORT: 0 ()

EXT IP ADVERTISE AS: ()

EXT TCP PORT ADVERTISE AS: 0 ()

EXT HTTP PORT ADVERTISE AS: 0 ()

INT IP ADVERTISE AS: ()

INT SECURE TCP PORT ADVERTISE AS: 0 ()

INT TCP PORT ADVERTISE AS: 0 ()

INT HTTP PORT ADVERTISE AS: 0 ()

GOSSIP ON SINGLE NODE: False ()

CONNECTION PENDING SEND BYTES THRESHOLD: False ()

FORCE: False ()

CLUSTER SIZE: 1 ()

NODE PRIORITY: 0 ()

MIN FLUSH DELAY MS: 2 ()

COMMIT COUNT: -1 ()

PREPARE COUNT: -1 ()

ADMIN ON EXT: True ()

STATS ON EXT: True ()

GOSSIP ON EXT: True ()

DISABLE SCAVENGE MERGING: False ()

SCAVENGE HISTORY MAX AGE: 30 ()

DISCOVER VIA DNS: True ()

CLUSTER DNS: fake.dns ()

CLUSTER GOSSIP PORT: 30777 ()

GOSSIP SEED: ()

STATS PERIOD SEC: 30 ()

CACHED CHUNKS: -1 ()

READER THREADS COUNT: 4 ()

CHUNKS CACHE SIZE: 536871424 ()

MAX MEM TABLE SIZE: 1000000 ()

HASH COLLISION READ LIMIT: 100 ()

INDEX: ()

MEM DB: False ()

SKIP DB VERIFY: False ()

WRITE THROUGH: False ()

UNBUFFERED: False ()

PROJECTION THREADS: 3 ()

WORKER THREADS: 5 ()

ENABLE TRUSTED AUTH: False ()

ADD INTERFACE PREFIXES: True ()

CERTIFICATE STORE LOCATION: ()

CERTIFICATE STORE NAME: ()

CERTIFICATE SUBJECT NAME: ()

CERTIFICATE THUMBPRINT: ()

CERTIFICATE FILE: ()

CERTIFICATE PASSWORD: ()

USE INTERNAL SSL: False ()

DISABLE INSECURE TCP: False ()

SSL TARGET HOST: n/a ()

SSL VALIDATE SERVER: True ()

AUTHENTICATION TYPE: internal ()

AUTHENTICATION CONFIG: ()

PREPARE TIMEOUT MS: 2000 ()

COMMIT TIMEOUT MS: 2000 ()

UNSAFE DISABLE FLUSH TO DISK: False ()

BETTER ORDERING: False ()

UNSAFE IGNORE HARD DELETE: False ()

INDEX CACHE DEPTH: 16 ()

GOSSIP INTERVAL MS: 1000 ()

GOSSIP ALLOWED DIFFERENCE MS: 60000 ()

GOSSIP TIMEOUT MS: 500 ()

ENABLE HISTOGRAMS: False ()

LOG HTTP REQUESTS: False ()

ALWAYS KEEP SCAVENGED: False ()

[PID:07640:001 2017.08.23 11:06:30.816 INFO ProgramBase`1 ] Quorum size set to 1

[PID:07640:001 2017.08.23 11:06:30.816 INFO ProgramBase`1 ] Cannot find plugins path: C:\EventStore\plugins

[PID:07640:001 2017.08.23 11:06:30.929 INFO VNodeBuilder ] INSTANCE ID: 229900f4-8650-470d-aa71-1e5fa599700b

[PID:07640:001 2017.08.23 11:06:30.929 INFO VNodeBuilder ] DATABASE: C:\EventStore\ESData

[PID:07640:001 2017.08.23 11:06:30.929 INFO VNodeBuilder ] WRITER CHECKPOINT: 0 (0x0)

[PID:07640:001 2017.08.23 11:06:30.929 INFO VNodeBuilder ] CHASER CHECKPOINT: 0 (0x0)

[PID:07640:001 2017.08.23 11:06:30.929 INFO VNodeBuilder ] EPOCH CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)

[PID:07640:001 2017.08.23 11:06:30.929 INFO VNodeBuilder ] TRUNCATE CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)

[PID:07640:001 2017.08.23 11:06:30.976 TRACE MessageHierarchy ] MessageHierarchy initialization took 00:00:00.0234095.

[PID:07640:001 2017.08.23 11:06:31.037 TRACE TFChunk ] CACHED TFChunk #0-0 (chunk-000000.000000) in 00:00:00.0017246.

[PID:07640:001 2017.08.23 11:06:31.140 INFO MiniWeb ] Starting MiniWeb for /web/es/js/projections ==> C:\EventStore\projections

[PID:07640:001 2017.08.23 11:06:31.140 INFO MiniWeb ] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> C:\EventStore\Prelude

[PID:07640:001 2017.08.23 11:06:31.143 TRACE MiniWeb ] Binding MiniWeb to /web/es/js/projections/{*remaining_path}

[PID:07640:001 2017.08.23 11:06:31.143 TRACE MiniWeb ] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*remaining_path}

[PID:07640:001 2017.08.23 11:06:31.143 INFO MiniWeb ] Starting MiniWeb for /web ==> C:\EventStore\clusternode-web

[PID:07640:001 2017.08.23 11:06:31.143 TRACE MiniWeb ] Binding MiniWeb to /web/{*remaining_path}

[PID:07640:016 2017.08.23 11:06:31.164 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] SYSTEM INIT…

[PID:07640:016 2017.08.23 11:06:31.187 INFO TcpServerListener ] Starting Normal TCP listening on TCP endpoint: 127.0.0.1:1113.

[PID:07640:017 2017.08.23 11:06:31.199 INFO IndexCommitter ] TableIndex initialization…

[PID:07640:017 2017.08.23 11:06:31.207 INFO IndexCommitter ] ReadIndex building…

[PID:07640:017 2017.08.23 11:06:31.207 DEBUG IndexCommitter ] ReadIndex rebuilding done: total processed 0 records, time elapsed: 00:00:00.0019945.

[PID:07640:016 2017.08.23 11:06:31.221 INFO HttpAsyncServer ] Starting HTTP server on [http://localhost:2113/,http://127.0.0.1:2113/]…

[PID:07640:016 2017.08.23 11:06:31.221 INFO HttpAsyncServer ] HTTP server is up and listening on [http://localhost:2113/,http://127.0.0.1:2113/]

[PID:07640:016 2017.08.23 11:06:31.221 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [MainQueue]: SystemInit - 68ms. Q: 0/5.

[PID:07640:016 2017.08.23 11:06:31.221 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] Service ‘StorageReader’ initialized.

[PID:07640:016 2017.08.23 11:06:31.221 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] Service ‘StorageWriter’ initialized.

[PID:07640:016 2017.08.23 11:06:31.221 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] Service ‘StorageChaser’ initialized.

[PID:07640:016 2017.08.23 11:06:31.221 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] SYSTEM START…

[PID:07640:016 2017.08.23 11:06:31.237 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] IS UNKNOWN…

[PID:07640:012 2017.08.23 11:06:31.256 DEBUG PersistentSubscripti] Subscriptions received state change to Unknown stopping listening.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: STARTING ELECTIONS.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) SHIFT TO LEADER ELECTION.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) VIEWCHANGE FROM [192.168.16.71:2112, {229900f4-8650-470d-aa71-1e5fa599700b}].

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) MAJORITY OF VIEWCHANGE.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) SHIFT TO PREPARE PHASE.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) PREPARE_OK FROM 192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) SHIFT TO REG_LEADER.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) SENDING PROPOSAL CANDIDATE: 192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}, ME: 192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}.

[PID:07640:016 2017.08.23 11:06:31.269 DEBUG ElectionsService ] ELECTIONS: (V=0) ACCEPT FROM [192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}] M=[192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}]).

[PID:07640:016 2017.08.23 11:06:31.269 INFO ElectionsService ] ELECTIONS: (V=0) DONE. ELECTED MASTER = 192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}. ME=192.168.16.71:2112,{229900f4-8650-470d-aa71-1e5fa599700b}.

[PID:07640:016 2017.08.23 11:06:31.285 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] PRE-MASTER STATE, WAITING FOR CHASER TO CATCH UP…

[PID:07640:007 2017.08.23 11:06:31.285 DEBUG PersistentSubscripti] Subscriptions received state change to PreMaster stopping listening.

[PID:07640:016 2017.08.23 11:06:31.285 INFO ClusterVNodeControll] ========== [192.168.16.71:2112] IS MASTER… SPARTA!

[PID:07640:006 2017.08.23 11:06:31.285 DEBUG PersistentSubscripti] Subscriptions Became Master so now handling subscriptions

[PID:07640:009 2017.08.23 11:06:31.344 TRACE QueuedHandlerThreadP] SLOW QUEUE MSG [MonitoringQueue]: SystemInit - 165ms. Q: 0/3.

[PID:07640:014 2017.08.23 11:06:31.398 DEBUG EpochManager ] === Writing E0@0:{a8f9254c-7869-45e7-a130-402f0a4e3d1d} (previous epoch at -1).

[PID:07640:014 2017.08.23 11:06:31.398 DEBUG EpochManager ] === Update Last Epoch E0@0:{a8f9254c-7869-45e7-a130-402f0a4e3d1d} (previous epoch at -1).

[PID:07640:006 2017.08.23 11:06:31.488 TRACE MonitoringService ] Created stats stream ‘$stats-127.0.0.1:2113’, code = Success

[PID:07640:016 2017.08.23 11:06:31.521 INFO UserManagementServic] ‘ops’ user account has been created.

[PID:07640:016 2017.08.23 11:06:31.521 INFO UserManagementServic] ‘admin’ user account has been created.

[PID:07640:016 2017.08.23 11:06:31.521 INFO UserManagementServic] ‘ops’ user added to $users.

[PID:07640:016 2017.08.23 11:06:31.521 INFO UserManagementServic] ‘admin’ user added to $users.

[PID:07640:018 2017.08.23 11:06:31.539 DEBUG ProjectionCoreCoordi] PROJECTIONS: Starting Projections Core Coordinator. (Node State : Master)

[PID:07640:018 2017.08.23 11:06:31.558 DEBUG ProjectionManager ] PROJECTIONS: Starting Projections Manager. (Node State : Master)

[PID:07640:018 2017.08.23 11:06:31.568 DEBUG ProjectionManagerRes] PROJECTIONS: Starting Projection Manager Response Reader (reads from $projections-$master)

[PID:07640:021 2017.08.23 11:06:31.568 DEBUG ProjectionCoreServic] PROJECTIONS: Starting Projection Core Reader (reads from $projections-$4c9121ced537410b905000c604ab327e)

[PID:07640:018 2017.08.23 11:06:31.593 DEBUG MultiStreamMessageWr] PROJECTIONS: Resetting Worker Writer

[PID:07640:020 2017.08.23 11:06:31.593 DEBUG ProjectionCoreServic] PROJECTIONS: Starting Projection Core Reader (reads from $projections-$f055e66c06b14c5d9173e2a3b8b1acee)

[PID:07640:018 2017.08.23 11:06:31.601 DEBUG ProjectionManagerRes] PROJECTIONS: Finished Starting Projection Manager Response Reader (reads from $projections-$master)

[PID:07640:020 2017.08.23 11:06:31.601 DEBUG ResponseWriter ] PROJECTIONS: Resetting Master Writer

[PID:07640:020 2017.08.23 11:06:31.601 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [Projection Core #1]: StartCore - 58ms. Q: 2/7.

[PID:07640:019 2017.08.23 11:06:31.601 DEBUG ProjectionCoreServic] PROJECTIONS: Starting Projection Core Reader (reads from $projections-$3cb853067d514ca39596366e0ccbbdaa)

[PID:07640:020 2017.08.23 11:06:31.601 DEBUG ProjectionCoreServic] PROJECTIONS: Starting read control from 0

[PID:07640:018 2017.08.23 11:06:31.612 DEBUG ProjectionManagerRes] PROJECTIONS: Response received: 0@$response-reader-starting

[PID:07640:018 2017.08.23 11:06:31.612 DEBUG ProjectionManagerRes] PROJECTIONS: Response received: 1@$projection-worker-started

[PID:07640:020 2017.08.23 11:06:31.612 DEBUG ProjectionCoreServic] PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-$f055e66c06b14c5d9173e2a3b8b1acee)

[PID:07640:019 2017.08.23 11:06:31.612 TRACE InMemoryBus ] SLOW BUS MSG [bus]: StartCore - 59ms. Handler: ProjectionCoreServiceCommandReader.

[PID:07640:019 2017.08.23 11:06:31.612 DEBUG ResponseWriter ] PROJECTIONS: Resetting Master Writer

[PID:07640:019 2017.08.23 11:06:31.612 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [Projection Core #0]: StartCore - 73ms. Q: 2/7.

[PID:07640:019 2017.08.23 11:06:31.612 DEBUG ProjectionCoreServic] PROJECTIONS: Starting read control from 1

[PID:07640:019 2017.08.23 11:06:31.612 DEBUG ProjectionCoreServic] PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-$3cb853067d514ca39596366e0ccbbdaa)

[PID:07640:021 2017.08.23 11:06:31.612 DEBUG ResponseWriter ] PROJECTIONS: Resetting Master Writer

[PID:07640:021 2017.08.23 11:06:31.612 TRACE QueuedHandlerMRES ] SLOW QUEUE MSG [Projection Core #2]: StartCore - 74ms. Q: 2/7.

[PID:07640:021 2017.08.23 11:06:31.612 DEBUG ProjectionCoreServic] PROJECTIONS: Starting read control from 0

[PID:07640:021 2017.08.23 11:06:31.612 DEBUG ProjectionCoreServic] PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-$4c9121ced537410b905000c604ab327e)

[PID:07640:018 2017.08.23 11:06:31.612 DEBUG ProjectionManagerRes] PROJECTIONS: Response received: 2@$projection-worker-started

[PID:07640:030 2017.08.23 11:09:41.730 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:57838, L127.0.0.1:1113, {26b34c33-1ce5-4366-8b36-0d3a473ba509}].

[PID:07640:027 2017.08.23 11:11:35.017 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:57866, L127.0.0.1:1113, {1ddad4ee-4d5c-4a94-b038-f11e980864c2}].

[PID:07640:034 2017.08.23 11:24:29.535 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:57961, L127.0.0.1:1113, {7c638e3a-1eb4-45d4-bf56-023b9fe662ce}].

[PID:07640:034 2017.08.23 11:24:30.327 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:57967, L127.0.0.1:1113, {0ee1e198-d252-479f-9a96-b0144ab4739c}].

[PID:07640:034 2017.08.23 11:24:30.640 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:57970, L127.0.0.1:1113, {37b933e1-4c0e-4882-8654-20d54da2f007}].

[PID:07640:034 2017.08.23 11:24:30.694 INFO TcpService ] External TCP connection accepted: [Normal, 127.0.0.1:57971, L127.0.0.1:1113, {79eb892a-1473-4a9b-aa1e-1c4120f0a26a}].

[PID:07640:033 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.234: N127.0.0.1:57961, L127.0.0.1:1113, {7c638e3a-1eb4-45d4-bf56-023b9fe662ce}]:Received bytes: 1214, Sent bytes: 1178

[PID:07640:045 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.234: N127.0.0.1:57970, L127.0.0.1:1113, {37b933e1-4c0e-4882-8654-20d54da2f007}]:Received bytes: 8814, Sent bytes: 8306

[PID:07640:033 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57961, L127.0.0.1:1113, {7c638e3a-1eb4-45d4-bf56-023b9fe662ce}]:Send calls: 23, callbacks: 23

[PID:07640:030 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.234: N127.0.0.1:57967, L127.0.0.1:1113, {0ee1e198-d252-479f-9a96-b0144ab4739c}]:Received bytes: 23383, Sent bytes: 21158

[PID:07640:037 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.234: N127.0.0.1:57838, L127.0.0.1:1113, {26b34c33-1ce5-4366-8b36-0d3a473ba509}]:Received bytes: 19083, Sent bytes: 17800

[PID:07640:045 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57970, L127.0.0.1:1113, {37b933e1-4c0e-4882-8654-20d54da2f007}]:Send calls: 88, callbacks: 88

[PID:07640:030 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57967, L127.0.0.1:1113, {0ee1e198-d252-479f-9a96-b0144ab4739c}]:Send calls: 211, callbacks: 211

[PID:07640:037 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57838, L127.0.0.1:1113, {26b34c33-1ce5-4366-8b36-0d3a473ba509}]:Send calls: 348, callbacks: 348

[PID:07640:045 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57970, L127.0.0.1:1113, {37b933e1-4c0e-4882-8654-20d54da2f007}]:Receive calls: 46, callbacks: 46

[PID:07640:037 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57838, L127.0.0.1:1113, {26b34c33-1ce5-4366-8b36-0d3a473ba509}]:Receive calls: 349, callbacks: 349

[PID:07640:033 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57961, L127.0.0.1:1113, {7c638e3a-1eb4-45d4-bf56-023b9fe662ce}]:Receive calls: 24, callbacks: 24

[PID:07640:030 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57967, L127.0.0.1:1113, {0ee1e198-d252-479f-9a96-b0144ab4739c}]:Receive calls: 105, callbacks: 105

[PID:07640:033 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57961, L127.0.0.1:1113, {7c638e3a-1eb4-45d4-bf56-023b9fe662ce}]:Close reason: [ConnectionReset] Socket receive error

[PID:07640:030 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57967, L127.0.0.1:1113, {0ee1e198-d252-479f-9a96-b0144ab4739c}]:Close reason: [ConnectionReset] Socket receive error

[PID:07640:037 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57838, L127.0.0.1:1113, {26b34c33-1ce5-4366-8b36-0d3a473ba509}]:Close reason: [ConnectionReset] Socket receive error

[PID:07640:045 2017.08.23 11:25:02.245 INFO TcpConnection ] ES TcpConnection closed [11:25:02.245: N127.0.0.1:57970, L127.0.0.1:1113, {37b933e1-4c0e-4882-8654-20d54da2f007}]:Close reason: [ConnectionReset] Socket receive error

[PID:07640:033 2017.08.23 11:25:02.255 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:57961, {7c638e3a-1eb4-45d4-bf56-023b9fe662ce}] closed: ConnectionReset.

[PID:07640:045 2017.08.23 11:25:02.255 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:57970, {37b933e1-4c0e-4882-8654-20d54da2f007}] closed: ConnectionReset.

[PID:07640:030 2017.08.23 11:25:02.255 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:57967, {0ee1e198-d252-479f-9a96-b0144ab4739c}] closed: ConnectionReset.

[PID:07640:037 2017.08.23 11:25:02.255 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:57838, {26b34c33-1ce5-4366-8b36-0d3a473ba509}] closed: ConnectionReset.

[PID:07640:011 2017.08.23 11:25:02.255 DEBUG PersistentSubscripti] Lost connection from 127.0.0.1:57961

[PID:07640:011 2017.08.23 11:25:02.255 DEBUG PersistentSubscripti] Lost connection from 127.0.0.1:57967

[PID:07640:011 2017.08.23 11:25:02.255 DEBUG PersistentSubscripti] Lost connection from 127.0.0.1:57838

[PID:07640:011 2017.08.23 11:25:02.255 DEBUG PersistentSubscripti] Lost connection from 127.0.0.1:57970

[PID:07640:045 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57866, L127.0.0.1:1113, {1ddad4ee-4d5c-4a94-b038-f11e980864c2}]:Received bytes: 1057182, Sent bytes: 889488

[PID:07640:037 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57971, L127.0.0.1:1113, {79eb892a-1473-4a9b-aa1e-1c4120f0a26a}]:Received bytes: 42606, Sent bytes: 4482

[PID:07640:045 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57866, L127.0.0.1:1113, {1ddad4ee-4d5c-4a94-b038-f11e980864c2}]:Send calls: 5122, callbacks: 5122

[PID:07640:037 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57971, L127.0.0.1:1113, {79eb892a-1473-4a9b-aa1e-1c4120f0a26a}]:Send calls: 99, callbacks: 99

[PID:07640:045 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57866, L127.0.0.1:1113, {1ddad4ee-4d5c-4a94-b038-f11e980864c2}]:Receive calls: 1686, callbacks: 1686

[PID:07640:037 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57971, L127.0.0.1:1113, {79eb892a-1473-4a9b-aa1e-1c4120f0a26a}]:Receive calls: 100, callbacks: 100

[PID:07640:045 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57866, L127.0.0.1:1113, {1ddad4ee-4d5c-4a94-b038-f11e980864c2}]:Close reason: [ConnectionReset] Socket receive error

[PID:07640:037 2017.08.23 11:25:03.745 INFO TcpConnection ] ES TcpConnection closed [11:25:03.745: N127.0.0.1:57971, L127.0.0.1:1113, {79eb892a-1473-4a9b-aa1e-1c4120f0a26a}]:Close reason: [ConnectionReset] Socket receive error

[PID:07640:045 2017.08.23 11:25:03.745 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:57866, {1ddad4ee-4d5c-4a94-b038-f11e980864c2}] closed: ConnectionReset.

[PID:07640:037 2017.08.23 11:25:03.745 INFO TcpConnectionManager] Connection ‘external-normal’ [127.0.0.1:57971, {79eb892a-1473-4a9b-aa1e-1c4120f0a26a}] closed: ConnectionReset.

[PID:07640:009 2017.08.23 11:25:03.745 DEBUG PersistentSubscripti] Lost connection from 127.0.0.1:57866

[PID:07640:009 2017.08.23 11:25:03.745 DEBUG PersistentSubscripti] Lost connection from 127.0.0.1:57971

Thank you for reporting this, we are currently looking into it.

Thanks.

Info: If we restart EventStore the projections will sometimes show up.

(we reinstall EventStore as part of our build so the tests will fail randomly, more often than not)

Hi Thomas

Thanks again for raising this issue, and next time you are more than welcome to raise issues like this github.

We have identified the issue and are already working on a fix for it.

If you are unable to wait for the fix to be released, you can rollback to 4.0.1.4 in the meantime.

Thanks for the quick response. We are back on 4.0.1.x until the next release.
/Thomas