1932613 - Perma mochitest Automation Error: mozharness timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', 'browser/base/content/test/backforward/browser.toml'

Status: NEW

(Core :: Machine Learning, defect, P5)

Description

[Treeherder Bug Filer]

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

---

task 2024-11-21T12:18:36.796Z] 12:18:36     INFO - TEST-START | toolkit/components/ml/tests/browser/browser_ml_end_to_end.js
[task 2024-11-21T12:18:36.864Z] 12:18:36     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f031166a400 == 5 [pid = 25043] [id = 4]
[task 2024-11-21T12:18:36.865Z] 12:18:36     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 10 (7f03104da600) [pid = 25043] [serial = 10] [outer = 0]
[task 2024-11-21T12:18:36.865Z] 12:18:36     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (7f0311663c00) [pid = 25043] [serial = 11] [outer = 7f03104da600]
[task 2024-11-21T12:18:36.876Z] 12:18:36     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (7f0311667c00) [pid = 25043] [serial = 12] [outer = 7f03104da600]
[task 2024-11-21T12:18:36.885Z] 12:18:36     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (7f0311666800) [pid = 25043] [serial = 13] [outer = 7f03104da600]
[task 2024-11-21T12:18:36.930Z] 12:18:36     INFO - GECKO(25043) | [Child 25214: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f7a6f27dc00 == 1 [pid = 25214] [id = 0]
[task 2024-11-21T12:18:36.931Z] 12:18:36     INFO - GECKO(25043) | [Child 25214: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7f7a6e695c00) [pid = 25214] [serial = 1] [outer = 0]
[task 2024-11-21T12:18:36.932Z] 12:18:36     INFO - GECKO(25043) | [Child 25214: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7f7a6f276400) [pid = 25214] [serial = 2] [outer = 7f7a6e695c00]
[task 2024-11-21T12:18:36.956Z] 12:18:36     INFO - GECKO(25043) | [Child 25214: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7f7a6f280000) [pid = 25214] [serial = 3] [outer = 7f7a6e695c00]
[task 2024-11-21T12:18:36.975Z] 12:18:36     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Creating a new engine"
[task 2024-11-21T12:18:36.983Z] 12:18:36     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Ignored attempt to delete previous models when the engine is not fully initialized."
[task 2024-11-21T12:18:37.317Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Using runtime ort-wasm-simd-threaded.jsep.wasm@2.0" ({id:"1ebb1385-346f-43e2-a754-3d91ca9e6a84", name:"ort-wasm-simd-threaded.jsep.wasm", version:"2.0", last_modified:1732191516801, schema:1732191516801})
[task 2024-11-21T12:18:37.386Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineChild: "Inference engine options:" ({engineId:"default-engine", featureId:null, taskName:"moz-image-to-text", timeoutMS:1000, modelHub:null, modelHubRootUrl:"chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data", modelHubUrlTemplate:"{model}/resolve/{revision}", modelId:"acme/test-vit-gpt2-image-captioning", modelRevision:"main", tokenizerId:"acme/test-vit-gpt2-image-captioning", tokenizerRevision:"main", processorId:"acme/test-vit-gpt2-image-captioning", processorRevision:"main", logLevel:"All", runtimeFilename:"ort-wasm-simd-threaded.jsep.wasm", device:null, dtype:"q8", numThreads:null, executionPriority:null})
[task 2024-11-21T12:18:37.582Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Initializing Pipeline for task moz-image-to-text"
[task 2024-11-21T12:18:37.584Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Internal task detected moz-image-to-text"
[task 2024-11-21T12:18:37.584Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Nightly detected. Using transformers-dev.js"
[task 2024-11-21T12:18:37.586Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Transformers.js env" ({version:"3.0.0-alpha.15", backends:{onnx:{wasm:{wasmPaths:{}, proxy:false, numThreads:2, wasmBinary:{}}, webgl:{}, webgpu:{powerPreference:"high-performance"}, versions:{common:"1.20.0-dev.20240827-5d54dc1462", web:"1.20.0-dev.20240827-1d059b8702"}, get logLevel(){return dr}, set logLevel(e){if(e!==void 0){if(typeof e!="string"||["verbose","info","warning","error","fatal"].indexOf(e)===-1)throw new Error(`Unsupported logging level: ${e}`);dr=e}}, trace:true, debug:true}}, allowRemoteModels:true, remoteHost:"chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data", remotePathTemplate:"{model}/resolve/{revision}", allowLocalModels:false, localModelPath:"NO_LOCAL", useFS:false, useBrowserCache:false, useFSCache:false, cacheDir:null, useCustomCache:true, customCache:{}})
[task 2024-11-21T12:18:37.595Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Setting up pipeline for wasm using q8 quantization."
[task 2024-11-21T12:18:37.595Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Using internal inference function"
[task 2024-11-21T12:18:37.595Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Loading model acme/test-vit-gpt2-image-captioning with class AutoModelForVision2Seq"
[task 2024-11-21T12:18:37.596Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Loading tokenizer acme/test-vit-gpt2-image-captioning with class AutoTokenizer"
[task 2024-11-21T12:18:37.598Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Loading processor acme/test-vit-gpt2-image-captioning with class AutoProcessor"
[task 2024-11-21T12:18:37.599Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Pipeline initialized"
[task 2024-11-21T12:18:37.608Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Creating model hub instance"
[task 2024-11-21T12:18:37.610Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Creating model hub instance"
[task 2024-11-21T12:18:37.612Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Creating model hub instance"
[task 2024-11-21T12:18:37.615Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Creating model hub instance"
[task 2024-11-21T12:18:37.615Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ONNXPipeline: "Initializing model, tokenizer and processor"
[task 2024-11-21T12:18:37.620Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.620Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.621Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/config.json?download=true"
[task 2024-11-21T12:18:37.626Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.626Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.626Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/tokenizer.json?download=true"
[task 2024-11-21T12:18:37.627Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.629Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.630Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/tokenizer_config.json?download=true"
[task 2024-11-21T12:18:37.632Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.632Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.633Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/preprocessor_config.json?download=true"
[task 2024-11-21T12:18:37.634Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/config.json?download=true"
[task 2024-11-21T12:18:37.638Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/tokenizer_config.json?download=true"
[task 2024-11-21T12:18:37.639Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/tokenizer.json?download=true"
[task 2024-11-21T12:18:37.641Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/preprocessor_config.json?download=true"
[task 2024-11-21T12:18:37.642Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/config.json with size:" "config.json"
[task 2024-11-21T12:18:37.643Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/config.json with headers:" ({'Content-Type':"application/json", 'Content-Length':"4609", ETag:"NO_ETAG", fileSize:4609})
[task 2024-11-21T12:18:37.648Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/tokenizer.json with size:" "tokenizer.json"
[task 2024-11-21T12:18:37.649Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/tokenizer.json with headers:" ({'Content-Type':"application/json", 'Content-Length':"5094", ETag:"NO_ETAG", fileSize:5094})
[task 2024-11-21T12:18:37.650Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/tokenizer_config.json with size:" "tokenizer_config.json"
[task 2024-11-21T12:18:37.651Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/tokenizer_config.json with headers:" ({'Content-Type':"application/json", 'Content-Length':"234", ETag:"NO_ETAG", fileSize:234})
[task 2024-11-21T12:18:37.653Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/preprocessor_config.json with size:" "preprocessor_config.json"
[task 2024-11-21T12:18:37.654Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/preprocessor_config.json with headers:" ({'Content-Type':"application/json", 'Content-Length':"293", ETag:"NO_ETAG", fileSize:293})
[task 2024-11-21T12:18:37.667Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/config.json, size 0MiB"
[task 2024-11-21T12:18:37.676Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/tokenizer.json, size 0MiB"
[task 2024-11-21T12:18:37.679Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.680Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.680Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/onnx/encoder_model_quantized.onnx?download=true"
[task 2024-11-21T12:18:37.683Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.683Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.683Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/onnx/decoder_model_merged_quantized.onnx?download=true"
[task 2024-11-21T12:18:37.684Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:182
[task 2024-11-21T12:18:37.685Z] 12:18:37     INFO - GECKO(25043) | [Parent 25043, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/chrome/nsChromeProtocolHandler.cpp:73
[task 2024-11-21T12:18:37.685Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Getting model file from chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/generation_config.json?download=true"
[task 2024-11-21T12:18:37.687Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/tokenizer_config.json, size 0MiB"
[task 2024-11-21T12:18:37.689Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/onnx/encoder_model_quantized.onnx?download=true"
[task 2024-11-21T12:18:37.695Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/onnx/decoder_model_merged_quantized.onnx?download=true"
[task 2024-11-21T12:18:37.696Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Fetching chrome://mochitests/content/browser/toolkit/components/ml/tests/browser/data/acme/test-vit-gpt2-image-captioning/resolve/main/generation_config.json?download=true"
[task 2024-11-21T12:18:37.697Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/preprocessor_config.json, size 0MiB"
[task 2024-11-21T12:18:37.703Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/onnx/encoder_model_quantized.onnx with size:" "onnx/encoder_model_quantized.onnx"
[task 2024-11-21T12:18:37.704Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/onnx/encoder_model_quantized.onnx with headers:" ({'Content-Type':"application/octet-stream", 'Content-Length':"28908", ETag:"NO_ETAG", fileSize:28908})
[task 2024-11-21T12:18:37.706Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/onnx/decoder_model_merged_quantized.onnx with size:" "onnx/decoder_model_merged_quantized.onnx"
[task 2024-11-21T12:18:37.707Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/onnx/decoder_model_merged_quantized.onnx with headers:" ({'Content-Type':"application/octet-stream", 'Content-Length':"84790", ETag:"NO_ETAG", fileSize:84790})
[task 2024-11-21T12:18:37.708Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/generation_config.json with size:" "generation_config.json"
[task 2024-11-21T12:18:37.709Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:ModelHub: "Storing acme/test-vit-gpt2-image-captioning/main/generation_config.json with headers:" ({'Content-Type':"application/json", 'Content-Length':"111", ETag:"NO_ETAG", fileSize:111})
[task 2024-11-21T12:18:37.723Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/onnx/encoder_model_quantized.onnx, size 0MiB"
[task 2024-11-21T12:18:37.727Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/onnx/decoder_model_merged_quantized.onnx, size 0MiB"
[task 2024-11-21T12:18:37.733Z] 12:18:37     INFO - GECKO(25043) | console.debug: ML:EngineParent: "Model acme/test-vit-gpt2-image-captioning was fetched from /acme/test-vit-gpt2-image-captioning/resolve/main/generation_config.json, size 0MiB"
[task 2024-11-21T12:18:37.992Z] 12:18:37     INFO - GECKO(25043) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpmf_zbr7l.mozrunner/runtests_leaks_tab_pid25359.log
[task 2024-11-21T12:18:38.084Z] 12:18:38     INFO - GECKO(25043) | [Child 25359, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:756
[task 2024-11-21T12:18:38.943Z] 12:18:38     INFO - GECKO(25043) | [Child 25214, DOM Worker] WARNING: Failed to clone data.: file /builds/worker/checkouts/gecko/dom/base/StructuredCloneHolder.cpp:198
[task 2024-11-21T12:18:38.944Z] 12:18:38     INFO - GECKO(25043) | [Child 25214, DOM Worker] WARNING: 'rv.Failed()', file /builds/worker/checkouts/gecko/dom/workers/MessageEventRunnable.cpp:61
[task 2024-11-21T12:18:38.969Z] 12:18:38     INFO - GECKO(25043) | [Child 25157: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7a6f27dc00 == 1 [pid = 25157] [id = 0] [url = about:blank]
[task 2024-11-21T12:18:38.992Z] 12:18:38     INFO - GECKO(25043) | [Child 25157: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (7f7a6e81f800) [pid = 25157] [serial = 1] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:39.807Z] 12:18:39     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (7f031ebe2c00) [pid = 25043] [serial = 4] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:39.811Z] 12:18:39     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (7f0311667c00) [pid = 25043] [serial = 12] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:39.813Z] 12:18:39     INFO - GECKO(25043) | [Parent 25043: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (7f0311663c00) [pid = 25043] [serial = 11] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:43.057Z] 12:18:43     INFO - GECKO(25043) | [Child 25157: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7f7a6f287000) [pid = 25157] [serial = 4] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:43.057Z] 12:18:43     INFO - GECKO(25043) | [Child 25157: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7f7a6f27e000) [pid = 25157] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:43.057Z] 12:18:43     INFO - GECKO(25043) | [Child 25157: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f7a6f283c00) [pid = 25157] [serial = 3] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:43.894Z] 12:18:43     INFO - GECKO(25043) | [Child 25212: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7a6f279800 == 0 [pid = 25212] [id = 0] [url = about:blank]
[task 2024-11-21T12:18:43.911Z] 12:18:43     INFO - GECKO(25043) | [Child 25212: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f7a6e8dc400) [pid = 25212] [serial = 1] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:44.726Z] 12:18:44     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (7f7a6f264800) [pid = 25117] [serial = 8] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:44.726Z] 12:18:44     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (7f7a6e8efc00) [pid = 25117] [serial = 17] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:44.727Z] 12:18:44     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (7f7a6f25c800) [pid = 25117] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:44.729Z] 12:18:44     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (7f7a6f25e000) [pid = 25117] [serial = 4] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:44.729Z] 12:18:44     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (7f7a6f267400) [pid = 25117] [serial = 10] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:44.729Z] 12:18:44     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (7f7a6f262c00) [pid = 25117] [serial = 6] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:45.267Z] 12:18:45     INFO - GECKO(25043) | [Child 25275: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f7a6f293800) [pid = 25275] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:47.983Z] 12:18:47     INFO - GECKO(25043) | [Child 25212: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7f7a6f275800) [pid = 25212] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-11-21T12:18:49.130Z] 12:18:49     INFO - GECKO(25043) | [Child 25214: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f7a6f276400) [pid = 25214] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-11-21T12:19:11.730Z] 12:19:11     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7a6f262800 == 5 [pid = 25117] [id = 3] [url = moz-extension://adfaff8b-1a64-4d0f-90d6-77c33898476b/_generated_background_page.html]
[task 2024-11-21T12:19:15.922Z] 12:19:15     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (7f7a6e824400) [pid = 25117] [serial = 7] [outer = 0] [url = moz-extension://adfaff8b-1a64-4d0f-90d6-77c33898476b/_generated_background_page.html]
[task 2024-11-21T12:19:19.988Z] 12:19:19     INFO - GECKO(25043) | [Child 25117: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (7f7a6e8eac00) [pid = 25117] [serial = 14] [outer = 0] [url = moz-extension://adfaff8b-1a64-4d0f-90d6-77c33898476b/_generated_background_page.html]
[task 2024-11-21T12:23:33.946Z] 12:23:33     INFO - GECKO(25043) | [Parent 25043, sqldb:places.sqlite #2] WARNING: Suboptimal indexes for the SQL statement 0x7f03126e4e40 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp:114
[task 2024-11-21T12:23:33.947Z] 12:23:33     INFO - GECKO(25043) | [Parent 25043, sqldb:places.sqlite #2] WARNING: Suboptimal indexes for the SQL statement 0x7f03126e4e40 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp:114
[task 2024-11-21T12:40:13.947Z] 12:40:13     INFO - Automation Error: mozharness timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', 'browser/base/content/test/backforward/browser.toml', 'browser/base/content/test/outOfProcess/browser.toml', 'browser/base/content/test/sidebar/browser.toml', 'browser/components/asrouter/tests/browser/browser.toml', 'browser/components/extensions/test/browser/browser-private.toml', 'browser/components/preferences/tests/browser.toml', 'browser/components/shell/test/browser.toml', 'browser/extensions/formautofill/test/browser/address/browser.toml', 'docshell/test/navigation/browser.toml', 'dom/ipc/tests/JSWindowActor/browser.toml', 'dom/security/test/referrer-policy/browser.toml', 'ipc/glue/test/browser/browser.toml', 'security/sandbox/test/browser_profiler.toml', 'toolkit/components/backgroundtasks/tests/browser/browser.toml', 'toolkit/components/ml/tests/browser/browser.toml', 'toolkit/components/resistfingerprinting/tests/browser/browser.toml', 'toolkit/modules/tests/browser/browser.toml', '--setpref=layout.css.stylo-threads=4', '--setpref=gfx.webrender.software=true', '--setpref=media.peerconnection.mtransport_process=false', '--setpref=network.process.enabled=false', '--setpref=layers.d3d11.enable-blacklist=false', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=/builds/worker/workspace/build/symbols', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/mochitest-browser-chrome_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', '--flavor=browser', '--chunk-by-runtime']
[task 2024-11-21T12:40:13.948Z] 12:40:13     INFO - Return code: -9
[task 2024-11-21T12:40:13.949Z] 12:40:13    ERROR - No suite end message was emitted by this harness.
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - TinderboxPrint: mochitest-mochitest-browser-chrome<br/>313/0/0
[task 2024-11-21T12:40:13.949Z] 12:40:13  WARNING - setting return code to 2
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - The mochitest suite: mochitest-browser-chrome ran with return status: FAILURE
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - Running post-action listener: _package_coverage_data
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - Running post-action listener: _resource_record_post_action
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - Running post-action listener: process_java_coverage_data
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - [mozharness: 2024-11-21 12:40:13.949833Z] Finished run-tests step (success)
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - [mozharness: 2024-11-21 12:40:13.949871Z] Running uninstall step.
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - Running pre-action listener: _resource_record_pre_action
[task 2024-11-21T12:40:13.949Z] 12:40:13     INFO - Running main action method: uninstall
[task 2024-11-21T12:40:13.950Z] 12:40:13     INFO - Skipping uninstall for non-MSIX test
[task 2024-11-21T12:40:13.950Z] 12:40:13     INFO - Running post-action listener: _resource_record_post_action
[task 2024-11-21T12:40:13.950Z] 12:40:13     INFO - [mozharness: 2024-11-21 12:40:13.950044Z] Finished uninstall step (success)
[task 2024-11-21T12:40:13.950Z] 12:40:13     INFO - Running post-run listener: _resource_record_post_run
[task 2024-11-21T12:40:15.199Z] 12:40:15     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-browser-chrome.8.overall", "extraOptions": ["e10s", "taskcluster-projects/887720501152/machineTypes/c2-standard-4"], "subtests": [{"name": "cpu_percent", "value": 27.70587259455878}, {"name": "io_write_bytes", "value": 2077687808}, {"name": "io.read_bytes", "value": 0}, {"name": "io_write_time", "value": 557196}, {"name": "io_read_time", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.8.start-pulseaudio", "subtests": [{"name": "time", "value": 0.019894591000138462}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.8.install", "subtests": [{"name": "time", "value": 22.064519953999934}, {"name": "cpu_percent", "value": 25.378995433789953}]}, {"name": "mochitest.mochitest-browser-chrome.8.stage-files", "subtests": [{"name": "time", "value": 0.00023771900032443227}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.8.run-tests", "subtests": [{"name": "time", "value": 3443.448594668}, {"name": "cpu_percent", "value": 27.72069541231112}]}, {"name": "mochitest.mochitest-browser-chrome.8.uninstall", "subtests": [{"name": "time", "value": 0.00011471399920992553}, {"name": "cpu_percent", "value": 0}]}]}
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - Total resource usage - Wall time: 3466s; CPU: Can't collect data; Read bytes: 0; Write bytes: 2077687808; Read time: 0; Write time: 557196
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - TinderboxPrint: I/O write bytes / time<br/>2,077,687,808 / 557,196
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - TinderboxPrint: CPU idle<br/>9,922.4 (71.8%)
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - TinderboxPrint: CPU system<br/>222.9 (1.6%)
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - TinderboxPrint: CPU user<br/>3,603.0 (26.1%)
[task 2024-11-21T12:40:15.201Z] 12:40:15     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2024-11-21T12:40:15.206Z] 12:40:15     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-11-21T12:40:15.211Z] 12:40:15     INFO - install - Wall time: 22s; CPU: 25%; Read bytes: 0; Write bytes: 22564864; Read time: 0; Write time: 8972
[task 2024-11-21T12:40:15.215Z] 12:40:15     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-11-21T12:40:15.423Z] 12:40:15     INFO - run-tests - Wall time: 3443s; CPU: 28%; Read bytes: 0; Write bytes: 2055122944; Read time: 0; Write time: 548224
[task 2024-11-21T12:40:15.439Z] 12:40:15     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-11-21T12:40:21.717Z] 12:40:21  WARNING - returning nonzero exit status 2

Comment 1

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e4305da6f59e
temporarily disable browser_ml_end_to_end.js for permanent failures. CLOSED TREE

Comment 2

[amarc]

https://hg.mozilla.org/mozilla-central/rev/e4305da6f59e

Comment 3

[Intermittent Failures Robot]

60 failures in 377 pushes (0.159 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 54
• mozilla-central: 3
• try: 3

Platform and build breakdown:

• linux1804-64-qr: 11
  • debug: 4
  • opt: 7
• macosx1015-64-shippable-qr: 5
  • opt: 5
• linux1804-64-asan-qr: 19
  • opt: 19
• macosx1015-64-qr: 12
  • opt: 7
  • debug: 5
• linux1804-64-shippable-qr: 3
  • opt: 3
• windows11-64-2009-qr: 1
  • opt: 1
• macosx1100-aarch64-shippable-qr: 5
  • opt: 5
• windows11-32-2009-qr: 2
  • debug: 2
• linux1804-64-tsan-qr: 1
  • opt: 1
• macosx1015-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1932613&startday=2024-11-21&endday=2024-11-21&tree=all

Comment 4

[Intermittent Failures Robot]

131 failures in 3002 pushes (0.044 failures/push) were associated with this bug in the last 7 days.

This is the #6 most frequent failure this week.

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 125
• mozilla-central: 3
• try: 3

Platform and build breakdown:

• linux1804-64-qr: 11
  • debug: 4
  • opt: 7
• macosx1015-64-shippable-qr: 5
  • opt: 5
• linux1804-64-asan-qr: 90
  • opt: 90
• macosx1015-64-qr: 12
  • opt: 7
  • debug: 5
• linux1804-64-shippable-qr: 3
  • opt: 3
• windows11-64-2009-qr: 1
  • opt: 1
• macosx1100-aarch64-shippable-qr: 5
  • opt: 5
• windows11-32-2009-qr: 2
  • debug: 2
• linux1804-64-tsan-qr: 1
  • opt: 1
• macosx1015-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1932613&startday=2024-11-18&endday=2024-11-24&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 3953 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1932613&startday=2024-11-25&endday=2024-12-01&tree=all