1817282 - Intermittent browser/components/urlbar/tests/ext/browser/browser_ext_urlbar_extensionTimeout.js | single tracking bug

Status: RESOLVED INCOMPLETE

(Firefox :: Address Bar, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-02-16T18:24:21.350Z] 18:24:21     INFO - TEST-START | browser/components/urlbar/tests/ext/browser/browser_ext_urlbar_extensionTimeout.js
[task 2023-02-16T18:25:06.353Z] 18:25:06     INFO - TEST-INFO | started process screenshot
[task 2023-02-16T18:25:06.423Z] 18:25:06     INFO - TEST-INFO | screenshot: exit 0
[task 2023-02-16T18:25:06.430Z] 18:25:06     INFO - Buffered messages logged at 18:24:21
[task 2023-02-16T18:25:06.431Z] 18:25:06     INFO - Entering setup bound loadSource
[task 2023-02-16T18:25:06.431Z] 18:25:06     INFO - Leaving setup bound loadSource
[task 2023-02-16T18:25:06.431Z] 18:25:06     INFO - Entering test bound get
[task 2023-02-16T18:25:06.432Z] 18:25:06     INFO - Extension loaded
[task 2023-02-16T18:25:06.432Z] 18:25:06     INFO - Console message: 1676571861356	addons.webextension.<unknown>	WARN	Loading extension 'null': Reading manifest: Invalid extension permission: urlbar
[task 2023-02-16T18:25:06.433Z] 18:25:06     INFO - Buffered messages finished
[task 2023-02-16T18:25:06.433Z] 18:25:06     INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/ext/browser/browser_ext_urlbar_extensionTimeout.js | Test timed out - 
[task 2023-02-16T18:25:06.433Z] 18:25:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-02-16T18:25:06.434Z] 18:25:06     INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/ext/browser/browser_ext_urlbar_extensionTimeout.js | Extension left running at test shutdown - 
[task 2023-02-16T18:25:06.434Z] 18:25:06     INFO - Stack trace:
[task 2023-02-16T18:25:06.434Z] 18:25:06     INFO - chrome://mochikit/content/browser-test.js:test_ok:1465
[task 2023-02-16T18:25:06.434Z] 18:25:06     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:132
[task 2023-02-16T18:25:06.434Z] 18:25:06     INFO - chrome://mochikit/content/browser-test.js:nextTest:611
[task 2023-02-16T18:25:06.435Z] 18:25:06     INFO - Console message: [JavaScript Error: "Message manager was disconnected before receiving Extension:ExtensionViewLoaded" {file: "resource://gre/modules/ExtensionParent.jsm" line: 1816}]
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - observer@resource://gre/modules/ExtensionParent.jsm:1816:11
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - _releaseBrowser@resource://gre/modules/ExtensionParent.jsm:1513:18
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - shutdown@resource://gre/modules/ExtensionParent.jsm:1508:12
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - shutdown@chrome://extensions/content/parent/ext-backgroundPage.js:149:11
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - onShutdown@chrome://extensions/content/parent/ext-backgroundPage.js:628:23
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - ExtensionAPI/<@resource://gre/modules/ExtensionCommon.jsm:362:14
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - wrapper@resource://gre/modules/ExtensionCommon.jsm:306:14
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - emit@resource://gre/modules/ExtensionCommon.jsm:333:32
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - emit@resource://gre/modules/Extension.jsm:2651:25
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - shutdown@resource://gre/modules/Extension.jsm:3388:10
[task 2023-02-16T18:25:06.436Z] 18:25:06     INFO - 
[task 2023-02-16T18:25:06.437Z] 18:25:06     INFO - GECKO(2544) | JavaScript error: resource://specialpowers/SpecialPowersParent.sys.mjs, line 1205: TypeError: can't access property "testMessage", extension is undefined
[task 2023-02-16T18:25:06.437Z] 18:25:06     INFO - Console message: [JavaScript Error: "TypeError: can't access property "testMessage", extension is undefined" {file: "resource://specialpowers/SpecialPowersParent.sys.mjs" line: 1205}]
[task 2023-02-16T18:25:14.363Z] 18:25:14     INFO - Console message: [JavaScript Error: "Timeout while waiting for extension child to shutdown: "Generated extension" (ID: {6fb3fabc-23f6-4ddb-991a-a928e79106ce}, moz-extension://2e15e715-7026-4752-b1bf-74c5eb001128/)" {file: "resource://gre/modules/Extension.jsm" line: 3399}]
[task 2023-02-16T18:25:14.363Z] 18:25:14     INFO - shutdown@resource://gre/modules/Extension.jsm:3399:10
[task 2023-02-16T18:25:14.363Z] 18:25:14     INFO - 
[task 2023-02-16T18:30:15.320Z] 18:30:15     INFO -  console.error: (new TypeError("connection not specified or invalid.", "resource://gre/modules/Sqlite.sys.mjs", 1363))
[task 2023-02-16T18:30:46.374Z] 18:30:46     INFO - GECKO(2544) | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.js", 334))
[task 2023-02-16T18:32:15.320Z] 18:32:15     INFO -  console.error: (new TypeError("can't access property \"executeTransaction\", db is undefined", "resource://gre/modules/PlacesFrecencyRecalculator.sys.mjs", 186))
[task 2023-02-16T18:32:46.395Z] 18:32:46     INFO - GECKO(2544) | 1676572366400	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2023-02-16T18:32:46.402Z] 18:32:46     INFO - Console message: [JavaScript Error: "1676572366400	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates" {file: "resource://gre/modules/Log.sys.mjs" line: 723}]
[task 2023-02-16T18:32:46.402Z] 18:32:46     INFO - append@resource://gre/modules/Log.sys.mjs:723:12
[task 2023-02-16T18:32:46.402Z] 18:32:46     INFO - log@resource://gre/modules/Log.sys.mjs:377:16
[task 2023-02-16T18:32:46.402Z] 18:32:46     INFO - error@resource://gre/modules/Log.sys.mjs:385:10
[task 2023-02-16T18:32:46.402Z] 18:32:46     INFO - updateSystemAddons/res<@resource://gre/modules/addons/XPIInstall.jsm:4104:25
[task 2023-02-16T18:32:46.402Z] 18:32:46     INFO - 
[task 2023-02-16T18:38:56.427Z] 18:38:56     INFO - Buffered messages finished
[task 2023-02-16T18:38:56.429Z] 18:38:56    ERROR - TEST-UNEXPECTED-TIMEOUT | browser/components/urlbar/tests/ext/browser/browser_ext_urlbar_extensionTimeout.js | application timed out after 370 seconds with no output
[task 2023-02-16T18:38:56.429Z] 18:38:56    ERROR - Force-terminating active process(es).
[task 2023-02-16T18:38:56.430Z] 18:38:56     INFO - Determining child pids from psutil...
[task 2023-02-16T18:38:56.435Z] 18:38:56     INFO - [7628]
[task 2023-02-16T18:38:56.436Z] 18:38:56     INFO - ==> process 7628 launched child process 1296 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.0.483800498\722435037" -parentBuildID 20230216160958 -prefsHandle 2176 -prefMapHandle 2168 -prefsLen 21513 -prefMapSize 248732 -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {956c8c66-2fb0-44b1-be2f-68957b0ce23e} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 2256 240fea2f058 gpu)
[task 2023-02-16T18:38:56.438Z] 18:38:56     INFO - ==> process 7628 launched child process 5516 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.1.881855728\547941450" -childID 1 -isForBrowser -prefsHandle 2960 -prefMapHandle 2944 -prefsLen 21534 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {4d941b74-39da-4d4e-a739-1815545d927e} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 2972 24103de9358 tab)
[task 2023-02-16T18:38:56.439Z] 18:38:56     INFO - ==> process 7628 launched child process 8796 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.2.378040513\285174317" -childID 2 -isForBrowser -prefsHandle 3376 -prefMapHandle 3372 -prefsLen 23070 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {46ce8539-e9d4-4a9c-b844-412179212d12} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 3384 240f2897958 tab)
[task 2023-02-16T18:38:56.440Z] 18:38:56     INFO - ==> process 7628 launched child process 6900 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.3.1804866644\169560711" -childID 3 -isForBrowser -prefsHandle 3596 -prefMapHandle 3592 -prefsLen 22730 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {22d37621-96a6-4da6-8d26-b5b16bd64457} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 3640 24105096158 tab)
[task 2023-02-16T18:38:56.442Z] 18:38:56     INFO - ==> process 7628 launched child process 8504 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.4.2698674\908235906" -parentBuildID 20230216160958 -sandboxingKind 0 -prefsHandle 4360 -prefMapHandle 4324 -prefsLen 31268 -prefMapSize 248732 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {64c54b2d-f6c7-43e0-ae62-c87c81763003} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 4196 24108903558 utility)
[task 2023-02-16T18:38:56.443Z] 18:38:56     INFO - ==> process 7628 launched child process 8272 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.5.1778565136\1174545986" -childID 4 -isForBrowser -prefsHandle 4388 -prefMapHandle 4196 -prefsLen 28582 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {5f03182f-89fa-4048-ac17-da77944eab08} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 4480 24104e55258 tab)
[task 2023-02-16T18:38:56.444Z] 18:38:56     INFO - ==> process 7628 launched child process 7708 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.6.585832347\1473213887" -childID 5 -isForBrowser -prefsHandle 4488 -prefMapHandle 4376 -prefsLen 28582 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {4eac2b8f-53ed-4f9c-a557-a6e96792f346} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 3028 24108905c58 tab)
[task 2023-02-16T18:38:56.446Z] 18:38:56     INFO - ==> process 7628 launched child process 2800 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.7.1066726239\378404484" -childID 6 -isForBrowser -prefsHandle 4660 -prefMapHandle 4776 -prefsLen 28582 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {fd7070f3-d34e-4c19-b2e7-a529c8e65205} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 4480 24108ea8c58 tab)
[task 2023-02-16T18:38:56.447Z] 18:38:56     INFO - ==> process 7628 launched child process 3920 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.8.505869898\1184315654" -childID 7 -isForBrowser -prefsHandle 4796 -prefMapHandle 4792 -prefsLen 31268 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {efb91024-ed19-4bee-96d1-3da3f4cf3bd5} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 3092 24108ea7158 tab)
[task 2023-02-16T18:38:56.448Z] 18:38:56     INFO - ==> process 7628 launched child process 8768 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.9.1059459575\251820434" -childID 8 -isForBrowser -prefsHandle 4888 -prefMapHandle 4492 -prefsLen 28757 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {37c3f711-e718-484c-a096-8e1814c2fa9f} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 5176 240f284b658 tab)
[task 2023-02-16T18:38:56.450Z] 18:38:56     INFO - ==> process 7628 launched child process 4452 ("C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\firefox.exe" -contentproc --channel="7628.10.1856807109\351630538" -childID 9 -isForBrowser -prefsHandle 5512 -prefMapHandle 5508 -prefsLen 28757 -prefMapSize 248732 -jsInitHandle 1308 -jsInitLen 257264 -parentBuildID 20230216160958 -win32kLockedDown -appDir "C:\Program Files\WindowsApps\Mozilla.MozillaFirefoxNightly_112.2302.1616.0_x64__gmpnhwe7bv608\VFS\ProgramFiles\MozillaFirefoxNightly Package Root\browser" - {522fb651-f92d-4c6a-b1b2-74e9d1abd5df} 7628 "\\.\pipe\gecko-crash-server-pipe.7628" 5524 24108ea6858 tab)
[task 2023-02-16T18:38:56.450Z] 18:38:56     INFO - Found child pids: {8768, 4452, 5516, 7628, 1296, 8272, 2800, 3920, 6900, 8504, 8796, 7708}
[task 2023-02-16T18:38:56.451Z] 18:38:56     INFO - Failed to get child procs
[task 2023-02-16T18:38:56.451Z] 18:38:56     INFO - Killing process: 8768

Comment 1

[Natalia Csoregi [:nataliaCs]]

First occurrence so far: range of retriggers and backfills

Comment 2

[Intermittent Failures Robot]

2 failures in 3856 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• autoland: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1817282&startday=2023-02-13&endday=2023-02-19&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1817282&startday=2023-02-20&endday=2023-02-26&tree=all

Comment 4

[Intermittent Failures Robot]

6 failures in 3752 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 3
• autoland: 3

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 3
  • opt: 3
• windows11-64-2009-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1817282&startday=2023-02-27&endday=2023-03-05&tree=all

Comment 5

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.