Repository navigation
fix(clock): cancel real-time timer when replay ends paused - #43873
Conversation
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
🟢 The CI failure is a pre-existing flakeHi, I'm the Playwright bot. I checked the failure against this PR and refreshed the CI test history. DetailsThe only reported failure is not caused by this PR. Pre-existing flake
The same test failed with that error on
Excluding this PR, the refreshed results database records 16 failed and 723 passed runs for this exact test on Ubuntu/Chrome between October 6 and November 3. The PR changes paused-clock log replay and its regression test. This MCP test does not install or pause the clock, so it does not exercise the changed path. The other test report contains one passed-on-retry test and no failures. CI failures checked by the Playwright bot - agent run Triaged by the Playwright bot - agent run |
Pavel Feldman (pavelfeldman)
left a comment
There was a problem hiding this comment.
Do not merge yet. The inline comment on clock.ts:480 describes tests that will fail on main.
The fix corrects the reported bug. With this PR, a page's zero-delay timer did not fire on Chromium, Firefox or WebKit for the issue's trigger, a window.open popup, or an iframe navigated from its initial blank document. On base, the timer fired in all of these cases except the WebKit popup.
Problems on lines outside the diff
These lines cannot have inline comments.
Related to this PR
clock.ts:254: the.thenhandler clears_currentRealTimeTimerwithout a check that the field still holds its own timer. The new paused branch makes it possible for the field to hold a newer timer. Example: timer A is running, a paused replay clears the field, andresume()arms timer B. When A finishes, its.thenclears B from the field and arms timer C. Fix: clear the field only ifthis._currentRealTimeTimer === realTimeTimer. This comes from reading the code only. A Node harness showed no harm, because B normally returns at its identity check.
Also on base
clock.ts:475: on Chromium, when the log replays in parts on a running clock, real time is counted twice. The second replay advances from an older log time after the first replay has already advanced to now. Steps:clock.install({ time: 0 }),page.addInitScript(() => Date.now()),clock.fastForward(1000), wait 3 s,goto. Chromium reportsDate.now()of about 7073 on base and on this PR. The same steps without the init script give about 4036. Firefox (4163) and WebKit (4037) are correct. Reproduced in real browsers. This is a candidate for a separate fix.clock.ts:187: a running_runToloop does not stop when a replay pauses the clock, so a paused clock can still fire due timers. With six due timers and a replay that ends paused in the second one, timers 3 to 6 still fire with_realTimeundefined. Reproduced only in a Node harness that callsClockControllerdirectly. The trigger is rare.clock.ts:278:_runWithDisabledRealTimeSyncalways resumes infinally, so a replay that ends paused duringrunFororfastForwardis undone and the native timer is armed again. Reproduced only in a Node harness. The trigger is rare.clock.ts:252:realTimeTimer.promiseis set only after the first timer callback has run synchronously inside_runTo, so during that callback the timer does not look in progress. If the first due timer callssetTimeout,addTimercalls_updateRealTimeTimer, and a second native timer replaces the running one in_currentRealTimeTimer._innerPausecan then wait for the wrong timer. A Node harness showed 2 overlapping_runToloops whenpauseAtwas called directly from the first callback. The path through pagesetTimeoutcomes from reading the code.
Optional cleanup
clock.ts:893: the old timer exists becauseinject()callscontroller.resume()and arms a native timer before the log is known. This PR removes that timer afterwards rather than not creating it. Ifinject()set_realTimewithout arming,addTimeror the end of the replay could arm the timer only when the clock is running. This cost is maintenance only. The fix in this PR is correct for the reported case.
Other notes
ubuntu-latest - chromefailed ontests/mcp/webmcp-dynamic.spec.ts:189. That spec does not use the clock, so the failure is probably not related, but this was not investigated.- The PR description has a verification paragraph.
AGENTS.mdsays not to add a test plan to a PR description.
| this._innerResume(); | ||
| } else { | ||
| this._realTime = undefined; | ||
| this._currentRealTimeTimer?.cancel(); |
There was a problem hiding this comment.
This change makes four tests fail in the frozen-clock CI job. These tests depended on the old timer to fire their setTimeout(..., 0) calls, and now they wait forever:
- EV-121:
tests/page/page-evaluate-callback.spec.ts:98 - EV-063:
tests/page/page-evaluate.spec.ts:576 - FC-026:
tests/page/page-filechooser.spec.ts:408 - RO-012:
tests/page/page-route.spec.ts:225
With PW_CLOCK=frozen on chromium-page (--retries=0 --repeat-each=3 --timeout=10000), base passes 12 of 12 and this PR fails 12 of 12. In a full frozen run on this PR, these 4 were the only unexpected failures.
The job time library - frozen (.github/workflows/tests_secondary.yml:116) runs only on push, not on a PR, unless the PR gets the CQ1 label. This PR does not have that label, so the first failure will be on main.
Fix: add it.skip(process.env.PW_CLOCK === 'frozen') to these tests, as other tests in tests/page do, or change them so they do not need the timer.
There was a problem hiding this comment.
Added frozen-clock skips to all four timer-dependent tests. With PW_CLOCK=frozen, all 36 checks skip as intended across three browsers and three repetitions; the normal runs pass on supported browsers.
Revised on Linux by the Playwright bot - agent run
| } else { | ||
| this._realTime = undefined; | ||
| this._currentRealTimeTimer?.cancel(); | ||
| this._currentRealTimeTimer = undefined; |
There was a problem hiding this comment.
This clears the reference even when this timer's _runTo is still running. _innerPause then no longer waits for the run, and _updateRealTimeTimer no longer sees it as in progress. The running branch respects an in-progress timer, but this branch does not.
In a Node harness that calls ClockController directly, a running clock has six due timers, and a replay that ends paused happens in the second callback, followed by pauseAt(9000):
- Base:
pauseAtwaits, at most 1_runToruns at a time, and the remaining timers see time 1000. - This PR:
pauseAtdoes not wait, 2_runToloops overlap, and the remaining timers see time 9000.
The overlap also lets _duringTick be reset by the other loop.
Fix: cancel and clear only when no run is in progress, because the existing .then clears the field otherwise.
if (!this._currentRealTimeTimer?.promise) {
this._currentRealTimeTimer?.cancel();
this._currentRealTimeTimer = undefined;
}The trigger is rare: the log grows only from init scripts, so they must run again on a live global while due timers are running. This was not reproduced in a browser.
There was a problem hiding this comment.
Paused replay now cancels and clears only when no run is in progress; the completion handler also checks timer identity. CK-221 verifies that pauseAt waits and the remaining callbacks see 1000, not 9000: it fails on the original PR source and passes with this revision.
Revised on Linux by the Playwright bot - agent run
| } else { | ||
| this._realTime = undefined; | ||
| this._currentRealTimeTimer?.cancel(); | ||
| this._currentRealTimeTimer = undefined; |
There was a problem hiding this comment.
This is a user-visible behavior change and it needs a release note. Since 1.57, pages opened after pauseAt could get zero-delay timers fired. Now these timers wait until the clock is advanced.
A test that runs pauseAt, then goto, then page.evaluate(() => new Promise(f => setTimeout(f, 0))) passed before if the timer was set in the first 100 ms or so of the document. Now it times out with no message about the clock.
The new behavior matches docs/src/api/class-clock.md:131, so the code is correct. The release note should tell users to call runFor(0) or to pause after load.
There was a problem hiding this comment.
Added a 1.65 release note in all four languages. It explains that page-load timers remain pending after pauseAt and recommends runFor(0) or pausing after load.
Revised on Linux by the Playwright bot - agent run
| this._innerResume(); | ||
| } else { | ||
| this._realTime = undefined; | ||
| this._currentRealTimeTimer?.cancel(); |
There was a problem hiding this comment.
Optional cleanup: this is the third copy of the stop logic. The other two are in _innerPause (lines 208-210) and _updateRealTimeTimer (lines 238-239), and each place handles an in-progress run differently.
A small synchronous helper, for example _stopRealTimeTimer(), would put that rule in one place. void this._innerPause() is not a replacement, because it clears the field only after an await, so the identity check in the timer callback would still pass.
There was a problem hiding this comment.
Kept the guard local rather than adding the optional helper. _innerPause must wait for an active run, _updateRealTimeTimer already returns for an active run, and paused replay must synchronously cancel only an idle timer.
Revised on Linux by the Playwright bot - agent run
| @@ -535,17 +535,27 @@ it.describe('while on pause', () => { | |||
| }); | |||
|
|
|||
| it('CK-045 should stay paused on the next page when an init script reads the time', { | |||
There was a problem hiding this comment.
This test does not contain the issue's trigger. Issue #43869 has no init script, but this test uses one. On Chromium, the first replay and the cancel happen in the Date.now() init script. In the issue, the replay starts from the page's setTimeout through addTimer.
A later change that breaks only that path would not fail this test. The title also still describes only the init-script case.
A second short test without addInitScript would cover the reported case.
There was a problem hiding this comment.
Added CK-220 without addInitScript, so the page's setTimeout triggers replay. It fails on base and passes with the fix on Chromium, Firefox and WebKit; CK-045 still covers replay from the init script.
Revised on Linux by the Playwright bot - agent run
|
Hi, I'm the Playwright bot. I started to address the review comments on Linux: agent run |
|
Hi, I'm the Playwright bot and I addressed the review. The revision preserves an active timer run during paused replay, checks timer identity before completion clears the field, and adds a unit regression for the overlap.
Verification on Linux
Revised on Linux by the Playwright bot - agent run |
e5d8cb0 to
087dc41
Compare
Test results for "tests 1"1 flaky23596 passed, 704 skipped Merge workflow run. |
This comment has been minimized.
This comment has been minimized.
|
|
||
| import LiteYouTube from '@site/src/components/LiteYouTube'; | ||
|
|
||
| ## Version 1.65 |
There was a problem hiding this comment.
don't edit release notes for any of the langs
There was a problem hiding this comment.
Removed the release-note changes for all four languages. All four files now match the base exactly.
Revised on Linux by the Playwright bot - agent run
|
Hi, I'm the Playwright bot. I started to address the review comments on Linux: agent run |
|
Hi, I'm the Playwright bot. I removed the release-note changes for all four languages, as requested. Those files now match the base exactly; the code and tests are unchanged. Build and full lint passed. The affected and neighboring tests passed on Chromium, Firefox and WebKit: 1360 passed, 17 skipped. Both page-load regressions failed without the fix on all three browsers and passed after restoring it; the overlap regression also passed. All 36 frozen-clock checks skipped as intended. I did not run macOS, Windows or the full frozen-clock job. The earlier PR-description edit still needs a maintainer; this workflow cannot edit the description. Revised on Linux by the Playwright bot - agent run |
087dc41 to
9ea7965
Compare
Test results for "MCP"5194 passed, 616 skipped Merge workflow run. |
Cancel the native real-time timer when clock-log replay ends paused. Previously only the running state was cleared, leaving a scheduled callback that could fire a page's zero-delay timer during load.
Extend CK-045 to verify that the timer stays pending across navigation until
runFor(0).Verified on Chromium, Firefox and WebKit: 651 clock tests passed, 6 skipped; the original trigger without an init script passed 9 runs. Build and flint passed.
Fixes #43869
Triaged on Linux by the Playwright bot - agent run