[CI] EsqlAsyncSecurityIT testInsufficientPrivilege failing

[DaveCTurner]

Build scan:
https://gradle-enterprise.elastic.co/s/7q4i7hkcgs3pw/tests/:x-pack:plugin:esql:qa:security:javaRestTest/org.elasticsearch.xpack.esql.EsqlAsyncSecurityIT/testInsufficientPrivilege

Reproduction line:

./gradlew ':x-pack:plugin:esql:qa:security:javaRestTest' --tests "org.elasticsearch.xpack.esql.EsqlAsyncSecurityIT.testInsufficientPrivilege" -Dtests.seed=6BE610F4610E7615 -Dtests.locale=ar-SA -Dtests.timezone=Australia/Lord_Howe -Druntime.java=17 -Dtests.fips.enabled=true

Applicable branches:
main

Reproduces locally?:
Didn't try

Failure history:
Failure dashboard for org.elasticsearch.xpack.esql.EsqlAsyncSecurityIT#testInsufficientPrivilege

Failure excerpt:

java.lang.AssertionError: 
Expected: a string containing "unauthorized for user [test-admin] run as [metadata1_read2] with effective roles [metadata1_read2] on indices [index-user1], this action is granted by the index privileges [read,all]"
     but: was "method [GET], host [http:https://127.0.0.1:38777], URI [_query/async/FlpMUS1pSkhMVE0teDdGQnhNenphb1EbNXlJcVVhN01SU1c2OVJMT1Q4SEdNdzo1NjI0?wait_for_completion_timeout=60s], status line [HTTP/1.1 404 Not Found]
{"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index [.async-search]","resource.type":"index_or_alias","resource.id":".async-search","index_uuid":"_na_","index":".async-search"}],"type":"index_not_found_exception","reason":"no such index [.async-search]","resource.type":"index_or_alias","resource.id":".async-search","index_uuid":"_na_","index":".async-search"},"status":404}"

  at __randomizedtesting.SeedInfo.seed([6BE610F4610E7615:7E9C3F3EA2F6C740]:0)
  at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18)
  at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
  at org.elasticsearch.test.ESTestCase.assertThat(ESTestCase.java:2275)
  at org.elasticsearch.xpack.esql.EsqlSecurityIT.testInsufficientPrivilege(EsqlSecurityIT.java:145)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
  at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:568)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:946)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:982)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.junit.rules.RunRules.evaluate(RunRules.java:20)
  at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:48)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at org.apache.lucene.tests.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:45)
  at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
  at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
  at org.junit.rules.RunRules.evaluate(RunRules.java:20)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:843)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:490)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:955)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:840)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:891)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:902)
  at org.elasticsearch.test.cluster.local.DefaultLocalElasticsearchCluster$1.evaluate(DefaultLocalElasticsearchCluster.java:47)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
  at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
  at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
  at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
  at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
  at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
  at org.apache.lucene.tests.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:47)
  at org.junit.rules.RunRules.evaluate(RunRules.java:20)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:390)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:850)
  at java.lang.Thread.run(Thread.java:833)

[elasticsearchmachine]

Pinging @elastic/es-analytical-engine (Team:Analytics)

[nik9000]

Gradle says:

[2024-06-16T14:51:12,102][INFO ][o.e.x.e.EsqlAsyncSecurityIT] [testInsufficientPrivilege] REQUEST=Request{method='POST', endpoint='_query/async', entity=[Content-Type: application/json; charset=UTF-8,Content-Length: 231,Chunked: false], options=RequestOptions{headers=es-security-runas-user: metadata1_read2}}
[2024-06-16T14:51:12,103][INFO ][o.e.x.e.EsqlAsyncSecurityIT] [testInsufficientPrivilege] REQUEST body={query=FROM index-user1,index-user2 | STATS sum=sum(value) | limit 10000000, keep_on_completion=true, wait_for_completion_timeout=913nanos, pragma={enrich_max_workers=5, data_partitioning=segment, page_size=1}}
[2024-06-16T14:51:12,115][INFO ][o.e.x.e.EsqlAsyncSecurityIT] [testInsufficientPrivilege] RESPONSE=Response{requestLine=POST _query/async HTTP/1.1, host=http:https://127.0.0.1:38777, response=HTTP/1.1 200 OK}
[2024-06-16T14:51:12,115][INFO ][o.e.x.e.EsqlAsyncSecurityIT] [testInsufficientPrivilege] REQUEST=Request{method='GET', endpoint='_query/async/FlpMUS1pSkhMVE0teDdGQnhNenphb1EbNXlJcVVhN01SU1c2OVJMT1Q4SEdNdzo1NjI0?wait_for_completion_timeout=60s', options=RequestOptions{headers=es-security-runas-user: metadata1_read2}}

[nik9000]

It looks to me like the request in question timed out waiting for the planning of the index to finish but then retried fast enough that the .async_search index had yet to be created. That, or it isn't allowed to access it. I'm not sure which one is more likely.

And I can't reproduce locally.

[nik9000]

Looks to only fail a couple of % of the time. Going to run it in a loop with iters

[nik9000]

Ha! Reproduced:

    {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index [.async-search]","resource.type":"index_or_alias","resource.id":".async-search","index_uuid":"_na_","index":".async-search"}],"type":"index_not_found_exception","reason":"no such index [.async-search]","resource.type":"index_or_alias","resource.id":".async-search","index_uuid":"_na_","index":".async-search"},"status":404}"