webdriverio/webdriverio
View on GitHub[🐛 Bug]: devtools-service : when I do an action on the site with getPerformance it goes into a timeout and I cannot continue
Open
#7,918 opened on Jan 14, 2022
Bug 🐛Needs Investigationhelp wanted
Description
Have you read the Contributing Guidelines on issues?
- I have read the Contributing Guidelines on issues.
WebdriverIO Version
7.16.13
Node.js Version
14
Mode
WDIO Testrunner
Which capabilities are you using?
capabilities: [{
// maxInstances can get overwritten per capability. So if you have an in-house Selenium
// grid with only 5 firefox instances available you can make sure that not more than
// 5 instances get started at a time.
maxInstances: 5,
//
browserName: 'chrome',
acceptInsecureCerts: true
// If outputDir is provided WebdriverIO can capture driver session logs
// it is possible to configure which logTypes to include/exclude.
// excludeDriverLogs: ['*'], // pass '*' to exclude all driver session logs
// excludeDriverLogs: ['bugreport', 'server'],
}],
//
// ===================
// Test Configurations
// ===================
// Define all options that are relevant for the WebdriverIO instance here
//
// Level of logging verbosity: trace | debug | info | warn | error | silent
logLevel: 'info',
//
// Set specific log levels per logger
// loggers:
// - webdriver, webdriverio
// - @wdio/browserstack-service, @wdio/devtools-service, @wdio/sauce-service
// - @wdio/mocha-framework, @wdio/jasmine-framework
// - @wdio/local-runner
// - @wdio/sumologic-reporter
// - @wdio/cli, @wdio/config, @wdio/utils
// Level of logging verbosity: trace | debug | info | warn | error | silent
// logLevels: {
// webdriver: 'info',
// '@wdio/appium-service': 'info'
// },
//
// If you only want to run your tests until a specific amount of tests have failed use
// bail (default is 0 - don't bail, run all tests).
bail: 0,
//
// Set a base URL in order to shorten url command calls. If your `url` parameter starts
// with `/`, the base url gets prepended, not including the path portion of your baseUrl.
// If your `url` parameter starts without a scheme or `/` (like `some/path`), the base url
// gets prepended directly.
baseUrl: 'http://localhost',
//
// Default timeout for all waitFor* commands.
waitforTimeout: 10000,
//
// Default timeout in milliseconds for request
// if browser driver or grid doesn't send response
connectionRetryTimeout: 120000,
//
// Default request retries count
connectionRetryCount: 3,
//
// Test runner services
// Services take over a specific job you don't want to take care of. They enhance
// your test setup with almost no effort. Unlike plugins, they don't add new
// commands. Instead, they hook themselves up into the test process.
services: ['chromedriver', 'devtools'],
What happened?
Hello
I activate the enablePerformanceAudits, then I I navigate to the url , I call getPerformancescore and getMetrics and I have a returned values.
Then I do an action of clicking on a button which will load a new page but I have an error and I have a timeout.
So I have to do a workaround by navigating through the url browser.url () instead of a click action, but I have to go to another domain before coming back to my domain to have datas because on the same domain it does not work...
What is your expected behavior?
a new score calculated after a click action
How to reproduce the bug.
describe('JSON.org page', () => { before(() => { browser.enablePerformanceAudits() })
it('should get and display performance and metrics', async () => {
await browser.url('https://www.blablacar.fr/')
await $("#didomi-notice-agree-button").click();
let metrics = await browser.getMetrics()
let score = await browser.getPerformanceScore()
await $("[aria-label=\"Se connecter\"]").click()
await $(".kirk-item").click()
let metricsAfterClick = await browser.getMetrics()
let scoreAfterClick = await browser.getPerformanceScore()
console.log( metrics, score)
console.log(metricsAfterClick, scoreAfterClick)
})
after(async () => {
browser.disablePerformanceAudits()
})
})
Relevant log output
npx wdio run ./wdio.conf.js --spec devtools-info.js
Execution of 1 workers started at 2022-01-14T08:40:24.016Z
2022-01-14T08:40:24.743Z INFO @wdio/cli:launcher: Run onPrepare hook
2022-01-14T08:40:24.744Z INFO chromedriver: Start Chromedriver (/Users/e.frelon/quality/test-devtools/node_modules/chromedriver/lib/chromedriver/chromedriver) with args --port=9515 --url-base=/
2022-01-14T08:40:24.780Z INFO chromedriver: Starting ChromeDriver 97.0.4692.71 (adefa7837d02a07a604c1e6eff0b3a09422ab88d-refs/branch-heads/4692@{#1247}) on port 9515
2022-01-14T08:40:24.780Z INFO chromedriver: Only local connections are allowed.
2022-01-14T08:40:24.780Z INFO chromedriver: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
2022-01-14T08:40:24.808Z INFO chromedriver: ChromeDriver was started successfully.
2022-01-14T08:40:24.884Z INFO @wdio/cli:launcher: Run onWorkerStart hook
2022-01-14T08:40:24.886Z INFO @wdio/local-runner: Start worker 0-0 with arg: run,./wdio.conf.js,--spec,devtools-info.js
[0-0] 2022-01-14T08:40:25.329Z INFO @wdio/local-runner: Run worker command: run
[0-0] RUNNING in chrome - /test/specs/devtools-info.js
[0-0] 2022-01-14T08:40:25.991Z INFO webdriver: Initiate new session using the WebDriver protocol
[0-0] 2022-01-14T08:40:26.055Z INFO webdriver: [POST] http://localhost:9515/session
[0-0] 2022-01-14T08:40:26.056Z INFO webdriver: DATA {
[0-0] capabilities: {
[0-0] alwaysMatch: { browserName: 'chrome', acceptInsecureCerts: true },
[0-0] firstMatch: [ {} ]
[0-0] },
[0-0] desiredCapabilities: { browserName: 'chrome', acceptInsecureCerts: true }
[0-0] }
[0-0] 2022-01-14T08:40:27.772Z INFO webdriver: COMMAND enablePerformanceAudits()
[0-0] 2022-01-14T08:40:27.773Z INFO webdriver: RESULT undefined
[0-0] 2022-01-14T08:40:27.774Z INFO @wdio/devtools-service:TraceGatherer: Start tracing frame with url https://www.blablacar.fr/
[0-0] 2022-01-14T08:40:27.908Z INFO webdriver: COMMAND navigateTo("https://www.blablacar.fr/")
[0-0] 2022-01-14T08:40:27.909Z INFO webdriver: [POST] http://localhost:9515/session/a3e4c3a971184d353caa64a0de10b2a8/url
[0-0] 2022-01-14T08:40:27.909Z INFO webdriver: DATA { url: 'https://www.blablacar.fr/' }
[0-0] 2022-01-14T08:40:28.969Z INFO @wdio/devtools-service:TraceGatherer: Page load detected: https://www.blablacar.fr/, set frameId 196230C8E5DA33E3620D5E7AECB8DDB7, set loaderId 606AE986AB9E7044211D3DE730020705
[0-0] 2022-01-14T08:40:30.154Z INFO @wdio/devtools-service:TraceGatherer: Ignore navigated frame with url about:blank
[0-0] 2022-01-14T08:40:31.394Z INFO @wdio/devtools-service:TraceGatherer: Ignore navigated frame with url about:blank
[0-0] 2022-01-14T08:40:31.404Z INFO @wdio/devtools-service:TraceGatherer: Ignore navigated frame with url about:blank
[0-0] 2022-01-14T08:40:31.425Z INFO @wdio/devtools-service:TraceGatherer: Ignore navigated frame with url about:blank
[0-0] 2022-01-14T08:40:31.433Z INFO @wdio/devtools-service:TraceGatherer: Ignore navigated frame with url about:blank
[0-0] 2022-01-14T08:40:31.740Z INFO @wdio/devtools-service:TraceGatherer: page load happen to quick, waiting 11034ms more
[0-0] 2022-01-14T08:40:31.745Z INFO @wdio/devtools-service: Wait until tracing for command navigateTo finishes
[0-0] 2022-01-14T08:40:42.779Z INFO @wdio/devtools-service:TraceGatherer: Tracing completed after 15005ms, capturing performance data for frame 196230C8E5DA33E3620D5E7AECB8DDB7
[0-0] 2022-01-14T08:40:43.484Z INFO @wdio/devtools-service:TraceGatherer: Replace mainFrame process id 27068 with actual thread process id 27067
[0-0] 2022-01-14T08:40:43.485Z INFO @wdio/devtools-service:TraceGatherer: Tracing for 196230C8E5DA33E3620D5E7AECB8DDB7 completed
[0-0] 2022-01-14T08:40:43.485Z INFO @wdio/devtools-service: Disable throttling
[0-0] 2022-01-14T08:40:43.487Z INFO @wdio/devtools-service: continuing with next WebDriver command
[0-0] 2022-01-14T08:40:43.489Z INFO webdriver: COMMAND findElement("css selector", "#didomi-notice-agree-button")
[0-0] 2022-01-14T08:40:43.489Z INFO webdriver: [POST] http://localhost:9515/session/a3e4c3a971184d353caa64a0de10b2a8/element
[0-0] 2022-01-14T08:40:43.489Z INFO webdriver: DATA { using: 'css selector', value: '#didomi-notice-agree-button' }
[0-0] 2022-01-14T08:40:43.501Z INFO webdriver: RESULT {
[0-0] 'element-6066-11e4-a52e-4f735466cecf': 'c32358fd-3846-411c-888f-7844e4e2dcd4'
[0-0] }
[0-0] 2022-01-14T08:40:43.507Z INFO @wdio/devtools-service:TraceGatherer: Start tracing frame with url click transition
[0-0] 2022-01-14T08:40:43.510Z INFO @wdio/devtools-service:TraceGatherer: Start checking for page load for click
[0-0] 2022-01-14T08:40:43.512Z INFO webdriver: COMMAND elementClick("c32358fd-3846-411c-888f-7844e4e2dcd4")
[0-0] 2022-01-14T08:40:43.513Z INFO webdriver: [POST] http://localhost:9515/session/a3e4c3a971184d353caa64a0de10b2a8/element/c32358fd-3846-411c-888f-7844e4e2dcd4/click
[0-0] 2022-01-14T08:40:43.619Z INFO @wdio/devtools-service: Wait until tracing for command click finishes
[0-0] 2022-01-14T08:40:45.515Z INFO @wdio/devtools-service:TraceGatherer: No page load detected, canceling trace
[0-0] 2022-01-14T08:40:45.515Z INFO @wdio/devtools-service:TraceGatherer: Tracing for undefined completed
[0-0] 2022-01-14T08:40:45.515Z INFO @wdio/devtools-service: Disable throttling
[0-0] 2022-01-14T08:40:45.517Z INFO @wdio/devtools-service: continuing with next WebDriver command
[0-0] 2022-01-14T08:40:45.517Z INFO webdriver: COMMAND getMetrics()
[0-0] 2022-01-14T08:40:46.040Z INFO webdriver: RESULT {
[0-0] timeToFirstByte: 847,
[0-0] serverResponseTime: 847,
[0-0] domContentLoaded: 1921,
[0-0] firstVisualChange: 1962,
[0-0] firstPaint: 1686,
[0-0] firstContentfulPaint: 1686,
[0-0] firstMeaningfulPaint: 1687,
[0-0] largestContentfulPaint: 1687,
[0-0] lastVisualChange: 3829,
[0-0] interactive: 3608,
[0-0] load: 3815,
[0-0] speedIndex: 3184,
[0-0] totalBlockingTime: 949,
[0-0] maxPotentialFID: 487,
[0-0] cumulativeLayoutShift: 0.0033352366981476886
[0-0] }
[0-0] 2022-01-14T08:40:46.040Z INFO webdriver: COMMAND getPerformanceScore()
[0-0] 2022-01-14T08:40:46.437Z INFO webdriver: RESULT 0.49
[0-0] 2022-01-14T08:40:46.438Z INFO webdriver: COMMAND findElement("css selector", "[aria-label="Se connecter"]")
[0-0] 2022-01-14T08:40:46.438Z INFO webdriver: [POST] http://localhost:9515/session/a3e4c3a971184d353caa64a0de10b2a8/element
[0-0] 2022-01-14T08:40:46.438Z INFO webdriver: DATA { using: 'css selector', value: '[aria-label="Se connecter"]' }
[0-0] 2022-01-14T08:40:46.449Z INFO webdriver: RESULT {
[0-0] 'element-6066-11e4-a52e-4f735466cecf': '07234021-0216-4b8b-92bb-15716d9a79b0'
[0-0] }
[0-0] 2022-01-14T08:40:46.452Z INFO @wdio/devtools-service:TraceGatherer: Start tracing frame with url click transition
[0-0] 2022-01-14T08:40:46.455Z ERROR @wdio/utils:shim: LHError: TRACING_ALREADY_STARTED
[0-0] at Function.fromProtocolMessage (/Users/e.frelon/quality/test-devtools/node_modules/lighthouse/lighthouse-core/lib/lh-error.js:140:14)
[0-0] at /Users/e.frelon/quality/test-devtools/node_modules/lighthouse/lighthouse-core/gather/connections/connection.js:141:25
[0-0] at processTicksAndRejections (internal/process/task_queues.js:95:5)
[0-0] 2022-01-14T08:40:46.455Z INFO webdriver: COMMAND elementClick("07234021-0216-4b8b-92bb-15716d9a79b0")
[0-0] 2022-01-14T08:40:46.455Z INFO webdriver: [POST] http://localhost:9515/session/a3e4c3a971184d353caa64a0de10b2a8/element/07234021-0216-4b8b-92bb-15716d9a79b0/click
[0-0] 2022-01-14T08:40:46.501Z INFO @wdio/devtools-service: Wait until tracing for command click finishes
[0-0] Error in "JSON.org page.should get and display performance and metrics"
Error: Timeout of 480000ms exceeded. The execution in the test "JSON.org page should get and display performance and metrics" took too long. Try to reduce the run time or increase your timeout for test specs (https://webdriver.io/docs/timeouts). (/Users/e.frelon/quality/test-devtools/test/specs/devtools-info.js)
at createTimeoutError (/Users/e.frelon/quality/test-devtools/node_modules/mocha/lib/errors.js:498:15)
at Test.Runnable._timeoutError (/Users/e.frelon/quality/test-devtools/node_modules/mocha/lib/runnable.js:431:10)
at Timeout.<anonymous> (/Users/e.frelon/quality/test-devtools/node_modules/mocha/lib/runnable.js:246:24)
at listOnTimeout (internal/timers.js:555:17)
at processTimers (internal/timers.js:498:7)
[0-0] 2022-01-14T08:48:27.779Z INFO webdriver: COMMAND disablePerformanceAudits()
[0-0] 2022-01-14T08:48:27.780Z INFO webdriver: RESULT undefined
[0-0] 2022-01-14T08:48:27.781Z INFO webdriver: COMMAND deleteSession()
[0-0] 2022-01-14T08:48:27.781Z INFO webdriver: [DELETE] http://localhost:9515/session/a3e4c3a971184d353caa64a0de10b2a8
[0-0] FAILED in chrome - /test/specs/devtools-info.js
2022-01-14T08:48:27.959Z INFO @wdio/cli:launcher: Run onComplete hook
"spec" Reporter:
------------------------------------------------------------------
[chrome 97.0.4692.71 mac os x #0-0] Running: chrome (v97.0.4692.71) on mac os x
[chrome 97.0.4692.71 mac os x #0-0] Session ID: a3e4c3a971184d353caa64a0de10b2a8
[chrome 97.0.4692.71 mac os x #0-0]
[chrome 97.0.4692.71 mac os x #0-0] » /test/specs/devtools-info.js
[chrome 97.0.4692.71 mac os x #0-0] JSON.org page
[chrome 97.0.4692.71 mac os x #0-0] ✖ should get and display performance and metrics
[chrome 97.0.4692.71 mac os x #0-0]
[chrome 97.0.4692.71 mac os x #0-0] 1 failing (8m)
[chrome 97.0.4692.71 mac os x #0-0]
[chrome 97.0.4692.71 mac os x #0-0] 1) JSON.org page should get and display performance and metrics
[chrome 97.0.4692.71 mac os x #0-0] Timeout of 480000ms exceeded. The execution in the test "JSON.org page should get and display performance and metrics" took too long. Try to reduce the run time or increase your timeout for test specs (https://webdriver.io/docs/timeouts). (/Users/e.frelon/quality/test-devtools/test/specs/devtools-info.js)
[chrome 97.0.4692.71 mac os x #0-0] Error: Timeout of 480000ms exceeded. The execution in the test "JSON.org page should get and display performance and metrics" took too long. Try to reduce the run time or increase your timeout for test specs (https://webdriver.io/docs/timeouts). (/Users/e.frelon/quality/test-devtools/test/specs/devtools-info.js)
[chrome 97.0.4692.71 mac os x #0-0] at createTimeoutError (/Users/e.frelon/quality/test-devtools/node_modules/mocha/lib/errors.js:498:15)
[chrome 97.0.4692.71 mac os x #0-0] at Test.Runnable._timeoutError (/Users/e.frelon/quality/test-devtools/node_modules/mocha/lib/runnable.js:431:10)
[chrome 97.0.4692.71 mac os x #0-0] at Timeout.<anonymous> (/Users/e.frelon/quality/test-devtools/node_modules/mocha/lib/runnable.js:246:24)
[chrome 97.0.4692.71 mac os x #0-0] at listOnTimeout (internal/timers.js:555:17)
[chrome 97.0.4692.71 mac os x #0-0] at processTimers (internal/timers.js:498:7)
Spec Files: 0 passed, 1 failed, 1 total (100% completed) in 00:08:03
2022-01-14T08:48:27.960Z INFO @wdio/local-runner: Shutting down spawned worker
2022-01-14T08:48:28.214Z INFO @wdio/local-runner: Waiting for 0 to shut down gracefully
2022-01-14T08:48:28.215Z INFO @wdio/local-runner: shutting down
Code of Conduct
- I agree to follow this project's Code of Conduct
Is there an existing issue for this?
- I have searched the existing issues