[CI] TransformContinuousIT.testContinousEvents failing

[mark-vieira]

This started failing often recently. Also average runtime have increased in the same time period so something is going on here.

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

Repro line:
./gradlew ':x-pack:plugin:transform:qa:multi-node-tests:javaRestTest' --tests "org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.testContinousEvents" -Dtests.seed=CE925CC7CF87CC0F -Dtests.security.manager=true -Dtests.locale=ar-SD -Dtests.timezone=America/Cancun -Druntime.java=8

Reproduces locally?:
Didn't reproduce for me.

Applicable branches:
master and 7.x

Failure history:
https://gradle-enterprise.elastic.co/scans/tests?search.relativeStartTime=P7D&search.timeZoneId=America/Los_Angeles&tests.container=org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT&tests.disabledDistributions=WyJvdXRjb21lOnBhc3NlZCJd&tests.sortField=FAILED&tests.test=testContinousEvents&tests.unstableOnly=true

Failure excerpt:

org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT > testContinousEvents FAILED
    java.lang.AssertionError: transform [continuous-histogram-pivot-test] does not progress, state: INDEXING, reason: null
    Expected: a value greater than <1608062383906L>
         but: <1608062360729L> was less than <1608062383906L>
        at __randomizedtesting.SeedInfo.seed([CE925CC7CF87CC0F:F5A42DDC45EC4E59]:0)
        at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18)
        at org.junit.Assert.assertThat(Assert.java:956)
        at org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.lambda$waitUntilTransformsReachedUpperBound$3(TransformContinuousIT.java:499)
        at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:1014)
        at org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.waitUntilTransformsReachedUpperBound(TransformContinuousIT.java:497)
        at org.elasticsearch.xpack.transform.integration.continuous.TransformContinuousIT.testContinousEvents(TransformContinuousIT.java:275)

[elasticmachine]

Pinging @elastic/ml-core (:ml/Transform)

[przemekwitek]

I'm seeing a number of errors in the server logs that relate to missing ingest pipeline:

x-pack/plugin/transform/qa/multi-node-tests/build/testclusters/javaRestTest-1/logs/javaRestTest_server.json:3161:{"type": "server", "timestamp": "2020-12-16T05:03:03,358Z", "level": "DEBUG", "component": "o.e.x.t.t.ClientTransformIndexer", "cluster.name": "javaRestTest", "node.name": "javaRestTest-1", "message": "[continuous-histogram-pivot-test] Bulk index experienced [10] failures and at least 1 irrecoverable [pipeline with id [transform-ingest] does not exist].", "cluster.uuid": "8J1ypiXkSF2_EIxJXslouA", "node.id": "KW0_s_TuSB2Rfzlw-TodSQ"  }
x-pack/plugin/transform/qa/multi-node-tests/build/testclusters/javaRestTest-1/logs/javaRestTest_server.json:3163:"stacktrace": ["org.elasticsearch.xpack.transform.transforms.BulkIndexingException: Bulk index experienced [10] failures and at least 1 irrecoverable [pipeline with id [transform-ingest] does not exist]. Other failures: ",
x-pack/plugin/transform/qa/multi-node-tests/build/testclusters/javaRestTest-1/logs/javaRestTest_server.json:3181:"Caused by: java.lang.IllegalArgumentException: pipeline with id [transform-ingest] does not exist",

Investigating...

[hendrikmuhs]

Also average runtime have increased in the same time period so something is going on here.

2 days ago I merged coverage for runtime fields, I think that explains the increased runtime. Whether that change also caused the failures sounds likely but is hard to say without inspecting the logs. We currently have a lot of commits (and breaks) coming in.

It would be good to improve error handling in the test to e.g. log the used configuration (the test suite uses a randomized permutation of elasticsearch features). In the past we have seen failures using a certain set of features (e.g. index sort). So this might help to find the common feature quicker.

[przemekwitek]

One more thing that may be related to the increased runtime of this test is that we moved it from single node to multi node a few days ago.
@hendrikmuhs, could you think of ways it could potentially affect correctness?

It would be good to improve error handling in the test to e.g. log the used configuration (the test suite uses a randomized permutation of elasticsearch features). In the past we have seen failures using a certain set of features (e.g. index sort). So this might help to find the common feature quicker.

I'm doing that as part of debugging. I'll raise a PR soon.

[hendrikmuhs]

One more thing that may be related to the increased runtime of this test is that we moved it from single node to multi node a few days ago.
@hendrikmuhs, could you think of ways it could potentially affect correctness?

No, it should work the same way as before. I can only imagine the runtime increase.