From 26ddeb2a7b341c16389cd8f798995bb34366ef8f Mon Sep 17 00:00:00 2001 From: "Tommy D. Rossi" Date: Tue, 3 Feb 2026 22:01:44 +0100 Subject: [PATCH] more logging --- playwriter/src/aria-snapshot.ts | 44 ++++++++++++++++++++------------- playwriter/src/cdp-relay.ts | 40 +++++++++++++++--------------- 2 files changed, 47 insertions(+), 37 deletions(-) diff --git a/playwriter/src/aria-snapshot.ts b/playwriter/src/aria-snapshot.ts index 8ba7101..4711a07 100644 --- a/playwriter/src/aria-snapshot.ts +++ b/playwriter/src/aria-snapshot.ts @@ -1069,12 +1069,19 @@ async function getLabelBoxesForRefs({ logger?: { info?: (...args: unknown[]) => void; error?: (...args: unknown[]) => void } cdp?: ICDPSession }): Promise { + const log = logger?.info ?? logger?.error ?? console.error const session = cdp || await getCDPSessionForPage({ page, wsUrl }) const sema = new Sema(maxConcurrency) const labelRefs = refs.filter((ref) => { return Boolean(ref.backendNodeId) && INTERACTIVE_ROLES.has(ref.role) }) + log(`[getLabelBoxesForRefs] processing ${labelRefs.length} interactive refs (concurrency: ${maxConcurrency})`) + const startTime = Date.now() + let completed = 0 + let timedOut = 0 + let failed = 0 + try { const labels = await Promise.all( labelRefs.map(async (ref) => { @@ -1089,8 +1096,12 @@ async function getLabelBoxesForRefs({ setTimeout(() => { resolve(null) }, BOX_MODEL_TIMEOUT_MS) }), ]) + completed++ + if (completed % 50 === 0 || completed === labelRefs.length) { + log(`[getLabelBoxesForRefs] progress: ${completed}/${labelRefs.length} (${timedOut} timeouts, ${failed} errors) - ${Date.now() - startTime}ms`) + } if (!response) { - logger?.error?.('[playwriter] getBoxModel timed out for', ref.ref) + timedOut++ return null } const box = buildBoxFromQuad(response.model.border) @@ -1099,13 +1110,15 @@ async function getLabelBoxesForRefs({ } return { ref: ref.ref, role: ref.role, box } } catch (error) { - logger?.error?.('[playwriter] getBoxModel failed for', ref.ref, error) + completed++ + failed++ return null } finally { sema.release() } }) ) + log(`[getLabelBoxesForRefs] done: ${completed} completed, ${timedOut} timeouts, ${failed} errors - ${Date.now() - startTime}ms`) return labels.filter(isTruthy) } finally { if (!cdp) { @@ -1145,24 +1158,24 @@ export async function showAriaRefLabels({ page, locator, interactiveOnly = true, labelCount: number }> { const startTime = Date.now() + const log = logger?.info ?? logger?.error ?? console.error + + log(`[showAriaRefLabels] starting...`) await ensureA11yClient(page) + log(`[showAriaRefLabels] ensureA11yClient: ${Date.now() - startTime}ms`) - const log = logger?.info ?? logger?.error - if (log) { - log(`ensureA11yClient: ${Date.now() - startTime}ms`) - } - - const snapshotStart = Date.now() + const cdpStart = Date.now() const cdp = await getCDPSessionForPage({ page, wsUrl }) + log(`[showAriaRefLabels] getCDPSessionForPage: ${Date.now() - cdpStart}ms`) try { + const snapshotStart = Date.now() const { snapshot, refs } = await getAriaSnapshot({ page, locator, interactiveOnly, wsUrl, cdp }) const shortRefMap = new Map(refs.map((entry) => { return [entry.ref, entry.shortRef] })) - if (log) { - log(`getAriaSnapshot: ${Date.now() - snapshotStart}ms`) - } + const interactiveRefs = refs.filter((ref) => Boolean(ref.backendNodeId) && INTERACTIVE_ROLES.has(ref.role)) + log(`[showAriaRefLabels] getAriaSnapshot: ${Date.now() - snapshotStart}ms (${refs.length} refs, ${interactiveRefs.length} interactive)`) const rootHandle = locator ? await locator.elementHandle() : null @@ -1174,9 +1187,7 @@ export async function showAriaRefLabels({ page, locator, interactiveOnly = true, ref: shortRefMap.get(label.ref) ?? label.ref, } }) - if (log) { - log(`getLabelBoxesForRefs: ${Date.now() - labelsStart}ms (${labels.length} boxes)`) - } + log(`[showAriaRefLabels] getLabelBoxesForRefs: ${Date.now() - labelsStart}ms (${labels.length} boxes)`) const renderStart = Date.now() const labelCount = await page.evaluate(({ entries, root, interactiveOnly: intOnly }) => { @@ -1196,9 +1207,8 @@ export async function showAriaRefLabels({ page, locator, interactiveOnly = true, throw new Error('a11y client not loaded') }, { entries: shortLabels, root: rootHandle, interactiveOnly }) - if (log) { - log(`renderA11yLabels: ${Date.now() - renderStart}ms (${labelCount} labels)`) - } + log(`[showAriaRefLabels] renderA11yLabels: ${Date.now() - renderStart}ms (${labelCount} labels)`) + log(`[showAriaRefLabels] total: ${Date.now() - startTime}ms`) return { snapshot, labelCount } } finally { diff --git a/playwriter/src/cdp-relay.ts b/playwriter/src/cdp-relay.ts index 21f7b2e..25e09df 100644 --- a/playwriter/src/cdp-relay.ts +++ b/playwriter/src/cdp-relay.ts @@ -1116,61 +1116,61 @@ export async function startPlayWriterCDPRelayServer({ // ============================================================================ // CLI Execute Endpoints - For stateful code execution via CLI // ============================================================================ - + // Session counter for suggesting next session number let nextSessionNumber = 1 - + // Lazy-load ExecutorManager to avoid circular imports and only when needed let executorManager: import('./executor.js').ExecutorManager | null = null - + const getExecutorManager = async () => { if (!executorManager) { const { ExecutorManager } = await import('./executor.js') // Pass config instead of URL so executor can generate unique client IDs for each connection executorManager = new ExecutorManager({ cdpConfig: { host: '127.0.0.1', port }, - logger: logger || { log: console.log, error: console.error }, + logger: logger || { log: console.error, error: console.error }, }) } return executorManager } - + app.post('/cli/execute', async (c) => { try { const body = await c.req.json() as { sessionId: string; code: string; timeout?: number; cwd?: string } const { sessionId, code, timeout = 10000, cwd } = body - + if (!sessionId || !code) { return c.json({ error: 'sessionId and code are required' }, 400) } - + const manager = await getExecutorManager() const executor = manager.getExecutor(sessionId, cwd) const result = await executor.execute(code, timeout) - + // Increment session counter after each execution to avoid conflicts nextSessionNumber++ - + return c.json(result) } catch (error: any) { logger?.error('Execute endpoint error:', error) return c.json({ text: `Server error: ${error.message}`, images: [], isError: true }, 500) } }) - + app.post('/cli/reset', async (c) => { try { const body = await c.req.json() as { sessionId: string; cwd?: string } const { sessionId, cwd } = body - + if (!sessionId) { return c.json({ error: 'sessionId is required' }, 400) } - + const manager = await getExecutorManager() const executor = manager.getExecutor(sessionId, cwd) const { page, context } = await executor.reset() - + return c.json({ success: true, pageUrl: page.url(), @@ -1181,32 +1181,32 @@ export async function startPlayWriterCDPRelayServer({ return c.json({ error: error.message }, 500) } }) - + app.get('/cli/sessions', async (c) => { const manager = await getExecutorManager() return c.json({ sessions: manager.listSessions() }) }) - + app.get('/cli/session/suggest', (c) => { return c.json({ next: nextSessionNumber }) }) - + app.post('/cli/session/delete', async (c) => { try { const body = await c.req.json() as { sessionId: string } const { sessionId } = body - + if (!sessionId) { return c.json({ error: 'sessionId is required' }, 400) } - + const manager = await getExecutorManager() const deleted = manager.deleteExecutor(sessionId) - + if (!deleted) { return c.json({ error: `Session ${sessionId} not found` }, 404) } - + return c.json({ success: true }) } catch (error: any) { logger?.error('Delete session endpoint error:', error)