{"action":"created","issue":{"url":"https://api.github.com/repos/EventStore/EventStore/issues/400","labels_url":"https://api.github.com/repos/EventStore/EventStore/issues/400/labels{/name}","comments_url":"https://api.github.com/repos/EventStore/EventStore/issues/400/comments","events_url":"https://api.github.com/repos/EventStore/EventStore/issues/400/events","html_url":"https://github.com/EventStore/EventStore/issues/400","id":58211279,"number":400,"title":"eventstore keeps rebuilding readindex","user":{"login":"robvdlv","id":171731,"avatar_url":"https://avatars.githubusercontent.com/u/171731?v=3","gravatar_id":"","url":"https://api.github.com/users/robvdlv","html_url":"https://github.com/robvdlv","followers_url":"https://api.github.com/users/robvdlv/followers","following_url":"https://api.github.com/users/robvdlv/following{/other_user}","gists_url":"https://api.github.com/users/robvdlv/gists{/gist_id}","starred_url":"https://api.github.com/users/robvdlv/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/robvdlv/subscriptions","organizations_url":"https://api.github.com/users/robvdlv/orgs","repos_url":"https://api.github.com/users/robvdlv/repos","events_url":"https://api.github.com/users/robvdlv/events{/privacy}","received_events_url":"https://api.github.com/users/robvdlv/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":1,"created_at":"2015-02-19T14:00:23Z","updated_at":"2015-02-19T14:07:27Z","closed_at":null,"body":"_Issue_\r\nWe have a case where the EventStore (3.0.1.0 (release-oss-v3.0.1/7fa876c111888dd5980dbd86d126e6abe13b05ab) keeps on rebuilding its read index.\r\n\r\nMore specifically:\r\n* We start the eventstore, it rebuilds its read index.\r\n* When its done rebuilding its read index, we shut down the eventstore.\r\n\r\n* We start the eventstore, it rebuilds its read index ... \r\n* And so on.\r\n\r\nSee attached logs for details.\r\n\r\n_Question_\r\nAny idea how we can get the data in a state where it does not keep rebuilding its read index all the time?\r\n\r\n_Logs_\r\n```\r\n[PID:04116:001 2015.02.19 13:16:03.087 INFO  ProgramBase`1       ] \r\nES VERSION:               3.0.1.0 (release-oss-v3.0.1/7fa876c111888dd5980dbd86d126e6abe13b05ab, Thu, 23 Oct 2014 22:27:04 +0100)\r\nOS:                       Windows (Microsoft Windows NT 6.1.7601 Service Pack 1)\r\nRUNTIME:                  .NET 4.0.30319.18063 (64-bit)\r\nGC:                       3 GENERATIONS\r\nLOGS:                     E:\\Applications\\eventstore-wrapper\\EventStoreLogs\r\n\r\nHELP:                     False (<DEFAULT>)\r\nVERSION:                  False (<DEFAULT>)\r\nLOG:                      EventStoreLogs (Command Line)\r\nCONFIG:                   <empty> (<DEFAULT>)\r\nDEFINES:                  <empty> (<DEFAULT>)\r\nWHAT IF:                  False (<DEFAULT>)\r\nINT IP:                   192.168.64.124 (Command Line)\r\nEXT IP:                   192.168.64.124 (Command Line)\r\nINT HTTP PORT:            2112 (<DEFAULT>)\r\nEXT HTTP PORT:            2113 (<DEFAULT>)\r\nINT TCP PORT:             1112 (<DEFAULT>)\r\nINT SECURE TCP PORT:      0 (<DEFAULT>)\r\nEXT TCP PORT:             1113 (<DEFAULT>)\r\nEXT SECURE TCP PORT:      0 (<DEFAULT>)\r\nINT TCP HEARTBEAT TIMEOUT: 700 (<DEFAULT>)\r\nEXT TCP HEARTBEAT TIMEOUT: 1000 (<DEFAULT>)\r\nINT TCP HEARTBEAT INTERVAL: 700 (<DEFAULT>)\r\nEXT TCP HEARTBEAT INTERVAL: 2000 (<DEFAULT>)\r\nFORCE:                    False (<DEFAULT>)\r\nCLUSTER SIZE:             1 (<DEFAULT>)\r\nNODE PRIORITY:            0 (<DEFAULT>)\r\nMIN FLUSH DELAY MS:       2 (<DEFAULT>)\r\nCOMMIT COUNT:             -1 (<DEFAULT>)\r\nPREPARE COUNT:            -1 (<DEFAULT>)\r\nADMIN ON EXT:             True (<DEFAULT>)\r\nSTATS ON EXT:             True (<DEFAULT>)\r\nGOSSIP ON EXT:            True (<DEFAULT>)\r\nDISABLE SCAVENGE MERGING: False (<DEFAULT>)\r\nDISCOVER VIA DNS:         True (<DEFAULT>)\r\nCLUSTER DNS:              fake.dns (<DEFAULT>)\r\nCLUSTER GOSSIP PORT:      30777 (<DEFAULT>)\r\nGOSSIP SEED:              <empty> (<DEFAULT>)\r\nSTATS PERIOD SEC:         30 (<DEFAULT>)\r\nCACHED CHUNKS:            -1 (<DEFAULT>)\r\nCHUNKS CACHE SIZE:        536871424 (<DEFAULT>)\r\nMAX MEM TABLE SIZE:       1000000 (<DEFAULT>)\r\nDB:                       E:\\PXR\\EventStoreData (Command Line)\r\nMEM DB:                   False (<DEFAULT>)\r\nSKIP DB VERIFY:           False (<DEFAULT>)\r\nRUN PROJECTIONS:          None (Command Line)\r\nPROJECTION THREADS:       3 (<DEFAULT>)\r\nWORKER THREADS:           5 (<DEFAULT>)\r\nHTTP PREFIXES:            [ http://127.0.0.1:2113/ ] (Command Line)\r\nENABLE TRUSTED AUTH:      False (<DEFAULT>)\r\nCERTIFICATE STORE LOCATION: <empty> (<DEFAULT>)\r\nCERTIFICATE STORE NAME:   <empty> (<DEFAULT>)\r\nCERTIFICATE SUBJECT NAME: <empty> (<DEFAULT>)\r\nCERTIFICATE THUMBPRINT:   <empty> (<DEFAULT>)\r\nCERTIFICATE FILE:         <empty> (<DEFAULT>)\r\nCERTIFICATE PASSWORD:     <empty> (<DEFAULT>)\r\nUSE INTERNAL SSL:         False (<DEFAULT>)\r\nSSL TARGET HOST:          n/a (<DEFAULT>)\r\nSSL VALIDATE SERVER:      True (<DEFAULT>)\r\nAUTHENTICATION TYPE:      internal (<DEFAULT>)\r\nPREPARE TIMEOUT MS:       2000 (<DEFAULT>)\r\nCOMMIT TIMEOUT MS:        2000 (<DEFAULT>)\r\nUNSAFE DISABLE FLUSH TO DISK: False (<DEFAULT>)\r\nGOSSIP INTERVAL MS:       1000 (<DEFAULT>)\r\nGOSSIP ALLOWED DIFFERENCE MS: 60000 (<DEFAULT>)\r\nGOSSIP TIMEOUT MS:        500 (<DEFAULT>)\r\n\r\n[PID:04116:001 2015.02.19 13:16:03.274 INFO  ProgramBase`1       ] Quorum size set to 1\r\n[PID:04116:001 2015.02.19 13:16:03.306 INFO  ProgramBase`1       ] Can't find plugins path: E:\\Applications\\geteventstore\\plugins\r\n[PID:04116:001 2015.02.19 13:16:03.337 INFO  ProgramBase`1       ] \r\nINSTANCE ID:              92733c82-88bd-4ad3-8393-093b2496b415\r\nDATABASE:                 E:\\PXR\\EventStoreData\r\nWRITER CHECKPOINT:        3091508232 (0xB844AC08)\r\nCHASER CHECKPOINT:        3091508232 (0xB844AC08)\r\nEPOCH CHECKPOINT:         2179096341 (0x81E25F15)\r\nTRUNCATE CHECKPOINT:      -1 (0xFFFFFFFFFFFFFFFF)\r\n\r\n[PID:04116:001 2015.02.19 13:16:03.962 TRACE MessageHierarchy    ] MessageHierarchy initialization took 00:00:00.5322879.\r\n[PID:04116:005 2015.02.19 13:16:05.525 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000009.000000'...\r\n[PID:04116:001 2015.02.19 13:16:05.681 TRACE TFChunk             ] CACHED TFChunk #11-11 (chunk-000011.000000) in 00:00:00.1748998.\r\n[PID:04116:001 2015.02.19 13:16:06.525 INFO  MiniWeb             ] Starting MiniWeb for /web/es/js/projections ==> E:\\Applications\\geteventstore\\projections\r\n[PID:04116:001 2015.02.19 13:16:06.525 INFO  MiniWeb             ] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> E:\\Applications\\geteventstore\\Prelude\r\n[PID:04116:001 2015.02.19 13:16:06.525 INFO  MiniWeb             ] Starting MiniWeb for /web/es/js/projections/resources ==> E:\\Applications\\geteventstore\\web-resources\\js\r\n[PID:04116:001 2015.02.19 13:16:06.540 TRACE MiniWeb             ] Binding MiniWeb to /web/es/js/projections/{*remaining_path}\r\n[PID:04116:001 2015.02.19 13:16:06.540 TRACE MiniWeb             ] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*remaining_path}\r\n[PID:04116:001 2015.02.19 13:16:06.540 TRACE MiniWeb             ] Binding MiniWeb to /web/es/js/projections/resources/{*remaining_path}\r\n[PID:04116:001 2015.02.19 13:16:06.556 INFO  MiniWeb             ] Starting MiniWeb for /web ==> E:\\Applications\\geteventstore\\clusternode-web\r\n[PID:04116:001 2015.02.19 13:16:06.556 TRACE MiniWeb             ] Binding MiniWeb to /web/{*remaining_path}\r\n[PID:04116:001 2015.02.19 13:16:06.759 INFO  MiniWeb             ] Starting MiniWeb for /web/users ==> E:\\Applications\\geteventstore\\Users\\web\r\n[PID:04116:001 2015.02.19 13:16:06.759 TRACE MiniWeb             ] Binding MiniWeb to /web/users/{*remaining_path}\r\n[PID:04116:010 2015.02.19 13:16:06.790 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] SYSTEM INIT...\r\n[PID:04116:014 2015.02.19 13:16:06.837 INFO  IndexCommitter      ] TableIndex initialization...\r\n[PID:04116:014 2015.02.19 13:16:06.853 INFO  IndexCommitter      ] ReadIndex building...\r\n[PID:04116:010 2015.02.19 13:16:06.884 INFO  TcpServerListener   ] Starting Normal TCP listening on TCP endpoint: 192.168.64.124:1113.\r\n[PID:04116:010 2015.02.19 13:16:06.915 TRACE InMemoryBus         ] SLOW BUS MSG [MainBus]: SystemInit - 62ms. Handler: TcpService.\r\n[PID:04116:010 2015.02.19 13:16:06.947 INFO  HttpAsyncServer     ] Starting HTTP server on [http://127.0.0.1:2113/]...\r\n[PID:04116:010 2015.02.19 13:16:06.962 INFO  HttpAsyncServer     ] HTTP server is up and listening on [http://127.0.0.1:2113/]\r\n[PID:04116:010 2015.02.19 13:16:06.993 TRACE QueuedHandlerMRES   ] SLOW QUEUE MSG [MainQueue]: SystemInit - 203ms. Q: 0/70.\r\n[PID:04116:010 2015.02.19 13:16:06.993 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] Service 'StorageReader' initialized.\r\n[PID:04116:010 2015.02.19 13:16:06.993 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] Service 'StorageWriter' initialized.\r\n[PID:04116:007 2015.02.19 13:16:09.259 TRACE TFChunk             ] CACHED TFChunk #10-10 (chunk-000010.000000) in 00:00:03.5794351.\r\n[PID:04116:011 2015.02.19 13:16:09.525 TRACE QueuedHandlerThreadP] SLOW QUEUE MSG [MonitoringQueue]: SystemInit - 2687ms. Q: 0/0.\r\n[PID:04116:014 2015.02.19 13:16:11.853 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 4090 records (1,9%).\r\n[PID:04116:005 2015.02.19 13:16:16.838 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000008.000000'...\r\n[PID:04116:014 2015.02.19 13:16:16.853 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 8104 records (3,9%).\r\n[PID:04116:014 2015.02.19 13:16:21.853 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 12182 records (5,8%).\r\n[PID:04116:014 2015.02.19 13:16:26.853 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 16215 records (7,7%).\r\n[PID:04116:005 2015.02.19 13:16:28.104 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000007.000000'...\r\n[PID:04116:014 2015.02.19 13:16:31.854 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 20191 records (9,6%).\r\n[PID:04116:014 2015.02.19 13:16:36.854 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 24114 records (11,5%).\r\n[PID:04116:005 2015.02.19 13:16:39.463 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000006.000000'...\r\n[PID:04116:014 2015.02.19 13:16:41.854 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 28163 records (13,4%).\r\n[PID:04116:014 2015.02.19 13:16:46.854 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 32361 records (15,4%).\r\n[PID:04116:005 2015.02.19 13:16:50.401 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000005.000000'...\r\n[PID:04116:014 2015.02.19 13:16:51.854 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 36503 records (17,4%).\r\n[PID:04116:014 2015.02.19 13:16:56.855 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 40431 records (19,3%).\r\n[PID:04116:005 2015.02.19 13:17:01.636 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000004.000000'...\r\n[PID:04116:014 2015.02.19 13:17:01.855 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 44508 records (21,3%).\r\n[PID:04116:014 2015.02.19 13:17:06.855 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 48478 records (23,2%).\r\n[PID:04116:014 2015.02.19 13:17:11.855 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 52714 records (25,2%).\r\n[PID:04116:005 2015.02.19 13:17:12.527 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000003.000000'...\r\n[PID:04116:014 2015.02.19 13:17:16.855 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 55610 records (26,6%).\r\n[PID:04116:014 2015.02.19 13:17:21.855 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 57611 records (27,6%).\r\n[PID:04116:014 2015.02.19 13:17:26.856 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 59489 records (28,5%).\r\n[PID:04116:014 2015.02.19 13:17:31.856 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 61375 records (29,4%).\r\n[PID:04116:005 2015.02.19 13:17:31.965 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000002.000000'...\r\n[PID:04116:014 2015.02.19 13:17:36.856 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 65203 records (31,2%).\r\n[PID:04116:014 2015.02.19 13:17:41.856 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 69036 records (33,1%).\r\n[PID:04116:005 2015.02.19 13:17:43.590 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000001.000000'...\r\n[PID:04116:014 2015.02.19 13:17:46.856 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 73077 records (35,0%).\r\n[PID:04116:014 2015.02.19 13:17:51.856 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 77369 records (37,1%).\r\n[PID:04116:005 2015.02.19 13:17:54.325 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000000.000000'...\r\n[PID:04116:014 2015.02.19 13:17:56.857 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 81643 records (39,2%).\r\n[PID:04116:014 2015.02.19 13:18:01.857 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 85706 records (41,1%).\r\n[PID:04116:014 2015.02.19 13:18:06.857 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 89883 records (43,1%).\r\n[PID:04116:014 2015.02.19 13:18:11.857 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 93867 records (45,0%).\r\n[PID:04116:014 2015.02.19 13:18:16.857 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 97965 records (47,0%).\r\n[PID:04116:014 2015.02.19 13:18:19.373 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 100000 records (48,0%).\r\n[PID:04116:014 2015.02.19 13:18:24.373 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 103668 records (49,8%).\r\n[PID:04116:014 2015.02.19 13:18:29.373 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 107637 records (51,7%).\r\n[PID:04116:014 2015.02.19 13:18:34.374 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 111593 records (53,6%).\r\n[PID:04116:014 2015.02.19 13:18:39.374 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 115496 records (55,5%).\r\n[PID:04116:014 2015.02.19 13:18:44.374 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 119145 records (57,2%).\r\n[PID:04116:014 2015.02.19 13:18:49.374 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 122888 records (59,0%).\r\n[PID:04116:014 2015.02.19 13:18:54.374 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 126859 records (60,9%).\r\n[PID:04116:014 2015.02.19 13:18:59.375 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 130707 records (62,8%).\r\n[PID:04116:014 2015.02.19 13:19:04.375 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 134694 records (64,7%).\r\n[PID:04116:014 2015.02.19 13:19:09.375 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 138563 records (66,5%).\r\n[PID:04116:014 2015.02.19 13:19:14.375 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 142582 records (68,5%).\r\n[PID:04116:014 2015.02.19 13:19:19.376 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 146435 records (70,3%).\r\n[PID:04116:014 2015.02.19 13:19:24.376 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 150529 records (72,2%).\r\n[PID:04116:014 2015.02.19 13:19:29.376 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 154306 records (73,9%).\r\n[PID:04116:014 2015.02.19 13:19:34.376 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 158558 records (76,0%).\r\n[PID:04116:014 2015.02.19 13:19:39.376 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 162221 records (77,7%).\r\n[PID:04116:014 2015.02.19 13:19:44.377 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 166212 records (79,6%).\r\n[PID:04116:014 2015.02.19 13:19:49.377 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 170654 records (81,8%).\r\n[PID:04116:014 2015.02.19 13:19:54.377 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 175064 records (83,8%).\r\n[PID:04116:014 2015.02.19 13:19:59.377 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 178854 records (85,6%).\r\n[PID:04116:014 2015.02.19 13:20:02.862 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 200000 records (95,8%).\r\n[PID:04116:014 2015.02.19 13:20:03.159 DEBUG IndexCommitter      ] ReadIndex rebuilding done: total processed 208675 records, time elapsed: 00:03:56.3059283.\r\n[PID:04116:010 2015.02.19 13:20:03.206 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] Service 'StorageChaser' initialized.\r\n[PID:04116:010 2015.02.19 13:20:03.206 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] SYSTEM START...\r\n[PID:04116:010 2015.02.19 13:20:03.206 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] IS UNKNOWN!!! WHOA!!!\r\n[PID:04116:010 2015.02.19 13:20:03.252 DEBUG ElectionsService    ] ELECTIONS: STARTING ELECTIONS.\r\n[PID:04116:010 2015.02.19 13:20:03.268 DEBUG ElectionsService    ] ELECTIONS: (V=0) SHIFT TO LEADER ELECTION.\r\n[PID:04116:010 2015.02.19 13:20:03.268 DEBUG ElectionsService    ] ELECTIONS: (V=0) VIEWCHANGE FROM [192.168.64.124:2112, {92733c82-88bd-4ad3-8393-093b2496b415}].\r\n[PID:04116:010 2015.02.19 13:20:03.268 DEBUG ElectionsService    ] ELECTIONS: (V=0) MAJORITY OF VIEWCHANGE.\r\n[PID:04116:010 2015.02.19 13:20:03.268 DEBUG ElectionsService    ] ELECTIONS: (V=0) SHIFT TO PREPARE PHASE.\r\n[PID:04116:010 2015.02.19 13:20:03.284 DEBUG ElectionsService    ] ELECTIONS: (V=0) PREPARE_OK FROM [192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}](L=3091493279,W=3091508232,C=3091508232,E1@2179096341:{5a0e9793-22fe-475b-bf6f-b1a4e8f75403}).\r\n[PID:04116:010 2015.02.19 13:20:03.284 DEBUG ElectionsService    ] ELECTIONS: (V=0) SHIFT TO REG_LEADER.\r\n[PID:04116:010 2015.02.19 13:20:03.299 DEBUG ElectionsService    ] ELECTIONS: (V=0) SENDING PROPOSAL CANDIDATE: [192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}](L=3091493279,W=3091508232,C=3091508232,E1@2179096341:{5a0e9793-22fe-475b-bf6f-b1a4e8f75403}), ME: [192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}](L=3091493279,W=3091508232,C=3091508232,E1@2179096341:{5a0e9793-22fe-475b-bf6f-b1a4e8f75403}).\r\n[PID:04116:010 2015.02.19 13:20:03.299 DEBUG ElectionsService    ] ELECTIONS: (V=0) ACCEPT FROM [192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}] M=[192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}]).\r\n[PID:04116:010 2015.02.19 13:20:03.299 INFO  ElectionsService    ] ELECTIONS: (V=0) DONE. ELECTED MASTER = [192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}](L=3091493279,W=3091508232,C=3091508232,E1@2179096341:{5a0e9793-22fe-475b-bf6f-b1a4e8f75403}). ME=[192.168.64.124:2112,{92733c82-88bd-4ad3-8393-093b2496b415}](L=3091493279,W=3091508232,C=3091508232,E1@2179096341:{5a0e9793-22fe-475b-bf6f-b1a4e8f75403}).\r\n[PID:04116:010 2015.02.19 13:20:03.315 TRACE InMemoryBus         ] SLOW BUS MSG [MainBus]: StartElections - 93ms. Handler: ElectionsService.\r\n[PID:04116:010 2015.02.19 13:20:03.315 TRACE QueuedHandlerMRES   ] SLOW QUEUE MSG [MainQueue]: StartElections - 93ms. Q: 1/7.\r\n[PID:04116:010 2015.02.19 13:20:03.315 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] PRE-MASTER STATE, WAITING FOR CHASER TO CATCH UP...\r\n[PID:04116:010 2015.02.19 13:20:03.331 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] IS MASTER!!! SPARTA!!!\r\n[PID:04116:008 2015.02.19 13:20:03.502 DEBUG EpochManager        ] === Writing E2@3091508232:{54fa36d3-cc89-4f3b-bc00-bb53f2c801a2} (previous epoch at 2179096341).\r\n[PID:04116:008 2015.02.19 13:20:03.549 DEBUG EpochManager        ] === Update Last Epoch E2@3091508232:{54fa36d3-cc89-4f3b-bc00-bb53f2c801a2} (previous epoch at 2179096341).\r\n[PID:04116:010 2015.02.19 13:20:03.706 TRACE InMemoryBus         ] SLOW BUS MSG [MainBus]: WritePrepares - 62ms. Handler: WideningHandler`2.\r\n[PID:04116:010 2015.02.19 13:20:03.706 TRACE QueuedHandlerMRES   ] SLOW QUEUE MSG [MainQueue]: WritePrepares - 62ms. Q: 0/0.\r\n[PID:04116:011 2015.02.19 13:20:03.752 TRACE MonitoringService   ] Created stats stream '$stats-192.168.64.124:2113', code = Success\r\n[PID:04912:001 2015.02.19 13:26:41.923 INFO  ProgramBase`1       ] \r\nES VERSION:               3.0.1.0 (release-oss-v3.0.1/7fa876c111888dd5980dbd86d126e6abe13b05ab, Thu, 23 Oct 2014 22:27:04 +0100)\r\nOS:                       Windows (Microsoft Windows NT 6.1.7601 Service Pack 1)\r\nRUNTIME:                  .NET 4.0.30319.18063 (64-bit)\r\nGC:                       3 GENERATIONS\r\nLOGS:                     E:\\Applications\\eventstore-wrapper\\EventStoreLogs\r\n\r\nHELP:                     False (<DEFAULT>)\r\nVERSION:                  False (<DEFAULT>)\r\nLOG:                      EventStoreLogs (Command Line)\r\nCONFIG:                   <empty> (<DEFAULT>)\r\nDEFINES:                  <empty> (<DEFAULT>)\r\nWHAT IF:                  False (<DEFAULT>)\r\nINT IP:                   192.168.64.124 (Command Line)\r\nEXT IP:                   192.168.64.124 (Command Line)\r\nINT HTTP PORT:            2112 (<DEFAULT>)\r\nEXT HTTP PORT:            2113 (<DEFAULT>)\r\nINT TCP PORT:             1112 (<DEFAULT>)\r\nINT SECURE TCP PORT:      0 (<DEFAULT>)\r\nEXT TCP PORT:             1113 (<DEFAULT>)\r\nEXT SECURE TCP PORT:      0 (<DEFAULT>)\r\nINT TCP HEARTBEAT TIMEOUT: 700 (<DEFAULT>)\r\nEXT TCP HEARTBEAT TIMEOUT: 1000 (<DEFAULT>)\r\nINT TCP HEARTBEAT INTERVAL: 700 (<DEFAULT>)\r\nEXT TCP HEARTBEAT INTERVAL: 2000 (<DEFAULT>)\r\nFORCE:                    False (<DEFAULT>)\r\nCLUSTER SIZE:             1 (<DEFAULT>)\r\nNODE PRIORITY:            0 (<DEFAULT>)\r\nMIN FLUSH DELAY MS:       2 (<DEFAULT>)\r\nCOMMIT COUNT:             -1 (<DEFAULT>)\r\nPREPARE COUNT:            -1 (<DEFAULT>)\r\nADMIN ON EXT:             True (<DEFAULT>)\r\nSTATS ON EXT:             True (<DEFAULT>)\r\nGOSSIP ON EXT:            True (<DEFAULT>)\r\nDISABLE SCAVENGE MERGING: False (<DEFAULT>)\r\nDISCOVER VIA DNS:         True (<DEFAULT>)\r\nCLUSTER DNS:              fake.dns (<DEFAULT>)\r\nCLUSTER GOSSIP PORT:      30777 (<DEFAULT>)\r\nGOSSIP SEED:              <empty> (<DEFAULT>)\r\nSTATS PERIOD SEC:         30 (<DEFAULT>)\r\nCACHED CHUNKS:            -1 (<DEFAULT>)\r\nCHUNKS CACHE SIZE:        536871424 (<DEFAULT>)\r\nMAX MEM TABLE SIZE:       1000000 (<DEFAULT>)\r\nDB:                       E:\\PXR\\EventStoreData (Command Line)\r\nMEM DB:                   False (<DEFAULT>)\r\nSKIP DB VERIFY:           False (<DEFAULT>)\r\nRUN PROJECTIONS:          None (Command Line)\r\nPROJECTION THREADS:       3 (<DEFAULT>)\r\nWORKER THREADS:           5 (<DEFAULT>)\r\nHTTP PREFIXES:            [ http://127.0.0.1:2113/ ] (Command Line)\r\nENABLE TRUSTED AUTH:      False (<DEFAULT>)\r\nCERTIFICATE STORE LOCATION: <empty> (<DEFAULT>)\r\nCERTIFICATE STORE NAME:   <empty> (<DEFAULT>)\r\nCERTIFICATE SUBJECT NAME: <empty> (<DEFAULT>)\r\nCERTIFICATE THUMBPRINT:   <empty> (<DEFAULT>)\r\nCERTIFICATE FILE:         <empty> (<DEFAULT>)\r\nCERTIFICATE PASSWORD:     <empty> (<DEFAULT>)\r\nUSE INTERNAL SSL:         False (<DEFAULT>)\r\nSSL TARGET HOST:          n/a (<DEFAULT>)\r\nSSL VALIDATE SERVER:      True (<DEFAULT>)\r\nAUTHENTICATION TYPE:      internal (<DEFAULT>)\r\nPREPARE TIMEOUT MS:       2000 (<DEFAULT>)\r\nCOMMIT TIMEOUT MS:        2000 (<DEFAULT>)\r\nUNSAFE DISABLE FLUSH TO DISK: False (<DEFAULT>)\r\nGOSSIP INTERVAL MS:       1000 (<DEFAULT>)\r\nGOSSIP ALLOWED DIFFERENCE MS: 60000 (<DEFAULT>)\r\nGOSSIP TIMEOUT MS:        500 (<DEFAULT>)\r\n\r\n[PID:04912:001 2015.02.19 13:26:42.095 INFO  ProgramBase`1       ] Quorum size set to 1\r\n[PID:04912:001 2015.02.19 13:26:42.111 INFO  ProgramBase`1       ] Can't find plugins path: E:\\Applications\\geteventstore\\plugins\r\n[PID:04912:001 2015.02.19 13:26:42.127 INFO  ProgramBase`1       ] \r\nINSTANCE ID:              05702f6b-bc89-42cc-8ed6-3674278e003e\r\nDATABASE:                 E:\\PXR\\EventStoreData\r\nWRITER CHECKPOINT:        3091701941 (0xB847A0B5)\r\nCHASER CHECKPOINT:        3091701941 (0xB847A0B5)\r\nEPOCH CHECKPOINT:         3091508232 (0xB844AC08)\r\nTRUNCATE CHECKPOINT:      -1 (0xFFFFFFFFFFFFFFFF)\r\n\r\n[PID:04912:001 2015.02.19 13:26:42.548 TRACE MessageHierarchy    ] MessageHierarchy initialization took 00:00:00.2371285.\r\n[PID:04912:006 2015.02.19 13:26:43.908 TRACE TFChunk             ] Verifying hash for TFChunk 'E:\\PXR\\EventStoreData\\chunk-000009.000000'...\r\n[PID:04912:001 2015.02.19 13:26:44.049 TRACE TFChunk             ] CACHED TFChunk #11-11 (chunk-000011.000000) in 00:00:00.1674425.\r\n[PID:04912:005 2015.02.19 13:26:44.408 TRACE TFChunk             ] CACHED TFChunk #10-10 (chunk-000010.000000) in 00:00:00.3480123.\r\n[PID:04912:001 2015.02.19 13:26:44.767 INFO  MiniWeb             ] Starting MiniWeb for /web/es/js/projections ==> E:\\Applications\\geteventstore\\projections\r\n[PID:04912:001 2015.02.19 13:26:44.767 INFO  MiniWeb             ] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> E:\\Applications\\geteventstore\\Prelude\r\n[PID:04912:001 2015.02.19 13:26:44.767 INFO  MiniWeb             ] Starting MiniWeb for /web/es/js/projections/resources ==> E:\\Applications\\geteventstore\\web-resources\\js\r\n[PID:04912:001 2015.02.19 13:26:44.767 TRACE MiniWeb             ] Binding MiniWeb to /web/es/js/projections/{*remaining_path}\r\n[PID:04912:001 2015.02.19 13:26:44.767 TRACE MiniWeb             ] Binding MiniWeb to /web/es/js/projections/v8/Prelude/{*remaining_path}\r\n[PID:04912:001 2015.02.19 13:26:44.767 TRACE MiniWeb             ] Binding MiniWeb to /web/es/js/projections/resources/{*remaining_path}\r\n[PID:04912:001 2015.02.19 13:26:44.799 INFO  MiniWeb             ] Starting MiniWeb for /web ==> E:\\Applications\\geteventstore\\clusternode-web\r\n[PID:04912:001 2015.02.19 13:26:44.799 TRACE MiniWeb             ] Binding MiniWeb to /web/{*remaining_path}\r\n[PID:04912:001 2015.02.19 13:26:44.814 INFO  MiniWeb             ] Starting MiniWeb for /web/users ==> E:\\Applications\\geteventstore\\Users\\web\r\n[PID:04912:001 2015.02.19 13:26:44.814 TRACE MiniWeb             ] Binding MiniWeb to /web/users/{*remaining_path}\r\n[PID:04912:010 2015.02.19 13:26:44.861 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] SYSTEM INIT...\r\n[PID:04912:013 2015.02.19 13:26:44.908 INFO  IndexCommitter      ] TableIndex initialization...\r\n[PID:04912:013 2015.02.19 13:26:44.924 INFO  IndexCommitter      ] ReadIndex building...\r\n[PID:04912:010 2015.02.19 13:26:44.955 INFO  TcpServerListener   ] Starting Normal TCP listening on TCP endpoint: 192.168.64.124:1113.\r\n[PID:04912:010 2015.02.19 13:26:44.986 TRACE InMemoryBus         ] SLOW BUS MSG [MainBus]: SystemInit - 62ms. Handler: TcpService.\r\n[PID:04912:010 2015.02.19 13:26:45.017 INFO  HttpAsyncServer     ] Starting HTTP server on [http://127.0.0.1:2113/]...\r\n[PID:04912:010 2015.02.19 13:26:45.017 INFO  HttpAsyncServer     ] HTTP server is up and listening on [http://127.0.0.1:2113/]\r\n[PID:04912:010 2015.02.19 13:26:45.049 TRACE QueuedHandlerMRES   ] SLOW QUEUE MSG [MainQueue]: SystemInit - 187ms. Q: 0/4.\r\n[PID:04912:010 2015.02.19 13:26:45.049 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] Service 'StorageReader' initialized.\r\n[PID:04912:010 2015.02.19 13:26:45.049 INFO  ClusterVNodeControll] ========== [192.168.64.124:2112] Service 'StorageWriter' initialized.\r\n[PID:04912:005 2015.02.19 13:26:48.205 TRACE QueuedHandlerThreadP] SLOW QUEUE MSG [MonitoringQueue]: SystemInit - 3328ms. Q: 0/0.\r\n[PID:04912:013 2015.02.19 13:26:49.924 DEBUG IndexCommitter      ] ReadIndex Rebuilding: processed 3998 records (1,9%)\r\n```"},"comment":{"url":"https://api.github.com/repos/EventStore/EventStore/issues/comments/75056784","html_url":"https://github.com/EventStore/EventStore/issues/400#issuecomment-75056784","issue_url":"https://api.github.com/repos/EventStore/EventStore/issues/400","id":75056784,"user":{"login":"jen20","id":548524,"avatar_url":"https://avatars.githubusercontent.com/u/548524?v=3","gravatar_id":"","url":"https://api.github.com/users/jen20","html_url":"https://github.com/jen20","followers_url":"https://api.github.com/users/jen20/followers","following_url":"https://api.github.com/users/jen20/following{/other_user}","gists_url":"https://api.github.com/users/jen20/gists{/gist_id}","starred_url":"https://api.github.com/users/jen20/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jen20/subscriptions","organizations_url":"https://api.github.com/users/jen20/orgs","repos_url":"https://api.github.com/users/jen20/repos","events_url":"https://api.github.com/users/jen20/events{/privacy}","received_events_url":"https://api.github.com/users/jen20/received_events","type":"User","site_admin":false},"created_at":"2015-02-19T14:07:27Z","updated_at":"2015-02-19T14:07:27Z","body":"The index exists in two places: the most recent chunk is kept only in memory and older segments are kept on disk. The default threshold for the first disk based index file is 1 million events. By the look of the log you only have 208,675 events which would explain this if you're running with default settings. You can adjust this with the `--max-mem-table-size=VALUE` option.\r\n\r\nHowever, this doesn't look like the actual root cause of your issue; taking four minutes to read 200,000 events is pretty bad - are you running in Azure or similar?"}}