Skip to content

Close a wait whose own hook WebdriverIO skipped when its test ends - #532

Open
vishnuv688 wants to merge 3 commits into
mainfrom
fix/529-conformance-wait-flake
Open

vishnuv688 wants to merge 3 commits into
mainfrom
fix/529-conformance-wait-flake

Conversation

@vishnuv688

@vishnuv688 vishnuv688 commented Nov 3, 2026 •

Copy link
Copy Markdown
Member

What & why

Closes #529. Part of #494.

The conformance suite failed now and then on the WDIO "times out waiting for a missing element" test. The cause is a real service bug, not a test problem.

WebdriverIO keeps one module-global flag and skips every command hook that starts while another hook is running. A wait times out from its own timer, whatever its poll is doing. When that timeout landed while a poll's afterCommand was still awaiting its screenshot and drain, WDIO skipped the wait's own afterCommand:

  • the wait kept its running row with no error, so a timed-out wait read as if it had not failed;
  • the poll's hook, still running when the test ended, held the flag into the next test and swallowed its first command, so that command lost its row.

With the fake driver's screenshot delayed 0-150 ms, the conformance scenario failed 28 of 60 runs on main and 0 of 60 with this change.

The fix: at the end of each test, step or scenario (afterTest, afterStep, afterScenario), the service:

  1. waits for its own command hooks still running, under a 10 s ceiling that is paid once if a hook never settles;
  2. closes every wait still open, innermost first, from its running row, with the test's outcome: its error if it failed, as passed if it did not.

This runs before the outcome marks a row and before the per-test trace slice is written, so the trace carries the closed wait.

Type of change

  • Bugfix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Polish (an improvement to an existing feature)
  • Breaking change (existing behavior changes for users)
  • Documentation
  • Internal (build, CI, dependencies, tooling)

Packages touched

  • shared (types and contracts)
  • core (framework-agnostic capture/reporting)
  • elements (published element/snapshot API — @wdio/elements)
  • service (WebdriverIO adapter)
  • nightwatch-devtools (Nightwatch adapter)
  • selenium-devtools (Selenium adapter)
  • selenium-devtools-py (Selenium Python adapter)
  • backend (server)
  • app (UI)
  • script (page-injected runtime)
  • trace (Trace mode)

Capability matrix

  • packages/conformance/src/features.ts updated, and tables regenerated with pnpm docs:capabilities, if this adds or changes user-facing behaviour

No user-facing feature changes; a wait row now shows the failure it already had.

Notes for reviewers

Why only the service: the shared hook flag is WebdriverIO's; the other adapters capture waits through their own patches and never lose a wait's outcome this way.

What the service observes: HooksInFlight returns the hook promise it tracks unchanged, so WDIO awaits exactly what it awaited before. CLAUDE.md treats that hook timing as load-bearing.

The error on a closed wait goes through the service's existing failure normalizer (toCommandError): ANSI stripped, a Cucumber string error kept as the runner reported it, and an assertion failure left on its own row rather than shown twice.

An earlier approach was dropped: deferring the poll's capture until after the wait. It risked a screenshot landing mid-click, and other services' hooks could reintroduce the bug.

Residuals (in the CLAUDE.md entry):

  • The wait closes with the test's outcome, not its own. A timeout the test caught, followed by a later failure, reads as that later error.
  • Until the test ends, a caught timeout whose own hook was skipped leaves later commands in that test nested under the dead wait.
  • Waits left open in mocha before/after hooks, or in runs with no per-test hooks, are not closed.
  • The closed row's span runs to the test's end.

Review: an independent review found nothing blocking. It raised the error normalization, the repeated ceiling and the residuals above, all now addressed; each new test was confirmed to fail without its fix.

Testing

  • pnpm build, pnpm lint and the leak grep are green.
  • pnpm test passed in full (3539 passed, 1 skipped). Other full runs on a heavily loaded machine hit timing flakes in files this PR does not touch (a Selenium conformance scenario timeout, Nightwatch attempt tracking, service session tests); each passed when rerun alone.
  • New tests in packages/service/tests/wait-rows.test.ts model WDIO's hook flag and cover: element and top-level waits, nested waits, a passed test, Cucumber steps, the next test's first command, the error shape, and the ceiling.

Also in this PR: the trace path is printed. Core logs "Trace saved to" at info, which the usual WDIO logLevel: 'warn' hides, so a trace-mode run never said where its trace went. Once capture is torn down in after(), the service writes each kept trace's path to stdout (DevTools trace saved to <path>), whatever the log level. Writing it any earlier would put the line in the trace's own Console tab. The README notes it for the WebdriverIO service only: Selenium, Nightwatch and Python still log the path at info. Not yet checked: a config that sets outputDir, where WDIO sends logger output to files.

Needs checking by hand: pnpm demo:wdio:mocha live, then in trace mode (DEVTOOLS_MODE=trace). Check that wait rows still nest their polls and close when they finish, and that a failing wait shows its timeout. In trace mode, the trace path prints at the end of the run.

🤖 Generated with Claude Code

WebdriverIO skips every command hook while another one is running. A
wait times out from its own timer, so a timeout landing while a poll's
afterCommand is still taking its screenshot made WDIO skip the wait's
afterCommand: the wait kept its running row with no error, and the poll
hook, outliving its test, swallowed the next test's first command. The
conformance scenario failed this way 28 of 60 times with the fake
driver's screenshot delayed.

At the end of each test, step or scenario the service now waits for its
own command hooks to settle (under a 10 s ceiling, paid once) and closes
every wait still open, innermost first, with the test's outcome, before
the outcome marks a row and before the per-test slice is flushed.

Closes #529

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
vishnuv688 and others added 2 commits November 3, 2026 12:08
Core logs the trace path at info level, which the usual
logLevel: 'warn' hides, so a trace-mode run ended without saying where
its trace went. The service now writes each kept trace's path to stdout
once capture is torn down, so the line never lands in a trace's own
console and shows whatever the log level.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…ait-flake

# Conflicts:
#	packages/service/src/index.ts

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Conformance: failed-test-has-error-row fails intermittently for the WDIO service

1 participant