[CI] AssertionError: Accounting breaker not reset

[DaveCTurner]

CI output: https://internal-ci.elastic.co/job/elastic+x-pack-elasticsearch+6.2+multijob-windows-compatibility/682/console

REPRODUCE WITH: gradlew :x-pack-elasticsearch:qa:smoke-test-monitoring-with-watcher:integTestRunner \
  -Dtests.seed=9700B8DD0A76FCC8 \
  -Dtests.class=org.elasticsearch.smoketest.PreventFailingBuildIT \
  -Dtests.method="testSoThatTestsDoNotFail" \
  -Dtests.security.manager=true \
  -Dtests.locale=en-IE \
  -Dtests.timezone=Africa/Tripoli

Stack trace:

java.lang.AssertionError: Accounting breaker not reset to 0 on node: {node-0}{V8XMZi9FQLOkQk79I8dxvw}{raz_TS_pQISiiXGUBcPMuA}{127.0.0.1}{127.0.0.1:21360}{testattr=test}
Expected: <0L>
     but: was <2250L>
	at __randomizedtesting.SeedInfo.seed([9700B8DD0A76FCC8:3B7E65085E8C56E4]:0)
	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
	at org.junit.Assert.assertThat(Assert.java:956)
	at org.elasticsearch.test.ExternalTestCluster.ensureEstimatedStats(ExternalTestCluster.java:171)
	at org.elasticsearch.test.TestCluster.assertAfterTest(TestCluster.java:93)
	at org.elasticsearch.test.ESIntegTestCase.afterInternal(ESIntegTestCase.java:582)
	at org.elasticsearch.test.ESIntegTestCase.cleanUpCluster(ESIntegTestCase.java:2085)
	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:1713)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:965)
	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:916)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	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)

I see nothing else suspicious in the test output or in the logs on the worker. Sorry, not a lot to go on here.

[elasticmachine]

Pinging @elastic/es-core-infra

[jpountz]

This happened in a different test today: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+periodic/6494/consoleFull

14:45:41   2> REPRODUCE WITH: ./gradlew :x-pack:plugin:rollup:internalClusterTest -Dtests.seed=9C130591FD311456 -Dtests.class=org.elasticsearch.xpack.rollup.RollupIT -Dtests.method="testTwoJobsStartStopDeleteOne" -Dtests.security.manager=true -Dtests.locale=el-CY -Dtests.timezone=Brazil/Acre
14:45:41 FAILURE 1.76s | RollupIT.testTwoJobsStartStopDeleteOne <<< FAILURES!
14:45:41    > Throwable #1: java.lang.AssertionError: Accounting breaker not reset to 0 on node: node_sd3
14:45:41    > Expected: <0L>
14:45:41    >      but: was <4775L>
14:45:41    > 	at __randomizedtesting.SeedInfo.seed([9C130591FD311456:BA93A46A17310921]:0)
14:45:41    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
14:45:41    > 	at org.elasticsearch.test.InternalTestCluster.ensureEstimatedStats(InternalTestCluster.java:2016)
14:45:41    > 	at org.elasticsearch.test.TestCluster.assertAfterTest(TestCluster.java:93)
14:45:41    > 	at org.elasticsearch.test.InternalTestCluster.assertAfterTest(InternalTestCluster.java:2047)
14:45:41    > 	at org.elasticsearch.test.ESIntegTestCase.afterInternal(ESIntegTestCase.java:590)
14:45:41    > 	at org.elasticsearch.test.ESIntegTestCase.cleanUpCluster(ESIntegTestCase.java:2163)

[polyfractal]

Another one on that rollup test today:

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+periodic/6596/console

./gradlew :x-pack:plugin:rollup:internalClusterTest \
  -Dtests.seed=2CD38EA34BC1EAAC \
  -Dtests.class=org.elasticsearch.xpack.rollup.RollupIT \
  -Dtests.method="testTwoJobsStartStopDeleteOne" \
  -Dtests.security.manager=true \
  -Dtests.locale=sl-SI \
  -Dtests.timezone=America/Miquelon

When I get a chance I'll see if there's anything in common between the watcher test and this rollup one.

[droberts195]

And again on the rollup test:

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+intake/2014/console

./gradlew :x-pack:plugin:rollup:internalClusterTest \
  -Dtests.seed=1D037D5E37846F9 \
  -Dtests.class=org.elasticsearch.xpack.rollup.RollupIT \
  -Dtests.method="testTwoJobsStartStopDeleteOne" \
  -Dtests.security.manager=true \
  -Dtests.locale=es-CL \
  -Dtests.timezone=Pacific/Truk

The assertion is this:

16:24:57 FAILURE 7.00s | RollupIT.testTwoJobsStartStopDeleteOne <<< FAILURES!
16:24:57    > Throwable #1: java.lang.AssertionError: Accounting breaker not reset to 0 on node: node_s0
16:24:57    > Expected: <0L>
16:24:57    >      but: was <7042L>
16:24:57    > 	at __randomizedtesting.SeedInfo.seed([1D037D5E37846F9:2750962E09785B8E]:0)
16:24:57    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
16:24:57    > 	at org.elasticsearch.test.InternalTestCluster.ensureEstimatedStats(InternalTestCluster.java:2023)
16:24:57    > 	at org.elasticsearch.test.TestCluster.assertAfterTest(TestCluster.java:93)
16:24:57    > 	at org.elasticsearch.test.InternalTestCluster.assertAfterTest(InternalTestCluster.java:2054)
16:24:57    > 	at org.elasticsearch.test.ESIntegTestCase.afterInternal(ESIntegTestCase.java:586)
16:24:57    > 	at org.elasticsearch.test.ESIntegTestCase.cleanUpCluster(ESIntegTestCase.java:2153)
16:24:57    > 	at java.lang.Thread.run(Thread.java:748)

[polyfractal]

I looked into this a bit... no idea what's going on. The Rollup test isn't anything special (edit: and doesn not index any docs, like the earlier auditing failures were doing), and that watcher test is literally just:

public class PreventFailingBuildIT extends ESIntegTestCase {

    public void testSoThatTestsDoNotFail() {
        // Noop

        // This is required because if tests are not enable no
        // tests will be run in the entire project and all tests will fail.
    }
}

I'm likely going to delete all of RollupIT for unrelated reasons (see #31258 (comment)) but we can leave it enabled for now to debug this problem if desired, since it seems to be failing on that one Rollup test in particular. I can't reproduce locally though.

[vladimirdolzhenko]

same again

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-unix-compatibility/os=centos/2536/console

00:51:11 FAILURE 6.42s | RollupIT.testTwoJobsStartStopDeleteOne <<< FAILURES!
00:51:11    > Throwable #1: java.lang.AssertionError: Accounting breaker not reset to 0 on node: node_s0
00:51:11    > Expected: <0L>
00:51:11    >      but: was <11421L>
00:51:11    > 	at __randomizedtesting.SeedInfo.seed([698DCF0963902073:4F0D6EF289903D04]:0)
00:51:11    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
00:51:11    > 	at org.elasticsearch.test.InternalTestCluster.ensureEstimatedStats(InternalTestCluster.java:2020)
00:51:11    > 	at org.elasticsearch.test.TestCluster.assertAfterTest(TestCluster.java:93)
00:51:11    > 	at org.elasticsearch.test.InternalTestCluster.assertAfterTest(InternalTestCluster.java:2051)
00:51:11    > 	at org.elasticsearch.test.ESIntegTestCase.afterInternal(ESIntegTestCase.java:586)
00:51:11    > 	at org.elasticsearch.test.ESIntegTestCase.cleanUpCluster(ESIntegTestCase.java:2159)
00:51:11    > 	at java.lang.Thread.run(Thread.java:748)

[dnhatn]

Another instance https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+matrix-java-periodic/ES_BUILD_JAVA=java10,ES_RUNTIME_JAVA=java10,nodes=virtual&&linux/158/console

16:10:08 FAILURE 4.58s J1 | ShrinkIndexIT.testShrinkIndexPrimaryTerm <<< FAILURES!
16:10:08    > Throwable #1: java.lang.AssertionError: Accounting breaker not reset to 0 on node: node_s2
16:10:08    > Expected: <0L>
16:10:08    >      but: was <1322L>
16:10:08    > 	at __randomizedtesting.SeedInfo.seed([2A7F48E21D6F8FBF:F37D7B03379AF2]:0)
16:10:08    > 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
16:10:08    > 	at org.elasticsearch.test.InternalTestCluster.ensureEstimatedStats(InternalTestCluster.java:2020)
16:10:08    > 	at org.elasticsearch.test.TestCluster.assertAfterTest(TestCluster.java:93)
16:10:08    > 	at org.elasticsearch.test.InternalTestCluster.assertAfterTest(InternalTestCluster.java:2051)
16:10:08    > 	at org.elasticsearch.test.ESIntegTestCase.afterInternal(ESIntegTestCase.java:592)
16:10:08    > 	at org.elasticsearch.test.ESIntegTestCase.cleanUpCluster(ESIntegTestCase.java:2185)
16:10:08    > 	at jdk.internal.reflect.GeneratedMethodAccessor8.invoke(Unknown Source)
16:10:08    > 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
16:10:08    > 	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
16:10:08    > 	at java.base/java.lang.Thread.run(Thread.java:844)