-
Notifications
You must be signed in to change notification settings - Fork 8.3k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
[ftr] Improve FTR error handling for NoSuchSessionError #161025
[ftr] Improve FTR error handling for NoSuchSessionError #161025
Conversation
public getClipboardValue(): Promise<string> { | ||
return this.driver.executeAsyncScript('navigator.clipboard.readText().then(arguments[0])'); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Unrelated to the main change, but I thought this update doesn't worth a separate PR
💚 Build Succeeded
Metrics [docs]Unknown metric groupsESLint disabled line counts
Total ESLint disabled count
History
To update your PR or re-run it, just comment with: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
## Summary Sometimes browser/driver process dies during test run on CI and FTR fails with errors cascade, good example is [here](https://buildkite.com/elastic/kibana-pull-request/builds/138535#0188fd74-9adf-4011-8168-1bdc6e3d0f17) Current behaviour on `main`: FTR lifecycle hooks, defined in [remote](https://github.com/elastic/kibana/blob/57aea91fae4f2d0a047ff9e2339eb61352f1d73d/test/functional/services/remote/remote.ts) service, has no access to the information about test suite run and particular test failure. These hooks are related to WebDriver (browser) state management and suppose to reset it to default state. Currently we silently fail screenshot taking which means tests execution is continued even if `--bail` flag is passed. It ends with cascade of failures with the same error `NoSuchSessionError: invalid session id` <details> <summary>FTR output on failure</summary> ``` └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' │ at Assertion.assert (expect.js:100:11) │ at Assertion.apply (expect.js:227:8) │ at Assertion.be (expect.js:69:22) │ at Context.<anonymous> (_discover.ts:53:31) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Object.apply (wrap_function.js:73:16) │ │ └-> "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count" └- ✖ fail: discover/group1 discover test query "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count" │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ └-> "after all" hook in "discover test" │ debg Cleaning all saved objects { space: undefined } │ succ deleted 2 objects └-> "after all" hook: afterTestSuite.trigger in "discover test" └- ✖ fail: discover/group1 discover test "after all" hook: afterTestSuite.trigger in "discover test" │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ └-> "after all" hook: unloadMakelogs in "discover/group1" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "mappings.json" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.22" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.20" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.21" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "data.json.gz" └-> "after all" hook: afterTestSuite.trigger in "discover/group1" └- ✖ fail: discover/group1 "after all" hook: afterTestSuite.trigger in "discover/group1" │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at runMicrotasks (<anonymous>) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ │ │0 passing (15.7s) │4 failing │ │1) discover/group1 │ discover test │ query │ should show correct time range string by timepicker: │ │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' │ at Assertion.assert (expect.js:100:11) │ at Assertion.apply (expect.js:227:8) │ at Assertion.be (expect.js:69:22) │ at Context.<anonymous> (_discover.ts:53:31) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Object.apply (wrap_function.js:73:16) │ │ │2) discover/group1 │ discover test │ query │ "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count": │ │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ │3) discover/group1 │ discover test │ "after all" hook: afterTestSuite.trigger in "discover test": │ │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ │4) discover/group1 │ "after all" hook: afterTestSuite.trigger in "discover/group1": │ │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at runMicrotasks (<anonymous>) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) ``` </details> This PR change: I didn't find a good reason why we need to fail silently on screenshot taking. I added a check WebDriver session status with `hasOpenWindow` and take failure artefacts only if is still valid. Next change is to fail FTR after hooks related to WebDriver silently: there is no help having cascade of the repeated stacktrace so I wrap WebDriver call in hooks with `tryWebDriverCall` that catches the error and only prints it for visibility. <details> <summary>FTR new output on failure</summary> ``` │ERROR WebDriver session is no longer valid. │ Probably Chrome process crashed when it tried to use more memory than what was available. │ERROR Browser is closed, no artifacts were captured for the failure └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' │ at Assertion.assert (expect.js:100:11) │ at Assertion.apply (expect.js:227:8) │ at Assertion.be (expect.js:69:22) │ at Context.<anonymous> (_discover.ts:53:31) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Object.apply (wrap_function.js:73:16) │ │ └-> "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count" │ERROR WebDriver session is no longer valid └-> "after all" hook in "discover test" │ debg Cleaning all saved objects { space: undefined } │ warn browser[SEVERE] ERROR FETCHING BROWSR LOGS: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used. │ succ deleted 2 objects └-> "after all" hook: afterTestSuite.trigger in "discover test" │ERROR WebDriver session is no longer valid └-> "after all" hook: unloadMakelogs in "discover/group1" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "mappings.json" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.22" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.20" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.21" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "data.json.gz" └-> "after all" hook: afterTestSuite.trigger in "discover/group1" │ERROR WebDriver session is no longer valid 0 passing (16.2s) 1 failing 1) discover/group1 discover test query should show correct time range string by timepicker: Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' at Assertion.assert (expect.js:100:11) at Assertion.apply (expect.js:227:8) at Assertion.be (expect.js:69:22) at Context.<anonymous> (_discover.ts:53:31) at processTicksAndRejections (node:internal/process/task_queues:96:5) at Object.apply (wrap_function.js:73:16) ``` </details> Flaky-test-runner verification: started 100x to hopefully catch invalid session on CI https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2539 Note: locally I was simulating it by calling `this.driver.close()` to close browser before screenshot taking (cherry picked from commit 8a95bf7)
## Summary Sometimes browser/driver process dies during test run on CI and FTR fails with errors cascade, good example is [here](https://buildkite.com/elastic/kibana-pull-request/builds/138535#0188fd74-9adf-4011-8168-1bdc6e3d0f17) Current behaviour on `main`: FTR lifecycle hooks, defined in [remote](https://github.com/elastic/kibana/blob/57aea91fae4f2d0a047ff9e2339eb61352f1d73d/test/functional/services/remote/remote.ts) service, has no access to the information about test suite run and particular test failure. These hooks are related to WebDriver (browser) state management and suppose to reset it to default state. Currently we silently fail screenshot taking which means tests execution is continued even if `--bail` flag is passed. It ends with cascade of failures with the same error `NoSuchSessionError: invalid session id` <details> <summary>FTR output on failure</summary> ``` └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' │ at Assertion.assert (expect.js:100:11) │ at Assertion.apply (expect.js:227:8) │ at Assertion.be (expect.js:69:22) │ at Context.<anonymous> (_discover.ts:53:31) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Object.apply (wrap_function.js:73:16) │ │ └-> "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count" └- ✖ fail: discover/group1 discover test query "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count" │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ └-> "after all" hook in "discover test" │ debg Cleaning all saved objects { space: undefined } │ succ deleted 2 objects └-> "after all" hook: afterTestSuite.trigger in "discover test" └- ✖ fail: discover/group1 discover test "after all" hook: afterTestSuite.trigger in "discover test" │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ └-> "after all" hook: unloadMakelogs in "discover/group1" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "mappings.json" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.22" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.20" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.21" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "data.json.gz" └-> "after all" hook: afterTestSuite.trigger in "discover/group1" └- ✖ fail: discover/group1 "after all" hook: afterTestSuite.trigger in "discover/group1" │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at runMicrotasks (<anonymous>) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ │ │0 passing (15.7s) │4 failing │ │1) discover/group1 │ discover test │ query │ should show correct time range string by timepicker: │ │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' │ at Assertion.assert (expect.js:100:11) │ at Assertion.apply (expect.js:227:8) │ at Assertion.be (expect.js:69:22) │ at Context.<anonymous> (_discover.ts:53:31) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Object.apply (wrap_function.js:73:16) │ │ │2) discover/group1 │ discover test │ query │ "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count": │ │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ │3) discover/group1 │ discover test │ "after all" hook: afterTestSuite.trigger in "discover test": │ │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) │ │ │4) discover/group1 │ "after all" hook: afterTestSuite.trigger in "discover/group1": │ │ NoSuchSessionError: invalid session id │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15) │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13) │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28) │ at runMicrotasks (<anonymous>) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Task.exec (prevent_parallel_calls.ts:28:20) ``` </details> This PR change: I didn't find a good reason why we need to fail silently on screenshot taking. I added a check WebDriver session status with `hasOpenWindow` and take failure artefacts only if is still valid. Next change is to fail FTR after hooks related to WebDriver silently: there is no help having cascade of the repeated stacktrace so I wrap WebDriver call in hooks with `tryWebDriverCall` that catches the error and only prints it for visibility. <details> <summary>FTR new output on failure</summary> ``` │ERROR WebDriver session is no longer valid. │ Probably Chrome process crashed when it tried to use more memory than what was available. │ERROR Browser is closed, no artifacts were captured for the failure └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' │ at Assertion.assert (expect.js:100:11) │ at Assertion.apply (expect.js:227:8) │ at Assertion.be (expect.js:69:22) │ at Context.<anonymous> (_discover.ts:53:31) │ at processTicksAndRejections (node:internal/process/task_queues:96:5) │ at Object.apply (wrap_function.js:73:16) │ │ └-> "after all" hook: afterTestSuite.trigger for "should reload the saved search with persisted query to show the initial hit count" │ERROR WebDriver session is no longer valid └-> "after all" hook in "discover test" │ debg Cleaning all saved objects { space: undefined } │ warn browser[SEVERE] ERROR FETCHING BROWSR LOGS: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used. │ succ deleted 2 objects └-> "after all" hook: afterTestSuite.trigger in "discover test" │ERROR WebDriver session is no longer valid └-> "after all" hook: unloadMakelogs in "discover/group1" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "mappings.json" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.22" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.20" │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index "logstash-2015.09.21" │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from "data.json.gz" └-> "after all" hook: afterTestSuite.trigger in "discover/group1" │ERROR WebDriver session is no longer valid 0 passing (16.2s) 1 failing 1) discover/group1 discover test query should show correct time range string by timepicker: Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000' at Assertion.assert (expect.js:100:11) at Assertion.apply (expect.js:227:8) at Assertion.be (expect.js:69:22) at Context.<anonymous> (_discover.ts:53:31) at processTicksAndRejections (node:internal/process/task_queues:96:5) at Object.apply (wrap_function.js:73:16) ``` </details> Flaky-test-runner verification: started 100x to hopefully catch invalid session on CI https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2539 Note: locally I was simulating it by calling `this.driver.close()` to close browser before screenshot taking (cherry picked from commit 8a95bf7)
💚 All backports created successfully
Note: Successful backport PRs will be merged automatically after passing CI. Questions ?Please refer to the Backport tool documentation |
… (#161207) # Backport This will backport the following commits from `main` to `8.9`: - [[ftr] Improve FTR error handling for NoSuchSessionError (#161025)](#161025) <!--- Backport version: 8.9.7 --> ### Questions ? Please refer to the [Backport tool documentation](https://github.com/sqren/backport) <!--BACKPORT [{"author":{"name":"Dzmitry Lemechko","email":"[email protected]"},"sourceCommit":{"committedDate":"2023-07-04T16:26:57Z","message":"[ftr] Improve FTR error handling for NoSuchSessionError (#161025)\n\n## Summary\r\n\r\nSometimes browser/driver process dies during test run on CI and FTR\r\nfails with errors cascade, good example is\r\n[here](https://buildkite.com/elastic/kibana-pull-request/builds/138535#0188fd74-9adf-4011-8168-1bdc6e3d0f17)\r\n\r\n\r\n\r\nCurrent behaviour on `main`: FTR lifecycle hooks, defined in\r\n[remote](https://github.com/elastic/kibana/blob/57aea91fae4f2d0a047ff9e2339eb61352f1d73d/test/functional/services/remote/remote.ts)\r\nservice, has no access to the information about test suite run and\r\nparticular test failure. These hooks are related to WebDriver (browser)\r\nstate management and suppose to reset it to default state.\r\nCurrently we silently fail screenshot taking which means tests execution\r\nis continued even if `--bail` flag is passed. It ends with cascade of\r\nfailures with the same error `NoSuchSessionError: invalid session id`\r\n\r\n<details>\r\n\r\n<summary>FTR output on failure</summary>\r\n\r\n```\r\n └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n └-> \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n └- ✖ fail: discover/group1 discover test query \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n └-> \"after all\" hook in \"discover test\"\r\n │ debg Cleaning all saved objects { space: undefined }\r\n │ succ deleted 2 objects\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n └- ✖ fail: discover/group1 discover test \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n └-> \"after all\" hook: unloadMakelogs in \"discover/group1\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"mappings.json\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.22\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.20\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.21\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"data.json.gz\"\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n └- ✖ fail: discover/group1 \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at runMicrotasks (<anonymous>)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │\r\n │0 passing (15.7s)\r\n │4 failing\r\n │\r\n │1) discover/group1\r\n │ discover test\r\n │ query\r\n │ should show correct time range string by timepicker:\r\n │\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n │2) discover/group1\r\n │ discover test\r\n │ query\r\n │ \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │3) discover/group1\r\n │ discover test\r\n │ \"after all\" hook: afterTestSuite.trigger in \"discover test\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │4) discover/group1\r\n │ \"after all\" hook: afterTestSuite.trigger in \"discover/group1\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at runMicrotasks (<anonymous>)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n```\r\n\r\n</details>\r\n\r\nThis PR change: I didn't find a good reason why we need to fail silently\r\non screenshot taking. I added a check WebDriver session status with\r\n`hasOpenWindow` and take failure artefacts only if is still valid.\r\nNext change is to fail FTR after hooks related to WebDriver silently:\r\nthere is no help having cascade of the repeated stacktrace so I wrap\r\nWebDriver call in hooks with `tryWebDriverCall` that catches the error\r\nand only prints it for visibility.\r\n\r\n<details>\r\n\r\n<summary>FTR new output on failure</summary>\r\n\r\n```\r\n │ERROR WebDriver session is no longer valid.\r\n │ Probably Chrome process crashed when it tried to use more memory than what was available.\r\n │ERROR Browser is closed, no artifacts were captured for the failure\r\n └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n └-> \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n │ERROR WebDriver session is no longer valid\r\n └-> \"after all\" hook in \"discover test\"\r\n │ debg Cleaning all saved objects { space: undefined }\r\n │ warn browser[SEVERE] ERROR FETCHING BROWSR LOGS: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.\r\n │ succ deleted 2 objects\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n │ERROR WebDriver session is no longer valid\r\n └-> \"after all\" hook: unloadMakelogs in \"discover/group1\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"mappings.json\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.22\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.20\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.21\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"data.json.gz\"\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n │ERROR WebDriver session is no longer valid\r\n\r\n0 passing (16.2s)\r\n1 failing\r\n\r\n1) discover/group1\r\n discover test\r\n query\r\n should show correct time range string by timepicker:\r\n\r\n Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n at Assertion.assert (expect.js:100:11)\r\n at Assertion.apply (expect.js:227:8)\r\n at Assertion.be (expect.js:69:22)\r\n at Context.<anonymous> (_discover.ts:53:31)\r\n at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n at Object.apply (wrap_function.js:73:16)\r\n```\r\n\r\n</details>\r\n\r\n\r\nFlaky-test-runner verification: started 100x to hopefully catch invalid\r\nsession on CI\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2539\r\nNote: locally I was simulating it by calling `this.driver.close()` to\r\nclose browser before screenshot taking","sha":"8a95bf7fabe34c601725313c922f95ee0fa641e5","branchLabelMapping":{"^v8.10.0$":"main","^v(\\d+).(\\d+).\\d+$":"$1.$2"}},"sourcePullRequest":{"labels":["release_note:skip","v8.9.0","v8.10.0","v8.8.3"],"number":161025,"url":"https://github.com/elastic/kibana/pull/161025","mergeCommit":{"message":"[ftr] Improve FTR error handling for NoSuchSessionError (#161025)\n\n## Summary\r\n\r\nSometimes browser/driver process dies during test run on CI and FTR\r\nfails with errors cascade, good example is\r\n[here](https://buildkite.com/elastic/kibana-pull-request/builds/138535#0188fd74-9adf-4011-8168-1bdc6e3d0f17)\r\n\r\n\r\n\r\nCurrent behaviour on `main`: FTR lifecycle hooks, defined in\r\n[remote](https://github.com/elastic/kibana/blob/57aea91fae4f2d0a047ff9e2339eb61352f1d73d/test/functional/services/remote/remote.ts)\r\nservice, has no access to the information about test suite run and\r\nparticular test failure. These hooks are related to WebDriver (browser)\r\nstate management and suppose to reset it to default state.\r\nCurrently we silently fail screenshot taking which means tests execution\r\nis continued even if `--bail` flag is passed. It ends with cascade of\r\nfailures with the same error `NoSuchSessionError: invalid session id`\r\n\r\n<details>\r\n\r\n<summary>FTR output on failure</summary>\r\n\r\n```\r\n └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n └-> \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n └- ✖ fail: discover/group1 discover test query \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n └-> \"after all\" hook in \"discover test\"\r\n │ debg Cleaning all saved objects { space: undefined }\r\n │ succ deleted 2 objects\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n └- ✖ fail: discover/group1 discover test \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n └-> \"after all\" hook: unloadMakelogs in \"discover/group1\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"mappings.json\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.22\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.20\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.21\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"data.json.gz\"\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n └- ✖ fail: discover/group1 \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at runMicrotasks (<anonymous>)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │\r\n │0 passing (15.7s)\r\n │4 failing\r\n │\r\n │1) discover/group1\r\n │ discover test\r\n │ query\r\n │ should show correct time range string by timepicker:\r\n │\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n │2) discover/group1\r\n │ discover test\r\n │ query\r\n │ \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │3) discover/group1\r\n │ discover test\r\n │ \"after all\" hook: afterTestSuite.trigger in \"discover test\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │4) discover/group1\r\n │ \"after all\" hook: afterTestSuite.trigger in \"discover/group1\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at runMicrotasks (<anonymous>)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n```\r\n\r\n</details>\r\n\r\nThis PR change: I didn't find a good reason why we need to fail silently\r\non screenshot taking. I added a check WebDriver session status with\r\n`hasOpenWindow` and take failure artefacts only if is still valid.\r\nNext change is to fail FTR after hooks related to WebDriver silently:\r\nthere is no help having cascade of the repeated stacktrace so I wrap\r\nWebDriver call in hooks with `tryWebDriverCall` that catches the error\r\nand only prints it for visibility.\r\n\r\n<details>\r\n\r\n<summary>FTR new output on failure</summary>\r\n\r\n```\r\n │ERROR WebDriver session is no longer valid.\r\n │ Probably Chrome process crashed when it tried to use more memory than what was available.\r\n │ERROR Browser is closed, no artifacts were captured for the failure\r\n └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n └-> \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n │ERROR WebDriver session is no longer valid\r\n └-> \"after all\" hook in \"discover test\"\r\n │ debg Cleaning all saved objects { space: undefined }\r\n │ warn browser[SEVERE] ERROR FETCHING BROWSR LOGS: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.\r\n │ succ deleted 2 objects\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n │ERROR WebDriver session is no longer valid\r\n └-> \"after all\" hook: unloadMakelogs in \"discover/group1\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"mappings.json\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.22\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.20\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.21\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"data.json.gz\"\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n │ERROR WebDriver session is no longer valid\r\n\r\n0 passing (16.2s)\r\n1 failing\r\n\r\n1) discover/group1\r\n discover test\r\n query\r\n should show correct time range string by timepicker:\r\n\r\n Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n at Assertion.assert (expect.js:100:11)\r\n at Assertion.apply (expect.js:227:8)\r\n at Assertion.be (expect.js:69:22)\r\n at Context.<anonymous> (_discover.ts:53:31)\r\n at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n at Object.apply (wrap_function.js:73:16)\r\n```\r\n\r\n</details>\r\n\r\n\r\nFlaky-test-runner verification: started 100x to hopefully catch invalid\r\nsession on CI\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2539\r\nNote: locally I was simulating it by calling `this.driver.close()` to\r\nclose browser before screenshot taking","sha":"8a95bf7fabe34c601725313c922f95ee0fa641e5"}},"sourceBranch":"main","suggestedTargetBranches":["8.9","8.8"],"targetPullRequestStates":[{"branch":"8.9","label":"v8.9.0","labelRegex":"^v(\\d+).(\\d+).\\d+$","isSourceBranch":false,"state":"NOT_CREATED"},{"branch":"main","label":"v8.10.0","labelRegex":"^v8.10.0$","isSourceBranch":true,"state":"MERGED","url":"https://github.com/elastic/kibana/pull/161025","number":161025,"mergeCommit":{"message":"[ftr] Improve FTR error handling for NoSuchSessionError (#161025)\n\n## Summary\r\n\r\nSometimes browser/driver process dies during test run on CI and FTR\r\nfails with errors cascade, good example is\r\n[here](https://buildkite.com/elastic/kibana-pull-request/builds/138535#0188fd74-9adf-4011-8168-1bdc6e3d0f17)\r\n\r\n\r\n\r\nCurrent behaviour on `main`: FTR lifecycle hooks, defined in\r\n[remote](https://github.com/elastic/kibana/blob/57aea91fae4f2d0a047ff9e2339eb61352f1d73d/test/functional/services/remote/remote.ts)\r\nservice, has no access to the information about test suite run and\r\nparticular test failure. These hooks are related to WebDriver (browser)\r\nstate management and suppose to reset it to default state.\r\nCurrently we silently fail screenshot taking which means tests execution\r\nis continued even if `--bail` flag is passed. It ends with cascade of\r\nfailures with the same error `NoSuchSessionError: invalid session id`\r\n\r\n<details>\r\n\r\n<summary>FTR output on failure</summary>\r\n\r\n```\r\n └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n └-> \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n └- ✖ fail: discover/group1 discover test query \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n └-> \"after all\" hook in \"discover test\"\r\n │ debg Cleaning all saved objects { space: undefined }\r\n │ succ deleted 2 objects\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n └- ✖ fail: discover/group1 discover test \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n └-> \"after all\" hook: unloadMakelogs in \"discover/group1\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"mappings.json\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.22\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.20\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.21\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"data.json.gz\"\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n └- ✖ fail: discover/group1 \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at runMicrotasks (<anonymous>)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │\r\n │0 passing (15.7s)\r\n │4 failing\r\n │\r\n │1) discover/group1\r\n │ discover test\r\n │ query\r\n │ should show correct time range string by timepicker:\r\n │\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n │2) discover/group1\r\n │ discover test\r\n │ query\r\n │ \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │3) discover/group1\r\n │ discover test\r\n │ \"after all\" hook: afterTestSuite.trigger in \"discover test\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n │\r\n │\r\n │4) discover/group1\r\n │ \"after all\" hook: afterTestSuite.trigger in \"discover/group1\":\r\n │\r\n │ NoSuchSessionError: invalid session id\r\n │ at Object.throwDecodedError (node_modules/selenium-webdriver/lib/error.js:524:15)\r\n │ at parseHttpResponse (node_modules/selenium-webdriver/lib/http.js:601:13)\r\n │ at Executor.execute (node_modules/selenium-webdriver/lib/http.js:529:28)\r\n │ at runMicrotasks (<anonymous>)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Task.exec (prevent_parallel_calls.ts:28:20)\r\n```\r\n\r\n</details>\r\n\r\nThis PR change: I didn't find a good reason why we need to fail silently\r\non screenshot taking. I added a check WebDriver session status with\r\n`hasOpenWindow` and take failure artefacts only if is still valid.\r\nNext change is to fail FTR after hooks related to WebDriver silently:\r\nthere is no help having cascade of the repeated stacktrace so I wrap\r\nWebDriver call in hooks with `tryWebDriverCall` that catches the error\r\nand only prints it for visibility.\r\n\r\n<details>\r\n\r\n<summary>FTR new output on failure</summary>\r\n\r\n```\r\n │ERROR WebDriver session is no longer valid.\r\n │ Probably Chrome process crashed when it tried to use more memory than what was available.\r\n │ERROR Browser is closed, no artifacts were captured for the failure\r\n └- ✖ fail: discover/group1 discover test query should show correct time range string by timepicker\r\n │ Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n │ at Assertion.assert (expect.js:100:11)\r\n │ at Assertion.apply (expect.js:227:8)\r\n │ at Assertion.be (expect.js:69:22)\r\n │ at Context.<anonymous> (_discover.ts:53:31)\r\n │ at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n │ at Object.apply (wrap_function.js:73:16)\r\n │\r\n │\r\n └-> \"after all\" hook: afterTestSuite.trigger for \"should reload the saved search with persisted query to show the initial hit count\"\r\n │ERROR WebDriver session is no longer valid\r\n └-> \"after all\" hook in \"discover test\"\r\n │ debg Cleaning all saved objects { space: undefined }\r\n │ warn browser[SEVERE] ERROR FETCHING BROWSR LOGS: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.\r\n │ succ deleted 2 objects\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover test\"\r\n │ERROR WebDriver session is no longer valid\r\n └-> \"after all\" hook: unloadMakelogs in \"discover/group1\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"mappings.json\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.22\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.20\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Deleted existing index \"logstash-2015.09.21\"\r\n │ info [test/functional/fixtures/es_archiver/logstash_functional] Unloading indices from \"data.json.gz\"\r\n └-> \"after all\" hook: afterTestSuite.trigger in \"discover/group1\"\r\n │ERROR WebDriver session is no longer valid\r\n\r\n0 passing (16.2s)\r\n1 failing\r\n\r\n1) discover/group1\r\n discover test\r\n query\r\n should show correct time range string by timepicker:\r\n\r\n Error: expected 'Sep 19, 2015 @ 06:31:44.000' to equal 'Sep 23, 2015 @ 18:31:44.000'\r\n at Assertion.assert (expect.js:100:11)\r\n at Assertion.apply (expect.js:227:8)\r\n at Assertion.be (expect.js:69:22)\r\n at Context.<anonymous> (_discover.ts:53:31)\r\n at processTicksAndRejections (node:internal/process/task_queues:96:5)\r\n at Object.apply (wrap_function.js:73:16)\r\n```\r\n\r\n</details>\r\n\r\n\r\nFlaky-test-runner verification: started 100x to hopefully catch invalid\r\nsession on CI\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2539\r\nNote: locally I was simulating it by calling `this.driver.close()` to\r\nclose browser before screenshot taking","sha":"8a95bf7fabe34c601725313c922f95ee0fa641e5"}},{"branch":"8.8","label":"v8.8.3","labelRegex":"^v(\\d+).(\\d+).\\d+$","isSourceBranch":false,"state":"NOT_CREATED"}]}] BACKPORT--> Co-authored-by: Dzmitry Lemechko <[email protected]>
* main: (354 commits) [Synthetics] Overview page fix last refresh value display (elastic#161086) [Synthetics] Remove TLS alert option for ICMP monitor (elastic#161173) fixing the path of manifets for hints autodiscover (elastic#161075) [Fleet] Fix permissions in integrations Assets page (elastic#161233) Update publicBaseUrl warning id (elastic#161204) [ML] Fix Anomaly Explorer URL for alerting context with non-default space (elastic#160899) [Enterprise Search]Add 404 error handling for mappings and documents endpoints (elastic#161203) [Logs Shared] Move LogStream and LogView into new shared plugin (elastic#161151) [Security Solutions] Fix CellActions component should hide ShowTopN action for nested fields (elastic#159645) [SecuritySolutions] Remove filter actions from Cases alerts table and fix show_top_n action (elastic#161150) [Infrastructure UI] Add strict payload validation to inventory_views endpoint (elastic#160852) [api-docs] 2023-07-05 Daily api_docs build (elastic#161225) Fix errors in custom metric payload in SLO dev docs (elastic#161141) [data views] Fix overwrite param for create (elastic#160953) [Synthetics] Perform params API HTTP migration (elastic#160575) [Cloud Security][FTR]Refactor API FTR to use .to.eql instead of .to.be (elastic#160694) Have SLO routes return a 403 instead of a 400 when user has an insufficient license (elastic#161193) [Discover] Fix shared links flaky test (elastic#161172) [ftr] Improve FTR error handling for NoSuchSessionError (elastic#161025) skip flaky suite (elastic#151981) ...
* main: (354 commits) [Synthetics] Overview page fix last refresh value display (elastic#161086) [Synthetics] Remove TLS alert option for ICMP monitor (elastic#161173) fixing the path of manifets for hints autodiscover (elastic#161075) [Fleet] Fix permissions in integrations Assets page (elastic#161233) Update publicBaseUrl warning id (elastic#161204) [ML] Fix Anomaly Explorer URL for alerting context with non-default space (elastic#160899) [Enterprise Search]Add 404 error handling for mappings and documents endpoints (elastic#161203) [Logs Shared] Move LogStream and LogView into new shared plugin (elastic#161151) [Security Solutions] Fix CellActions component should hide ShowTopN action for nested fields (elastic#159645) [SecuritySolutions] Remove filter actions from Cases alerts table and fix show_top_n action (elastic#161150) [Infrastructure UI] Add strict payload validation to inventory_views endpoint (elastic#160852) [api-docs] 2023-07-05 Daily api_docs build (elastic#161225) Fix errors in custom metric payload in SLO dev docs (elastic#161141) [data views] Fix overwrite param for create (elastic#160953) [Synthetics] Perform params API HTTP migration (elastic#160575) [Cloud Security][FTR]Refactor API FTR to use .to.eql instead of .to.be (elastic#160694) Have SLO routes return a 403 instead of a 400 when user has an insufficient license (elastic#161193) [Discover] Fix shared links flaky test (elastic#161172) [ftr] Improve FTR error handling for NoSuchSessionError (elastic#161025) skip flaky suite (elastic#151981) ...
Looks like this PR has backport PRs but they still haven't been merged. Please merge them ASAP to keep the branches relatively in sync. |
Summary
Sometimes browser/driver process dies during test run on CI and FTR fails with errors cascade, good example is here
Current behaviour on
main
: FTR lifecycle hooks, defined in remote service, has no access to the information about test suite run and particular test failure. These hooks are related to WebDriver (browser) state management and suppose to reset it to default state.Currently we silently fail screenshot taking which means tests execution is continued even if
--bail
flag is passed. It ends with cascade of failures with the same errorNoSuchSessionError: invalid session id
FTR output on failure
This PR change: I didn't find a good reason why we need to fail silently on screenshot taking. I added a check WebDriver session status with
hasOpenWindow
and take failure artefacts only if is still valid.Next change is to fail FTR after hooks related to WebDriver silently: there is no help having cascade of the repeated stacktrace so I wrap WebDriver call in hooks with
tryWebDriverCall
that catches the error and only prints it for visibility.FTR new output on failure
Flaky-test-runner verification: started 100x to hopefully catch invalid session on CI https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2539
Note: locally I was simulating it by calling
this.driver.close()
to close browser before screenshot taking