feat(debug): more logs while waiting for stable, enabled, etc. (#2531)

src/dom.ts

@@ -383,12 +383,14 @@ export class ElementHandle<T extends Node = Node> extends js.JSHandle<T> {
     progress.log(apiLog, `elementHandle.fill("${value}")`);
     assert(helper.isString(value), 'Value must be string. Found value "' + value + '" of type "' + (typeof value) + '"');
     await this._page._frameManager.waitForSignalsCreatedBy(progress, options.noWaitAfter, async () => {
+      progress.log(apiLog, '  waiting for element to be visible, enabled and editable');
       const poll = await this._evaluateHandleInUtility(([injected, node, value]) => {
         return injected.waitForEnabledAndFill(node, value);
       }, value);
       const pollHandler = new InjectedScriptPollHandler(progress, poll);
       const injectedResult = await pollHandler.finish();
       const needsInput = handleInjectedResult(injectedResult);
+      progress.log(apiLog, '  element is visible, enabled and editable');
       progress.throwIfAborted();  // Avoid action that has side-effects.
       if (needsInput) {
         if (value)
@@ -535,7 +537,7 @@ export class ElementHandle<T extends Node = Node> extends js.JSHandle<T> {
   }
 
   async _waitForDisplayedAtStablePositionAndEnabled(progress: Progress): Promise<void> {
-    progress.log(apiLog, '  waiting for element to be displayed, enabled and not moving');
+    progress.log(apiLog, '  waiting for element to be visible, enabled and not moving');
     const rafCount =  this._page._delegate.rafCountForStablePosition();
     const poll = this._evaluateHandleInUtility(([injected, node, rafCount]) => {
       return injected.waitForDisplayedAtStablePositionAndEnabled(node, rafCount);
@@ -543,7 +545,7 @@ export class ElementHandle<T extends Node = Node> extends js.JSHandle<T> {
     const pollHandler = new InjectedScriptPollHandler<types.InjectedScriptResult>(progress, await poll);
     const injectedResult = await pollHandler.finish();
     handleInjectedResult(injectedResult);
-    progress.log(apiLog, '  element is displayed and does not move');
+    progress.log(apiLog, '  element is visible, enabled and does not move');
   }
 
   async _checkHitTargetAt(point: types.Point): Promise<boolean> {

src/injected/injectedScript.ts

@@ -161,12 +161,18 @@ export default class InjectedScript {
       };
     });
 
+    let lastLog = '';
     const progress: types.InjectedScriptProgress = {
       canceled: false,
       log: (message: string) => {
+        lastLog = message;
         currentLogs.push(message);
         logReady();
       },
+      logRepeating: (message: string) => {
+        if (message !== lastLog)
+          progress.log(message);
+      },
     };
 
     // It is important to create logs promise before running the poll to capture logs from the first run.
@@ -225,14 +231,16 @@ export default class InjectedScript {
   }
 
   waitForEnabledAndFill(node: Node, value: string): types.InjectedScriptPoll<types.InjectedScriptResult<boolean>> {
-    return this.poll('raf', () => {
+    return this.poll('raf', progress => {
       if (node.nodeType !== Node.ELEMENT_NODE)
         return { status: 'error', error: 'Node is not of type HTMLElement' };
       const element = node as HTMLElement;
       if (!element.isConnected)
         return { status: 'notconnected' };
-      if (!this.isVisible(element))
+      if (!this.isVisible(element)) {
+        progress.logRepeating('    element is not visible - waiting...');
         return false;
+      }
       if (element.nodeName.toLowerCase() === 'input') {
         const input = element as HTMLInputElement;
         const type = (input.getAttribute('type') || '').toLowerCase();
@@ -245,10 +253,14 @@ export default class InjectedScript {
           if (isNaN(Number(value)))
             return { status: 'error', error: 'Cannot type text into input[type=number].' };
         }
-        if (input.disabled)
+        if (input.disabled) {
+          progress.logRepeating('    element is disabled - waiting...');
           return false;
-        if (input.readOnly)
+        }
+        if (input.readOnly) {
+          progress.logRepeating('    element is readonly - waiting...');
           return false;
+        }
         if (kDateTypes.has(type)) {
           value = value.trim();
           input.focus();
@@ -261,10 +273,14 @@ export default class InjectedScript {
         }
       } else if (element.nodeName.toLowerCase() === 'textarea') {
         const textarea = element as HTMLTextAreaElement;
-        if (textarea.disabled)
+        if (textarea.disabled) {
+          progress.logRepeating('    element is disabled - waiting...');
           return false;
-        if (textarea.readOnly)
+        }
+        if (textarea.readOnly) {
+          progress.logRepeating('    element is readonly - waiting...');
           return false;
+        }
       } else if (!element.isContentEditable) {
         return { status: 'error', error: 'Element is not an <input>, <textarea> or [contenteditable] element.' };
       }
@@ -392,13 +408,15 @@ export default class InjectedScript {
         // Note: this logic should be similar to isVisible() to avoid surprises.
         const clientRect = element.getBoundingClientRect();
         const rect = { x: clientRect.top, y: clientRect.left, width: clientRect.width, height: clientRect.height };
-        const samePosition = lastRect && rect.x === lastRect.x && rect.y === lastRect.y && rect.width === lastRect.width && rect.height === lastRect.height && rect.width > 0 && rect.height > 0;
+        const samePosition = lastRect && rect.x === lastRect.x && rect.y === lastRect.y && rect.width === lastRect.width && rect.height === lastRect.height;
-        lastRect = rect;
+        const isDisplayed = rect.width > 0 && rect.height > 0;
         if (samePosition)
           ++samePositionCounter;
         else
           samePositionCounter = 0;
-        const isDisplayedAndStable = samePositionCounter >= rafCount;
+        const isStable = samePositionCounter >= rafCount;
+        const isStableForLogs = isStable || !lastRect;
+        lastRect = rect;
 
         const style = element.ownerDocument && element.ownerDocument.defaultView ? element.ownerDocument.defaultView.getComputedStyle(element) : undefined;
         const isVisible = !!style && style.visibility !== 'hidden';
@@ -406,7 +424,16 @@ export default class InjectedScript {
         const elementOrButton = element.closest('button, [role=button]') || element;
         const isDisabled = ['BUTTON', 'INPUT', 'SELECT'].includes(elementOrButton.nodeName) && elementOrButton.hasAttribute('disabled');
 
-        return isDisplayedAndStable && isVisible && !isDisabled ? { status: 'success' } : false;
+        if (isDisplayed && isStable && isVisible && !isDisabled)
+          return { status: 'success' };
+
+        if (!isDisplayed || !isVisible)
+          progress.logRepeating(`    element is not visible - waiting...`);
+        else if (!isStableForLogs)
+          progress.logRepeating(`    element is moving - waiting...`);
+        else if (isDisabled)
+          progress.logRepeating(`    element is disabled - waiting...`);
+        return false;
       });
     });
   }

src/types.ts

@@ -170,6 +170,7 @@ export type InjectedScriptResult<T = undefined> =
 export type InjectedScriptProgress = {
   canceled: boolean,
   log: (message: string) => void,
+  logRepeating: (message: string) => void,
 };
 
 export type InjectedScriptLogs = { current: string[], next: Promise<InjectedScriptLogs> };

test/click.spec.js

@@ -189,14 +189,16 @@ describe('Page.click', function() {
     await page.$eval('button', b => b.style.display = 'none');
     const error = await page.click('button', { timeout: 5000 }).catch(e => e);
     expect(error.message).toContain('Timeout 5000ms exceeded during page.click.');
-    expect(error.message).toContain('waiting for element to be displayed, enabled and not moving');
+    expect(error.message).toContain('waiting for element to be visible, enabled and not moving');
+    expect(error.message).toContain('element is not visible - waiting');
   });
   it('should timeout waiting for visbility:hidden to be gone', async({page, server}) => {
     await page.goto(server.PREFIX + '/input/button.html');
     await page.$eval('button', b => b.style.visibility = 'hidden');
     const error = await page.click('button', { timeout: 5000 }).catch(e => e);
     expect(error.message).toContain('Timeout 5000ms exceeded during page.click.');
-    expect(error.message).toContain('waiting for element to be displayed, enabled and not moving');
+    expect(error.message).toContain('waiting for element to be visible, enabled and not moving');
+    expect(error.message).toContain('element is not visible - waiting');
   });
   it('should waitFor visible when parent is hidden', async({page, server}) => {
     let done = false;
@@ -438,7 +440,8 @@ describe('Page.click', function() {
     });
     const error = await button.click({ timeout: 5000 }).catch(e => e);
     expect(error.message).toContain('Timeout 5000ms exceeded during elementHandle.click.');
-    expect(error.message).toContain('waiting for element to be displayed, enabled and not moving');
+    expect(error.message).toContain('waiting for element to be visible, enabled and not moving');
+    expect(error.message).toContain('element is moving - waiting');
   });
   it('should wait for becoming hit target', async({page, server}) => {
     await page.goto(server.PREFIX + '/input/button.html');
@@ -517,6 +520,13 @@ describe('Page.click', function() {
     await clickPromise;
     expect(await page.evaluate(() => window.__CLICKED)).toBe(true);
   });
+  it('should timeout waiting for button to be enabled', async({page, server}) => {
+    await page.setContent('<button onclick="javascript:window.__CLICKED=true;" disabled><span>Click target</span></button>');
+    const error = await page.click('text=Click target', { timeout: 3000 }).catch(e => e);
+    expect(await page.evaluate(() => window.__CLICKED)).toBe(undefined);
+    expect(error.message).toContain('Timeout 3000ms exceeded during page.click.');
+    expect(error.message).toContain('element is disabled - waiting');
+  });
   it('should wait for input to be enabled', async({page, server}) => {
     await page.setContent('<input onclick="javascript:window.__CLICKED=true;" disabled>');
     let done = false;