Skip to content

Commit 8b18549

Browse files
committed
build: Fix duplicate "browser_connected" debug log message
When there is a retry after a timeout, the final "browser_connected" debug message was logged multiple times. Example: ``` 05:30:49 [qtap_browser_client_S1_C1_edge] browser_spawn_command /usr/bin/microsoft-edge … 05:31:49 [qtap_browser_client_S1_C1_edge] WARNING browser_connect_timeout Browser did not start within 60s 05:31:49 qtap_server_S1] browser_connect_retry Retrying, attempt 2 of 3 05:31:49 [qtap_browser_client_S1_C1_edge] browser_spawn_command /usr/bin/microsoft-edge 05:31:49 [qtap_browser_client_S1_C1_edge] browser_launch_stopped BrowserConnectTimeout: Browser did not start within 60s 05:31:49 [qtap_browser_client_S1_C1_edge] browser_connected Edge Headless connected! Serving test file. 05:31:49 [qtap_browser_client_S1_C1_edge] browser_connected Edge Headless connected! Serving test file. 05:31:49 [qtap_browser_client_S1_C1_edge] WARNING browser_idle_timeout Test timed out after 60s ``` This happened because the first attempt was still listening to the `clientonline` event and handling the later attempt to send its own copy of the log message just before calling `resolve()` on the already-rejected Promise. That resolve() call is a no-op, but logger call is not. We could fix this by carefully avoiding that through local state, such as by setting `connectTimeoutTimer = false` from the setTimeout callback and checking that in the 'clientonline' callback. Or, by adding support for `eventbus.off()` and removing the 'clientonline' callback from inside setTimeout callback. This patch does none of that, and instead leverages the fact that the Promise boundary already cleanly represents this, by moving the log message to the caller.
1 parent edc49bc commit 8b18549

File tree

1 file changed

+2
-4
lines changed

1 file changed

+2
-4
lines changed

src/server.js

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -444,6 +444,7 @@ class ControlServer {
444444

445445
try {
446446
await this.launchBrowserAndConnect(browserFn, browser, signals);
447+
logger.debug('browser_connected', `${browser.getDisplayName()} connected! Serving test file.`);
447448
} catch (e) {
448449
// Handle util.BrowserConnectTimeout from launchBrowserAndConnect
449450
//
@@ -538,9 +539,7 @@ class ControlServer {
538539
})
539540
.catch(/** @type {Error|Object|string} */ e => {
540541
// Silence any errors from browserFn that happen after we called browser.stop().
541-
if (signals.browser.aborted) {
542-
browser.logger.debug('browser_launch_stopped', String(e.cause || e));
543-
} else {
542+
if (!signals.browser.aborted) {
544543
browser.logger.warning('browser_launch_error', e);
545544
browser.stop(e);
546545
throw e;
@@ -574,7 +573,6 @@ class ControlServer {
574573
this.eventbus.on('clientonline', (event) => {
575574
if (event.clientId === browser.clientId) {
576575
clearTimeout(connectTimeoutTimer);
577-
browser.logger.debug('browser_connected', `${browser.getDisplayName()} connected! Serving test file.`);
578576
resolve(null);
579577
}
580578
});

0 commit comments

Comments
 (0)