Closed Bug 1692852 Opened 4 years ago Closed 2 years ago

Intermittent Fission /html/browsers/history/the-history-interface/005.html | window.onpopstate should register a listener for the popstate event - assert_true: expected true got false

Categories

(Core :: DOM: Core & HTML, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1668853
Fission Milestone Future
Tracking Status
firefox90 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

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


[task 2021-02-15T10:47:59.145Z] 10:47:59     INFO - TEST-OK | /html/browsers/history/the-history-interface/004.html | took 1175ms
[task 2021-02-15T10:47:59.146Z] 10:47:59     INFO - TEST-START | /html/browsers/history/the-history-interface/005.html
[task 2021-02-15T10:47:59.149Z] 10:47:59     INFO - Closing window 6442450967
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - 
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - TEST-PASS | /html/browsers/history/the-history-interface/005.html | history.pushState support is needed for this testcase 
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - TEST-PASS | /html/browsers/history/the-history-interface/005.html | <body onpopstate="..."> should register a listener for the popstate event 
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - TEST-UNEXPECTED-FAIL | /html/browsers/history/the-history-interface/005.html | window.onpopstate should register a listener for the popstate event - assert_true: expected true got false
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - step3/<@http://web-platform.test:8000/html/browsers/history/the-history-interface/005.html:35:16
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2092:25
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - test@http://web-platform.test:8000/resources/testharness.js:566:30
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - step3@http://web-platform.test:8000/html/browsers/history/the-history-interface/005.html:34:7
[task 2021-02-15T10:48:00.878Z] 10:48:00     INFO - TEST-OK | /html/browsers/history/the-history-interface/005.html | took 1733ms
[task 2021-02-15T10:48:00.902Z] 10:48:00     INFO - PID 9174 | 1613386080900	Marionette	INFO	Stopped listening on port 50315
[task 2021-02-15T10:48:00.953Z] 10:48:00     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
[task 2021-02-15T10:48:00.955Z] 10:48:00     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
[task 2021-02-15T10:48:00.967Z] 10:48:00     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
[task 2021-02-15T10:48:00.977Z] 10:48:00     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
[task 2021-02-15T10:48:00.978Z] 10:48:00     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
[task 2021-02-15T10:48:01.259Z] 10:48:01     INFO - PID 9174 | [Parent 9174, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:370
[task 2021-02-15T10:48:01.358Z] 10:48:01     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:01.371Z] 10:48:01     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:01.372Z] 10:48:01     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:01.421Z] 10:48:01     INFO - PID 9174 | [2021-02-15T10:48:01Z WARN  xulstore::persist] tried to remove key that isn't in the store
[task 2021-02-15T10:48:01.423Z] 10:48:01     INFO - PID 9174 | [2021-02-15T10:48:01Z WARN  xulstore::persist] tried to remove key that isn't in the store
[task 2021-02-15T10:48:01.554Z] 10:48:01     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:01.571Z] 10:48:01     INFO - PID 9174 | [Child 9412, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:01.738Z] 10:48:01     INFO - PID 9174 | [Child 9561, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:01.757Z] 10:48:01     INFO - PID 9174 | [Child 9561, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:02.196Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:02.199Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:02.201Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:02.205Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:02.205Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:02.206Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:02.243Z] 10:48:02     INFO - PID 9174 | [Child 9605, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:02.248Z] 10:48:02     INFO - PID 9174 | [Child 9720, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:02.257Z] 10:48:02     INFO - PID 9174 | [Child 9590, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:02.259Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000002s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.261Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000089s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.261Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000104s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.265Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000618s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.265Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000643s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.265Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: cache: '0.000681s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.270Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: sdb: '0.000696s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.270Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: ls: '0.000706s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.270Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000749s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.270Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.000763s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.270Z] 10:48:02     INFO - PID 9174 | [Child 9720, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:02.270Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.008672s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.272Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.008754s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.273Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.008767s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.274Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: idb: '0.009059s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.276Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: cache: '0.009126s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.276Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: sdb: '0.009137s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.277Z] 10:48:02     INFO - PID 9174 | [Parent 9174, IPDL Background] WARNING: ls: '0.009146s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3633
[task 2021-02-15T10:48:02.278Z] 10:48:02     INFO - PID 9174 | [Child 9590, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:02.279Z] 10:48:02     INFO - PID 9174 | [Child 9605, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:02.551Z] 10:48:02     INFO - PID 9174 | [Parent 9174, Main Thread] WARNING: NS_ENSURE_TRUE(mDB) failed: file /builds/worker/checkouts/gecko/netwerk/cache/nsDiskCacheDeviceSQL.cpp:1276
[task 2021-02-15T10:48:02.573Z] 10:48:02     INFO - PID 9174 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:03.912Z] 10:48:03     INFO - PID 9174 | [Parent 9174, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:03.963Z] 10:48:03     INFO - PID 9174 | [Parent 9174, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:03.983Z] 10:48:03     INFO - Browser exited with return code 0
[task 2021-02-15T10:48:03.984Z] 10:48:03     INFO - PROCESS LEAKS /tmp/tmp9nt5upng/runtests_leaks_1127.log
[task 2021-02-15T10:48:03.984Z] 10:48:03     INFO - leakcheck | Processing log file /tmp/tmp9nt5upng/runtests_leaks_1127.log for scope /html/browsers/history
[task 2021-02-15T10:48:03.984Z] 10:48:03     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 16000 bytes
[task 2021-02-15T10:48:03.985Z] 10:48:03     INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2021-02-15T10:48:03.989Z] 10:48:03     INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2021-02-15T10:48:03.989Z] 10:48:03     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 10000 bytes
[task 2021-02-15T10:48:03.989Z] 10:48:03     INFO - TEST-INFO | leakcheck | plugin process: leak threshold set at 0 bytes
[task 2021-02-15T10:48:03.989Z] 10:48:03     INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 0 bytes
[task 2021-02-15T10:48:03.989Z] 10:48:03     INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 10000 bytes
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO - leakcheck | Processing leak log file /tmp/tmp9nt5upng/runtests_leaks_1127_tab_pid9561.log
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO - 
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 9561
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO - 
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2021-02-15T10:48:03.990Z] 10:48:03     INFO -    0 |TOTAL                                 |       41        0|  386650        0|
[task 2021-02-15T10:48:03.993Z] 10:48:03     INFO - 
[task 2021-02-15T10:48:03.994Z] 10:48:03     INFO - nsTraceRefcnt::DumpStatistics: 914 entries
<...>
[task 2021-02-15T10:48:04.111Z] 10:48:04     INFO - PID 9662 | [Child 9929, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-15T10:48:04.111Z] 10:48:04     INFO - PID 9662 | 1613386075918	Marionette	INFO	Listening on port 54403
[task 2021-02-15T10:48:04.112Z] 10:48:04     INFO - Starting runner
[task 2021-02-15T10:48:04.841Z] 10:48:04     INFO - PID 9662 | [Parent 9662, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4252
[task 2021-02-15T10:48:04.842Z] 10:48:04     INFO - PID 9662 | [Parent 9662, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4252
[task 2021-02-15T10:48:05.147Z] 10:48:05     INFO - PID 9662 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:05.150Z] 10:48:05     INFO - PID 9662 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-15T10:48:05.251Z] 10:48:05     INFO - PID 9662 | [Child 9802, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-15T10:48:05.303Z] 10:48:05     INFO - PID 9662 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpnw_9o5jq/runtests_leaks_1127_tab_pid10041.log
[task 2021-02-15T10:48:05.309Z] 10:48:05     INFO - PID 9662 | [10041, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-15T10:48:05.311Z] 10:48:05     INFO - PID 9662 | [Child 9802, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-15T10:48:05.444Z] 10:48:05     INFO - PID 9662 | [Child 10041, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-15T10:48:05.543Z] 10:48:05     INFO - PID 9662 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2021-02-15T10:48:05.543Z] 10:48:05     INFO - PID 9662 | [Child 10041, 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:377
[task 2021-02-15T10:48:05.686Z] 10:48:05     INFO - TEST-START | /html/browsers/history/the-history-interface/006.html```

This WPT failure is an intermittent failure that happens on Fission debug. The failure rate is low enough that it doesn't need to block Fission MVP.

https://searchfox.org/mozilla-central/source/testing/web-platform/meta/html/browsers/history/the-history-interface/005.html.ini#7-9

  [window.onpopstate should register a listener for the popstate event]
    expected:
      if fission and debug: ["PASS", "FAIL"]
Blocks: WPT-Fis
Fission Milestone: --- → Future
Summary: Intermittent /html/browsers/history/the-history-interface/005.html | window.onpopstate should register a listener for the popstate event - assert_true: expected true got false → Intermittent Fission /html/browsers/history/the-history-interface/005.html | window.onpopstate should register a listener for the popstate event - assert_true: expected true got false

Resolving as incomplete because there have been no failures in two months.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE

Reopening this bug because this test is annotated as failing intermittently with Fission, as recently as 2021-11-09:

https://searchfox.org/mozilla-central/rev/553bf8428885dbd1eab9b63f71ef647f799372c2/testing/web-platform/meta/html/browsers/history/the-history-interface/005.html.ini#11-16

  [window.onpopstate should register a listener for the popstate event]
    bug:
      if fission and debug: https://bugzilla.mozilla.org/show_bug.cgi?id=1692852
    expected:
      if fission and (os == "win") and debug: [PASS, FAIL]
      if fission and (os == "linux"): [PASS, FAIL]
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Duplicate of bug: 1668853
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.