[CI] ForecastIT.testOverflowToDisk failing on EAR builds

[ywelsch]

This test has failed three times in the past 2 weeks

https://gradle-enterprise.elastic.co/s/mp3vxqny35j4e

Output:

org.elasticsearch.xpack.ml.integration.ForecastIT > testOverflowToDisk FAILED
    org.elasticsearch.ElasticsearchStatusException: Test likely fails due to insufficient disk space on test machine, please free up space.
        at __randomizedtesting.SeedInfo.seed([8263E7B83540FE6E:CDB359E25C3EF7DE]:0)
        at org.elasticsearch.xpack.ml.integration.ForecastIT.testOverflowToDisk(ForecastIT.java:244)

        Caused by:
        org.elasticsearch.ElasticsearchStatusException: Cannot run forecast: Forecast cannot be executed as models exceed internal memory limit and available disk space is insufficient Minimum disk space required: [200mb]
            at org.elasticsearch.xpack.core.ml.utils.ExceptionsHelper.badRequestException(ExceptionsHelper.java:75)
            at org.elasticsearch.xpack.ml.action.TransportForecastJobAction.lambda$getForecastRequestStats$2(TransportForecastJobAction.java:125)
            at org.elasticsearch.xpack.ml.job.persistence.JobResultsProvider.lambda$getForecastRequestStats$40(JobResultsProvider.java:1368)
            at org.elasticsearch.xpack.ml.job.persistence.JobResultsProvider.lambda$searchSingleResult$33(JobResultsProvider.java:1165)
            at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:63)
            at org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:43)
            at org.elasticsearch.client.node.NodeClient.lambda$executeLocally$0(NodeClient.java:91)
            at org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:175)
            at org.elasticsearch.tasks.TaskManager$1.onResponse(TaskManager.java:169)
            at org.elasticsearch.action.support.ContextPreservingActionListener.onResponse(ContextPreservingActionListener.java:43)
            at org.elasticsearch.action.search.AbstractSearchAsyncAction.sendSearchResponse(AbstractSearchAsyncAction.java:545)
            at org.elasticsearch.action.search.ExpandSearchPhase.run(ExpandSearchPhase.java:117)
            at org.elasticsearch.action.search.AbstractSearchAsyncAction.executePhase(AbstractSearchAsyncAction.java:350)
            at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:344)
            at org.elasticsearch.action.search.FetchSearchPhase.moveToNextPhase(FetchSearchPhase.java:231)
            at org.elasticsearch.action.search.FetchSearchPhase.lambda$innerRun$1(FetchSearchPhase.java:119)
            at org.elasticsearch.action.search.FetchSearchPhase.innerRun(FetchSearchPhase.java:125)
            at org.elasticsearch.action.search.FetchSearchPhase$1.doRun(FetchSearchPhase.java:95)
            at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
            at org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:44)
            at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:706)
            at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
            at java.lang.Thread.run(Thread.java:834)

I'm not too familiar with this part of the system, but wonder if we truly have less than 200mb available on disk when running the test (in that case we could possibly raise it as infrastructural issue), or if we should perhaps have the test skipped in case where these conditions are not met.

[elasticmachine]

Pinging @elastic/ml-core (:ml)

[pgomulka]

happen again on master https://gradle-enterprise.elastic.co/s/2zk4lmgz2gy6i

it looks like during that run indeed there was less then 200mb available https://infra-stats.elastic.co/app/kibana#/discover?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:'2020-07-03T07:00:00.000Z',to:'2020-07-03T07:30:00.000Z'))&_a=(columns:!(_source),index:'metricbeat-*',interval:auto,query:(language:kuery,query:elasticsearch-ci-immutable-u-1804-pkg-large-1593757207748855610),sort:!('@timestamp',desc))

[pgomulka]

@hendrikmuhs do you think we could add more debug information for this test? How much was disk available, what was the partition it was checking etc?

[droberts195]

All the failures are on "EAR" builds: encryption at rest.

It may mean that disk space is not the problem, but something to do with the encryption that's being misreported.

If you look at the C++ code that detects lack of disk space it returns false (on line 495) if it cannot obtain the amount of free disk space: https://github.com/elastic/ml-cpp/blob/edafba5165656ef617074e332268d7bdaba23922/lib/api/CForecastRunner.cc#L488-L499

This will get reported to the Java in the same way as actual lack of disk space, hence the misleading error message.

If there's a problem with the Boost.FileSystem library and the way EAR is implemented then we need to add a known issue that ML forecasting cannot be used if you are using EAR.

[droberts195]

I looked for "Failed to retrieve disk information for" in the server side logs of https://gradle-enterprise.elastic.co/s/2zk4lmgz2gy6i (obtained from https://storage.cloud.google.com/elasticsearch-ci-artifacts/jobs/elastic+elasticsearch+master+EAR/build/75.tar.bz2) and didn't see it, so either forecasting is looking for space on a partition that has very little available, or else the Boost.FileSystem library "succeeds" in getting free disk space but gets an incorrect amount.

I opened elastic/ml-cpp#1380 to add more logging to find out exactly which partition we're checking and how much space Boost.FileSystem thinks it has.