Closed Bug 1717917 Opened 3 months ago Closed 28 days ago

Intermittent windows7-32-qr browser/components/preferences/tests/<test> | application terminated with exit code 1 | application crashed [@ mozalloc_handle_oom(unsigned int)/moz_xmalloc(unsigned int)]

Categories

(Firefox :: Preferences, defect, P3)

defect

Tracking

()

RESOLVED FIXED
93 Branch
Tracking Status
firefox93 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, perf-alert, Whiteboard: [stockwell unknown])

Crash Data

Attachments

(2 files)

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


INFO - TEST-PASS | browser/components/preferences/tests/browser_subdialogs.js | stack children count should decrease by 1 - 1 == 1 - 
[task 2021-06-23T19:04:16.846Z] 19:04:16     INFO - Leaving test bound window_close_on_dialog
[task 2021-06-23T19:04:16.847Z] 19:04:16     INFO - Entering test bound click_close_button_on_dialog
[task 2021-06-23T19:04:16.847Z] 19:04:16     INFO - waiting for subdialog DOMFrameContentLoaded
[task 2021-06-23T19:04:16.848Z] 19:04:16     INFO - Buffered messages finished
[task 2021-06-23T19:04:16.848Z] 19:04:16    ERROR - TEST-UNEXPECTED-FAIL | browser/components/preferences/tests/browser_subdialogs.js | application terminated with exit code 1
[task 2021-06-23T19:04:16.849Z] 19:04:16     INFO - runtests.py | Application ran for: 0:03:45.676565
[task 2021-06-23T19:04:16.849Z] 19:04:16     INFO - zombiecheck | Reading PID log: C:\Users\task_1624473431\AppData\Local\Temp\tmpn7ifbhfjpidlog
[task 2021-06-23T19:04:16.850Z] 19:04:16     INFO - ==> process 5292 launched child process 4976 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.0.428842888\1367658354" -childID 1 -isForBrowser -prefsHandle 2368 -prefMapHandle 2356 -prefsLen 1 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 2412 96ba80 tab)
[task 2021-06-23T19:04:16.852Z] 19:04:16     INFO - ==> process 5292 launched child process 5840 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.1.1434539041\1318236561" -childID 2 -isForBrowser -prefsHandle 2708 -prefMapHandle 2704 -prefsLen 184 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 2720 1a585300 tab)
[task 2021-06-23T19:04:16.853Z] 19:04:16     INFO - ==> process 5292 launched child process 3932 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.2.661063438\1438741" -childID 3 -isForBrowser -prefsHandle 2708 -prefMapHandle 2748 -prefsLen 224 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 2848 1a585800 tab)
[task 2021-06-23T19:04:16.854Z] 19:04:16     INFO - ==> process 5292 launched child process 3492 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.3.1340913635\590761014" -parentBuildID 20210623155053 -prefsHandle 3128 -prefMapHandle 3124 -prefsLen 1349 -prefMapSize 250863 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 3140 166409b0 rdd)
[task 2021-06-23T19:04:16.855Z] 19:04:16     INFO - ==> process 5292 launched child process 3792 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.5.536595020\1804624331" -childID 4 -isForBrowser -prefsHandle 3676 -prefMapHandle 3680 -prefsLen 8835 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 3628 2686de00 tab)
[task 2021-06-23T19:04:16.856Z] 19:04:16     INFO - ==> process 5292 launched child process 2084 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.6.14733385\1496497826" -childID 5 -isForBrowser -prefsHandle 3900 -prefMapHandle 3888 -prefsLen 8931 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 3912 1a585440 tab)
[task 2021-06-23T19:04:16.857Z] 19:04:16     INFO - ==> process 5292 launched child process 5940 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.7.2126521836\1860023601" -childID 6 -isForBrowser -prefsHandle 4424 -prefMapHandle 4440 -prefsLen 9368 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 4188 1c8c1dc0 tab)
[task 2021-06-23T19:04:16.858Z] 19:04:16     INFO - ==> process 5292 launched child process 3236 ("Z:\task_1624473431\build\application\firefox\firefox.exe" -contentproc --channel="5292.8.1059305822\528964618" -childID 7 -isForBrowser -prefsHandle 4468 -prefMapHandle 4472 -prefsLen 9368 -prefMapSize 250863 -jsInit 968 285640 -parentBuildID 20210623155053 -appdir "Z:\task_1624473431\build\application\firefox\browser" - 5292 "\\.\pipe\gecko-crash-server-pipe.5292" 4484 2686c280 tab)
[task 2021-06-23T19:04:16.859Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 3492
[task 2021-06-23T19:04:16.859Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 2084
[task 2021-06-23T19:04:16.860Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 3236
[task 2021-06-23T19:04:16.860Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 4976
[task 2021-06-23T19:04:16.861Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 3792
[task 2021-06-23T19:04:16.861Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 5840
[task 2021-06-23T19:04:16.862Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 5940
[task 2021-06-23T19:04:16.862Z] 19:04:16     INFO - zombiecheck | Checking for orphan process with PID: 3932
[task 2021-06-23T19:04:16.863Z] 19:04:16     INFO - mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/DSFjdKncQSSKRLQZjpzZVw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-06-23T19:04:24.052Z] 19:04:24     INFO - mozcrash Copy/paste: Z:/task_1624473431/fetches\minidump_stackwalk\minidump_stackwalk.exe C:\Users\task_1624473431\AppData\Local\Temp\tmpon7rupf9.mozrunner\minidumps\120f8955-2a97-4eaa-b7db-0172aca0c8b0.dmp C:\Users\task_1624473431\AppData\Local\Temp\tmpwmg6l6z6
[task 2021-06-23T19:04:46.427Z] 19:04:46     INFO - mozcrash Saved minidump as Z:\task_1624473431\build\blobber_upload_dir\120f8955-2a97-4eaa-b7db-0172aca0c8b0.dmp
[task 2021-06-23T19:04:46.433Z] 19:04:46     INFO - mozcrash Saved app info as Z:\task_1624473431\build\blobber_upload_dir\120f8955-2a97-4eaa-b7db-0172aca0c8b0.extra
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - PROCESS-CRASH | browser/components/preferences/tests/browser_subdialogs.js | application crashed [@ mozalloc_handle_oom(unsigned int)]
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - Mozilla crash reason: MOZ_CRASH()
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - Crash dump filename: C:\Users\task_1624473431\AppData\Local\Temp\tmpon7rupf9.mozrunner\minidumps\120f8955-2a97-4eaa-b7db-0172aca0c8b0.dmp
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - Operating system: Windows NT
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO -                   6.1.7601 Service Pack 1
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - CPU: x86
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO -      GenuineIntel family 6 model 63 stepping 2
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO -      8 CPUs
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - 
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - GPU: UNKNOWN
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - 
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - Crash reason:  EXCEPTION_BREAKPOINT
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - Crash address: 0x6ada2ecc
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - Process uptime: 225 seconds
[task 2021-06-23T19:04:46.771Z] 19:04:46     INFO - 
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO - Thread 0 (crashed)
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -  0  mozglue.dll!mozalloc_abort(char const* const) [mozalloc_abort.cpp:ff8225deba22d2d84d8678851a5589b75845634c : 33 + 0x0]
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     eip = 0x6ada2ecc   esp = 0x001dc888   ebp = 0x001dc890   ebx = 0x00100000
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     esi = 0x001dc89c   edi = 0x6a91f9b0   eax = 0x0000000a   ecx = 0x6a927af0
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     edx = 0x00000000   efl = 0x00000206
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     Found by: given as instruction pointer in context
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -  1  mozglue.dll!mozalloc_handle_oom(unsigned int) [mozalloc_oom.cpp:ff8225deba22d2d84d8678851a5589b75845634c : 51 + 0x9]
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     eip = 0x6ada3002   esp = 0x001dc898   ebp = 0x001dc8d0   esi = 0x00c00000
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     edi = 0x00080000
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -  2  mozglue.dll!moz_xmalloc(unsigned int) [mozalloc.cpp:ff8225deba22d2d84d8678851a5589b75845634c : 54 + 0x6]
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     eip = 0x6ada2fb1   esp = 0x001dc8d8   ebp = 0x001dc8e0
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -  3  xul.dll + 0x56188
[task 2021-06-23T19:04:46.772Z] 19:04:46     INFO -     eip = 0x57076188   esp = 0x001dc8e8   ebp = 0x001dc91c   esi = 0x00400000
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -  4  xul.dll + 0x5600c
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     eip = 0x5707600c   esp = 0x001dc924   ebp = 0x001dc948
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -  5  xul.dll + 0x4e34c
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     eip = 0x5706e34c   esp = 0x001dc950   ebp = 0x001dc9a8
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -  6  xul.dll + 0x51084
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     eip = 0x57071084   esp = 0x001dc9b0   ebp = 0x001dc9cc
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -  7  xul.dll + 0x19773f6
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     eip = 0x589973f6   esp = 0x001dc9d4   ebp = 0x001dc9f8
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -  8  xul.dll + 0xec7cff
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     eip = 0x57ee7cff   esp = 0x001dca00   ebp = 0x001dcb8c
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -  9  xul.dll + 0x157b940
[task 2021-06-23T19:04:46.773Z] 19:04:46     INFO -     eip = 0x5859b940   esp = 0x001dcb94   ebp = 0x001dccb8
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO - 10  xul.dll + 0x17214e4
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     eip = 0x587414e4   esp = 0x001dccc0   ebp = 0x001dcd20
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO - 11  xul.dll + 0x35f3527
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     eip = 0x5a613527   esp = 0x001dcd28   ebp = 0x001dcd78
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO - 12  xul.dll + 0x35ee09e
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     eip = 0x5a60e09e   esp = 0x001dcd80   ebp = 0x001dd0c8
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO - 13  xul.dll + 0x35e6603
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     eip = 0x5a606603   esp = 0x001dd0d0   ebp = 0x001dd148
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO - 14  xul.dll + 0x35f466a
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     eip = 0x5a61466a   esp = 0x001dd150   ebp = 0x001dd1a0
[task 2021-06-23T19:04:46.774Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO - 15  xul.dll + 0x35f473a
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     eip = 0x5a61473a   esp = 0x001dd1a8   ebp = 0x001dd1c8
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO - 16  xul.dll + 0x36aabd1
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     eip = 0x5a6cabd1   esp = 0x001dd1d0   ebp = 0x001dd1ec
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO - 17  xul.dll + 0x36aad75
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     eip = 0x5a6cad75   esp = 0x001dd1f4   ebp = 0x001dd224
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO - 18  xul.dll + 0x8bab67
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     eip = 0x578dab67   esp = 0x001dd22c   ebp = 0x001dd564
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO - 19  xul.dll + 0x8ba2dc
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     eip = 0x578da2dc   esp = 0x001dd56c   ebp = 0x001dd5ac
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.775Z] 19:04:46     INFO - 20  xul.dll + 0x4daf517
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     eip = 0x5bdcf517   esp = 0x001dd5b4   ebp = 0x001dd5d8
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO - 21  xul.dll + 0x8f0c4e
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     eip = 0x57910c4e   esp = 0x001dd5e0   ebp = 0x001dd78c
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO - 22  xul.dll + 0x8f1d5d
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     eip = 0x57911d5d   esp = 0x001dd794   ebp = 0x001dd820
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO - 23  xul.dll + 0x35f3527
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     eip = 0x5a613527   esp = 0x001dd828   ebp = 0x001dd878
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO - 24  xul.dll + 0x35ee09e
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     eip = 0x5a60e09e   esp = 0x001dd880   ebp = 0x001ddbc8
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.776Z] 19:04:46     INFO - 25  xul.dll + 0x35e6603
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     eip = 0x5a606603   esp = 0x001ddbd0   ebp = 0x001ddc48
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO - 26  xul.dll + 0x35f466a
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     eip = 0x5a61466a   esp = 0x001ddc50   ebp = 0x001ddca0
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO - 27  xul.dll + 0x35f473a
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     eip = 0x5a61473a   esp = 0x001ddca8   ebp = 0x001ddcc8
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO - 28  xul.dll + 0x36aabd1
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     eip = 0x5a6cabd1   esp = 0x001ddcd0   ebp = 0x001ddcec
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO - 29  xul.dll + 0x36aad75
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     eip = 0x5a6cad75   esp = 0x001ddcf4   ebp = 0x001ddd24
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO - 30  xul.dll + 0x8bab67
[task 2021-06-23T19:04:46.777Z] 19:04:46     INFO -     eip = 0x578dab67   esp = 0x001ddd2c   ebp = 0x001de064
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO - 31  xul.dll + 0x8ba2dc
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     eip = 0x578da2dc   esp = 0x001de06c   ebp = 0x001de0ac
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO - 32  xul.dll + 0x4daf517
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     eip = 0x5bdcf517   esp = 0x001de0b4   ebp = 0x001de0d8
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO - 33  xul.dll + 0x8f0c4e
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     eip = 0x57910c4e   esp = 0x001de0e0   ebp = 0x001de28c
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO - 34  xul.dll + 0x8f1d5d
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     eip = 0x57911d5d   esp = 0x001de294   ebp = 0x001de320
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO - 35  0x308e17c8
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     eip = 0x308e17c8   esp = 0x001de328   ebp = 0xffffff82
[task 2021-06-23T19:04:46.778Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO - 36  xul.dll + 0x463d651
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     eip = 0x5b65d651   esp = 0x001de3c8   ebp = 0x001de4c0
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     Found by: stack scanning
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO - 37  xul.dll + 0x35e65d9
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     eip = 0x5a6065d9   esp = 0x001de4c8   ebp = 0x001de548
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO - 38  xul.dll + 0x35f3701
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     eip = 0x5a613701   esp = 0x001de550   ebp = 0x001de59c
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO - 39  xul.dll + 0x35f3d50
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     eip = 0x5a613d50   esp = 0x001de5a4   ebp = 0x001de5c0
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO - 40  xul.dll + 0x364c398
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     eip = 0x5a66c398   esp = 0x001de5c8   ebp = 0x001de684
[task 2021-06-23T19:04:46.779Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO - 41  xul.dll + 0x8ecfbc
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     eip = 0x5790cfbc   esp = 0x001de68c   ebp = 0x001de908
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO - 42  xul.dll + 0x1038f3
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     eip = 0x571238f3   esp = 0x001de910   ebp = 0x001de9b4
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO - 43  xul.dll + 0x102856
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     eip = 0x57122856   esp = 0x001de9bc   ebp = 0x001de9d0
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO - 44  xul.dll + 0x89111
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     eip = 0x570a9111   esp = 0x001de9d8   ebp = 0x001de9fc
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO - 45  xul.dll + 0x8d89f
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     eip = 0x570ad89f   esp = 0x001dea04   ebp = 0x001deb38
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO - 46  xul.dll + 0xfb4486
[task 2021-06-23T19:04:46.780Z] 19:04:46     INFO -     eip = 0x57fd4486   esp = 0x001deb40   ebp = 0x001deb68
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO - 47  xul.dll + 0xa093ae
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     eip = 0x57a293ae   esp = 0x001deb70   ebp = 0x001deb74
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO - 48  xul.dll + 0xe4b2cd
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     eip = 0x57e6b2cd   esp = 0x001deb7c   ebp = 0x001dec04
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO - 49  xul.dll + 0xe4b32f
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     eip = 0x57e6b32f   esp = 0x001dec0c   ebp = 0x001dec1c
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO - 50  xul.dll + 0x1f5d96e
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     eip = 0x58f7d96e   esp = 0x001dec24   ebp = 0x001deca8
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO - 51  xul.dll + 0x1f5d792
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     eip = 0x58f7d792   esp = 0x001decb0   ebp = 0x001dece4
[task 2021-06-23T19:04:46.781Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO - 52  xul.dll + 0x9ae1ad
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     eip = 0x579ce1ad   esp = 0x001decec   ebp = 0x001decfc
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO - 53  xul.dll + 0x971b6f
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     eip = 0x57991b6f   esp = 0x001ded04   ebp = 0x001ded1c
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO - 54  xul.dll + 0x5321e2
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     eip = 0x575521e2   esp = 0x001ded24   ebp = 0x001ded3c
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO - 55  xul.dll + 0x493c7c
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     eip = 0x574b3c7c   esp = 0x001ded44   ebp = 0x001ded5c
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO - 56  xul.dll + 0x971b6f
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     eip = 0x57991b6f   esp = 0x001ded64   ebp = 0x001ded7c
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.782Z] 19:04:46     INFO - 57  xul.dll + 0x1af2e7
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     eip = 0x571cf2e7   esp = 0x001ded84   ebp = 0x001deda4
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO - 58  xul.dll + 0x1c23ef
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     eip = 0x571e23ef   esp = 0x001dedac   ebp = 0x001dedd4
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO - 59  xul.dll + 0x1c1c4e
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     eip = 0x571e1c4e   esp = 0x001deddc   ebp = 0x001dedf8
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO - 60  xul.dll + 0xbf216
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     eip = 0x570df216   esp = 0x001dee00   ebp = 0x001dee14
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO - 61  xul.dll + 0xf4e40
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     eip = 0x57114e40   esp = 0x001dee1c   ebp = 0x001df268
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO - 62  xul.dll + 0xe314b
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     eip = 0x5710314b   esp = 0x001df270   ebp = 0x001df51c
[task 2021-06-23T19:04:46.783Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO - 63  xul.dll + 0xe1f31
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     eip = 0x57101f31   esp = 0x001df524   ebp = 0x001df56c
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO - 64  xul.dll + 0xe2179
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     eip = 0x57102179   esp = 0x001df574   ebp = 0x001df598
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO - 65  xul.dll + 0xf76c0
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     eip = 0x571176c0   esp = 0x001df5a0   ebp = 0x001df5a4
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO - 66  xul.dll + 0xec8f9
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     eip = 0x5710c8f9   esp = 0x001df5ac   ebp = 0x001df6d8
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO - 67  xul.dll + 0xf0c1f
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     eip = 0x57110c1f   esp = 0x001df6e0   ebp = 0x001df6fc
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.784Z] 19:04:46     INFO - 68  xul.dll + 0x5ee2d1
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     eip = 0x5760e2d1   esp = 0x001df704   ebp = 0x001df72c
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO - 69  xul.dll + 0x5b25b9
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     eip = 0x575d25b9   esp = 0x001df734   ebp = 0x001df764
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO - 70  xul.dll + 0x5b2518
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     eip = 0x575d2518   esp = 0x001df76c   ebp = 0x001df784
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO - 71  xul.dll + 0x22aa125
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     eip = 0x592ca125   esp = 0x001df78c   ebp = 0x001df794
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO - 72  xul.dll + 0x2324579
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     eip = 0x59344579   esp = 0x001df79c   ebp = 0x001df8d0
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO - 73  xul.dll + 0x34829de
[task 2021-06-23T19:04:46.785Z] 19:04:46     INFO -     eip = 0x5a4a29de   esp = 0x001df8d8   ebp = 0x001df8ec
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO - 74  xul.dll + 0x3538a14
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     eip = 0x5a558a14   esp = 0x001df8f4   ebp = 0x001dfb84
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO - 75  xul.dll + 0x3539dcd
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     eip = 0x5a559dcd   esp = 0x001dfb8c   ebp = 0x001dfbdc
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO - 76  xul.dll + 0x353a0a5
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     eip = 0x5a55a0a5   esp = 0x001dfbe4   ebp = 0x001dfcb8
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO - 77  xul.dll + 0x35493d1
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     eip = 0x5a5693d1   esp = 0x001dfcc0   ebp = 0x001dfccc
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO - 78  firefox.exe!NS_internal_main(int, char**, char**) [nsBrowserApp.cpp:ff8225deba22d2d84d8678851a5589b75845634c : 378 + 0xf9]
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     eip = 0x013516e8   esp = 0x001dfcd4   ebp = 0x001dfe50
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO -     Found by: previous frame's frame pointer
[task 2021-06-23T19:04:46.786Z] 19:04:46     INFO - 79  firefox.exe!wmain(int, wchar_t**) [nsWindowsWMain.cpp:ff8225deba22d2d84d8678851a5589b75845634c : 131 + 0x11]
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     eip = 0x013511c3   esp = 0x001dfe58   ebp = 0x001dfe84   ebx = 0x003ffad8
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     esi = 0x009020c0   edi = 0x009020a0
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO - 80  firefox.exe!__scrt_common_main_seh() [exe_common.inl : 288 + 0x1c]
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     eip = 0x0139facc   esp = 0x001dfe8c   ebp = 0x001dfecc   ebx = 0x7ffda000
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     esi = 0x6a9ff0b0   edi = 0x003ffad8
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO - 81  kernel32.dll!void __thiscall CBandSite::_DeleteAllBandItems + 0x3a
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     eip = 0x7726ef3c   esp = 0x001dfed4   ebp = 0x001dfed8
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO - 82  ntdll.dll!GetTreeIndexFromLeafIndexAndCollection + 0x8d
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     eip = 0x77603618   esp = 0x001dfee0   ebp = 0x001dfed8
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO -     Found by: call frame info
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO - 
[task 2021-06-23T19:04:46.787Z] 19:04:46     INFO - Thread 1

Jaws, this has started appearing frequently on windows7-32-shippable-qr with these two signatures,
could you please take a look?

Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)]
Summary: Intermittent browser/components/preferences/tests/browser_subdialogs.js | application terminated with exit code 1 | application crashed [@ mozalloc_handle_oom(unsigned int)] → Intermittent windows7-32-shippable-qr browser/components/preferences/tests/<test> | application terminated with exit code 1 | application crashed [@ mozalloc_handle_oom(unsigned int)/moz_xmalloc(unsigned int)]
Duplicate of this bug: 1718273
Duplicate of this bug: 1718077
Duplicate of this bug: 1718254
See Also: → 1718179
See Also: → 1719324
See Also: → 1718978
Duplicate of this bug: 1723347
Duplicate of this bug: 1723406
Duplicate of this bug: 1718976
Duplicate of this bug: 1721479
Duplicate of this bug: 1723512

Between this and all the dupes this is probably failing 40-50 times a week so we should figure out what's happening here.

Priority: P5 → --

From bug 1719324:

(In reply to Gabriele Svelto [:gsvelto] from comment #6)

Yes, this is an OOM crash where the xul.dll library was unloaded (hence the useless stack). Specifically the allocation that failed was ~300KiB in size and it failed because we most likely ran out of address space; there was only ~172MiB left of it and it was probably heavily fragmented at that point. Given this is a 32-bit build it's likely that the process was pushing the boundaries of what we can do in the 2GiB of available address space.

Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7]
Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e]

Maybe we could profile these tests with the nativeallocations feature enabled to see where they are allocating (or retaining) memory.

That would be something like: MOZ_PROFILER_STARTUP_FEATURES=js,stackwalk,cpu,nativeallocations MOZ_PROFILER_STARTUP_ENTRIES=1000000000 ./mach test browser/components/preferences/tests/ --profiler

1000000000 is an arbitrary large value, the actual maximum buffer size is 2GB, which is probably not enough to profile the entire folder, so you might want to stop the run at some point (just quit the browser)

Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e]
Flags: needinfo?(gijskruitbosch+bugs)
Priority: -- → P3
Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028]
Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028] [@ xul.dll + 0x38d8aa0]
Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028] [@ xul.dll + 0x38d8aa0] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028] [@ xul.dll + 0x38d8aa0] [@ xul.dll + 0x83e6a]
See Also: → 1723672
See Also: → 1723701
Duplicate of this bug: 1723672
Crash Signature: [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028] [@ xul.dll + 0x38d8aa0] [@ xul.dll + 0x83e6a] → [@ moz_xmalloc(unsigned int)], [@ mozalloc_handle_oom(unsigned int)] [@ xul.dll + 0x19666a7] [@ xul.dll + 0x2530c7e] [@ xul.dll + 0x12f028] [@ xul.dll + 0x38d8aa0] [@ xul.dll + 0x83e6a]
Summary: Intermittent windows7-32-shippable-qr browser/components/preferences/tests/<test> | application terminated with exit code 1 | application crashed [@ mozalloc_handle_oom(unsigned int)/moz_xmalloc(unsigned int)] → Intermittent windows7-32-qr browser/components/preferences/tests/<test> | application terminated with exit code 1 | application crashed [@ mozalloc_handle_oom(unsigned int)/moz_xmalloc(unsigned int)]
Duplicate of this bug: 1723701

(In reply to Florian Quèze [:florian] (PTO until Aug 23) from comment #18)

Maybe we could profile these tests with the nativeallocations feature enabled to see where they are allocating (or retaining) memory.

That would be something like: MOZ_PROFILER_STARTUP_FEATURES=js,stackwalk,cpu,nativeallocations MOZ_PROFILER_STARTUP_ENTRIES=1000000000 ./mach test browser/components/preferences/tests/ --profiler

1000000000 is an arbitrary large value, the actual maximum buffer size is 2GB, which is probably not enough to profile the entire folder, so you might want to stop the run at some point (just quit the browser)

First of all, we really want browser.ini added to the path, or it runs the main dir and the siteData subdirectory separately which messes things up.

Still, this doesn't appear to work for me. In some cases the browser crashes, in other cases the profile doesn't symbolicate. I've now tried about 10 times, quitting the browser initially not at all (caused crashes), then after 1 minute, then progressively shorter intervals. Still, the symbolication issue doesn't go away:

profiler ERROR Encountered an exception during profile symbolication
profiler ERROR 'charmap' codec can't decode byte 0x9d in position 116223574: character maps to <undefined>

which means the results are not very useful: https://share.firefox.dev/3xtAZAV

As far as I can tell, the memory track thinks the main process retained about 400mb of memory. Which is weird, because the retained memory data source only tracks about 200mb of memory, so I don't understand where the other half is.

Of the 200mb, when looking at the JS view because the C++ symbols are useless, the biggest culprit (some 75mb) is AsyncShutdown - which is pretty confusing because presumably that's all from me manually quitting the browser, which wouldn't happen if the tests just completed. Of everything else, if I invert call trees, I see a few mb for different DOM and JS APIs, but nothing really jumps out - not to the point where we should be stuck for memory. This despite the fact that the commandline output does indicate memory use grows significantly while running the tests, from:

 0:15.10 GECKO(15984) MEMORY STAT | vsize 2104582MB | vsizeMaxContiguous 65537938MB | residentFast 496MB | heapAllocated 332MB

after the first one to:

 0:41.06 GECKO(15984) MEMORY STAT | vsize 2106082MB | vsizeMaxContiguous 65537938MB | residentFast 1354MB | heapAllocated 1112MB

right before quitting.

The final thing that is odd is that I would expect that any DOM/JS stuff inside about:preferences gets cleared out by GCs, but on the retained memory event source, if I select some of the methods listed as having retained memory, it highlights things on the timeline from very early in the run, which (assuming the highlighting is accurate in terms of which calls to these functions/methods allocated the retained memory) suggests we haven't deallocated the relevant DOM/JS bits yet, which I find surprising. But I don't know how to get any more information about why that is from the profile or the tests.

Florian is out for the next 2 weeks; :mccr8, or gerald, do you think you might be in a position to help here?

I suspect fixing bug 1533771 may help here, but that also feels like it might wallpaper the "real" issues here.

Flags: needinfo?(gsquelart)
Flags: needinfo?(gijskruitbosch+bugs)
Flags: needinfo?(continuation)

Looking at the MEMORY STAT values that continue as the directory runs, it starts out around 223MB of heapAllocated. As the tests go on, this changes by anywhere from -50MB to 30MB. It isn't climbing up monotonically, but it is definitely more up than down.

I can take a look. I'm going to log all CCs, then look in later logs for anything that seems like it is from an earlier test, likely through the advanced technique of grepping for the name of the test.

Flags: needinfo?(continuation)

Ok, looking for a test name didn't help much.

Next, I ran my census.py script on the GC logs, comparing an early log to a late log (where the size of the later log dropped a bunch compared to the previous one, so hopefully there's no as much garbage in it. The most common script, chrome://browser/content/preferences/main.js, had around 4300 instances in the early log (4), and about 11,800 in the later log (41).

I then grepped the logs for these scripts, filtered by whether they are black (B) which means they are currently active, or grey (G) which means they are only being held alive via C++.

The number of "active" scripts is about the same:

> grep "B script chrome://browser/content/preferences/main.js" gc-edges.6171-4.log | wc
    2145    8580  157954
> grep "B script chrome://browser/content/preferences/main.js" gc-edges.6171-41.log | wc
    2852   11408  209449

But the number of "inactive" scripts has really increased:

> grep "G script chrome://browser/content/preferences/main.js" gc-edges.6171-4.log | wc 
    1443    5772  106122
> grep "G script chrome://browser/content/preferences/main.js" gc-edges.6171-41.log | wc
    8596   34384  631731

There's also a large increase in the number of copies of functions named MozButtonBase/< chrome://global/content/elements/button.js (from about 4800 to 12000) and about a doubling in the number of copies of functions named MozCheckbox/< chrome://global/content/elements/checkbox.js.

I'll see if I can figure out what is holding alive the grey main.js scripts.

It does look like the grey scripts are periodically being cleaned up completely. I guess I need to figure out what changed to make it so we cleaned them up. I just looked at a chain of about 12 logs where the number of main.js scripts creeped up from about 3200 to 5600, then dropped to 357.

(In reply to :Gijs (he/him) from comment #22)

Still, this doesn't appear to work for me. In some cases the browser crashes, in other cases the profile doesn't symbolicate. I've now tried about 10 times, quitting the browser initially not at all (caused crashes), then after 1 minute, then progressively shorter intervals. Still, the symbolication issue doesn't go away:

profiler ERROR Encountered an exception during profile symbolication
profiler ERROR 'charmap' codec can't decode byte 0x9d in position 116223574: character maps to <undefined>

which means the results are not very useful: https://share.firefox.dev/3xtAZAV

One quick trick you could try: Add MOZ_PROFILER_SYMBOLICATE=1 to your command line, it does symbolication a different way, directly inside Firefox -- note that will freeze Firefox for a few (lots of) seconds when you capture/quit.

NI -> Markus, who knows more/everything about profiler symbolication.

(And I can't give useful advice regarding the memory issue being investigated. Good luck!)

Flags: needinfo?(gsquelart) → needinfo?(mstange.moz)

(In reply to :Gijs (he/him) from comment #22)

profiler ERROR Encountered an exception during profile symbolication
profiler ERROR 'charmap' codec can't decode byte 0x9d in position 116223574: character maps to <undefined>

This error probably comes from the python scripts that try to do the symbolication. I'm not very familiar with those.

Gijs, as a workaround, you could try to do the following:

cargo install profiler-symbol-server
profiler-symbol-server yourprofile.json

And then maybe you'll need to go to the Profile Info panel and forcefully re-trigger symbolication, if it doesn't happen automatically.

Flags: needinfo?(mstange.moz)

(In reply to :Gijs (he/him) from comment #22)

As far as I can tell, the memory track thinks the main process retained about 400mb of memory. Which is weird, because the retained memory data source only tracks about 200mb of memory, so I don't understand where the other half is.

Indeed, this looks odd. It's suspicious that it's exactly half.

Of everything else, if I invert call trees, I see a few mb for different DOM and JS APIs, but nothing really jumps out

Nothing jumps out in the memory track, either - there are no big steps.

This despite the fact that the commandline output does indicate memory use grows significantly while running the tests, from:

 0:15.10 GECKO(15984) MEMORY STAT | vsize 2104582MB | vsizeMaxContiguous 65537938MB | residentFast 496MB | heapAllocated 332MB

after the first one to:

 0:41.06 GECKO(15984) MEMORY STAT | vsize 2106082MB | vsizeMaxContiguous 65537938MB | residentFast 1354MB | heapAllocated 1112MB

right before quitting.

That's a much larger increase that what the memory track shows, which only goes to 400MB of explicit allocations. Weird.

(assuming the highlighting is accurate in terms of which calls to these functions/methods allocated the retained memory)

I think it's accurate in the sense that it shows where the same stacks were observed, as the ones that allocated memory. But it doesn't mean that the stack allocated a lot of memory in the highlighted places, just that the same stacks ran at those times. I guess it would be useful to be able to select a stack and then see a graph of when most of that stack's retained memory was allocated.

Thanks Markus and Gerald for the profiler tips. I'm going to re-add the needinfo for reasons that will become apparent shortly...

(In reply to Gerald Squelart [:gerald] (he/him) from comment #26)

One quick trick you could try: Add MOZ_PROFILER_SYMBOLICATE=1 to your command line, it does symbolication a different way, directly inside Firefox -- note that will freeze Firefox for a few (lots of) seconds when you capture/quit.

This appears to cause Firefox to hang / get confused at startup. It just sits there in the task manager, taking no CPU and only 1MB of RAM, doing nothing (last output on the commandline is Started process `GECKO(pid)`, and then nothing happens).

Should I file a bug? Where do I start? :-)

(In reply to Markus Stange [:mstange] from comment #27)

(In reply to :Gijs (he/him) from comment #22)

profiler ERROR Encountered an exception during profile symbolication
profiler ERROR 'charmap' codec can't decode byte 0x9d in position 116223574: character maps to <undefined>

This error probably comes from the python scripts that try to do the symbolication. I'm not very familiar with those.

Gijs, as a workaround, you could try to do the following:

cargo install profiler-symbol-server
profiler-symbol-server yourprofile.json

And then maybe you'll need to go to the Profile Info panel and forcefully re-trigger symbolication, if it doesn't happen automatically.

OK, fwiw, it took me a few tries to even get a file out of the profiler (I tried using MOZ_PROFILER_SHUTDOWN=path which didn't work; I tried using the file path that mochitest outputs, which also didn't work (apparently gets removed as soon as it's handed off to the profiler).
I then tried using --profiler-save-only in combination with setting MOZ_UPLOAD_DIR, which appears to have worked. Then I tried to install profiler-symbol-server in order to follow your steps, but it doesn't compile, because it uses std::os::Unix::io in src/filedescriptor.rs, in core-foundation-0.9.1, and I'm trying this on Windows^^. Then there's more errors that it can't find RawFd and PATH_MAX. I don't know how to fix that. Is there an alternative that works on Windows, or am I just going to want to run these steps on macOS and hope whatever we find accurately indicates where the problems are on Windows?

^^ in part because that's where the issue is (though I'm testing on Win10) and in part because I have a much beefier Windows machine than my macbook...

Flags: needinfo?(mstange.moz)
Flags: needinfo?(gsquelart)

(In reply to :Gijs (he/him) from comment #30)

Then I tried to install profiler-symbol-server in order to follow your steps, but it doesn't compile, because it uses std::os::Unix::io in src/filedescriptor.rs, in core-foundation-0.9.1, and I'm trying this on Windows^^.

Sorry about that. I've pushed a fix. cargo install profiler-symbol-server now works on Windows.

Flags: needinfo?(mstange.moz)

(In reply to Markus Stange [:mstange] from comment #31)

(In reply to :Gijs (he/him) from comment #30)

Then I tried to install profiler-symbol-server in order to follow your steps, but it doesn't compile, because it uses std::os::Unix::io in src/filedescriptor.rs, in core-foundation-0.9.1, and I'm trying this on Windows^^.

Sorry about that. I've pushed a fix. cargo install profiler-symbol-server now works on Windows.

Thanks, this helped! I now have https://share.firefox.dev/3CCGW2j which is symbolicated, but I'm still about as puzzled as before about the contents of the profile... Though one odd thing I did find is how about:newtab's AboutPreferences.jsm's setupUserEvent call is apparently responsible for 1.3mb of retained memory (https://share.firefox.dev/3jJdjnp), more than all the other CE bindings or whatever? That seems like a lot, but still it's peanuts compared to the total numbers we're talking about, so I continue to be confused. :-(

(In reply to Andrew McCreight [:mccr8] from comment #25)

It does look like the grey scripts are periodically being cleaned up completely. I guess I need to figure out what changed to make it so we cleaned them up. I just looked at a chain of about 12 logs where the number of main.js scripts creeped up from about 3200 to 5600, then dropped to 357.

Is it possible there is some async task that outlives the about:preferences windows "for a while" and causes all this to stick around, until the task finishes? And because of how fast the tests run, we just accrue a bunch of such nearly-but-not-quite dead windows, and that adds up, or something? If so, is there a straightforward way of finding out what task that is?

Flags: needinfo?(gsquelart) → needinfo?(continuation)

I was able to look at this some more today. I wrote a Python script to analyze what happens to the various preferences/main.js scripts from one GC log to the next. Mostly this confirmed what I said before. From log 14 to 15, about 4500 black scripts remain black and 4300 grey remain grey. Then in the next one practically every black script becomes grey. Then all of the grey scripts are cleaned up. I picked about a half dozen different black script objects that turned grey from 15 to 16, and looked up why they were black.

I'll attach the log, but unfortunately there's no real commonality that I can see. There's some cacheir-object edges in there that looks suspicious to me, but maybe that's normal now?

Jan, what's with these cacheir-shape edges? Do they keep stuff alive for awhile (like some of the old JIT cache things that got purged only on major GCs)?

Flags: needinfo?(jdemooij)
Flags: needinfo?(continuation)

(In reply to Andrew McCreight [:mccr8] from comment #36)

Jan, what's with these cacheir-shape edges? Do they keep stuff alive for awhile (like some of the old JIT cache things that got purged only on major GCs)?

Yeah exactly, these are shapes stored in JIT IC stubs. Shapes have a realm and keep that realm's global alive. We purge JIT code and IC stubs on major GCs based on some heuristics. Ideally these IC edges would be weak, but it's complicated...

It's possible we could improve our JIT/IC discarding heuristics, but would that help here? Reading your comments it sounds like we do collect most of the garbage pretty quickly.

Flags: needinfo?(continuation)
Whiteboard: [stockwell needswork:owner]

(In reply to Jan de Mooij [:jandem] from comment #37)

It's possible we could improve our JIT/IC discarding heuristics, but would that help here? Reading your comments it sounds like we do collect most of the garbage pretty quickly.

Well, something, possibly this JIT IC thing, is keeping stuff around long enough that we are frequently OOMing on Win32 in this specific test directory. The general GC/CC issue we have with tests is that they create and destroy lots of DOM stuff very quickly, so time based heuristics often don't do well.

Flags: needinfo?(continuation)

(In reply to Andrew McCreight [:mccr8] from comment #38)

(In reply to Jan de Mooij [:jandem] from comment #37)

It's possible we could improve our JIT/IC discarding heuristics, but would that help here? Reading your comments it sounds like we do collect most of the garbage pretty quickly.

Well, something, possibly this JIT IC thing, is keeping stuff around long enough that we are frequently OOMing on Win32 in this specific test directory. The general GC/CC issue we have with tests is that they create and destroy lots of DOM stuff very quickly, so time based heuristics often don't do well.

If we're convinced that the GC/CC behaviour here is proper and there isn't a lurking issue with prefs or other code-under-test causing leaks, then perhaps we should just have the head.js file here add a clean up function that forces a GC/CC? Presumably that would address the OOM conditions...

I'll take a look at our JIT code discarding heuristics to see if there's something we can do there.

(In reply to :Gijs (he/him) from comment #39)

If we're convinced that the GC/CC behaviour here is proper and there isn't a lurking issue with prefs or other code-under-test causing leaks, then perhaps we should just have the head.js file here add a clean up function that forces a GC/CC? Presumably that would address the OOM conditions...

We're already doing a bunch of GCs/CCs, I believe. The problem is that this isn't enough for some reason, possibly because JIT memory isn't being freed. Maybe we could force a compacting GC or something, though GCing too much can slow things down a lot, and generally I try to avoid doing non-incremental GCs because then we have less testing for incremental GC, which is what we use most of the time. Of course, for just a single directory that's not as much of a concern.

I confirmed this has to do with our JIT code discarding heuristics. I'm testing a fix for this.

This fixes frequent OOMs on Win32 when running about:preferences tests.

THe problem is that we don't discard JIT code frequently enough if we keep being
notified of animations. This resulted in leaking global objects via Baseline
IC stubs, likely because we keep loading things in the system zone. This patch
changes the heuristic to ignore the animation hint if the last code discard was
more than 30 seconds ago.

This is all quite brittle unfortunately and these heuristics should probably be
redone at some point as part of a bigger project.

Assignee: nobody → jdemooij
Status: NEW → ASSIGNED
Flags: needinfo?(jdemooij)
Pushed by jdemooij@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/6f20e462bf19
Don't delay discarding JIT code for more than 30 seconds when animating. r=jonco

Thanks for the fix, Jan!

Status: ASSIGNED → RESOLVED
Closed: 28 days ago
Resolution: --- → FIXED
Target Milestone: --- → 93 Branch

== Change summary for alert #31000 (as of Mon, 23 Aug 2021 06:10:32 GMT) ==

Improvements:

Ratio Test Platform Options Absolute values (old vs new)
27% tp5o_webext responsiveness windows10-64-shippable-qr e10s stylo webrender 2.06 -> 1.51
25% tp5o_webext responsiveness windows10-64-shippable-qr e10s stylo webrender-sw 1.96 -> 1.47
14% tp5o_webext responsiveness linux1804-64-shippable-qr e10s stylo webrender-sw 5.69 -> 4.91
14% tp5o_webext responsiveness linux1804-64-shippable-qr e10s stylo webrender-sw 5.58 -> 4.82
13% tp5o_webext responsiveness linux1804-64-shippable-qr e10s stylo webrender 5.50 -> 4.77
12% tp5o_webext responsiveness linux1804-64-shippable-qr e10s stylo webrender-sw 5.56 -> 4.92

For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=31000

Keywords: perf-alert

It looks like this failure stopped right after the patch landed. Hurray!

You need to log in before you can comment on or make changes to this bug.