EventStore rebuilding fails and kills ES

Jason_Hamm · June 23, 2018, 5:38am

I am using a Docker container to create my ES. I am using the Docker Hub eventstore/eventstore. I push a backup to the container, so when the ES starts, it tries to rebuild and always dies. Here is the error:

[00032,13,05:31:10.156] ========== [0.0.0.0:2112] Service ‘StorageWriter’ initialized.

[00032,13,05:31:10.156] ========== [0.0.0.0:2112] Service ‘StorageReader’ initialized.

[00032,14,05:31:15.061] ReadIndex Rebuilding: processed 7630 records (0.7%).

/init.sh: line 11: 32 Killed /entrypoint.sh

the init.sh is just starting cron and running /entrypoint.sh. The entrypoint.sh is just this

#!/usr/bin/env bash

set -e

if [ ! -z ${EVENTSTORE_CLUSTER_SIZE+x} ] && [ -z ${EVENTSTORE_INT_IP} ]

then

export EVENTSTORE_INT_IP=ip addr show eth0|grep -E '(\/[0-9][0-9])'|awk '/inet / {print $2}'|sed -e 's/\/.*//'

fi

exec eventstored

Does the error above make any sense to anyone? When I run this locally, it actually works, but I am trying to push to hyper.sh and it is dying. I don’t get any errors to the console, which would be nice.

Greg_Young1 · June 23, 2018, 6:55am

I have never seen a crash without any error to the console. Try running it directly as opposed to your script.

Jason_Hamm · June 23, 2018, 12:04pm

I run the /entrypoint manually. I get to rebuilding, and it just stops with no errors. Here is the end of the log

[00006,13,12:01:43.815] Starting HTTP server on [http://*:2113/]…

[00006,13,12:01:43.826] HTTP server is up and listening on [http://*:2113/]

[00006,13,12:01:43.845] SLOW QUEUE MSG [MainQueue]: SystemInit - 144ms. Q: 0/4.

[00006,13,12:01:43.846] ========== [0.0.0.0:2112] Service ‘StorageWriter’ initialized.

[00006,13,12:01:43.846] ========== [0.0.0.0:2112] Service ‘StorageReader’ initialized.

[00006,14,12:01:47.186] ReadIndex building…

Greg_Young1 · June 23, 2018, 12:20pm

And nothing further? This is a really weird log for me. Have you tried running it directly?

Jason_Hamm · June 23, 2018, 12:51pm

There is nothing further. There are about 1.2 million events in this backup that I am restoring. On my local machine, I can see the prior events being processed. Here is the log from my local machine running the same docker image. You can see the indexing happening properly. When I push the docker image to hyper.sh, things start the same, but the ReadIndex Rebuilding doesn’t work. Posting those logs after the working logs

========================================= Working logs =========================================

[00063,01,12:49:45.518] Quorum size set to 1

[00063,01,12:49:45.526] Cannot find plugins path: plugins

[00063,01,12:49:45.577] INSTANCE ID: 9071763b-4b2b-4978-b07a-7816fab8d7d5

[00063,01,12:49:45.578] DATABASE: /var/lib/eventstore

[00063,01,12:49:45.578] WRITER CHECKPOINT: 772007012 (0x2E03E464)

[00063,01,12:49:45.578] CHASER CHECKPOINT: 772007012 (0x2E03E464)

[00063,01,12:49:45.578] EPOCH CHECKPOINT: 658000 (0xA0A50)

[00063,01,12:49:45.578] TRUNCATE CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)

[00063,01,12:49:45.732] MessageHierarchy initialization took 00:00:00.1294863.

[00063,01,12:49:45.771] Opened completed /var/lib/eventstore/chunk-000000.000000 as version 3

[00063,01,12:49:45.773] Opened completed /var/lib/eventstore/chunk-000001.000000 as version 3

[00063,01,12:49:46.787] Opened ongoing /var/lib/eventstore/chunk-000002.000000 as version 3

[00063,06,12:49:46.791] Verifying hash for TFChunk ‘/var/lib/eventstore/chunk-000000.000000’…

[00063,01,12:49:46.917] CACHED TFChunk #2-2 (chunk-000002.000000) in 00:00:00.1261521.

[00063,09,12:49:47.053] CACHED TFChunk #1-1 (chunk-000001.000000) in 00:00:00.1363548.

[00063,01,12:49:47.083] Starting MiniWeb for /web/es/js/projections ==> /usr/share/eventstore/projections

[00063,01,12:49:47.083] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> /usr/share/eventstore/Prelude

[00063,01,12:49:47.084] Binding MiniWeb to /web/es/js/projections/{*remaining_path}

[00063,01,12:49:47.084] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*remaining_path}

[00063,01,12:49:47.091] Starting MiniWeb for /web ==> /usr/share/eventstore/clusternode-web

[00063,01,12:49:47.091] Binding MiniWeb to /web/{*remaining_path}

[00063,13,12:49:47.107] ========== [0.0.0.0:2112] SYSTEM INIT…

[00063,13,12:49:47.124] Starting Normal TCP listening on TCP endpoint: 0.0.0.0:1113.

[00063,14,12:49:47.139] TableIndex initialization…

[00063,14,12:49:47.146] ReadIndex building…

[00063,13,12:49:47.158] Starting HTTP server on [http://*:2113/]…

[00063,13,12:49:47.160] HTTP server is up and listening on [http://*:2113/]

[00063,13,12:49:47.179] SLOW QUEUE MSG [MainQueue]: SystemInit - 68ms. Q: 0/15.

[00063,13,12:49:47.179] ========== [0.0.0.0:2112] Service ‘StorageReader’ initialized.

[00063,13,12:49:47.179] ========== [0.0.0.0:2112] Service ‘StorageWriter’ initialized.

[00063,17,12:49:48.007] Segments count: 1, buffers count: 20, should be when full: 20

[00063,14,12:49:48.860] ReadIndex Rebuilding: processed 100000 records (8.8%).

[00063,19,12:49:49.228] SLOW QUEUE MSG [MonitoringQueue]: GetFreshStats - 1190ms. Q: 0/0.

[00063,14,12:49:50.123] ReadIndex Rebuilding: processed 200000 records (16.5%).

[00063,14,12:49:51.329] ReadIndex Rebuilding: processed 300000 records (24.2%).

[00063,14,12:49:52.616] ReadIndex Rebuilding: processed 400000 records (31.9%).

[00063,14,12:49:53.486] ReadIndex Rebuilding: processed 500000 records (39.6%).

[00063,14,12:49:54.250] ReadIndex Rebuilding: processed 600000 records (47.3%).

[00063,14,12:49:55.034] ReadIndex Rebuilding: processed 700000 records (55.0%).

[00063,14,12:49:55.673] ReadIndex Rebuilding: processed 800000 records (62.7%).

[00063,14,12:49:56.530] ReadIndex Rebuilding: processed 900000 records (70.4%).

[00063,14,12:49:57.187] ReadIndex Rebuilding: processed 1000000 records (77.9%).

[00063,14,12:49:57.202] Switching MemTable, currently: 2 awaiting tables.

[00063,18,12:49:57.203] Awaiting tables queue size is: 2.

[00063,13,12:49:57.549] SLOW BUS MSG [MainBus]: EventCommitted - 79ms. Handler: WideningHandler`2.

[00063,13,12:49:57.549] SLOW QUEUE MSG [MainQueue]: EventCommitted - 96ms. Q: 20/3581.

[00063,18,12:49:57.910] Cached 65536 index midpoints to PTable

[00063,13,12:49:58.015] SLOW BUS MSG [MainBus]: EventCommitted - 103ms. Handler: WideningHandler`2.

[00063,13,12:49:58.015] SLOW QUEUE MSG [MainQueue]: EventCommitted - 103ms. Q: 90/204.

[00063,18,12:49:58.015] Dumped MemTable [00aa79d8-4b47-47fb-b3ce-56d5a6677a35, 1000000 entries] in 00:00:00.8109459.

[00063,18,12:49:58.019] Loading and Verification of PTable ‘35637e03-c12a-423f-9232-183aa4017a3a’ started…

[00063,14,12:49:58.023] ReadIndex Rebuilding: processed 1100000 records (80.6%).

[00063,18,12:49:58.231] Loading PTable (Version: 4) ‘35637e03-c12a-423f-9232-183aa4017a3a’ (1000000 entries, cache depth 16) done in 00:00:00.2115403.

[00063,18,12:49:58.240] There are now 1 awaiting tables.

[00063,18,12:49:58.240] Awaiting tables queue size is: 1.

[00063,14,12:49:58.755] ReadIndex Rebuilding: processed 1200000 records (83.4%).

[00063,14,12:49:59.597] ReadIndex Rebuilding: processed 1300000 records (86.2%).

[00063,13,12:49:59.814] SLOW BUS MSG [MainBus]: EventCommitted - 94ms. Handler: WideningHandler`2.

[00063,13,12:49:59.814] SLOW QUEUE MSG [MainQueue]: EventCommitted - 95ms. Q: 129/405.

[00063,14,12:50:00.472] ReadIndex rebuilding done: total processed 1382746 records, time elapsed: 00:00:13.3255730.

[00063,13,12:50:00.480] ========== [0.0.0.0:2112] Service ‘StorageChaser’ initialized.

[00063,13,12:50:00.480] ========== [0.0.0.0:2112] SYSTEM START…

[00063,13,12:50:00.483] ========== [0.0.0.0:2112] IS UNKNOWN…

[00063,32,12:50:00.497] Subscriptions received state change to Unknown stopping listening.

[00063,13,12:50:00.507] ELECTIONS: STARTING ELECTIONS.

[00063,13,12:50:00.507] ELECTIONS: (V=0) SHIFT TO LEADER ELECTION.

[00063,13,12:50:00.508] ELECTIONS: (V=0) VIEWCHANGE FROM [0.0.0.0:2112, {9071763b-4b2b-4978-b07a-7816fab8d7d5}].

[00063,13,12:50:00.508] ELECTIONS: (V=0) MAJORITY OF VIEWCHANGE.

[00063,13,12:50:00.508] ELECTIONS: (V=0) SHIFT TO PREPARE PHASE.

[00063,13,12:50:00.510] ELECTIONS: (V=0) PREPARE_OK FROM [0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}](L=771990008,W=772007012,C=772007012,E2@658000:{2bc79dca-0033-4a86-a4be-b3017f2915b8}).

[00063,13,12:50:00.510] ELECTIONS: (V=0) SHIFT TO REG_LEADER.

[00063,13,12:50:00.514] ELECTIONS: (V=0) SENDING PROPOSAL CANDIDATE: [0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}](L=771990008,W=772007012,C=772007012,E2@658000:{2bc79dca-0033-4a86-a4be-b3017f2915b8}), ME: [0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}](L=771990008,W=772007012,C=772007012,E2@658000:{2bc79dca-0033-4a86-a4be-b3017f2915b8}).

[00063,13,12:50:00.514] ELECTIONS: (V=0) ACCEPT FROM [0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}] M=[0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}]).

[00063,13,12:50:00.515] ELECTIONS: (V=0) DONE. ELECTED MASTER = [0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}](L=771990008,W=772007012,C=772007012,E2@658000:{2bc79dca-0033-4a86-a4be-b3017f2915b8}). ME=[0.0.0.0:2112,{9071763b-4b2b-4978-b07a-7816fab8d7d5}](L=771990008,W=772007012,C=772007012,E2@658000:{2bc79dca-0033-4a86-a4be-b3017f2915b8}).

[00063,13,12:50:00.516] ========== [0.0.0.0:2112] PRE-MASTER STATE, WAITING FOR CHASER TO CATCH UP…

[00063,24,12:50:00.516] Subscriptions received state change to PreMaster stopping listening.

[00063,13,12:50:00.518] ========== [0.0.0.0:2112] IS MASTER… SPARTA!

[00063,19,12:50:00.519] Subscriptions Became Master so now handling subscriptions

[00063,11,12:50:00.543] === Writing E3@772007012:{8117aa53-5e0d-4d8d-8cbd-78e4000ec2e9} (previous epoch at 658000).

[00063,34,12:50:00.561] PROJECTIONS: Starting Projections Core Coordinator. (Node State : Master)

[00063,34,12:50:00.582] PROJECTIONS: Starting Projections Manager. (Node State : Master)

[00063,34,12:50:00.582] PROJECTIONS: SubComponent Started: EventReaderCoreService

[00063,34,12:50:00.582] PROJECTIONS: SubComponent Started: ProjectionCoreService

[00063,34,12:50:00.582] PROJECTIONS: SubComponent Started: EventReaderCoreService

[00063,34,12:50:00.582] PROJECTIONS: SubComponent Started: ProjectionCoreService

[00063,11,12:50:00.615] === Update Last Epoch E3@772007012:{8117aa53-5e0d-4d8d-8cbd-78e4000ec2e9} (previous epoch at 658000).

[00063,35,12:50:00.628] PROJECTIONS: Starting Projection Core Reader (reads from $projections-$c06788ae54654c55a10d96838488d378)

[00063,36,12:50:00.628] PROJECTIONS: Starting Projection Core Reader (reads from $projections-$24112effcf82494d805a3a90ab0f680c)

[00063,37,12:50:00.628] PROJECTIONS: Starting Projection Core Reader (reads from $projections-$cf69e959caea41c9bdb6f143f143f150)

[00063,36,12:50:00.632] SLOW BUS MSG [bus]: StartCore - 64ms. Handler: ProjectionCoreServiceCommandReader.

[00063,35,12:50:00.632] SLOW BUS MSG [bus]: StartCore - 66ms. Handler: ProjectionCoreServiceCommandReader.

[00063,37,12:50:00.633] SLOW BUS MSG [bus]: StartCore - 66ms. Handler: ProjectionCoreServiceCommandReader.

[00063,34,12:50:00.646] PROJECTIONS: Starting Projection Manager Response Reader (reads from $projections-$master)

[00063,34,12:50:00.647] SLOW BUS MSG [manager input bus]: Starting - 64ms. Handler: ProjectionManagerResponseReader.

[00063,18,12:50:00.657] Created stats stream ‘$stats-0.0.0.0:2113’, code = WrongExpectedVersion

[00063,35,12:50:00.669] PROJECTIONS: Resetting Master Writer

[00063,36,12:50:00.669] PROJECTIONS: Resetting Master Writer

[00063,35,12:50:00.669] SLOW QUEUE MSG [Projection Core #0]: StartCore - 103ms. Q: 3/7.

[00063,36,12:50:00.669] SLOW QUEUE MSG [Projection Core #1]: StartCore - 103ms. Q: 3/7.

[00063,37,12:50:00.669] PROJECTIONS: Resetting Master Writer

[00063,37,12:50:00.669] SLOW QUEUE MSG [Projection Core #2]: StartCore - 102ms. Q: 3/7.

[00063,35,12:50:00.677] PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-$c06788ae54654c55a10d96838488d378)

[00063,36,12:50:00.677] PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-$24112effcf82494d805a3a90ab0f680c)

[00063,36,12:50:00.678] PROJECTIONS: Starting read $projections-$control-8117aa53-5e0d-4d8d-8cbd-78e4000ec2e9

[00063,35,12:50:00.678] PROJECTIONS: Starting read $projections-$control-8117aa53-5e0d-4d8d-8cbd-78e4000ec2e9

[00063,37,12:50:00.679] PROJECTIONS: Finished Starting Projection Core Reader (reads from $projections-$cf69e959caea41c9bdb6f143f143f150)

[00063,37,12:50:00.679] PROJECTIONS: Starting read $projections-$control-8117aa53-5e0d-4d8d-8cbd-78e4000ec2e9

[00063,34,12:50:00.699] PROJECTIONS: Resetting Worker Writer

[00063,34,12:50:00.699] SLOW BUS MSG [manager input bus]: Starting - 51ms. Handler: ProjectionManagerCommandWriter.

[00063,34,12:50:00.699] SLOW QUEUE MSG [Projections Master]: Starting - 116ms. Q: 0/6.

[00063,34,12:50:00.699] PROJECTIONS: SubComponent Started: ProjectionCoreServiceCommandReader

[00063,34,12:50:00.700] PROJECTIONS: SubComponent Started: ProjectionCoreServiceCommandReader

[00063,34,12:50:00.715] PROJECTIONS: Finished Starting Projection Manager Response Reader (reads from $projections-$master)

[00063,34,12:50:00.721] PROJECTIONS: Response received: 527@$response-reader-starting

[00063,34,12:50:00.722] PROJECTIONS: Response received: 528@$projection-worker-started

[00063,34,12:50:00.726] PROJECTIONS: Response received: 529@$projection-worker-started

[00063,34,12:50:00.726] PROJECTIONS: Response received: 530@$projection-worker-started

[00063,34,12:50:00.727] PROJECTIONS: Reading Existing Projections from $projections-$all

[00063,34,12:50:00.732] PROJECTIONS: Found the following projections. $streams, $stream_by_category, $by_category, $by_event_type, aggregate-stream

[00063,34,12:50:00.734] Adding projection a5708f69-e65a-4df8-b98c-24522c5dcceb@$streams to list

[00063,34,12:50:00.736] Adding projection fe92693b-9da7-42d6-97bd-9d010c9bcea3@$stream_by_category to list

[00063,34,12:50:00.736] Adding projection 59557a45-ab98-4adf-a989-ac3029ac35c1@$by_category to list

[00063,34,12:50:00.736] Adding projection aa319e29-0571-4bf8-a687-63668dbcf7a5@$by_event_type to list

[00063,34,12:50:00.737] Adding projection 38ea8354-7277-412d-95fb-2da963133a68@aggregate-stream to list

[00063,13,12:50:00.737] ========== [0.0.0.0:2112] Sub System ‘Projections’ initialized.

[00063,34,12:50:00.761] PROJECTIONS: Scheduling the writing of $create-prepared to $projections-$c06788ae-5465-4c55-a10d-96838488d378. Current status of Writer: Busy: False

[00063,34,12:50:00.772] PROJECTIONS: Scheduling the writing of $create-prepared to $projections-$24112eff-cf82-494d-805a-3a90ab0f680c. Current status of Writer: Busy: False

[00063,34,12:50:00.772] PROJECTIONS: Scheduling the writing of $create-prepared to $projections-$cf69e959-caea-41c9-bdb6-f143f143f150. Current status of Writer: Busy: False

[00063,34,12:50:00.772] PROJECTIONS: Scheduling the writing of $create-prepared to $projections-$c06788ae-5465-4c55-a10d-96838488d378. Current status of Writer: Busy: True

[00063,34,12:50:00.773] PROJECTIONS: Scheduling the writing of $create-and-prepare to $projections-$24112eff-cf82-494d-805a-3a90ab0f680c. Current status of Writer: Busy: True

[00063,34,12:50:00.777] PROJECTIONS: Finished writing events to $projections-$c06788ae54654c55a10d96838488d378: $create-prepared

[00063,35,12:50:00.778] PROJECTIONS: Command received: 0@$create-prepared

[00063,34,12:50:00.778] PROJECTIONS: Finished writing events to $projections-$24112effcf82494d805a3a90ab0f680c: $create-prepared

[00063,36,12:50:00.778] PROJECTIONS: Command received: 0@$create-prepared

[00063,37,12:50:00.778] PROJECTIONS: Command received: 0@$create-prepared

[00063,34,12:50:00.782] PROJECTIONS: Finished writing events to $projections-$cf69e959caea41c9bdb6f143f143f150: $create-prepared

[00063,34,12:50:00.782] PROJECTIONS: Finished writing events to $projections-$c06788ae54654c55a10d96838488d378: $create-prepared

[00063,34,12:50:00.786] PROJECTIONS: Finished writing events to $projections-$24112effcf82494d805a3a90ab0f680c: $create-and-prepare

[00063,36,12:50:00.806] PROJECTIONS: Scheduling the writing of $prepared to $projections-$master. Current status of Writer: Busy: True

[00063,35,12:50:00.806] PROJECTIONS: Scheduling the writing of $prepared to $projections-$master. Current status of Writer: Busy: True

[00063,37,12:50:00.806] PROJECTIONS: Scheduling the writing of $prepared to $projections-$master. Current status of Writer: Busy: True

[00063,36,12:50:00.806] PROJECTIONS: Command received: 1@$create-and-prepare

[00063,35,12:50:00.806] PROJECTIONS: Command received: 1@$create-prepared

[00063,35,12:50:00.807] PROJECTIONS: Scheduling the writing of $prepared to $projections-$master. Current status of Writer: Busy: True

[00063,37,12:50:00.828] PROJECTIONS: Finished writing events to $projections-$master: $prepared

[00063,34,12:50:00.828] PROJECTIONS: Response received: 534@$prepared

[00063,34,12:50:00.829] PROJECTIONS: Scheduling the writing of $load-stopped to $projections-$cf69e959-caea-41c9-bdb6-f143f143f150. Current status of Writer: Busy: False

[00063,35,12:50:00.835] PROJECTIONS: Finished writing events to $projections-$master: $prepared

[00063,34,12:50:00.835] PROJECTIONS: Response received: 535@$prepared

[00063,34,12:50:00.835] PROJECTIONS: Response received: 537@$prepared

[00063,34,12:50:00.835] PROJECTIONS: Scheduling the writing of $load-stopped to $projections-$c06788ae-5465-4c55-a10d-96838488d378. Current status of Writer: Busy: False

[00063,34,12:50:00.836] PROJECTIONS: Scheduling the writing of $load-stopped to $projections-$c06788ae-5465-4c55-a10d-96838488d378. Current status of Writer: Busy: True

[00063,34,12:50:00.842] PROJECTIONS: Finished writing events to $projections-$cf69e959caea41c9bdb6f143f143f150: $load-stopped

[00063,37,12:50:00.842] PROJECTIONS: Command received: 1@$load-stopped

[00063,34,12:50:00.846] PROJECTIONS: Finished writing events to $projections-$c06788ae54654c55a10d96838488d378: $load-stopped

[00063,35,12:50:00.846] PROJECTIONS: Command received: 2@$load-stopped

[00063,35,12:50:00.852] PROJECTIONS: Scheduling the writing of $stopped to $projections-$master. Current status of Writer: Busy: True

[00063,37,12:50:00.852] PROJECTIONS: Scheduling the writing of $stopped to $projections-$master. Current status of Writer: Busy: True

[00063,34,12:50:00.856] PROJECTIONS: Finished writing events to $projections-$c06788ae54654c55a10d96838488d378: $load-stopped

[00063,35,12:50:00.856] PROJECTIONS: Command received: 3@$load-stopped

[00063,35,12:50:00.857] PROJECTIONS: Scheduling the writing of $stopped to $projections-$master. Current status of Writer: Busy: True

[00063,37,12:50:00.862] PROJECTIONS: Finished writing events to $projections-$master: $stopped

[00063,34,12:50:00.862] PROJECTIONS: Response received: 541@$stopped

[00063,34,12:50:00.865] PROJECTIONS: Response received: 544@$stopped

[00063,35,12:50:00.866] PROJECTIONS: Finished writing events to $projections-$master: $stopped

[00063,35,12:50:00.876] PROJECTIONS: Finished writing events to $projections-$master: $stopped

[00063,34,12:50:00.877] PROJECTIONS: Response received: 548@$stopped

[00063,36,12:50:00.996] SLOW BUS MSG [bus]: CreateAndPrepare - 188ms. Handler: ProjectionCoreService.

[00063,36,12:50:00.996] SLOW QUEUE MSG [Projection Core #1]: CreateAndPrepare - 188ms. Q: 4/12.

[00063,36,12:50:00.996] PROJECTIONS: Scheduling the writing of $prepared to $projections-$master. Current status of Writer: Busy: True

[00063,36,12:50:01.003] PROJECTIONS: Finished writing events to $projections-$master: $prepared

[00063,34,12:50:01.003] PROJECTIONS: Response received: 550@$prepared

[00063,34,12:50:01.003] PROJECTIONS: Response received: 552@$prepared

[00063,34,12:50:01.003] PROJECTIONS: Scheduling the writing of $load-stopped to $projections-$24112eff-cf82-494d-805a-3a90ab0f680c. Current status of Writer: Busy: False

[00063,34,12:50:01.003] PROJECTIONS: Scheduling the writing of $start to $projections-$24112eff-cf82-494d-805a-3a90ab0f680c. Current status of Writer: Busy: True

[00063,34,12:50:01.006] PROJECTIONS: Finished writing events to $projections-$24112effcf82494d805a3a90ab0f680c: $load-stopped

[00063,36,12:50:01.006] PROJECTIONS: Command received: 2@$load-stopped

[00063,36,12:50:01.008] PROJECTIONS: Scheduling the writing of $stopped to $projections-$master. Current status of Writer: Busy: True

[00063,34,12:50:01.010] PROJECTIONS: Finished writing events to $projections-$24112effcf82494d805a3a90ab0f680c: $start

[00063,36,12:50:01.010] PROJECTIONS: Command received: 3@$start

[00063,34,12:50:01.012] PROJECTIONS: Response received: 555@$stopped

[00063,36,12:50:01.022] PROJECTIONS: Finished writing events to $projections-$master: $stopped

[00063,36,12:50:01.215] PROJECTIONS: Scheduling the writing of $started to $projections-$master. Current status of Writer: Busy: False

[00063,34,12:50:01.219] PROJECTIONS: Response received: 559@$started

[00063,36,12:50:01.223] PROJECTIONS: Finished writing events to $projections-$master: $started

[00063,10,12:50:12.056] SLOW QUEUE MSG [MonitoringQueue]: GetFreshStats - 567ms. Q: 0/1.

[00063,19,12:50:13.625] SLOW QUEUE MSG [MonitoringQueue]: GetFreshStats - 558ms. Q: 0/1.

[00063,08,12:50:19.877] SLOW QUEUE MSG [MonitoringQueue]: GetFreshStats - 575ms. Q: 0/0.

========================================= Non Working logs =========================================

[00031,01,12:43:54.672] Quorum size set to 1

[00031,01,12:43:54.682] Cannot find plugins path: plugins

[00031,01,12:43:54.794] INSTANCE ID: 66254093-1462-491f-8a9a-c2c146552c84

[00031,01,12:43:54.795] DATABASE: /var/lib/eventstore

[00031,01,12:43:54.795] WRITER CHECKPOINT: 772007012 (0x2E03E464)

[00031,01,12:43:54.795] CHASER CHECKPOINT: 772007012 (0x2E03E464)

[00031,01,12:43:54.795] EPOCH CHECKPOINT: 658000 (0xA0A50)

[00031,01,12:43:54.795] TRUNCATE CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)

[00031,01,12:43:55.058] MessageHierarchy initialization took 00:00:00.2079058.

[00031,01,12:43:55.132] Opened completed /var/lib/eventstore/chunk-000000.000000 as version 3

[00031,01,12:43:55.136] Opened completed /var/lib/eventstore/chunk-000001.000000 as version 3

[00031,01,12:43:57.887] Opened ongoing /var/lib/eventstore/chunk-000002.000000 as version 3

[00031,08,12:43:57.892] Verifying hash for TFChunk ‘/var/lib/eventstore/chunk-000000.000000’…

[00031,01,12:43:58.173] CACHED TFChunk #2-2 (chunk-000002.000000) in 00:00:00.2789156.

[00031,01,12:43:58.779] Starting MiniWeb for /web/es/js/projections ==> /usr/share/eventstore/projections

[00031,01,12:43:58.779] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> /usr/share/eventstore/Prelude

[00031,01,12:43:58.783] Binding MiniWeb to /web/es/js/projections/{*remaining_path}

[00031,01,12:43:58.784] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*remaining_path}

[00031,01,12:43:58.813] Starting MiniWeb for /web ==> /usr/share/eventstore/clusternode-web

[00031,01,12:43:58.815] Binding MiniWeb to /web/{*remaining_path}

[00031,13,12:43:58.858] ========== [0.0.0.0:2112] SYSTEM INIT…

[00031,13,12:43:58.906] Starting Normal TCP listening on TCP endpoint: 0.0.0.0:1113.

[00031,14,12:43:58.935] TableIndex initialization…

[00031,14,12:43:58.948] ReadIndex building…

[00031,13,12:43:58.983] SLOW BUS MSG [MainBus]: SystemInit - 52ms. Handler: TcpService.

[00031,13,12:43:59.042] Starting HTTP server on [http://*:2113/]…

[00031,13,12:43:59.047] HTTP server is up and listening on [http://*:2113/]

[00031,13,12:43:59.047] SLOW BUS MSG [MainBus]: SystemInit - 63ms. Handler: HttpService.

[00031,13,12:43:59.084] SLOW QUEUE MSG [MainQueue]: SystemInit - 229ms. Q: 0/28.

[00031,13,12:43:59.084] ========== [0.0.0.0:2112] Service ‘StorageWriter’ initialized.

[00031,13,12:43:59.084] ========== [0.0.0.0:2112] Service ‘StorageReader’ initialized.

[00031,14,12:44:03.949] ReadIndex Rebuilding: processed 8712 records (0.8%).

/init.sh: line 9: 31 Killed /entrypoint.sh

Greg_Young1 · June 23, 2018, 12:59pm

Can you run it directly? My guess is there is more information after

[00031,14,12:44:03.949] ReadIndex Rebuilding: processed 8712 records (0.8%).

/init.sh: line 9: 31 Killed /entrypoint.sh

Jason_Hamm · June 23, 2018, 7:33pm

I ssh’ed into the machine and that is all I got