microsoft / accessibility-insights-action

Github Action to scan for accessibility issues in github pages
MIT License
80 stars 43 forks source link

My tests keep timing out at 180 seconds despite increasing scanTimeout #1606

Closed Onokaev closed 1 year ago

Onokaev commented 1 year ago

Your question here

Screenshot 2023-03-28 at 4 19 10 PM

Could this be related to the container issue that was raised before? I am running the tests using a self-hosted agent

microsoft-github-policy-service[bot] commented 1 year ago

This issue requires additional investigation by the Accessibility Insights team. When the issue is ready to be triaged again, we will update the issue with the investigation result and add "status: ready for triage". Thank you for contributing to Accessibility Insights!

JGibson2019 commented 1 year ago

Hi @Onokaev a couple of things:

  1. To clarify, you're referencing this container issue or another one?
  2. Just as a best practice can you update the issue to include the text listed in your error message in addition to the screenshot? This makes it easier for us and is accessible. Thank you!
Onokaev commented 1 year ago
  1. Yes. That's the issue I'm referencing
  2. Here is the raw log from the error: 2023-03-28T10:12:17.9832737Z ##[section]Starting: accessibilityinsights 2023-03-28T10:12:17.9960195Z ============================================================================== 2023-03-28T10:12:17.9960687Z Task : Accessibility Insights Azure DevOps Task 2023-03-28T10:12:17.9960904Z Description : Scan for accessibility issues in an Azure DevOps pipeline 2023-03-28T10:12:17.9961104Z Version : 3.3.0 2023-03-28T10:12:17.9961219Z Author : Accessibility Insights 2023-03-28T10:12:17.9961508Z Help : For help with configuring and troubleshooting this task, see https://aka.ms/accessibility-insights-faq#azure-devops-extension 2023-03-28T10:12:17.9961899Z ============================================================================== 2023-03-28T10:12:18.4615081Z ##[group]Installing runtime dependencies 2023-03-28T10:12:18.4625222Z ##[debug]Using node from C:\vss-agent\3.218.0\externals\node16\bin\node.exe 2023-03-28T10:12:18.4626544Z ##[debug]Using bundled yarn from D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0.yarn\releases\yarn-3.4.1.cjs 2023-03-28T10:12:19.0502335Z ➤ YN0000: ┌ Resolution step 2023-03-28T10:12:19.2221098Z ➤ YN0002: │ @fluentui/font-icons-mdl2@npm:8.4.13 doesn't provide @types/react (p46e09), requested by @fluentui/utilities 2023-03-28T10:12:19.2234930Z ➤ YN0002: │ @fluentui/font-icons-mdl2@npm:8.4.13 doesn't provide react (pc3e60), requested by @fluentui/utilities 2023-03-28T10:12:19.2237737Z ➤ YN0002: │ @fluentui/style-utilities@npm:8.7.12 doesn't provide @types/react (p1c0a5), requested by @fluentui/utilities 2023-03-28T10:12:19.2239357Z ➤ YN0002: │ @fluentui/style-utilities@npm:8.7.12 doesn't provide @types/react (p1f230), requested by @fluentui/theme 2023-03-28T10:12:19.2240702Z ➤ YN0002: │ @fluentui/style-utilities@npm:8.7.12 doesn't provide react (pd254b), requested by @fluentui/utilities 2023-03-28T10:12:19.2241788Z ➤ YN0002: │ @fluentui/style-utilities@npm:8.7.12 doesn't provide react (p716df), requested by @fluentui/theme 2023-03-28T10:12:19.2242936Z ➤ YN0002: │ accessibility-insights-report@npm:4.6.3 doesn't provide @types/react (pcd13e), requested by @fluentui/react 2023-03-28T10:12:19.2244043Z ➤ YN0002: │ accessibility-insights-report@npm:4.6.3 doesn't provide @types/react-dom (p6fea8), requested by @fluentui/react 2023-03-28T10:12:19.2245179Z ➤ YN0002: │ accessibility-insights-report@npm:4.6.4 doesn't provide @types/react (p6edd6), requested by @fluentui/react 2023-03-28T10:12:19.2246298Z ➤ YN0002: │ accessibility-insights-report@npm:4.6.4 doesn't provide @types/react-dom (p17015), requested by @fluentui/react 2023-03-28T10:12:19.2247544Z ➤ YN0060: │ accessibility-insights-scan@npm:1.6.0 provides puppeteer (pe6ec9) with version 18.1.0, which doesn't satisfy what apify requests 2023-03-28T10:12:19.2248751Z ➤ YN0000: │ Some peer dependencies are incorrectly met; run yarn explain peer-requirements for details, where is the six-letter p-prefixed code 2023-03-28T10:12:19.2327919Z ➤ YN0000: └ Completed 2023-03-28T10:12:19.2657212Z ➤ YN0000: ┌ Fetch step 2023-03-28T10:12:37.4992304Z ➤ YN0013: │ No packages were cached - 493 packages had to be fetched 2023-03-28T10:12:37.5021938Z ➤ YN0000: └ Completed in 18s 247ms 2023-03-28T10:12:37.5662272Z ➤ YN0000: ┌ Link step 2023-03-28T10:12:51.2515061Z ➤ YN0007: │ leveldown@npm:6.1.1 must be built because it never has been before or the last one failed 2023-03-28T10:12:51.2526264Z ➤ YN0007: │ puppeteer@npm:18.1.0 must be built because it never has been before or the last one failed 2023-03-28T10:12:51.2534010Z ➤ YN0007: │ better-sqlite3-with-prebuilds@npm:7.4.3 must be built because it never has been before or the last one failed 2023-03-28T10:12:54.1289771Z ➤ YN0000: │ puppeteer@npm:18.1.0 STDERR 2023-03-28T10:13:01.6906028Z ➤ YN0000: │ puppeteer@npm:18.1.0 STDOUT Chromium (1045629) downloaded to D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\puppeteer.local-chromium\win64-1045629 2023-03-28T10:13:01.7059498Z ➤ YN0000: └ Completed in 24s 162ms 2023-03-28T10:13:01.7521880Z ➤ YN0000: Done with warnings in 42s 705ms 2023-03-28T10:13:02.3917139Z ##[endgroup] 2023-03-28T10:13:05.6575584Z ##[debug][Telemetry] tracking a 'ScanStart' event 2023-03-28T10:13:05.6597053Z ##[debug][Telemetry] tracking a 'Inputs' event 2023-03-28T10:13:05.6602222Z ##[group]Scanning URL https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:13:05.6603427Z ##[debug]Starting accessibility scanning of URL https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:13:05.6604396Z ##[debug]Chrome app executable: system default 2023-03-28T10:13:05.6727813Z ##[debug] Created a data storage folder at D:\a_work_temp\accessibility-insights-action-zx5OHN. You can override the path by setting the APIFY_LOCAL_STORAGE_DIR environment variable 2023-03-28T10:13:06.0206064Z ##[debug] PuppeteerCrawler:AutoscaledPool:Snapshotter: Setting max memory of this run to 2048 MB. Use the APIFY_MEMORY_MBYTES environment variable to override it. 2023-03-28T10:13:06.0308793Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":0,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":null},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":null},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":null},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":null}}} 2023-03-28T10:13:54.2282681Z Processing page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:13:54.3025181Z Discovered 2 links on page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:14:05.7871735Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":60041,"retryHistogram":[]} 2023-03-28T10:14:07.0908078Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0.193},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0.176},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0.304},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:15:05.7532805Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":120057,"retryHistogram":[]} 2023-03-28T10:15:07.0744782Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:16:05.7536819Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":180057,"retryHistogram":[]} 2023-03-28T10:16:07.1214377Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:16:54.3145066Z ##[debug]Accessibility scan timed out after 180 seconds. 2023-03-28T10:16:54.3326929Z ERROR PuppeteerCrawler: handleRequestFunction failed, reclaiming failed request back to the list or queue {"url":"https://developer.microsoft.com/en-us/graph/graph-explorer","retryCount":1,"id":"3Tim2B8fMVabxle"} 2023-03-28T10:16:54.3329186Z Error: Accessibility scan timed out after 180 seconds. 2023-03-28T10:16:54.3331149Z at AccessibilityScanOperation.scanForA11yIssues (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4055:19) 2023-03-28T10:16:54.3333351Z at async AccessibilityScanOperation.run (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4043:28) 2023-03-28T10:16:54.3335052Z at async ClassicPageProcessor.processPage (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4221:32) 2023-03-28T10:16:54.3336659Z at async PuppeteerCrawler.PageProcessorBase.pageHandler [as handlePageFunction] (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4295:17) 2023-03-28T10:16:54.3338018Z at async wrap (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\@apify\timeout\index.js:73:27) 2023-03-28T10:17:05.7561259Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":240059,"retryHistogram":[]} 2023-03-28T10:17:07.1667816Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0.021},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0.034},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:17:20.9491819Z Processing page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:17:21.0084367Z Discovered 2 links on page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:18:05.7613448Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":300065,"retryHistogram":[]} 2023-03-28T10:18:07.3217061Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":false,"memInfo":{"isOverloaded":true,"limitRatio":0.2,"actualRatio":0.656},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0.481},"cpuInfo":{"isOverloaded":true,"limitRatio":0.4,"actualRatio":0.652},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:19:05.7778435Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":360081,"retryHistogram":[]} 2023-03-28T10:19:07.3854016Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:20:05.7787396Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":420082,"retryHistogram":[]} 2023-03-28T10:20:07.4366088Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:20:21.0247357Z ##[debug]Accessibility scan timed out after 180 seconds. 2023-03-28T10:20:21.0396198Z ERROR PuppeteerCrawler: handleRequestFunction failed, reclaiming failed request back to the list or queue {"url":"https://developer.microsoft.com/en-us/graph/graph-explorer","retryCount":2,"id":"3Tim2B8fMVabxle"} 2023-03-28T10:20:21.0398402Z Error: Accessibility scan timed out after 180 seconds. 2023-03-28T10:20:21.0400326Z at AccessibilityScanOperation.scanForA11yIssues (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4055:19) 2023-03-28T10:20:21.0402352Z at async AccessibilityScanOperation.run (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4043:28) 2023-03-28T10:20:21.0404053Z at async ClassicPageProcessor.processPage (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4221:32) 2023-03-28T10:20:21.0405860Z at async PuppeteerCrawler.PageProcessorBase.pageHandler [as handlePageFunction] (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4295:17) 2023-03-28T10:20:21.0407481Z at async wrap (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\@apify\timeout\index.js:73:27) 2023-03-28T10:20:47.1724183Z Processing page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:20:47.2353968Z Discovered 2 links on page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:21:05.9274191Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":480183,"retryHistogram":[]} 2023-03-28T10:21:07.6535270Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":false,"memInfo":{"isOverloaded":true,"limitRatio":0.2,"actualRatio":0.236},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0.384},"cpuInfo":{"isOverloaded":true,"limitRatio":0.4,"actualRatio":0.56},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:22:05.8926720Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":540196,"retryHistogram":[]} 2023-03-28T10:22:07.9461209Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:23:05.8993845Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":600203,"retryHistogram":[]} 2023-03-28T10:23:07.9782647Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:23:47.2481963Z ##[debug]Accessibility scan timed out after 180 seconds. 2023-03-28T10:23:47.2630190Z ERROR PuppeteerCrawler: handleRequestFunction failed, reclaiming failed request back to the list or queue {"url":"https://developer.microsoft.com/en-us/graph/graph-explorer","retryCount":3,"id":"3Tim2B8fMVabxle"} 2023-03-28T10:23:47.2652724Z Error: Accessibility scan timed out after 180 seconds. 2023-03-28T10:23:47.2692903Z at AccessibilityScanOperation.scanForA11yIssues (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4055:19) 2023-03-28T10:23:47.2697682Z at async AccessibilityScanOperation.run (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4043:28) 2023-03-28T10:23:47.2699809Z at async ClassicPageProcessor.processPage (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4221:32) 2023-03-28T10:23:47.2701613Z at async PuppeteerCrawler.PageProcessorBase.pageHandler [as handlePageFunction] (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\accessibility-insights-scan\dist\index.js:4295:17) 2023-03-28T10:23:47.2703187Z at async wrap (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\node_modules\@apify\timeout\index.js:73:27) 2023-03-28T10:24:05.9666964Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":660203,"retryHistogram":[]} 2023-03-28T10:24:08.0422239Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0.019},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0.034},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:24:13.5933274Z Processing page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:24:13.6566612Z Discovered 2 links on page https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:25:05.9024986Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":720206,"retryHistogram":[]} 2023-03-28T10:25:08.4728934Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":false,"memInfo":{"isOverloaded":true,"limitRatio":0.2,"actualRatio":0.296},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0.218},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0.145},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:26:05.9150271Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":780219,"retryHistogram":[]} 2023-03-28T10:26:08.5260113Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:27:05.9164546Z ##[debug] Statistics: PuppeteerCrawler request statistics: {"requestAvgFailedDurationMillis":null,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":0,"requestsTotal":0,"crawlerRuntimeMillis":840220,"retryHistogram":[]} 2023-03-28T10:27:08.5849390Z ##[debug] PuppeteerCrawler:AutoscaledPool: state {"currentConcurrency":1,"desiredConcurrency":1,"systemStatus":{"isSystemIdle":true,"memInfo":{"isOverloaded":false,"limitRatio":0.2,"actualRatio":0},"eventLoopInfo":{"isOverloaded":false,"limitRatio":0.6,"actualRatio":0},"cpuInfo":{"isOverloaded":false,"limitRatio":0.4,"actualRatio":0},"clientInfo":{"isOverloaded":false,"limitRatio":0.3,"actualRatio":0}}} 2023-03-28T10:27:13.6648079Z ##[debug]Accessibility scan timed out after 180 seconds. 2023-03-28T10:27:13.6871998Z ##[debug] PuppeteerCrawler: All the requests from request list and/or request queue have been processed, the crawler will shut down. 2023-03-28T10:27:13.6927082Z ##[debug] PuppeteerCrawler: Final request statistics: {"requestsFinished":0,"requestsFailed":1,"retryHistogram":[null,null,null,1],"requestAvgFailedDurationMillis":202949,"requestAvgFinishedDurationMillis":null,"requestsFinishedPerMinute":0,"requestsFailedPerMinute":0,"requestTotalDurationMillis":202949,"requestsTotal":1,"crawlerRuntimeMillis":847996} 2023-03-28T10:27:13.7030073Z ##[error]Scan failed with 1 error(s) 2023-03-28T10:27:13.7040076Z ##[error][Exception]ErrorWithCause: An error occurred while scanning website page: https://developer.microsoft.com/en-us/graph/graph-explorer 2023-03-28T10:27:13.7041580Z at Logger.trackExceptionAny (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:174460:29) 2023-03-28T10:27:13.7047407Z at Scanner.logAndTrackScanningException (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175730:21) 2023-03-28T10:27:13.7049126Z at D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175661:30 2023-03-28T10:27:13.7050224Z at Array.forEach () 2023-03-28T10:27:13.7051323Z at Scanner. (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175660:47) 2023-03-28T10:27:13.7052268Z at Generator.next () 2023-03-28T10:27:13.7053343Z at fulfilled (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175563:58) 2023-03-28T10:27:13.7054234Z at processTicksAndRejections (node:internal/process/task_queues:96:5) 2023-03-28T10:27:13.7055015Z caused by: Error: '{\n' + 2023-03-28T10:27:13.7055725Z " name: 'Error',\n" + 2023-03-28T10:27:13.7056740Z " message: 'Accessibility scan timed out after 180 seconds.',\n" + 2023-03-28T10:27:13.7057631Z " stack: 'Error: Accessibility scan timed out after 180 seconds.\n' +\n" + 2023-03-28T10:27:13.7058931Z " ' at AccessibilityScanOperation.scanForA11yIssues (D:\\a\\_work\\_tasks\\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\\3.3.0\\node_modules\\accessibility-insights-scan\\dist\\index.js:4055:19)\n' +\n" + 2023-03-28T10:27:13.7060506Z " ' at async AccessibilityScanOperation.run (D:\\a\\_work\\_tasks\\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\\3.3.0\\node_modules\\accessibility-insights-scan\\dist\\index.js:4043:28)\n' +\n" + 2023-03-28T10:27:13.7062128Z " ' at async ClassicPageProcessor.processPage (D:\\a\\_work\\_tasks\\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\\3.3.0\\node_modules\\accessibility-insights-scan\\dist\\index.js:4221:32)\n' +\n" + 2023-03-28T10:27:13.7064186Z " ' at async PuppeteerCrawler.PageProcessorBase.pageHandler [as handlePageFunction] (D:\\a\\_work\\_tasks\\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\\3.3.0\\node_modules\\accessibility-insights-scan\\dist\\index.js:4295:17)\n' +\n" + 2023-03-28T10:27:13.7066103Z " ' at async wrap (D:\\a\\_work\\_tasks\\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\\3.3.0\\node_modules\\@apify\\timeout\\index.js:73:27)'\n" + 2023-03-28T10:27:13.7067114Z '}' 2023-03-28T10:27:13.7068137Z at Logger.trackExceptionAny (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:174459:94) 2023-03-28T10:27:13.7069413Z at Scanner.logAndTrackScanningException (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175730:21) 2023-03-28T10:27:13.7070673Z at D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175661:30 2023-03-28T10:27:13.7071600Z at Array.forEach () 2023-03-28T10:27:13.7072657Z at Scanner. (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175660:47) 2023-03-28T10:27:13.7073544Z at Generator.next () 2023-03-28T10:27:13.7074603Z at fulfilled (D:\a_work_tasks\accessibility-insights_4811a442-2fd3-5aa8-ba1a-14cb7e24c113\3.3.0\index.js:175563:58) 2023-03-28T10:27:13.7075510Z at processTicksAndRejections (node:internal/process/task_queues:96:5) 2023-03-28T10:27:13.7076460Z ##[debug][Telemetry] tracking a 'ErrorFound' event 2023-03-28T10:27:13.7077335Z Accessibility scanning of URL https://developer.microsoft.com/en-us/graph/graph-explorer completed 2023-03-28T10:27:14.0899063Z ##[error]Scan failed with 1 error(s) 2023-03-28T10:27:14.1594109Z ##[section]Finishing: accessibilityinsights
Onokaev commented 1 year ago

Here is the yaml:

name: $(date:yyyyMMdd)$(rev:.r)

pool: 1es-windows-latest

pr: branches: include:

variables: isMaster: $[eq(variables['Build.SourceBranch'], 'refs/heads/master')] isDev: $[eq(variables['Build.SourceBranch'], 'refs/heads/dev')]

trigger: branches: include:

jobs:

Onokaev commented 1 year ago

The accessibility job is the last one: job: Four

DaveTryon commented 1 year ago

@Onokaev, the error being thrown is coming from this line. This class wraps the scan of a single page. The value for AccessibilityScanOperation.axeScanTimeoutSec is hardcoded to 180 on line 17 and no plumbing currently exists to provide an override.

The extension's scanTimeout parameter influences the overall execution time, but has no impact on the hardcode per-page limitation. As a team, we'll discuss potential configuration options for the per-page timeout, then let you know where that lands.

In the meantime, you might be able to work around this by enabling the extension's singleWorker flag to minimize contention from scanning pages concurrently, or by breaking the job into multiple scans, potentially each starting with a different url under https://developer.microsoft.com/en-us/graph/graph-explorer.

microsoft-github-policy-service[bot] commented 1 year ago

This issue has been marked as ready for team triage; we will triage it in our weekly review and update the issue. Thank you for contributing to Accessibility Insights!

dbjorge commented 1 year ago

Hi @Onokaev , it looks like the page in question is embedding a copy of the Monaco editor. We think the issue you're encountering is a repro of a known performance issue in axe-core (the open source accessibility testing engine we're based on) which is triggered by an implementation detail of the Monaco editor, tracked by https://github.com/dequelabs/axe-core/issues/3923 and currently planned to be fixed in the next feature-level engine release. We're going to treat this issue as blocked pending that upstream fix.

DaveTryon commented 1 year ago

Update: https://github.com/dequelabs/axe-core/issues/3923 has been resolved and will be in axe-core 4.8. We don't yet have a timetable for consuming it.

DaveTryon commented 1 year ago

@nang4a11y, please add this to your notes for the future feature that consumes axe-core 4.8, so that we can test it and mention it in the release notes.