diff --git a/PLAYWRITER_AGENTS.md b/PLAYWRITER_AGENTS.md index 010f547..70518a6 100644 --- a/PLAYWRITER_AGENTS.md +++ b/PLAYWRITER_AGENTS.md @@ -51,3 +51,5 @@ each test() block should reset the extension connection to make sure tests are i NEVER call browser.close() in the tests remember that every time the extension is activated in a tab that tab gets added to the available pages. so if you toggle the extension and then do .newPage() there will be 2 pages, not 1. + +to debug server or extension issues you can also inspect the file playwriter/relay-server.log to see both extension and server logs. with all cdp events sent. to see if there are events missing or something broken. this file is recreated every time the server is started and appended in real time. use rg to only read relevant lines and parts because it can get quite long diff --git a/extension/src/background.ts b/extension/src/background.ts index 556071f..7b1bf5f 100644 --- a/extension/src/background.ts +++ b/extension/src/background.ts @@ -1,4 +1,4 @@ -import { RelayConnection, debugLog } from './relayConnection' +import { RelayConnection, logger } from './relayConnection' import { createStore } from 'zustand/vanilla' // Relay URL - fixed port for MCP bridge @@ -80,8 +80,8 @@ declare global { async function resetDebugger() { let targets = await chrome.debugger.getTargets() targets = targets.filter((x) => x.tabId && x.attached) - console.log(`found ${targets.length} existing debugger targets. detaching them before background script starts`) - console.log(targets) + logger.log(`found ${targets.length} existing debugger targets. detaching them before background script starts`) + logger.log(targets) for (const target of targets) { await chrome.debugger.detach({ tabId: target.tabId }) } @@ -145,7 +145,7 @@ const icons = { } as const useExtensionStore.subscribe(async (state, prevState) => { - console.log(state) + logger.log(state) const { connectionState, connectedTabs, errorText } = state const tabs = await chrome.tabs.query({}) @@ -193,54 +193,54 @@ useExtensionStore.subscribe(async (state, prevState) => { async function ensureConnection(): Promise { const { connection } = useExtensionStore.getState() if (connection) { - debugLog('Connection already exists, reusing') + logger.debug('Connection already exists, reusing') return } - debugLog('No existing connection, creating new relay connection') - debugLog('Waiting for server at http://localhost:19988...') + logger.debug('No existing connection, creating new relay connection') + logger.debug('Waiting for server at http://localhost:19988...') useExtensionStore.setState({ connectionState: 'reconnecting' }) while (true) { try { await fetch('http://localhost:19988', { method: 'HEAD' }) - debugLog('Server is available') + logger.debug('Server is available') break } catch (error: any) { - debugLog('Server not available, retrying in 1 second...') + logger.debug('Server not available, retrying in 1 second...') await new Promise((resolve) => setTimeout(resolve, 1000)) } } - debugLog('Server is ready, creating WebSocket connection to:', RELAY_URL) + logger.debug('Server is ready, creating WebSocket connection to:', RELAY_URL) const socket = new WebSocket(RELAY_URL) - debugLog('WebSocket created, initial readyState:', socket.readyState, '(0=CONNECTING, 1=OPEN, 2=CLOSING, 3=CLOSED)') + logger.debug('WebSocket created, initial readyState:', socket.readyState, '(0=CONNECTING, 1=OPEN, 2=CLOSING, 3=CLOSED)') await new Promise((resolve, reject) => { let timeoutFired = false const timeout = setTimeout(() => { timeoutFired = true - debugLog('=== WebSocket connection TIMEOUT after 5 seconds ===') - debugLog('Final WebSocket readyState:', socket.readyState) - debugLog('WebSocket URL:', socket.url) - debugLog('Socket protocol:', socket.protocol) + logger.debug('=== WebSocket connection TIMEOUT after 5 seconds ===') + logger.debug('Final WebSocket readyState:', socket.readyState) + logger.debug('WebSocket URL:', socket.url) + logger.debug('Socket protocol:', socket.protocol) reject(new Error('Connection timeout')) }, 5000) socket.onopen = () => { if (timeoutFired) { - debugLog('WebSocket opened but timeout already fired!') + logger.debug('WebSocket opened but timeout already fired!') return } - debugLog('WebSocket onopen fired! readyState:', socket.readyState) + logger.debug('WebSocket onopen fired! readyState:', socket.readyState) clearTimeout(timeout) resolve() } socket.onerror = (error) => { - debugLog('WebSocket onerror during connection:', error) - debugLog('Error type:', error.type) - debugLog('Current readyState:', socket.readyState) + logger.debug('WebSocket onerror during connection:', error) + logger.debug('Error type:', error.type) + logger.debug('Current readyState:', socket.readyState) if (!timeoutFired) { clearTimeout(timeout) reject(new Error('WebSocket connection failed')) @@ -248,7 +248,7 @@ async function ensureConnection(): Promise { } socket.onclose = (event) => { - debugLog('WebSocket onclose during connection setup:', { + logger.debug('WebSocket onclose during connection setup:', { code: event.code, reason: event.reason, wasClean: event.wasClean, @@ -260,19 +260,19 @@ async function ensureConnection(): Promise { } } - debugLog('Event handlers set, waiting for connection...') + logger.debug('Event handlers set, waiting for connection...') }) - debugLog('WebSocket connected successfully, creating RelayConnection instance') + logger.debug('WebSocket connected successfully, creating RelayConnection instance') const newConnection = new RelayConnection({ ws: socket, onClose: (reason, code) => { - debugLog('=== Relay connection onClose callback triggered ===', { reason, code }) + logger.debug('=== Relay connection onClose callback triggered ===', { reason, code }) const { connectedTabs } = useExtensionStore.getState() - debugLog('Connected tabs before potential reconnection:', Array.from(connectedTabs.keys())) + logger.debug('Connected tabs before potential reconnection:', Array.from(connectedTabs.keys())) if (reason === 'Extension Replaced' || code === 4001) { - debugLog('Connection replaced by another extension instance. Not reconnecting.') + logger.debug('Connection replaced by another extension instance. Not reconnecting.') useExtensionStore.setState({ connection: undefined, connectionState: 'error', @@ -284,15 +284,15 @@ async function ensureConnection(): Promise { useExtensionStore.setState({ connection: undefined, connectionState: 'disconnected' }) if (connectedTabs.size > 0) { - debugLog('Tabs still connected, triggering reconnection') + logger.debug('Tabs still connected, triggering reconnection') void reconnect() } else { - debugLog('No tabs to reconnect') + logger.debug('No tabs to reconnect') } }, onTabDetached: (tabId, reason) => { - debugLog('=== Manual tab detachment detected for tab:', tabId, '===') - debugLog('User closed debugger via Chrome automation bar') + logger.debug('=== Manual tab detachment detected for tab:', tabId, '===') + logger.debug('User closed debugger via Chrome automation bar') useExtensionStore.setState((state) => { const newTabs = new Map(state.connectedTabs) @@ -303,17 +303,17 @@ async function ensureConnection(): Promise { // if user cancels debugger. disconnect everything useExtensionStore.setState({ connectionState: 'disconnected' }) } - debugLog('Removed tab from _connectedTabs map') + logger.debug('Removed tab from _connectedTabs map') }, }) useExtensionStore.setState({ connection: newConnection }) - debugLog('Connection established, WebSocket open (caller should set connectionState)') + logger.debug('Connection established, WebSocket open (caller should set connectionState)') } async function connectTab(tabId: number): Promise { try { - debugLog(`=== Starting connection to tab ${tabId} ===`) + logger.debug(`=== Starting connection to tab ${tabId} ===`) useExtensionStore.setState((state) => { const newTabs = new Map(state.connectedTabs) @@ -326,11 +326,11 @@ async function connectTab(tabId: number): Promise { await ensureConnection() - debugLog('Calling attachTab for tab:', tabId) + logger.debug('Calling attachTab for tab:', tabId) const { connection } = useExtensionStore.getState() if (!connection) return const targetInfo = await connection.attachTab(tabId) - debugLog('attachTab completed, updating targetId in connectedTabs map') + logger.debug('attachTab completed, updating targetId in connectedTabs map') useExtensionStore.setState((state) => { const newTabs = new Map(state.connectedTabs) newTabs.set(tabId, { @@ -340,11 +340,11 @@ async function connectTab(tabId: number): Promise { return { connectedTabs: newTabs, connectionState: 'connected' } }) - debugLog(`=== Successfully connected to tab ${tabId} ===`) + logger.debug(`=== Successfully connected to tab ${tabId} ===`) } catch (error: any) { - debugLog(`=== Failed to connect to tab ${tabId} ===`) - debugLog('Error details:', error) - debugLog('Error stack:', error.stack) + logger.debug(`=== Failed to connect to tab ${tabId} ===`) + logger.debug('Error details:', error) + logger.debug('Error stack:', error.stack) useExtensionStore.setState((state) => { const newTabs = new Map(state.connectedTabs) @@ -367,55 +367,55 @@ async function connectTab(tabId: number): Promise { } async function disconnectTab(tabId: number): Promise { - debugLog(`=== Disconnecting tab ${tabId} ===`) + logger.debug(`=== Disconnecting tab ${tabId} ===`) const { connectedTabs, connection } = useExtensionStore.getState() if (!connectedTabs.has(tabId)) { - debugLog('Tab not in connectedTabs map, ignoring disconnect') + logger.debug('Tab not in connectedTabs map, ignoring disconnect') return } - debugLog('Calling detachTab on connection') + logger.debug('Calling detachTab on connection') connection?.detachTab(tabId) useExtensionStore.setState((state) => { const newTabs = new Map(state.connectedTabs) newTabs.delete(tabId) return { connectedTabs: newTabs } }) - debugLog('Tab removed from connectedTabs map') + logger.debug('Tab removed from connectedTabs map') const { connectedTabs: updatedTabs, connection: updatedConnection } = useExtensionStore.getState() - debugLog('Connected tabs remaining:', updatedTabs.size) + logger.debug('Connected tabs remaining:', updatedTabs.size) if (updatedTabs.size === 0 && updatedConnection) { - debugLog('No tabs remaining, closing relay connection') + logger.debug('No tabs remaining, closing relay connection') updatedConnection.close('All tabs disconnected') useExtensionStore.setState({ connection: undefined, connectionState: 'disconnected' }) } } async function reconnect(): Promise { - debugLog('=== Starting reconnection ===') + logger.debug('=== Starting reconnection ===') const { connectedTabs } = useExtensionStore.getState() - debugLog('Tabs to reconnect:', Array.from(connectedTabs.keys())) + logger.debug('Tabs to reconnect:', Array.from(connectedTabs.keys())) try { await ensureConnection() const tabsToReconnect = Array.from(connectedTabs.keys()) - debugLog('Re-attaching', tabsToReconnect.length, 'tabs') + logger.debug('Re-attaching', tabsToReconnect.length, 'tabs') for (const tabId of tabsToReconnect) { const { connectedTabs: currentTabs } = useExtensionStore.getState() if (!currentTabs.has(tabId)) { - debugLog('Tab', tabId, 'was manually disconnected during reconnection, skipping') + logger.debug('Tab', tabId, 'was manually disconnected during reconnection, skipping') continue } try { - debugLog('Checking if tab', tabId, 'still exists') + logger.debug('Checking if tab', tabId, 'still exists') await chrome.tabs.get(tabId) - debugLog('Re-attaching tab:', tabId) + logger.debug('Re-attaching tab:', tabId) const { connection } = useExtensionStore.getState() if (!connection) return const targetInfo = await connection.attachTab(tabId) @@ -427,9 +427,9 @@ async function reconnect(): Promise { }) return { connectedTabs: newTabs } }) - debugLog('Successfully re-attached tab:', tabId) + logger.debug('Successfully re-attached tab:', tabId) } catch (error: any) { - debugLog('Failed to re-attach tab:', tabId, error.message) + logger.debug('Failed to re-attach tab:', tabId, error.message) useExtensionStore.setState((state) => { const newTabs = new Map(state.connectedTabs) newTabs.delete(tabId) @@ -439,18 +439,18 @@ async function reconnect(): Promise { } const { connectedTabs: finalTabs } = useExtensionStore.getState() - debugLog('=== Reconnection complete ===') - debugLog('Successfully reconnected tabs:', finalTabs.size) + logger.debug('=== Reconnection complete ===') + logger.debug('Successfully reconnected tabs:', finalTabs.size) if (finalTabs.size > 0) { useExtensionStore.setState({ connectionState: 'connected' }) - debugLog('Set connectionState to connected') + logger.debug('Set connectionState to connected') } else { - debugLog('No tabs successfully reconnected, staying in reconnecting state') + logger.debug('No tabs successfully reconnected, staying in reconnecting state') useExtensionStore.setState({ connectionState: 'disconnected' }) } } catch (error: any) { - debugLog('=== Reconnection failed ===', error) + logger.debug('=== Reconnection failed ===', error) useExtensionStore.setState({ connectedTabs: new Map(), @@ -462,21 +462,21 @@ async function reconnect(): Promise { async function onTabRemoved(tabId: number): Promise { const { connectedTabs } = useExtensionStore.getState() - debugLog('Tab removed event for tab:', tabId, 'is connected:', connectedTabs.has(tabId)) + logger.debug('Tab removed event for tab:', tabId, 'is connected:', connectedTabs.has(tabId)) if (!connectedTabs.has(tabId)) return - debugLog(`Connected tab ${tabId} was closed, disconnecting`) + logger.debug(`Connected tab ${tabId} was closed, disconnecting`) await disconnectTab(tabId) } async function onTabActivated(activeInfo: chrome.tabs.TabActiveInfo): Promise { - debugLog('Tab activated:', activeInfo.tabId) + logger.debug('Tab activated:', activeInfo.tabId) useExtensionStore.setState({ currentTabId: activeInfo.tabId }) } async function onActionClicked(tab: chrome.tabs.Tab): Promise { if (!tab.id) { - debugLog('No tab ID available') + logger.debug('No tab ID available') return } @@ -484,13 +484,13 @@ async function onActionClicked(tab: chrome.tabs.Tab): Promise { const tabInfo = connectedTabs.get(tab.id) if (connectionState === 'error') { - debugLog('Global error state - retrying reconnection') + logger.debug('Global error state - retrying reconnection') await reconnect() return } if (connectionState === 'reconnecting') { - debugLog('User clicked during reconnection, canceling and disconnecting all tabs') + logger.debug('User clicked during reconnection, canceling and disconnecting all tabs') const tabsToDisconnect = Array.from(connectedTabs.keys()) @@ -508,7 +508,7 @@ async function onActionClicked(tab: chrome.tabs.Tab): Promise { } if (tabInfo?.state === 'error') { - debugLog('Tab has error - disconnecting to clear state') + logger.debug('Tab has error - disconnecting to clear state') await disconnectTab(tab.id) return } @@ -520,7 +520,7 @@ async function onActionClicked(tab: chrome.tabs.Tab): Promise { } } -debugLog(`Using relay URL: ${RELAY_URL}`) +logger.debug(`Using relay URL: ${RELAY_URL}`) chrome.tabs.onRemoved.addListener(onTabRemoved) chrome.tabs.onActivated.addListener(onTabActivated) chrome.action.onClicked.addListener(onActionClicked) diff --git a/extension/src/relayConnection.ts b/extension/src/relayConnection.ts index 5eaae5e..28d6e02 100644 --- a/extension/src/relayConnection.ts +++ b/extension/src/relayConnection.ts @@ -17,14 +17,56 @@ import type { CDPEvent, Protocol } from 'playwriter/src/cdp-types'; import type { ExtensionCommandMessage, ExtensionResponseMessage } from 'playwriter/src/extension/protocol'; -export function debugLog(...args: unknown[]): void { - const enabled = true; - if (enabled) { - // eslint-disable-next-line no-console - console.log('[Extension]', ...args); +let activeConnection: RelayConnection | undefined; + +export const logger = { + log: (...args: any[]) => logToRemote('log', args), + debug: (...args: any[]) => logToRemote('debug', args), + info: (...args: any[]) => logToRemote('info', args), + warn: (...args: any[]) => logToRemote('warn', args), + error: (...args: any[]) => logToRemote('error', args), +}; + +function logToRemote(level: 'log' | 'debug' | 'info' | 'warn' | 'error', args: any[]) { + // Always log to local console + console[level](...args); + + if (activeConnection) { + activeConnection.sendLog(level, args); } } +function safeSerialize(arg: any): string { + if (arg === undefined) return 'undefined'; + if (arg === null) return 'null'; + if (typeof arg === 'function') return `[Function: ${arg.name || 'anonymous'}]`; + if (typeof arg === 'symbol') return String(arg); + + if (arg instanceof Error) { + return arg.stack || arg.message || String(arg); + } + + if (typeof arg === 'object') { + try { + const seen = new WeakSet(); + return JSON.stringify(arg, (key, value) => { + if (typeof value === 'object' && value !== null) { + if (seen.has(value)) return '[Circular]'; + seen.add(value); + } + return value; + }); + } catch (e) { + return String(arg); + } + } + + return String(arg); +} + + + + interface AttachedTab { debuggee: chrome.debugger.Debuggee; targetId: string; @@ -58,7 +100,7 @@ export class RelayConnection { try { message = JSON.parse(event.data); } catch (error: any) { - debugLog('Error parsing message:', error); + logger.debug('Error parsing message:', error); this._sendMessage({ error: { code: -32700, @@ -68,7 +110,7 @@ export class RelayConnection { return; } - debugLog('Received message:', message); + logger.debug('Received message:', message); const response: ExtensionResponseMessage = { id: message.id, @@ -76,14 +118,14 @@ export class RelayConnection { try { response.result = await this._handleCommand(message); } catch (error: any) { - debugLog('Error handling command:', error); + logger.debug('Error handling command:', error); response.error = error.message; } - debugLog('Sending response:', response); + logger.debug('Sending response:', response); this._sendMessage(response); }; this._ws.onclose = (event: CloseEvent) => { - debugLog('WebSocket onclose event:', { + logger.debug('WebSocket onclose event:', { code: event.code, reason: event.reason, wasClean: event.wasClean @@ -91,33 +133,44 @@ export class RelayConnection { this._onClose(event.reason, event.code); }; this._ws.onerror = (event: Event) => { - debugLog('WebSocket onerror event:', event); + logger.debug('WebSocket onerror event:', event); }; chrome.debugger.onEvent.addListener(this._onDebuggerEvent); chrome.debugger.onDetach.addListener(this._onDebuggerDetach); - debugLog('RelayConnection created, WebSocket readyState:', this._ws.readyState); + logger.debug('RelayConnection created, WebSocket readyState:', this._ws.readyState); + activeConnection = this; + } + + sendLog(level: string, args: any[]) { + this._sendMessage({ + method: 'log', + params: { + level, + args: args.map(arg => safeSerialize(arg)) + } + }); } async attachTab(tabId: number): Promise { const debuggee = { tabId }; - debugLog('Attaching debugger to tab:', tabId, 'WebSocket state:', this._ws.readyState); + logger.debug('Attaching debugger to tab:', tabId, 'WebSocket state:', this._ws.readyState); try { await chrome.debugger.attach(debuggee, '1.3'); - debugLog('Debugger attached successfully to tab:', tabId); + logger.debug('Debugger attached successfully to tab:', tabId); } catch (error: any) { - debugLog('ERROR attaching debugger to tab:', tabId, error); + logger.debug('ERROR attaching debugger to tab:', tabId, error); throw error; } - debugLog('Sending Target.getTargetInfo command for tab:', tabId); + logger.debug('Sending Target.getTargetInfo command for tab:', tabId); const result = await chrome.debugger.sendCommand( debuggee, 'Target.getTargetInfo' ) as Protocol.Target.GetTargetInfoResponse; - debugLog('Received targetInfo for tab:', tabId, result.targetInfo); + logger.debug('Received targetInfo for tab:', tabId, result.targetInfo); const targetInfo = result.targetInfo; const sessionId = `pw-tab-${this._nextSessionId++}`; @@ -130,7 +183,7 @@ export class RelayConnection { executionContexts: new Map() }); - debugLog('Sending Target.attachedToTarget event, WebSocket state:', this._ws.readyState); + logger.debug('Sending Target.attachedToTarget event, WebSocket state:', this._ws.readyState); this._sendMessage({ method: 'forwardCDPEvent', params: { @@ -146,7 +199,7 @@ export class RelayConnection { } }); - debugLog('Tab attached successfully:', tabId, 'sessionId:', sessionId, 'targetId:', targetInfo.targetId); + logger.debug('Tab attached successfully:', tabId, 'sessionId:', sessionId, 'targetId:', targetInfo.targetId); return targetInfo; } @@ -157,11 +210,11 @@ export class RelayConnection { private _cleanupTab(tabId: number, shouldDetachDebugger: boolean): void { const tab = this._attachedTabs.get(tabId); if (!tab) { - debugLog('cleanupTab: tab not found in map:', tabId); + logger.debug('cleanupTab: tab not found in map:', tabId); return; } - debugLog('Cleaning up tab:', tabId, 'sessionId:', tab.sessionId, 'shouldDetach:', shouldDetachDebugger); + logger.debug('Cleaning up tab:', tabId, 'sessionId:', tab.sessionId, 'shouldDetach:', shouldDetachDebugger); this._sendMessage({ method: 'forwardCDPEvent', @@ -175,32 +228,32 @@ export class RelayConnection { }); this._attachedTabs.delete(tabId); - debugLog('Removed tab from _attachedTabs map. Remaining tabs:', this._attachedTabs.size); + logger.debug('Removed tab from _attachedTabs map. Remaining tabs:', this._attachedTabs.size); if (shouldDetachDebugger) { chrome.debugger.detach(tab.debuggee) .then(() => { - debugLog('Successfully detached debugger from tab:', tabId); + logger.debug('Successfully detached debugger from tab:', tabId); }) .catch((err) => { - debugLog('Error detaching debugger from tab:', tabId, err.message); + logger.debug('Error detaching debugger from tab:', tabId, err.message); }); } } close(message: string): void { - debugLog('Closing RelayConnection, reason:', message, 'current state:', this._ws.readyState); + logger.debug('Closing RelayConnection, reason:', message, 'current state:', this._ws.readyState); this._ws.close(1000, message); this._onClose(message, 1000); } private _onClose(reason: string = 'Unknown', code: number = 1000) { if (this._closed) { - debugLog('_onClose called but already closed'); + logger.debug('_onClose called but already closed'); return; } - debugLog('Connection closing, attached tabs count:', this._attachedTabs.size); + logger.debug('Connection closing, attached tabs count:', this._attachedTabs.size); this._closed = true; @@ -208,23 +261,26 @@ export class RelayConnection { chrome.debugger.onDetach.removeListener(this._onDebuggerDetach); const tabIds = Array.from(this._attachedTabs.keys()); - debugLog('Detaching all tabs:', tabIds); + logger.debug('Detaching all tabs:', tabIds); for (const [tabId, tab] of this._attachedTabs) { - debugLog('Detaching debugger from tab:', tabId); + logger.debug('Detaching debugger from tab:', tabId); chrome.debugger.detach(tab.debuggee) .then(() => { - debugLog('Successfully detached from tab:', tabId); + logger.debug('Successfully detached from tab:', tabId); }) .catch((err) => { - debugLog('Error detaching from tab:', tabId, err.message); + logger.debug('Error detaching from tab:', tabId, err.message); }); } this._attachedTabs.clear(); - debugLog('All tabs cleared from map. Chrome automation bar should disappear in a few seconds.'); + logger.debug('All tabs cleared from map. Chrome automation bar should disappear in a few seconds.'); - debugLog('Connection closed, calling onClose callback'); + logger.debug('Connection closed, calling onClose callback'); + if (activeConnection === this) { + activeConnection = undefined; + } this._onCloseCallback?.(reason, code); } @@ -238,17 +294,17 @@ export class RelayConnection { if (method === 'Runtime.executionContextCreated') { const contextEvent = params as Protocol.Runtime.ExecutionContextCreatedEvent; tab.executionContexts.set(contextEvent.context.id, contextEvent); - debugLog('Cached execution context:', contextEvent.context.id, 'for tab:', source.tabId, 'total contexts:', tab.executionContexts.size); + logger.debug('Cached execution context:', contextEvent.context.id, 'for tab:', source.tabId, 'total contexts:', tab.executionContexts.size); } else if (method === 'Runtime.executionContextDestroyed') { const destroyedEvent = params as Protocol.Runtime.ExecutionContextDestroyedEvent; tab.executionContexts.delete(destroyedEvent.executionContextId); - debugLog('Removed execution context:', destroyedEvent.executionContextId, 'from tab:', source.tabId, 'remaining:', tab.executionContexts.size); + logger.debug('Removed execution context:', destroyedEvent.executionContextId, 'from tab:', source.tabId, 'remaining:', tab.executionContexts.size); } else if (method === 'Runtime.executionContextsCleared') { tab.executionContexts.clear(); - debugLog('Cleared all execution contexts for tab:', source.tabId); + logger.debug('Cleared all execution contexts for tab:', source.tabId); } - debugLog('Forwarding CDP event:', method, 'from tab:', source.tabId); + logger.debug('Forwarding CDP event:', method, 'from tab:', source.tabId); this._sendMessage({ method: 'forwardCDPEvent', @@ -262,15 +318,15 @@ export class RelayConnection { private _onDebuggerDetach = (source: chrome.debugger.Debuggee, reason: `${chrome.debugger.DetachReason}`): void => { const tabId = source.tabId; - debugLog('_onDebuggerDetach called for tab:', tabId, 'reason:', reason, 'isAttached:', tabId ? this._attachedTabs.has(tabId) : false); + logger.debug('_onDebuggerDetach called for tab:', tabId, 'reason:', reason, 'isAttached:', tabId ? this._attachedTabs.has(tabId) : false); if (!tabId || !this._attachedTabs.has(tabId)) { - debugLog('Ignoring debugger detach event for untracked tab:', tabId); + logger.debug('Ignoring debugger detach event for untracked tab:', tabId); return; } - debugLog(`Manual debugger detachment detected for tab ${tabId}: ${reason}`); - debugLog('User closed debugger via Chrome automation bar, calling onTabDetached callback'); + logger.debug(`Manual debugger detachment detected for tab ${tabId}: ${reason}`); + logger.debug('User closed debugger via Chrome automation bar, calling onTabDetached callback'); this._onTabDetachedCallback?.(tabId, reason); this._cleanupTab(tabId, false); @@ -286,14 +342,14 @@ export class RelayConnection { if (msg.params.method === 'Target.createTarget') { const url = msg.params.params?.url || 'about:blank'; - debugLog('Creating new tab with URL:', url); + logger.debug('Creating new tab with URL:', url); const tab = await chrome.tabs.create({ url, active: false }); if (!tab.id) { throw new Error('Failed to create tab'); } - debugLog('Created tab:', tab.id, 'waiting for it to load...'); + logger.debug('Created tab:', tab.id, 'waiting for it to load...'); // Wait a bit for tab to initialize await new Promise(resolve => setTimeout(resolve, 100)); @@ -305,17 +361,17 @@ export class RelayConnection { } if (msg.params.method === 'Target.closeTarget' && msg.params.params?.targetId) { - debugLog('Closing target:', msg.params.params.targetId); + logger.debug('Closing target:', msg.params.params.targetId); for (const [tabId, tab] of this._attachedTabs) { if (tab.targetId === msg.params.params.targetId) { - debugLog('Found tab to close:', tabId); + logger.debug('Found tab to close:', tabId); await chrome.tabs.remove(tabId); return { success: true }; } } - debugLog('Target not found:', msg.params.params.targetId); + logger.debug('Target not found:', msg.params.params.targetId); throw new Error(`Target not found: ${msg.params.params.targetId}`); } @@ -338,7 +394,7 @@ export class RelayConnection { } } - debugLog('CDP command:', msg.params.method, 'for tab:', targetTab.debuggee.tabId); + logger.debug('CDP command:', msg.params.method, 'for tab:', targetTab.debuggee.tabId); const debuggerSession: chrome.debugger.DebuggerSession = { ...targetTab.debuggee, @@ -356,10 +412,10 @@ export class RelayConnection { // This causes page.evaluate() to hang because Playwright has no execution context IDs. // Solution: manually replay all cached contexts so Playwright gets fresh, valid IDs. if (msg.params.method === 'Runtime.enable' && targetTab.executionContexts.size > 0) { - debugLog('Runtime.enable called, replaying', targetTab.executionContexts.size, 'cached execution contexts for tab:', targetTab.debuggee.tabId); + logger.debug('Runtime.enable called, replaying', targetTab.executionContexts.size, 'cached execution contexts for tab:', targetTab.debuggee.tabId); for (const contextEvent of targetTab.executionContexts.values()) { - debugLog('Replaying execution context:', contextEvent.context.id); + logger.debug('Replaying execution context:', contextEvent.context.id); this._sendMessage({ method: 'forwardCDPEvent', params: { @@ -379,12 +435,12 @@ export class RelayConnection { if (this._ws.readyState === WebSocket.OPEN) { try { this._ws.send(JSON.stringify(message)); - debugLog('Message sent successfully, type:', message.method || 'response'); + // logger.debug('Message sent successfully, type:', message.method || 'response'); } catch (error: any) { - debugLog('ERROR sending message:', error, 'message type:', message.method || 'response'); + logger.debug('ERROR sending message:', error, 'message type:', message.method || 'response'); } } else { - debugLog('Cannot send message, WebSocket not open. State:', this._ws.readyState, 'message type:', message.method || 'response'); + logger.debug('Cannot send message, WebSocket not open. State:', this._ws.readyState, 'message type:', message.method || 'response'); } } } diff --git a/playwriter/src/extension/cdp-relay.ts b/playwriter/src/extension/cdp-relay.ts index 1dd0644..e306d76 100644 --- a/playwriter/src/extension/cdp-relay.ts +++ b/playwriter/src/extension/cdp-relay.ts @@ -379,6 +379,11 @@ export async function startPlayWriterCDPRelayServer({ port = 19988, host = '127. } else { pending.resolve(message.result) } + } else if (message.method === 'log') { + const { level, args } = message.params + const logFn = (logger as any)[level] || logger.log + const prefix = chalk.yellow(`[Extension] [${level.toUpperCase()}]`) + logFn(prefix, ...args) } else { const extensionEvent = message as ExtensionEventMessage diff --git a/playwriter/src/extension/protocol.ts b/playwriter/src/extension/protocol.ts index c1c3454..ac84f4f 100644 --- a/playwriter/src/extension/protocol.ts +++ b/playwriter/src/extension/protocol.ts @@ -44,4 +44,12 @@ export type ExtensionEventMessage = } }[keyof ProtocolMapping.Events] -export type ExtensionMessage = ExtensionResponseMessage | ExtensionEventMessage +export type ExtensionLogMessage = { + method: 'log' + params: { + level: 'log' | 'debug' | 'info' | 'warn' | 'error' + args: string[] + } +} + +export type ExtensionMessage = ExtensionResponseMessage | ExtensionEventMessage | ExtensionLogMessage