1630268 - Intermittent devtools/client/inspector/rules/test/<test_name> | application crashed [@ mozalloc_handle_oom(unsigned int)]

Status: RESOLVED FIXED

(DevTools :: Inspector: Rules, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=297727928&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GR5lSoU8S6utGZAihcbxeQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-04-15T12:04:03.321Z] 12:04:03 INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_search-filter_09.js
[task 2020-04-15T12:04:03.500Z] 12:04:03 INFO - GECKO(5268) | console.error: "Store does not have a valid reducer. Make sure the argument passed to combineReducers is an object whose values are reducers."
[task 2020-04-15T12:04:03.695Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-04-15T12:04:03.695Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-04-15T12:04:03.710Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2020-04-15T12:04:03.710Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2020-04-15T12:04:03.745Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-04-15T12:04:03.745Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2020-04-15T12:04:03.752Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2020-04-15T12:04:03.815Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-04-15T12:04:03.818Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2020-04-15T12:04:03.825Z] 12:04:03 INFO - GECKO(5268) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2020-04-15T12:04:05.664Z] 12:04:05 INFO - GECKO(5268) | out of memory: 0x0000000000010000 bytes requested
[task 2020-04-15T12:04:05.803Z] 12:04:05 INFO - GECKO(5268) | Exiting due to channel error.
[task 2020-04-15T12:04:05.803Z] 12:04:05 INFO - GECKO(5268) | Exiting due to channel error.
[task 2020-04-15T12:04:05.803Z] 12:04:05 INFO - GECKO(5268) | Exiting due to channel error.
[task 2020-04-15T12:04:06.003Z] 12:04:06 INFO - TEST-INFO | Main app process: exit 1

[task 2020-04-15T12:04:06.013Z] 12:04:06 INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_search-filter_09.js | margin-left text property is correctly highlighted. -
[task 2020-04-15T12:04:06.013Z] 12:04:06 INFO - Leaving test bound
[task 2020-04-15T12:04:06.014Z] 12:04:06 INFO - Buffered messages finished
[task 2020-04-15T12:04:06.014Z] 12:04:06 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_search-filter_09.js | application terminated with exit code 1
[task 2020-04-15T12:04:06.014Z] 12:04:06 INFO - runtests.py | Application ran for: 0:07:13.323000
[task 2020-04-15T12:04:06.014Z] 12:04:06 INFO - zombiecheck | Reading PID log: c:\users\task_1586950959\appdata\local\temp\tmpkkviztpidlog
[task 2020-04-15T12:04:06.014Z] 12:04:06 INFO - ==> process 5384 launched child process 5916 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.0.1422297803\1898212347" -childID 1 -isForBrowser -prefsHandle 2108 -prefMapHandle 2100 -prefsLen 1 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 2152 tab)
[task 2020-04-15T12:04:06.014Z] 12:04:06 INFO - ==> process 5384 launched child process 2716 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.6.2070841016\1707742002" -childID 2 -isForBrowser -prefsHandle 2392 -prefMapHandle 2388 -prefsLen 142 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 2404 tab)
[task 2020-04-15T12:04:06.014Z] 12:04:06 INFO - ==> process 5384 launched child process 2504 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.12.1562018629\1881433884" -childID 3 -isForBrowser -prefsHandle 4680 -prefMapHandle 2176 -prefsLen 568 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 4692 tab)
[task 2020-04-15T12:04:06.015Z] 12:04:06 INFO - ==> process 5384 launched child process 2072 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.18.702015704\1542781163" -childID 4 -isForBrowser -prefsHandle 4176 -prefMapHandle 4172 -prefsLen 10546 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 3200 tab)
[task 2020-04-15T12:04:06.015Z] 12:04:06 INFO - ==> process 5384 launched child process 4088 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.24.94673788\692451476" -childID 5 -isForBrowser -prefsHandle 4116 -prefMapHandle 2876 -prefsLen 10844 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 2924 tab)
[task 2020-04-15T12:04:06.015Z] 12:04:06 INFO - ==> process 5384 launched child process 1648 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.30.1633381324\115056992" -childID 6 -isForBrowser -prefsHandle 4136 -prefMapHandle 4000 -prefsLen 10985 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 2588 tab)
[task 2020-04-15T12:04:06.015Z] 12:04:06 INFO - ==> process 5384 launched child process 1508 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.36.46598761\1067165600" -childID 7 -isForBrowser -prefsHandle 4116 -prefMapHandle 4120 -prefsLen 11232 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 3408 tab)
[task 2020-04-15T12:04:06.015Z] 12:04:06 INFO - ==> process 5384 launched child process 5536 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.42.404338391\81512143" -childID 8 -isForBrowser -prefsHandle 2692 -prefMapHandle 4116 -prefsLen 11232 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 2772 tab)
[task 2020-04-15T12:04:06.015Z] 12:04:06 INFO - ==> process 5384 launched child process 4596 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.48.1238816179\313851864" -childID 9 -isForBrowser -prefsHandle 4116 -prefMapHandle 2900 -prefsLen 11232 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 2656 tab)
[task 2020-04-15T12:04:06.016Z] 12:04:06 INFO - ==> process 5384 launched child process 3488 ("Z:\task_1586950959\build\application\firefox\firefox.exe" -contentproc --channel="5384.54.1474359305\1400098830" -childID 10 -isForBrowser -prefsHandle 4420 -prefMapHandle 4080 -prefsLen 11232 -prefMapSize 230955 -parentBuildID 20200415100054 -appdir "Z:\task_1586950959\build\application\firefox\browser" - 5384 "\.\pipe\gecko-crash-server-pipe.5384" 4448 tab)
[task 2020-04-15T12:04:06.016Z] 12:04:06 INFO - zombiecheck | Checking for orphan process with PID: 5536
[task 2020-04-15T12:04:06.016Z] 12:04:06 INFO - zombiecheck | Checking for orphan process with PID: 3488

[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - PROCESS-CRASH | devtools/client/inspector/rules/test/browser_rules_search-filter_09.js | application crashed [@ mozalloc_handle_oom(unsigned int)]
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Mozilla crash reason: MOZ_CRASH()
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Crash dump filename: c:\users\task_1586950959\appdata\local\temp\tmpgun8nj.mozrunner\minidumps\958cc794-0343-4222-a794-476f66317bd2.dmp
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Operating system: Windows NT
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - 6.1.7601 Service Pack 1
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - CPU: x86
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - GenuineIntel family 6 model 63 stepping 2
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - 8 CPUs
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO -
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - GPU: UNKNOWN
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO -
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Crash reason: EXCEPTION_BREAKPOINT
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Crash address: 0x6a8ceeac
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Process uptime: 433 seconds
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO -
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - Thread 0 (crashed)
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - 0 mozglue.dll!mozalloc_abort(char const* const) [mozalloc_abort.cpp:e4c33c86b39877dc225e7a686d567919e18e82d1 : 33 + 0x0]
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - eip = 0x6a8ceeac esp = 0x002be594 ebp = 0x002be59c ebx = 0x6cada000
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - esi = 0x002be5aa edi = 0x6a72f9b0 eax = 0x0000000a ecx = 0x6a737af0
[task 2020-04-15T12:04:18.815Z] 12:04:18 INFO - edx = 0x00000000 efl = 0x00000212
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: given as instruction pointer in context
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 1 mozglue.dll!mozalloc_handle_oom(unsigned int) [mozalloc_oom.cpp:e4c33c86b39877dc225e7a686d567919e18e82d1 : 51 + 0x6]
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x6a8cf013 esp = 0x002be5a4 ebp = 0x002be5e4 esi = 0x002be5aa
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - edi = 0x00000000
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 2 mozglue.dll!moz_xmalloc(unsigned int) [mozalloc.cpp:e4c33c86b39877dc225e7a686d567919e18e82d1 : 54 + 0x6]
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x6a8cefa1 esp = 0x002be5ec ebp = 0x002be5f4 esi = 0x00010000
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - edi = 0x22222222
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 3 xul.dll + 0x81effe
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x585ceffe esp = 0x002be5fc ebp = 0x002be65c esi = 0x7eebc568
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 4 xul.dll + 0x80f59c
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x585bf59c esp = 0x002be664 ebp = 0x002be750
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 5 xul.dll + 0x3604d85
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x5b3b4d85 esp = 0x002be758 ebp = 0x002be7a0
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 6 xul.dll + 0x80f705
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x585bf705 esp = 0x002be7a8 ebp = 0x002be890
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - 7 xul.dll + 0x361a4d7
[task 2020-04-15T12:04:18.816Z] 12:04:18 INFO - eip = 0x5b3ca4d7 esp = 0x002be898 ebp = 0x002be8b4
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 8 xul.dll + 0x345718c
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x5b20718c esp = 0x002be8bc ebp = 0x002be8f0
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 9 xul.dll + 0x3628850
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x5b3d8850 esp = 0x002be8f8 ebp = 0x002be908
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 10 xul.dll + 0x80ec80
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x585bec80 esp = 0x002be910 ebp = 0x002bea68
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 11 xul.dll + 0x81cd5d
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x585ccd5d esp = 0x002bea70 ebp = 0x002beaa0
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 12 xul.dll + 0x82233b
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x585d233b esp = 0x002beaa8 ebp = 0x002beaac
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 13 xul.dll + 0x8241d5
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x585d41d5 esp = 0x002beab4 ebp = 0x002beb14
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 14 xul.dll + 0x826219
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x585d6219 esp = 0x002beb1c ebp = 0x002beb78
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - 15 xul.dll + 0x147d8be
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - eip = 0x5922d8be esp = 0x002beb80 ebp = 0x002bebe4
[task 2020-04-15T12:04:18.817Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 16 xul.dll + 0x1351c6d
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x59101c6d esp = 0x002bebec ebp = 0x002bec04
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 17 xul.dll + 0x443dfe7
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x5c1edfe7 esp = 0x002bec0c ebp = 0x002bec18
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 18 xul.dll + 0x8f9ff
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x57e3f9ff esp = 0x002bec20 ebp = 0x002bedd4
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 19 xul.dll + 0xe95ddd
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x58c45ddd esp = 0x002beddc ebp = 0x002bee58
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 20 0xcd97a77
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x0cd97a77 esp = 0x002bee60 ebp = 0x002bee90
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 21 0x444c8570
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x444c8570 esp = 0x002bee98 ebp = 0x002beedc
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 22 0xcc8065b
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x0cc8065b esp = 0x002beee4 ebp = 0x002bef10
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - 23 xul.dll + 0x3f49140
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - eip = 0x5bcf9140 esp = 0x002bef18 ebp = 0x002bf13c
[task 2020-04-15T12:04:18.818Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 24 xul.dll + 0x32f1c3b
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x5b0a1c3b esp = 0x002bf144 ebp = 0x002bf1a8
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 25 xul.dll + 0x32f2291
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x5b0a2291 esp = 0x002bf1b0 ebp = 0x002bf1b8
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 26 xul.dll + 0x3401356
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x5b1b1356 esp = 0x002bf1c0 ebp = 0x002bf28c
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 27 xul.dll + 0x32f19d8
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x5b0a19d8 esp = 0x002bf294 ebp = 0x002bf2fc
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 28 xul.dll + 0x335e865
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x5b10e865 esp = 0x002bf304 ebp = 0x002bf39c
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 29 xul.dll + 0x1718f1f
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x594c8f1f esp = 0x002bf3a4 ebp = 0x002bf3fc
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 30 xul.dll + 0x16b50c
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x57f1b50c esp = 0x002bf404 ebp = 0x002bf574
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 31 xul.dll + 0x382ea
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - eip = 0x57de82ea esp = 0x002bf57c ebp = 0x002bf70c
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.819Z] 12:04:18 INFO - 32 xul.dll + 0x374cb
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57de74cb esp = 0x002bf714 ebp = 0x002bf730
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - 33 xul.dll + 0x16555b
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57f1555b esp = 0x002bf738 ebp = 0x002bf788
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - 34 xul.dll + 0x1e254
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57dce254 esp = 0x002bf790 ebp = 0x002bf7c0
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - 35 xul.dll + 0x37011
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57de7011 esp = 0x002bf7c8 ebp = 0x002bf7e0
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - 36 xul.dll + 0x165455
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57f15455 esp = 0x002bf7e8 ebp = 0x002bf7f0
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - 37 xul.dll + 0x163fff
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57f13fff esp = 0x002bf7f8 ebp = 0x002bf80c
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - 38 xul.dll + 0x163f40
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - eip = 0x57f13f40 esp = 0x002bf814 ebp = 0x002bf81c
[task 2020-04-15T12:04:18.820Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 39 xul.dll + 0x82cbc
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x57e32cbc esp = 0x002bf824 ebp = 0x002bf9f8
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 40 xul.dll + 0x2a36
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x57db2a36 esp = 0x002bfa00 ebp = 0x002bfa40
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 41 xul.dll + 0x2667
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x57db2667 esp = 0x002bfa48 ebp = 0x002bfb20
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 42 xul.dll + 0x25e1
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x57db25e1 esp = 0x002bfb28 ebp = 0x002bfb34
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 43 firefox.exe!NS_internal_main(int, char**, char**) [nsBrowserApp.cpp:e4c33c86b39877dc225e7a686d567919e18e82d1 : 331 + 0x83]
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x0105145f esp = 0x002bfb3c ebp = 0x002bfca8
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - Found by: previous frame's frame pointer
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 44 firefox.exe!wmain(int, wchar_t**) [nsWindowsWMain.cpp:e4c33c86b39877dc225e7a686d567919e18e82d1 : 131 + 0x12]
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x0105119c esp = 0x002bfcb0 ebp = 0x002bfcd4 ebx = 0x0008ae68
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - esi = 0x00702040 edi = 0x00702080
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - 45 firefox.exe!__scrt_common_main_seh() [exe_common.inl : 288 + 0x1c]
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - eip = 0x0108c9dc esp = 0x002bfcdc ebp = 0x002bfd1c ebx = 0x7ffdd000
[task 2020-04-15T12:04:18.821Z] 12:04:18 INFO - esi = 0x6a80f0b0 edi = 0x0008ae68
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - 46 kernel32.dll!pszNtAMD64Suffix + 0x25e4
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - eip = 0x7654ef3c esp = 0x002bfd24 ebp = 0x002bfd28
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - 47 ntdll.dll!SetupDiChangeState + 0x707
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - eip = 0x76fe3618 esp = 0x002bfd30 ebp = 0x002bfd68
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - Found by: call frame info
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - 48 ntdll.dll!SetupDiChangeState + 0x6da
[task 2020-04-15T12:04:18.822Z] 12:04:18 INFO - eip = 0x76fe35eb esp = 0x002bfd70 ebp = 0x002bfd80

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2
• autoland: 3
• mozilla-central: 1

Platform breakdown:

• windows7-32-shippable: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-04-13&endday=2020-04-19&tree=all

Comment 7

[Intermittent Failures Robot]

18 failures in 5582 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 15
• try: 3

Platform breakdown:

• windows7-32-shippable: 18

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-04-20&endday=2020-04-26&tree=all

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 7
• mozilla-central: 1
• try: 2

Platform breakdown:

• windows7-32-shippable: 10

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-04-27&endday=2020-05-03&tree=all

Comment 9

[Intermittent Failures Robot]

15 failures in 5276 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 12
• mozilla-central: 2
• mozilla-release: 1

Platform breakdown:

• windows7-32-shippable: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-05-04&endday=2020-05-10&tree=all

Comment 10

[Intermittent Failures Robot]

23 failures in 5488 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 16
• mozilla-central: 6
• try: 1

Platform breakdown:

• windows7-32-shippable: 20
• windows7-32: 2
• windows7-32-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-05-11&endday=2020-05-17&tree=all

Comment 11

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Razvan, can anything be done to stop these out of memory errors?

Comment 12

[Intermittent Failures Robot]

15 failures in 4727 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 15

Platform breakdown:

• windows7-32-shippable: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-05-18&endday=2020-05-24&tree=all

Comment 13

[Razvan Caliman [:rcaliman]]

I have no idea where to begin debugging out-of-memory issues. Brad, is this something you can help with?

Comment 14

[Brad Werth [:bradwerth]]

I don't have great insight into this. The test alone on my macOS system does not crash. Some thoughts:

1. All of the checks in the test are passing before the error, and the out-of-memory is happening in the cleanup phase. The last message before the crash is a "zombiecheck" log message, but all of those zombiecheck messages match up to the processes that were spawned by the test. The next thing that runs is the "mozcrash" function, but this is just a roll-up of crashes that happened earlier. The raw log does seem to show that the OOM happens within the run of browser_rules_search-filter_09.js, but in a cleanup phase after the last check that "margin-left text property is correctly highlighted."

2. At the point of the crash, it says that the process ran for 7 minutes and 13 seconds. That corresponds to a process start time of 11:56:53 which is when the 5268 process is spawned. It runs 207 tests, with the last one being browser_rules_search-filter_09.js before crashing. During that time, memory usage seems to go up, but I don't know if any of the status message indicate that some limit is being reached. The failing allocation is for 64MB at a time when the last memory stat message is MEMORY STAT | vsize 1890MB | vsizeMaxContiguous 6MB | residentFast 1215MB | heapAllocated 633MB

3. I note that browser_rules_search-filter_09.js calls addTab but not removeTab. A quick sampling of the 207 tests run by this crashed process shows a similar pattern in all the tests I checked. It seems unlikely that this could be a source of unbounded memory growth when run in the test harness, but it couldn't hurt to remove tabs at the end of these tests.

I can't figure out anything else. I have a question out to somebody on how to proceed with a OOM crash report and if I learn anything useful from that I'll add it here.

Comment 15

[Brad Werth [:bradwerth]]

(In reply to Brad Werth [:bradwerth] from comment #14)

1. All of the checks in the test are passing before the error, and the out-of-memory is happening in the cleanup phase.

And indeed the orange factor crash signatures show that this OOM is happening on various tests in the devtools/client/inspector/rules/test/ directory, thus the more general title for this bug. The browser_rules_search-filter_09.js test is not a specific culprit -- it's just near the end.

2. It runs 207 tests, with the last one being browser_rules_search-filter_09.js before crashing. During that time, memory usage seems to go up...

We probably have memory leaks in devtools, and 200 tests opening and closing the toolbox, even if done correctly, will consume increasing amounts memory.

3. I note that browser_rules_search-filter_09.js calls addTab but not removeTab. A quick sampling of the 207 tests run by this crashed process shows a similar pattern in all the tests I checked. It seems unlikely that this could be a source of unbounded memory growth when run in the test harness, but it couldn't hurt to remove tabs at the end of these tests.

The devtools shared-head.js has a cleanup function that should be taking care of this.

Given all this, one option is to split the tests in devtools/client/inspector/rules/test/ into two chunks, similar to how it's done for the webconsole. That will ensure that a fresh process is created to host each chunk and should alleviate the memory pressure. Alex, does this seem like a reasonable solution?

Comment 16

[Intermittent Failures Robot]

22 failures in 5458 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 20
• try: 1
• mozilla-central: 1

Platform breakdown:

• windows7-32-shippable: 21
• windows7-32-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-05-25&endday=2020-05-31&tree=all

Comment 19

[Brad Werth [:bradwerth]]

Attachment: Bug 1630268 Part 1: Rename devtools/client/inspector/rules/test/browser.ini.

Comment 20

[Brad Werth [:bradwerth]]

Attachment: Bug 1630268 Part 2: Move half of the tests in browser_part1.ini into a new file, browser_part2.ini.

Depends on D78354

Comment 21

[Brad Werth [:bradwerth]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=7a00d99e3d6c5962c56a2bc16cc3fef7880b7542

Comment 22

[Brad Werth [:bradwerth]]

Moving to review.

Comment 24

[Intermittent Failures Robot]

19 failures in 4949 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 3
• autoland: 11
• try: 1
• mozilla-central: 4

Platform breakdown:

• windows7-32-shippable: 17
• windows7-32-devedition: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-06-01&endday=2020-06-07&tree=all

Comment 25

[Alexandre Poirot [:ochameau]]

It would be interesting to know if one test leaks a lot or, if we are leaking a bit on each test.

How to investigate just one test

I tried to briefly look at just one test. I choosed randomly | browser_rules_search-filter_01.js`:

MOZ_PROFILER_STARTUP_ENTRIES=70000000 MOZ_PROFILER_STARTUP_FEATURES=nativeallocations,js,stackwalk MOZ_PROFILER_STARTUP=1 MOZ_PROFILER_SHUTDOWN=mochitestprofile.json MOZCONFIG=mozconfig-firefox-artifact ./mach mochitest --headless devtools/client/inspector/rules/test/browser_rules_search-filter_01.js --repeat 3

This command runs the test three times, while recording its allocations:
https://share.firefox.dev/3cLd7OZ

I ran it 3 times, because the first time will allocate a lot of memory, which is expected to stay allocated until firefox closes.
The first run:

• is loading all JSM used by DevTools,
• instantiates all modules/code/menus related to DevTools when we open them for the first time,
• instantiate the "main" DevTools Loader, which works like JSM. By default, all modules loaded once and kept in memory until we close Firefox. This is valid for the "main" Loader, but not for "Browser Loaders". These other loaders should be freed once the toolbox is closed.

In the recorded profile:

• the marker chart is useful to identify and focus on the 2nd or 3rd test run, search for browser-test.
• the flame chart is also useful, you would need to toggle the view to display "retained memory".

It might be interesting to investigate this very particular view:
https://share.firefox.dev/3cLfpO5

Nothing immediately obvious/actionnable appeared to me, but I saw:

• resource://devtools/client/shared/source-map/worker.js potentially leaking 800k. It allocates much much more, most is being freed, but a few hundred k are left allocated quite consistantly during each test run.
• because of bug 1644114, I'm missing c++ symbols, but I'm wondering why painting keeps things allocated (ClientPaintedLayer::RenderLayerWithReadback)
• we might leak something around customelementregistry.define and custom elements. about:devtools-toolbox, i.e. DevTools toolbox involves a few custom elements, but they should be freed when closing the toolbox. I think the elements are freed, but we might spare a few things from the custom element internal implementations.

Also note that I patched the shared-head in order to force a few garbage collection at the end of each test run:

diff --git a/devtools/client/shared/test/shared-head.js b/devtools/client/shared/test/shared-head.js
index aa7a615d458b9..39f20c0442eec 100644
--- a/devtools/client/shared/test/shared-head.js
+++ b/devtools/client/shared/test/shared-head.js
@@ -276,6 +276,8 @@ registerCleanupFunction(async function cleanup() {
       conn.close();
     }
   }
+  Cu.forceCC();
+  Cu.forceGC();
 });
 
 /**

Investigate to see if one test is leaking a lot

We could pile up on the patch I just mentioned, in order to force some GC, and, print the memory used at the end of each test.
On linux, we could retrieve the memory via:
Cc["@mozilla.org/memory-reporter-manager;1"].getService(Ci.nsIMemoryReporterManager).residentUnique
We could probably print the memory used at the end thanks to this.
It would require reading the test log and try to spot if one test does a significant increase.

GC hazards

The GC algorithm is known to be flaky when running automated test. It is highly optimized for production and not for running stress test.
Stress test, involving privileged API, privileged compartments, may allocate a lot and use pattern of code which would not trigger any GC, while allocating a lot.
We are used to add a few forced GC here and there, especially at the end of tests allocating a lot without trigerring the GC by their test scripts.

Comment 26

[Alexandre Poirot [:ochameau]]

Sorry, I did not meant to update the crash signature.

Comment 27

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3cf723e5db77
Part 1: Rename devtools/client/inspector/rules/test/browser.ini. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/fcfe04e34559
Part 2: Move half of the tests in browser_part1.ini into a new file, browser_part2.ini. r=ochameau

Comment 28

[Brad Werth [:bradwerth]]

(In reply to Alexandre Poirot [:ochameau] from comment #25)

Thanks for the detailed approach to analyzing these memory leaks. I've linked to your comment from the devtools memory leak meta bug. I'll land this paper-over fix and we can potentially revisit this split when the memory leaks are under control.

Comment 29

[Dorel Luca [:dluca]]

https://hg.mozilla.org/mozilla-central/rev/3cf723e5db77
https://hg.mozilla.org/mozilla-central/rev/fcfe04e34559

Comment 30

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/bc5df77ec3f3
https://hg.mozilla.org/releases/mozilla-beta/rev/cdbfcce60794

Comment 32

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-beta: 1

Platform breakdown:

• windows7-32-shippable: 1
• windows7-32-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630268&startday=2020-06-08&endday=2020-06-14&tree=all