Closed Bug 1676986 Opened 4 years ago Closed 3 years ago

Intermittent browser_aboutprocesses_show_frames_without_threads.js | Found at least one about:blank in-process subframe - false == true - JS frame :: chrome://*/head.js :: testAboutProcessesWithConfig :: line 650

Categories

(Toolkit :: Performance Monitoring, defect, P5)

defect

Tracking

()

RESOLVED FIXED
95 Branch
Tracking Status
firefox-esr91 --- fixed
firefox95 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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


[task 2020-11-12T22:39:43.660Z] 22:39:43     INFO - TEST-START | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js
[task 2020-11-12T22:39:43.697Z] 22:39:43     INFO - GECKO(6296) | [Child 6746, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-12T22:39:43.712Z] 22:39:43     INFO - GECKO(6296) | [Child 6745, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-12T22:39:43.740Z] 22:39:43     INFO - GECKO(6296) | [Child 6746, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-12T22:39:43.756Z] 22:39:43     INFO - GECKO(6296) | [Child 6745, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-12T22:39:43.800Z] 22:39:43     INFO - GECKO(6296) | [Parent 6296, Main Thread] WARNING: Need BrowserChild to get the nativeWindow from!: file /builds/worker/checkouts/gecko/widget/PuppetWidget.cpp:1040
[task 2020-11-12T22:39:43.800Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f5b86842800 == 4 [pid = 6496] [id = 8]
[task 2020-11-12T22:39:43.800Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (0x7f5b87ff4900) [pid = 6496] [serial = 23] [outer = (nil)]
[task 2020-11-12T22:39:43.804Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (0x7f5b86843c00) [pid = 6496] [serial = 24] [outer = 0x7f5b87ff4900]
[task 2020-11-12T22:39:43.819Z] 22:39:43     INFO - GECKO(6296) | [Child 6496, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2715
[task 2020-11-12T22:39:43.843Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (0x7f5b8684a400) [pid = 6496] [serial = 25] [outer = 0x7f5b87ff4900]
[task 2020-11-12T22:39:43.884Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f5b8684c000 == 5 [pid = 6496] [id = 9]
[task 2020-11-12T22:39:43.885Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 14 (0x7f5b87ff4c80) [pid = 6496] [serial = 26] [outer = (nil)]
[task 2020-11-12T22:39:43.901Z] 22:39:43     INFO - GECKO(6296) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2KIvgZ.mozrunner/runtests_leaks_tab_pid6936.log
[task 2020-11-12T22:39:43.902Z] 22:39:43     INFO - GECKO(6296) | [6936, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-12T22:39:43.942Z] 22:39:43     INFO - GECKO(6296) | [Parent 6296: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f6608e2d000 == 9 [pid = 6296] [id = 13]
[task 2020-11-12T22:39:43.943Z] 22:39:43     INFO - GECKO(6296) | [Child 6496: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 15 (0x7f5b86845800) [pid = 6496] [serial = 27] [outer = 0x7f5b87ff4c80]
[task 2020-11-12T22:39:43.944Z] 22:39:43     INFO - GECKO(6296) | [Parent 6296: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 19 (0x7f660b788ac0) [pid = 6296] [serial = 34] [outer = (nil)]
[task 2020-11-12T22:39:43.951Z] 22:39:43     INFO - GECKO(6296) | [Parent 6296: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0x7f6608e31000) [pid = 6296] [serial = 35] [outer = 0x7f660b788ac0]
[task 2020-11-12T22:39:44.009Z] 22:39:44     INFO - GECKO(6296) | [Child 6936, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:628
[task 2020-11-12T22:39:44.065Z] 22:39:44     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f6632af0000 == 1 [pid = 6872] [id = 0]
[task 2020-11-12T22:39:44.102Z] 22:39:44     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f662c7d2040) [pid = 6872] [serial = 1] [outer = (nil)]
[task 2020-11-12T22:39:44.103Z] 22:39:44     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f662c74e800) [pid = 6872] [serial = 2] [outer = 0x7f662c7d2040]
[task 2020-11-12T22:39:44.103Z] 22:39:44     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fb6fa6f1000 == 1 [pid = 6882] [id = 0]
[task 2020-11-12T22:39:44.179Z] 22:39:44     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7fb6f43d4040) [pid = 6882] [serial = 1] [outer = (nil)]
[task 2020-11-12T22:39:44.179Z] 22:39:44     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7fb6f4350c00) [pid = 6882] [serial = 2] [outer = 0x7fb6f43d4040]
[task 2020-11-12T22:39:44.235Z] 22:39:44     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7ff14a3f1000 == 1 [pid = 6936] [id = 0]
[task 2020-11-12T22:39:44.296Z] 22:39:44     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7ff1440cf040) [pid = 6936] [serial = 1] [outer = (nil)]
[task 2020-11-12T22:39:44.304Z] 22:39:44     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7ff144049c00) [pid = 6936] [serial = 2] [outer = 0x7ff1440cf040]
[task 2020-11-12T22:39:44.320Z] 22:39:44     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fb6f43b8c00 == 2 [pid = 6882] [id = 1]
[task 2020-11-12T22:39:44.320Z] 22:39:44     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7fb6f43d4200) [pid = 6882] [serial = 3] [outer = (nil)]
[task 2020-11-12T22:39:44.320Z] 22:39:44     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7fb6fa6f5800) [pid = 6882] [serial = 4] [outer = 0x7fb6f43d4200]
[task 2020-11-12T22:39:44.396Z] 22:39:44     INFO - GECKO(6296) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2KIvgZ.mozrunner/runtests_leaks_tab_pid6959.log
[task 2020-11-12T22:39:44.396Z] 22:39:44     INFO - GECKO(6296) | [6959, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-12T22:39:44.399Z] 22:39:44     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7ff1440b1000 == 2 [pid = 6936] [id = 1]
[task 2020-11-12T22:39:44.399Z] 22:39:44     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7ff1440cf200) [pid = 6936] [serial = 3] [outer = (nil)]
[task 2020-11-12T22:39:44.399Z] 22:39:44     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7ff1440b2400) [pid = 6936] [serial = 4] [outer = 0x7ff1440cf200]
[task 2020-11-12T22:39:44.603Z] 22:39:44     INFO - GECKO(6296) | [Child 6959, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:628
[task 2020-11-12T22:39:44.663Z] 22:39:44     INFO - GECKO(6296) | [Parent 6296: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (0x7f660cdb5400) [pid = 6296] [serial = 36] [outer = 0x7f660b788ac0]
[task 2020-11-12T22:39:44.691Z] 22:39:44     INFO - GECKO(6296) | [Parent 6296, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1132
[task 2020-11-12T22:39:44.953Z] 22:39:44     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fc3c5cd7400 == 1 [pid = 6959] [id = 0]
[task 2020-11-12T22:39:45.029Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7fc3bf9cf040) [pid = 6959] [serial = 1] [outer = (nil)]
[task 2020-11-12T22:39:45.032Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7fc3bf94cc00) [pid = 6959] [serial = 2] [outer = 0x7fc3bf9cf040]
[task 2020-11-12T22:39:45.113Z] 22:39:45     INFO - GECKO(6296) | [Child 6744: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f3aa3d4a800) [pid = 6744] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-11-12T22:39:45.129Z] 22:39:45     INFO - GECKO(6296) | [Child 6744: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f3aa3dae800 == 0 [pid = 6744] [id = 1] [url = http://example.net/]
[task 2020-11-12T22:39:45.225Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fc3bf9b4800 == 2 [pid = 6959] [id = 1]
[task 2020-11-12T22:39:45.225Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7fc3bf9cf200) [pid = 6959] [serial = 3] [outer = (nil)]
[task 2020-11-12T22:39:45.225Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7fc3c5d06800) [pid = 6959] [serial = 4] [outer = 0x7fc3bf9cf200]
[task 2020-11-12T22:39:45.396Z] 22:39:45     INFO - GECKO(6296) | [Child 6872, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.396Z] 22:39:45     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f6632b60800) [pid = 6872] [serial = 3] [outer = 0x7f662c7d2040]
[task 2020-11-12T22:39:45.405Z] 22:39:45     INFO - GECKO(6296) | [Child 6882, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.405Z] 22:39:45     INFO - GECKO(6296) | [Child 6882, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.411Z] 22:39:45     INFO - GECKO(6296) | [Child 6936, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.412Z] 22:39:45     INFO - GECKO(6296) | [Child 6936, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.412Z] 22:39:45     INFO - GECKO(6296) | [Parent 6296, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:403
[task 2020-11-12T22:39:45.414Z] 22:39:45     INFO - GECKO(6296) | [Parent 6296, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:403
[task 2020-11-12T22:39:45.425Z] 22:39:45     INFO - GECKO(6296) | [Child 6959, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.425Z] 22:39:45     INFO - GECKO(6296) | [Child 6959, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-12T22:39:45.425Z] 22:39:45     INFO - GECKO(6296) | [Parent 6296, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFileChunk.cpp:403
[task 2020-11-12T22:39:45.433Z] 22:39:45     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7fb6f4453400) [pid = 6882] [serial = 5] [outer = 0x7fb6f43d4040]
[task 2020-11-12T22:39:45.442Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7fc3bfc4e800) [pid = 6959] [serial = 5] [outer = 0x7fc3bf9cf040]
[task 2020-11-12T22:39:45.462Z] 22:39:45     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7ff14a3fcc00) [pid = 6936] [serial = 5] [outer = 0x7ff1440cf040]
[task 2020-11-12T22:39:45.477Z] 22:39:45     INFO - GECKO(6296) | [Child 6959: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (0x7fc3bfc51000) [pid = 6959] [serial = 6] [outer = 0x7fc3bf9cf200]
[task 2020-11-12T22:39:45.522Z] 22:39:45     INFO - GECKO(6296) | [Child 6882: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (0x7fb6f4455400) [pid = 6882] [serial = 6] [outer = 0x7fb6f43d4200]
[task 2020-11-12T22:39:45.530Z] 22:39:45     INFO - GECKO(6296) | [Child 6936: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (0x7ff1443c8800) [pid = 6936] [serial = 6] [outer = 0x7ff1440cf200]
[task 2020-11-12T22:39:45.626Z] 22:39:45     INFO - GECKO(6296) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2KIvgZ.mozrunner/runtests_leaks_tab_pid6988.log
[task 2020-11-12T22:39:45.629Z] 22:39:45     INFO - GECKO(6296) | [6988, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-12T22:39:45.685Z] 22:39:45     INFO - GECKO(6296) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2KIvgZ.mozrunner/runtests_leaks_tab_pid6994.log
[task 2020-11-12T22:39:45.685Z] 22:39:45     INFO - GECKO(6296) | [6994, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-12T22:39:45.726Z] 22:39:45     INFO - GECKO(6296) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2KIvgZ.mozrunner/runtests_leaks_tab_pid6997.log
[task 2020-11-12T22:39:45.726Z] 22:39:45     INFO - GECKO(6296) | [6997, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-12T22:39:46.097Z] 22:39:46     INFO - GECKO(6296) | [Child 6988, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:628
[task 2020-11-12T22:39:46.173Z] 22:39:46     INFO - GECKO(6296) | [Child 6994, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:628
[task 2020-11-12T22:39:46.234Z] 22:39:46     INFO - GECKO(6296) | [Child 6997, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:628
[task 2020-11-12T22:39:46.532Z] 22:39:46     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f662c755c00 == 2 [pid = 6872] [id = 1]
[task 2020-11-12T22:39:46.535Z] 22:39:46     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7f662c7d2580) [pid = 6872] [serial = 4] [outer = (nil)]
[task 2020-11-12T22:39:46.596Z] 22:39:46     INFO - GECKO(6296) | [Child 6872: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7f662c7a8c00) [pid = 6872] [serial = 5] [outer = 0x7f662c7d2580]
[task 2020-11-12T22:39:47.529Z] 22:39:47     INFO - TEST-INFO | started process screentopng
[task 2020-11-12T22:39:47.869Z] 22:39:47     INFO - TEST-INFO | screentopng: exit 0
[task 2020-11-12T22:39:47.869Z] 22:39:47     INFO - Buffered messages logged at 22:39:43
[task 2020-11-12T22:39:47.870Z] 22:39:47     INFO - Entering test bound testShowFramesWithoutThreads
[task 2020-11-12T22:39:47.871Z] 22:39:47     INFO - Extension loaded
[task 2020-11-12T22:39:47.871Z] 22:39:47     INFO - Setting up about:processes
[task 2020-11-12T22:39:47.872Z] 22:39:47     INFO - Buffered messages logged at 22:39:44
[task 2020-11-12T22:39:47.873Z] 22:39:47     INFO - Setting up example.com
[task 2020-11-12T22:39:47.873Z] 22:39:47     INFO - Setting up tabs we intend to close
[task 2020-11-12T22:39:47.874Z] 22:39:47     INFO - Buffered messages logged at 22:39:46
[task 2020-11-12T22:39:47.875Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | {"location":{"href":"about:processes","origin":"null","protocol":"about:","host":"","hostname":"","port":"","pathname":"processes","search":"","hash":"","assign":"function assign() {\n    [native code]\n}","replace":"function replace() {\n    [native code]\n}","reload":"function reload() {\n    [native code]\n}","toString":"function toString() {\n    [native code]\n}"}} == true - 
[task 2020-11-12T22:39:47.876Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | {} == true - 
[task 2020-11-12T22:39:47.877Z] 22:39:47     INFO - Setting up fake process hang detector
[task 2020-11-12T22:39:47.878Z] 22:39:47     INFO - Buffered messages logged at 22:39:47
[task 2020-11-12T22:39:47.878Z] 22:39:47     INFO - Looking at the contents of about:processes
[task 2020-11-12T22:39:47.879Z] 22:39:47     INFO - Running sanity tests on browser
[task 2020-11-12T22:39:47.880Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | found a table row for browser - true == true - 
[task 2020-11-12T22:39:47.880Z] 22:39:47     INFO - Sanity checks: type
[task 2020-11-12T22:39:47.884Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Type browser should be one of browser - true == true - 
[task 2020-11-12T22:39:47.884Z] 22:39:47     INFO - Sanity checks: pid
[task 2020-11-12T22:39:47.885Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Checking pid 6296 - true == true - 
[task 2020-11-12T22:39:47.885Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | 6296 == 6296 - 
[task 2020-11-12T22:39:47.886Z] 22:39:47     INFO - Sanity checks: memory resident
[task 2020-11-12T22:39:47.887Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Testing memory display 414MB (+12MB) vs total 434290688, delta 12251136 - true == true - 
[task 2020-11-12T22:39:47.887Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Can we parse 414MB (+12MB) with /([0-9.,]+)(TB|GB|MB|KB|B)( \(([-+]?)([0-9.,]+)(GB|MB|KB|B)\))?/? - ["414MB (+12MB)","414","MB"," (+12MB)","+","12","MB"] != null - 
[task 2020-11-12T22:39:47.888Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Unitless total memory use is greater than 0: 414 - true == true - 
[task 2020-11-12T22:39:47.889Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Unitless total memory use is less than 1024: 414 - true == true - 
[task 2020-11-12T22:39:47.889Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The displayed approximation of the total amount of memory is reasonable: 434110464 vs 434290688 - true == true - 
[task 2020-11-12T22:39:47.890Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The total amount amount of memory is reasonable: 434110464 in [1048576, 1099511627776] - true == true - 
[task 2020-11-12T22:39:47.891Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Unitless delta memory use is in (0, 1024): 12 - true == true - 
[task 2020-11-12T22:39:47.891Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Delta unit is reasonable: MB - true == true - 
[task 2020-11-12T22:39:47.892Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Delta has the right sign: 12582912 vs 12251136 - true == true - 
[task 2020-11-12T22:39:47.892Z] 22:39:47     INFO - Sanity checks: CPU (Total)
[task 2020-11-12T22:39:47.893Z] 22:39:47     INFO - Testing CPU display 59% (31s) vs total 31100000000, slope 0.5878894828774351
[task 2020-11-12T22:39:47.895Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The displayed approximation of the slope is reasonable: 59 vs 58.788948287743516 - true == true - 
[task 2020-11-12T22:39:47.895Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Not too little: 0.59 >=? 0  - true == true - 
[task 2020-11-12T22:39:47.896Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Not too much: 0.59 <=? 1000  - true == true - 
[task 2020-11-12T22:39:47.897Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The displayed approximation of the total duration is reasonable: 31000 vs 31100 - true == true - 
[task 2020-11-12T22:39:47.897Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The total number of MS is reasonable 31100: [10, 10000000] - true == true - 
[task 2020-11-12T22:39:47.898Z] 22:39:47     INFO - In this mode, we shouldn't display any threads
[task 2020-11-12T22:39:47.899Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | In hidden threads mode, we shouldn't have any thread summary - null == null - 
[task 2020-11-12T22:39:47.907Z] 22:39:47     INFO - Testing subframes
[task 2020-11-12T22:39:47.908Z] 22:39:47     INFO - Buffered messages finished
[task 2020-11-12T22:39:47.908Z] 22:39:47     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Found at least one about:blank in-process subframe - false == true - JS frame :: chrome://mochitests/content/browser/toolkit/components/aboutprocesses/tests/browser/head.js :: testAboutProcessesWithConfig :: line 650
[task 2020-11-12T22:39:47.908Z] 22:39:47     INFO - Stack trace:
[task 2020-11-12T22:39:47.909Z] 22:39:47     INFO - chrome://mochitests/content/browser/toolkit/components/aboutprocesses/tests/browser/head.js:testAboutProcessesWithConfig:650
[task 2020-11-12T22:39:47.910Z] 22:39:47     INFO - Running sanity tests on hung
[task 2020-11-12T22:39:47.910Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | found a table row for hung - true == true - 
[task 2020-11-12T22:39:47.911Z] 22:39:47     INFO - Sanity checks: type
[task 2020-11-12T22:39:47.912Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Type webIsolated should be one of web,webIsolated - true == true - 
[task 2020-11-12T22:39:47.912Z] 22:39:47     INFO - Sanity checks: pid
[task 2020-11-12T22:39:47.914Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Checking pid 6872 - true == true - 
[task 2020-11-12T22:39:47.915Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | 6872 == 6872 - 
[task 2020-11-12T22:39:47.917Z] 22:39:47     INFO - Sanity checks: memory resident
[task 2020-11-12T22:39:47.919Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Testing memory display 20MB (+3MB) vs total 20639744, delta 3129344 - true == true - 
[task 2020-11-12T22:39:47.920Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Can we parse 20MB (+3MB) with /([0-9.,]+)(TB|GB|MB|KB|B)( \(([-+]?)([0-9.,]+)(GB|MB|KB|B)\))?/? - ["20MB (+3MB)","20","MB"," (+3MB)","+","3","MB"] != null - 
[task 2020-11-12T22:39:47.920Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Unitless total memory use is greater than 0: 20 - true == true - 
[task 2020-11-12T22:39:47.921Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Unitless total memory use is less than 1024: 20 - true == true - 
[task 2020-11-12T22:39:47.922Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The displayed approximation of the total amount of memory is reasonable: 20971520 vs 20639744 - true == true - 
[task 2020-11-12T22:39:47.925Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The total amount amount of memory is reasonable: 20971520 in [1048576, 1099511627776] - true == true - 
[task 2020-11-12T22:39:47.930Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Unitless delta memory use is in (0, 1024): 3 - true == true - 
[task 2020-11-12T22:39:47.931Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Delta unit is reasonable: MB - true == true - 
[task 2020-11-12T22:39:47.931Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Delta has the right sign: 3145728 vs 3129344 - true == true - 
[task 2020-11-12T22:39:47.932Z] 22:39:47     INFO - Sanity checks: CPU (Total)
[task 2020-11-12T22:39:47.933Z] 22:39:47     INFO - Testing CPU display 10% (560ms) vs total 560000000, slope 0.10374520286072386
[task 2020-11-12T22:39:47.934Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The displayed approximation of the slope is reasonable: 10 vs 10.374520286072386 - true == true - 
[task 2020-11-12T22:39:47.934Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Not too little: 0.1 >=? 0  - true == true - 
[task 2020-11-12T22:39:47.935Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Not too much: 0.1 <=? 1000  - true == true - 
[task 2020-11-12T22:39:47.936Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The displayed approximation of the total duration is reasonable: 560 vs 560 - true == true - 
[task 2020-11-12T22:39:47.936Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | The total number of MS is reasonable 560: [10, 10000000] - true == true - 
[task 2020-11-12T22:39:47.937Z] 22:39:47     INFO - In this mode, we shouldn't display any threads
[task 2020-11-12T22:39:47.938Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | In hidden threads mode, we shouldn't have any thread summary - null == null - 
[task 2020-11-12T22:39:47.939Z] 22:39:47     INFO - Testing subframes
[task 2020-11-12T22:39:47.939Z] 22:39:47     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-12T22:39:47.940Z] 22:39:47     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Found at least one about:blank in-process subframe - false == true - JS frame :: chrome://mochitests/content/browser/toolkit/components/aboutprocesses/tests/browser/head.js :: testAboutProcessesWithConfig :: line 650
[task 2020-11-12T22:39:47.941Z] 22:39:47     INFO - Stack trace:
[task 2020-11-12T22:39:47.942Z] 22:39:47     INFO - chrome://mochitests/content/browser/toolkit/components/aboutprocesses/tests/browser/head.js:testAboutProcessesWithConfig:650
[task 2020-11-12T22:39:47.942Z] 22:39:47     INFO - Running sanity tests on non-hung
[task 2020-11-12T22:39:47.943Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | found a table row for non-hung - true == true - 
[task 2020-11-12T22:39:47.944Z] 22:39:47     INFO - Sanity checks: type
[task 2020-11-12T22:39:47.945Z] 22:39:47     INFO - TEST-PASS | toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js | Type web should be one of web,webIsolated - true == true - 
[task 2020-11-12T22:39:47.945Z] 22:39:47     INFO - Sanity checks: pid
...
...
...```
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE

I can reproduce at least half the time on my local mac opt build using: MOZ_CHAOSMODE=0xfb ./mach test toolkit/components/aboutprocesses/tests/browser/browser_aboutprocesses_show_frames_without_threads.js --run-until-failure --headless --profiler

Here's a profile of the test first passing and then failing: https://share.firefox.dev/3FFFIEV

I think there's 2 issues:

  1. we don't wait for the load of the about:blank subframe (that was already fixed in the above profile)
  2. sometimes the first update of about:processes happened before the about:blank load finished, because we await both loading about:processes and loading the other tabs in parallel. Moving the code checking the subframes after the next forced update of about:processes fixes that.

With both of those things fixed, I can no longer reproduce.

Assignee: nobody → florian
Status: REOPENED → ASSIGNED
See Also: → 1671819
Pushed by fqueze@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7c046349158b
Ensure the about:blank subframe is loaded before browser_aboutprocesses_show_frames_without_threads.js verifies it's displayed in about:processes, r=dthayer.
Status: ASSIGNED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 95 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: