[CI] TransformContinuousIT testContinousEvents failing

[DaveCTurner]

Didn't succeed locally but nor did I reproduce this failure - it was still running after 5m so I gave up waiting.

Build scan:
https://gradle-enterprise.elastic.co/s/zyaccxx3a3b6a/tests/:x-pack:plugin:transform:qa:multi-node-tests:javaRestTest/org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT/testContinousEvents

Reproduction line:
./gradlew ':x-pack:plugin:transform:qa:multi-node-tests:javaRestTest' --tests "org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.testContinousEvents" -Dtests.seed=1D8A7A1836C9021F -Dtests.locale=ro -Dtests.timezone=America/Rankin_Inlet -Druntime.java=11

Applicable branches:
master

Reproduces locally?:
No

Failure history:
https://gradle-enterprise.elastic.co/scans/tests?tests.container=org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT&tests.test=testContinousEvents

Failure excerpt:

java.lang.AssertionError: Error in test case [continuous-terms-pivot-test].If you want to mute the test, please mute [org.elasticsearch.xpack.transform.integration.continuous.TermsGroupByIT] only, but _not_ [org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT] as a whole.

  at __randomizedtesting.SeedInfo.seed([1D8A7A1836C9021F:26BC0B03BCA28049]:0)
  at org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.testContinousEvents(TransformContinuousIT.java:292)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
  at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:566)
  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.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:375)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:824)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:475)
  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.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 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:375)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:831)
  at java.lang.Thread.run(Thread.java:834)

  Caused by: java.lang.AssertionError: Number of buckets did not match, source: 0, expected: 49, iteration: 0
  Expected: <49L>
       but: was <0L>

    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18)
    at org.junit.Assert.assertThat(Assert.java:956)
    at org.elasticsearch.xpack.transform.integration.continuous.TermsGroupByIT.testIteration(TermsGroupByIT.java:108)
    at org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.testContinousEvents(TransformContinuousIT.java:283)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:566)
    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.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:375)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:824)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:475)
    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.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 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:375)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:831)
    at java.lang.Thread.run(Thread.java:834)

[elasticmachine]

Pinging @elastic/ml-core (Team:ML)

[hendrikmuhs]

I looked for relevant log lines:

[2021-09-06T12:07:37,103][DEBUG][o.e.x.t.t.TransformIndexer] [javaRestTest-1] [continuous-terms-pivot-test] Querying [test-transform-continuous-events] for data: {"size":0,"query":{"bool":{"filter":[{"match_all":{"boost":1.0}},{"range":{"timestamp":{"from":null,"to":1630930056063,"include_lower":true,"include_upper":false,"format":"epoch_millis","boost":1.0}}}],"boost":1.0}},"aggregations":{"_transform":{"composite":{"size":10,"sources":[{"event":{"terms":{"field":"event-upper","missing_bucket":false,"order":"asc"}}}]},"aggregations":{"run.max":{"max":{"field":"run"}},"count":{"value_count":{"field":"run"}},"time.max":{"max":{"field":"timestamp"}},"metric.avg":{"avg":{"field":"metric-rt-2x"}}}}}}
[2021-09-06T12:07:37,123][DEBUG][o.e.x.c.i.AsyncTwoPhaseIndexer] [javaRestTest-1] Finished indexing for job [continuous-terms-pivot-test], saving state and shutting down.
[2021-09-06T12:07:37,132][DEBUG][o.e.x.t.t.TransformIndexer] [javaRestTest-1] [continuous-terms-pivot-test] finished indexing for transform checkpoint [1].
[2021-09-06T12:07:37,132][DEBUG][o.e.x.t.t.TransformIndexer] [javaRestTest-1] [continuous-terms-pivot-test] updating persistent state of transform to [{"task_state":"started","indexer_state":"started","checkpoint":1,"progress":{"docs_remaining":0,"total_docs":0,"percent_complete":100.0,"docs_indexed":0,"docs_processed":0},"should_stop_at_checkpoint":false}].
[2021-09-06T12:07:37,157][DEBUG][o.e.x.t.t.ClientTransformIndexer] [javaRestTest-1] [continuous-terms-pivot-test] Updated state document from [null] to [{seqNo=7,primaryTerm=1,index=.transform-internal-007}]
[2021-09-06T12:07:37,492][DEBUG][o.e.x.t.t.TransformTask  ] [javaRestTest-1] [continuous-date-histogram-pivot-test] start called with state [{"task_state":"stopped","indexer_state":"stopped","checkpoint":0,"progress":{"docs_indexed":0,"docs_processed":0},"should_stop_at_checkpoint":false}].

The transform indexed 0 documents, and total_docs is reported 0, too.

total_docs comes from an independent search call. So 2 times 0 documents are returned by search. However the test is really a test suite sharing data with other tests, they report total_docs:983.

Another observation: All other transforms run on node 3 while this one was the only one executing on node 2. Could it be a serialization issue?

The tests started to fail on Sept 5th, no failures the days before. I will check the commit history tomorrow. I am not sure this is a transform issue.

[hendrikmuhs]

After some more investigation I am certain that this is a regression of #75839.