-
Notifications
You must be signed in to change notification settings - Fork 136
Description
At the time of the filing of this issue, Zui is at commit a231ce0.
While verifying that the fix in #2842 was effective CI, I bumped into a separate intermittent failure that seems worthy of examination. An example of the failure is visible in the Actions run https://github.com/brimdata/zui/actions/runs/5919160618/job/16049163945, and here's the relevant error output:
1) pool-loads.spec.ts:26:3 › Pool Loads › load more data into the pool ===========================
locator.waitFor: Error: strict mode violation: ".zed-table__cell" resolved to 2 elements:
1) <div id="col:0_row:0" data-column-id="col:0" class="z…>…</div> aka playwright.$("[id="col\:0_row\:0"]")
2) <div id="col:0_row:1" data-column-id="col:0" class="z…>…</div> aka playwright.$("[id="col\:0_row\:1"]")
=========================== logs ===========================
waiting for selector ".zed-table__cell" to be visible
strict mode violation: ".zed-table__cell" resolved to 2 elements:
1) <div id="col:0_row:0" data-column-id="col:0" class="z…>…</div> aka playwright.$("[id="col\:0_row\:0"]")
2) <div id="col:0_row:1" data-column-id="col:0" class="z…>…</div> aka playwright.$("[id="col\:0_row\:1"]")
============================================================
at ../helpers/test-app.ts:98
96 | async getViewerResults(includeHeaders = true): Promise<string[]> {
97 | const fields = await this.mainWin.locator('.zed-table__cell');
> 98 | await fields.waitFor();
| ^
99 | let results = await fields.evaluateAll<string[], HTMLElement>((nodes) =>
100 | nodes.map((n) => n.innerText.trim())
101 | );
at TestApp.getViewerResults (/home/runner/work/zui/zui/packages/e2e-tests/helpers/test-app.ts:98:18)
at /home/runner/work/zui/zui/packages/e2e-tests/tests/pool-loads.spec.ts:[35](https://github.com/brimdata/zui/actions/runs/5919160618/job/16049163945#step:8:36):21
I've seen this style of failure before (#2602) and I know we've made some other recent changes to tighten up this test (#2687). I reproduced this one in a Linux VM so I could see the contrast between the success & failure cases, and both of these are shown in the attached video.
newbug.mp4
Looking at that alongside the test code:
zui/packages/e2e-tests/tests/pool-loads.spec.ts
Lines 34 to 36 in a231ce0
| await app.query("count()") | |
| const results = await app.getViewerResults() | |
| expect(results).toEqual(["this", "2"]) |
The query() helper waits for the "Fetching" status message to become hidden before it quits.
zui/packages/e2e-tests/helpers/test-app.ts
Lines 84 to 88 in a231ce0
| async query(zed: string): Promise<void> { | |
| await this.setEditor(zed); | |
| await this.mainWin.locator('[aria-label="run-query"]').click(); | |
| await this.mainWin.locator('span[aria-label="fetching"]').isHidden(); | |
| } |
If we jump to second 17 in the video and use the left/right arrow keys in QuickTIme, we can jump between the two frames that mark this precise moment of transition: The "Fetching" does indeed go away, and the two lines of query response are immediately replaced by the single line with the count() result of 2. This animated GIF shows that toggle.
Now here's the same toggle within second 41 where the failure happens. Now we see that in the frame that immediately follows the disappearing "Fetching" message, the count() result is not yet displayed.
Given that the failure message speaks of seeing two .zed-table__cell elements, my guess is that there's a timing problem where the query output is checked at that precise instance the "Fetching" goes away and it still sees what's left of the prior two lines that were there.
Is there a clean way we can make this reliable? If my theory is correct then I assume a brief sleep timer of just a couple seconds at the end of query() would give it all the time needed to fill in the result such that getViewerResults() will see the right thing. However, I know that's hacky and would slow down the tests a bit, so hopefully there's a better way. A few thoughts:
-
Is there a better check we can use than "Fetching" becoming hidden? If I trust the essence of the wording, "I am done fetching" is indeed not the same thing as "the result is now available to view", though I think the latter is what the test is hoping would happen.
-
Would it be possible to have some kind unique ID that "tag" issued queries and their results? Looking again at the test code, we've got the call to
await app.query("count()")and then next the checkconst results = await app.getViewerResults(), but indeed, there's nothing that strictly ties the issued query to the retrieved results, though the use ofawaiton both seems to express faith that these will happen serially. However, ifquery()returned an ID and thengetViewerResults()could be wired up to wait specifically for a query result that's somehow tagged with that ID, it seems that might do the trick. -
If no other ideas surface, perhaps it could be improved in the short term by just having the wait on the disappearing "Load Successful" happen earlier, since that takes a few seconds anyway, so that would give more time for the correct result to fill in before
getViewerResults()is called. This has limited shelf life because I still have hopes we'll soon get to Allow dismissal of pop-up notifications #2605 and make those go away faster, but even if it becomes possible to click those to make them go away quickly, that might still buy enough time to dodge the problem.

