FrozenIndexTests.testCloseFreezeAndOpen fails on master

[javanna]

Failure: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/266/console

13:58:03 FAILURE 3.12s J2 | FrozenIndexTests.testCloseFreezeAndOpen <<< FAILURES!
13:58:03    > Throwable #1: java.lang.AssertionError
13:58:03    > 	at __randomizedtesting.SeedInfo.seed([AABC9D28F4622B51:9CD27E54D7263843]:0)
13:58:03    > 	at org.elasticsearch.index.engine.FrozenIndexTests.testCloseFreezeAndOpen(FrozenIndexTests.java:92)
13:58:03    > 	at java.lang.Thread.run(Thread.java:748)

The assertion that fails is at assertFalse(((FrozenEngine) engine).isReaderOpen());

Reproduce line (does not reproduce for me):

./gradlew :x-pack:plugin:core:test \
  -Dtests.seed=AABC9D28F4622B51 \
  -Dtests.class=org.elasticsearch.index.engine.FrozenIndexTests \
  -Dtests.method="testCloseFreezeAndOpen" \
  -Dtests.security.manager=true \
  -Dtests.locale=de-GR \
  -Dtests.timezone=America/Montevideo \
  -Dcompiler.java=11 \
  -Druntime.java=8

[elasticmachine]

Pinging @elastic/es-distributed

[javanna]

@s1monw would you like to have a look at this? I haven't muted the test as it failed only once since it was added. Let me know how you prefer to proceed?

[albertzaharovits]

Another hit:
https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/266/console

java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([AABC9D28F4622B51:9CD27E54D7263843]:0)
	at org.junit.Assert.fail(Assert.java:86)
	at org.junit.Assert.assertTrue(Assert.java:41)
	at org.junit.Assert.assertFalse(Assert.java:64)
	at org.junit.Assert.assertFalse(Assert.java:74)
	at org.elasticsearch.index.engine.FrozenIndexTests.testCloseFreezeAndOpen(FrozenIndexTests.java:92)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)

[jpountz]

We looked at this failure during test triage power hour. In the beginning we thought this might be due to the response being returned after only one of the shards returned data from the fetch phase, which is always the case since this is paginating with a size of 1. But now that I'm looking deeper I'm afraid this can't explain this test failure. Our gut feeling was that this is is a race condition, ie. the response is returned before the reader had a chance to be closed but we would like to be sure before turning the assertion into an assertBusy.
cc @s1monw.

[s1monw]

We looked at this failure during test triage power hour. In the beginning we thought this might be due to the response being returned after only one of the shards returned data from the fetch phase, which is always the case since this is paginating with a size of 1. But now that I'm looking deeper I'm afraid this can't explain this test failure. Our gut feeling was that this is is a race condition, ie. the response is returned before the reader had a chance to be closed but we would like to be sure before turning the assertion into an assertBusy.

@jpountz I opened #35837 - the issue is that we concurrently hold the reader to check if a refresh is needed. I was able to reproduce it with a tight loop around the scroll. So it's kind of a test bug to I fixed it in code since the refreshNeeded call is unnecessary.