Skip to content

Instantly share code, notes, and snippets.

@npryce
Created March 1, 2011 14:01
Show Gist options
  • Save npryce/849165 to your computer and use it in GitHub Desktop.
Save npryce/849165 to your computer and use it in GitHub Desktop.
Test to demonstrate search after refresh problem
Starting Elastic
2011-03-01T14:02:24.737+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:24.737+0000 INFO [main] [org.elasticsearch.plugins] [Stark, Arno] loaded []
2011-03-01T14:02:25.970+0000 WARN [main] [org.elasticsearch.indices] [Stark, Arno] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:26.610+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:26.610+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:26.626+0000 INFO [main] [org.elasticsearch.transport] [Stark, Arno] bound_address {local[1]}, publish_address {local[1]}
2011-03-01T14:02:26.626+0000 INFO [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [org.elasticsearch.cluster.service] [Stark, Arno] new_master [Stark, Arno][1][local[1]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:26.657+0000 INFO [main] [org.elasticsearch.discovery] [Stark, Arno] elasticsearch/1
2011-03-01T14:02:26.829+0000 INFO [main] [org.elasticsearch.http] [Stark, Arno] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:26.829+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:27.344+0000 INFO [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [org.elasticsearch.cluster.metadata] [Stark, Arno] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:27.719+0000 DEBUG [elasticsearch[cached]-pool-1-thread-3] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][0], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.719+0000 INFO [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [org.elasticsearch.cluster.metadata] [Stark, Arno] [test_index_name] created and added to cluster_state
2011-03-01T14:02:27.719+0000 DEBUG [elasticsearch[cached]-pool-1-thread-3] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][0], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.719+0000 DEBUG [elasticsearch[cached]-pool-1-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][1], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.734+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] applying started shard [test_index_name][0], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.734+0000 DEBUG [elasticsearch[cached]-pool-1-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][1], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.750+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][1], node[1], [P], s[INITIALIZING], reason [master [Stark, Arno][1][local[1]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:27.750+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][1], node[1], [P], s[INITIALIZING], reason [master [Stark, Arno][1][local[1]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:27.765+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] applying started shard [test_index_name][1], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.781+0000 DEBUG [elasticsearch[cached]-pool-1-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][2], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.797+0000 DEBUG [elasticsearch[cached]-pool-1-thread-3] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][3], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.812+0000 DEBUG [elasticsearch[cached]-pool-1-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][2], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.812+0000 DEBUG [elasticsearch[cached]-pool-1-thread-3] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][3], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.812+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] applying started shard [test_index_name][2], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.828+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][3], node[1], [P], s[INITIALIZING], reason [master [Stark, Arno][1][local[1]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:27.828+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][3], node[1], [P], s[INITIALIZING], reason [master [Stark, Arno][1][local[1]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:27.844+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] applying started shard [test_index_name][3], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.859+0000 DEBUG [elasticsearch[cached]-pool-1-thread-3] [elasticsearch.cluster.action.shard] [Stark, Arno] sending shard started for [test_index_name][4], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.890+0000 DEBUG [elasticsearch[cached]-pool-1-thread-3] [elasticsearch.cluster.action.shard] [Stark, Arno] received shard started for [test_index_name][4], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.890+0000 DEBUG [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [elasticsearch.cluster.action.shard] [Stark, Arno] applying started shard [test_index_name][4], node[1], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:27.953+0000 INFO [elasticsearch[Stark, Arno]clusterService#updateTask-pool-10-thread-1] [org.elasticsearch.cluster.metadata] [Stark, Arno] [test_index_name] update_mapping [testIndexType] (dynamic)
Stopping Elastic
2011-03-01T14:02:28.078+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:28.109+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:28.109+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:28.109+0000 INFO [main] [org.elasticsearch.node] [Stark, Arno] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:28.156+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:28.156+0000 INFO [main] [org.elasticsearch.plugins] [Arcturus Rann] loaded []
2011-03-01T14:02:28.296+0000 WARN [main] [org.elasticsearch.indices] [Arcturus Rann] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:28.811+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:28.811+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:28.811+0000 INFO [main] [org.elasticsearch.transport] [Arcturus Rann] bound_address {local[2]}, publish_address {local[2]}
2011-03-01T14:02:28.811+0000 INFO [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [org.elasticsearch.cluster.service] [Arcturus Rann] new_master [Arcturus Rann][2][local[2]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:28.827+0000 INFO [main] [org.elasticsearch.discovery] [Arcturus Rann] elasticsearch/2
2011-03-01T14:02:28.843+0000 INFO [main] [org.elasticsearch.http] [Arcturus Rann] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:28.843+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:28.968+0000 INFO [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [org.elasticsearch.cluster.metadata] [Arcturus Rann] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:29.108+0000 DEBUG [elasticsearch[cached]-pool-14-thread-3] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][0], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.108+0000 DEBUG [elasticsearch[cached]-pool-14-thread-3] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][0], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.108+0000 INFO [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [org.elasticsearch.cluster.metadata] [Arcturus Rann] [test_index_name] created and added to cluster_state
2011-03-01T14:02:29.108+0000 DEBUG [elasticsearch[cached]-pool-14-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][1], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.139+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] applying started shard [test_index_name][0], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.139+0000 DEBUG [elasticsearch[cached]-pool-14-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][1], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.139+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][1], node[2], [P], s[INITIALIZING], reason [master [Arcturus Rann][2][local[2]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:29.139+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][1], node[2], [P], s[INITIALIZING], reason [master [Arcturus Rann][2][local[2]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:29.249+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] applying started shard [test_index_name][1], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.264+0000 DEBUG [elasticsearch[cached]-pool-14-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][2], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.264+0000 DEBUG [elasticsearch[cached]-pool-14-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][2], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.264+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] applying started shard [test_index_name][2], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:29.280+0000 DEBUG [elasticsearch[cached]-pool-14-thread-4] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][3], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.311+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][3], node[2], [P], s[INITIALIZING], reason [master [Arcturus Rann][2][local[2]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:29.311+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:29.311+0000 DEBUG [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][3], node[2], [P], s[INITIALIZING], reason [master [Arcturus Rann][2][local[2]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:29.311+0000 DEBUG [elasticsearch[cached]-pool-14-thread-4] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][3], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.327+0000 WARN [elasticsearch[Arcturus Rann]clusterService#updateTask-pool-23-thread-1] [org.elasticsearch.cluster.metadata] [Arcturus Rann] failed to dynamically update the mapping in cluster_state from shard
org.elasticsearch.ElasticSearchIllegalStateException: Can't create an index [test_index_name] is closed
at org.elasticsearch.indices.InternalIndicesService.createIndex(InternalIndicesService.java:214)
at org.elasticsearch.cluster.metadata.MetaDataMappingService$1.execute(MetaDataMappingService.java:86)
at org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:175)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-03-01T14:02:29.342+0000 DEBUG [elasticsearch[cached]-pool-14-thread-4] [elasticsearch.cluster.action.shard] [Arcturus Rann] sending shard started for [test_index_name][4], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.373+0000 DEBUG [elasticsearch[cached]-pool-14-thread-4] [elasticsearch.cluster.action.shard] [Arcturus Rann] received shard started for [test_index_name][4], node[2], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:29.373+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:29.373+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:29.389+0000 INFO [main] [org.elasticsearch.node] [Arcturus Rann] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.onFirstPhaseResult(TransportSearchTypeAction.java:247)
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.start(TransportSearchTypeAction.java:137)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:56)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:48)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:99)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:45)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.client.node.NodeClient.search(NodeClient.java:168)
at org.elasticsearch.client.action.search.SearchRequestBuilder.doExecute(SearchRequestBuilder.java:488)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:56)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:51)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:111)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:29.483+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:29.483+0000 INFO [main] [org.elasticsearch.plugins] [Hit-Maker] loaded []
2011-03-01T14:02:29.545+0000 WARN [main] [org.elasticsearch.indices] [Hit-Maker] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:30.060+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:30.060+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:30.060+0000 INFO [main] [org.elasticsearch.transport] [Hit-Maker] bound_address {local[3]}, publish_address {local[3]}
2011-03-01T14:02:30.060+0000 INFO [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [org.elasticsearch.cluster.service] [Hit-Maker] new_master [Hit-Maker][3][local[3]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:30.092+0000 INFO [main] [org.elasticsearch.discovery] [Hit-Maker] elasticsearch/3
2011-03-01T14:02:30.107+0000 INFO [main] [org.elasticsearch.http] [Hit-Maker] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:30.107+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:30.217+0000 INFO [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [org.elasticsearch.cluster.metadata] [Hit-Maker] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:30.404+0000 DEBUG [elasticsearch[cached]-pool-27-thread-3] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][0], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.404+0000 INFO [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [org.elasticsearch.cluster.metadata] [Hit-Maker] [test_index_name] created and added to cluster_state
2011-03-01T14:02:30.404+0000 DEBUG [elasticsearch[cached]-pool-27-thread-3] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][0], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.420+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] applying started shard [test_index_name][0], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.420+0000 DEBUG [elasticsearch[cached]-pool-27-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][1], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.420+0000 DEBUG [elasticsearch[cached]-pool-27-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][1], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.420+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] applying started shard [test_index_name][1], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.435+0000 DEBUG [elasticsearch[cached]-pool-27-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][2], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.482+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][2], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.482+0000 DEBUG [elasticsearch[cached]-pool-27-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][2], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.482+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][2], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.498+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] applying started shard [test_index_name][2], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.513+0000 DEBUG [elasticsearch[cached]-pool-27-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][3], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.513+0000 DEBUG [elasticsearch[cached]-pool-27-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][3], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.513+0000 DEBUG [elasticsearch[cached]-pool-27-thread-3] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][4], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.544+0000 DEBUG [elasticsearch[cached]-pool-27-thread-3] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][4], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.513+0000 INFO [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [org.elasticsearch.cluster.metadata] [Hit-Maker] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:30.544+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][3], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.544+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][3], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.560+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][4], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.560+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][4], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.560+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] applying started shard [test_index_name][3], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:30.576+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] sending shard started for [test_index_name][4], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.576+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] received shard started for [test_index_name][4], node[3], [P], s[INITIALIZING], reason [master [Hit-Maker][3][local[3]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:30.576+0000 DEBUG [elasticsearch[Hit-Maker]clusterService#updateTask-pool-36-thread-1] [elasticsearch.cluster.action.shard] [Hit-Maker] applying started shard [test_index_name][4], node[3], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:30.591+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:30.622+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:30.622+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:30.622+0000 INFO [main] [org.elasticsearch.node] [Hit-Maker] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:30.669+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:30.669+0000 INFO [main] [org.elasticsearch.plugins] [Mundi, Rex] loaded []
2011-03-01T14:02:30.716+0000 WARN [main] [org.elasticsearch.indices] [Mundi, Rex] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:31.231+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:31.231+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:31.231+0000 INFO [main] [org.elasticsearch.transport] [Mundi, Rex] bound_address {local[4]}, publish_address {local[4]}
2011-03-01T14:02:31.231+0000 INFO [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [org.elasticsearch.cluster.service] [Mundi, Rex] new_master [Mundi, Rex][4][local[4]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:31.247+0000 INFO [main] [org.elasticsearch.discovery] [Mundi, Rex] elasticsearch/4
2011-03-01T14:02:31.263+0000 INFO [main] [org.elasticsearch.http] [Mundi, Rex] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:31.263+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:31.434+0000 INFO [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [org.elasticsearch.cluster.metadata] [Mundi, Rex] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:31.575+0000 DEBUG [elasticsearch[cached]-pool-40-thread-3] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][0], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.575+0000 INFO [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [org.elasticsearch.cluster.metadata] [Mundi, Rex] [test_index_name] created and added to cluster_state
2011-03-01T14:02:31.575+0000 DEBUG [elasticsearch[cached]-pool-40-thread-3] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][0], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.590+0000 DEBUG [elasticsearch[cached]-pool-40-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][1], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.622+0000 DEBUG [elasticsearch[cached]-pool-40-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][1], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.606+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] applying started shard [test_index_name][0], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.622+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][1], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.622+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][1], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.637+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] applying started shard [test_index_name][1], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.653+0000 DEBUG [elasticsearch[cached]-pool-40-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][2], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.653+0000 DEBUG [elasticsearch[cached]-pool-40-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][2], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.653+0000 DEBUG [elasticsearch[cached]-pool-40-thread-3] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][3], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.653+0000 INFO [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [org.elasticsearch.cluster.metadata] [Mundi, Rex] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:31.684+0000 DEBUG [elasticsearch[cached]-pool-40-thread-3] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][3], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.684+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][2], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.684+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][2], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.700+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][3], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.700+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][3], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.700+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] applying started shard [test_index_name][2], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.700+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][3], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.700+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][3], node[4], [P], s[INITIALIZING], reason [master [Mundi, Rex][4][local[4]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:31.715+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] applying started shard [test_index_name][3], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.731+0000 DEBUG [elasticsearch[cached]-pool-40-thread-3] [elasticsearch.cluster.action.shard] [Mundi, Rex] sending shard started for [test_index_name][4], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.731+0000 DEBUG [elasticsearch[cached]-pool-40-thread-3] [elasticsearch.cluster.action.shard] [Mundi, Rex] received shard started for [test_index_name][4], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:31.762+0000 DEBUG [elasticsearch[Mundi, Rex]clusterService#updateTask-pool-49-thread-1] [elasticsearch.cluster.action.shard] [Mundi, Rex] applying started shard [test_index_name][4], node[4], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:31.793+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:31.809+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:31.809+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:31.825+0000 INFO [main] [org.elasticsearch.node] [Mundi, Rex] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:31.856+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:31.856+0000 INFO [main] [org.elasticsearch.plugins] [Peregrine] loaded []
2011-03-01T14:02:31.981+0000 WARN [main] [org.elasticsearch.indices] [Peregrine] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:32.496+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:32.496+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:32.496+0000 INFO [main] [org.elasticsearch.transport] [Peregrine] bound_address {local[5]}, publish_address {local[5]}
2011-03-01T14:02:32.496+0000 INFO [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [org.elasticsearch.cluster.service] [Peregrine] new_master [Peregrine][5][local[5]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:32.543+0000 INFO [main] [org.elasticsearch.discovery] [Peregrine] elasticsearch/5
2011-03-01T14:02:32.558+0000 INFO [main] [org.elasticsearch.http] [Peregrine] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:32.558+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:32.652+0000 INFO [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [org.elasticsearch.cluster.metadata] [Peregrine] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:32.761+0000 DEBUG [elasticsearch[cached]-pool-53-thread-3] [elasticsearch.cluster.action.shard] [Peregrine] sending shard started for [test_index_name][0], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.761+0000 INFO [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [org.elasticsearch.cluster.metadata] [Peregrine] [test_index_name] created and added to cluster_state
2011-03-01T14:02:32.761+0000 DEBUG [elasticsearch[cached]-pool-53-thread-3] [elasticsearch.cluster.action.shard] [Peregrine] received shard started for [test_index_name][0], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.777+0000 DEBUG [elasticsearch[cached]-pool-53-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] sending shard started for [test_index_name][1], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.808+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] applying started shard [test_index_name][0], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.808+0000 DEBUG [elasticsearch[cached]-pool-53-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] received shard started for [test_index_name][1], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.824+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] sending shard started for [test_index_name][1], node[5], [P], s[INITIALIZING], reason [master [Peregrine][5][local[5]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:32.824+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] received shard started for [test_index_name][1], node[5], [P], s[INITIALIZING], reason [master [Peregrine][5][local[5]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:32.839+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] applying started shard [test_index_name][1], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.855+0000 DEBUG [elasticsearch[cached]-pool-53-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] sending shard started for [test_index_name][2], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.855+0000 DEBUG [elasticsearch[cached]-pool-53-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] received shard started for [test_index_name][2], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:32.871+0000 DEBUG [elasticsearch[cached]-pool-53-thread-3] [elasticsearch.cluster.action.shard] [Peregrine] sending shard started for [test_index_name][3], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.855+0000 INFO [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [org.elasticsearch.cluster.metadata] [Peregrine] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:32.886+0000 DEBUG [elasticsearch[cached]-pool-53-thread-3] [elasticsearch.cluster.action.shard] [Peregrine] received shard started for [test_index_name][3], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.886+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:32.886+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] sending shard started for [test_index_name][2], node[5], [P], s[INITIALIZING], reason [master [Peregrine][5][local[5]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:32.902+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1] [elasticsearch.cluster.action.shard] [Peregrine] received shard started for [test_index_name][2], node[5], [P], s[INITIALIZING], reason [master [Peregrine][5][local[5]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:32.996+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-2] [elasticsearch.cluster.action.shard] [Peregrine] applying started shard [test_index_name][2], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:32.996+0000 DEBUG [elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-2] [elasticsearch.cluster.action.shard] [Peregrine] applying started shard [test_index_name][3], node[5], [P], s[INITIALIZING], reason [after recovery from gateway]
Exception in thread "elasticsearch[Peregrine]clusterService#updateTask-pool-62-thread-1" org.elasticsearch.indices.IndexMissingException: [test_index_name] missing
at org.elasticsearch.indices.InternalIndicesService.indexServiceSafe(InternalIndicesService.java:207)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.applyNewOrUpdatedShards(IndicesClusterStateService.java:336)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:134)
at org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:230)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-03-01T14:02:33.011+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:33.011+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:33.027+0000 INFO [main] [org.elasticsearch.node] [Peregrine] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.onFirstPhaseResult(TransportSearchTypeAction.java:247)
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.start(TransportSearchTypeAction.java:137)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:56)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:48)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:99)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:45)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.client.node.NodeClient.search(NodeClient.java:168)
at org.elasticsearch.client.action.search.SearchRequestBuilder.doExecute(SearchRequestBuilder.java:488)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:56)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:51)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:111)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:33.152+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:33.152+0000 INFO [main] [org.elasticsearch.plugins] [Yrial] loaded []
2011-03-01T14:02:33.198+0000 WARN [main] [org.elasticsearch.indices] [Yrial] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:33.714+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:33.714+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:33.714+0000 INFO [main] [org.elasticsearch.transport] [Yrial] bound_address {local[6]}, publish_address {local[6]}
2011-03-01T14:02:33.714+0000 INFO [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [org.elasticsearch.cluster.service] [Yrial] new_master [Yrial][6][local[6]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:33.729+0000 INFO [main] [org.elasticsearch.discovery] [Yrial] elasticsearch/6
2011-03-01T14:02:33.745+0000 INFO [main] [org.elasticsearch.http] [Yrial] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:33.745+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:33.823+0000 INFO [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [org.elasticsearch.cluster.metadata] [Yrial] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:33.948+0000 DEBUG [elasticsearch[cached]-pool-66-thread-3] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][0], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:33.948+0000 INFO [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [org.elasticsearch.cluster.metadata] [Yrial] [test_index_name] created and added to cluster_state
2011-03-01T14:02:33.948+0000 DEBUG [elasticsearch[cached]-pool-66-thread-3] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][0], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:33.948+0000 DEBUG [elasticsearch[cached]-pool-66-thread-1] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][1], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:33.995+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] applying started shard [test_index_name][0], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:33.995+0000 DEBUG [elasticsearch[cached]-pool-66-thread-1] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][1], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:33.995+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][1], node[6], [P], s[INITIALIZING], reason [master [Yrial][6][local[6]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:33.995+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][1], node[6], [P], s[INITIALIZING], reason [master [Yrial][6][local[6]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:34.010+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] applying started shard [test_index_name][1], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.026+0000 DEBUG [elasticsearch[cached]-pool-66-thread-1] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][2], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.026+0000 DEBUG [elasticsearch[cached]-pool-66-thread-1] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][2], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.042+0000 DEBUG [elasticsearch[cached]-pool-66-thread-3] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][3], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.057+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] applying started shard [test_index_name][2], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.057+0000 DEBUG [elasticsearch[cached]-pool-66-thread-3] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][3], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.057+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][3], node[6], [P], s[INITIALIZING], reason [master [Yrial][6][local[6]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:34.073+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][3], node[6], [P], s[INITIALIZING], reason [master [Yrial][6][local[6]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:34.166+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] applying started shard [test_index_name][3], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.166+0000 INFO [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [org.elasticsearch.cluster.metadata] [Yrial] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:34.182+0000 DEBUG [elasticsearch[cached]-pool-66-thread-3] [elasticsearch.cluster.action.shard] [Yrial] sending shard started for [test_index_name][4], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.182+0000 DEBUG [elasticsearch[cached]-pool-66-thread-3] [elasticsearch.cluster.action.shard] [Yrial] received shard started for [test_index_name][4], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:34.182+0000 DEBUG [elasticsearch[Yrial]clusterService#updateTask-pool-75-thread-1] [elasticsearch.cluster.action.shard] [Yrial] applying started shard [test_index_name][4], node[6], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:34.213+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:34.229+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:34.229+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:34.244+0000 INFO [main] [org.elasticsearch.node] [Yrial] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:34.276+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:34.276+0000 INFO [main] [org.elasticsearch.plugins] [Starhawk] loaded []
2011-03-01T14:02:34.323+0000 WARN [main] [org.elasticsearch.indices] [Starhawk] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:34.838+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:34.838+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:34.838+0000 INFO [main] [org.elasticsearch.transport] [Starhawk] bound_address {local[7]}, publish_address {local[7]}
2011-03-01T14:02:34.838+0000 INFO [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [org.elasticsearch.cluster.service] [Starhawk] new_master [Starhawk][7][local[7]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:34.853+0000 INFO [main] [org.elasticsearch.discovery] [Starhawk] elasticsearch/7
2011-03-01T14:02:34.885+0000 INFO [main] [org.elasticsearch.http] [Starhawk] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:34.885+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:34.963+0000 INFO [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [org.elasticsearch.cluster.metadata] [Starhawk] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:35.166+0000 DEBUG [elasticsearch[cached]-pool-79-thread-3] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][0], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.166+0000 INFO [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [org.elasticsearch.cluster.metadata] [Starhawk] [test_index_name] created and added to cluster_state
2011-03-01T14:02:35.166+0000 DEBUG [elasticsearch[cached]-pool-79-thread-3] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][0], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.166+0000 DEBUG [elasticsearch[cached]-pool-79-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][1], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.181+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] applying started shard [test_index_name][0], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.181+0000 DEBUG [elasticsearch[cached]-pool-79-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][1], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.181+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][1], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.181+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][1], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.197+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] applying started shard [test_index_name][1], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.212+0000 DEBUG [elasticsearch[cached]-pool-79-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][2], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.212+0000 DEBUG [elasticsearch[cached]-pool-79-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][2], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.228+0000 DEBUG [elasticsearch[cached]-pool-79-thread-4] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][3], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.212+0000 INFO [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [org.elasticsearch.cluster.metadata] [Starhawk] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:35.244+0000 DEBUG [elasticsearch[cached]-pool-79-thread-4] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][3], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.244+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][2], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.259+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][2], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.259+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][3], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.259+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][3], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.259+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] applying started shard [test_index_name][2], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.259+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][3], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.275+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][3], node[7], [P], s[INITIALIZING], reason [master [Starhawk][7][local[7]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:35.322+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] applying started shard [test_index_name][3], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.337+0000 DEBUG [elasticsearch[cached]-pool-79-thread-4] [elasticsearch.cluster.action.shard] [Starhawk] sending shard started for [test_index_name][4], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.337+0000 DEBUG [elasticsearch[cached]-pool-79-thread-4] [elasticsearch.cluster.action.shard] [Starhawk] received shard started for [test_index_name][4], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:35.384+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:35.384+0000 DEBUG [elasticsearch[Starhawk]clusterService#updateTask-pool-88-thread-1] [elasticsearch.cluster.action.shard] [Starhawk] applying started shard [test_index_name][4], node[7], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:35.400+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:35.400+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:35.415+0000 INFO [main] [org.elasticsearch.node] [Starhawk] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:35.447+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:35.447+0000 INFO [main] [org.elasticsearch.plugins] [Wing, Colleen] loaded []
2011-03-01T14:02:35.493+0000 WARN [main] [org.elasticsearch.indices] [Wing, Colleen] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:36.009+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:36.009+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:36.009+0000 INFO [main] [org.elasticsearch.transport] [Wing, Colleen] bound_address {local[8]}, publish_address {local[8]}
2011-03-01T14:02:36.009+0000 INFO [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [org.elasticsearch.cluster.service] [Wing, Colleen] new_master [Wing, Colleen][8][local[8]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:36.055+0000 INFO [main] [org.elasticsearch.discovery] [Wing, Colleen] elasticsearch/8
2011-03-01T14:02:36.071+0000 INFO [main] [org.elasticsearch.http] [Wing, Colleen] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:36.071+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:36.149+0000 INFO [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [org.elasticsearch.cluster.metadata] [Wing, Colleen] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:36.336+0000 DEBUG [elasticsearch[cached]-pool-92-thread-3] [elasticsearch.cluster.action.shard] [Wing, Colleen] sending shard started for [test_index_name][0], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.336+0000 INFO [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [org.elasticsearch.cluster.metadata] [Wing, Colleen] [test_index_name] created and added to cluster_state
2011-03-01T14:02:36.336+0000 DEBUG [elasticsearch[cached]-pool-92-thread-3] [elasticsearch.cluster.action.shard] [Wing, Colleen] received shard started for [test_index_name][0], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.352+0000 DEBUG [elasticsearch[cached]-pool-92-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] sending shard started for [test_index_name][1], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.368+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] applying started shard [test_index_name][0], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.368+0000 DEBUG [elasticsearch[cached]-pool-92-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] received shard started for [test_index_name][1], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.368+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] sending shard started for [test_index_name][1], node[8], [P], s[INITIALIZING], reason [master [Wing, Colleen][8][local[8]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:36.383+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] received shard started for [test_index_name][1], node[8], [P], s[INITIALIZING], reason [master [Wing, Colleen][8][local[8]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:36.399+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] applying started shard [test_index_name][1], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.415+0000 DEBUG [elasticsearch[cached]-pool-92-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] sending shard started for [test_index_name][2], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:36.415+0000 DEBUG [elasticsearch[cached]-pool-92-thread-3] [elasticsearch.cluster.action.shard] [Wing, Colleen] sending shard started for [test_index_name][3], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.415+0000 INFO [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [org.elasticsearch.cluster.metadata] [Wing, Colleen] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:36.446+0000 DEBUG [elasticsearch[cached]-pool-92-thread-3] [elasticsearch.cluster.action.shard] [Wing, Colleen] received shard started for [test_index_name][3], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.446+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:36.446+0000 DEBUG [elasticsearch[cached]-pool-92-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] received shard started for [test_index_name][2], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.446+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] sending shard started for [test_index_name][2], node[8], [P], s[INITIALIZING], reason [master [Wing, Colleen][8][local[8]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:36.461+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1] [elasticsearch.cluster.action.shard] [Wing, Colleen] received shard started for [test_index_name][2], node[8], [P], s[INITIALIZING], reason [master [Wing, Colleen][8][local[8]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:36.461+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-2] [elasticsearch.cluster.action.shard] [Wing, Colleen] applying started shard [test_index_name][3], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:36.461+0000 DEBUG [elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-2] [elasticsearch.cluster.action.shard] [Wing, Colleen] applying started shard [test_index_name][2], node[8], [P], s[INITIALIZING], reason [after recovery from gateway]
Exception in thread "elasticsearch[Wing, Colleen]clusterService#updateTask-pool-101-thread-1" org.elasticsearch.indices.IndexMissingException: [test_index_name] missing
at org.elasticsearch.indices.InternalIndicesService.indexServiceSafe(InternalIndicesService.java:207)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.applyNewOrUpdatedShards(IndicesClusterStateService.java:336)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:134)
at org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:230)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-03-01T14:02:36.477+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:36.477+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:36.477+0000 INFO [main] [org.elasticsearch.node] [Wing, Colleen] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.onFirstPhaseResult(TransportSearchTypeAction.java:247)
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.start(TransportSearchTypeAction.java:137)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:56)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:48)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:99)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:45)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.client.node.NodeClient.search(NodeClient.java:168)
at org.elasticsearch.client.action.search.SearchRequestBuilder.doExecute(SearchRequestBuilder.java:488)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:56)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:51)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:111)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:36.602+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:36.602+0000 INFO [main] [org.elasticsearch.plugins] [Lilandra Neramani] loaded []
2011-03-01T14:02:36.649+0000 WARN [main] [org.elasticsearch.indices] [Lilandra Neramani] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:37.164+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:37.164+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:37.164+0000 INFO [main] [org.elasticsearch.transport] [Lilandra Neramani] bound_address {local[9]}, publish_address {local[9]}
2011-03-01T14:02:37.164+0000 INFO [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [org.elasticsearch.cluster.service] [Lilandra Neramani] new_master [Lilandra Neramani][9][local[9]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:37.195+0000 INFO [main] [org.elasticsearch.discovery] [Lilandra Neramani] elasticsearch/9
2011-03-01T14:02:37.211+0000 INFO [main] [org.elasticsearch.http] [Lilandra Neramani] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:37.211+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:37.289+0000 INFO [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [org.elasticsearch.cluster.metadata] [Lilandra Neramani] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:37.492+0000 DEBUG [elasticsearch[cached]-pool-105-thread-3] [elasticsearch.cluster.action.shard] [Lilandra Neramani] sending shard started for [test_index_name][0], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.492+0000 INFO [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [org.elasticsearch.cluster.metadata] [Lilandra Neramani] [test_index_name] created and added to cluster_state
2011-03-01T14:02:37.492+0000 DEBUG [elasticsearch[cached]-pool-105-thread-3] [elasticsearch.cluster.action.shard] [Lilandra Neramani] received shard started for [test_index_name][0], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.492+0000 DEBUG [elasticsearch[cached]-pool-105-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] sending shard started for [test_index_name][1], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.507+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] applying started shard [test_index_name][0], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.507+0000 DEBUG [elasticsearch[cached]-pool-105-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] received shard started for [test_index_name][1], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.507+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] sending shard started for [test_index_name][1], node[9], [P], s[INITIALIZING], reason [master [Lilandra Neramani][9][local[9]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:37.507+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] received shard started for [test_index_name][1], node[9], [P], s[INITIALIZING], reason [master [Lilandra Neramani][9][local[9]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:37.523+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] applying started shard [test_index_name][1], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.539+0000 DEBUG [elasticsearch[cached]-pool-105-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] sending shard started for [test_index_name][2], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:37.554+0000 DEBUG [elasticsearch[cached]-pool-105-thread-3] [elasticsearch.cluster.action.shard] [Lilandra Neramani] sending shard started for [test_index_name][3], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.585+0000 DEBUG [elasticsearch[cached]-pool-105-thread-3] [elasticsearch.cluster.action.shard] [Lilandra Neramani] received shard started for [test_index_name][3], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.539+0000 INFO [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [org.elasticsearch.cluster.metadata] [Lilandra Neramani] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:37.570+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:37.570+0000 DEBUG [elasticsearch[cached]-pool-105-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] received shard started for [test_index_name][2], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.585+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] sending shard started for [test_index_name][2], node[9], [P], s[INITIALIZING], reason [master [Lilandra Neramani][9][local[9]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:37.601+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1] [elasticsearch.cluster.action.shard] [Lilandra Neramani] received shard started for [test_index_name][2], node[9], [P], s[INITIALIZING], reason [master [Lilandra Neramani][9][local[9]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:37.601+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-2] [elasticsearch.cluster.action.shard] [Lilandra Neramani] applying started shard [test_index_name][3], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:37.601+0000 DEBUG [elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-2] [elasticsearch.cluster.action.shard] [Lilandra Neramani] applying started shard [test_index_name][2], node[9], [P], s[INITIALIZING], reason [after recovery from gateway]
Exception in thread "elasticsearch[Lilandra Neramani]clusterService#updateTask-pool-114-thread-1" org.elasticsearch.indices.IndexMissingException: [test_index_name] missing
at org.elasticsearch.indices.InternalIndicesService.indexServiceSafe(InternalIndicesService.java:207)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.applyNewOrUpdatedShards(IndicesClusterStateService.java:336)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:134)
at org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:230)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-03-01T14:02:37.617+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:37.617+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:37.617+0000 INFO [main] [org.elasticsearch.node] [Lilandra Neramani] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.onFirstPhaseResult(TransportSearchTypeAction.java:247)
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.start(TransportSearchTypeAction.java:137)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:56)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:48)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:99)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:45)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.client.node.NodeClient.search(NodeClient.java:168)
at org.elasticsearch.client.action.search.SearchRequestBuilder.doExecute(SearchRequestBuilder.java:488)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:56)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:51)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:111)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:37.726+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:37.726+0000 INFO [main] [org.elasticsearch.plugins] [DuQuesne, Jacques] loaded []
2011-03-01T14:02:37.773+0000 WARN [main] [org.elasticsearch.indices] [DuQuesne, Jacques] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:38.288+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:38.288+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:38.288+0000 INFO [main] [org.elasticsearch.transport] [DuQuesne, Jacques] bound_address {local[10]}, publish_address {local[10]}
2011-03-01T14:02:38.288+0000 INFO [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [org.elasticsearch.cluster.service] [DuQuesne, Jacques] new_master [DuQuesne, Jacques][10][local[10]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:38.335+0000 INFO [main] [org.elasticsearch.discovery] [DuQuesne, Jacques] elasticsearch/10
2011-03-01T14:02:38.350+0000 INFO [main] [org.elasticsearch.http] [DuQuesne, Jacques] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:38.350+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:38.429+0000 INFO [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [org.elasticsearch.cluster.metadata] [DuQuesne, Jacques] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:38.538+0000 DEBUG [elasticsearch[cached]-pool-118-thread-3] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][0], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.538+0000 INFO [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [org.elasticsearch.cluster.metadata] [DuQuesne, Jacques] [test_index_name] created and added to cluster_state
2011-03-01T14:02:38.538+0000 DEBUG [elasticsearch[cached]-pool-118-thread-3] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][0], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.553+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] applying started shard [test_index_name][0], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.553+0000 DEBUG [elasticsearch[cached]-pool-118-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][1], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.553+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][1], node[10], [P], s[INITIALIZING], reason [master [DuQuesne, Jacques][10][local[10]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:38.553+0000 DEBUG [elasticsearch[cached]-pool-118-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][1], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.553+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][1], node[10], [P], s[INITIALIZING], reason [master [DuQuesne, Jacques][10][local[10]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:38.569+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] applying started shard [test_index_name][1], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[cached]-pool-118-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][2], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[cached]-pool-118-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][2], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] applying started shard [test_index_name][2], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[cached]-pool-118-thread-3] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][3], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][3], node[10], [P], s[INITIALIZING], reason [master [DuQuesne, Jacques][10][local[10]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[cached]-pool-118-thread-3] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][3], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.663+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][3], node[10], [P], s[INITIALIZING], reason [master [DuQuesne, Jacques][10][local[10]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:38.678+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] applying started shard [test_index_name][3], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.694+0000 INFO [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [org.elasticsearch.cluster.metadata] [DuQuesne, Jacques] [test_index_name] update_mapping [testIndexType] (dynamic)
Stopping Elastic
2011-03-01T14:02:38.725+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:38.694+0000 DEBUG [elasticsearch[cached]-pool-118-thread-3] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][4], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.725+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] sending shard started for [test_index_name][4], node[10], [P], s[INITIALIZING], reason [master [DuQuesne, Jacques][10][local[10]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:38.725+0000 DEBUG [elasticsearch[cached]-pool-118-thread-3] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][4], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.741+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] received shard started for [test_index_name][4], node[10], [P], s[INITIALIZING], reason [master [DuQuesne, Jacques][10][local[10]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:38.741+0000 DEBUG [elasticsearch[DuQuesne, Jacques]clusterService#updateTask-pool-127-thread-1] [elasticsearch.cluster.action.shard] [DuQuesne, Jacques] applying started shard [test_index_name][4], node[10], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:38.756+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:38.756+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:38.756+0000 INFO [main] [org.elasticsearch.node] [DuQuesne, Jacques] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.failNotEquals(Assert.java:283)
at junit.framework.Assert.assertEquals(Assert.java:64)
at junit.framework.Assert.assertEquals(Assert.java:130)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:117)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:38.881+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:38.881+0000 INFO [main] [org.elasticsearch.plugins] [Shadow King] loaded []
2011-03-01T14:02:38.928+0000 WARN [main] [org.elasticsearch.indices] [Shadow King] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:39.443+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:39.443+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:39.443+0000 INFO [main] [org.elasticsearch.transport] [Shadow King] bound_address {local[11]}, publish_address {local[11]}
2011-03-01T14:02:39.443+0000 INFO [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [org.elasticsearch.cluster.service] [Shadow King] new_master [Shadow King][11][local[11]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:39.459+0000 INFO [main] [org.elasticsearch.discovery] [Shadow King] elasticsearch/11
2011-03-01T14:02:39.475+0000 INFO [main] [org.elasticsearch.http] [Shadow King] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:39.475+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:39.568+0000 INFO [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [org.elasticsearch.cluster.metadata] [Shadow King] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:39.740+0000 DEBUG [elasticsearch[cached]-pool-131-thread-3] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][0], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.740+0000 INFO [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [org.elasticsearch.cluster.metadata] [Shadow King] [test_index_name] created and added to cluster_state
2011-03-01T14:02:39.740+0000 DEBUG [elasticsearch[cached]-pool-131-thread-3] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][0], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.756+0000 DEBUG [elasticsearch[cached]-pool-131-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][1], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.771+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] applying started shard [test_index_name][0], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.787+0000 DEBUG [elasticsearch[cached]-pool-131-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][1], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.787+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][1], node[11], [P], s[INITIALIZING], reason [master [Shadow King][11][local[11]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:39.787+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][1], node[11], [P], s[INITIALIZING], reason [master [Shadow King][11][local[11]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:39.802+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] applying started shard [test_index_name][1], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.818+0000 DEBUG [elasticsearch[cached]-pool-131-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][2], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.818+0000 DEBUG [elasticsearch[cached]-pool-131-thread-3] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][3], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.849+0000 DEBUG [elasticsearch[cached]-pool-131-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][2], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.849+0000 DEBUG [elasticsearch[cached]-pool-131-thread-3] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][3], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.849+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] applying started shard [test_index_name][2], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.865+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][3], node[11], [P], s[INITIALIZING], reason [master [Shadow King][11][local[11]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:39.865+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][3], node[11], [P], s[INITIALIZING], reason [master [Shadow King][11][local[11]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:39.880+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] applying started shard [test_index_name][3], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.880+0000 INFO [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [org.elasticsearch.cluster.metadata] [Shadow King] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:39.896+0000 DEBUG [elasticsearch[cached]-pool-131-thread-3] [elasticsearch.cluster.action.shard] [Shadow King] sending shard started for [test_index_name][4], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:39.927+0000 DEBUG [elasticsearch[cached]-pool-131-thread-3] [elasticsearch.cluster.action.shard] [Shadow King] received shard started for [test_index_name][4], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.927+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:39.927+0000 DEBUG [elasticsearch[Shadow King]clusterService#updateTask-pool-140-thread-1] [elasticsearch.cluster.action.shard] [Shadow King] applying started shard [test_index_name][4], node[11], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:39.959+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:39.959+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:39.959+0000 INFO [main] [org.elasticsearch.node] [Shadow King] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.failNotEquals(Assert.java:283)
at junit.framework.Assert.assertEquals(Assert.java:64)
at junit.framework.Assert.assertEquals(Assert.java:130)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:117)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:40.083+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:40.083+0000 INFO [main] [org.elasticsearch.plugins] [Cybelle] loaded []
2011-03-01T14:02:40.130+0000 WARN [main] [org.elasticsearch.indices] [Cybelle] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:40.645+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:40.645+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:40.645+0000 INFO [main] [org.elasticsearch.transport] [Cybelle] bound_address {local[12]}, publish_address {local[12]}
2011-03-01T14:02:40.645+0000 INFO [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [org.elasticsearch.cluster.service] [Cybelle] new_master [Cybelle][12][local[12]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:40.661+0000 INFO [main] [org.elasticsearch.discovery] [Cybelle] elasticsearch/12
2011-03-01T14:02:40.677+0000 INFO [main] [org.elasticsearch.http] [Cybelle] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:40.677+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:40.755+0000 INFO [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [org.elasticsearch.cluster.metadata] [Cybelle] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:40.926+0000 DEBUG [elasticsearch[cached]-pool-144-thread-3] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][0], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:40.926+0000 DEBUG [elasticsearch[cached]-pool-144-thread-3] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][0], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:40.926+0000 INFO [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [org.elasticsearch.cluster.metadata] [Cybelle] [test_index_name] created and added to cluster_state
2011-03-01T14:02:40.942+0000 DEBUG [elasticsearch[cached]-pool-144-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][1], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:40.973+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] applying started shard [test_index_name][0], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:40.973+0000 DEBUG [elasticsearch[cached]-pool-144-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][1], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:40.973+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][1], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:40.973+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][1], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:40.989+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] applying started shard [test_index_name][1], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.005+0000 DEBUG [elasticsearch[cached]-pool-144-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][2], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.005+0000 DEBUG [elasticsearch[cached]-pool-144-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][2], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.005+0000 DEBUG [elasticsearch[cached]-pool-144-thread-3] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][3], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.005+0000 INFO [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [org.elasticsearch.cluster.metadata] [Cybelle] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:41.036+0000 DEBUG [elasticsearch[cached]-pool-144-thread-3] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][3], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.036+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][2], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:41.051+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][2], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:41.051+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][3], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:41.051+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][3], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:41.067+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] applying started shard [test_index_name][2], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.067+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][3], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:41.067+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][3], node[12], [P], s[INITIALIZING], reason [master [Cybelle][12][local[12]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:41.083+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] applying started shard [test_index_name][3], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.098+0000 DEBUG [elasticsearch[cached]-pool-144-thread-3] [elasticsearch.cluster.action.shard] [Cybelle] sending shard started for [test_index_name][4], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.098+0000 DEBUG [elasticsearch[cached]-pool-144-thread-3] [elasticsearch.cluster.action.shard] [Cybelle] received shard started for [test_index_name][4], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:41.129+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:41.129+0000 DEBUG [elasticsearch[Cybelle]clusterService#updateTask-pool-153-thread-1] [elasticsearch.cluster.action.shard] [Cybelle] applying started shard [test_index_name][4], node[12], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:41.176+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:41.176+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:41.176+0000 INFO [main] [org.elasticsearch.node] [Cybelle] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.failNotEquals(Assert.java:283)
at junit.framework.Assert.assertEquals(Assert.java:64)
at junit.framework.Assert.assertEquals(Assert.java:130)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:117)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:41.286+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:41.286+0000 INFO [main] [org.elasticsearch.plugins] [Malekith the Accursed] loaded []
2011-03-01T14:02:41.332+0000 WARN [main] [org.elasticsearch.indices] [Malekith the Accursed] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:41.848+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:41.848+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:41.848+0000 INFO [main] [org.elasticsearch.transport] [Malekith the Accursed] bound_address {local[13]}, publish_address {local[13]}
2011-03-01T14:02:41.848+0000 INFO [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [org.elasticsearch.cluster.service] [Malekith the Accursed] new_master [Malekith the Accursed][13][local[13]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:41.863+0000 INFO [main] [org.elasticsearch.discovery] [Malekith the Accursed] elasticsearch/13
2011-03-01T14:02:41.879+0000 INFO [main] [org.elasticsearch.http] [Malekith the Accursed] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:41.879+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:41.957+0000 INFO [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [org.elasticsearch.cluster.metadata] [Malekith the Accursed] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:42.144+0000 DEBUG [elasticsearch[cached]-pool-157-thread-3] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][0], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.144+0000 DEBUG [elasticsearch[cached]-pool-157-thread-3] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][0], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.144+0000 INFO [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [org.elasticsearch.cluster.metadata] [Malekith the Accursed] [test_index_name] created and added to cluster_state
2011-03-01T14:02:42.160+0000 DEBUG [elasticsearch[cached]-pool-157-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][1], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.175+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] applying started shard [test_index_name][0], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.175+0000 DEBUG [elasticsearch[cached]-pool-157-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][1], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.175+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][1], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.191+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][1], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.207+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] applying started shard [test_index_name][1], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.207+0000 DEBUG [elasticsearch[cached]-pool-157-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][2], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.222+0000 DEBUG [elasticsearch[cached]-pool-157-thread-3] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][3], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.222+0000 INFO [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [org.elasticsearch.cluster.metadata] [Malekith the Accursed] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:42.253+0000 DEBUG [elasticsearch[cached]-pool-157-thread-3] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][3], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.238+0000 DEBUG [elasticsearch[cached]-pool-157-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][2], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.253+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][2], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.253+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][2], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.253+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][3], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.269+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][3], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.269+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] applying started shard [test_index_name][3], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.269+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][2], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.269+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][2], node[13], [P], s[INITIALIZING], reason [master [Malekith the Accursed][13][local[13]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:42.285+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] applying started shard [test_index_name][2], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.300+0000 DEBUG [elasticsearch[cached]-pool-157-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] sending shard started for [test_index_name][4], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.332+0000 DEBUG [elasticsearch[cached]-pool-157-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] received shard started for [test_index_name][4], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:42.332+0000 DEBUG [elasticsearch[Malekith the Accursed]clusterService#updateTask-pool-166-thread-1] [elasticsearch.cluster.action.shard] [Malekith the Accursed] applying started shard [test_index_name][4], node[13], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:42.363+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:42.378+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:42.378+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:42.378+0000 INFO [main] [org.elasticsearch.node] [Malekith the Accursed] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:42.425+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:42.425+0000 INFO [main] [org.elasticsearch.plugins] [Armadillo] loaded []
2011-03-01T14:02:42.472+0000 WARN [main] [org.elasticsearch.indices] [Armadillo] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:42.987+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:42.987+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:42.987+0000 INFO [main] [org.elasticsearch.transport] [Armadillo] bound_address {local[14]}, publish_address {local[14]}
2011-03-01T14:02:42.987+0000 INFO [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [org.elasticsearch.cluster.service] [Armadillo] new_master [Armadillo][14][local[14]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:43.018+0000 INFO [main] [org.elasticsearch.discovery] [Armadillo] elasticsearch/14
2011-03-01T14:02:43.034+0000 INFO [main] [org.elasticsearch.http] [Armadillo] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:43.034+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:43.112+0000 INFO [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [org.elasticsearch.cluster.metadata] [Armadillo] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:43.284+0000 DEBUG [elasticsearch[cached]-pool-170-thread-3] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][0], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.284+0000 DEBUG [elasticsearch[cached]-pool-170-thread-3] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][0], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.284+0000 INFO [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [org.elasticsearch.cluster.metadata] [Armadillo] [test_index_name] created and added to cluster_state
2011-03-01T14:02:43.299+0000 DEBUG [elasticsearch[cached]-pool-170-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][1], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.331+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] applying started shard [test_index_name][0], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.331+0000 DEBUG [elasticsearch[cached]-pool-170-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][1], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.331+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][1], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.331+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][1], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.346+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] applying started shard [test_index_name][1], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.362+0000 DEBUG [elasticsearch[cached]-pool-170-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][2], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.378+0000 DEBUG [elasticsearch[cached]-pool-170-thread-2] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][3], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.362+0000 INFO [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [org.elasticsearch.cluster.metadata] [Armadillo] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:43.393+0000 DEBUG [elasticsearch[cached]-pool-170-thread-2] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][3], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.393+0000 DEBUG [elasticsearch[cached]-pool-170-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][2], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.409+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][2], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.409+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][2], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.424+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][3], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.424+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][3], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.424+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] applying started shard [test_index_name][3], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.440+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][2], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.440+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][2], node[14], [P], s[INITIALIZING], reason [master [Armadillo][14][local[14]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:43.456+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] applying started shard [test_index_name][2], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.456+0000 DEBUG [elasticsearch[cached]-pool-170-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] sending shard started for [test_index_name][4], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:43.502+0000 DEBUG [elasticsearch[cached]-pool-170-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] received shard started for [test_index_name][4], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.502+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:43.502+0000 DEBUG [elasticsearch[Armadillo]clusterService#updateTask-pool-179-thread-1] [elasticsearch.cluster.action.shard] [Armadillo] applying started shard [test_index_name][4], node[14], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:43.534+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:43.534+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:43.534+0000 INFO [main] [org.elasticsearch.node] [Armadillo] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.failNotEquals(Assert.java:283)
at junit.framework.Assert.assertEquals(Assert.java:64)
at junit.framework.Assert.assertEquals(Assert.java:130)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:117)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:43.659+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:43.659+0000 INFO [main] [org.elasticsearch.plugins] [Darkstar] loaded []
2011-03-01T14:02:43.690+0000 WARN [main] [org.elasticsearch.indices] [Darkstar] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:44.221+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:44.221+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:44.221+0000 INFO [main] [org.elasticsearch.transport] [Darkstar] bound_address {local[15]}, publish_address {local[15]}
2011-03-01T14:02:44.221+0000 INFO [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [org.elasticsearch.cluster.service] [Darkstar] new_master [Darkstar][15][local[15]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:44.221+0000 INFO [main] [org.elasticsearch.discovery] [Darkstar] elasticsearch/15
2011-03-01T14:02:44.236+0000 INFO [main] [org.elasticsearch.http] [Darkstar] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:44.236+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:44.314+0000 INFO [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [org.elasticsearch.cluster.metadata] [Darkstar] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:44.502+0000 DEBUG [elasticsearch[cached]-pool-183-thread-3] [elasticsearch.cluster.action.shard] [Darkstar] sending shard started for [test_index_name][0], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.502+0000 INFO [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [org.elasticsearch.cluster.metadata] [Darkstar] [test_index_name] created and added to cluster_state
2011-03-01T14:02:44.502+0000 DEBUG [elasticsearch[cached]-pool-183-thread-3] [elasticsearch.cluster.action.shard] [Darkstar] received shard started for [test_index_name][0], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.502+0000 DEBUG [elasticsearch[cached]-pool-183-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] sending shard started for [test_index_name][1], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.533+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] applying started shard [test_index_name][0], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.548+0000 DEBUG [elasticsearch[cached]-pool-183-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] received shard started for [test_index_name][1], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.548+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] sending shard started for [test_index_name][1], node[15], [P], s[INITIALIZING], reason [master [Darkstar][15][local[15]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:44.564+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] received shard started for [test_index_name][1], node[15], [P], s[INITIALIZING], reason [master [Darkstar][15][local[15]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:44.580+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] applying started shard [test_index_name][1], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.580+0000 DEBUG [elasticsearch[cached]-pool-183-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] sending shard started for [test_index_name][2], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.580+0000 DEBUG [elasticsearch[cached]-pool-183-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] received shard started for [test_index_name][2], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:44.595+0000 DEBUG [elasticsearch[cached]-pool-183-thread-4] [elasticsearch.cluster.action.shard] [Darkstar] sending shard started for [test_index_name][3], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.595+0000 INFO [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [org.elasticsearch.cluster.metadata] [Darkstar] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:44.627+0000 DEBUG [elasticsearch[cached]-pool-183-thread-4] [elasticsearch.cluster.action.shard] [Darkstar] received shard started for [test_index_name][3], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.627+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:44.627+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] sending shard started for [test_index_name][2], node[15], [P], s[INITIALIZING], reason [master [Darkstar][15][local[15]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:44.642+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1] [elasticsearch.cluster.action.shard] [Darkstar] received shard started for [test_index_name][2], node[15], [P], s[INITIALIZING], reason [master [Darkstar][15][local[15]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:44.642+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-2] [elasticsearch.cluster.action.shard] [Darkstar] applying started shard [test_index_name][2], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:44.642+0000 DEBUG [elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-2] [elasticsearch.cluster.action.shard] [Darkstar] applying started shard [test_index_name][3], node[15], [P], s[INITIALIZING], reason [after recovery from gateway]
Exception in thread "elasticsearch[Darkstar]clusterService#updateTask-pool-192-thread-1" org.elasticsearch.indices.IndexMissingException: [test_index_name] missing
at org.elasticsearch.indices.InternalIndicesService.indexServiceSafe(InternalIndicesService.java:207)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.applyNewOrUpdatedShards(IndicesClusterStateService.java:336)
at org.elasticsearch.indices.cluster.IndicesClusterStateService.clusterChanged(IndicesClusterStateService.java:134)
at org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:230)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-03-01T14:02:44.658+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:44.658+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:44.658+0000 INFO [main] [org.elasticsearch.node] [Darkstar] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.onFirstPhaseResult(TransportSearchTypeAction.java:247)
at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.start(TransportSearchTypeAction.java:137)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:56)
at org.elasticsearch.action.search.type.TransportSearchQueryThenFetchAction.doExecute(TransportSearchQueryThenFetchAction.java:48)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:99)
at org.elasticsearch.action.search.TransportSearchAction.doExecute(TransportSearchAction.java:45)
at org.elasticsearch.action.support.BaseAction.execute(BaseAction.java:61)
at org.elasticsearch.client.node.NodeClient.search(NodeClient.java:168)
at org.elasticsearch.client.action.search.SearchRequestBuilder.doExecute(SearchRequestBuilder.java:488)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:56)
at org.elasticsearch.client.action.support.BaseRequestBuilder.execute(BaseRequestBuilder.java:51)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:111)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:44.767+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:44.767+0000 INFO [main] [org.elasticsearch.plugins] [Hensley Fargus] loaded []
2011-03-01T14:02:44.814+0000 WARN [main] [org.elasticsearch.indices] [Hensley Fargus] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:45.329+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:45.329+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:45.329+0000 INFO [main] [org.elasticsearch.transport] [Hensley Fargus] bound_address {local[16]}, publish_address {local[16]}
2011-03-01T14:02:45.329+0000 INFO [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [org.elasticsearch.cluster.service] [Hensley Fargus] new_master [Hensley Fargus][16][local[16]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:45.376+0000 INFO [main] [org.elasticsearch.discovery] [Hensley Fargus] elasticsearch/16
2011-03-01T14:02:45.392+0000 INFO [main] [org.elasticsearch.http] [Hensley Fargus] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:45.392+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:45.470+0000 INFO [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [org.elasticsearch.cluster.metadata] [Hensley Fargus] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:45.657+0000 DEBUG [elasticsearch[cached]-pool-196-thread-3] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][0], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.657+0000 INFO [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [org.elasticsearch.cluster.metadata] [Hensley Fargus] [test_index_name] created and added to cluster_state
2011-03-01T14:02:45.657+0000 DEBUG [elasticsearch[cached]-pool-196-thread-3] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][0], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.657+0000 DEBUG [elasticsearch[cached]-pool-196-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][1], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.688+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] applying started shard [test_index_name][0], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.688+0000 DEBUG [elasticsearch[cached]-pool-196-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][1], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.704+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][1], node[16], [P], s[INITIALIZING], reason [master [Hensley Fargus][16][local[16]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:45.704+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][1], node[16], [P], s[INITIALIZING], reason [master [Hensley Fargus][16][local[16]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:45.719+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] applying started shard [test_index_name][1], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.735+0000 DEBUG [elasticsearch[cached]-pool-196-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][2], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.735+0000 DEBUG [elasticsearch[cached]-pool-196-thread-3] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][3], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.766+0000 DEBUG [elasticsearch[cached]-pool-196-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][2], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.766+0000 DEBUG [elasticsearch[cached]-pool-196-thread-3] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][3], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.782+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] applying started shard [test_index_name][2], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.782+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][3], node[16], [P], s[INITIALIZING], reason [master [Hensley Fargus][16][local[16]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:45.782+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][3], node[16], [P], s[INITIALIZING], reason [master [Hensley Fargus][16][local[16]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:45.797+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] applying started shard [test_index_name][3], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.797+0000 INFO [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [org.elasticsearch.cluster.metadata] [Hensley Fargus] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:45.813+0000 DEBUG [elasticsearch[cached]-pool-196-thread-3] [elasticsearch.cluster.action.shard] [Hensley Fargus] sending shard started for [test_index_name][4], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.844+0000 DEBUG [elasticsearch[cached]-pool-196-thread-3] [elasticsearch.cluster.action.shard] [Hensley Fargus] received shard started for [test_index_name][4], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:45.860+0000 DEBUG [elasticsearch[Hensley Fargus]clusterService#updateTask-pool-205-thread-1] [elasticsearch.cluster.action.shard] [Hensley Fargus] applying started shard [test_index_name][4], node[16], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:45.875+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:45.907+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:45.907+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:45.907+0000 INFO [main] [org.elasticsearch.node] [Hensley Fargus] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:45.954+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:45.954+0000 INFO [main] [org.elasticsearch.plugins] [Jaspers, James] loaded []
2011-03-01T14:02:46.032+0000 WARN [main] [org.elasticsearch.indices] [Jaspers, James] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:46.547+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:46.547+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:46.547+0000 INFO [main] [org.elasticsearch.transport] [Jaspers, James] bound_address {local[17]}, publish_address {local[17]}
2011-03-01T14:02:46.547+0000 INFO [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [org.elasticsearch.cluster.service] [Jaspers, James] new_master [Jaspers, James][17][local[17]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:46.578+0000 INFO [main] [org.elasticsearch.discovery] [Jaspers, James] elasticsearch/17
2011-03-01T14:02:46.594+0000 INFO [main] [org.elasticsearch.http] [Jaspers, James] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:46.594+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:46.672+0000 INFO [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [org.elasticsearch.cluster.metadata] [Jaspers, James] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:46.859+0000 DEBUG [elasticsearch[cached]-pool-209-thread-3] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][0], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.859+0000 DEBUG [elasticsearch[cached]-pool-209-thread-3] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][0], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.859+0000 INFO [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [org.elasticsearch.cluster.metadata] [Jaspers, James] [test_index_name] created and added to cluster_state
2011-03-01T14:02:46.875+0000 DEBUG [elasticsearch[cached]-pool-209-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][1], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.890+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] applying started shard [test_index_name][0], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.890+0000 DEBUG [elasticsearch[cached]-pool-209-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][1], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.890+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][1], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.890+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][1], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.906+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] applying started shard [test_index_name][1], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.921+0000 DEBUG [elasticsearch[cached]-pool-209-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][2], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.937+0000 DEBUG [elasticsearch[cached]-pool-209-thread-3] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][3], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.953+0000 DEBUG [elasticsearch[cached]-pool-209-thread-3] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][3], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.921+0000 INFO [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [org.elasticsearch.cluster.metadata] [Jaspers, James] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:46.953+0000 DEBUG [elasticsearch[cached]-pool-209-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][2], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.953+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][2], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.968+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][2], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.968+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][3], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.968+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][3], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.968+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] applying started shard [test_index_name][3], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:46.968+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][2], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:46.984+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][2], node[17], [P], s[INITIALIZING], reason [master [Jaspers, James][17][local[17]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:47.000+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] applying started shard [test_index_name][2], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:47.000+0000 DEBUG [elasticsearch[cached]-pool-209-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] sending shard started for [test_index_name][4], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:47.031+0000 DEBUG [elasticsearch[cached]-pool-209-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] received shard started for [test_index_name][4], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:47.031+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:47.046+0000 DEBUG [elasticsearch[Jaspers, James]clusterService#updateTask-pool-218-thread-1] [elasticsearch.cluster.action.shard] [Jaspers, James] applying started shard [test_index_name][4], node[17], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:47.078+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:47.078+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:47.078+0000 INFO [main] [org.elasticsearch.node] [Jaspers, James] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>
at junit.framework.Assert.fail(Assert.java:47)
at junit.framework.Assert.failNotEquals(Assert.java:283)
at junit.framework.Assert.assertEquals(Assert.java:64)
at junit.framework.Assert.assertEquals(Assert.java:130)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.assertIndexHasEntryFor(SearchingAfterRefreshTest.java:117)
at acceptance.giraffe.indexing.SearchingAfterRefreshTest.doSomeIndexing(SearchingAfterRefreshTest.java:106)
at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:25)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Starting Elastic
2011-03-01T14:02:47.187+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:47.187+0000 INFO [main] [org.elasticsearch.plugins] [Eon] loaded []
2011-03-01T14:02:47.234+0000 WARN [main] [org.elasticsearch.indices] [Eon] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:47.749+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:47.749+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:47.749+0000 INFO [main] [org.elasticsearch.transport] [Eon] bound_address {local[18]}, publish_address {local[18]}
2011-03-01T14:02:47.749+0000 INFO [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [org.elasticsearch.cluster.service] [Eon] new_master [Eon][18][local[18]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:47.765+0000 INFO [main] [org.elasticsearch.discovery] [Eon] elasticsearch/18
2011-03-01T14:02:47.780+0000 INFO [main] [org.elasticsearch.http] [Eon] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:47.780+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:47.858+0000 INFO [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [org.elasticsearch.cluster.metadata] [Eon] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:48.046+0000 DEBUG [elasticsearch[cached]-pool-222-thread-3] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][0], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.046+0000 INFO [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [org.elasticsearch.cluster.metadata] [Eon] [test_index_name] created and added to cluster_state
2011-03-01T14:02:48.061+0000 DEBUG [elasticsearch[cached]-pool-222-thread-3] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][0], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.061+0000 DEBUG [elasticsearch[cached]-pool-222-thread-1] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][1], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.077+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] applying started shard [test_index_name][0], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.077+0000 DEBUG [elasticsearch[cached]-pool-222-thread-1] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][1], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.077+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][1], node[18], [P], s[INITIALIZING], reason [master [Eon][18][local[18]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:48.092+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][1], node[18], [P], s[INITIALIZING], reason [master [Eon][18][local[18]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:48.092+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] applying started shard [test_index_name][1], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.108+0000 DEBUG [elasticsearch[cached]-pool-222-thread-1] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][2], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.108+0000 DEBUG [elasticsearch[cached]-pool-222-thread-1] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][2], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.124+0000 DEBUG [elasticsearch[cached]-pool-222-thread-3] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][3], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.155+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] applying started shard [test_index_name][2], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.155+0000 DEBUG [elasticsearch[cached]-pool-222-thread-3] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][3], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.155+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][3], node[18], [P], s[INITIALIZING], reason [master [Eon][18][local[18]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:48.170+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][3], node[18], [P], s[INITIALIZING], reason [master [Eon][18][local[18]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:48.170+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] applying started shard [test_index_name][3], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.186+0000 DEBUG [elasticsearch[cached]-pool-222-thread-3] [elasticsearch.cluster.action.shard] [Eon] sending shard started for [test_index_name][4], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.186+0000 DEBUG [elasticsearch[cached]-pool-222-thread-3] [elasticsearch.cluster.action.shard] [Eon] received shard started for [test_index_name][4], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.217+0000 DEBUG [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [elasticsearch.cluster.action.shard] [Eon] applying started shard [test_index_name][4], node[18], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:48.233+0000 INFO [elasticsearch[Eon]clusterService#updateTask-pool-231-thread-1] [org.elasticsearch.cluster.metadata] [Eon] [test_index_name] update_mapping [testIndexType] (dynamic)
Stopping Elastic
2011-03-01T14:02:48.249+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:48.280+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:48.280+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:48.280+0000 INFO [main] [org.elasticsearch.node] [Eon] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:48.327+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:48.327+0000 INFO [main] [org.elasticsearch.plugins] [Piper] loaded []
2011-03-01T14:02:48.358+0000 WARN [main] [org.elasticsearch.indices] [Piper] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:48.873+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:48.873+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:48.873+0000 INFO [main] [org.elasticsearch.transport] [Piper] bound_address {local[19]}, publish_address {local[19]}
2011-03-01T14:02:48.889+0000 INFO [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [org.elasticsearch.cluster.service] [Piper] new_master [Piper][19][local[19]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:48.889+0000 INFO [main] [org.elasticsearch.discovery] [Piper] elasticsearch/19
2011-03-01T14:02:48.904+0000 INFO [main] [org.elasticsearch.http] [Piper] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:48.904+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:48.998+0000 INFO [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [org.elasticsearch.cluster.metadata] [Piper] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:49.170+0000 DEBUG [elasticsearch[cached]-pool-235-thread-3] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][0], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.170+0000 INFO [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [org.elasticsearch.cluster.metadata] [Piper] [test_index_name] created and added to cluster_state
2011-03-01T14:02:49.170+0000 DEBUG [elasticsearch[cached]-pool-235-thread-3] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][0], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.185+0000 DEBUG [elasticsearch[cached]-pool-235-thread-1] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][1], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.216+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] applying started shard [test_index_name][0], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.216+0000 DEBUG [elasticsearch[cached]-pool-235-thread-1] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][1], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.216+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][1], node[19], [P], s[INITIALIZING], reason [master [Piper][19][local[19]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:49.232+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][1], node[19], [P], s[INITIALIZING], reason [master [Piper][19][local[19]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:49.248+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] applying started shard [test_index_name][1], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.263+0000 DEBUG [elasticsearch[cached]-pool-235-thread-1] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][2], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.263+0000 DEBUG [elasticsearch[cached]-pool-235-thread-1] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][2], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.263+0000 DEBUG [elasticsearch[cached]-pool-235-thread-3] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][3], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.295+0000 DEBUG [elasticsearch[cached]-pool-235-thread-3] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][3], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.295+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] applying started shard [test_index_name][2], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.295+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][3], node[19], [P], s[INITIALIZING], reason [master [Piper][19][local[19]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:49.295+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][3], node[19], [P], s[INITIALIZING], reason [master [Piper][19][local[19]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:49.310+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] applying started shard [test_index_name][3], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.310+0000 INFO [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [org.elasticsearch.cluster.metadata] [Piper] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:49.326+0000 DEBUG [elasticsearch[cached]-pool-235-thread-3] [elasticsearch.cluster.action.shard] [Piper] sending shard started for [test_index_name][4], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.357+0000 DEBUG [elasticsearch[cached]-pool-235-thread-3] [elasticsearch.cluster.action.shard] [Piper] received shard started for [test_index_name][4], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:49.373+0000 DEBUG [elasticsearch[Piper]clusterService#updateTask-pool-244-thread-1] [elasticsearch.cluster.action.shard] [Piper] applying started shard [test_index_name][4], node[19], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:49.388+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:49.404+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:49.404+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:49.419+0000 INFO [main] [org.elasticsearch.node] [Piper] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
Starting Elastic
2011-03-01T14:02:49.451+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: initializing ...
2011-03-01T14:02:49.451+0000 INFO [main] [org.elasticsearch.plugins] [Echo] loaded []
2011-03-01T14:02:49.497+0000 WARN [main] [org.elasticsearch.indices] [Echo] lucene default FieldCache is used, not enabling eager reader based cache eviction
2011-03-01T14:02:50.013+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: initialized
2011-03-01T14:02:50.013+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: starting ...
2011-03-01T14:02:50.013+0000 INFO [main] [org.elasticsearch.transport] [Echo] bound_address {local[20]}, publish_address {local[20]}
2011-03-01T14:02:50.013+0000 INFO [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [org.elasticsearch.cluster.service] [Echo] new_master [Echo][20][local[20]]{local=true}, reason: local-disco-initial_connect(master)
2011-03-01T14:02:50.044+0000 INFO [main] [org.elasticsearch.discovery] [Echo] elasticsearch/20
2011-03-01T14:02:50.060+0000 INFO [main] [org.elasticsearch.http] [Echo] bound_address {inet[/0.0.0.0:9200]}, publish_address {inet[/166.15.99.96:9200]}
2011-03-01T14:02:50.060+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: started
Started Elastic
2011-03-01T14:02:50.138+0000 INFO [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [org.elasticsearch.cluster.metadata] [Echo] [test_index_name] creating index, cause [auto(bulk api)], shards [5]/[1], mappings []
2011-03-01T14:02:50.325+0000 DEBUG [elasticsearch[cached]-pool-248-thread-3] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][0], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.325+0000 INFO [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [org.elasticsearch.cluster.metadata] [Echo] [test_index_name] created and added to cluster_state
2011-03-01T14:02:50.325+0000 DEBUG [elasticsearch[cached]-pool-248-thread-3] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][0], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.341+0000 DEBUG [elasticsearch[cached]-pool-248-thread-1] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][1], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.356+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] applying started shard [test_index_name][0], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.356+0000 DEBUG [elasticsearch[cached]-pool-248-thread-1] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][1], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.356+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][1], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.356+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][1], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.372+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] applying started shard [test_index_name][1], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.387+0000 DEBUG [elasticsearch[cached]-pool-248-thread-1] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][2], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.387+0000 DEBUG [elasticsearch[cached]-pool-248-thread-1] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][2], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.387+0000 DEBUG [elasticsearch[cached]-pool-248-thread-3] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][3], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.387+0000 INFO [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [org.elasticsearch.cluster.metadata] [Echo] [test_index_name] update_mapping [testIndexType] (dynamic)
2011-03-01T14:02:50.419+0000 DEBUG [elasticsearch[cached]-pool-248-thread-3] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][3], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.434+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][2], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.434+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][2], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.434+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][3], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.434+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][3], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.450+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] applying started shard [test_index_name][2], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.450+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][3], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.450+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][3], node[20], [P], s[INITIALIZING], reason [master [Echo][20][local[20]]{local=true} marked shard as initializing, but shard already started, mark shard as started]
2011-03-01T14:02:50.450+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] applying started shard [test_index_name][3], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.465+0000 DEBUG [elasticsearch[cached]-pool-248-thread-3] [elasticsearch.cluster.action.shard] [Echo] sending shard started for [test_index_name][4], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.465+0000 DEBUG [elasticsearch[cached]-pool-248-thread-3] [elasticsearch.cluster.action.shard] [Echo] received shard started for [test_index_name][4], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
2011-03-01T14:02:50.497+0000 DEBUG [elasticsearch[Echo]clusterService#updateTask-pool-257-thread-1] [elasticsearch.cluster.action.shard] [Echo] applying started shard [test_index_name][4], node[20], [P], s[INITIALIZING], reason [after recovery from gateway]
Stopping Elastic
2011-03-01T14:02:50.528+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: stopping ...
2011-03-01T14:02:50.544+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: stopped
2011-03-01T14:02:50.544+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: closing ...
2011-03-01T14:02:50.559+0000 INFO [main] [org.elasticsearch.node] [Echo] {elasticsearch/0.15.0}[4436]: closed
Stopped Elastic
java.lang.AssertionError: 20 iterations, 10 failures: {1=org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}, 4=org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}, 7=org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}, 8=org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}, 9=junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>, 10=junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>, 11=junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>, 13=junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>, 14=org.elasticsearch.action.search.SearchPhaseExecutionException: Failed to execute phase [query], total failure; shardFailures {[_na_][test_index_name][2]: No active shards}{[_na_][test_index_name][3]: No active shards}, 16=junit.framework.AssertionFailedError: should return exactly one hit expected:<1> but was:<0>}
at acceptance.giraffe.indexing.Repeat$1.evaluate(Repeat.java:33)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:97)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:196)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Process finished with exit code -1
package acceptance.giraffe.indexing;
import java.util.SortedMap;
import java.util.TreeMap;
import org.junit.rules.MethodRule;
import org.junit.runners.model.FrameworkMethod;
import org.junit.runners.model.Statement;
public class Repeat implements MethodRule {
private final int iterations;
private final SortedMap<Integer, Throwable> failures = new TreeMap<Integer, Throwable>();
public Repeat(int iterations) {
this.iterations = iterations;
}
@Override
public Statement apply(final Statement base, FrameworkMethod method, Object target) {
return new Statement() {
@Override
public void evaluate() throws Throwable {
for (int i = 0; i < iterations; i++) {
try {
base.evaluate();
} catch (Throwable e) {
e.printStackTrace();
failures.put(i, e);
}
}
if (!failures.isEmpty()) {
throw new AssertionError(iterations + " iterations, " + failures.size() + " failures: " + failures);
}
}
};
}
}
package acceptance.giraffe.indexing;
import java.io.File;
import java.util.HashMap;
import java.util.Map;
import org.apache.log4j.Logger;
import org.elasticsearch.action.admin.indices.create.CreateIndexRequest;
import org.elasticsearch.action.admin.indices.create.CreateIndexResponse;
import org.elasticsearch.action.search.SearchResponse;
import org.elasticsearch.action.search.SearchType;
import org.elasticsearch.client.Client;
import org.elasticsearch.client.action.bulk.BulkRequestBuilder;
import org.elasticsearch.client.action.index.IndexRequestBuilder;
import org.elasticsearch.cluster.metadata.IndexMetaData;
import org.elasticsearch.common.collect.ImmutableMap;
import org.elasticsearch.index.query.xcontent.MatchAllQueryBuilder;
import org.elasticsearch.node.Node;
import org.elasticsearch.search.SearchHit;
import org.elasticsearch.search.SearchHits;
import org.junit.After;
import org.junit.Before;
import org.junit.Rule;
import org.junit.Test;
import static junit.framework.Assert.assertEquals;
import static org.apache.commons.io.FileUtils.*;
import static org.elasticsearch.client.Requests.*;
import static org.elasticsearch.common.settings.ImmutableSettings.*;
import static org.elasticsearch.common.unit.TimeValue.*;
import static org.elasticsearch.index.query.xcontent.QueryBuilders.fieldQuery;
import static org.elasticsearch.node.NodeBuilder.*;
import giraffe.indexing.DocumentType;
import giraffe.testing.IntentionallyNotInSuite;
@IntentionallyNotInSuite
public class SearchingAfterRefreshTest {
private final File indexerDataDir = new File("indexer-tests");
private Node node;
private Client client;
public @Rule Repeat repeat = new Repeat(20);
@Before
public void start() {
deleteQuietly(indexerDataDir);
startElastic();
}
private void startElastic() {
System.out.println("Starting Elastic");
node = nodeBuilder()
.local(true)
.settings(settingsBuilder()
.put("path.data", indexerDataDir.getAbsolutePath())
.put("http.port", 9200))
.node();
node.start();
client = node.client();
client.admin()
.cluster()
.health(
clusterHealthRequest()
.waitForYellowStatus()
.timeout(timeValueSeconds(60))
)
.actionGet();
System.out.println("Started Elastic");
}
@Test
public void doSomeIndexing() throws InterruptedException {
String indexName = "test_index_name";
HashMap<String, Object> doc = new HashMap<String, Object>();
doc.put("name", "mooky");
doc.put("ccy", "usd");
doc.put("underlying", "ftse");
HashMap<String, Object> doc2 = new HashMap<String, Object>();
doc2.put("name", "foobar");
doc2.put("ccy", "usd");
doc2.put("underlying", "ftse");
Map<String, Object>[] datas = new Map[]{doc, doc2};
BulkRequestBuilder bulkRequestBuilder = client.prepareBulk();
for (Map<String, Object> data : datas) {
IndexRequestBuilder builder = client.prepareIndex(indexName, "testIndexType").setSource(data);
bulkRequestBuilder.add(builder);
}
bulkRequestBuilder.execute().actionGet();
client
.admin()
.indices()
.refresh(
refreshRequest(indexName)
)
.actionGet();
// Thread.sleep(250);
assertIndexHasEntryFor(indexName, "name", "mooky");
assertIndexHasEntryFor(indexName, "name", "foobar");
}
private void assertIndexHasEntryFor(String indexName, String field, String query) {
SearchResponse searchResponse = client.prepareSearch(indexName)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.setQuery(fieldQuery(field, query))
.setFrom(0).setSize(6000).setExplain(true)
.execute()
.actionGet();
assertEquals("should return exactly one hit ", 1, searchResponse.getHits().getTotalHits());
}
@After
public void stop() {
stopElastic();
deleteQuietly(indexerDataDir);
}
private void stopElastic() {
System.out.println("Stopping Elastic");
try {
//happens when start fails
if (client != null) {
client.close();
}
} finally {
//happens when start fails
if (node != null) {
node.close();
}
}
System.out.println("Stopped Elastic");
}
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment