Skip to content

Instantly share code, notes, and snippets.

@nellicus

nellicus/debug logs

Created July 23, 2015 14:27
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save nellicus/c779113544c5f44f6d18 to your computer and use it in GitHub Desktop.
Save nellicus/c779113544c5f44f6d18 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
debug logs
$ cat start-es170.sh
#!/bin/bash
/opt/elk/TEST/es170-a/elasticsearch-1.7.0/bin/elasticsearch -d -Des.logger.level=DEBUG
/opt/elk/TEST/es170-b/elasticsearch-1.7.0/bin/elasticsearch -d -Des.logger.level=DEBUG
abonuccelli@w530 /opt/elk/TEST $ ./start-es170.sh
abonuccelli@w530 /opt/elk/TEST $ find es170-? -type f -name test.log | xargs tail -F
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
mtu [65536] multicast [false] ptp [false] loopback [true] up [true] virtual [false]
[2015-07-23 15:47:45,491][DEBUG][monitor.fs ] [J. Jonah Jameson] Using probe [org.elasticsearch.monitor.fs.SigarFsProbe@5b8b3c4a] with refresh_interval [1s]
[2015-07-23 15:47:45,496][DEBUG][common.netty ] using gathering [true]
[2015-07-23 15:47:45,517][DEBUG][discovery.zen.elect ] [J. Jonah Jameson] using minimum_master_nodes [-1]
[2015-07-23 15:47:45,518][DEBUG][discovery.zen.ping.multicast] [J. Jonah Jameson] using group [224.2.2.4], with port [54328], ttl [3], and address [null]
[2015-07-23 15:47:45,521][DEBUG][discovery.zen.ping.unicast] [J. Jonah Jameson] using initial hosts [], with concurrent_connects [10]
[2015-07-23 15:47:45,521][DEBUG][discovery.zen ] [J. Jonah Jameson] using ping.timeout [3s], join.timeout [1m], master_election.filter_client [true], master_election.filter_data [false]
[2015-07-23 15:47:45,522][DEBUG][discovery.zen.fd ] [J. Jonah Jameson] [master] uses ping_interval [1s], ping_timeout [30s], ping_retries [3]
[2015-07-23 15:47:45,524][DEBUG][discovery.zen.fd ] [J. Jonah Jameson] [node ] uses ping_interval [1s], ping_timeout [30s], ping_retries [3]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
mtu [1500] multicast [true] ptp [false] loopback [false] up [true] virtual [false]
eth0 display_name [eth0]
address [/fe80:0:0:0:3e97:eff:fe28:d4d0%2] [/192.168.1.105]
mtu [1500] multicast [true] ptp [false] loopback [false] up [true] virtual [false]
lo display_name [lo]
address [/0:0:0:0:0:0:0:1%1] [/127.0.0.1]
mtu [65536] multicast [false] ptp [false] loopback [true] up [true] virtual [false]
[2015-07-23 15:47:45,543][DEBUG][monitor.fs ] [Super Rabbit] Using probe [org.elasticsearch.monitor.fs.SigarFsProbe@19a743eb] with refresh_interval [1s]
[2015-07-23 15:47:45,549][DEBUG][common.netty ] using gathering [true]
[2015-07-23 15:47:45,570][DEBUG][discovery.zen.elect ] [Super Rabbit] using minimum_master_nodes [-1]
[2015-07-23 15:47:45,571][DEBUG][discovery.zen.ping.multicast] [Super Rabbit] using group [224.2.2.4], with port [54328], ttl [3], and address [null]
[2015-07-23 15:47:45,575][DEBUG][discovery.zen.ping.unicast] [Super Rabbit] using initial hosts [], with concurrent_connects [10]
[2015-07-23 15:47:45,575][DEBUG][discovery.zen ] [Super Rabbit] using ping.timeout [3s], join.timeout [1m], master_election.filter_client [true], master_election.filter_data [false]
[2015-07-23 15:47:45,576][DEBUG][discovery.zen.fd ] [Super Rabbit] [master] uses ping_interval [1s], ping_timeout [30s], ping_retries [3]
[2015-07-23 15:47:45,578][DEBUG][discovery.zen.fd ] [Super Rabbit] [node ] uses ping_interval [1s], ping_timeout [30s], ping_retries [3]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,753][DEBUG][script ] [J. Jonah Jameson] using script cache with max_size [100], expire [null]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,809][DEBUG][script ] [Super Rabbit] using script cache with max_size [100], expire [null]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,811][DEBUG][cluster.routing.allocation.decider] [J. Jonah Jameson] using node_concurrent_recoveries [2], node_initial_primaries_recoveries [4]
[2015-07-23 15:47:45,812][DEBUG][cluster.routing.allocation.decider] [J. Jonah Jameson] using [cluster.routing.allocation.allow_rebalance] with [indices_all_active]
[2015-07-23 15:47:45,812][DEBUG][cluster.routing.allocation.decider] [J. Jonah Jameson] using [cluster_concurrent_rebalance] with [2]
[2015-07-23 15:47:45,813][DEBUG][indices.recovery ] [J. Jonah Jameson] using max_bytes_per_sec[40mb], concurrent_streams [3], file_chunk_size [512kb], translog_size [512kb], translog_ops [1000], and compress [true]
[2015-07-23 15:47:45,835][DEBUG][gateway.local ] [J. Jonah Jameson] using initial_shards [quorum]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,871][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] using node_concurrent_recoveries [2], node_initial_primaries_recoveries [4]
[2015-07-23 15:47:45,871][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] using [cluster.routing.allocation.allow_rebalance] with [indices_all_active]
[2015-07-23 15:47:45,872][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] using [cluster_concurrent_rebalance] with [2]
[2015-07-23 15:47:45,873][DEBUG][indices.recovery ] [Super Rabbit] using max_bytes_per_sec[40mb], concurrent_streams [3], file_chunk_size [512kb], translog_size [512kb], translog_ops [1000], and compress [true]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,885][DEBUG][http.netty ] [J. Jonah Jameson] using max_chunk_size[8kb], max_header_size[8kb], max_initial_line_length[4kb], max_content_length[100mb], receive_predictor[512kb->512kb], pipelining[true], pipelining_max_events[10000]
[2015-07-23 15:47:45,893][DEBUG][indices.store ] [J. Jonah Jameson] using indices.store.throttle.type [MERGE], with index.store.throttle.max_bytes_per_sec [20mb]
[2015-07-23 15:47:45,894][DEBUG][indices.memory ] [J. Jonah Jameson] using index_buffer_size [98.9mb], with min_shard_index_buffer_size [4mb], max_shard_index_buffer_size [512mb], shard_inactive_time [5m]
[2015-07-23 15:47:45,894][DEBUG][indices.cache.filter ] [J. Jonah Jameson] using [node] weighted filter cache with size [10%], actual_size [98.9mb], expire [null], clean_interval [1m]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,894][DEBUG][gateway.local ] [Super Rabbit] using initial_shards [quorum]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,895][DEBUG][indices.fielddata.cache ] [J. Jonah Jameson] using size [-1] [-1b], expire [null]
[2015-07-23 15:47:45,907][DEBUG][gateway.local.state.shards] [J. Jonah Jameson] took 0s to load started shards state
[2015-07-23 15:47:45,909][DEBUG][gateway.local.state.meta ] [J. Jonah Jameson] using gateway.local.auto_import_dangled [YES], gateway.local.delete_timeout [30s], with gateway.local.dangling_timeout [2h]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,944][DEBUG][http.netty ] [Super Rabbit] using max_chunk_size[8kb], max_header_size[8kb], max_initial_line_length[4kb], max_content_length[100mb], receive_predictor[512kb->512kb], pipelining[true], pipelining_max_events[10000]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,949][DEBUG][gateway.local.state.meta ] [J. Jonah Jameson] took 38ms to load state
[2015-07-23 15:47:45,952][DEBUG][bulk.udp ] [J. Jonah Jameson] using enabled [false], host [null], port [9700-9800], bulk_actions [1000], bulk_size [5mb], flush_interval [5s], concurrent_requests [4]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,954][DEBUG][indices.store ] [Super Rabbit] using indices.store.throttle.type [MERGE], with index.store.throttle.max_bytes_per_sec [20mb]
[2015-07-23 15:47:45,955][DEBUG][indices.memory ] [Super Rabbit] using index_buffer_size [98.9mb], with min_shard_index_buffer_size [4mb], max_shard_index_buffer_size [512mb], shard_inactive_time [5m]
[2015-07-23 15:47:45,956][DEBUG][indices.cache.filter ] [Super Rabbit] using [node] weighted filter cache with size [10%], actual_size [98.9mb], expire [null], clean_interval [1m]
[2015-07-23 15:47:45,956][DEBUG][indices.fielddata.cache ] [Super Rabbit] using size [-1] [-1b], expire [null]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,964][INFO ][node ] [J. Jonah Jameson] initialized
[2015-07-23 15:47:45,964][INFO ][node ] [J. Jonah Jameson] starting ...
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,969][DEBUG][gateway.local.state.shards] [Super Rabbit] took 1ms to load started shards state
[2015-07-23 15:47:45,971][DEBUG][gateway.local.state.meta ] [Super Rabbit] using gateway.local.auto_import_dangled [YES], gateway.local.delete_timeout [30s], with gateway.local.dangling_timeout [2h]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:45,974][DEBUG][netty.channel.socket.nio.SelectorUtil] Using select timeout of 500
[2015-07-23 15:47:45,974][DEBUG][netty.channel.socket.nio.SelectorUtil] Epoll-bug workaround enabled = false
[2015-07-23 15:47:45,990][DEBUG][transport.netty ] [J. Jonah Jameson] using profile[default], worker_count[16], port[9300-9400], bind_host[null], publish_host[null], compress[false], connect_timeout[30s], connections_per_node[2/3/6/1/1], receive_predictor[512kb->512kb]
[2015-07-23 15:47:46,012][DEBUG][transport.netty ] [J. Jonah Jameson] Bound profile [default] to address [/0:0:0:0:0:0:0:0:9300]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,012][DEBUG][gateway.local.state.meta ] [Super Rabbit] took 40ms to load state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,014][INFO ][transport ] [J. Jonah Jameson] bound_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish_address {inet[/192.168.1.105:9300]}
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,015][DEBUG][bulk.udp ] [Super Rabbit] using enabled [false], host [null], port [9700-9800], bulk_actions [1000], bulk_size [5mb], flush_interval [5s], concurrent_requests [4]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,026][INFO ][discovery ] [J. Jonah Jameson] test/Uc0hQoZLRJGjp-qyjNkQKg
[2015-07-23 15:47:46,026][DEBUG][cluster.service ] [J. Jonah Jameson] processing [initial_join]: execute
[2015-07-23 15:47:46,027][DEBUG][cluster.service ] [J. Jonah Jameson] processing [initial_join]: took 0s no change in cluster_state
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,027][INFO ][node ] [Super Rabbit] initialized
[2015-07-23 15:47:46,027][INFO ][node ] [Super Rabbit] starting ...
[2015-07-23 15:47:46,038][DEBUG][netty.channel.socket.nio.SelectorUtil] Using select timeout of 500
[2015-07-23 15:47:46,038][DEBUG][netty.channel.socket.nio.SelectorUtil] Epoll-bug workaround enabled = false
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,048][DEBUG][transport.netty ] [J. Jonah Jameson] connected to node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,054][DEBUG][transport.netty ] [Super Rabbit] using profile[default], worker_count[16], port[9300-9400], bind_host[null], publish_host[null], compress[false], connect_timeout[30s], connections_per_node[2/3/6/1/1], receive_predictor[512kb->512kb]
[2015-07-23 15:47:46,076][DEBUG][transport.netty ] [Super Rabbit] Bound profile [default] to address [/0:0:0:0:0:0:0:0:9301]
[2015-07-23 15:47:46,078][INFO ][transport ] [Super Rabbit] bound_address {inet[/0:0:0:0:0:0:0:0:9301]}, publish_address {inet[/192.168.1.105:9301]}
[2015-07-23 15:47:46,090][INFO ][discovery ] [Super Rabbit] test/4kauOR8qRlmRQ4VmEw6p6g
[2015-07-23 15:47:46,090][DEBUG][cluster.service ] [Super Rabbit] processing [initial_join]: execute
[2015-07-23 15:47:46,090][DEBUG][cluster.service ] [Super Rabbit] processing [initial_join]: took 0s no change in cluster_state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,097][DEBUG][transport.netty ] [J. Jonah Jameson] connected to node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:46,108][DEBUG][transport.netty ] [Super Rabbit] connected to node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]
[2015-07-23 15:47:47,546][DEBUG][transport.netty ] [Super Rabbit] connected to node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,044][DEBUG][discovery.zen ] [J. Jonah Jameson] filtered ping responses: (filter_client[true], filter_data[false])
--> ping_response{node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]], id[6], master [null], hasJoinedOnce [false], cluster_name[test]}
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,057][DEBUG][cluster.service ] [Super Rabbit] processing [zen-disco-receive(join from node[[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]])]: execute
[2015-07-23 15:47:49,058][DEBUG][cluster.service ] [Super Rabbit] failing [zen-disco-receive(join from node[[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]])]: local node is no longer master
[2015-07-23 15:47:49,100][DEBUG][discovery.zen ] [Super Rabbit] filtered ping responses: (filter_client[true], filter_data[false])
--> ping_response{node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]], id[9], master [null], hasJoinedOnce [false], cluster_name[test]}
[2015-07-23 15:47:49,101][DEBUG][cluster.service ] [Super Rabbit] processing [zen-disco-join (elected_as_master)]: execute
[2015-07-23 15:47:49,106][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [1], source [zen-disco-join (elected_as_master)]
[2015-07-23 15:47:49,107][INFO ][cluster.service ] [Super Rabbit] new_master [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]], reason: zen-disco-join (elected_as_master)
[2015-07-23 15:47:49,107][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 1
[2015-07-23 15:47:49,107][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 1
[2015-07-23 15:47:49,109][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:47:49,109][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 15:47:49,109][DEBUG][cluster.service ] [Super Rabbit] processing [zen-disco-join (elected_as_master)]: took 8ms done applying updated cluster_state (version: 1)
[2015-07-23 15:47:49,123][DEBUG][cluster.service ] [Super Rabbit] processing [local-gateway-elected-state]: execute
[2015-07-23 15:47:49,124][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [2], source [local-gateway-elected-state]
[2015-07-23 15:47:49,124][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 2
[2015-07-23 15:47:49,124][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 2
[2015-07-23 15:47:49,127][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:47:49,127][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 15:47:49,129][INFO ][http ] [Super Rabbit] bound_address {inet[/0:0:0:0:0:0:0:0:9200]}, publish_address {inet[/192.168.1.105:9200]}
[2015-07-23 15:47:49,129][INFO ][node ] [Super Rabbit] started
[2015-07-23 15:47:49,154][INFO ][gateway ] [Super Rabbit] recovered [0] indices into cluster_state
[2015-07-23 15:47:49,154][DEBUG][cluster.service ] [Super Rabbit] processing [local-gateway-elected-state]: took 30ms done applying updated cluster_state (version: 2)
[2015-07-23 15:47:49,215][DEBUG][cluster.service ] [Super Rabbit] processing [zen-disco-receive(join from node[[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]])]: execute
[2015-07-23 15:47:49,215][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [3], source [zen-disco-receive(join from node[[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]])]
[2015-07-23 15:47:49,215][INFO ][cluster.service ] [Super Rabbit] added {[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]],}, reason: zen-disco-receive(join from node[[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]])
[2015-07-23 15:47:49,216][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 3
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,224][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 3
[2015-07-23 15:47:49,225][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 15:47:49,225][DEBUG][discovery.zen.fd ] [J. Jonah Jameson] [master] restarting fault detection against master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]], reason [new cluster state received and we are monitoring the wrong master [null]]
[2015-07-23 15:47:49,225][DEBUG][discovery.zen ] [J. Jonah Jameson] got first state from fresh master [4kauOR8qRlmRQ4VmEw6p6g]
[2015-07-23 15:47:49,226][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [3], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 15:47:49,226][INFO ][cluster.service ] [J. Jonah Jameson] detected_master [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]], added {[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]],}, reason: zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])
[2015-07-23 15:47:49,227][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 3
[2015-07-23 15:47:49,256][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 30ms done applying updated cluster_state (version: 3)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,256][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 3
[2015-07-23 15:47:49,256][DEBUG][cluster ] [Super Rabbit] data node was added, retrieving new cluster info
[2015-07-23 15:47:49,258][DEBUG][cluster.service ] [Super Rabbit] processing [zen-disco-receive(join from node[[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]])]: took 42ms done applying updated cluster_state (version: 3)
[2015-07-23 15:47:49,258][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:47:49,258][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,258][DEBUG][cluster.service ] [J. Jonah Jameson] processing [finalize_join ([Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]])]: execute
[2015-07-23 15:47:49,258][DEBUG][cluster.service ] [J. Jonah Jameson] processing [finalize_join ([Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]])]: took 0s no change in cluster_state
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,258][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute(post_node_add)]: execute
[2015-07-23 15:47:49,261][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute(post_node_add)]: took 0s no change in cluster_state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:47:49,265][INFO ][http ] [J. Jonah Jameson] bound_address {inet[/0:0:0:0:0:0:0:0:9201]}, publish_address {inet[/192.168.1.105:9201]}
[2015-07-23 15:47:49,265][INFO ][node ] [J. Jonah Jameson] started
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:48:19,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:48:19,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:48:19,116][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:48:19,116][INFO ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on one or more nodes, rerouting shards
[2015-07-23 15:48:19,125][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: execute
[2015-07-23 15:48:19,128][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [4], source [cluster_reroute (api)]
[2015-07-23 15:48:19,128][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 4
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:48:19,131][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 4
[2015-07-23 15:48:19,132][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 15:48:19,132][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [4], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 15:48:19,132][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 4
[2015-07-23 15:48:19,133][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 1ms done applying updated cluster_state (version: 4)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:48:19,133][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 4
[2015-07-23 15:48:19,134][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:48:19,134][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 15:48:19,134][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: took 8ms done applying updated cluster_state (version: 4)
[2015-07-23 15:48:49,114][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:48:49,115][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:48:49,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:48:49,115][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:49:19,114][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:49:19,115][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:49:19,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:49:19,115][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:49:49,114][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:49:49,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:49:49,115][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:49:49,115][INFO ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on one or more nodes, rerouting shards
[2015-07-23 15:49:49,115][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: execute
[2015-07-23 15:49:49,116][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [5], source [cluster_reroute (api)]
[2015-07-23 15:49:49,116][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 5
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:49:49,119][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 5
[2015-07-23 15:49:49,119][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 15:49:49,120][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [5], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 15:49:49,120][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 5
[2015-07-23 15:49:49,121][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 1ms done applying updated cluster_state (version: 5)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:49:49,121][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 5
[2015-07-23 15:49:49,122][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:49:49,122][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 15:49:49,122][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: took 6ms done applying updated cluster_state (version: 5)
[2015-07-23 15:50:00,182][DEBUG][cluster.service ] [Super Rabbit] processing [create-index [idx], cause [auto(index api)]]: execute
[2015-07-23 15:50:00,186][DEBUG][indices ] [Super Rabbit] creating Index [idx], shards [5]/[1]
[2015-07-23 15:50:00,299][DEBUG][index.mapper ] [Super Rabbit] [idx] using dynamic[true], default mapping: default_mapping_location[null], loaded_from[jar:file:/opt/elk/TEST/es170-b/elasticsearch-1.7.0/lib/elasticsearch-1.7.0.jar!/org/elasticsearch/index/mapper/default-mapping.json], default percolator mapping: location[null], loaded_from[null]
[2015-07-23 15:50:00,299][DEBUG][index.cache.query.parser.resident] [Super Rabbit] [idx] using [resident] query cache with max_size [100], expire [null]
[2015-07-23 15:50:00,302][DEBUG][index.store.fs ] [Super Rabbit] [idx] using index.store.throttle.type [node], with index.store.throttle.max_bytes_per_sec [0b]
[2015-07-23 15:50:00,353][INFO ][cluster.metadata ] [Super Rabbit] [idx] creating index, cause [auto(index api)], templates [], shards [5]/[1], mappings [doc]
[2015-07-23 15:50:00,361][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,361][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,361][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,361][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,362][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,362][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,362][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,362][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,362][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,363][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:00,363][DEBUG][indices ] [Super Rabbit] [idx] closing ... (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,363][DEBUG][indices ] [Super Rabbit] [idx] closing index service (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,363][DEBUG][indices ] [Super Rabbit] [idx] closing index cache (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,363][DEBUG][index.cache.filter.weighted] [Super Rabbit] [idx] full cache clear, reason [close]
[2015-07-23 15:50:00,363][DEBUG][index.cache.fixedbitset ] [Super Rabbit] [idx] clearing all bitsets because [close]
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] clearing index field data (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] closing analysis service (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] closing index engine (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] closing index gateway (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] closing mapper service (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] closing index query parser service (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,364][DEBUG][indices ] [Super Rabbit] [idx] closing index service (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,365][DEBUG][indices ] [Super Rabbit] [idx] closed... (reason [cleaning up after validating index on master])
[2015-07-23 15:50:00,365][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [6], source [create-index [idx], cause [auto(index api)]]
[2015-07-23 15:50:00,365][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 6
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:50:00,378][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 6
[2015-07-23 15:50:00,378][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 15:50:00,379][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [6], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 15:50:00,379][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 6
[2015-07-23 15:50:00,397][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 18ms done applying updated cluster_state (version: 6)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:50:00,397][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 6
[2015-07-23 15:50:00,398][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:50:00,398][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 15:50:00,412][DEBUG][cluster.service ] [Super Rabbit] processing [create-index [idx], cause [auto(index api)]]: took 229ms done applying updated cluster_state (version: 6)
[2015-07-23 15:50:19,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:50:19,115][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:50:19,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:50:19,116][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:50:49,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:50:49,115][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:50:49,116][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:50:49,116][INFO ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on one or more nodes, rerouting shards
[2015-07-23 15:50:49,116][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: execute
[2015-07-23 15:50:49,117][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [4kauOR8qRlmRQ4VmEw6p6g], preventing allocation
[2015-07-23 15:50:49,118][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [Uc0hQoZLRJGjp-qyjNkQKg], preventing allocation
[2015-07-23 15:50:49,118][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [4kauOR8qRlmRQ4VmEw6p6g], preventing allocation
[2015-07-23 15:50:49,119][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [Uc0hQoZLRJGjp-qyjNkQKg], preventing allocation
[2015-07-23 15:50:49,119][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [4kauOR8qRlmRQ4VmEw6p6g], preventing allocation
[2015-07-23 15:50:49,119][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [Uc0hQoZLRJGjp-qyjNkQKg], preventing allocation
[2015-07-23 15:50:49,119][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [4kauOR8qRlmRQ4VmEw6p6g], preventing allocation
[2015-07-23 15:50:49,120][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [Uc0hQoZLRJGjp-qyjNkQKg], preventing allocation
[2015-07-23 15:50:49,120][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [4kauOR8qRlmRQ4VmEw6p6g], preventing allocation
[2015-07-23 15:50:49,120][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] More than the allowed 85% used disk threshold (94.4% used) on node [Uc0hQoZLRJGjp-qyjNkQKg], preventing allocation
[2015-07-23 15:50:49,121][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,121][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,121][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,121][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,122][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,122][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,122][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,123][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,123][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node Uc0hQoZLRJGjp-qyjNkQKg, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,123][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Less than the required 10% free bytes threshold (5.5% bytes free) on node 4kauOR8qRlmRQ4VmEw6p6g, preventing allocation even though primary has never been allocated
[2015-07-23 15:50:49,124][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [7], source [cluster_reroute (api)]
[2015-07-23 15:50:49,125][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 7
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:50:49,129][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 7
[2015-07-23 15:50:49,129][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 15:50:49,129][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [7], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 15:50:49,130][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 7
[2015-07-23 15:50:49,131][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 1ms done applying updated cluster_state (version: 7)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 15:50:49,131][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 7
[2015-07-23 15:50:49,131][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 15:50:49,132][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 15:50:49,132][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: took 15ms done applying updated cluster_state (version: 7)
[2015-07-23 15:51:00,415][DEBUG][action.index ] [Super Rabbit] observer: timeout notification from cluster service. timeout setting [1m], time since start [1m]
[2015-07-23 15:51:19,116][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:51:19,116][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [Uc0hQoZLRJGjp-qyjNkQKg][J. Jonah Jameson] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 15:51:19,117][WARN ][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark [90%] exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%], shards will be relocated away from this node
[2015-07-23 15:51:19,117][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] high disk watermark exceeded on [4kauOR8qRlmRQ4VmEw6p6g][Super Rabbit] free: 24.1gb[5.5%] but an automatic reroute has occurred in the last [1m], skipping reroute
[2015-07-23 16:00:01,771][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: execute
[2015-07-23 16:00:01,776][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [8], source [cluster_reroute (api)]
[2015-07-23 16:00:01,776][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 8
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:01,779][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 8
[2015-07-23 16:00:01,779][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:01,779][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [8], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:01,780][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 8
[2015-07-23 16:00:01,780][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx] creating index
[2015-07-23 16:00:01,781][DEBUG][indices ] [J. Jonah Jameson] creating Index [idx], shards [5]/[1]
[2015-07-23 16:00:01,890][DEBUG][index.mapper ] [J. Jonah Jameson] [idx] using dynamic[true], default mapping: default_mapping_location[null], loaded_from[jar:file:/opt/elk/TEST/es170-a/elasticsearch-1.7.0/lib/elasticsearch-1.7.0.jar!/org/elasticsearch/index/mapper/default-mapping.json], default percolator mapping: location[null], loaded_from[null]
[2015-07-23 16:00:01,891][DEBUG][index.cache.query.parser.resident] [J. Jonah Jameson] [idx] using [resident] query cache with max_size [100], expire [null]
[2015-07-23 16:00:01,895][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using index.store.throttle.type [node], with index.store.throttle.max_bytes_per_sec [0b]
[2015-07-23 16:00:01,898][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx] adding mapping [doc], source [{"doc":{"properties":{}}}]
[2015-07-23 16:00:01,944][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx][4] creating shard
[2015-07-23 16:00:01,944][DEBUG][index ] [J. Jonah Jameson] [idx] creating shard_id [idx][4]
[2015-07-23 16:00:02,001][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/4/index] as shard's index location
[2015-07-23 16:00:02,003][DEBUG][index.store ] [J. Jonah Jameson] [idx][4] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,003][DEBUG][index.merge.scheduler ] [J. Jonah Jameson] [idx][4] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,004][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/4/translog] as shard's translog location
[2015-07-23 16:00:02,006][DEBUG][index.deletionpolicy ] [J. Jonah Jameson] [idx][4] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,007][DEBUG][index.merge.policy ] [J. Jonah Jameson] [idx][4] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,008][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] state: [CREATED]
[2015-07-23 16:00:02,008][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,009][DEBUG][index.translog ] [J. Jonah Jameson] [idx][4] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,013][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] state: [CREATED]->[RECOVERING], reason [from gateway]
[2015-07-23 16:00:02,014][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx][0] creating shard
[2015-07-23 16:00:02,014][DEBUG][index.gateway ] [J. Jonah Jameson] [idx][4] starting recovery from local ...
[2015-07-23 16:00:02,014][DEBUG][index ] [J. Jonah Jameson] [idx] creating shard_id [idx][0]
[2015-07-23 16:00:02,027][DEBUG][index.engine ] [J. Jonah Jameson] [idx][4] skipping check for 3x segments
[2015-07-23 16:00:02,028][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/0/index] as shard's index location
[2015-07-23 16:00:02,029][DEBUG][index.store ] [J. Jonah Jameson] [idx][0] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,029][DEBUG][index.merge.scheduler ] [J. Jonah Jameson] [idx][0] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,029][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/0/translog] as shard's translog location
[2015-07-23 16:00:02,030][DEBUG][index.deletionpolicy ] [J. Jonah Jameson] [idx][0] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,030][DEBUG][index.merge.policy ] [J. Jonah Jameson] [idx][0] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,031][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] state: [CREATED]
[2015-07-23 16:00:02,031][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,031][DEBUG][index.translog ] [J. Jonah Jameson] [idx][0] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,032][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] state: [CREATED]->[RECOVERING], reason [from gateway]
[2015-07-23 16:00:02,032][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx][2] creating shard
[2015-07-23 16:00:02,032][DEBUG][index.gateway ] [J. Jonah Jameson] [idx][0] starting recovery from local ...
[2015-07-23 16:00:02,032][DEBUG][index ] [J. Jonah Jameson] [idx] creating shard_id [idx][2]
[2015-07-23 16:00:02,033][DEBUG][index.engine ] [J. Jonah Jameson] [idx][0] skipping check for 3x segments
[2015-07-23 16:00:02,044][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/2/index] as shard's index location
[2015-07-23 16:00:02,045][DEBUG][index.store ] [J. Jonah Jameson] [idx][2] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,045][DEBUG][index.merge.scheduler ] [J. Jonah Jameson] [idx][2] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,046][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/2/translog] as shard's translog location
[2015-07-23 16:00:02,047][DEBUG][index.deletionpolicy ] [J. Jonah Jameson] [idx][2] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,048][DEBUG][index.merge.policy ] [J. Jonah Jameson] [idx][2] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,048][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] state: [CREATED]
[2015-07-23 16:00:02,048][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,049][DEBUG][index.translog ] [J. Jonah Jameson] [idx][2] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,050][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] state: [CREATED]->[RECOVERING], reason [from gateway]
[2015-07-23 16:00:02,051][DEBUG][index.gateway ] [J. Jonah Jameson] [idx][2] starting recovery from local ...
[2015-07-23 16:00:02,052][DEBUG][index.engine ] [J. Jonah Jameson] [idx][2] skipping check for 3x segments
[2015-07-23 16:00:02,052][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 272ms done applying updated cluster_state (version: 8)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,053][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 8
[2015-07-23 16:00:02,054][DEBUG][indices.cluster ] [Super Rabbit] [idx] creating index
[2015-07-23 16:00:02,054][DEBUG][indices ] [Super Rabbit] creating Index [idx], shards [5]/[1]
[2015-07-23 16:00:02,079][DEBUG][index.mapper ] [Super Rabbit] [idx] using dynamic[true], default mapping: default_mapping_location[null], loaded_from[jar:file:/opt/elk/TEST/es170-b/elasticsearch-1.7.0/lib/elasticsearch-1.7.0.jar!/org/elasticsearch/index/mapper/default-mapping.json], default percolator mapping: location[null], loaded_from[null]
[2015-07-23 16:00:02,080][DEBUG][index.cache.query.parser.resident] [Super Rabbit] [idx] using [resident] query cache with max_size [100], expire [null]
[2015-07-23 16:00:02,080][DEBUG][index.store.fs ] [Super Rabbit] [idx] using index.store.throttle.type [node], with index.store.throttle.max_bytes_per_sec [0b]
[2015-07-23 16:00:02,082][DEBUG][indices.cluster ] [Super Rabbit] [idx] adding mapping [doc], source [{"doc":{"properties":{}}}]
[2015-07-23 16:00:02,086][DEBUG][indices.cluster ] [Super Rabbit] [idx][3] creating shard
[2015-07-23 16:00:02,087][DEBUG][index ] [Super Rabbit] [idx] creating shard_id [idx][3]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,095][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] scheduling refresher every 1s
[2015-07-23 16:00:02,098][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] scheduling refresher every 1s
[2015-07-23 16:00:02,098][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] scheduling refresher every 1s
[2015-07-23 16:00:02,098][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] state: [RECOVERING]->[POST_RECOVERY], reason [post recovery from gateway, no translog]
[2015-07-23 16:00:02,098][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] state: [RECOVERING]->[POST_RECOVERY], reason [post recovery from gateway, no translog]
[2015-07-23 16:00:02,098][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] state: [RECOVERING]->[POST_RECOVERY], reason [post recovery from gateway, no translog]
[2015-07-23 16:00:02,098][DEBUG][index.gateway ] [J. Jonah Jameson] [idx][0] recovery completed from [local], took [66ms]
[2015-07-23 16:00:02,098][DEBUG][index.gateway ] [J. Jonah Jameson] [idx][4] recovery completed from [local], took [84ms]
[2015-07-23 16:00:02,098][DEBUG][index.gateway ] [J. Jonah Jameson] [idx][2] recovery completed from [local], took [47ms]
[2015-07-23 16:00:02,099][DEBUG][cluster.action.shard ] [J. Jonah Jameson] sending shard started for [idx][2], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,099][DEBUG][cluster.action.shard ] [J. Jonah Jameson] sending shard started for [idx][0], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,099][DEBUG][cluster.action.shard ] [J. Jonah Jameson] sending shard started for [idx][4], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,100][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][4], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,100][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][2], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,100][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][0], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,146][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/3/index] as shard's index location
[2015-07-23 16:00:02,148][DEBUG][index.store ] [Super Rabbit] [idx][3] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,148][DEBUG][index.merge.scheduler ] [Super Rabbit] [idx][3] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,149][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/3/translog] as shard's translog location
[2015-07-23 16:00:02,152][DEBUG][index.deletionpolicy ] [Super Rabbit] [idx][3] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,153][DEBUG][index.merge.policy ] [Super Rabbit] [idx][3] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,153][DEBUG][index.shard ] [Super Rabbit] [idx][3] state: [CREATED]
[2015-07-23 16:00:02,154][DEBUG][index.shard ] [Super Rabbit] [idx][3] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,154][DEBUG][index.translog ] [Super Rabbit] [idx][3] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,158][DEBUG][index.shard ] [Super Rabbit] [idx][3] state: [CREATED]->[RECOVERING], reason [from gateway]
[2015-07-23 16:00:02,158][DEBUG][indices.cluster ] [Super Rabbit] [idx][1] creating shard
[2015-07-23 16:00:02,158][DEBUG][index.gateway ] [Super Rabbit] [idx][3] starting recovery from local ...
[2015-07-23 16:00:02,159][DEBUG][index ] [Super Rabbit] [idx] creating shard_id [idx][1]
[2015-07-23 16:00:02,169][DEBUG][index.engine ] [Super Rabbit] [idx][3] skipping check for 3x segments
[2015-07-23 16:00:02,169][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/1/index] as shard's index location
[2015-07-23 16:00:02,170][DEBUG][index.store ] [Super Rabbit] [idx][1] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,170][DEBUG][index.merge.scheduler ] [Super Rabbit] [idx][1] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,170][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/1/translog] as shard's translog location
[2015-07-23 16:00:02,171][DEBUG][index.deletionpolicy ] [Super Rabbit] [idx][1] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,171][DEBUG][index.merge.policy ] [Super Rabbit] [idx][1] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,171][DEBUG][index.shard ] [Super Rabbit] [idx][1] state: [CREATED]
[2015-07-23 16:00:02,171][DEBUG][index.shard ] [Super Rabbit] [idx][1] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,171][DEBUG][index.translog ] [Super Rabbit] [idx][1] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,172][DEBUG][index.shard ] [Super Rabbit] [idx][1] state: [CREATED]->[RECOVERING], reason [from gateway]
[2015-07-23 16:00:02,172][DEBUG][index.gateway ] [Super Rabbit] [idx][1] starting recovery from local ...
[2015-07-23 16:00:02,173][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,173][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:02,173][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute (api)]: took 402ms done applying updated cluster_state (version: 8)
[2015-07-23 16:00:02,173][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][4], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: execute
[2015-07-23 16:00:02,173][DEBUG][index.engine ] [Super Rabbit] [idx][1] skipping check for 3x segments
[2015-07-23 16:00:02,174][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,174][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,175][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,175][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [9], source [shard-started ([idx][4], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]
[2015-07-23 16:00:02,175][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 9
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,178][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 9
[2015-07-23 16:00:02,178][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:02,178][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [9], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:02,178][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 9
[2015-07-23 16:00:02,179][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,179][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,179][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,213][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 35ms done applying updated cluster_state (version: 9)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,213][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 9
[2015-07-23 16:00:02,214][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,215][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:02,215][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][4], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: took 41ms done applying updated cluster_state (version: 9)
[2015-07-23 16:00:02,215][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][2], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: execute
[2015-07-23 16:00:02,215][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][2], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: took 0s no change in cluster_state
[2015-07-23 16:00:02,215][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][0], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: execute
[2015-07-23 16:00:02,216][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][0], node[Uc0hQoZLRJGjp-qyjNkQKg], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: took 0s no change in cluster_state
[2015-07-23 16:00:02,252][DEBUG][index.shard ] [Super Rabbit] [idx][1] scheduling refresher every 1s
[2015-07-23 16:00:02,252][DEBUG][index.shard ] [Super Rabbit] [idx][3] scheduling refresher every 1s
[2015-07-23 16:00:02,252][DEBUG][index.shard ] [Super Rabbit] [idx][1] state: [RECOVERING]->[POST_RECOVERY], reason [post recovery from gateway, no translog]
[2015-07-23 16:00:02,253][DEBUG][index.shard ] [Super Rabbit] [idx][3] state: [RECOVERING]->[POST_RECOVERY], reason [post recovery from gateway, no translog]
[2015-07-23 16:00:02,253][DEBUG][index.gateway ] [Super Rabbit] [idx][1] recovery completed from [local], took [80ms]
[2015-07-23 16:00:02,253][DEBUG][index.gateway ] [Super Rabbit] [idx][3] recovery completed from [local], took [95ms]
[2015-07-23 16:00:02,254][DEBUG][cluster.action.shard ] [Super Rabbit] sending shard started for [idx][1], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,254][DEBUG][cluster.action.shard ] [Super Rabbit] sending shard started for [idx][3], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,254][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][1], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,254][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][3], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery from gateway]
[2015-07-23 16:00:02,254][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][1], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: execute
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,262][DEBUG][indices.store ] [J. Jonah Jameson] [idx][0] loaded store meta data (took [2.3ms])
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,263][DEBUG][indices.store ] [Super Rabbit] [idx][1] loaded store meta data (took [3.4ms])
[2015-07-23 16:00:02,263][DEBUG][indices.store ] [Super Rabbit] [idx][3] loaded store meta data (took [4.5ms])
[2015-07-23 16:00:02,265][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,265][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,265][DEBUG][indices.store ] [J. Jonah Jameson] [idx][4] loaded store meta data (took [632.3micros])
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,265][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,265][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,265][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,266][DEBUG][indices.store ] [J. Jonah Jameson] [idx][2] loaded store meta data (took [785.8micros])
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,267][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [10], source [shard-started ([idx][1], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]
[2015-07-23 16:00:02,267][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 10
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,271][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 10
[2015-07-23 16:00:02,271][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:02,271][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [10], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:02,271][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 10
[2015-07-23 16:00:02,272][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 1ms done applying updated cluster_state (version: 10)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,273][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 10
[2015-07-23 16:00:02,274][DEBUG][index.shard ] [Super Rabbit] [idx][3] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,274][DEBUG][index.shard ] [Super Rabbit] [idx][1] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,275][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,275][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:02,299][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][1], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: took 44ms done applying updated cluster_state (version: 10)
[2015-07-23 16:00:02,299][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][3], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: execute
[2015-07-23 16:00:02,300][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][3], node[4kauOR8qRlmRQ4VmEw6p6g], [P], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery from gateway]]: took 0s no change in cluster_state
[2015-07-23 16:00:02,300][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute(async_shard_fetch)]: execute
[2015-07-23 16:00:02,304][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,304][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,305][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,305][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,305][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,307][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [11], source [cluster_reroute(async_shard_fetch)]
[2015-07-23 16:00:02,307][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 11
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,311][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 11
[2015-07-23 16:00:02,312][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:02,312][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [11], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:02,312][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 11
[2015-07-23 16:00:02,313][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx][3] creating shard
[2015-07-23 16:00:02,313][DEBUG][index ] [J. Jonah Jameson] [idx] creating shard_id [idx][3]
[2015-07-23 16:00:02,326][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/3/index] as shard's index location
[2015-07-23 16:00:02,327][DEBUG][index.store ] [J. Jonah Jameson] [idx][3] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,327][DEBUG][index.merge.scheduler ] [J. Jonah Jameson] [idx][3] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,327][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/3/translog] as shard's translog location
[2015-07-23 16:00:02,328][DEBUG][index.deletionpolicy ] [J. Jonah Jameson] [idx][3] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,328][DEBUG][index.merge.policy ] [J. Jonah Jameson] [idx][3] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,328][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] state: [CREATED]
[2015-07-23 16:00:02,328][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,329][DEBUG][index.translog ] [J. Jonah Jameson] [idx][3] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,330][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] state: [CREATED]->[RECOVERING], reason [from [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]
[2015-07-23 16:00:02,331][DEBUG][indices.cluster ] [J. Jonah Jameson] [idx][1] creating shard
[2015-07-23 16:00:02,331][DEBUG][index ] [J. Jonah Jameson] [idx] creating shard_id [idx][1]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,333][DEBUG][indices.recovery ] [Super Rabbit] delaying recovery of [idx][3] as it is not listed as assigned to target node [J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,343][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/1/index] as shard's index location
[2015-07-23 16:00:02,344][DEBUG][index.store ] [J. Jonah Jameson] [idx][1] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,344][DEBUG][index.merge.scheduler ] [J. Jonah Jameson] [idx][1] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,344][DEBUG][index.store.fs ] [J. Jonah Jameson] [idx] using [/opt/elk/TEST/es170-a/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/1/translog] as shard's translog location
[2015-07-23 16:00:02,345][DEBUG][index.deletionpolicy ] [J. Jonah Jameson] [idx][1] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,345][DEBUG][index.merge.policy ] [J. Jonah Jameson] [idx][1] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,346][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] state: [CREATED]
[2015-07-23 16:00:02,346][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,346][DEBUG][index.translog ] [J. Jonah Jameson] [idx][1] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,347][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] state: [CREATED]->[RECOVERING], reason [from [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,348][DEBUG][indices.recovery ] [Super Rabbit] delaying recovery of [idx][1] as it is not listed as assigned to target node [J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,370][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 58ms done applying updated cluster_state (version: 11)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,370][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 11
[2015-07-23 16:00:02,371][DEBUG][indices.cluster ] [Super Rabbit] [idx][2] creating shard
[2015-07-23 16:00:02,371][DEBUG][index ] [Super Rabbit] [idx] creating shard_id [idx][2]
[2015-07-23 16:00:02,383][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/2/index] as shard's index location
[2015-07-23 16:00:02,384][DEBUG][index.store ] [Super Rabbit] [idx][2] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,384][DEBUG][index.merge.scheduler ] [Super Rabbit] [idx][2] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,384][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/2/translog] as shard's translog location
[2015-07-23 16:00:02,385][DEBUG][index.deletionpolicy ] [Super Rabbit] [idx][2] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,385][DEBUG][index.merge.policy ] [Super Rabbit] [idx][2] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,385][DEBUG][index.shard ] [Super Rabbit] [idx][2] state: [CREATED]
[2015-07-23 16:00:02,386][DEBUG][index.shard ] [Super Rabbit] [idx][2] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,386][DEBUG][index.translog ] [Super Rabbit] [idx][2] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,387][DEBUG][index.shard ] [Super Rabbit] [idx][2] state: [CREATED]->[RECOVERING], reason [from [J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]
[2015-07-23 16:00:02,388][DEBUG][indices.cluster ] [Super Rabbit] [idx][0] creating shard
[2015-07-23 16:00:02,388][DEBUG][index ] [Super Rabbit] [idx] creating shard_id [idx][0]
[2015-07-23 16:00:02,398][DEBUG][index.store ] [Super Rabbit] [idx][2] create legacy length-only output for recovery.1437660002387.segments_1
[2015-07-23 16:00:02,400][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/0/index] as shard's index location
[2015-07-23 16:00:02,401][DEBUG][index.store ] [Super Rabbit] [idx][0] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,401][DEBUG][index.merge.scheduler ] [Super Rabbit] [idx][0] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,401][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/0/translog] as shard's translog location
[2015-07-23 16:00:02,402][DEBUG][index.deletionpolicy ] [Super Rabbit] [idx][0] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,402][DEBUG][index.merge.policy ] [Super Rabbit] [idx][0] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,402][DEBUG][index.shard ] [Super Rabbit] [idx][0] state: [CREATED]
[2015-07-23 16:00:02,402][DEBUG][index.shard ] [Super Rabbit] [idx][0] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,403][DEBUG][index.translog ] [Super Rabbit] [idx][0] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,403][DEBUG][index.shard ] [Super Rabbit] [idx][0] state: [CREATED]->[RECOVERING], reason [from [J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]
[2015-07-23 16:00:02,404][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,404][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:02,410][DEBUG][index.store ] [Super Rabbit] [idx][0] create legacy length-only output for recovery.1437660002403.segments_1
[2015-07-23 16:00:02,418][DEBUG][index.engine ] [Super Rabbit] [idx][2] skipping check for 3x segments
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,423][DEBUG][cluster.service ] [J. Jonah Jameson] processing [recovery_mapping_check]: execute
[2015-07-23 16:00:02,423][DEBUG][cluster.service ] [J. Jonah Jameson] processing [recovery_mapping_check]: took 0s no change in cluster_state
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,425][DEBUG][index.shard ] [Super Rabbit] [idx][2] scheduling refresher every 1s
[2015-07-23 16:00:02,428][DEBUG][index.engine ] [Super Rabbit] [idx][0] skipping check for 3x segments
[2015-07-23 16:00:02,428][DEBUG][index.shard ] [Super Rabbit] [idx][2] state: [RECOVERING]->[POST_RECOVERY], reason [peer recovery done]
[2015-07-23 16:00:02,429][DEBUG][cluster.action.shard ] [Super Rabbit] sending shard started for [idx][2], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]
[2015-07-23 16:00:02,429][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][2], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]
[2015-07-23 16:00:02,429][DEBUG][indices.recovery ] [Super Rabbit] [idx][2] recovery done from [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]], took [41ms]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,434][DEBUG][cluster.service ] [J. Jonah Jameson] processing [recovery_mapping_check]: execute
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,434][DEBUG][cluster.service ] [Super Rabbit] processing [cluster_reroute(async_shard_fetch)]: took 133ms done applying updated cluster_state (version: 11)
[2015-07-23 16:00:02,434][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][2], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]: execute
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,435][DEBUG][cluster.service ] [J. Jonah Jameson] processing [recovery_mapping_check]: took 0s no change in cluster_state
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,436][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,436][DEBUG][index.shard ] [Super Rabbit] [idx][0] scheduling refresher every 1s
[2015-07-23 16:00:02,436][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,436][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,436][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,437][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,437][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,438][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [12], source [shard-started ([idx][2], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]
[2015-07-23 16:00:02,438][DEBUG][index.shard ] [Super Rabbit] [idx][0] state: [RECOVERING]->[POST_RECOVERY], reason [peer recovery done]
[2015-07-23 16:00:02,438][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 12
[2015-07-23 16:00:02,439][DEBUG][cluster.action.shard ] [Super Rabbit] sending shard started for [idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]
[2015-07-23 16:00:02,439][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]
[2015-07-23 16:00:02,439][DEBUG][indices.recovery ] [Super Rabbit] [idx][0] recovery done from [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]], took [34ms]
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,441][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 12
[2015-07-23 16:00:02,441][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:02,442][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [12], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:02,442][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 12
[2015-07-23 16:00:02,464][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 22ms done applying updated cluster_state (version: 12)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,464][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 12
[2015-07-23 16:00:02,465][DEBUG][indices.cluster ] [Super Rabbit] [idx][4] creating shard
[2015-07-23 16:00:02,465][DEBUG][index ] [Super Rabbit] [idx] creating shard_id [idx][4]
[2015-07-23 16:00:02,481][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/4/index] as shard's index location
[2015-07-23 16:00:02,481][DEBUG][index.store ] [Super Rabbit] [idx][4] store stats are refreshed with refresh_interval [10s]
[2015-07-23 16:00:02,481][DEBUG][index.merge.scheduler ] [Super Rabbit] [idx][4] using [concurrent] merge scheduler with max_thread_count[3], max_merge_count[5]
[2015-07-23 16:00:02,481][DEBUG][index.store.fs ] [Super Rabbit] [idx] using [/opt/elk/TEST/es170-b/elasticsearch-1.7.0/data/test/nodes/0/indices/idx/4/translog] as shard's translog location
[2015-07-23 16:00:02,482][DEBUG][index.deletionpolicy ] [Super Rabbit] [idx][4] Using [keep_only_last] deletion policy
[2015-07-23 16:00:02,482][DEBUG][index.merge.policy ] [Super Rabbit] [idx][4] using [tiered] merge mergePolicy with expunge_deletes_allowed[10.0], floor_segment[2mb], max_merge_at_once[10], max_merge_at_once_explicit[30], max_merged_segment[5gb], segments_per_tier[10.0], reclaim_deletes_weight[2.0]
[2015-07-23 16:00:02,483][DEBUG][index.shard ] [Super Rabbit] [idx][4] state: [CREATED]
[2015-07-23 16:00:02,483][DEBUG][index.shard ] [Super Rabbit] [idx][4] scheduling optimizer / merger every 1s
[2015-07-23 16:00:02,483][DEBUG][index.translog ] [Super Rabbit] [idx][4] interval [5s], flush_threshold_ops [2147483647], flush_threshold_size [512mb], flush_threshold_period [30m]
[2015-07-23 16:00:02,484][DEBUG][index.shard ] [Super Rabbit] [idx][4] state: [CREATED]->[RECOVERING], reason [from [J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]
[2015-07-23 16:00:02,484][DEBUG][cluster.action.shard ] [Super Rabbit] sending shard started for [idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [master [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]] marked shard as initializing, but shard state is [POST_RECOVERY], mark shard as started]
[2015-07-23 16:00:02,484][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [master [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]] marked shard as initializing, but shard state is [POST_RECOVERY], mark shard as started]
[2015-07-23 16:00:02,485][DEBUG][index.shard ] [Super Rabbit] [idx][2] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,485][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,485][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:02,487][DEBUG][index.store ] [Super Rabbit] [idx][4] create legacy length-only output for recovery.1437660002484.segments_1
[2015-07-23 16:00:02,500][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][2], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]: took 65ms done applying updated cluster_state (version: 12)
[2015-07-23 16:00:02,500][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]: execute
[2015-07-23 16:00:02,501][DEBUG][cluster.routing.allocation] [Super Rabbit] failed to find shard [[idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]] in order to start it [no matching shard on node], ignoring
[2015-07-23 16:00:02,501][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,501][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,501][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,502][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,502][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,502][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,502][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,504][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [13], source [shard-started ([idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]
[2015-07-23 16:00:02,504][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 13
[2015-07-23 16:00:02,506][DEBUG][index.engine ] [Super Rabbit] [idx][4] skipping check for 3x segments
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,508][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 13
[2015-07-23 16:00:02,508][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:02,509][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [13], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:02,509][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 13
[2015-07-23 16:00:02,518][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 9ms done applying updated cluster_state (version: 13)
[2015-07-23 16:00:02,518][DEBUG][cluster.service ] [J. Jonah Jameson] processing [recovery_mapping_check]: execute
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,518][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 13
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,518][DEBUG][cluster.service ] [J. Jonah Jameson] processing [recovery_mapping_check]: took 0s no change in cluster_state
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,519][DEBUG][index.shard ] [Super Rabbit] [idx][0] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,519][DEBUG][index.shard ] [Super Rabbit] [idx][4] scheduling refresher every 1s
[2015-07-23 16:00:02,520][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,520][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:02,522][DEBUG][index.shard ] [Super Rabbit] [idx][4] state: [RECOVERING]->[POST_RECOVERY], reason [peer recovery done]
[2015-07-23 16:00:02,522][DEBUG][cluster.action.shard ] [Super Rabbit] sending shard started for [idx][4], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]
[2015-07-23 16:00:02,522][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][4], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]
[2015-07-23 16:00:02,523][DEBUG][indices.recovery ] [Super Rabbit] [idx][4] recovery done from [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]], took [37ms]
[2015-07-23 16:00:02,530][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]: took 29ms done applying updated cluster_state (version: 13)
[2015-07-23 16:00:02,530][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [master [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]] marked shard as initializing, but shard state is [POST_RECOVERY], mark shard as started]]: execute
[2015-07-23 16:00:02,530][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][0], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [master [Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]] marked shard as initializing, but shard state is [POST_RECOVERY], mark shard as started]]: took 0s no change in cluster_state
[2015-07-23 16:00:02,531][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][4], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]: execute
[2015-07-23 16:00:02,531][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,531][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,531][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,531][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,531][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,532][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,532][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,532][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:02,533][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [14], source [shard-started ([idx][4], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]
[2015-07-23 16:00:02,533][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 14
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,537][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 14
[2015-07-23 16:00:02,538][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:02,538][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [14], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:02,538][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 14
[2015-07-23 16:00:02,548][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 10ms done applying updated cluster_state (version: 14)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,549][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 14
[2015-07-23 16:00:02,549][DEBUG][index.shard ] [Super Rabbit] [idx][4] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:02,550][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:02,550][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:02,860][DEBUG][index.store ] [J. Jonah Jameson] [idx][3] create legacy length-only output for recovery.1437660002330.segments_1
[2015-07-23 16:00:02,861][DEBUG][index.store ] [J. Jonah Jameson] [idx][1] create legacy length-only output for recovery.1437660002347.segments_1
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,118][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][4], node[4kauOR8qRlmRQ4VmEw6p6g], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[J. Jonah Jameson][Uc0hQoZLRJGjp-qyjNkQKg][w530][inet[/192.168.1.105:9300]]]]]: took 587ms done applying updated cluster_state (version: 14)
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,127][DEBUG][index.engine ] [J. Jonah Jameson] [idx][1] skipping check for 3x segments
[2015-07-23 16:00:03,127][DEBUG][index.engine ] [J. Jonah Jameson] [idx][3] skipping check for 3x segments
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,131][DEBUG][cluster.service ] [Super Rabbit] processing [recovery_mapping_check]: execute
[2015-07-23 16:00:03,132][DEBUG][cluster.service ] [Super Rabbit] processing [recovery_mapping_check]: took 0s no change in cluster_state
[2015-07-23 16:00:03,132][DEBUG][cluster.service ] [Super Rabbit] processing [recovery_mapping_check]: execute
[2015-07-23 16:00:03,133][DEBUG][cluster.service ] [Super Rabbit] processing [recovery_mapping_check]: took 0s no change in cluster_state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,134][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] scheduling refresher every 1s
[2015-07-23 16:00:03,134][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] scheduling refresher every 1s
[2015-07-23 16:00:03,136][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] state: [RECOVERING]->[POST_RECOVERY], reason [peer recovery done]
[2015-07-23 16:00:03,136][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] state: [RECOVERING]->[POST_RECOVERY], reason [peer recovery done]
[2015-07-23 16:00:03,137][DEBUG][cluster.action.shard ] [J. Jonah Jameson] sending shard started for [idx][3], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]
[2015-07-23 16:00:03,137][DEBUG][cluster.action.shard ] [J. Jonah Jameson] sending shard started for [idx][1], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]
[2015-07-23 16:00:03,137][DEBUG][indices.recovery ] [J. Jonah Jameson] [idx][3] recovery done from [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]], took [806ms]
[2015-07-23 16:00:03,137][DEBUG][indices.recovery ] [J. Jonah Jameson] [idx][1] recovery done from [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]], took [789ms]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,137][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][3], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]
[2015-07-23 16:00:03,137][DEBUG][cluster.action.shard ] [Super Rabbit] received shard started for [idx][1], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]], indexUUID [bVX9r06FQDS2sXbvOZ_bnA], reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]
[2015-07-23 16:00:03,138][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][3], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]]: execute
[2015-07-23 16:00:03,138][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,138][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,139][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,139][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,139][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,139][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,139][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,140][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,140][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [Uc0hQoZLRJGjp-qyjNkQKg] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,140][DEBUG][cluster.routing.allocation.decider] [Super Rabbit] Node [4kauOR8qRlmRQ4VmEw6p6g] has 28.35393445340771% free disk (133309640704 bytes)
[2015-07-23 16:00:03,141][DEBUG][cluster.service ] [Super Rabbit] cluster state updated, version [15], source [shard-started ([idx][3], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]]
[2015-07-23 16:00:03,142][DEBUG][cluster.service ] [Super Rabbit] publishing cluster state version 15
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,144][DEBUG][discovery.zen.publish ] [J. Jonah Jameson] received cluster state version 15
[2015-07-23 16:00:03,144][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: execute
[2015-07-23 16:00:03,145][DEBUG][cluster.service ] [J. Jonah Jameson] cluster state updated, version [15], source [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]
[2015-07-23 16:00:03,145][DEBUG][cluster.service ] [J. Jonah Jameson] set local cluster state to version 15
[2015-07-23 16:00:03,146][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:03,146][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] state: [POST_RECOVERY]->[STARTED], reason [global state is [STARTED]]
[2015-07-23 16:00:03,171][DEBUG][cluster.service ] [J. Jonah Jameson] processing [zen-disco-receive(from master [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]])]: took 25ms done applying updated cluster_state (version: 15)
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:03,171][DEBUG][cluster.service ] [Super Rabbit] set local cluster state to version 15
[2015-07-23 16:00:03,172][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: execute
[2015-07-23 16:00:03,173][DEBUG][river.cluster ] [Super Rabbit] processing [reroute_rivers_node_changed]: no change in cluster_state
[2015-07-23 16:00:03,195][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][3], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]]: took 56ms done applying updated cluster_state (version: 15)
[2015-07-23 16:00:03,195][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][1], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]]: execute
[2015-07-23 16:00:03,195][DEBUG][cluster.service ] [Super Rabbit] processing [shard-started ([idx][1], node[Uc0hQoZLRJGjp-qyjNkQKg], [R], s[INITIALIZING], unassigned_info[[reason=INDEX_CREATED], at[2015-07-23T13:50:00.355Z]]), reason [after recovery (replica) from node [[Super Rabbit][4kauOR8qRlmRQ4VmEw6p6g][w530][inet[/192.168.1.105:9301]]]]]: took 0s no change in cluster_state
==> es170-a/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:15,975][DEBUG][indices.memory ] [J. Jonah Jameson] recalculating shard indexing buffer (reason=[[ADDED]]), total is [98.9mb] with [5] active shards, each shard set to indexing=[19.7mb], translog=[64kb]
[2015-07-23 16:00:15,976][DEBUG][index.shard ] [J. Jonah Jameson] [idx][0] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:15,976][DEBUG][index.shard ] [J. Jonah Jameson] [idx][1] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:15,976][DEBUG][index.shard ] [J. Jonah Jameson] [idx][2] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:15,977][DEBUG][index.shard ] [J. Jonah Jameson] [idx][3] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:15,977][DEBUG][index.shard ] [J. Jonah Jameson] [idx][4] updating index_buffer_size from [64mb] to [19.7mb]
==> es170-b/elasticsearch-1.7.0/logs/test.log <==
[2015-07-23 16:00:16,038][DEBUG][indices.memory ] [Super Rabbit] recalculating shard indexing buffer (reason=[[ADDED]]), total is [98.9mb] with [5] active shards, each shard set to indexing=[19.7mb], translog=[64kb]
[2015-07-23 16:00:16,038][DEBUG][index.shard ] [Super Rabbit] [idx][0] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:16,039][DEBUG][index.shard ] [Super Rabbit] [idx][1] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:16,039][DEBUG][index.shard ] [Super Rabbit] [idx][2] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:16,039][DEBUG][index.shard ] [Super Rabbit] [idx][3] updating index_buffer_size from [64mb] to [19.7mb]
[2015-07-23 16:00:16,039][DEBUG][index.shard ] [Super Rabbit] [idx][4] updating index_buffer_size from [64mb] to [19.7mb]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment