UpgradeClusterClientYamlTestSuiteIT timing stats test failures

[pgomulka]

Looks like this is a new test introduced on the 17th June. It fails frequently on master https://build-stats.elastic.co/app/kibana#/discover?_g=(refreshInterval:(pause:!t,value:0),time:(from:now-7d,mode:quick,to:now))&_a=(columns:!(_source),index:b646ed00-7efc-11e8-bf69-63c8ef516157,interval:auto,query:(language:lucene,query:'UpgradeClusterClientYamlTestSuiteIT%20AND%20%22Test%20get%20old%20cluster%20job!'s%20timing%20stats%22'),sort:!(process.time-start,desc))

Reproduce line (does not reproduce locally)

./gradlew :x-pack:qa:rolling-upgrade:v7.3.0#upgradedClusterTestRunner --tests "org.elasticsearch.upgrades.UpgradeClusterClientYamlTestSuiteIT.test {p0=upgraded_cluster/30_ml_jobs_crud/Test get old cluster job's timing stats}" -Dtests.seed=450CFDC224E9996A -Dtests.security.manager=true -Dtests.locale=dav-KE -Dtests.timezone=America/New_York -Dcompiler.java=12 -Druntime.java=11 -Dtests.rest.suite=upgraded_cluster

Possibly introduced by: 1ac725c

[elasticmachine]

Pinging @elastic/ml-core

[droberts195]

The "stash dump on failure" from the console log (https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/205/console) shows the problem:

04:06:31   1> [2019-06-18T00:06:31,277][INFO ][o.e.u.UpgradeClusterClientYamlTestSuiteIT] [test] Stash dump on test failure [{
04:06:31   1>   "stash" : {
04:06:31   1>     "body" : {
04:06:31   1>       "error" : {
04:06:31   1>         "root_cause" : [
04:06:31   1>           {
04:06:31   1>             "type" : "resource_not_found_exception",
04:06:31   1>             "reason" : "No known job with id 'old-cluster-job'",
04:06:31   1>             "stack_trace" : "ResourceNotFoundException[No known job with id 'old-cluster-job']
04:06:31   1> 	at org.elasticsearch.xpack.core.ml.utils.ExceptionsHelper.missingJobException(ExceptionsHelper.java:22)
04:06:31   1> 	at org.elasticsearch.xpack.ml.job.persistence.JobConfigProvider.lambda$expandJobsIds$5(JobConfigProvider.java:535)
04:06:31   1> 	at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:62)
04:06:31   1> 	at org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:43)
04:06:31   1> 	at org.elasticsearch.action.support.TransportAction$1.onResponse(TransportAction.java:68)
04:06:31   1> 	at org.elasticsearch.action.support.TransportAction$1.onResponse(TransportAction.java:64)
04:06:31   1> 	at org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:43)
04:06:31   1> 	at org.elasticsearch.action.search.AbstractSearchAsyncAction.onResponse(AbstractSearchAsyncAction.java:321)
04:06:31   1> 	at org.elasticsearch.action.search.AbstractSearchAsyncAction.onResponse(AbstractSearchAsyncAction.java:51)
04:06:31   1> 	at org.elasticsearch.action.search.FetchSearchPhase$3.run(FetchSearchPhase.java:213)
04:06:31   1> 	at org.elasticsearch.action.search.AbstractSearchAsyncAction.executePhase(AbstractSearchAsyncAction.java:171)
04:06:31   1> 	at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:165)
04:06:31   1> 	at org.elasticsearch.action.search.ExpandSearchPhase.run(ExpandSearchPhase.java:120)
04:06:31   1> 	at org.elasticsearch.action.search.AbstractSearchAsyncAction.executePhase(AbstractSearchAsyncAction.java:171)
04:06:31   1> 	at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:165)
04:06:31   1> 	at org.elasticsearch.action.search.FetchSearchPhase.moveToNextPhase(FetchSearchPhase.java:206)
04:06:31   1> 	at org.elasticsearch.action.search.FetchSearchPhase.lambda$innerRun$2(FetchSearchPhase.java:104)
04:06:31   1> 	at org.elasticsearch.action.search.FetchSearchPhase.innerRun(FetchSearchPhase.java:110)
04:06:31   1> 	at org.elasticsearch.action.search.FetchSearchPhase$1.doRun(FetchSearchPhase.java:86)
04:06:31   1> 	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
04:06:31   1> 	at org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:44)
04:06:31   1> 	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:757)
04:06:31   1> 	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
04:06:31   1> 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
04:06:31   1> 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
04:06:31   1> 	at java.base/java.lang.Thread.run(Thread.java:834)
04:06:31   1> "
04:06:31   1>           }
04:06:31   1>         ],

It's because the tests run in a random order and one of the others deletes the job.

Given the random ordering and the fact that the test needs to be skipped in some combinations of old and new versions I think the only solution is to create a completely separate job in the old cluster specially for testing the timing stats.

[przemekwitek]

It's because the tests run in a random order and one of the others deletes the job.

Given the random ordering and the fact that the test needs to be skipped in some combinations of old and new versions I think the only solution is to create a completely separate job in the old cluster specially for testing the timing stats.

Thanks for analyzing that, @droberts195 ! I agree with the conclusion and will do exactly that.