search

dequelabs / axe-webdriverjs

Provides a chainable axe API for Selenium's WebDriverJS and automatically injects into all frames.
Mozilla Public License 2.0
130 stars 46 forks source link

Infinitely looping when injecting axe-core #63

Closed stephenmathieson closed 6 years ago

stephenmathieson commented 6 years ago

Attempting to get an analysis on https://buy.garmin.com/en-US/US/p/591046 causes axe-webdriverjs to hang forever. Based on selenium logs (and my own hacky console.log debugging), it looks like axe-webdriverjs is getting stuck infinitely recusing when attempting to inject axe-core into each frame.

I'm not sure why it's stuck in a loop here, as it seems to work just fine elsewhere. If I manually remove the Facebook "like" widget from the page (and its <iframe>s), the issue seems to disappear. I will continue looking into the root cause.

As a quick "band-aid", I suggest adding a maximum recursion depth of ~10. This will prevent axe-webdriverjs from recursing too much and/or getting "stuck".

Reproduction Steps

Here's the test script I've been using:

const chrome = require('selenium-webdriver/chrome')
const AxeBuilder = require('.')

const test = async () => {
  // Create a Chrome service with logs persisted to disk
  const service = new chrome.ServiceBuilder()
    .loggingTo('./selenium-logs')
    .build()

  // Dummy options
  const options = new chrome.Options()

  // Create our driver instance
  const driver = new chrome.Driver(options, service)

  // Navigate to the page
  await driver.get('https://buy.garmin.com/en-US/US/p/591046')

  // Create our axe instance
  const axe = new AxeBuilder(driver)

  // Analyze the page
  const results = await new Promise(resolve => axe.analyze(resolve))

  console.log(results)

  // Cleanup
  await driver.quit()
}

// Timeout after 5m
setTimeout(() => {
  throw new Error('Manual timeout')
}, 1000 * 60 * 5)

// Run our test
test().catch(err => {
  console.error('Unexpected error:', err)
})

Logs

Logs from the Node script:

node test.js
(node:12998) [DEP0022] DeprecationWarning: os.tmpDir() is deprecated. Use os.tmpdir() instead.
/Users/stephen/dev/src/github.com/dequelabs/axe-webdriverjs/test.js:31
  throw new Error('Manual timeout')
  ^

Error: Manual timeout
    at Timeout.setTimeout [as _onTimeout] (/Users/stephen/dev/src/github.com/dequelabs/axe-webdriverjs/test.js:31:9)
    at ontimeout (timers.js:427:11)
    at tryOnTimeout (timers.js:289:5)
    at listOnTimeout (timers.js:252:5)
    at Timer.processTimers (timers.js:212:10)

The outputted selenium-logs file is several MB, so I'm not sharing the entire thing. Instead, here's an excerpt of the loop:

[...]
[1529523791.365][INFO]: Waiting for pending navigations...
[1529523791.366][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.366][INFO]: Waiting for pending navigations...
[1529523791.454][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.454][INFO]: RESPONSE SwitchToFrame
[1529523791.468][INFO]: COMMAND ExecuteScript {
   "args": [  ],
   "script": "(function axeFunction(window) { [...] })"
}
[1529523791.468][INFO]: Waiting for pending navigations...
[1529523791.469][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.526][INFO]: Waiting for pending navigations...
[1529523791.529][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.529][INFO]: RESPONSE ExecuteScript
[1529523791.530][INFO]: COMMAND FindElements {
   "using": "css selector",
   "value": "iframe"
}
[1529523791.530][INFO]: Waiting for pending navigations...
[1529523791.533][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.543][INFO]: Waiting for pending navigations...
[1529523791.547][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.547][INFO]: RESPONSE FindElements [ {
   "ELEMENT": "0.6076278183128079-1"
}, {
   "ELEMENT": "0.6076278183128079-2"
}, {
   "ELEMENT": "0.6076278183128079-3"
}, {
   "ELEMENT": "0.6076278183128079-4"
}, {
   "ELEMENT": "0.6076278183128079-5"
}, {
   "ELEMENT": "0.6076278183128079-6"
}, {
   "ELEMENT": "0.6076278183128079-7"
}, {
   "ELEMENT": "0.6076278183128079-8"
} ]
[1529523791.549][INFO]: COMMAND SwitchToFrame {
   "id": null
}
[1529523791.549][INFO]: Waiting for pending navigations...
[1529523791.550][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.550][INFO]: Waiting for pending navigations...
[1529523791.551][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.551][INFO]: RESPONSE SwitchToFrame
[1529523791.553][INFO]: COMMAND SwitchToFrame {
   "id": {
      "ELEMENT": "0.6076278183128079-1",
      "element-6066-11e4-a52e-4f735466cecf": "0.6076278183128079-1"
   }
}
[1529523791.553][INFO]: Waiting for pending navigations...
[1529523791.554][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.579][INFO]: Waiting for pending navigations...
[1529523791.580][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.580][INFO]: RESPONSE SwitchToFrame
[1529523791.589][INFO]: COMMAND ExecuteScript {
   "args": [  ],
   "script": "(function axeFunction(window) { [...] })"
}
[1529523791.589][INFO]: Waiting for pending navigations...
[1529523791.590][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.617][INFO]: Waiting for pending navigations...
[1529523791.618][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.618][INFO]: RESPONSE ExecuteScript
[1529523791.620][INFO]: COMMAND FindElements {
   "using": "css selector",
   "value": "iframe"
}
[1529523791.620][INFO]: Waiting for pending navigations...
[1529523791.621][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.625][INFO]: Waiting for pending navigations...
[1529523791.625][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.625][INFO]: RESPONSE FindElements [  ]
[1529523791.627][INFO]: COMMAND SwitchToFrame {
   "id": null
}
[1529523791.627][INFO]: Waiting for pending navigations...
[1529523791.627][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.628][INFO]: Waiting for pending navigations...
[1529523791.628][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.628][INFO]: RESPONSE SwitchToFrame
[1529523791.629][INFO]: COMMAND SwitchToFrame {
   "id": {
      "ELEMENT": "0.6076278183128079-2",
      "element-6066-11e4-a52e-4f735466cecf": "0.6076278183128079-2"
   }
}
[1529523791.629][INFO]: Waiting for pending navigations...
[1529523791.630][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.645][INFO]: Waiting for pending navigations...
[1529523791.646][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.646][INFO]: RESPONSE SwitchToFrame
[1529523791.657][INFO]: COMMAND ExecuteScript {
   "args": [  ],
   "script": "(function axeFunction(window) { [...] })"
}
[1529523791.657][INFO]: Waiting for pending navigations...
[1529523791.658][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.685][INFO]: Waiting for pending navigations...
[1529523791.686][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.686][INFO]: RESPONSE ExecuteScript
[1529523791.688][INFO]: COMMAND FindElements {
   "using": "css selector",
   "value": "iframe"
}
[1529523791.688][INFO]: Waiting for pending navigations...
[1529523791.689][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.698][INFO]: Waiting for pending navigations...
[1529523791.699][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.699][INFO]: RESPONSE FindElements [  ]
[1529523791.701][INFO]: COMMAND SwitchToFrame {
   "id": null
}
[1529523791.701][INFO]: Waiting for pending navigations...
[1529523791.702][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.702][INFO]: Waiting for pending navigations...
[1529523791.703][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.703][INFO]: RESPONSE SwitchToFrame
[1529523791.704][INFO]: COMMAND SwitchToFrame {
   "id": {
      "ELEMENT": "0.6076278183128079-3",
      "element-6066-11e4-a52e-4f735466cecf": "0.6076278183128079-3"
   }
}
[1529523791.704][INFO]: Waiting for pending navigations...
[1529523791.707][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.723][INFO]: Waiting for pending navigations...
[1529523791.723][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.723][INFO]: RESPONSE SwitchToFrame
[1529523791.733][INFO]: COMMAND ExecuteScript {
   "args": [  ],
   "script": "(function axeFunction(window) { [...] })"
}
[1529523791.733][INFO]: Waiting for pending navigations...
[1529523791.733][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.759][INFO]: Waiting for pending navigations...
[1529523791.760][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.760][INFO]: RESPONSE ExecuteScript
[1529523791.761][INFO]: COMMAND FindElements {
   "using": "css selector",
   "value": "iframe"
}
[1529523791.761][INFO]: Waiting for pending navigations...
[1529523791.762][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.766][INFO]: Waiting for pending navigations...
[1529523791.766][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.766][INFO]: RESPONSE FindElements [  ]
[1529523791.768][INFO]: COMMAND SwitchToFrame {
   "id": null
}
[1529523791.768][INFO]: Waiting for pending navigations...
[1529523791.768][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.768][INFO]: Waiting for pending navigations...
[1529523791.769][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.769][INFO]: RESPONSE SwitchToFrame
[1529523791.770][INFO]: COMMAND SwitchToFrame {
   "id": {
      "ELEMENT": "0.6076278183128079-4",
      "element-6066-11e4-a52e-4f735466cecf": "0.6076278183128079-4"
   }
}
[1529523791.770][INFO]: Waiting for pending navigations...
[1529523791.771][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.791][INFO]: Waiting for pending navigations...
[1529523791.793][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.793][INFO]: RESPONSE SwitchToFrame
[1529523791.808][INFO]: COMMAND ExecuteScript {
   "args": [  ],
   "script": "(function axeFunction(window) { [...] })"
}
[1529523791.808][INFO]: Waiting for pending navigations...
[1529523791.809][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.835][INFO]: Waiting for pending navigations...
[1529523791.837][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.837][INFO]: RESPONSE ExecuteScript
[1529523791.838][INFO]: COMMAND FindElements {
   "using": "css selector",
   "value": "iframe"
}
[1529523791.838][INFO]: Waiting for pending navigations...
[1529523791.839][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.843][INFO]: Waiting for pending navigations...
[1529523791.844][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.844][INFO]: RESPONSE FindElements [  ]
[1529523791.846][INFO]: COMMAND SwitchToFrame {
   "id": null
}
[1529523791.846][INFO]: Waiting for pending navigations...
[1529523791.847][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.847][INFO]: Waiting for pending navigations...
[1529523791.848][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.848][INFO]: RESPONSE SwitchToFrame
[1529523791.849][INFO]: COMMAND SwitchToFrame {
   "id": {
      "ELEMENT": "0.6076278183128079-5",
      "element-6066-11e4-a52e-4f735466cecf": "0.6076278183128079-5"
   }
}
[1529523791.849][INFO]: Waiting for pending navigations...
[1529523791.850][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.864][INFO]: Waiting for pending navigations...
[1529523791.865][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.865][INFO]: RESPONSE SwitchToFrame
[1529523791.874][INFO]: COMMAND ExecuteScript {
   "args": [  ],
   "script": "(function axeFunction(window) { [...] })"
}
[1529523791.874][INFO]: Waiting for pending navigations...
[1529523791.875][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.877][INFO]: Waiting for pending navigations...
[1529523791.877][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.879][INFO]: Waiting for pending navigations...
[1529523791.879][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.905][INFO]: Waiting for pending navigations...
[1529523791.907][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.907][INFO]: RESPONSE ExecuteScript
[1529523791.908][INFO]: COMMAND FindElements {
   "using": "css selector",
   "value": "iframe"
}
[1529523791.908][INFO]: Waiting for pending navigations...
[1529523791.910][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.915][INFO]: Waiting for pending navigations...
[1529523791.915][INFO]: Done waiting for pending navigations. Status: ok
[1529523791.915][INFO]: RESPONSE FindElements [ {
   "ELEMENT": "0.6076278183128079-1"
}, {
   "ELEMENT": "0.6076278183128079-2"
}, {
   "ELEMENT": "0.6076278183128079-3"
}, {
   "ELEMENT": "0.6076278183128079-4"
}, {
   "ELEMENT": "0.6076278183128079-5"
}, {
   "ELEMENT": "0.6076278183128079-6"
}, {
   "ELEMENT": "0.6076278183128079-7"
}, {
   "ELEMENT": "0.6076278183128079-8"
} ]
[1529523791.919][INFO]: COMMAND SwitchToFrame {
   "id": null
}
[...]