Closed Bug 1953433 Opened 3 days ago Closed 3 days ago

Intermittent raptor-browsertime Critical: Failed waiting on page https://prod.youtube-test.prod.webservices.mozgcp.net/main.html?test_type=playbackperf-hfr-test&tests=38&raptor=true&exclude=1,2&muted=true&command=run to finished loading, timed out after

Categories

(Testing :: Raptor, defect, P5)

Product:
Testing
Component:
Raptor
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1953448

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: amarc [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=498765707&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/bScZ0X40RB2LzvFxdf-AEw/runs/0/artifacts/public/logs/live_backing.log

[task 2025-03-12T12:00:48.584Z] 12:00:48     INFO -  raptor-browsertime Info: Calling browsertime with proc_timeout=129680, and output_timeout=None
[task 2025-03-12T12:00:48.584Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (root) created
[task 2025-03-12T12:00:48.584Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.515Z serialport/bindings-cpp loading LinuxBinding
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.android) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.firefox) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.bidi) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.firefox.bidi) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.chrome.network) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.chrome.cpu) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.chrome) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.chrome.trace) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.chrome.cdp) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.connectivity.humble) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.connectivity) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.gnirehtet) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.addText) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.click) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.wait) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.video) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.measure) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.javascript) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.switch) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.screenshot) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.set) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.cache) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.stopwatch) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.select) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.debug) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.android) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.devtoolsprotocol) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.chrometrace) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.mouse) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.scroll) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.navigation) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.command.geckoprofiler) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.edge) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.screenshot) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:logger:DEBUG Logger (browsertime.dns) created
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Wed, 12 Mar 2025 12:00:48 GMT intel:DEBUG basicConfig { format: '[%(date)s] %(levelname)s: %(message)s', level: 40 }
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.729Z adb:command Send '000Chost:devices'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.731Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.732Z adb:command Send '001Cshell:echo $EXTERNAL_STORAGE'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.774Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.775Z adb:command Send '001Cshell:dumpsys window windows'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.815Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.816Z adb:command Send '001Bshell:svc power stayon true'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.822Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.822Z adb:command Send '001Eshell:getprop ro.product.model'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.837Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.837Z adb:command Send '001Dshell:getprop ro.product.name'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.853Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.853Z adb:command Send '001Fshell:getprop ro.product.device'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.885Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.885Z adb:command Send '0019shell:getprop ro.serialno'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.916Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.916Z adb:command Send '0038shell:dumpsys netstats | grep -E 'iface=wlan.*networkId''
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.969Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: 2025-03-12T12:00:48.969Z adb:command Send '0027shell:getprop ro.build.version.release '
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Run tests on SM-A556E [R5CX439M71Y] using Android version 14
[task 2025-03-12T12:01:01.202Z] 12:00:48     INFO -  raptor-browsertime Info: Running tests using Firefox - 1 iteration(s)
[task 2025-03-12T12:01:01.202Z] 12:00:49     INFO -  raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2025-03-12T12:01:01.202Z] 12:01:01     INFO -  raptor-browsertime Info: 2025-03-12T12:01:01.010Z adb:command Send '001Ahost:transport:R5CX439M71Y'
[task 2025-03-12T12:01:01.202Z] 12:01:01     INFO -  raptor-browsertime Info: 2025-03-12T12:01:01.011Z adb:command Send '0040shell:dumpsys battery | grep temperature | grep -Eo '[0-9]{1,3}''
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info: Starting a browsertime benchamrk
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info: Initializing power usage measurements
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info: Error: LIBUSB_ERROR_NO_DEVICE
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at Device.open (/builds/task_174178076931424/fetches/browsertime/node_modules/usb/dist/usb/device.js:63:14)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at tryDevice (/builds/task_174178076931424/fetches/browsertime/node_modules/usb-power-profiling/usb-power-profiling.js:1064:14)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at Object.startSampling (/builds/task_174178076931424/fetches/browsertime/node_modules/usb-power-profiling/usb-power-profiling.js:1124:11)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async SupportMeasurements._initializeMeasurePower (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/support_measurements.js:153:7)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async SupportMeasurements.initialize (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/support_measurements.js:246:7)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async initializeMeasurements (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/support_measurements.js:299:3)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async /builds/task_174178076931424/workspace/build/tests/raptor/browsertime/browsertime_benchmark.js:27:5
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async wrappedTest (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/profiling.js:269:14)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/engine/run.js:4:7
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async Iteration.run (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:162:9)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async Engine.runByScript (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:308:20)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async run (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:104:22)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:240:1 {
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:   errno: -4
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info: }
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info: Error: LIBUSB_ERROR_NO_DEVICE
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at Device.open (/builds/task_174178076931424/fetches/browsertime/node_modules/usb/dist/usb/device.js:63:14)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at tryDevice (/builds/task_174178076931424/fetches/browsertime/node_modules/usb-power-profiling/usb-power-profiling.js:1064:14)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at Object.startSampling (/builds/task_174178076931424/fetches/browsertime/node_modules/usb-power-profiling/usb-power-profiling.js:1124:11)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async SupportMeasurements._initializeMeasurePower (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/support_measurements.js:153:7)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async SupportMeasurements.initialize (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/support_measurements.js:246:7)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async initializeMeasurements (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/support_measurements.js:299:3)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async /builds/task_174178076931424/workspace/build/tests/raptor/browsertime/browsertime_benchmark.js:27:5
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async wrappedTest (/builds/task_174178076931424/workspace/build/tests/raptor/browsertime/utils/profiling.js:269:14)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/engine/run.js:4:7
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async Iteration.run (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:162:9)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async Engine.runByScript (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:308:20)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async run (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:104:22)
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:     at async file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:240:1 {
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info:   errno: -4
[task 2025-03-12T12:01:01.302Z] 12:01:01     INFO -  raptor-browsertime Info: }
<...>
[task 2025-03-12T12:01:01.904Z] 12:01:01     INFO -  raptor-browsertime Info:   errno: -4
[task 2025-03-12T12:01:01.904Z] 12:01:01     INFO -  raptor-browsertime Info: }
[task 2025-03-12T12:03:54.997Z] 12:01:01     INFO -  raptor-browsertime Info: Waiting for 20000 ms (post_startup_delay)
[task 2025-03-12T12:03:54.997Z] 12:01:21     INFO -  raptor-browsertime Info: Navigating to about:blank
[task 2025-03-12T12:03:54.997Z] 12:01:21     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2025-03-12T12:03:54.997Z] 12:01:27     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2025-03-12T12:03:54.998Z] 12:01:28     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2025-03-12T12:03:54.998Z] 12:01:28     INFO -  raptor-browsertime Info: Testing url https://prod.youtube-test.prod.webservices.mozgcp.net/main.html?test_type=playbackperf-hfr-test&tests=38&raptor=true&exclude=1,2&muted=true&command=run iteration 1
[task 2025-03-12T12:03:54.998Z] 12:01:43     INFO -  raptor-browsertime Info: Will check again if the browser has navigated to the page
[task 2025-03-12T12:03:54.998Z] 12:03:43    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info: return (function(waitTime) {
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     try {
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:             var end = window.performance.timing.loadEventEnd;
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:             var start= window.performance.timing.navigationStart;
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:             return (end > 0) && (performance.now() > end - start + waitTime);
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     }
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     catch(e) {
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:         return true;
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     }
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info: })(arguments[arguments.length - 1]);
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:  took too long
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info: return (function(waitTime) {
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     try {
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:             var end = window.performance.timing.loadEventEnd;
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:             var start= window.performance.timing.navigationStart;
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:             return (end > 0) && (performance.now() > end - start + waitTime);
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     }
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     catch(e) {
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:         return true;
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     }
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info: })(arguments[arguments.length - 1]);
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:  took too long
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     at Timeout.<anonymous> (file:///builds/task_174178076931424/fetches/browsertime/node_modules/browsertime/lib/core/seleniumRunner.js:45:16)
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     at listOnTimeout (node:internal/timers:569:17)
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info:     at process.processTimers (node:internal/timers:512:7)
[task 2025-03-12T12:03:54.998Z] 12:03:43     INFO -  raptor-browsertime Info: URL failed to load, trying 4 more time(s): Failed waiting on page https://prod.youtube-test.prod.webservices.mozgcp.net/main.html?test_type=playbackperf-hfr-test&tests=38&raptor=true&exclude=1,2&muted=true&command=run  to finished loading, timed out after 120000 ms
[task 2025-03-12T12:03:54.998Z] 12:03:45     INFO -  adb Setting test_root to /data/local/tmp/test_root
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -  TEST-INFO | screencap: exit 0
[task 2025-03-12T12:03:54.998Z] 12:03:46 CRITICAL -  raptor-browsertime Critical: Failed waiting on page https://prod.youtube-test.prod.webservices.mozgcp.net/main.html?test_type=playbackperf-hfr-test&tests=38&raptor=true&exclude=1,2&muted=true&command=run to finished loading, timed out after 120000 ms Error: Running page complete check
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -  raptor-browsertime-android Info: removing reverse socket connections
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -  raptor-browsertime Info: Test support class is cleaning up...
[task 2025-03-12T12:03:54.998Z] 12:03:46    ERROR -  Traceback (most recent call last):
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -    File "/builds/task_174178076931424/workspace/build/tests/raptor/raptor/raptor.py", line 189, in <module>
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -      main()
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -    File "/builds/task_174178076931424/workspace/build/tests/raptor/raptor/raptor.py", line 138, in main
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -    File "/builds/task_174178076931424/workspace/build/tests/raptor/raptor/browsertime/android.py", line 280, in run_tests
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -      return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -    File "/builds/task_174178076931424/workspace/build/tests/raptor/raptor/perftest.py", line 502, in run_tests
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -    File "/builds/task_174178076931424/workspace/build/tests/raptor/raptor/browsertime/base.py", line 1099, in run_test
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -      raise Exception(self.browsertime_failure)
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO -  Exception: Failed waiting on page https://prod.youtube-test.prod.webservices.mozgcp.net/main.html?test_type=playbackperf-hfr-test&tests=38&raptor=true&exclude=1,2&muted=true&command=run to finished loading, timed out after 120000 ms Error: Running page complete check
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Return code: 1
[task 2025-03-12T12:03:54.998Z] 12:03:46  WARNING - setting return code to 1
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Killing logcat pid 829.
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Copying Raptor results to upload dir:
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - /builds/task_174178076931424/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Copying raptor results from /builds/task_174178076931424/workspace/build/raptor.json to /builds/task_174178076931424/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2025-03-12T12:03:54.998Z] 12:03:46 CRITICAL - Error copying results /builds/task_174178076931424/workspace/build/raptor.json to upload dir /builds/task_174178076931424/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - [Errno 2] No such file or directory: '/builds/task_174178076931424/workspace/build/raptor.json'
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Running post-action listener: _package_coverage_data
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Running post-action listener: _resource_record_post_action
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Running post-action listener: process_java_coverage_data
[task 2025-03-12T12:03:54.998Z] 12:03:46     INFO - Running post-action listener: stop_device
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - /data/tombstones/tombstone_01 deleted
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - /data/tombstones/tombstone_01.pb deleted
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - Killing logcat pid 829.
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - [mozharness: 2025-03-12 12:03:49.562648Z] Finished run-tests step (success)
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - Running post-run listener: _resource_record_post_run
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - Total resource usage - Wall time: 205s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - TinderboxPrint: I/O write bytes / time<br/>0 / 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - install-chrome-android - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - install-chromium-android - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - install - Wall time: 16s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-03-12T12:03:54.998Z] 12:03:49     INFO - run-tests - Wall time: 187s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-03-12T12:03:54.998Z] 12:03:49  WARNING - returning nonzero exit status 1
[task 2025-03-12T12:03:54.998Z] cleanup
[task 2025-03-12T12:03:54.998Z] + cleanup
[task 2025-03-12T12:03:54.998Z] + local rv=1
[task 2025-03-12T12:03:54.998Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2025-03-12T12:03:54.998Z] + false
[task 2025-03-12T12:03:54.998Z] + '[' ']'
[task 2025-03-12T12:03:54.998Z] + false
[task 2025-03-12T12:03:54.998Z] + exit 1
[task 2025-03-12T12:03:54.998Z] script.py: command finished
[task 2025-03-12T12:03:54.998Z] command_output: adb kill-server, timeout: None, timedout: None, exitcode: 0, output: 
[task 2025-03-12T12:03:55.059Z] 
[task 2025-03-12T12:03:55.059Z] netstat -aop
[task 2025-03-12T12:03:55.059Z] Active Internet connections (servers and established)
[task 2025-03-12T12:03:55.059Z] Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name     Timer
[task 2025-03-12T12:03:55.059Z] tcp        0      0 localhost:36787         0.0.0.0:*               LISTEN      1178/geckodriver     off (0.00/0/0)
[task 2025-03-12T12:03:55.059Z] tcp        0      0 127.0.0.11:34179        0.0.0.0:*               LISTEN      -                    off (0.00/0/0)
[task 2025-03-12T12:03:55.059Z] tcp        0      0 localhost:8099          0.0.0.0:*               LISTEN      79/taskcluster-prox  off (0.00/0/0)
Status: NEW → RESOLVED
Closed: 3 days ago
Duplicate of bug: 1953448
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.