Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

waitUntil may not wait when used in a custom command #3753

Open
reallymello opened this issue May 25, 2023 · 11 comments
Open

waitUntil may not wait when used in a custom command #3753

reallymello opened this issue May 25, 2023 · 11 comments

Comments

@reallymello
Copy link
Contributor

reallymello commented May 25, 2023

Description of the bug/issue

When I use waitUntil in a custom command I expect the test to waitUntil evaluates to true and exits or times out, but the test runs through it as waitUntil continues to execute sometimes even after the browser session is closed due to the test completing.

It seems to be related to what I am looping on/what commands I am using inside the body of the waitUntil. I noticed the behavior when using browser.execute, but not with other methods.

Steps to reproduce

  1. Checkout https://github.com/reallymello/nightwatchTutorials/blob/master/nw30typescriptExample/
  2. npm install followed by npx nightwatch -t "nightwatch/tests/notWaiting.ts" --headless

The test on line 14 is running dropDownPage.problemCommand(...) asserting the wrong title. "problemCommand" is a custom command that uses waitUntil to wait until the title equals the expectation. It gets the title using browser.execute inside the waitUntil body. The test is purposefully using the wrong title. For diagnostics, it is also logging the title of the page each time waitUntil loops.

You can see in the screenshot it logs the title "The Internet" twice, but then falls through to the remainder of the script and passes the test. It should have remained there and failed the test since the title will never match. The command keeps running after the browser closes causing the Error Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

image

If you comment out line 14 and uncomment the equivalent code on lines 15-21 the test will work as expected

image

image

image

Sample test

https://github.com/reallymello/nightwatchTutorials/blob/master/nw30typescriptExample/nightwatch/tests/notWaiting.ts

Command to run

npx nightwatch -t "nightwatch/tests/notWaiting.ts" --headless

Verbose Output

npx nightwatch -t "nightwatch/tests/notWaiting.ts" --headless --verbose
 Now you can run TS tests directly using Nightwatch.


[Not Waiting] Test Suite
────────────────────────────────────────────────
⠋ Starting ChromeDriver on port 9515...
 Starting ChromeDriver with server_path=C:\Projects\nightwatchTutorials\nw30typescriptExample\node_modules\chromedriver\lib\chromedriver\chromedriver.exe...
   Request POST /session  
   {
     capabilities: {
       firstMatch: [ {} ],
       alwaysMatch: {
         browserName: 'chrome',
         'goog:chromeOptions': { args: [ 'headless=new' ] }
       }
     }
⠹ Starting ChromeDriver on port 9515...
DevTools listening on ws://127.0.0.1:53397/devtools/browser/34059c69-9c52-4243-a270-f9758e0b232e
⠧ Starting ChromeDriver on port 9515...
   Response 200 POST /session (624ms)
   {
     value: {
       capabilities: {
         acceptInsecureCerts: false,
         browserName: 'chrome',
         browserVersion: '113.0.5672.127',
         chrome: {
           chromedriverVersion: '113.0.5672.63 (0e1a4471d5ae5bf128b1bd8f4d627c8cbd55f70c-refs/branch-heads/5672@{#912})',
           userDataDir: 'C:\\Users\\Mr\\AppData\\Local\\Temp\\scoped_dir21516_571968051'
         },
         'goog:chromeOptions': { debuggerAddress: 'localhost:53397' },
         networkConnectionEnabled: false,
         pageLoadStrategy: 'normal',
         platformName: 'windows',
         proxy: {},
         setWindowRect: true,
         strictFileInteractability: false,
         timeouts: { implicit: 0, pageLoad: 300000, script: 30000 },
         unhandledPromptBehavior: 'dismiss and notify',
         'webauthn:extension:credBlob': true,
         'webauthn:extension:largeBlob': true,
         'webauthn:extension:minPinLength': true,
         'webauthn:extension:prf': true,
         'webauthn:virtualAuthenticators': true
       },
       sessionId: 'bf4bcb60b5776bde381216d05846b6f1'
     }
ℹ Connected to ChromeDriver on port 9515 (703ms).
  Using: chrome (113.0.5672.127) on WINDOWS.

 Received session with ID: bf4bcb60b5776bde381216d05846b6f1

 → Running [before]:
 → Completed [before].



  Running Not waiting:
───────────────────────────────────────────────────────────────────────────────────────────────────
 → Running [beforeEach]:
 → Completed [beforeEach].
 → Running [afterEach]:
 
 → Running command: url ('http://the-internet.herokuapp.com/dropdown', )
  ⠋ Loading url: http://the-internet.herokuapp.com/dropdown
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/url  
  ⠦ Loading url: http://the-internet.herokuapp.com/dropdown
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/url (576ms)
  ℹ Loaded url http://the-internet.herokuapp.com/dropdown in 578ms
 → Completed command: url ('http://the-internet.herokuapp.com/dropdown', ) (580ms)

 → Running command: waitForLoadScreen (10000)

 → Running command: expect.element ('#loadScreenOverlay')
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/elements  
   { using: 'css selector', value: '#loadScreenOverlay' }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/elements (13ms)
   { value: [] }
  √ Expected element <#loadScreenOverlay> to not be present in 10000ms - element was not found (16ms)
 → Completed command: expect.element ('#loadScreenOverlay') (19ms)
 → Completed command: waitForLoadScreen (10000) (24ms)

 → Running command: expect.element ({name, __index, __selector, locateStrategy, pseudoSelector, parent, resolvedElement, abortOnFailure, suppressNotFoundErrors, timeout...})
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/elements  
   { using: 'css selector', value: '#dropdown' }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/elements (12ms)
   {
     value: [
       {
         'element-6066-11e4-a52e-4f735466cecf': '80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3'
       }
     ]
  }
   Request GET /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/property/value  

   Response 200 GET /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/property/value (6ms)
   { value: '' }
  √ Expected element @dropDown <#dropdown> to have value equal: "" (23ms)
 → Completed command: expect.element ({name, __index, __selector, locateStrategy, pseudoSelector, parent, resolvedElement, abortOnFailure, suppressNotFoundErrors, timeout...}) (24ms)

 → Running command: problemCommand ('Not the title I was expecting')
 → Completed command: problemCommand ('Not the title I was expecting') (1ms)

 → Running command: waitUntil ([Function])
 
 → Running command: execute ([Function])
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/execute/sync  
   {
     script: 'var passedArgs = Array.prototype.slice.call(arguments,0); return (function () {\n' +
       '                return document.title;\n' +
       '            }).apply(window, passedArgs);... (160 characters)',
     args: []
  }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/execute/sync (7ms)
   { value: 'The Internet' }
 → Completed command: execute ([Function]) (8ms)
The Internet
 
 → Running command: execute ([Function])
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/execute/sync  
   {
     script: 'var passedArgs = Array.prototype.slice.call(arguments,0); return (function () {\n' +
       '                return document.title;\n' +
       '            }).apply(window, passedArgs);... (160 characters)',
     args: []
  }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/execute/sync (7ms)
   { value: 'The Internet' }
 → Completed command: execute ([Function]) (9ms)

 → Running command: setValue ({name, __index, __selector, locateStrategy, pseudoSelector, parent, resolvedElement, abortOnFailure, suppressNotFoundErrors, timeout...}, 'Option 2')
The Internet
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/elements  
   { using: 'css selector', value: '#dropdown' }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/elements (9ms)
   {
     value: [
       {
         'element-6066-11e4-a52e-4f735466cecf': '80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3'
       }
     ]
  }
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/clear  
{}
   Response 400 POST /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/clear (13ms)
   {
     value: {
       error: 'invalid element state',
       message: 'invalid element state\n  (Session info: chrome=113.0.5672.127)',
       stacktrace: ''
     }
  }
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/value  
   {
     text: 'Option 2',
     value: [
       'O', 'p', 't',
       'i', 'o', 'n',
       ' ', '2'
     ]
  }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/value (46ms)
   { value: null }
 → Completed command: setValue ({name, __index, __selector, locateStrategy, pseudoSelector, parent, resolvedElement, abortOnFailure, suppressNotFoundErrors, timeout...}, 'Option 2') (77ms)

 → Running command: expect.element ({name, __index, __selector, locateStrategy, pseudoSelector, parent, resolvedElement, abortOnFailure, suppressNotFoundErrors, timeout...})
   Request POST /session/bf4bcb60b5776bde381216d05846b6f1/elements  
   { using: 'css selector', value: '#dropdown' }
   Response 200 POST /session/bf4bcb60b5776bde381216d05846b6f1/elements (10ms)
   {
     value: [
       {
         'element-6066-11e4-a52e-4f735466cecf': '80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3'
       }
     ]
  }
   Request GET /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/property/value  

   Response 200 GET /session/bf4bcb60b5776bde381216d05846b6f1/element/80D18E3D8E6AC800FCE0BCFFCD0315A8_element_3/property/value (7ms)
   { value: '2' }
  √ Expected element @dropDown <#dropdown> to have value equal: "2" (20ms)
 → Completed command: expect.element ({name, __index, __selector, locateStrategy, pseudoSelector, parent, resolvedElement, abortOnFailure, suppressNotFoundErrors, timeout...}) (20ms)
 → Completed [afterEach].

  ✨ PASSED. 3 assertions. (1.314s)
 → Running [after]:
 → Completed [after].
 
 → Running command: end (true)
 
 → Running command: session ('delete', [Function])
   Request DELETE /session/bf4bcb60b5776bde381216d05846b6f1  

   Response 200 DELETE /session/bf4bcb60b5776bde381216d05846b6f1 (36ms)
   { value: null }
 → Completed command: end (true) (54ms)
 → Completed command: session ('delete', [Function]) (40ms)
 Wrote HTML report file to: C:\Projects\nightwatchTutorials\nw30typescriptExample\tests_output\nightwatch-html-report\index.html

 Wrote JSON report file to: C:\Projects\nightwatchTutorials\nw30typescriptExample\tests_output\CHROME_113.0.5672.127__notWaiting.json
 Wrote XML report file to: C:\Projects\nightwatchTutorials\nw30typescriptExample\tests_output\CHROME_113.0.5672.127__notWaiting.xml
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (2ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
 
 → Running command: execute ([Function])
    Error   Error while running .executeScript() protocol action: This driver instance does not have a valid session ID (did you call WebDriver.quit()?) and may no longer be used.

 → Completed command: execute ([Function]) (1ms)
null
    Error   Error while running .wait() protocol action: Wait timed out after 5263ms

  TimeoutError
   Wait timed out after 5263ms

Nightwatch Configuration

// Refer to the online docs for more details:
// https://nightwatchjs.org/gettingstarted/configuration/
//

//  _   _  _         _      _                     _          _
// | \ | |(_)       | |    | |                   | |        | |
// |  \| | _   __ _ | |__  | |_ __      __  __ _ | |_   ___ | |__
// | . ` || | / _` || '_ \ | __|\ \ /\ / / / _` || __| / __|| '_ \
// | |\  || || (_| || | | || |_  \ V  V / | (_| || |_ | (__ | | | |
// \_| \_/|_| \__, ||_| |_| \__|  \_/\_/   \__,_| \__| \___||_| |_|
//             __/ |
//            |___/

module.exports = {
  // An array of folders (excluding subfolders) where your tests are located;
  // if this is not specified, the test source must be passed as the second argument to the test runner.
  src_folders: ['nightwatch/tests'],

  // See https://nightwatchjs.org/guide/concepts/page-object-model.html
  page_objects_path: ['nightwatch/page-objects'],

  // See https://nightwatchjs.org/guide/extending-nightwatch/adding-custom-commands.html
  custom_commands_path: ['nightwatch/commands'],

  // See https://nightwatchjs.org/guide/extending-nightwatch/adding-custom-assertions.html
  custom_assertions_path: [],

  // See https://nightwatchjs.org/guide/extending-nightwatch/adding-plugins.html
  plugins: [],

  // See https://nightwatchjs.org/guide/concepts/test-globals.html
  globals_path: '',

  webdriver: {},

  test_workers: {
    enabled: true,
  },

  test_settings: {
    default: {
      disable_error_log: false,
      launch_url: 'http://localhost',

      screenshots: {
        enabled: false,
        path: 'screens',
        on_failure: true,
      },

      desiredCapabilities: {
        browserName: 'chrome',
      },

      webdriver: {
        start_process: true,
        server_path: '',
      },
    },

    chrome: {
      desiredCapabilities: {
        browserName: 'chrome',
        'goog:chromeOptions': {
          // More info on Chromedriver: https://sites.google.com/a/chromium.org/chromedriver/
          //
          // w3c:false tells Chromedriver to run using the legacy JSONWire protocol (not required in Chrome 78)
          w3c: true,
          args: [
            //'--no-sandbox',
            //'--ignore-certificate-errors',
            //'--allow-insecure-localhost',
            //'--headless'
          ],
        },
      },

      webdriver: {
        start_process: true,
        server_path: '',
        cli_args: [
          // --verbose
        ],
      },
    },
  },
};

Nightwatch.js Version

3.0.0-beta.1

Node Version

18.16.0

Browser

Chrome 113

Operating System

Windows

Additional Information

Happens on 2.6.21 and the 3.0 beta. Not sure if it is related to #3741

@reallymello
Copy link
Contributor Author

I forgot to mention I did try adding await in front of browser.waitUntil and/or the use of the command in the test and it does not help.

image

@beatfactor
Copy link
Member

Ok, but if the command is async then await should be used.

@reallymello
Copy link
Contributor Author

reallymello commented May 25, 2023

Agreed, but after going through all sorts of different iterations and not having expected behavior I started second-guessing how this command maybe was supposed to work with async await, but I guess it turned out to be this bug I'm reporting.

@beatfactor
Copy link
Member

This is also related. @garg3133 has some more context.

#3511

@garg3133
Copy link
Member

garg3133 commented May 27, 2023

@gravityvi This does not seem to me like a selenium issue, but an issue with Nightwatch itself. I'm saying this because I did some fresh investigations and it seems that the working of waitUntil depends on whether the command written after waitUntil is chained together with waitUntil or written separately using await.

The following code works fine (the waitUntil condition function keeps on running again and again until the function resolves to true or waitUntil times out):

it('demo waitUntil', async function () {
  browser
    .navigateTo('https://ecosia.org')
    .waitUntil(async () => {
      const title = await browser.execute(function () {
        return document.title;
      });
      console.log(title);
      return title === 'Not the title I was expecting';
    })
    .findElement('input[type=search]');
});

But in the following code, the waitUntil condition function runs only once and then the commands after waitUntil starts to execute, while the waitUntil condition function keeps on running in the background until true is returned or waitUntil is timed out.

it('demo waitUntil', async function () {
  browser
    .navigateTo('https://ecosia.org')
    .waitUntil(async () => {
      const title = await browser.execute(function () {
        return document.title;
      });
      console.log(title);
      return title === 'Not the title I was expecting';
    })

    await browser.findElement('input[type=search]');
});

I've also updated #3511 with the new findings (added a new sample code in the issue description which works fine with async/await).

@garg3133
Copy link
Member

garg3133 commented May 27, 2023

And a workaround for @reallymello, if you chain the waitUntil in your custom-command with any random command from Nightwatch API, your test should work fine.

Below, I've chained waitUntil() with getTitle() command and it works as expected:

// nightwatch/commands/problemCommand.ts
export default class WaitForLoadScreen {
  async command(this: NightwatchClient, expectedTitle: string) {
    browser.waitUntil(async () => {
      const title = await browser.execute(function () {
        return document.title;
      });
      console.log(title);
      return title === expectedTitle;
    }).getTitle();
  }
}

@reallymello
Copy link
Contributor Author

@garg3133 thanks I will try the workaround. Can you also clarify since the custom command is async if the test using it needs to call it with await or if Nightwatch handles that for me?

For example, which is correct, 1 or 2?

it('demo waitUntil', async function () {
  browser.navigateTo('https://ecosia.org');
  browser.waitForLoadScreen(); // the async command inclusive of the workaround/fix
  browser.click('#something`);
}
it('demo waitUntil', async function () {
  browser.navigateTo('https://ecosia.org');
  await browser.waitForLoadScreen(); // the async command inclusive of the workaround/fix
  browser.click('#something`);
}

@beatfactor
Copy link
Member

@garg3133 Yes, I observed the same and I'm using the same workaround in the Vite plugin. It is definitely an issue with Nightwatch, but looking at the waitUntil implementation everything looks as it should be, so the only thing that must be causing this is the queuing system.

@garg3133
Copy link
Member

garg3133 commented May 27, 2023

@reallymello No, you don't necessarily need to use await if a custom-command created by you is async, Nightwatch handles all that internally. So, both the examples provided by you are correct.

@garg3133
Copy link
Member

@beatfactor Yes, it definitely seems to be an issue with the queuing system. What happens here is that when an async callback is passed to waitUntil command, as soon as the first execution of the callback resolves, waitUntil command resolves as well with some result and the commands following the waitUntil starts to execute, while the callback to waitUntil command keeps on executing in the background until it resolves to true. But this does not happen if the next command is chained to waitUntil.

@beatfactor
Copy link
Member

I wonder if we could fix this for now by wrapping the entire waitUntil command implementation in a setTimeout()? I think that would fix it until we have a better fix for the queueing system.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants