We started to get CirrusSearchFullTextLatencyTooHigh: CirrusSearch full_text 95th percentiles latency is too high (mw@eqiad to eqiad) and similar alerts beginning about a week and a half ago as I write this. Although the alerts usually clear quickly, there have also been extended periods of high latency .
Creating this ticket to:
Per IRC conversation with @gmodena , we suspect one or more of the following issues:
Somewhat related is T386860 , in which we've discussed enabling the Performance governor on all R450 or later chassis. This change made a huge difference on WDQS hosts and we hope it might have a similar effect on the Elastic hosts.
Change #1122660 had a related patch set uploaded (by Bking; author: Bking):
[operations/puppet@production] elastic: enable perf governor, remove unused host hieradata
Change #1122660 merged by Bking:
[operations/puppet@production] elastic: enable perf governor, remove unused host hieradata
Here's a graph that shows all the recent spikes. We had another today at the usual time of 8 PM UTC. The extremely quick ramp-up of the threadpool queue may suggest an automated process.
Mentioned in SAL (#wikimedia-operations) [2025-02-28T22:02:18Z] <bking@cumin2002> START - Cookbook sre.elasticsearch.ban Banning hosts: elastic1103*,elastic1107* for ban hosts to change threadpool settings - bking@cumin2002 - T387176
Mentioned in SAL (#wikimedia-operations) [2025-02-28T22:02:22Z] <bking@cumin2002> END (PASS) - Cookbook sre.elasticsearch.ban (exit_code=0) Banning hosts: elastic1103*,elastic1107* for ban hosts to change threadpool settings - bking@cumin2002 - T387176
Mentioned in SAL (#wikimedia-operations) [2025-02-28T22:30:47Z] <inflatador> bking@elastic1103 restart elastic-chi to apply thread pool settings T387176
We had another spike today. Looking at Logstash, we saw some messages like
org.elasticsearch.common.util.concurrent.EsRejectedExecutionException: rejected execution of org.elasticsearch.common.util.concurrent.TimedRunnable@28be706e on QueueResizingEsThreadPoolExecutor[name = elastic1066-production-search-eqiad/search, queue capacity = 1000, min queue capacity = 1000, max queue capacity = 1000, frame size = 2000, targeted response rate = 1s, task execution EWMA = 310.3ms, adjustment amount = 50, org.elasticsearch.common.util.concurrent.QueueResizingEsThreadPoolExecutor@4e773165[Running, pool size = 61, active threads = 61, queued tasks = 1000, completed tasks = 62763343]]
The queue size is set via this Puppet hieradata , which is rendered as
# Thread pool settings
##
thread_pool:
write:
size: 6
queue_size: 1000in /etc/elasticsearch/production-search-eqiad/elasticsearch.yml
Elastic's docs on thread pools state the that write queue is "fixed with a size of # of allocated processors, queue_size of 10000. " Which is significantly higher than our values of size 6, queue_size 1000.
So it appears that when I removed the 3 servers a couple of weeks ago, we lost enough queue capacity that the cluster actually runs out of queue space. But this issue doesn't seem to correlate with resource constraints (CPU, memory, I/O). So I think we have some headroom to increase these values, but I'd like to run that by our team members before I make any changes.
In the meantime, I've one-offed elastic1103 and elastic1107 with settings that are closer to Elastic's defaults. Specifically, threadpool size of 48 and queue size of 2000. I'll check in a few times over the weekend to see how things are going.
f things are really bad, I can always reimage the 3 servers again and put them back in the Elastic clusters.
The EsRejectedExecutionException problem seen in logstash refers to the search thread pool, the puppet settings you mention refers to the write thread pool. I doubt that increasing the write thread pool is going to have any positive impact on the search latency issues. The reason we tuned the write thread is perhaps related to the way we performed writes when we ran updates from the MW job queue (high concurrency of write requests), I suspect that the defaults could have caused this pool to consume most the CPUs most of the time but it's unclear from the commit message that introduced this setting (https://gerrit.wikimedia.org/r/c/operations/puppet/+/197533). Now that we run from a flink job I suspect that the concurrency is much lower.
.
Had a look at the search thread pool and it appears that elastic1066 is an host having a very high number of rejections compared to other hosts: P73928.
It might be interesting to collect these stats while we are in the middle of a latency spike to see if one particular host is rejecting a lot more requests.
This could suggest that the shard distribution is particularly bad for this host.
Mentioned in SAL (#wikimedia-operations) [2025-03-03T14:21:35Z] <bking@cumin2002> START - Cookbook sre.elasticsearch.ban Banning hosts: elastic1066* for ban elastic1066 to hopefully stop rejections - bking@cumin2002 - T387176
Mentioned in SAL (#wikimedia-operations) [2025-03-03T14:21:38Z] <bking@cumin2002> END (PASS) - Cookbook sre.elasticsearch.ban (exit_code=0) Banning hosts: elastic1066* for ban elastic1066 to hopefully stop rejections - bking@cumin2002 - T387176
Mentioned in SAL (#wikimedia-operations) [2025-03-03T19:26:02Z] <bking@cumin2002> START - Cookbook sre.elasticsearch.ban Banning hosts: reforge1005*,relforge1006*,relforge1007* for ban hosts prior to revert - bking@cumin2002 - T387176
Mentioned in SAL (#wikimedia-operations) [2025-03-03T19:26:05Z] <bking@cumin2002> END (PASS) - Cookbook sre.elasticsearch.ban (exit_code=0) Banning hosts: reforge1005*,relforge1006*,relforge1007* for ban hosts prior to revert - bking@cumin2002 - T387176
Cookbook cookbooks.sre.hosts.rename started by bking@cumin2002 from relforge1005 to elastic1108 completed:
Cookbook cookbooks.sre.hosts.rename started by bking@cumin2002 from relforge1006 to elastic1109 completed:
Cookbook cookbooks.sre.hosts.rename started by bking@cumin2002 from relforge1005 to elastic1108 completed:
Cookbook cookbooks.sre.hosts.rename started by bking@cumin2002 from relforge1006 to elastic1109 completed:
Cookbook cookbooks.sre.hosts.rename started by bking@cumin2002 from relforge1007 to elastic1110 completed:
For some reason this broke PCC on deploy servers:
Error: Evaluation Error: Error while evaluating a Function Call, DNS lookup failed for relforge1006.eqiad.wmnet Resolv::DNS::Resource::IN::A (file: /srv/jenkins/puppet-compiler/5033/production/src/modules/profile/functions/kubernetes/deployment_server/elasticsearch_external_services_config.pp, line: 22, column: 12) on node deploy1003.eqiad.wmnet Error: Evaluation Error: Error while evaluating a Function Call, DNS lookup failed for relforge1006.eqiad.wmnet Resolv::DNS::Resource::IN::A (file: /srv/jenkins/puppet-compiler/5033/production/src/modules/profile/functions/kubernetes/deployment_server/elasticsearch_external_services_config.pp, line: 22, column: 12) on node deploy1003.eqiad.wmnet Error: Could not call 'find' on 'catalog': Evaluation Error: Error while evaluating a Function Call, DNS lookup failed for relforge1006.eqiad.wmnet Resolv::DNS::Resource::IN::A (file: /srv/jenkins/puppet-compiler/5033/production/src/modules/profile/functions/kubernetes/deployment_server/elasticsearch_external_services_config.pp, line: 22, column: 12) on node deploy1003.eqiad.wmnet Error: Could not call 'find' on 'catalog': Evaluation Error: Error while evaluating a Function Call, DNS lookup failed for relforge1006.eqiad.wmnet Resolv::DNS::Resource::IN::A (file: /srv/jenkins/puppet-compiler/5033/production/src/modules/profile/functions/kubernetes/deployment_server/elasticsearch_external_services_config.pp, line: 22, column: 12) on node deploy1003.eqiad.wmnet Error: Try 'puppet help catalog compile' for usage
The PQL query in question does no longer return relforge1006.eqiad.wmnet when the production puppet db is queried, but it still does when querying the pcc db. I ran https://wikitech.wikimedia.org/wiki/Help:Puppet-compiler#Manually_update_production, but the issue persists. This issue is quite similar to T380937#10461825.
Change #1125180 had a related patch set uploaded (by Bking; author: Bking):
[operations/alerts@master] cirrussearch: Add alerts for thread pool rejections
@Jelto I'm not sure what's going on with the PCC failures, would you like me to spin off a ticket for Infrastructure Foundations (I think they own PCC?)
Getting back to the cluster latency...per today's Search Platform stand-up, the most likely explanation is sub-optimal shard routing.
As this issue happens fairly rarely (less than once a year), and we added alerts to catch the problem earlier, we are going to call this one solved for now. If it crops again, we'll probably put more effort into long-term mitigations. Closing...
Change #1125180 merged by jenkins-bot:
[operations/alerts@master] cirrussearch: Add alerts for thread pool rejections