Closed Bug 1839890 Opened 2 years ago Closed 2 years ago

Intermittent TV /tests/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html | single tracking bug

Tracking

(firefox-esr102 unaffected, firefox114 unaffected, firefox115 unaffected, firefox116 fixed)

Status:

RESOLVED FIXED

Milestone:

116 Branch

Tracking Flags:

Tracking

Status

firefox-esr102

---

unaffected

firefox114

---

unaffected

firefox115

---

unaffected

firefox116

---

fixed

People

(Reporter: intermittent-bug-filer, Assigned: robwu)

References

Details

(Keywords: intermittent-failure, test-verify-fail, Whiteboard: [addons-jira])

Attachments

(1 file)

Bug 1839890 - Add browser.pageActions.persistedActions to ignorePrefs.json 2 years ago Rob Wu [:robwu] 48 bytes, text/x-phabricator-request		Details \| Review

Treeherder Bug Filer

Reporter

Description

•

2 years ago

treeherder

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=420293882&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/AfXO4XiQRRaQeNYupnjZPA/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/AfXO4XiQRRaQeNYupnjZPA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2023-06-22T14:16:44.701Z] 14:16:44     INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html | took 2563ms
[task 2023-06-22T14:16:45.147Z] 14:16:45    ERROR - TEST-UNEXPECTED-FAIL | /tests/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html | changed preference: browser.pageActions.persistedActions
[task 2023-06-22T14:16:45.149Z] 14:16:45     INFO - TEST-START | Shutdown
[task 2023-06-22T14:16:45.149Z] 14:16:45     INFO - Passed:  7
[task 2023-06-22T14:16:45.151Z] 14:16:45     INFO - Failed:  0
[task 2023-06-22T14:16:45.153Z] 14:16:45     INFO - Todo:    0
[task 2023-06-22T14:16:45.155Z] 14:16:45     INFO - Mode:    e10s
[task 2023-06-22T14:16:45.155Z] 14:16:45     INFO - Slowest: 2563ms - /tests/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html
[task 2023-06-22T14:16:45.157Z] 14:16:45     INFO - TEST-INFO | Ran 1 Loops
[task 2023-06-22T14:16:45.158Z] 14:16:45     INFO - SimpleTest FINISHED
[task 2023-06-22T14:16:45.300Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.302Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.322Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.348Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.396Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.399Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.428Z] 14:16:45     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:45.806Z] 14:16:45     INFO - GECKO(1635) | 1687443405805	Marionette	TRACE	Received observer notification quit-application
[task 2023-06-22T14:16:45.808Z] 14:16:45     INFO - GECKO(1635) | 1687443405806	Marionette	INFO	Stopped listening on port 2828
[task 2023-06-22T14:16:45.814Z] 14:16:45     INFO - GECKO(1635) | 1687443405813	Marionette	DEBUG	Marionette stopped listening
[task 2023-06-22T14:16:45.888Z] 14:16:45     INFO - GECKO(1635) | [Parent 1635, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:371
[task 2023-06-22T14:16:45.939Z] 14:16:45     INFO - GECKO(1635) | [Parent 1635, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:232
[task 2023-06-22T14:16:45.939Z] 14:16:45     INFO - GECKO(1635) | [Parent 1635, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:232
[task 2023-06-22T14:16:46.400Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPC I/O Parent] WARNING: [1.1]: GetUserData call for port '8D66772B5F8F9F3F.AEE0AAEFF93DBE1B' failed: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:406
[task 2023-06-22T14:16:46.407Z] 14:16:46     INFO - GECKO(1635) | [Child 1731, Main Thread] WARNING: Finishing incremental GC in progress during CC: file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3361
[task 2023-06-22T14:16:46.510Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.000005s: startCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.516Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.000799s: initiateShutdownWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.518Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.000838s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.518Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: cache: '0.000855s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.518Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: sdb: '0.000862s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.522Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: fs: '0.000869s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.523Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: ls: '0.000876s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.524Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.000887s: startKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.525Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.000941s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.527Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.000950s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.527Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.001122s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.528Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.001135s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.529Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.001850s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.531Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.001868s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.533Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.004459s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.537Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.004538s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.538Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.004549s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.539Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.006735s: stopKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.540Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.006756s: shutdownAndJoinWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.542Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: idb: '0.006763s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.543Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: cache: '0.006805s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.545Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: sdb: '0.006813s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.547Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: fs: '0.006819s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.548Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: ls: '0.006826s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.554Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.006832s: shutdownAndJoinIOThread', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.555Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.006990s: invalidatePendingDirectoryLocks', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.556Z] 14:16:46     INFO - GECKO(1635) | [Parent 1635, IPDL Background] WARNING: quota manager shutdown step: '0.007002s: stopCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3266
[task 2023-06-22T14:16:46.853Z] 14:16:46     INFO - GECKO(1635) | [Utility 1814, Main Thread] WARNING: IPC message 'PUtilityProcess::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:508
[task 2023-06-22T14:16:46.881Z] 14:16:46     INFO - GECKO(1635) | Destroying context 0x7ff98213b200 surface (nil) on display 0x7ff982beef00
[task 2023-06-22T14:16:47.473Z] 14:16:47     INFO - GECKO(1635) | [Parent 1635, Main Thread] WARNING: '!top', file /builds/worker/checkouts/gecko/dom/xul/MenuBarListener.cpp:99
[task 2023-06-22T14:16:47.817Z] 14:16:47     INFO - GECKO(1635) | [Parent 1635, Main Thread] WARNING: WaylandDisplayRelease(): Wayland display is missing!: file /builds/worker/checkouts/gecko/widget/gtk/nsWaylandDisplay.cpp:31
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - TEST-INFO | Main app process: exit 0
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - runtests.py | Application ran for: 0:00:18.636869
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - zombiecheck | Reading PID log: /tmp/tmpli_1tc1tpidlog
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - ==> process 1635 launched child process 1655
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - ==> process 1635 launched child process 1731
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - ==> process 1635 launched child process 1758
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - ==> process 1635 launched child process 1814
[task 2023-06-22T14:16:47.839Z] 14:16:47     INFO - ==> process 1635 launched child process 1819
[task 2023-06-22T14:16:47.841Z] 14:16:47     INFO - ==> process 1635 launched child process 1821
[task 2023-06-22T14:16:47.842Z] 14:16:47     INFO - ==> process 1635 launched child process 1844
[task 2023-06-22T14:16:47.843Z] 14:16:47     INFO - ==> process 1635 launched child process 1855
[task 2023-06-22T14:16:47.845Z] 14:16:47     INFO - ==> process 1635 launched child process 1909
[task 2023-06-22T14:16:47.846Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1731
[task 2023-06-22T14:16:47.847Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1844
[task 2023-06-22T14:16:47.848Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1909
[task 2023-06-22T14:16:47.849Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1814
[task 2023-06-22T14:16:47.849Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1655
[task 2023-06-22T14:16:47.850Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1819
[task 2023-06-22T14:16:47.851Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1821
[task 2023-06-22T14:16:47.854Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1758
[task 2023-06-22T14:16:47.854Z] 14:16:47     INFO - zombiecheck | Checking for orphan process with PID: 1855
[task 2023-06-22T14:16:47.854Z] 14:16:47     INFO - Stopping web server
[task 2023-06-22T14:16:47.854Z] 14:16:47     INFO - Server shut down.
[task 2023-06-22T14:16:47.877Z] 14:16:47     INFO - Web server killed.
[task 2023-06-22T14:16:47.877Z] 14:16:47     INFO - Stopping web socket server
[task 2023-06-22T14:16:47.896Z] 14:16:47     INFO - Stopping ssltunnel
[task 2023-06-22T14:16:47.916Z] 14:16:47     INFO - Stopping gst for v4l2loopback
[task 2023-06-22T14:16:47.918Z] 14:16:47     INFO - leakcheck | Processing log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks.log
[task 2023-06-22T14:16:47.919Z] 14:16:47     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.920Z] 14:16:47     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.921Z] 14:16:47     INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2023-06-22T14:16:47.921Z] 14:16:47     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.922Z] 14:16:47     INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.923Z] 14:16:47     INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.924Z] 14:16:47     INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.924Z] 14:16:47     INFO - TEST-INFO | leakcheck | sandboxbroker process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.925Z] 14:16:47     INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.926Z] 14:16:47     INFO - TEST-INFO | leakcheck | utility process: leak threshold set at 0 bytes
[task 2023-06-22T14:16:47.926Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1819.log
[task 2023-06-22T14:16:47.928Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.929Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1758.log
[task 2023-06-22T14:16:47.931Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.932Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1844.log
[task 2023-06-22T14:16:47.933Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.934Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1909.log
[task 2023-06-22T14:16:47.937Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.938Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_utility_pid1814.log
[task 2023-06-22T14:16:47.939Z] 14:16:47     INFO - TEST-PASS | leakcheck | utility no leaks detected!
[task 2023-06-22T14:16:47.940Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1855.log
[task 2023-06-22T14:16:47.941Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.941Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1821.log
[task 2023-06-22T14:16:47.942Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.943Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks.log
[task 2023-06-22T14:16:47.945Z] 14:16:47     INFO - TEST-PASS | leakcheck | default no leaks detected!
[task 2023-06-22T14:16:47.946Z] 14:16:47     INFO - leakcheck | Processing leak log file /tmp/tmplssz9tdv.mozrunner/runtests_leaks_tab_pid1731.log
[task 2023-06-22T14:16:47.948Z] 14:16:47     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-06-22T14:16:47.949Z] 14:16:47     INFO - runtests.py | Running tests: end.
[task 2023-06-22T14:16:47.967Z] 14:16:47     INFO -  Failed to unload module: Module b'30\n' not loaded
[task 2023-06-22T14:16:47.975Z] 14:16:47     INFO -  Failed to unload module: Module b'31\n' not loaded
[task 2023-06-22T14:16:47.982Z] 14:16:47     INFO -  Failed to unload module: Module b'32\n' not loaded
[task 2023-06-22T14:16:47.989Z] 14:16:47     INFO -  Failed to unload module: Module b'33\n' not loaded
[task 2023-06-22T14:16:47.990Z] 14:16:47     INFO - Buffered messages finished
[task 2023-06-22T14:16:47.991Z] 14:16:47     INFO - Running manifest: toolkit/components/extensions/test/mochitest/mochitest.ini:toolkit/components/extensions/test/mochitest/mochitest-common.ini
[task 2023-06-22T14:16:47.992Z] 14:16:47     INFO - The following extra prefs will be set:
[task 2023-06-22T14:16:47.992Z] 14:16:47     INFO -   extensions.webextensions.remote=false
[task 2023-06-22T14:16:47.992Z] 14:16:47     INFO -   javascript.options.asyncstack_capture_debuggee_only=false
[task 2023-06-22T14:16:47.992Z] 14:16:47     INFO -   security.mixed_content.upgrade_display_content=false
[task 2023-06-22T14:16:47.992Z] 14:16:47     INFO -   browser.chrome.guess_favicon=true
[task 2023-06-22T14:16:48.020Z] 14:16:48     INFO -  Setting pipeline to PAUSED ...
[task 2023-06-22T14:16:48.022Z] 14:16:48     INFO -  Pipeline is PREROLLING ...
[task 2023-06-22T14:16:48.025Z] 14:16:48     INFO -  Pipeline is PREROLLED ...
[task 2023-06-22T14:16:48.025Z] 14:16:48     INFO -  Setting pipeline to PLAYING ...
[task 2023-06-22T14:16:48.026Z] 14:16:48     INFO -  New clock: GstSystemClock
[task 2023-06-22T14:16:48.059Z] 14:16:48     INFO -  Got EOS from element "pipeline0".
[task 2023-06-22T14:16:48.059Z] 14:16:48     INFO -  Execution ended after 0:00:00.032823464
[task 2023-06-22T14:16:48.059Z] 14:16:48     INFO -  Setting pipeline to PAUSED ...
[task 2023-06-22T14:16:48.059Z] 14:16:48     INFO -  Setting pipeline to READY ...
[task 2023-06-22T14:16:48.060Z] 14:16:48     INFO -  (gst-launch-1.0:1951): GStreamer-CRITICAL **: 14:16:48.058: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2023-06-22T14:16:48.061Z] 14:16:48     INFO -  Setting pipeline to NULL ...
[task 2023-06-22T14:16:48.061Z] 14:16:48     INFO -  Freeing pipeline ...
[task 2023-06-22T14:16:48.910Z] 14:16:48     INFO - PID 1964 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2023-06-22T14:16:49.045Z] 14:16:49     INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmppdcs3lf_.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2023-06-22T14:16:49.045Z] 14:16:49     INFO - runtests.py | Server pid: 1979
[task 2023-06-22T14:16:49.052Z] 14:16:49     INFO - runtests.py | Websocket server pid: 1982
[task 2023-06-22T14:16:49.083Z] 14:16:49     INFO - runtests.py | SSL tunnel pid: 1986
[task 2023-06-22T14:16:49.195Z] 14:16:49     INFO -  Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2023-06-22T14:16:49.197Z] 14:16:49     INFO -  [Parent 1979, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:400
[task 2023-06-22T14:16:49.234Z] 14:16:49     INFO - use http3 server: 0
[task 2023-06-22T14:16:49.237Z] 14:16:49     INFO - runtests.py | Running with scheme: http
[task 2023-06-22T14:16:49.237Z] 14:16:49     INFO - runtests.py | Running with e10s: True
[task 2023-06-22T14:16:49.237Z] 14:16:49     INFO - runtests.py | Running with fission: True
[task 2023-06-22T14:16:49.237Z] 14:16:49     INFO - runtests.py | Running with cross-origin iframes: False
[task 2023-06-22T14:16:49.237Z] 14:16:49     INFO - runtests.py | Running with serviceworker_e10s: True
[task 2023-06-22T14:16:49.241Z] 14:16:49     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2023-06-22T14:16:49.242Z] 14:16:49     INFO - runtests.py | Running tests: start.
[task 2023-06-22T14:16:49.242Z] 14:16:49     INFO - 
[task 2023-06-22T14:16:49.250Z] 14:16:49     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmppdcs3lf_.mozrunner
[task 2023-06-22T14:16:49.262Z] 14:16:49     INFO - runtests.py | Application pid: 2004
[task 2023-06-22T14:16:49.262Z] 14:16:49     INFO - TEST-INFO | started process GECKO(2004)
[task 2023-06-22T14:16:49.287Z] 14:16:49     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks.log
[task 2023-06-22T14:16:49.403Z] 14:16:49     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Rejected attempt to change type of pref extensions.formautofill.creditCards.available's user value from bool to string: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:1895
[task 2023-06-22T14:16:49.936Z] 14:16:49     INFO - GECKO(2004) | [WARN  rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
[task 2023-06-22T14:16:50.307Z] 14:16:50     INFO - GECKO(2004) | ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-06-22T14:16:50.312Z] 14:16:50     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: GLX_swap_control unsupported, ASAP mode may still block on buffer swaps.: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderGLX.cpp:213
[task 2023-06-22T14:16:50.323Z] 14:16:50     INFO - GECKO(2004) | ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-06-22T14:16:50.331Z] 14:16:50     INFO - GECKO(2004) | [Parent 2004, Renderer] WARNING: Failed to create EGLContext with khr_rbab_attribs: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderEGL.cpp:737
[task 2023-06-22T14:16:50.332Z] 14:16:50     INFO - GECKO(2004) | [Parent 2004, Renderer] WARNING: Failed to create EGLContext with khr_robustness_attribs: file /builds/worker/checkouts/gecko/gfx/gl/GLContextProviderEGL.cpp:749
[task 2023-06-22T14:16:50.339Z] 14:16:50     INFO - GECKO(2004) | Initializing context 0x7fb66023f270 surface (nil) on display 0x7fb66025cf00
[task 2023-06-22T14:16:50.342Z] 14:16:50     INFO - GECKO(2004) | GL_VENDOR: VMware, Inc.
[task 2023-06-22T14:16:50.344Z] 14:16:50     INFO - GECKO(2004) | mVendor: VMware, Inc.
[task 2023-06-22T14:16:50.346Z] 14:16:50     INFO - GECKO(2004) | GL_RENDERER: llvmpipe (LLVM 10.0.0, 256 bits)
[task 2023-06-22T14:16:50.346Z] 14:16:50     INFO - GECKO(2004) | mRenderer: Unknown
[task 2023-06-22T14:16:50.347Z] 14:16:50     INFO - GECKO(2004) | mIsMesa: 1
[task 2023-06-22T14:16:50.347Z] 14:16:50     INFO - GECKO(2004) | [Parent 2004, Renderer] WARNING: robust_buffer_access_behavior marked as unsupported: file /builds/worker/checkouts/gecko/gfx/gl/GLContextFeatures.cpp:638
[task 2023-06-22T14:16:50.348Z] 14:16:50     INFO - GECKO(2004) | [Parent 2004, Renderer] WARNING: Robustness supported, strategy is not LOSE_CONTEXT_ON_RESET!: file /builds/worker/checkouts/gecko/gfx/gl/GLContext.cpp:999
[task 2023-06-22T14:16:50.349Z] 14:16:50     INFO - GECKO(2004) | [Parent 2004, Renderer] WARNING: robustness marked as unsupported: file /builds/worker/checkouts/gecko/gfx/gl/GLContextFeatures.cpp:638
[task 2023-06-22T14:16:50.399Z] 14:16:50     INFO - GECKO(2004) | 1687443410398	Marionette	INFO	Marionette enabled
[task 2023-06-22T14:16:50.404Z] 14:16:50     INFO - GECKO(2004) | 1687443410403	Marionette	TRACE	Received observer notification final-ui-startup
[task 2023-06-22T14:16:50.527Z] 14:16:50     INFO - GECKO(2004) | console.error: "Warning: unrecognized command line flag" "-foreground"
[task 2023-06-22T14:16:50.579Z] 14:16:50     INFO - GECKO(2004) | 1687443410578	Marionette	INFO	Listening on port 2828
[task 2023-06-22T14:16:50.585Z] 14:16:50     INFO - GECKO(2004) | 1687443410584	Marionette	DEBUG	Marionette is listening
[task 2023-06-22T14:16:50.618Z] 14:16:50     INFO - GECKO(2004) | 1687443410617	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:35254
[task 2023-06-22T14:16:50.702Z] 14:16:50     INFO - GECKO(2004) | 1687443410701	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:35256
[task 2023-06-22T14:16:50.704Z] 14:16:50     INFO - GECKO(2004) | 1687443410702	Marionette	DEBUG	Closed connection 0
[task 2023-06-22T14:16:51.159Z] 14:16:51     INFO - GECKO(2004) | 1687443411158	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-06-22T14:16:51.171Z] 14:16:51     INFO - GECKO(2004) | 1687443411170	Marionette	DEBUG	Waiting for initial application window
[task 2023-06-22T14:16:51.585Z] 14:16:51     INFO - GECKO(2004) | [Parent 2004, GMPThread] WARNING: Failed to delete GMP storage directory: file /builds/worker/checkouts/gecko/dom/media/gmp/GMPServiceParent.cpp:1759
[task 2023-06-22T14:16:51.603Z] 14:16:51     INFO - GECKO(2004) | [WARN  webrender::device::gl] Missing optimized shader source for gpu_cache_update
[task 2023-06-22T14:16:51.626Z] 14:16:51     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks_tab_pid2074.log
[task 2023-06-22T14:16:51.663Z] 14:16:51     INFO - GECKO(2004) | [Child 2074, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:655
[task 2023-06-22T14:16:51.882Z] 14:16:51     INFO - GECKO(2004) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-22T14:16:51.917Z] 14:16:51     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:51.937Z] 14:16:51     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:51.947Z] 14:16:51     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:51.956Z] 14:16:51     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:51.967Z] 14:16:51     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:55.169Z] 14:16:55     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/generic/nsFrameSelection.cpp:1711
[task 2023-06-22T14:16:55.307Z] 14:16:55     INFO - GECKO(2004) | console.error: ({})
[task 2023-06-22T14:16:55.515Z] 14:16:55     INFO - GECKO(2004) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2023-06-22T14:16:55.515Z] 14:16:55     INFO - GECKO(2004) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2023-06-22T14:16:55.515Z] 14:16:55     INFO - GECKO(2004) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2023-06-22T14:16:55.558Z] 14:16:55     INFO - GECKO(2004) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2023-06-22T14:16:55.558Z] 14:16:55     INFO - GECKO(2004) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2023-06-22T14:16:55.559Z] 14:16:55     INFO - GECKO(2004) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2023-06-22T14:16:56.147Z] 14:16:56     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2023-06-22T14:16:56.366Z] 14:16:56     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:56.368Z] 14:16:56     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-22T14:16:56.400Z] 14:16:56     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:57.235Z] 14:16:57     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:57.965Z] 14:16:57     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/ThirdPartyUtil.cpp:421
[task 2023-06-22T14:16:57.965Z] 14:16:57     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1235
[task 2023-06-22T14:16:58.041Z] 14:16:58     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: NS_ENSURE_TRUE(mNameHashtable.Get(aName, &index)) failed: file /builds/worker/checkouts/gecko/storage/mozStorageRow.cpp:91
[task 2023-06-22T14:16:58.157Z] 14:16:58     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: NS_ENSURE_TRUE(mNameHashtable.Get(aName, &index)) failed: file /builds/worker/checkouts/gecko/storage/mozStorageRow.cpp:91
[task 2023-06-22T14:16:58.209Z] 14:16:58     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: NS_ENSURE_TRUE(mNameHashtable.Get(aName, &index)) failed: file /builds/worker/checkouts/gecko/storage/mozStorageRow.cpp:91
[task 2023-06-22T14:16:58.982Z] 14:16:58     INFO - GECKO(2004) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-22T14:16:58.985Z] 14:16:58     INFO - GECKO(2004) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-22T14:16:58.987Z] 14:16:58     INFO - GECKO(2004) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-22T14:16:59.020Z] 14:16:59     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks_utility_pid2128.log
[task 2023-06-22T14:16:59.105Z] 14:16:59     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks_tab_pid2135.log
[task 2023-06-22T14:16:59.118Z] 14:16:59     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks_tab_pid2133.log
[task 2023-06-22T14:16:59.161Z] 14:16:59     INFO - GECKO(2004) | [Child 2135, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:655
[task 2023-06-22T14:16:59.165Z] 14:16:59     INFO - GECKO(2004) | [Child 2133, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:655
[task 2023-06-22T14:16:59.326Z] 14:16:59     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks_tab_pid2159.log
[task 2023-06-22T14:16:59.381Z] 14:16:59     INFO - GECKO(2004) | [Child 2159, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:655
[task 2023-06-22T14:16:59.494Z] 14:16:59     INFO - GECKO(2004) | 1687443419491	Marionette	TRACE	Received observer notification browser-idle-startup-tasks-finished
[task 2023-06-22T14:16:59.503Z] 14:16:59     INFO - GECKO(2004) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmppdcs3lf_.mozrunner/runtests_leaks_tab_pid2174.log
[task 2023-06-22T14:16:59.522Z] 14:16:59     INFO - GECKO(2004) | 1687443419521	RemoteAgent	TRACE	[9] ProgressListener Start: expectNavigation=false resolveWhenStarted=false unloadTimeout=40000 waitForExplicitStart=false
[task 2023-06-22T14:16:59.525Z] 14:16:59     INFO - GECKO(2004) | 1687443419524	RemoteAgent	TRACE	[9] ProgressListener Setting unload timer (40000ms)
[task 2023-06-22T14:16:59.530Z] 14:16:59     INFO - GECKO(2004) | 1687443419529	RemoteAgent	TRACE	[9] Document already finished loading: about:blank
[task 2023-06-22T14:16:59.534Z] 14:16:59     INFO - GECKO(2004) | 1687443419533	RemoteAgent	TRACE	[9] ProgressListener Stop: has error=false
[task 2023-06-22T14:16:59.544Z] 14:16:59     INFO - GECKO(2004) | [Child 2174, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:655
[task 2023-06-22T14:16:59.590Z] 14:16:59     INFO - GECKO(2004) | 1687443419588	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"6c71f103-96a9-46ce-9bb5-603c13489961","capabilities":{"browserName":"firefox","browserVersion":"116.0a1","platformName":"linux","acceptInsecureCerts":false,"pageLoadStrategy":"normal","setWindowRect":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"strictFileInteractability":true,"unhandledPromptBehavior":"dismiss and notify","moz:accessibilityChecks":false,"moz:buildID":"20230622135106","moz:headless":false,"moz:platformVersion":"4.4.0-1014-aws","moz:processID":2004,"moz:profile":"/tmp/tmppdcs3lf_.mozrunner","moz:shutdownTimeout":60000,"moz:webdriverClick":true,"moz:windowless":false,"proxy":{}}}]
[task 2023-06-22T14:16:59.624Z] 14:16:59     INFO - GECKO(2004) | 1687443419623	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpohobkakq.zip","temporary":false}]
[task 2023-06-22T14:16:59.858Z] 14:16:59     INFO - GECKO(2004) | [WARN  glean_core::upload] Attempted to enqueue a duplicate ping 28dd747d-4193-40ef-8c80-a481289b3d11 at /submit/firefox-desktop/baseline/1/28dd747d-4193-40ef-8c80-a481289b3d11.
[task 2023-06-22T14:17:00.033Z] 14:17:00     INFO - GECKO(2004) | 1687443420032	Marionette	DEBUG	1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2023-06-22T14:17:00.067Z] 14:17:00     INFO - GECKO(2004) | 1687443420065	Marionette	DEBUG	1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpvxllaoxh.zip","temporary":false}]
[task 2023-06-22T14:17:00.174Z] 14:17:00     INFO - GECKO(2004) | 1687443420173	Marionette	DEBUG	1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2023-06-22T14:17:00.183Z] 14:17:00     INFO - GECKO(2004) | 1687443420182	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2023-06-22T14:17:00.184Z] 14:17:00     INFO - GECKO(2004) | 1687443420183	Marionette	DEBUG	1 <- [1,4,null,{"value":"content"}]
[task 2023-06-22T14:17:00.188Z] 14:17:00     INFO - GECKO(2004) | 1687443420187	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-06-22T14:17:00.189Z] 14:17:00     INFO - GECKO(2004) | 1687443420188	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2023-06-22T14:17:00.194Z] 14:17:00     INFO - GECKO(2004) | 1687443420192	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, v. 2.0. If a copy of the MPL was not distr ... s which flavor and url to load.\nlet ev = new CustomEvent(\"mochitest-load\", { detail: [flavor, url] });\nwin.dispatchEvent(ev);","args":[{"flavor":"mochitest","testUrl":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest?autorun=1&closeWhenDone=1&consoleLevel=INFO&runUnti ... tml&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true&comparePrefs=true&ignorePrefsFile=ignorePrefs.json"}],"newSandbox":true,"sandbox":"default","line":2141,"filename":"tests/mochitest/runtests.py"}]
[task 2023-06-22T14:17:00.206Z] 14:17:00     INFO - GECKO(2004) | 1687443420205	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 2004
[task 2023-06-22T14:17:00.209Z] 14:17:00     INFO - GECKO(2004) | 1687443420208	Marionette	TRACE	[1] MarionetteCommands actor created for window id 2
[task 2023-06-22T14:17:00.334Z] 14:17:00     INFO - GECKO(2004) | 1687443420333	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2023-06-22T14:17:00.356Z] 14:17:00     INFO - GECKO(2004) | 1687443420355	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2023-06-22T14:17:00.357Z] 14:17:00     INFO - GECKO(2004) | 1687443420356	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2023-06-22T14:17:00.599Z] 14:17:00     INFO - GECKO(2004) | 1687443420598	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 13
[task 2023-06-22T14:17:00.626Z] 14:17:00     INFO - GECKO(2004) | 1687443420625	Marionette	DEBUG	1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2023-06-22T14:17:00.632Z] 14:17:00     INFO - GECKO(2004) | 1687443420630	Marionette	TRACE	[1] MarionetteCommands actor destroyed for window id 2
[task 2023-06-22T14:17:00.647Z] 14:17:00     INFO - GECKO(2004) | 1687443420646	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2023-06-22T14:17:00.692Z] 14:17:00     INFO - runtests.py | Waiting for browser...
[task 2023-06-22T14:17:00.705Z] 14:17:00     INFO - GECKO(2004) | 1687443420704	Marionette	DEBUG	Closed connection 1
[task 2023-06-22T14:17:01.479Z] 14:17:01     INFO - GECKO(2004) | [Parent 2004, Main Thread] WARNING: NS_ENSURE_TRUE(she && she->mInfo->mSharedState.Get()) failed: file /builds/worker/checkouts/gecko/docshell/shistory/SessionHistoryEntry.cpp:1156
[task 2023-06-22T14:17:01.666Z] 14:17:01     INFO - SimpleTest START
[task 2023-06-22T14:17:01.667Z] 14:17:01     INFO - Dumping test context:
[task 2023-06-22T14:17:01.668Z] 14:17:01     INFO -   fission.autostart=true
[task 2023-06-22T14:17:01.693Z] 14:17:01     INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html

BugBot [:suhaib / :marco/ :calixte]

Comment 1

•

2 years ago

:robwu, since you are the author of the regressor, bug 1811608, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(rob)

BugBot [:suhaib / :marco/ :calixte]

Comment 2

•

2 years ago

Set release status flags based on info from the regressing bug 1811608

status-firefox114: --- → unaffected

status-firefox115: --- → unaffected

status-firefox116: --- → affected

status-firefox-esr102: --- → unaffected

Rob Wu [:robwu]

Assignee

Comment 3

•

2 years ago

This is a pre-existing issue, due to the --compare-preferences feature enabled in TV by bug 1783248.

I checked the prefs before and at the end of the test, using the snippet at the bottom:

Pref state BEFORE {"ids":["bookmark"],"idsInUrlbar":["bookmark"],"idsInUrlbarPreProton":[],"version":1}
Pref state AFTER {"ids":["bookmark","_213e8461-4303-4379-a6bf-b1e4073f7bb1_"],"idsInUrlbar":["_213e8461-4303-4379-a6bf-b1e4073f7bb1_","bookmark"],"idsInUrlbarPreProton":[],"version":1}

This suggests that the pref value may potentially not be cleaned up. Upon inspection, the cleanup does happen:

Extension unload signals intent to remove: https://searchfox.org/mozilla-central/rev/d307d4d9f06dab6d16e963a4318e5e8ff4899141/browser/components/extensions/parent/ext-pageAction.js#176-183
PageActions.remove does not immediately reset the pref: https://searchfox.org/mozilla-central/rev/d307d4d9f06dab6d16e963a4318e5e8ff4899141/browser/modules/PageActions.sys.mjs#1071-1081
Prefs are ordinarily cleaned up upon shutdown: https://searchfox.org/mozilla-central/rev/d307d4d9f06dab6d16e963a4318e5e8ff4899141/browser/modules/PageActions.sys.mjs#65-74
- Note: even if that doesn't happen (e.g. when the browser crashed), it will happen eventually in a future browser session.

So in short, despite the pref being changed, there is no actionable issue here, and therefore I am going to add this pref to the list of prefs to ignore.

Snippet for debugging:

diff --git a/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html b/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html
index f1bf544dd94ab..d09bb875784ac 100644
--- a/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html
+++ b/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html
@@ -14,6 +14,12 @@
 "use strict";

 add_task(async function test_pageAction_onClicked_and_inputHandling() {
+  async function infopref(str) {
+    await SpecialPowers.spawnChrome([str], str => {
+      dump(`\nPref state ${str} ${Services.prefs.getStringPref("browser.pageActions.persistedActions", "(prefs not set)")}\n`);
+    });
+  }
+  await infopref("BEFORE");
   const extension = ExtensionTestUtils.loadExtension({
     manifest: {
       page_action: { show_matches: ["<all_urls>"] },
@@ -72,6 +78,7 @@ add_task(async function test_pageAction_onClicked_and_inputHandling() {
   await AppTestDelegate.closePageAction(window, extension);

   await extension.unload();
+  await infopref("AFTER");
 });

Flags: needinfo?(rob)

Keywords: regression

No longer regressed by: 1811608

Updated

•

2 years ago

See Also: → https://mozilla-hub.atlassian.net/browse/WEBEXT-1358

Rob Wu [:robwu]

Assignee

Comment 4

•

2 years ago

Attached file Bug 1839890 - Add browser.pageActions.persistedActions to ignorePrefs.json — Details

browser.pageActions.persistedActions can be updated during tests, but is
eventually cleaned up at shutdown (or later), see
https://bugzilla.mozilla.org/show_bug.cgi?id=1839890#c3

Verified with

./mach test --compare-preferences toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html

Phabricator Automation

Updated

•

2 years ago

Assignee: nobody → rob

Status: NEW → ASSIGNED

Comment hidden (Intermittent Failures Robot)

Pulsebot

Comment 6

•

2 years ago

Pushed by rob@robwu.nl: https://hg.mozilla.org/integration/autoland/rev/9f3ca0bd4811 Add browser.pageActions.persistedActions to ignorePrefs.json r=adw

Norisz Fay [:noriszfay]

Comment 7

•

2 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/9f3ca0bd4811

Status: ASSIGNED → RESOLVED

Closed: 2 years ago

status-firefox116: affected → fixed

Resolution: --- → FIXED

Target Milestone: --- → 116 Branch

Rob Wu [:robwu]

Assignee

Updated

•

1 year ago

Bugzilla

Intermittent TV /tests/toolkit/components/extensions/test/mochitest/test_ext_pageAction_onClicked.html | single tracking bug

Categories

(WebExtensions :: General, defect, P5)

Tracking

(firefox-esr102 unaffected, firefox114 unaffected, firefox115 unaffected, firefox116 fixed)

People

(Reporter: intermittent-bug-filer, Assigned: robwu)

References

Details

(Keywords: intermittent-failure, test-verify-fail, Whiteboard: [addons-jira])

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Comment 2

Comment 3

Updated

Comment 4

Updated

Comment 5

Comment 6

Comment 7

Updated

Attachment

General

Description

File Name

Content Type