# Higher search rate when added final data node to cluster

**URL:** <https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912>\
**Category:** Elasticsearch\
**Created:** [April 21, 2022, 1:07pm UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912 "2022-04-21T13:07:05Z")\
**Posts on this page:** 12\
**Page:** 1

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [April 21, 2022, 1:07pm UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/1 "2022-04-21T13:07:05Z")

</div>

We've got a 5 data node v.6.8.23 cluster in production, that seems to increase search rate and cpu usage when the fifth node (exrhel0212) has joined the cluster, running on four nodes cluster is much calmer.

Hints on how to investigate what's going on and why search rate and cpu userland usage increases much appreciated, TIA!

from Kibana cluster monitoring:

 ![Screenshot 2022-04-21 at 13.49.43](https://us1.discourse-cdn.com/elastic/original/3X/0/5/05285a553631be3aba3d935e913393f486ce6b1f.png)

 ![Screenshot 2022-04-21 at 13.50.15](https://us1.discourse-cdn.com/elastic/original/3X/4/9/491aefa041f54e7e1b4e7dc874997d81f1d1f6d7.png)

Network activity on current master node:

 ![Screenshot 2022-04-21 at 13.52.32](https://us1.discourse-cdn.com/elastic/original/3X/6/6/668b3ed3d8be8509f8b9797a4b2fa1098d9b6a7e.png)

CPU metrics from current master node:

 ![Screenshot 2022-04-21 at 13.53.11](https://us1.discourse-cdn.com/elastic/original/3X/e/9/e9e88990e28c216002184663eb2393c4d3f3789a.jpeg)

---

<div class="post-metadata">

**Author:** ![warkolm](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/warkolm/32/39224_2.png) [@warkolm](https://discuss.elastic.co/u/warkolm)\
**Post date:** [April 26, 2022, 1:28am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/2 "2022-04-26T01:28:30Z")

</div>

> [@stefws](#):
>
> v.6.8.23

6.X is [EOL](https://www.elastic.co/support/eol), please upgrade ASAP 🙂

Can you share the output from the `_cluster/stats?pretty&human` API?

---

<div class="post-metadata">

**Author:** ![stephenb](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stephenb/32/40856_2.png) [@stephenb](https://discuss.elastic.co/u/stephenb)\
**Post date:** [April 26, 2022, 2:21am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/3 "2022-04-26T02:21:55Z")

</div>

Perhaps an obvious observation when you add another node shards get shuffled to even the shards out and that uses CPU and IO.... Is it that??

---

<div class="post-metadata">

**Author:** ![warkolm](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/warkolm/32/39224_2.png) [@warkolm](https://discuss.elastic.co/u/warkolm)\
**Post date:** [April 26, 2022, 2:49am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/4 "2022-04-26T02:49:26Z")

</div>

True, it could be transitory.

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [April 28, 2022, 8:01am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/5 "2022-04-28T08:01:01Z")

</div>

Thanks for replying, nope reshuffling has settled nicely reasonably fast. The higher search rate continues as a new baseline.

Now Operational staff have had the node out of the cluster for several days =\> considering added it to cluster as a new bare/naked data node thus to expand cluster...

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [April 28, 2022, 8:09am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/6 "2022-04-28T08:09:52Z")

</div>

Know about 6.x EOL, v.7 is on the roadmap... 🙂

```auto
{
  "_nodes" : {
    "total" : 5,
    "successful" : 5,
    "failed" : 0
  },
  "cluster_name" : "RMElastic_prod",
  "cluster_uuid" : "cB79gjmQRRG9Tw9RKbyZog",
  "timestamp" : 1651133179324,
  "status" : "green",
  "indices" : {
    "count" : 1809,
    "shards" : {
      "total" : 8490,
      "primaries" : 4245,
      "replication" : 1.0,
      "index" : {
        "shards" : {
          "min" : 2,
          "max" : 10,
          "avg" : 4.693200663349917
        },
        "primaries" : {
          "min" : 1,
          "max" : 5,
          "avg" : 2.3466003316749586
        },
        "replication" : {
          "min" : 1.0,
          "max" : 1.0,
          "avg" : 1.0
        }
      }
    },
    "docs" : {
      "count" : 1053840751,
      "deleted" : 20366758
    },
    "store" : {
      "size" : "282.6gb",
      "size_in_bytes" : 303447749685
    },
    "fielddata" : {
      "memory_size" : "106.2mb",
      "memory_size_in_bytes" : 111398832,
      "evictions" : 0
    },
    "query_cache" : {
      "memory_size" : "41.4mb",
      "memory_size_in_bytes" : 43444818,
      "total_count" : 1186286,
      "hit_count" : 1132270,
      "miss_count" : 54016,
      "cache_size" : 1996,
      "cache_count" : 8684,
      "evictions" : 6688
    },
    "completion" : {
      "size" : "0b",
      "size_in_bytes" : 0
    },
    "segments" : {
      "count" : 63096,
      "memory" : "1.1gb",
      "memory_in_bytes" : 1220579609,
      "terms_memory" : "910.2mb",
      "terms_memory_in_bytes" : 954433089,
      "stored_fields_memory" : "92.3mb",
      "stored_fields_memory_in_bytes" : 96797568,
      "term_vectors_memory" : "0b",
      "term_vectors_memory_in_bytes" : 0,
      "norms_memory" : "79.4mb",
      "norms_memory_in_bytes" : 83277888,
      "points_memory" : "32.2mb",
      "points_memory_in_bytes" : 33850344,
      "doc_values_memory" : "49.8mb",
      "doc_values_memory_in_bytes" : 52220720,
      "index_writer_memory" : "5.1mb",
      "index_writer_memory_in_bytes" : 5414386,
      "version_map_memory" : "1.1mb",
      "version_map_memory_in_bytes" : 1250847,
      "fixed_bit_set" : "258.8mb",
      "fixed_bit_set_memory_in_bytes" : 271377488,
      "max_unsafe_auto_id_timestamp" : 1651104004845,
      "file_sizes" : { }
    }
  },
  "nodes" : {
    "count" : {
      "total" : 5,
      "data" : 4,
      "coordinating_only" : 0,
      "master" : 4,
      "ingest" : 5
    },
    "versions" : [
      "6.8.23"
    ],
    "os" : {
      "available_processors" : 18,
      "allocated_processors" : 18,
      "names" : [
        {
          "name" : "Linux",
          "count" : 5
        }
      ],
      "pretty_names" : [
        {
          "pretty_name" : "Red Hat Enterprise Linux",
          "count" : 5
        }
      ],
      "mem" : {
        "total" : "254.7gb",
        "total_in_bytes" : 273525952512,
        "free" : "2.5gb",
        "free_in_bytes" : 2708037632,
        "used" : "252.2gb",
        "used_in_bytes" : 270817914880,
        "free_percent" : 1,
        "used_percent" : 99
      }
    },
    "process" : {
      "cpu" : {
        "percent" : 48
      },
      "open_file_descriptors" : {
        "min" : 322,
        "max" : 17637,
        "avg" : 12823
      }
    },
    "jvm" : {
      "max_uptime" : "1.9d",
      "max_uptime_in_millis" : 165952585,
      "versions" : [
        {
          "version" : "1.8.0_322",
          "vm_name" : "OpenJDK 64-Bit Server VM",
          "vm_version" : "25.322-b06",
          "vm_vendor" : "Red Hat, Inc.",
          "count" : 5
        }
      ],
      "mem" : {
        "heap_used" : "52.1gb",
        "heap_used_in_bytes" : 55963970208,
        "heap_max" : "105.8gb",
        "heap_max_in_bytes" : 113659740160
      },
      "threads" : 568
    },
    "fs" : {
      "total" : "807.9gb",
      "total_in_bytes" : 867486879744,
      "free" : "490.9gb",
      "free_in_bytes" : 527122898944,
      "available" : "490.9gb",
      "available_in_bytes" : 527122898944
    },
    "plugins" : [],
    "network_types" : {
      "transport_types" : {
        "security4" : 5
      },
      "http_types" : {
        "security4" : 5
      }
    }
  }
}

```

---

<div class="post-metadata">

**Author:** ![warkolm](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/warkolm/32/39224_2.png) [@warkolm](https://discuss.elastic.co/u/warkolm)\
**Post date:** [April 28, 2022, 9:27am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/7 "2022-04-28T09:27:36Z")

</div>

Your average shard size is 0.03GB. You're likely wasting a tonne of resources there which won't help.

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [April 28, 2022, 6:26pm UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/8 "2022-04-28T18:26:46Z")

</div>

We are aware of this, on the roadmap are plan to aggregate many smaller indicies to monthly/yearly, only this doesn't explain why 5 nodes are running with so much higher load/search rate than 4 nodes for the same client load.

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [May 10, 2022, 11:29pm UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/9 "2022-05-10T23:29:21Z")

</div>

So attempted to rejoin node 212 as a new clean node today just before 12:00CEST, only it seems that after reshuffling has settled specific this node is sending approx 1K packets to each of the other 4 data nodes approx the same as the new baseline search rate. So my Q is howto figure out what's going on in this nodes brain 🙂

Kibana Monitoring showing baselines before and after expand cluster with 5th. data node 212:

 ![Screenshot 2022-05-11 at 01.14.11](https://us1.discourse-cdn.com/elastic/original/3X/6/8/680e4018aefb3ea688b726595c64cf425aa6ddb5.jpeg)

Network statistics for each cluster node:

Master electable node 217:

 ![Screenshot 2022-05-11 at 01.16.19](https://us1.discourse-cdn.com/elastic/original/3X/5/1/51f40f9707aff2df47498b04811e6b27f666fbba.jpeg)

Data node 215:

 ![Screenshot 2022-05-11 at 01.15.47](https://us1.discourse-cdn.com/elastic/original/3X/5/b/5b5b84d060640f77ee11e5f4830b982eaef9c7e6.jpeg)

Data node 214:

 ![Screenshot 2022-05-11 at 01.15.37](https://us1.discourse-cdn.com/elastic/original/3X/e/8/e81052e62f171d298798e2d9d8f67c3f60fcfa34.jpeg)

Data node 213:

 ![Screenshot 2022-05-11 at 01.15.25](https://us1.discourse-cdn.com/elastic/original/3X/0/e/0e8534ec45359857a37da8685352440751d45850.jpeg)

Data node 212:

 ![Screenshot 2022-05-11 at 01.15.13](https://us1.discourse-cdn.com/elastic/original/3X/5/3/537e00a489b855d2d2837da6b86ce92820ccc4c8.jpeg)

Data node 211:

 ![Screenshot 2022-05-11 at 01.14.58](https://us1.discourse-cdn.com/elastic/original/3X/4/1/410f52cf122140cd7a2e7cfc45257a1d4274f8d7.jpeg)

Attaching jstack dump of node 212: [Jstack dump](https://www.icloud.com/iclouddrive/0883MrfwnOxCDkWBBRXR5FxoQ#jstack-212)

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [May 12, 2022, 8:59am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/10 "2022-05-12T08:59:46Z")

</div>

Would it be possible dynamically to increase search logging to debug or TRACE through cluster settings, eg.

```auto
PUT /_cluster/settings
{
  "transient": {
    "logger.search": "TRACE"
  }
}

```

But guess one needs a LogConfig context predefined first, maybe like this:

```auto
appender.search_rolling.type = RollingFile
appender.search_rolling.name = search_rolling
appender.search_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_search.log
appender.search_rolling.layout.type = PatternLayout
appender.search_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n
appender.search_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_search-%i.log.gz
appender.search_rolling.policies.type = Policies
appender.search_rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.search_rolling.policies.size.size = 1GB
appender.search_rolling.strategy.type = DefaultRolloverStrategy
appender.search_rolling.strategy.max = 4

logger.search.name = org.elasticsearch.search
logger.search.level = warn
logger.search.appenderRef.search_rolling.ref = search_rolling
logger.search.additivity = false

```

---

<div class="post-metadata">

**Author:** ![stefws](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/stefws/32/6442_2.png) [@stefws](https://discuss.elastic.co/u/stefws)\
**Post date:** [May 17, 2022, 7:32am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/11 "2022-05-17T07:32:39Z")

</div>

Finally nailed the culprit through backtracking connecting http clients IPs 🙂

It turned out that somewhere someone had created a umbraco based monitoring service, running under an IIS, which target only node 212 as coordinating node with non-time-constrained searches every 10 sec thus searching every shards of specific indicies.

Had to kill it of course 😉

Still would be nice to know if it's possible to log searches with an appender + logger as above, since tcpdump doesn't reveal much with https connections.

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [June 14, 2022, 7:32am UTC](https://discuss.elastic.co/t/higher-search-rate-when-added-final-data-node-to-cluster/302912/12 "2022-06-14T07:32:55Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.