Failing ES promotion: machine learning data frame analytics total feature importance panel and decision path popover binary classification job should display the feature importance decision path in the data grid #90526
A failing ML test is currently blocking the promotion of ES snapshots for master and 7.12. This test seems to be failing consistently using a snapshot built from latest ES source, so it seems likely that it's due to some change in ES.
```
[00:00:00] │
[00:00:00] └-: machine learning
[00:00:00] └-> "before all" hook in "machine learning"
[00:00:00] └-:
[00:00:00] └-> "before all" hook in ""
[00:00:00] └-> "before all" hook in ""
[00:00:00] │ debg creating role ft_ml_source
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_ml_source]
[00:00:00] │ debg creating role ft_ml_source_readonly
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_ml_source_readonly]
[00:00:00] │ debg creating role ft_ml_dest
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_ml_dest]
[00:00:00] │ debg creating role ft_ml_dest_readonly
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_ml_dest_readonly]
[00:00:00] │ debg creating role ft_ml_ui_extras
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_ml_ui_extras]
[00:00:00] │ debg creating role ft_default_space_ml_all
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_default_space_ml_all]
[00:00:00] │ debg creating role ft_default_space1_ml_all
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_default_space1_ml_all]
[00:00:00] │ debg creating role ft_all_spaces_ml_all
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_all_spaces_ml_all]
[00:00:00] │ debg creating role ft_default_space_ml_read
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_default_space_ml_read]
[00:00:00] │ debg creating role ft_default_space1_ml_read
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_default_space1_ml_read]
[00:00:00] │ debg creating role ft_all_spaces_ml_read
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_all_spaces_ml_read]
[00:00:00] │ debg creating role ft_default_space_ml_none
[00:00:00] │ info [o.e.x.s.a.r.TransportPutRoleAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added role [ft_default_space_ml_none]
[00:00:00] │ debg creating user ft_ml_poweruser
[00:00:00] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_poweruser]
[00:00:00] │ debg created user ft_ml_poweruser
[00:00:00] │ debg creating user ft_ml_poweruser_spaces
[00:00:00] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_poweruser_spaces]
[00:00:00] │ debg created user ft_ml_poweruser_spaces
[00:00:00] │ debg creating user ft_ml_poweruser_space1
[00:00:00] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_poweruser_space1]
[00:00:00] │ debg created user ft_ml_poweruser_space1
[00:00:00] │ debg creating user ft_ml_poweruser_all_spaces
[00:00:00] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_poweruser_all_spaces]
[00:00:00] │ debg created user ft_ml_poweruser_all_spaces
[00:00:00] │ debg creating user ft_ml_viewer
[00:00:01] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_viewer]
[00:00:01] │ debg created user ft_ml_viewer
[00:00:01] │ debg creating user ft_ml_viewer_spaces
[00:00:01] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_viewer_spaces]
[00:00:01] │ debg created user ft_ml_viewer_spaces
[00:00:01] │ debg creating user ft_ml_viewer_space1
[00:00:01] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_viewer_space1]
[00:00:01] │ debg created user ft_ml_viewer_space1
[00:00:01] │ debg creating user ft_ml_viewer_all_spaces
[00:00:01] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_viewer_all_spaces]
[00:00:01] │ debg created user ft_ml_viewer_all_spaces
[00:00:01] │ debg creating user ft_ml_unauthorized
[00:00:01] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_unauthorized]
[00:00:01] │ debg created user ft_ml_unauthorized
[00:00:01] │ debg creating user ft_ml_unauthorized_spaces
[00:00:01] │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] added user [ft_ml_unauthorized_spaces]
[00:00:01] │ debg created user ft_ml_unauthorized_spaces
[00:42:44] └-: data frame analytics
[00:42:44] └-> "before all" hook in "data frame analytics"
[00:45:59] └-: total feature importance panel and decision path popover
[00:45:59] └-> "before all" hook in "total feature importance panel and decision path popover"
[00:45:59] └-> "before all" hook in "total feature importance panel and decision path popover"
[00:45:59] │ debg applying update to kibana config: {"dateFormat:tz":"UTC"}
[00:46:00] │ debg SecurityPage.forceLogout
[00:46:00] │ debg Find.existsByDisplayedByCssSelector('.login-form') with timeout=100
[00:46:00] │ debg --- retry.tryForTime error: .login-form is not displayed
[00:46:01] │ debg Redirecting to /logout to force the logout
[00:46:01] │ debg Waiting on the login form to appear
[00:46:01] │ debg Waiting for Login Page to appear.
[00:46:01] │ debg Waiting up to 100000ms for login page...
[00:46:01] │ debg browser[INFO] http://localhost:6131/logout?_t=1612562689460 341 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:46:01] │
[00:46:01] │ debg browser[INFO] http://localhost:6131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:46:01] │ debg Find.existsByDisplayedByCssSelector('.login-form') with timeout=2500
[00:46:03] │ERROR browser[SEVERE] http://localhost:6131/internal/security/me - Failed to load resource: the server responded with a status of 401 (Unauthorized)
[00:46:03] │ debg browser[INFO] http://localhost:6131/login?msg=LOGGED_OUT 341 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:46:03] │
[00:46:03] │ debg browser[INFO] http://localhost:6131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:46:03] │ debg --- retry.tryForTime error: .login-form is not displayed
[00:46:04] │ERROR browser[SEVERE] http://localhost:6131/internal/spaces/_active_space - Failed to load resource: the server responded with a status of 401 (Unauthorized)
[00:46:04] │ERROR browser[SEVERE] http://localhost:6131/internal/security/me - Failed to load resource: the server responded with a status of 401 (Unauthorized)
[00:46:04] │ debg browser[INFO] http://localhost:6131/40201/bundles/core/core.entry.js 12:159324 "Detected an unhandled Promise rejection.
[00:46:04] │ Error: Unauthorized"
[00:46:04] │ERROR browser[SEVERE] http://localhost:6131/40201/bundles/core/core.entry.js 5:3002
[00:46:04] │ERROR browser[SEVERE] http://localhost:6131/api/licensing/info - Failed to load resource: the server responded with a status of 401 (Unauthorized)
[00:46:04] │ debg Find.existsByDisplayedByCssSelector('.login-form') with timeout=2500
[00:46:05] │ debg TestSubjects.exists(loginForm)
[00:46:05] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="loginForm"]') with timeout=2500
[00:46:05] │ debg Waiting for Login Form to appear.
[00:46:05] │ debg Waiting up to 100000ms for login form...
[00:46:05] │ debg TestSubjects.exists(loginForm)
[00:46:05] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="loginForm"]') with timeout=2500
[00:46:05] │ debg TestSubjects.setValue(loginUsername, ft_ml_poweruser)
[00:46:05] │ debg TestSubjects.click(loginUsername)
[00:46:05] │ debg Find.clickByCssSelector('[data-test-subj="loginUsername"]') with timeout=10000
[00:46:05] │ debg Find.findByCssSelector('[data-test-subj="loginUsername"]') with timeout=10000
[00:46:05] │ debg TestSubjects.setValue(loginPassword, mlp001)
[00:46:05] │ debg TestSubjects.click(loginPassword)
[00:46:05] │ debg Find.clickByCssSelector('[data-test-subj="loginPassword"]') with timeout=10000
[00:46:05] │ debg Find.findByCssSelector('[data-test-subj="loginPassword"]') with timeout=10000
[00:46:05] │ debg TestSubjects.click(loginSubmit)
[00:46:05] │ debg Find.clickByCssSelector('[data-test-subj="loginSubmit"]') with timeout=10000
[00:46:05] │ debg Find.findByCssSelector('[data-test-subj="loginSubmit"]') with timeout=10000
[00:46:05] │ debg Waiting for login result, expected: chrome.
[00:46:05] │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"] .app-wrapper:not(.hidden-chrome)') with timeout=20000
[00:46:05] │ proc [kibana] log [22:04:53.789] [info][plugins][routes][security] Logging in with provider "basic" (basic)
[00:46:07] │ debg browser[INFO] http://localhost:6131/app/home 341 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:46:07] │
[00:46:07] │ debg browser[INFO] http://localhost:6131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:46:07] │ debg Finished login process currentUrl = http://localhost:6131/app/home#/
[00:46:07] │ debg Waiting up to 20000ms for logout button visible...
[00:46:07] │ debg TestSubjects.exists(userMenuButton)
[00:46:07] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="userMenuButton"]') with timeout=2500
[00:46:07] │ debg TestSubjects.exists(userMenu)
[00:46:07] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="userMenu"]') with timeout=2500
[00:46:09] │ debg --- retry.tryForTime error: [data-test-subj="userMenu"] is not displayed
[00:46:10] │ debg TestSubjects.click(userMenuButton)
[00:46:10] │ debg Find.clickByCssSelector('[data-test-subj="userMenuButton"]') with timeout=10000
[00:46:10] │ debg Find.findByCssSelector('[data-test-subj="userMenuButton"]') with timeout=10000
[00:46:10] │ debg TestSubjects.exists(userMenu)
[00:46:10] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="userMenu"]') with timeout=120000
[00:46:10] │ debg TestSubjects.exists(userMenu > logoutLink)
[00:46:10] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="userMenu"] [data-test-subj="logoutLink"]') with timeout=2500
[00:46:10] │ info [ml/ihp_outlier] Loading "mappings.json"
[00:46:10] │ info [ml/ihp_outlier] Loading "data.json.gz"
[00:46:10] │ info [ml/ihp_outlier] Skipped restore for existing index "ft_ihp_outlier"
[00:46:10] │ debg Searching for 'index-pattern' with title 'ft_ihp_outlier'...
[00:46:10] │ debg > Found 'e83f55e0-67f7-11eb-adb3-879a9bac9bac'
[00:46:10] │ debg Index pattern with title 'ft_ihp_outlier' already exists. Nothing to create.
[00:46:10] │ debg Creating data frame analytic job with id 'ihp_fi_binary_1612559927491' ...
[00:46:10] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [.ml-config] creating index, cause [auto(bulk api)], templates [], shards [1]/[1]
[00:46:10] │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] updating number_of_replicas to [0] for indices [.ml-config]
[00:46:10] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [.ml-annotations-6] creating index, cause [api], templates [], shards [1]/[1]
[00:46:10] │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] updating number_of_replicas to [0] for indices [.ml-annotations-6]
[00:46:10] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [.ml-notifications-000001] creating index, cause [auto(bulk api)], templates [.ml-notifications-000001], shards [1]/[1]
[00:46:10] │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] updating number_of_replicas to [0] for indices [.ml-notifications-000001]
[00:46:11] │ debg Waiting up to 5000ms for 'ihp_fi_binary_1612559927491' to exist...
[00:46:11] │ debg Fetching data frame analytics job 'ihp_fi_binary_1612559927491'...
[00:46:11] │ debg > DFA job fetched.
[00:46:11] │ debg > DFA job created.
[00:46:11] │ debg Starting data frame analytics job 'ihp_fi_binary_1612559927491'...
[00:46:11] │ info [o.e.x.m.a.TransportStartDataFrameAnalyticsAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Starting data frame analytics from state [stopped]
[00:46:11] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [.ml-inference-000003] creating index, cause [api], templates [], shards [1]/[1]
[00:46:11] │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] updating number_of_replicas to [0] for indices [.ml-inference-000003]
[00:46:11] │ info [o.e.x.c.m.u.MlIndexAndAlias] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] About to create first concrete index [.ml-state-000001] with alias [.ml-state-write]
[00:46:11] │ debg > DFA job started.
[00:46:11] │ debg Waiting up to 60000ms for 'ihp_fi_binary_1612559927491' to have training_docs_count > 0...
[00:46:11] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:11] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [.ml-state-000001] creating index, cause [api], templates [.ml-state], shards [1]/[1]
[00:46:11] │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] updating number_of_replicas to [0] for indices [.ml-state-000001]
[00:46:11] │ debg > DFA job stats fetched.
[00:46:11] │ debg --- retry.waitForWithTimeout error: expected data frame analytics job 'ihp_fi_binary_1612559927491' to have training_docs_count > 0 (got 0)
[00:46:11] │ info [o.e.x.i.IndexLifecycleTransition] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] moving index [.ml-state-000001] from [null] to [{"phase":"new","action":"complete","name":"complete"}] in policy [ml-size-based-ilm-policy]
[00:46:11] │ info [o.e.x.c.m.u.MlIndexAndAlias] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] About to create first concrete index [.ml-stats-000001] with alias [.ml-stats-write]
[00:46:11] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [.ml-stats-000001] creating index, cause [api], templates [.ml-stats], shards [1]/[1]
[00:46:11] │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] updating number_of_replicas to [0] for indices [.ml-stats-000001]
[00:46:11] │ info [o.e.x.i.IndexLifecycleTransition] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] moving index [.ml-state-000001] from [{"phase":"new","action":"complete","name":"complete"}] to [{"phase":"hot","action":"unfollow","name":"wait-for-indexing-complete"}] in policy [ml-size-based-ilm-policy]
[00:46:11] │ info [o.e.x.i.IndexLifecycleTransition] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] moving index [.ml-stats-000001] from [null] to [{"phase":"new","action":"complete","name":"complete"}] in policy [ml-size-based-ilm-policy]
[00:46:11] │ info [o.e.x.m.d.s.ReindexingStep] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Creating destination index [user-ihp_fi_binary_1612559927491]
[00:46:11] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [user-ihp_fi_binary_1612559927491] creating index, cause [api], templates [], shards [1]/[1]
[00:46:11] │ info [o.e.x.i.IndexLifecycleTransition] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] moving index [.ml-state-000001] from [{"phase":"hot","action":"unfollow","name":"wait-for-indexing-complete"}] to [{"phase":"hot","action":"unfollow","name":"wait-for-follow-shard-tasks"}] in policy [ml-size-based-ilm-policy]
[00:46:11] │ info [o.e.x.m.d.s.ReindexingStep] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Started reindexing
[00:46:11] │ info [o.e.x.i.IndexLifecycleTransition] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] moving index [.ml-stats-000001] from [{"phase":"new","action":"complete","name":"complete"}] to [{"phase":"hot","action":"unfollow","name":"wait-for-indexing-complete"}] in policy [ml-size-based-ilm-policy]
[00:46:12] │ info [o.e.x.i.IndexLifecycleTransition] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] moving index [.ml-stats-000001] from [{"phase":"hot","action":"unfollow","name":"wait-for-indexing-complete"}] to [{"phase":"hot","action":"unfollow","name":"wait-for-follow-shard-tasks"}] in policy [ml-size-based-ilm-policy]
[00:46:12] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:12] │ debg > DFA job stats fetched.
[00:46:12] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:12] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Started loading data
[00:46:12] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Started analyzing
[00:46:12] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Waiting for result processor to complete
[00:46:12] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:12] │ debg > DFA job stats fetched.
[00:46:12] │ debg Waiting up to 120000ms for analytics state to be stopped...
[00:46:12] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:12] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:12] │ debg > DFA job stats fetched.
[00:46:12] │ debg --- retry.waitForWithTimeout error: expected analytics state to be stopped but got started
[00:46:13] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:13] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:13] │ debg > DFA job stats fetched.
[00:46:13] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:13] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:13] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:13] │ debg > DFA job stats fetched.
[00:46:13] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:14] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:14] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:14] │ debg > DFA job stats fetched.
[00:46:14] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:14] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:14] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:14] │ debg > DFA job stats fetched.
[00:46:14] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:15] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:15] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:15] │ debg > DFA job stats fetched.
[00:46:15] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:15] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:15] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:15] │ debg > DFA job stats fetched.
[00:46:15] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:16] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:16] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:16] │ debg > DFA job stats fetched.
[00:46:16] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:16] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:16] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:16] │ debg > DFA job stats fetched.
[00:46:16] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:17] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:17] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:17] │ debg > DFA job stats fetched.
[00:46:17] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:17] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:17] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:17] │ debg > DFA job stats fetched.
[00:46:17] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:18] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:18] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:18] │ debg > DFA job stats fetched.
[00:46:18] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:18] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:18] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:18] │ debg > DFA job stats fetched.
[00:46:18] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:19] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:19] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:19] │ debg > DFA job stats fetched.
[00:46:19] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:19] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:19] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:19] │ debg > DFA job stats fetched.
[00:46:19] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:20] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:20] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:20] │ debg > DFA job stats fetched.
[00:46:20] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:20] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:20] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:20] │ debg > DFA job stats fetched.
[00:46:20] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:21] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:21] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:21] │ debg > DFA job stats fetched.
[00:46:21] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:22] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:22] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:22] │ debg > DFA job stats fetched.
[00:46:22] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:22] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:22] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:22] │ debg > DFA job stats fetched.
[00:46:22] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:23] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:23] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:23] │ debg > DFA job stats fetched.
[00:46:23] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:23] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:23] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:23] │ debg > DFA job stats fetched.
[00:46:23] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:24] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:24] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:24] │ debg > DFA job stats fetched.
[00:46:24] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:24] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:24] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:24] │ debg > DFA job stats fetched.
[00:46:24] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:25] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:25] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:25] │ debg > DFA job stats fetched.
[00:46:25] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:25] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:25] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:25] │ debg > DFA job stats fetched.
[00:46:25] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:26] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:26] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:26] │ debg > DFA job stats fetched.
[00:46:26] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:26] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:26] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:26] │ debg > DFA job stats fetched.
[00:46:26] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:27] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:27] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:27] │ debg > DFA job stats fetched.
[00:46:27] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:27] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:27] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:27] │ debg > DFA job stats fetched.
[00:46:27] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:27] │ info [o.e.x.m.p.l.CppLogMessageHandler] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] [data_frame_analyzer/170462] [CBoostedTreeImpl.cc@245] Hyperparameter selection failed: exiting loop early
[00:46:27] │ info [o.e.x.m.d.p.ChunkedTrainedModelPersister] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] finished storing trained model with id [ihp_fi_binary_1612559927491-1612562716304]
[00:46:27] │ info [o.e.x.m.d.p.AnalyticsResultProcessor] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Started writing results
[00:46:28] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:28] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:28] │ debg > DFA job stats fetched.
[00:46:28] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:28] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Result processor has completed
[00:46:28] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Closing process
[00:46:28] │ info [o.e.x.m.p.l.CppLogMessageHandler] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] [data_frame_analyzer/170462] [Main.cc@241] [{"name":"E_DFTPMEstimatedPeakMemoryUsage","description":"The upfront estimate of the peak memory training the predictive model would use","value":6040636}
[00:46:28] │ ,{"name":"E_DFTPMPeakMemoryUsage","description":"The peak memory training the predictive model used","value":344315}
[00:46:28] │ ,{"name":"E_DFTPMTimeToTrain","description":"The time it took to train the predictive model","value":15293}
[00:46:28] │ ,{"name":"E_DFTPMTrainedForestNumberTrees","description":"The total number of trees in the trained forest","value":127}
[00:46:28] │ ]
[00:46:28] │ info [o.e.x.m.p.AbstractNativeProcess] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] State output finished
[00:46:28] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Closed process
[00:46:28] │ info [o.e.x.m.d.i.InferenceRunner] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Started inference on test data against model [ihp_fi_binary_1612559927491-1612562716304]
[00:46:28] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:28] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:28] │ debg > DFA job stats fetched.
[00:46:28] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:28] │ info [o.e.x.m.d.DataFrameAnalyticsManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_binary_1612559927491] Marking task completed
[00:46:29] │ debg Fetching analytics state for job ihp_fi_binary_1612559927491
[00:46:29] │ debg Fetching data frame analytics job stats for job ihp_fi_binary_1612559927491...
[00:46:29] │ debg > DFA job stats fetched.
[00:46:29] │ info [ml/ihp_outlier] Loading "mappings.json"
[00:46:29] │ info [ml/ihp_outlier] Loading "data.json.gz"
[00:46:29] │ info [ml/ihp_outlier] Skipped restore for existing index "ft_ihp_outlier"
[00:46:29] │ debg Searching for 'index-pattern' with title 'ft_ihp_outlier'...
[00:46:29] │ debg > Found 'e83f55e0-67f7-11eb-adb3-879a9bac9bac'
[00:46:29] │ debg Index pattern with title 'ft_ihp_outlier' already exists. Nothing to create.
[00:46:29] │ debg Creating data frame analytic job with id 'ihp_fi_multi_1612559927491' ...
[00:46:29] │ debg Waiting up to 5000ms for 'ihp_fi_multi_1612559927491' to exist...
[00:46:29] │ debg Fetching data frame analytics job 'ihp_fi_multi_1612559927491'...
[00:46:29] │ debg > DFA job fetched.
[00:46:29] │ debg > DFA job created.
[00:46:29] │ debg Starting data frame analytics job 'ihp_fi_multi_1612559927491'...
[00:46:29] │ info [o.e.x.m.a.TransportStartDataFrameAnalyticsAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Starting data frame analytics from state [stopped]
[00:46:29] │ debg > DFA job started.
[00:46:29] │ debg Waiting up to 60000ms for 'ihp_fi_multi_1612559927491' to have training_docs_count > 0...
[00:46:29] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:29] │ info [o.e.x.m.d.s.ReindexingStep] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Creating destination index [user-ihp_fi_multi_1612559927491]
[00:46:29] │ debg > DFA job stats fetched.
[00:46:29] │ debg --- retry.waitForWithTimeout error: expected data frame analytics job 'ihp_fi_multi_1612559927491' to have training_docs_count > 0 (got 0)
[00:46:29] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [user-ihp_fi_multi_1612559927491] creating index, cause [api], templates [], shards [1]/[1]
[00:46:29] │ info [o.e.x.m.d.s.ReindexingStep] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Started reindexing
[00:46:30] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:30] │ debg > DFA job stats fetched.
[00:46:30] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:30] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Started loading data
[00:46:30] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Started analyzing
[00:46:30] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Waiting for result processor to complete
[00:46:30] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:30] │ debg > DFA job stats fetched.
[00:46:30] │ debg Waiting up to 120000ms for analytics state to be stopped...
[00:46:30] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:30] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:30] │ debg > DFA job stats fetched.
[00:46:30] │ debg --- retry.waitForWithTimeout error: expected analytics state to be stopped but got started
[00:46:31] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:31] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:31] │ debg > DFA job stats fetched.
[00:46:31] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:31] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:31] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:31] │ debg > DFA job stats fetched.
[00:46:31] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:32] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:32] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:32] │ debg > DFA job stats fetched.
[00:46:32] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:32] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:32] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:32] │ debg > DFA job stats fetched.
[00:46:32] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:33] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:33] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:33] │ debg > DFA job stats fetched.
[00:46:33] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:33] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:33] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:33] │ debg > DFA job stats fetched.
[00:46:33] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:34] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:34] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:34] │ debg > DFA job stats fetched.
[00:46:34] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:34] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:34] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:34] │ debg > DFA job stats fetched.
[00:46:34] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:35] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:35] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:35] │ debg > DFA job stats fetched.
[00:46:35] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:35] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:35] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:35] │ debg > DFA job stats fetched.
[00:46:35] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:36] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:36] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:36] │ debg > DFA job stats fetched.
[00:46:36] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:36] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:36] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:36] │ debg > DFA job stats fetched.
[00:46:36] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:37] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:37] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:37] │ debg > DFA job stats fetched.
[00:46:37] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:37] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:37] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:37] │ debg > DFA job stats fetched.
[00:46:37] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:38] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:38] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:38] │ debg > DFA job stats fetched.
[00:46:38] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:38] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:38] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:38] │ debg > DFA job stats fetched.
[00:46:38] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:39] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:39] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:39] │ debg > DFA job stats fetched.
[00:46:39] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:39] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:39] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:39] │ debg > DFA job stats fetched.
[00:46:39] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:40] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:40] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:40] │ debg > DFA job stats fetched.
[00:46:40] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:41] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:41] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:41] │ debg > DFA job stats fetched.
[00:46:41] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:41] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:41] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:41] │ debg > DFA job stats fetched.
[00:46:41] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:42] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:42] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:42] │ debg > DFA job stats fetched.
[00:46:42] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:42] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:42] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:42] │ debg > DFA job stats fetched.
[00:46:42] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:43] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:43] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:43] │ debg > DFA job stats fetched.
[00:46:43] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:43] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:43] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:43] │ debg > DFA job stats fetched.
[00:46:43] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:44] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:44] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:44] │ debg > DFA job stats fetched.
[00:46:44] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:44] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:44] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:44] │ debg > DFA job stats fetched.
[00:46:44] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:45] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:45] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:45] │ debg > DFA job stats fetched.
[00:46:45] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:45] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:45] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:45] │ debg > DFA job stats fetched.
[00:46:45] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:46] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:46] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:46] │ debg > DFA job stats fetched.
[00:46:46] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:46] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:46] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:46] │ debg > DFA job stats fetched.
[00:46:46] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:47] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:47] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:47] │ debg > DFA job stats fetched.
[00:46:47] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:47] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:47] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:47] │ debg > DFA job stats fetched.
[00:46:47] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:48] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:48] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:48] │ debg > DFA job stats fetched.
[00:46:48] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:48] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:48] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:48] │ debg > DFA job stats fetched.
[00:46:48] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:49] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:49] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:49] │ debg > DFA job stats fetched.
[00:46:49] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:49] │ info [o.e.x.m.p.l.CppLogMessageHandler] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] [data_frame_analyzer/170534] [CBoostedTreeImpl.cc@245] Hyperparameter selection failed: exiting loop early
[00:46:49] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:49] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:49] │ debg > DFA job stats fetched.
[00:46:49] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:49] │ info [o.e.x.m.d.p.ChunkedTrainedModelPersister] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] finished storing trained model with id [ihp_fi_multi_1612559927491-1612562738254]
[00:46:49] │ info [o.e.x.m.d.p.AnalyticsResultProcessor] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Started writing results
[00:46:50] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Result processor has completed
[00:46:50] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Closing process
[00:46:50] │ info [o.e.x.m.p.l.CppLogMessageHandler] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] [data_frame_analyzer/170534] [Main.cc@241] [{"name":"E_DFTPMEstimatedPeakMemoryUsage","description":"The upfront estimate of the peak memory training the predictive model would use","value":9613500}
[00:46:50] │ ,{"name":"E_DFTPMPeakMemoryUsage","description":"The peak memory training the predictive model used","value":1443809}
[00:46:50] │ ,{"name":"E_DFTPMTimeToTrain","description":"The time it took to train the predictive model","value":19309}
[00:46:50] │ ,{"name":"E_DFTPMTrainedForestNumberTrees","description":"The total number of trees in the trained forest","value":22}
[00:46:50] │ ]
[00:46:50] │ info [o.e.x.m.p.AbstractNativeProcess] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] State output finished
[00:46:50] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Closed process
[00:46:50] │ info [o.e.x.m.d.i.InferenceRunner] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Started inference on test data against model [ihp_fi_multi_1612559927491-1612562738254]
[00:46:50] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:50] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:50] │ debg > DFA job stats fetched.
[00:46:50] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:50] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:50] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:50] │ debg > DFA job stats fetched.
[00:46:50] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:50] │ info [o.e.x.m.d.DataFrameAnalyticsManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [ihp_fi_multi_1612559927491] Marking task completed
[00:46:51] │ debg Fetching analytics state for job ihp_fi_multi_1612559927491
[00:46:51] │ debg Fetching data frame analytics job stats for job ihp_fi_multi_1612559927491...
[00:46:51] │ debg > DFA job stats fetched.
[00:46:51] │ info [ml/egs_regression] Loading "mappings.json"
[00:46:51] │ info [ml/egs_regression] Loading "data.json.gz"
[00:46:51] │ info [ml/egs_regression] Skipped restore for existing index "ft_egs_regression"
[00:46:51] │ debg Searching for 'index-pattern' with title 'ft_egs_regression'...
[00:46:51] │ debg > Found 'd1ea1d60-67fd-11eb-adb3-879a9bac9bac'
[00:46:51] │ debg Index pattern with title 'ft_egs_regression' already exists. Nothing to create.
[00:46:51] │ debg Creating data frame analytic job with id 'egs_fi_reg_1612559927491' ...
[00:46:51] │ debg Waiting up to 5000ms for 'egs_fi_reg_1612559927491' to exist...
[00:46:51] │ debg Fetching data frame analytics job 'egs_fi_reg_1612559927491'...
[00:46:51] │ debg > DFA job fetched.
[00:46:51] │ debg > DFA job created.
[00:46:51] │ debg Starting data frame analytics job 'egs_fi_reg_1612559927491'...
[00:46:51] │ info [o.e.x.m.a.TransportStartDataFrameAnalyticsAction] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Starting data frame analytics from state [stopped]
[00:46:51] │ debg > DFA job started.
[00:46:51] │ debg Waiting up to 60000ms for 'egs_fi_reg_1612559927491' to have training_docs_count > 0...
[00:46:51] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:51] │ info [o.e.x.m.d.s.ReindexingStep] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Creating destination index [user-egs_fi_reg_1612559927491]
[00:46:51] │ debg > DFA job stats fetched.
[00:46:51] │ debg --- retry.waitForWithTimeout error: expected data frame analytics job 'egs_fi_reg_1612559927491' to have training_docs_count > 0 (got 0)
[00:46:51] │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [user-egs_fi_reg_1612559927491] creating index, cause [api], templates [], shards [1]/[1]
[00:46:51] │ info [o.e.x.m.d.s.ReindexingStep] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Started reindexing
[00:46:52] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:52] │ debg > DFA job stats fetched.
[00:46:52] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:52] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Started loading data
[00:46:52] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Started analyzing
[00:46:52] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Waiting for result processor to complete
[00:46:52] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:52] │ debg > DFA job stats fetched.
[00:46:52] │ debg Waiting up to 120000ms for analytics state to be stopped...
[00:46:52] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:52] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:52] │ debg > DFA job stats fetched.
[00:46:52] │ debg --- retry.waitForWithTimeout error: expected analytics state to be stopped but got started
[00:46:53] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:53] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:53] │ debg > DFA job stats fetched.
[00:46:53] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:53] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:53] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:53] │ debg > DFA job stats fetched.
[00:46:53] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:54] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:54] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:54] │ debg > DFA job stats fetched.
[00:46:54] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:54] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:54] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:54] │ debg > DFA job stats fetched.
[00:46:54] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:55] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:55] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:55] │ debg > DFA job stats fetched.
[00:46:55] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:55] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:55] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:55] │ debg > DFA job stats fetched.
[00:46:55] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:56] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:56] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:56] │ debg > DFA job stats fetched.
[00:46:56] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:56] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:56] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:56] │ debg > DFA job stats fetched.
[00:46:56] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:57] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:57] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:57] │ debg > DFA job stats fetched.
[00:46:57] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:57] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:57] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:57] │ debg > DFA job stats fetched.
[00:46:57] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:58] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:58] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:58] │ debg > DFA job stats fetched.
[00:46:58] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:58] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:58] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:58] │ debg > DFA job stats fetched.
[00:46:58] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:59] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:59] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:59] │ debg > DFA job stats fetched.
[00:46:59] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:46:59] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:46:59] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:46:59] │ debg > DFA job stats fetched.
[00:46:59] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:00] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:00] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:00] │ debg > DFA job stats fetched.
[00:47:00] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:00] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:00] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:00] │ debg > DFA job stats fetched.
[00:47:00] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:01] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:01] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:01] │ debg > DFA job stats fetched.
[00:47:01] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:01] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:01] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:02] │ debg > DFA job stats fetched.
[00:47:02] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:02] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:02] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:02] │ debg > DFA job stats fetched.
[00:47:02] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:03] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:03] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:03] │ debg > DFA job stats fetched.
[00:47:03] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:03] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:03] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:03] │ debg > DFA job stats fetched.
[00:47:03] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:04] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:04] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:04] │ debg > DFA job stats fetched.
[00:47:04] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:04] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:04] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:04] │ debg > DFA job stats fetched.
[00:47:04] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:05] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:05] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:05] │ debg > DFA job stats fetched.
[00:47:05] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:05] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:05] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:05] │ debg > DFA job stats fetched.
[00:47:05] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:06] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:06] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:06] │ debg > DFA job stats fetched.
[00:47:06] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:06] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:06] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:06] │ debg > DFA job stats fetched.
[00:47:06] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:07] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:07] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:07] │ debg > DFA job stats fetched.
[00:47:07] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:07] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:07] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:07] │ debg > DFA job stats fetched.
[00:47:07] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:08] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:08] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:08] │ debg > DFA job stats fetched.
[00:47:08] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:08] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:08] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:08] │ debg > DFA job stats fetched.
[00:47:08] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:09] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:09] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:09] │ debg > DFA job stats fetched.
[00:47:09] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:09] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:09] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:09] │ debg > DFA job stats fetched.
[00:47:09] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:10] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:10] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:10] │ debg > DFA job stats fetched.
[00:47:10] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:10] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:10] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:10] │ debg > DFA job stats fetched.
[00:47:10] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:11] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:11] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:11] │ debg > DFA job stats fetched.
[00:47:11] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:11] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:11] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:11] │ debg > DFA job stats fetched.
[00:47:11] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:12] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:12] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:12] │ debg > DFA job stats fetched.
[00:47:12] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:12] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:12] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:12] │ debg > DFA job stats fetched.
[00:47:12] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:13] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:13] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:13] │ debg > DFA job stats fetched.
[00:47:13] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:13] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:13] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:13] │ debg > DFA job stats fetched.
[00:47:13] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:14] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:14] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:14] │ debg > DFA job stats fetched.
[00:47:14] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:14] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:14] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:14] │ debg > DFA job stats fetched.
[00:47:14] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:15] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:15] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:15] │ debg > DFA job stats fetched.
[00:47:15] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:15] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:15] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:15] │ debg > DFA job stats fetched.
[00:47:15] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:16] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:16] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:16] │ debg > DFA job stats fetched.
[00:47:16] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:16] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:16] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:16] │ debg > DFA job stats fetched.
[00:47:16] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:16] │ info [o.e.x.m.p.l.CppLogMessageHandler] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] [data_frame_analyzer/170587] [CBoostedTreeImpl.cc@245] Hyperparameter selection failed: exiting loop early
[00:47:17] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:17] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:17] │ debg > DFA job stats fetched.
[00:47:17] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:17] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:17] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:17] │ debg > DFA job stats fetched.
[00:47:17] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:18] │ info [o.e.x.m.d.p.ChunkedTrainedModelPersister] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] finished storing trained model with id [egs_fi_reg_1612559927491-1612562766435]
[00:47:18] │ info [o.e.x.m.d.p.AnalyticsResultProcessor] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Started writing results
[00:47:18] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:18] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:18] │ debg > DFA job stats fetched.
[00:47:18] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:18] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Result processor has completed
[00:47:18] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Closing process
[00:47:18] │ info [o.e.x.m.p.l.CppLogMessageHandler] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] [data_frame_analyzer/170587] [Main.cc@241] [{"name":"E_DFTPMEstimatedPeakMemoryUsage","description":"The upfront estimate of the peak memory training the predictive model would use","value":7582544}
[00:47:18] │ ,{"name":"E_DFTPMPeakMemoryUsage","description":"The peak memory training the predictive model used","value":7402902}
[00:47:18] │ ,{"name":"E_DFTPMTimeToTrain","description":"The time it took to train the predictive model","value":25202}
[00:47:18] │ ,{"name":"E_DFTPMTrainedForestNumberTrees","description":"The total number of trees in the trained forest","value":380}
[00:47:18] │ ]
[00:47:18] │ info [o.e.x.m.p.AbstractNativeProcess] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] State output finished
[00:47:18] │ info [o.e.x.m.d.p.AnalyticsProcessManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Closed process
[00:47:18] │ info [o.e.x.m.d.i.InferenceRunner] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Started inference on test data against model [egs_fi_reg_1612559927491-1612562766435]
[00:47:18] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:18] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:18] │ debg > DFA job stats fetched.
[00:47:18] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:19] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:19] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:19] │ debg > DFA job stats fetched.
[00:47:19] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:19] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:19] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:19] │ debg > DFA job stats fetched.
[00:47:19] │ debg --- retry.waitForWithTimeout failed again with the same message...
[00:47:19] │ info [o.e.x.m.d.DataFrameAnalyticsManager] [kibana-ci-immutable-debian-tests-xl-1612554727656914853] [egs_fi_reg_1612559927491] Marking task completed
[00:47:20] │ debg Fetching analytics state for job egs_fi_reg_1612559927491
[00:47:20] │ debg Fetching data frame analytics job stats for job egs_fi_reg_1612559927491...
[00:47:20] │ debg > DFA job stats fetched.
[00:47:20] └-: binary classification job
[00:47:20] └-> "before all" hook for "should display the total feature importance in the results view"
[00:47:20] └-> "before all" hook for "should display the total feature importance in the results view"
[00:47:20] │ debg navigating to ml url: http://localhost:6131/app/ml
[00:47:20] │ debg navigate to: http://localhost:6131/app/ml
[00:47:20] │ debg browser[INFO] http://localhost:6131/app/ml?_t=1612562768727 341 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:47:20] │
[00:47:20] │ debg browser[INFO] http://localhost:6131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:47:20] │ debg ... sleep(700) start
[00:47:21] │ debg ... sleep(700) end
[00:47:21] │ debg returned from get, calling refresh
[00:47:21] │ERROR browser[SEVERE] http://localhost:6131/40201/bundles/core/core.entry.js 12:158376 TypeError: Failed to fetch
[00:47:21] │ at fetch_Fetch.fetchResponse (http://localhost:6131/40201/bundles/core/core.entry.js:6:32451)
[00:47:21] │ at async interceptResponse (http://localhost:6131/40201/bundles/core/core.entry.js:6:28637)
[00:47:21] │ at async http://localhost:6131/40201/bundles/core/core.entry.js:6:31117
[00:47:21] │ debg browser[INFO] http://localhost:6131/app/ml?_t=1612562768727 341 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:47:21] │
[00:47:21] │ debg browser[INFO] http://localhost:6131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:47:22] │ debg currentUrl = http://localhost:6131/app/ml
[00:47:22] │ appUrl = http://localhost:6131/app/ml
[00:47:22] │ debg TestSubjects.find(kibanaChrome)
[00:47:22] │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=60000
[00:47:22] │ debg ... sleep(501) start
[00:47:23] │ debg ... sleep(501) end
[00:47:23] │ debg in navigateTo url = http://localhost:6131/app/ml/overview
[00:47:23] │ debg --- retry.try error: URL changed, waiting for it to settle
[00:47:23] │ debg ... sleep(501) start
[00:47:24] │ debg ... sleep(501) end
[00:47:24] │ debg in navigateTo url = http://localhost:6131/app/ml/overview
[00:47:24] │ debg TestSubjects.exists(statusPageContainer)
[00:47:24] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="statusPageContainer"]') with timeout=2500
[00:47:26] │ debg --- retry.tryForTime error: [data-test-subj="statusPageContainer"] is not displayed
[00:47:27] │ debg TestSubjects.exists(mlApp)
[00:47:27] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlApp"]') with timeout=2000
[00:47:27] │ debg TestSubjects.click(~mlMainTab & ~dataFrameAnalytics)
[00:47:27] │ debg Find.clickByCssSelector('[data-test-subj~="mlMainTab"][data-test-subj~="dataFrameAnalytics"]') with timeout=10000
[00:47:27] │ debg Find.findByCssSelector('[data-test-subj~="mlMainTab"][data-test-subj~="dataFrameAnalytics"]') with timeout=10000
[00:47:27] │ debg TestSubjects.exists(~mlMainTab & ~dataFrameAnalytics & ~selected)
[00:47:27] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj~="mlMainTab"][data-test-subj~="dataFrameAnalytics"][data-test-subj~="selected"]') with timeout=120000
[00:47:27] │ debg TestSubjects.exists(mlPageDataFrameAnalytics)
[00:47:27] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlPageDataFrameAnalytics"]') with timeout=120000
[00:47:27] │ debg TestSubjects.exists(~mlAnalyticsTable)
[00:47:27] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj~="mlAnalyticsTable"]') with timeout=60000
[00:47:28] │ debg TestSubjects.exists(mlAnalyticsTable loaded)
[00:47:28] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlAnalyticsTable loaded"]') with timeout=30000
[00:47:28] │ debg TestSubjects.exists(~mlAnalyticsTable > ~row-ihp_fi_binary_1612559927491 > mlAnalyticsJobViewButton)
[00:47:28] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj~="mlAnalyticsTable"] [data-test-subj~="row-ihp_fi_binary_1612559927491"] [data-test-subj="mlAnalyticsJobViewButton"]') with timeout=120000
[00:47:28] │ debg TestSubjects.click(~mlAnalyticsTable > ~row-ihp_fi_binary_1612559927491 > mlAnalyticsJobViewButton)
[00:47:28] │ debg Find.clickByCssSelector('[data-test-subj~="mlAnalyticsTable"] [data-test-subj~="row-ihp_fi_binary_1612559927491"] [data-test-subj="mlAnalyticsJobViewButton"]') with timeout=10000
[00:47:28] │ debg Find.findByCssSelector('[data-test-subj~="mlAnalyticsTable"] [data-test-subj~="row-ihp_fi_binary_1612559927491"] [data-test-subj="mlAnalyticsJobViewButton"]') with timeout=10000
[00:47:28] │ debg TestSubjects.exists(mlPageDataFrameAnalyticsExploration)
[00:47:28] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlPageDataFrameAnalyticsExploration"]') with timeout=20000
[00:47:28] └-> should display the total feature importance in the results view
[00:47:28] └-> "before each" hook: global before each for "should display the total feature importance in the results view"
[00:47:28] │ debg TestSubjects.exists(mlDFExpandableSection-FeatureImportanceSummary)
[00:47:28] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlDFExpandableSection-FeatureImportanceSummary"]') with timeout=120000
[00:47:29] │ debg TestSubjects.exists(mlTotalFeatureImportanceChart)
[00:47:29] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlTotalFeatureImportanceChart"]') with timeout=5000
[00:47:29] └- ✓ pass (1.1s) "machine learning data frame analytics total feature importance panel and decision path popover binary classification job should display the total feature importance in the results view"
[00:47:29] └-> should display the feature importance decision path in the data grid
[00:47:29] └-> "before each" hook: global before each for "should display the feature importance decision path in the data grid"
[00:47:29] │ debg TestSubjects.exists(mlExplorationDataGrid loaded)
[00:47:29] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlExplorationDataGrid loaded"]') with timeout=5000
[00:47:29] │ debg TestSubjects.find(mlExplorationDataGrid loaded)
[00:47:29] │ debg Find.findByCssSelector('[data-test-subj="mlExplorationDataGrid loaded"]') with timeout=10000
[00:47:29] │ debg TestSubjects.find(mlExplorationDataGrid loaded)
[00:47:29] │ debg Find.findByCssSelector('[data-test-subj="mlExplorationDataGrid loaded"]') with timeout=10000
[00:47:29] │ debg TestSubjects.find(mlExplorationDataGrid loaded)
[00:47:29] │ debg Find.findByCssSelector('[data-test-subj="mlExplorationDataGrid loaded"]') with timeout=10000
[00:47:31] │ debg --- retry.tryForTime error: Expected data grid cell button to be visible
[00:47:32] │ debg TestSubjects.exists(mlDFADecisionPathPopover)
[00:47:32] │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="mlDFADecisionPathPopover"]') with timeout=120000
[00:47:34] │ debg --- retry.tryForTime error: [data-test-subj="mlDFADecisionPathPopover"] is not displayed
[00:47:37] │ debg --- retry.tryForTime failed again with the same message...
[00:47:40] │ debg --- retry.tryForTime failed again with the same message...
[00:47:43] │ debg --- retry.tryForTime failed again with the same message...
[00:47:46] │ debg --- retry.tryForTime failed again with the same message...
[00:47:49] │ debg --- retry.tryForTime failed again with the same message...
[00:47:52] │ debg --- retry.tryForTime failed again with the same message...
[00:47:56] │ debg --- retry.tryForTime failed again with the same message...
[00:47:59] │ debg --- retry.tryForTime failed again with the same message...
[00:48:02] │ debg --- retry.tryForTime failed again with the same message...
[00:48:05] │ debg --- retry.tryForTime failed again with the same message...
[00:48:08] │ debg --- retry.tryForTime failed again with the same message...
[00:48:11] │ debg --- retry.tryForTime failed again with the same message...
[00:48:14] │ debg --- retry.tryForTime failed again with the same message...
[00:48:17] │ debg --- retry.tryForTime failed again with the same message...
[00:48:20] │ debg --- retry.tryForTime failed again with the same message...
[00:48:23] │ debg --- retry.tryForTime failed again with the same message...
[00:48:26] │ debg --- retry.tryForTime failed again with the same message...
[00:48:29] │ debg --- retry.tryForTime failed again with the same message...
[00:48:32] │ debg --- retry.tryForTime failed again with the same message...
[00:48:35] │ debg --- retry.tryForTime failed again with the same message...
[00:48:38] │ debg --- retry.tryForTime failed again with the same message...
[00:48:41] │ debg --- retry.tryForTime failed again with the same message...
[00:48:44] │ debg --- retry.tryForTime failed again with the same message...
[00:48:47] │ debg --- retry.tryForTime failed again with the same message...
[00:48:50] │ debg --- retry.tryForTime failed again with the same message...
[00:48:53] │ debg --- retry.tryForTime failed again with the same message...
[00:48:56] │ debg --- retry.tryForTime failed again with the same message...
[00:48:59] │ debg --- retry.tryForTime failed again with the same message...
[00:49:02] │ debg --- retry.tryForTime failed again with the same message...
[00:49:05] │ debg --- retry.tryForTime failed again with the same message...
[00:49:08] │ debg --- retry.tryForTime failed again with the same message...
[00:49:11] │ debg --- retry.tryForTime failed again with the same message...
[00:49:14] │ debg --- retry.tryForTime failed again with the same message...
[00:49:17] │ debg --- retry.tryForTime failed again with the same message...
[00:49:21] │ debg --- retry.tryForTime failed again with the same message...
[00:49:24] │ debg --- retry.tryForTime failed again with the same message...
[00:49:27] │ debg --- retry.tryForTime failed again with the same message...
[00:49:30] │ debg --- retry.tryForTime failed again with the same message...
[00:49:33] │ debg --- retry.tryForTime failed again with the same message...
[00:49:33] │ info Taking screenshot "/dev/shm/workspace/kibana/x-pack/test/functional/screenshots/failure/machine learning data frame analytics total feature importance panel and decision path popover binary classification job should display the feature importance decision path in the data grid.png"
[00:49:33] │ info Current URL is: http://localhost:6131/app/ml/data_frame_analytics/exploration?_g=(ml%3A(analysisType%3Aclassification%2CjobId%3Aihp_fi_binary_1612559927491))
[00:49:33] │ info Saving page source to: /dev/shm/workspace/kibana/x-pack/test/functional/failure_debug/html/machine learning data frame analytics total feature importance panel and decision path popover binary classification job should display the feature importance decision path in the data grid.html
[00:49:33] └- ✖ fail: machine learning data frame analytics total feature importance panel and decision path popover binary classification job should display the feature importance decision path in the data grid
[00:49:33] │ Error: expected testSubject(mlDFADecisionPathPopover) to exist
[00:49:33] │ at TestSubjects.existOrFail (/dev/shm/workspace/kibana/test/functional/services/common/test_subjects.ts:51:15)
[00:49:33] │ at Object.openFeatureImportanceDecisionPathPopover (test/functional/services/ml/data_frame_analytics_results.ts:102:7)
[00:49:33] │ at Context. (test/functional/apps/ml/data_frame_analytics/feature_importance.ts:206:11)
[00:49:33] │ at Object.apply (/dev/shm/workspace/kibana/packages/kbn-test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)
[00:49:33] │
[00:49:33] │
```
A failing ML test is currently blocking the promotion of ES snapshots for master and 7.12. This test seems to be failing consistently using a snapshot built from latest ES source, so it seems likely that it's due to some change in ES.
Example here: https://kibana-ci.elastic.co/job/elasticsearch+snapshots+verify/2222/testReport/junit/Chrome%20X-Pack%20UI%20Functional%20Tests/x-pack_test_functional_apps_ml_data_frame_analytics_feature_importance%C2%B7ts/Kibana_Pipeline___kibana_xpack_agent___machine_learning__data_frame_analytics_total_feature_importance_panel_and_decision_path_popover_binary_classification_job_should_display_the_feature_importance_decision_path_in_the_data_grid/
See logs:
For more information on the Elasticsearch snapshot promotion process: https://www.elastic.co/guide/en/kibana/master/development-es-snapshots.html