[CI] IngestGeoIpClientYamlTestSuiteIT class failing

[elasticsearchmachine]

Build Scans:

• elasticsearch-periodic-platform-support #11451 / ubuntu-2404-aarch64_checkrestcompat_platform-support-arm
• elasticsearch-periodic-platform-support #11443 / ubuntu-2404-aarch64_checkrestcompat_platform-support-arm

Reproduction Line:

./gradlew ":modules:ingest-geoip:yamlRestCompatTest" --tests "org.elasticsearch.ingest.geoip.IngestGeoIpClientYamlTestSuiteIT.test {yaml=ingest_geoip/20_geoip_processor/Test geoip processor with lists, first only}" -Dtests.seed=6C5CDC64CB8FC1B7 -Dtests.locale=gu-Gujr-IN -Dtests.timezone=Australia/Adelaide -Druntime.java=25

Applicable branches:
9.1

Reproduces locally?:
N/A

Failure History:
See dashboard

Failure Message:

java.lang.AssertionError: 
Expected: <4>
     but: was <3>

Issue Reasons:

• [9.1] 2 failures in class org.elasticsearch.ingest.geoip.IngestGeoIpClientYamlTestSuiteIT (2.8% fail rate in 71 executions)
• [9.1] 2 failures in step ubuntu-2404-aarch64_checkrestcompat_platform-support-arm (66.7% fail rate in 3 executions)
• [9.1] 2 failures in pipeline elasticsearch-periodic-platform-support (66.7% fail rate in 3 executions)

Note:
This issue was created using new test triage automation. Please report issues or feedback to es-delivery.

[elasticsearchmachine]

Pinging @elastic/es-data-management (Team:Data Management)

[nielsbauman]

Very sad to see that these failures are still occurring 🥲; I had hoped that #137660 would have resolved any issues here.

I already tried reproducing this on some VMs some time ago, but I'll try again.

[nielsbauman]

Ok, I think I know what's going on. I ran ~31k iterations on a few VMs, but wasn't able to reproduce this once. However, I looked at the logs of some test failures, and I think it's simply a case of slow clusters not being able to download all four GeoIP databases within 10 seconds (the timeout of the assertBusy that times out in these failures).

Looking at the logs of this test failure, you can see that the downloader started downloading databases around 16:45:31 and was even able to download all four, but the test failed right before the last database was downloaded.

[2025-11-24T16:45:31,289][INFO ][o.e.c.m.MetadataCreateIndexService] [test-cluster-0] creating index [.geoip_databases] in project [default], cause [auto(bulk api)], templates [], shards [1]/[1]	
[2025-11-24T16:45:31,353][INFO ][o.e.c.r.a.AllocationService] [test-cluster-0] in project [default] updating number_of_replicas to [0] for indices [.geoip_databases]	
[2025-11-24T16:45:31,952][INFO ][o.e.c.u.FeatureFlag      ] [test-cluster-0] The current build is a snapshot, feature flag [zstd_stored_fields] is enabled	
[2025-11-24T16:45:32,307][INFO ][o.e.c.r.a.AllocationService] [test-cluster-0] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.geoip_databases][0]]])." previous.health="YELLOW" reason="shards started [[.geoip_databases][0]]"	
[2025-11-24T16:45:33,268][INFO ][o.e.i.g.ConfigDatabases  ] [test-cluster-0] database file changed [/opt/buildkite-agent/builds/bk-agent-prod-aws-1763991162206468162/elastic/elasticsearch-periodic-platform-support/modules/ingest-geoip/build/testrun/yamlRestCompatTest/temp/junit8229543378580106576/ingest-geoip/asn.mmdb], reloading database...	
[2025-11-24T16:45:34,931][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [GeoLite2-City.mmdb] for project [default]	
[2025-11-24T16:45:35,085][INFO ][o.e.i.g.DatabaseNodeService] [test-cluster-0] successfully loaded database file [GeoLite2-City.mmdb]	
[2025-11-24T16:45:37,486][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [GeoLite2-ASN.mmdb] for project [default]	
[2025-11-24T16:45:37,532][INFO ][o.e.i.g.DatabaseNodeService] [test-cluster-0] successfully loaded database file [GeoLite2-ASN.mmdb]	
[2025-11-24T16:45:39,410][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [GeoLite2-Country.mmdb] for project [default]	
[2025-11-24T16:45:39,416][INFO ][o.e.i.g.DatabaseNodeService] [test-cluster-0] successfully loaded database file [GeoLite2-Country.mmdb]	
[2025-11-24T13:45:41,058][INFO ][o.e.i.g.IngestGeoIpClientYamlTestSuiteIT][test] Waiting for all cluster updates up to this moment to be processed	
[2025-11-24T16:45:41,346][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [MyCustomGeoLite2-City.mmdb] for project [default]	
[2025-11-24T16:45:41,347][INFO ][o.e.c.m.MetadataDeleteIndexService] [test-cluster-0] [.geoip_databases/uC3bTI_hQECwagZQKb0jHw] deleting index

(The test framework logs Waiting for all cluster updates up to this moment to be processed when it starts cleaning up after a test, which means the test failed right before that time)

In some other failures, like https://gradle-enterprise.elastic.co/s/6h4yztdjxqsky, the whole suite fails. We again see that the assertBusy times out after 10 seconds before all databases are downloaded in the first failure of the suite:

[2025-11-23T23:53:50,359][INFO ][o.e.c.m.MetadataCreateIndexService] [test-cluster-0] creating index [.geoip_databases] in project [default], cause [auto(bulk api)], templates [], shards [1]/[1]	
[2025-11-23T23:53:50,371][INFO ][o.e.c.r.a.AllocationService] [test-cluster-0] in project [default] updating number_of_replicas to [0] for indices [.geoip_databases]	
[2025-11-23T23:53:51,412][INFO ][o.e.c.u.FeatureFlag      ] [test-cluster-0] The current build is a snapshot, feature flag [zstd_stored_fields] is enabled	
[2025-11-23T23:53:53,182][INFO ][o.e.c.r.a.AllocationService] [test-cluster-0] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.geoip_databases][0]]])." previous.health="YELLOW" reason="shards started [[.geoip_databases][0]]"	
[2025-11-23T23:53:56,039][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [GeoLite2-City.mmdb] for project [default]	
[2025-11-23T23:53:56,169][INFO ][o.e.i.g.DatabaseNodeService] [test-cluster-0] successfully loaded database file [GeoLite2-City.mmdb]	
[2025-11-23T23:53:58,452][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [GeoLite2-ASN.mmdb] for project [default]	
[2025-11-23T23:53:58,527][INFO ][o.e.i.g.DatabaseNodeService] [test-cluster-0] successfully loaded database file [GeoLite2-ASN.mmdb]	
[2025-11-23T23:54:00,074][INFO ][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] successfully downloaded geoip database [GeoLite2-Country.mmdb] for project [default]	
[2025-11-23T23:54:00,080][INFO ][o.e.i.g.DatabaseNodeService] [test-cluster-0] successfully loaded database file [GeoLite2-Country.mmdb]	
[2025-11-23T23:54:00,092][INFO ][o.e.i.g.IngestGeoIpClientYamlTestSuiteIT][test] Waiting for all cluster updates up to this moment to be processed	
[2025-11-23T23:54:00,110][INFO ][o.e.c.m.MetadataDeleteIndexService] [test-cluster-0] [.geoip_databases/KzR1Y89UTCaeai9XqnMYiQ] deleting index	
[2025-11-23T23:54:00,182][ERROR][o.e.i.g.GeoIpDownloader  ] [test-cluster-0] error downloading geoip database [MyCustomGeoLite2-City.mmdb] for project [default] [.geoip_databases] org.elasticsearch.index.IndexNotFoundException: no such index [.geoip_databases]	
	at org.elasticsearch.server@9.1.8-SNAPSHOT/org.elasticsearch.cluster.metadata.IndexNameExpressionResolver.notFoundException(IndexNameExpressionResolver.java:778)

However, in this case the .geoip_databases index is already deleted as part of the test cleanup, causing an exception in the downloader. Subsequent tests in the suite fail on the same assertBusy without any logs. The fact that the following tests are also failing might look like a bug, but that's simply because there are no cluster state updates in this test cluster, which prevents the GeoIpDownloader from running again. In production clusters, it is unlikely that the .geoip_databases index gets deleted while it's downloading databases. But even if it would, subsequent cluster state updates (or even the periodic run once every 3 days) would trigger the downloader to download the databases.

Therefore, simply extending the timeout will avoid the index from being deleted while the downloader is still running, which will also avoid subsequent tests from failing.

[nielsbauman]

You can easily reproduce the first failure with something like:

diff --git a/modules/ingest-geoip/src/main/java/org/elasticsearch/ingest/geoip/GeoIpDownloader.java b/modules/ingest-geoip/src/main/java/org/elasticsearch/ingest/geoip/GeoIpDownloader.java
index 1872fc90d7f..0ab4d7032f5 100644
--- a/modules/ingest-geoip/src/main/java/org/elasticsearch/ingest/geoip/GeoIpDownloader.java
+++ b/modules/ingest-geoip/src/main/java/org/elasticsearch/ingest/geoip/GeoIpDownloader.java
@@ -207,6 +207,11 @@ public class GeoIpDownloader extends AbstractGeoIpDownloader {
                 state = state.put(name, new Metadata(start, firstChunk, lastChunk - 1, md5, start));
                 updateTaskState();
                 stats = stats.successfulDownload(System.currentTimeMillis() - start).databasesCount(state.getDatabases().size());
+                try {
+                    Thread.sleep(5000);
+                } catch (Exception e) {
+                    // ignore
+                }
                 logger.info("successfully downloaded geoip database [{}] for project [{}]", name, projectId);
                 deleteOldChunks(name, firstChunk);
             }

Reproducing the second failure is a bit harder because it requires very specific timing.