Dashboard view/edit mode selenium flakiness

[epixa]

I'm seeing this selenium failure on an unrelated PR that I believe is a timing issue with either the selenium test or the dashboard view/edit mode feature itself:

https://kibana-ci.elastic.co/job/elastic+kibana+pull-request+multijob-selenium/4907/consoleFull

[stacey-gammon]

I ran into this in another PR, based on the screen shot, you can see the global loading indicator at the top and the create button is not visible on the page. My hope is that the button will appear by the time the global loading indicator is hidden. I'm working on adding some extra waits, instead of the arbitrary 3 second sleep, to fix this.

Here is the screenshot:

[stacey-gammon]

I think this might still be a problem. Just ran into this error again:

60          │ debg  Kibana uiSettings are in elasticsearch and the server is reporting a green status
05:36:07.460        │ debg  click Visualize tab
05:36:09.982        │ debg  Taking screenshot "/var/lib/jenkins/workspace/elastic+kibana+pull-request+multijob-selenium/test/functional/screenshots/failure/dashboard app dashboard view edit mode create new dashboard opens in edit mode.png"
05:36:10.076      └- ✖ fail: "dashboard app dashboard view edit mode create new dashboard opens in edit mode"
05:36:10.076      │        [POST http://localhost:9515/session/771e363c16d80ac8e4a6f3f85e3e1152/element/0.8652604812149967-1/click] element not visible
05:36:10.076      │         (Session info: chrome=56.0.2924.87)
05:36:10.076      │         (Driver info: chromedriver=2.29.461571 (8a88bbe0775e2a23afda0ceaf2ef7ee74e822cc5),platform=Linux 4.4.0-45-generic x86_64)
05:36:10.076      │         at Server._post (test/functional/services/remote/verbose_remote_logging.js:15:21)
05:36:10.077      │         at runRequest (node_modules/leadfoot/Session.js:92:40)
05:36:10.077      │         at node_modules/leadfoot/Session.js:113:39
05:36:10.077      │         at new Promise (node_modules/dojo/Promise.js:172:17)
05:36:10.078      │         at Session._post (node_modules/leadfoot/Session.js:67:10)
05:36:10.078      │         at Element._post (node_modules/leadfoot/Element.js:23:31)
05:36:10.078      │         at Element.click (node_modules/leadfoot/Element.js:191:15)
05:36:10.078      │         at Command.<anonymous> (node_modules/leadfoot/Command.js:680:19)
05:36:10.078      │         at node_modules/dojo/Promise.js:156:41
05:36:10.078      │         at run (node_modules/dojo/Promise.js:51:33)
05:36:10.078      │         at node_modules/dojo/nextTick.js:35:17

Same screenshot, where it's on the dashboard tab but still loading:

Which doesn't quite make sense because according to the debug output, it is trying to click the visualize link.

[LeeDr]

These are recent 5.5 builds that all failed on this test (it's the only test causing failures);

$ for i in {1..40}; do echo "$i: `curl -s https://kibana-ci.elastic.co/job/elastic+kibana+5.5+multijob-selenium/$i/consoleFull | grep "fail:"`"; done
1:
2:
3: 07:45:18.633          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
4:
5:
6:
7:
8:
9:
10:
11:
12:
13:
14: 11:05:43.612          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
15: 09:32:50.018          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
16:
17: 09:32:04.724          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
18:
19:
20:
21:
22:
23:
24: 11:15:57.846          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
25:
26:
27:
28: 07:15:28.361          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
29: 09:35:53.859          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
30:
31:
32: 01:53:47.498          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
33:
34:
35:
36:
37:
38:
39: 09:32:10.241          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
40: 09:32:34.408          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>

And 5.x tests that also failed on this test;

$ for i in {1171..1194}; do echo "$i: `curl -s https://kibana-ci.elastic.co/job/elastic+kibana+5.x+multijob-selenium/$i/consoleFull | grep "fail:"`"; done
1171: 11:05:53.649          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
1172: 04:59:46.891          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
1173:
1174:
1175:
1176:
1177:
1178:
1179:
1180:
1181:
1182:
1183:
1184:
1185: 12:17:14.189          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
1186:
1187:
1188:
1189:
1190:
1191:
1192:
1193: 06:22:41.861          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>
1194: 03:44:41.860          └- ✖ <span style="color: #CD0000;">fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"</span>

[LeeDr]

This is the screenshot from one of the recent failures. I'm not familiar with the test so I don't really know if anything is wrong in it. Is it supposed to be showing a confirmation about losing changes or should show filters?

[LeeDr]

Here's the part of the log with the failure;

06:39:26.729            └- ✓ pass 
06:39:26.729          └-> when a filter is deleted
06:39:26.729            └-> "before each" hook: global before each
06:39:26.735              │ debg  Kibana uiSettings are in elasticsearch and the server is reporting a green status
06:39:26.736            └-> "before each" hook
06:39:26.738              │ debg  Load Saved Dashboard Dashboard View Edit Test
06:39:26.739              │ debg  searchForDashboardWithName: Dashboard View Edit Test
06:39:26.739              │ debg  gotoDashboardLandingPage
06:39:26.739              │ debg  onDashboardLandingPage
06:39:26.739              │ debg  doesTestSubjectExist dashboardLandingPage
06:39:27.796              │ debg  clickDashboardBreadcrumbLink
06:39:27.925              │ debg  in findTestSubject: [data-test-subj~="searchFilter"]
06:39:27.960              │ debg  in findTestSubject: [data-test-subj~="searchFilter"]
06:39:28.319              │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:28.487              │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:28.884              │ debg  Clicking edit
06:39:28.886              │ debg  in findTestSubject: [data-test-subj~="dashboardEditMode"]
06:39:29.273            │ debg  Setting absolute range to 2015-09-19 06:31:44.000 to 2015-09-23 18:31:44.000
06:39:31.318            │ debg  ensureTimePickerIsOpen: false
06:39:31.319            │ debg  --Opening time picker
06:39:31.319            │ debg  in findTestSubject: [data-test-subj~="globalTimepickerButton"]
06:39:31.509            │ debg  --Clicking Absolute button
06:39:31.510            │ debg  showAbsoluteSection
06:39:31.511            │ debg  isAbsoluteSectionShowing
06:39:31.511            │ debg  doesCssSelectorExist input[ng-model='absolute.from']
06:39:31.536            │ debg  exists? true
06:39:31.536            │ debg  --Setting From Time : 2015-09-19 06:31:44.000
06:39:31.537            │ debg  setFromTime: 2015-09-19 06:31:44.000
06:39:31.573            │ debg  ensureTimePickerIsOpen: true
06:39:31.573            │ debg  showAbsoluteSection
06:39:31.574            │ debg  isAbsoluteSectionShowing
06:39:31.575            │ debg  doesCssSelectorExist input[ng-model='absolute.from']
06:39:31.585            │ debg  exists? true
06:39:32.611            │ debg  --Setting To Time : 2015-09-23 18:31:44.000
06:39:32.612            │ debg  setToTime: 2015-09-23 18:31:44.000
06:39:32.629            │ debg  ensureTimePickerIsOpen: true
06:39:32.629            │ debg  showAbsoluteSection
06:39:32.630            │ debg  isAbsoluteSectionShowing
06:39:32.630            │ debg  doesCssSelectorExist input[ng-model='absolute.from']
06:39:32.638            │ debg  exists? true
06:39:33.156            │ debg  clickGoButton
06:39:33.158            │ debg  in findTestSubject: [data-test-subj~="timepickerGoButton"]
06:39:33.299            │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:34.152            │ debg  Filtering on a pie slice
06:39:34.153            │ debg  in findAllByCssSelector: svg > g > path.slice
06:39:34.182            │ debg  Found 10 for selector svg > g > path.slice
06:39:34.182            │ debg  Slices found:10
06:39:34.368            │ debg  in findTestSubject: [data-test-subj~="dashboardSaveMenuItem"]
06:39:34.709            │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:36.742            │ debg  entering new title
06:39:37.278            │ debg  clicking final Save button for named dashboard
06:39:37.280            │ debg  in findTestSubject: [data-test-subj~="confirmSaveDashboardButton"]
06:39:37.387            │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:37.515            │ debg  verify toast-message for saved dashboard
06:39:37.582            │ debg  clickToastOK
06:39:37.647            │ debg  Load Saved Dashboard Dashboard View Edit Test
06:39:37.648            │ debg  searchForDashboardWithName: Dashboard View Edit Test
06:39:37.648            │ debg  gotoDashboardLandingPage
06:39:37.648            │ debg  onDashboardLandingPage
06:39:37.648            │ debg  doesTestSubjectExist dashboardLandingPage
06:39:38.675            │ debg  clickDashboardBreadcrumbLink
06:39:38.805            │ debg  in findTestSubject: [data-test-subj~="searchFilter"]
06:39:38.859            │ debg  in findTestSubject: [data-test-subj~="searchFilter"]
06:39:39.223            │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:39.431            │ debg  in findTestSubject: [data-test-subj~="globalLoadingIndicator"]
06:39:39.903            │ debg  Clicking edit
06:39:39.905            │ debg  in findTestSubject: [data-test-subj~="dashboardEditMode"]
06:39:40.235            │ debg  in findAllByCssSelector: .filter-bar > .filter
06:39:50.273            │ debg  Found 0 for selector .filter-bar > .filter
06:39:50.274            │ debg  --- tryForTime failure: expected filters
06:39:50.778            │ debg  in findAllByCssSelector: .filter-bar > .filter
06:40:00.843            │ debg  Found 0 for selector .filter-bar > .filter
06:40:00.844            │ debg  --- tryForTime failed again with the same message  ...
06:40:01.348            │ debg  in findAllByCssSelector: .filter-bar > .filter
06:40:11.400            │ debg  Found 0 for selector .filter-bar > .filter
06:40:11.401            │ debg  --- tryForTime failed again with the same message  ...
06:40:11.905            │ debg  in findAllByCssSelector: .filter-bar > .filter
06:40:21.956            │ debg  Found 0 for selector .filter-bar > .filter
06:40:21.957            │ debg  --- tryForTime failed again with the same message  ...
06:40:22.467            │ debg  Taking screenshot "/var/lib/jenkins/workspace/elastic+kibana+5.5+multijob-selenium/test/functional/screenshots/failure/dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted.png"
06:40:22.566          └- ✖ fail: "dashboard app dashboard view edit mode shows lose changes warning and loses changes on confirmation when a filter is deleted"
06:40:22.566          │        tryForTime timeout: Error: expected filters
06:40:22.566          │           at /var/lib/jenkins/workspace/elastic+kibana+5.5+multijob-selenium/test/functional/apps/dashboard/_view_edit.js:179:40
06:40:22.567          │           at undefined.next (native)
06:40:22.567          │           at step (/var/lib/jenkins/workspace/elastic+kibana+5.5+multijob-selenium/test/functional/apps/dashboard/_view_edit.js:1:1)
06:40:22.567          │           at /var/lib/jenkins/workspace/elastic+kibana+5.5+multijob-selenium/test/functional/apps/dashboard/_view_edit.js:1:1
06:40:22.567          │           at process._tickDomainCallback (internal/process/next_tick.js:135:7)
06:40:22.567          │         Error: tryForTime timeout: Error: expected filters
06:40:22.567          │         at test/functional/apps/dashboard/_view_edit.js:179:40
06:40:22.567          │         at undefined.next (native)
06:40:22.567          │         at step (test/functional/apps/dashboard/_view_edit.js:1:1)
06:40:22.568          │         at test/functional/apps/dashboard/_view_edit.js:1:1
06:40:22.568          │         at process._tickDomainCallback (internal/process/next_tick.js:135:7)
06:40:22.568          │         at attempt (test/functional/services/retry.js:19:17)
06:40:22.568          │         at tryCatcher (node_modules/bluebird/js/main/util.js:26:23)
06:40:22.568          │         at Promise._settlePromiseFromHandler (node_modules/bluebird/js/main/promise.js:503:31)
06:40:22.568          │         at Promise._settlePromiseAt (node_modules/bluebird/js/main/promise.js:577:18)
06:40:22.569          │         at Promise._settlePromises (node_modules/bluebird/js/main/promise.js:693:14)
06:40:22.569          │         at Async._drainQueue (node_modules/bluebird/js/main/async.js:123:16)
06:40:22.569          │         at Async._drainQueues (node_modules/bluebird/js/main/async.js:133:10)
06:40:22.569          │         at Immediate.Async.drainQueues (node_modules/bluebird/js/main/async.js:15:14)
06:40:22.569          │       
06:40:22.569          │       
06:40:22.570      └-> "after all" hook

[stacey-gammon]

Recently submitted a couple different PRs that should address this, so closing for now. If more arise, we can create new issues for them specifically.