RollupDocumentationIT.testStartRollupJob fails

[javanna]

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

12:57:00 ERROR   0.36s | RollupDocumentationIT.testStartRollupJob <<< FAILURES!
12:57:00    > Throwable #1: org.elasticsearch.client.ResponseException: method [DELETE], host [http://[::1]:52535], URI [/_xpack/rollup/job/job_1], status line [HTTP/1.1 500 Internal Server Error]
12:57:00    > {"task_failures":[{"task_id":8905,"node_id":"FhzPJ_ibQoS6vX9AbmETzA","status":"INTERNAL_SERVER_ERROR","reason":{"type":"illegal_state_exception","reason":"Could not delete job [job_1] because indexer state is [STOPPING].  Job must be [STOPPED] before deletion."}}],"acknowledged":false}
12:57:00    > 	at __randomizedtesting.SeedInfo.seed([8485FBE4F308CC81:EB88BE3030DD61E3]:0)
12:57:00    > 	at org.elasticsearch.client.RestClient$SyncResponseListener.get(RestClient.java:687)
12:57:00    > 	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:218)
12:57:00    > 	at org.elasticsearch.client.documentation.RollupDocumentationIT.deleteRollupJobs(RollupDocumentationIT.java:437)
12:57:00    > 	at org.elasticsearch.client.documentation.RollupDocumentationIT.wipeRollup(RollupDocumentationIT.java:417)
12:57:00    > 	at java.lang.Thread.run(Thread.java:748)

Reproduce line (though does not repro locally):

REPRODUCE WITH: ./gradlew :client:rest-high-level:integTestRunner -Dtests.seed=8485FBE4F308CC81 -Dtests.class=org.elasticsearch.client.documentation.RollupDocumentationIT -Dtests.method="testStartRollupJob" -Dtests.security.manager=true -Dtests.locale=ru-RU -Dtests.timezone=Africa/Malabo -Dcompiler.java=11 -Druntime.java=8

[elasticmachine]

Pinging @elastic/es-search-aggs

[javanna]

@polyfractal this one looks like a timing issue where in some cases we delete the rollup jobs before they are stopped, but rather while they are stopping. Sounds like we should adapt the test?

[polyfractal]

Yeah, sounds like it. This behavior is caused by the recent #34574, but there is an awaitBusy that is supposed to stop this from happening (or fail).

I'll investigate today, thanks for the ping.

[alpar-t]

Another reproduction https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-unix-compatibility/os=centos/44/console
Build stats point to failures on 6.x also and 10-12 failures per week.
Will mute the tests.

[polyfractal]

I found the issue. RollupDocumentationIT has some old/obsolete cleanup code. It's no longer needed because the xpack cleanup code was moved into ESRestTestCase, but this class was missed during the refactor.

Removing the cleanup and using the superclass fixes the issue. Ran it for a few hundred iterations and it looks good. Unrelated, I also saw that we weren't checking the return result of an awaitBusy() and added an assertion.

Will push a fix and unmute these. Sorry for the noise all!

[mayya-sharipova]

This resurfaced again on 6.x. Seems to be a timeout issue.
Does NOT reproduce locally on 6.x for me.

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

REPRODUCE WITH: ./gradlew :client:rest-high-level:integTestRunner \
  -Dtests.seed=F86D6F8A86509455 \
  -Dtests.class=org.elasticsearch.client.documentation.RollupDocumentationIT \
  -Dtests.method="testStartRollupJob" \
  -Dtests.security.manager=true \
  -Dtests.locale=tr \
  -Dtests.timezone=Antarctica/South_Pole \
  -Dcompiler.java=11 \
  -Druntime.java=8

REPRODUCE WITH: ./gradlew :client:rest-high-level:integTestRunner \
  -Dtests.seed=F86D6F8A86509455 \
  -Dtests.class=org.elasticsearch.client.documentation.RollupDocumentationIT \
  -Dtests.method="testDeleteRollupJob" \
  -Dtests.security.manager=true \
  -Dtests.locale=tr \
  -Dtests.timezone=Antarctica/South_Pole \
  -Dcompiler.java=11 \
  -Druntime.java=8

REPRODUCE WITH: ./gradlew :client:rest-high-level:integTestRunner \
  -Dtests.seed=F86D6F8A86509455 \
  -Dtests.class=org.elasticsearch.client.documentation.RollupDocumentationIT \
  -Dtests.method="testDeleteRollupJob" \
  -Dtests.security.manager=true \
  -Dtests.locale=tr \
  -Dtests.timezone=Antarctica/South_Pole \
  -Dcompiler.java=11 \
  -Druntime.java=8

REPRODUCE WITH: ./gradlew :client:rest-high-level:integTestRunner \
  -Dtests.seed=F86D6F8A86509455 \
  -Dtests.class=org.elasticsearch.client.documentation.RollupDocumentationIT \
  -Dtests.method="testGetRollupCaps" \
  -Dtests.security.manager=true \
  -Dtests.locale=tr \
  -Dtests.timezone=Antarctica/South_Pole \
  -Dcompiler.java=11 \
  -Druntime.java=8

Relevant stacktrace:

17:46:20     > {"error":{"root_cause":[{"type":"timeout_exception","reason":"Timed out after [10s] while waiting for rollup job [job_1] to stop"}],"type":"timeout_exception","reason":"Timed out after [10s] while waiting for rollup job [job_1] to stop"},"status":500}
17:46:20     >  at __randomizedtesting.SeedInfo.seed([F86D6F8A86509455:97602A5E45853937]:0)
17:46:20     >  at org.elasticsearch.client.RestClient$SyncResponseListener.get(RestClient.java:929)
17:46:20     >  at org.elasticsearch.client.RestClient.performRequest(RestClient.java:229)
17:46:20     >  at org.elasticsearch.test.rest.ESRestTestCase.wipeRollupJobs(ESRestTestCase.java:570)
17:46:20     >  at org.elasticsearch.test.rest.ESRestTestCase.wipeCluster(ESRestTestCase.java:482)
17:46:20     >  at org.elasticsearch.test.rest.ESRestTestCase.cleanUpCluster(ESRestTestCase.java:263)
17:46:20     >  at java.lang.Thread.run(Thread.java:748)
17:46:20     > Caused by: org.elasticsearch.client.ResponseException: method [POST], host [http://[::1]:38195], URI [/_xpack/rollup/job/job_1/_stop?wait_for_completion=true&timeout=10s], status line [HTTP/1.1 500 Internal Server Error]
17:46:20     > {"error":{"root_cause":[{"type":"timeout_exception","reason":"Timed out after [10s] while waiting for rollup job [job_1] to stop"}],"type":"timeout_exception","reason":"Timed out after [10s] while waiting for rollup job [job_1] to stop"},"status":500}
17:46:20     >  at org.elasticsearch.client.RestClient$1.completed(RestClient.java:548)
17:46:20     >  at org.elasticsearch.client.RestClient$1.completed(RestClient.java:533)
17:46:20     >  at org.apache.http.concurrent.BasicFuture.completed(BasicFuture.java:119)
17:46:20     >  at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.responseCompleted(DefaultClientExchangeHandlerImpl.java:177)
17:46:20     >  at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.processResponse(HttpAsyncRequestExecutor.java:436)
17:46:20     >  at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(HttpAsyncRequestExecutor.java:326)
17:46:20     >  at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:265)
17:46:20     >  at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:81)
17:46:20     >  at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
17:46:20     >  at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:114)
17:46:20     >  at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
17:46:20     >  at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
17:46:20     >  at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
17:46:20     >  at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
17:46:20     >  at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
17:46:20     >  at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)