Closed Bug 1832153 Opened 1 year ago Closed 9 months ago

Perma Linux valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc

Categories

(Core :: JavaScript Engine, defect, P2)

defect

Tracking

()

RESOLVED FIXED
120 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox-esr115 --- fixed
firefox113 --- unaffected
firefox114 --- unaffected
firefox115 --- wontfix
firefox116 --- wontfix
firefox117 --- wontfix
firefox118 --- wontfix
firefox119 --- fixed
firefox120 --- fixed

People

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

References

(Blocks 2 open bugs, Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disable-recommended])

Attachments

(2 files)

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


[task 2023-05-09T16:53:44.640Z] 16:53:44     INFO -  --30725-- Scanning and archiving ExeContexts ...
[task 2023-05-09T16:53:45.217Z] 16:53:45     INFO -  --30725-- Scanned 3,880,440 ExeContexts, archived 81 ExeContexts
[task 2023-05-09T16:53:45.366Z] 16:53:45     INFO -  ==30725==
[task 2023-05-09T16:53:45.370Z] 16:53:45     INFO -  ==30725== HEAP SUMMARY:
[task 2023-05-09T16:53:45.370Z] 16:53:45     INFO -  ==30725==     in use at exit: 11,093,595 bytes in 63,877 blocks
[task 2023-05-09T16:53:45.370Z] 16:53:45     INFO -  ==30725==   total heap usage: 6,513,056 allocs, 6,449,179 frees, 4,009,426,133 bytes allocated
[task 2023-05-09T16:53:45.370Z] 16:53:45     INFO -  ==30725==
[task 2023-05-09T16:53:45.409Z] 16:53:45     INFO -  ==30725== Searching for pointers to 62,714 not-freed blocks
[task 2023-05-09T16:53:46.024Z] 16:53:46     INFO -  ==30725== Checked 340,516,488 bytes
[task 2023-05-09T16:53:46.024Z] 16:53:46     INFO -  ==30725==
[task 2023-05-09T16:53:47.064Z] 16:53:47     INFO -  TEST-UNEXPECTED-FAIL | valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc
[task 2023-05-09T16:53:47.064Z] 16:53:47     INFO -  ==30725== 16 bytes in 1 blocks are definitely lost in loss record 4,053 of 21,963
[task 2023-05-09T16:53:47.065Z] 16:53:47     INFO -  ==30725==    at 0x48397B5: malloc+117 (vg_replace_malloc.c:393)
[task 2023-05-09T16:53:47.065Z] 16:53:47     INFO -  ==30725==    by 0xFA37AB3: js_arena_malloc (dist/include/js/Utility.h:366)
[task 2023-05-09T16:53:47.065Z] 16:53:47     INFO -  ==30725==    by 0xFA37AB3: js_pod_arena_malloc<unsigned char> (dist/include/js/Utility.h:576)
[task 2023-05-09T16:53:47.065Z] 16:53:47     INFO -  ==30725==    by 0xFA37AB3: maybe_pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:57)
[task 2023-05-09T16:53:47.066Z] 16:53:47     INFO -  ==30725==    by 0xFA37AB3: pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:109)
[task 2023-05-09T16:53:47.066Z] 16:53:47     INFO -  ==30725==    by 0xFA37AB3: pod_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:127)
[task 2023-05-09T16:53:47.066Z] 16:53:47     INFO -  ==30725==    by 0xFA37AB3: js::Nursery::allocateBuffer(JS::Zone*, JSObject*, unsigned long)+67 (checkouts/gecko/js/src/gc/Nursery.cpp:645)
[task 2023-05-09T16:53:47.066Z] 16:53:47     INFO -  ==30725==    by 0xF6BFA66: AllocateObjectBuffer<js::HeapSlot> (checkouts/gecko/js/src/gc/Nursery-inl.h:113)
[task 2023-05-09T16:53:47.066Z] 16:53:47     INFO -  ==30725==    by 0xF6BFA66: allocateSlots (checkouts/gecko/js/src/vm/NativeObject.cpp:347)
[task 2023-05-09T16:53:47.067Z] 16:53:47     INFO -  ==30725==    by 0xF6BFA66: js::NativeObject::setOrUpdateUniqueId(JSContext*, unsigned long)+70 (checkouts/gecko/js/src/vm/NativeObject.cpp:240)
[task 2023-05-09T16:53:47.067Z] 16:53:47     INFO -  ==30725==    by 0xF750C90: SetObjectIsUsedAsPrototype (checkouts/gecko/js/src/vm/Shape.cpp:1015)
[task 2023-05-09T16:53:47.067Z] 16:53:47     INFO -  ==30725==    by 0xF750C90: JSObject::setProtoUnchecked(JSContext*, JS::Handle<JSObject*>, JS::Handle<js::TaggedProto>)+128 (checkouts/gecko/js/src/vm/Shape.cpp:1039)
[task 2023-05-09T16:53:47.067Z] 16:53:47     INFO -  ==30725==    by 0xF696620: js::SetPrototype(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>, JS::ObjectOpResult&)+624 (checkouts/gecko/js/src/vm/JSObject.cpp:1998)
[task 2023-05-09T16:53:47.067Z] 16:53:47     INFO -  ==30725==    by 0xF69669E: js::SetPrototype(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>)+46 (checkouts/gecko/js/src/vm/JSObject.cpp:2007)
[task 2023-05-09T16:53:47.068Z] 16:53:47     INFO -  ==30725==    by 0xB9DDA06: XPCWrappedNative::WrapNewGlobal(JSContext*, xpcObjectHelper&, nsIPrincipal*, bool, JS::RealmOptions&, XPCWrappedNative**)+486 (checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:212)
[task 2023-05-09T16:53:47.068Z] 16:53:47     INFO -  ==30725==    by 0xB9D56AF: xpc::InitClassesWithNewWrappedGlobal(JSContext*, nsISupports*, nsIPrincipal*, unsigned int, JS::RealmOptions&, JS::MutableHandle<JSObject*>)+159 (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:556)
[task 2023-05-09T16:53:47.068Z] 16:53:47     INFO -  ==30725==    by 0xB98C011: mozJSModuleLoader::CreateLoaderGlobal(JSContext*, nsTSubstring<char> const&, JS::MutableHandle<JSObject*>)+257 (checkouts/gecko/js/xpconnect/loader/mozJSModuleLoader.cpp:608)
[task 2023-05-09T16:53:47.068Z] 16:53:47     INFO -  ==30725==    by 0xB98C34F: mozJSModuleLoader::GetSharedGlobal(JSContext*)+175 (checkouts/gecko/js/xpconnect/loader/mozJSModuleLoader.cpp:650)
[task 2023-05-09T16:53:47.068Z] 16:53:47     INFO -  ==30725==    by 0xB9BD6CC: XPCJSRuntime::LoaderGlobal()+92 (checkouts/gecko/js/xpconnect/src/XPCJSRuntime.cpp:3161)
[task 2023-05-09T16:53:47.069Z] 16:53:47     INFO -  ==30725==    by 0xB997145: mozilla::ScriptPreloader::InitCache(nsTSubstring<char16_t> const&)+101 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:445)
[task 2023-05-09T16:53:47.069Z] 16:53:47     INFO -  ==30725==    by 0xB995A10: mozilla::ScriptPreloader::GetChildSingleton()+272 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:155)
[task 2023-05-09T16:53:47.069Z] 16:53:47     INFO -  ==30725==    by 0xB99702E: mozilla::ScriptPreloader::GetSingleton()+238 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:117)
[task 2023-05-09T16:53:47.069Z] 16:53:47     INFO -  ==30725==    by 0xB9E87A5: InitJSContext (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:102)
[task 2023-05-09T16:53:47.069Z] 16:53:47     INFO -  ==30725==    by 0xB9E87A5: xpc::InitializeJSContext()+53 (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:107)
[task 2023-05-09T16:53:47.070Z] 16:53:47     INFO -  ==30725==    by 0xF4B2DCD: XREMain::XRE_mainRun()+1229 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5362)
[task 2023-05-09T16:53:47.070Z] 16:53:47     INFO -  ==30725==    by 0xF4B3C04: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)+1156 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5857)
[task 2023-05-09T16:53:47.070Z] 16:53:47     INFO -  ==30725==    by 0xF4B3F91: XRE_main(int, char**, mozilla::BootstrapConfig const&)+193 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5913)
[task 2023-05-09T16:53:47.070Z] 16:53:47     INFO -  ==30725==    by 0x12D429: do_main (checkouts/gecko/browser/app/nsBrowserApp.cpp:227)
[task 2023-05-09T16:53:47.070Z] 16:53:47     INFO -  ==30725==    by 0x12D429: main+1065 (checkouts/gecko/browser/app/nsBrowserApp.cpp:445)
[task 2023-05-09T16:53:47.070Z] 16:53:47     INFO -  ==30725==

Hello Jon! Could you please take a look at this? It looks like this failure is related with your push, as it can be seen here.

Thank you!

Flags: needinfo?(jcoppeard)
Keywords: regression
Regressed by: 1828455
Assignee: nobody → jcoppeard
Flags: needinfo?(jcoppeard)

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

Whiteboard: [stockwell needswork:owner]

We had 108 occurrences for this failure in the past 7 days, all of them on linux64-qr opt platform.
Recent failure: https://treeherder.mozilla.org/logviewer?job_id=416231239&repo=autoland&lineNumber=73342

[task 2023-05-18T11:15:58.142Z] 11:15:58 INFO - ==30533== HEAP SUMMARY:
[task 2023-05-18T11:15:58.142Z] 11:15:58 INFO - ==30533== in use at exit: 10,804,203 bytes in 63,548 blocks
[task 2023-05-18T11:15:58.142Z] 11:15:58 INFO - ==30533== total heap usage: 6,533,371 allocs, 6,469,823 frees, 3,953,926,924 bytes allocated
[task 2023-05-18T11:15:58.142Z] 11:15:58 INFO - ==30533==
[task 2023-05-18T11:15:58.179Z] 11:15:58 INFO - ==30533== Searching for pointers to 62,385 not-freed blocks
[task 2023-05-18T11:15:58.791Z] 11:15:58 INFO - ==30533== Checked 340,225,152 bytes
[task 2023-05-18T11:15:58.791Z] 11:15:58 INFO - ==30533==
[task 2023-05-18T11:15:59.809Z] 11:15:59 INFO - TEST-UNEXPECTED-FAIL | valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc
[task 2023-05-18T11:15:59.809Z] 11:15:59 INFO - ==30533== 16 bytes in 1 blocks are definitely lost in loss record 4,055 of 21,831
[task 2023-05-18T11:15:59.809Z] 11:15:59 INFO - ==30533== at 0x48397B5: malloc+117 (vg_replace_malloc.c:393)
[task 2023-05-18T11:15:59.809Z] 11:15:59 INFO - ==30533== by 0xFA9E1A3: js_arena_malloc (dist/include/js/Utility.h:366)
[task 2023-05-18T11:15:59.810Z] 11:15:59 INFO - ==30533== by 0xFA9E1A3: js_pod_arena_malloc<unsigned char> (dist/include/js/Utility.h:576)
[task 2023-05-18T11:15:59.810Z] 11:15:59 INFO - ==30533== by 0xFA9E1A3: maybe_pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:57)

Summary: Intermittent valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc → High frequency valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc

Update: in the past week, we had 93 occurrences for this failure, all on linux64-qr opt.
Latest log failure: https://treeherder.mozilla.org/logviewer?job_id=417885164&repo=mozilla-central&lineNumber=72073


T-UNEXPECTED-FAIL | valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc
[task 2023-06-02T10:29:15.208Z] 10:29:15     INFO -  ==31253== 16 bytes in 1 blocks are definitely lost in loss record 4,080 of 22,060
[task 2023-06-02T10:29:15.208Z] 10:29:15     INFO -  ==31253==    at 0x48397B5: malloc+117 (vg_replace_malloc.c:393)
[task 2023-06-02T10:29:15.208Z] 10:29:15     INFO -  ==31253==    by 0xFB9D8D3: js_arena_malloc (dist/include/js/Utility.h:366)
[task 2023-06-02T10:29:15.209Z] 10:29:15     INFO -  ==31253==    by 0xFB9D8D3: js_pod_arena_malloc<unsigned char> (dist/include/js/Utility.h:576)
[task 2023-06-02T10:29:15.209Z] 10:29:15     INFO -  ==31253==    by 0xFB9D8D3: maybe_pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:57)
[task 2023-06-02T10:29:15.209Z] 10:29:15     INFO -  ==31253==    by 0xFB9D8D3: pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:109)
[task 2023-06-02T10:29:15.209Z] 10:29:15     INFO -  ==31253==    by 0xFB9D8D3: pod_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:127)
[task 2023-06-02T10:29:15.210Z] 10:29:15     INFO -  ==31253==    by 0xFB9D8D3: js::Nursery::allocateBuffer(JS::Zone*, JSObject*, unsigned long)+67 (checkouts/gecko/js/src/gc/Nursery.cpp:609)
[task 2023-06-02T10:29:15.210Z] 10:29:15     INFO -  ==31253==    by 0xF819E06: AllocateObjectBuffer<js::HeapSlot> (checkouts/gecko/js/src/gc/Nursery-inl.h:113)
[task 2023-06-02T10:29:15.210Z] 10:29:15     INFO -  ==31253==    by 0xF819E06: allocateSlots (checkouts/gecko/js/src/vm/NativeObject.cpp:348)
[task 2023-06-02T10:29:15.210Z] 10:29:15     INFO -  ==31253==    by 0xF819E06: js::NativeObject::setOrUpdateUniqueId(JSContext*, unsigned long)+70 (checkouts/gecko/js/src/vm/NativeObject.cpp:241)
[task 2023-06-02T10:29:15.210Z] 10:29:15     INFO -  ==31253==    by 0xF8ACBE9: SetObjectIsUsedAsPrototype (checkouts/gecko/js/src/vm/Shape.cpp:1015)
[task 2023-06-02T10:29:15.211Z] 10:29:15     INFO -  ==31253==    by 0xF8ACBE9: JSObject::setProtoUnchecked(JSContext*, JS::Handle<JSObject*>, JS::Handle<js::TaggedProto>)+121 (checkouts/gecko/js/src/vm/Shape.cpp:1039)
[task 2023-06-02T10:29:15.211Z] 10:29:15     INFO -  ==31253==    by 0xF7EF8D0: js::SetPrototype(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>, JS::ObjectOpResult&)+624 (checkouts/gecko/js/src/vm/JSObject.cpp:1998)
[task 2023-06-02T10:29:15.211Z] 10:29:15     INFO -  ==31253==    by 0xF7EF94E: js::SetPrototype(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>)+46 (checkouts/gecko/js/src/vm/JSObject.cpp:2007)
[task 2023-06-02T10:29:15.212Z] 10:29:15     INFO -  ==31253==    by 0xBAA53B1: XPCWrappedNative::WrapNewGlobal(JSContext*, xpcObjectHelper&, nsIPrincipal*, bool, JS::RealmOptions&, XPCWrappedNative**)+689 (checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:212)
[task 2023-06-02T10:29:15.212Z] 10:29:15     INFO -  ==31253==    by 0xBA9CE5F: xpc::InitClassesWithNewWrappedGlobal(JSContext*, nsISupports*, nsIPrincipal*, unsigned int, JS::RealmOptions&, JS::MutableHandle<JSObject*>)+159 (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:556)
[task 2023-06-02T10:29:15.212Z] 10:29:15     INFO -  ==31253==    by 0xBA52F03: mozJSModuleLoader::CreateLoaderGlobal(JSContext*, nsTSubstring<char> const&, JS::MutableHandle<JSObject*>)+259 (checkouts/gecko/js/xpconnect/loader/mozJSModuleLoader.cpp:608)
[task 2023-06-02T10:29:15.212Z] 10:29:15     INFO -  ==31253==    by 0xBA5323F: mozJSModuleLoader::GetSharedGlobal(JSContext*)+175 (checkouts/gecko/js/xpconnect/loader/mozJSModuleLoader.cpp:650)
[task 2023-06-02T10:29:15.213Z] 10:29:15     INFO -  ==31253==    by 0xBA84E0C: XPCJSRuntime::LoaderGlobal()+92 (checkouts/gecko/js/xpconnect/src/XPCJSRuntime.cpp:3161)
[task 2023-06-02T10:29:15.213Z] 10:29:15     INFO -  ==31253==    by 0xBA5E175: mozilla::ScriptPreloader::InitCache(nsTSubstring<char16_t> const&)+101 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:454)
[task 2023-06-02T10:29:15.213Z] 10:29:15     INFO -  ==31253==    by 0xBA5CA20: mozilla::ScriptPreloader::GetChildSingleton()+272 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:160)
[task 2023-06-02T10:29:15.213Z] 10:29:15     INFO -  ==31253==    by 0xBA5E05E: mozilla::ScriptPreloader::GetSingleton()+238 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:122)
[task 2023-06-02T10:29:15.214Z] 10:29:15     INFO -  ==31253==    by 0xBAB0345: InitJSContext (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:102)
[task 2023-06-02T10:29:15.214Z] 10:29:15     INFO -  ==31253==    by 0xBAB0345: xpc::InitializeJSContext()+53 (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:107)
[task 2023-06-02T10:29:15.214Z] 10:29:15     INFO -  ==31253==    by 0xF606CAF: XREMain::XRE_mainRun()+1231 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5364)
[task 2023-06-02T10:29:15.214Z] 10:29:15     INFO -  ==31253==    by 0xF607C13: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)+1235 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5859)
[task 2023-06-02T10:29:15.215Z] 10:29:15     INFO -  ==31253==    by 0xF607FA1: XRE_main(int, char**, mozilla::BootstrapConfig const&)+193 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5915)
[task 2023-06-02T10:29:15.215Z] 10:29:15     INFO -  ==31253==    by 0x12D839: do_main (checkouts/gecko/browser/app/nsBrowserApp.cpp:227)```
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]
Flags: needinfo?(jcoppeard)

I've been looking into this but I don't know what's happening here.

This seems to be failing > 50% of the time on infra, but I haven't yet reproduced it locally in 9 successful runs so far.

The path in the valgrind warning for the leak is exercised a bunch of times when creating a global so it's strange that only 1 block is being reported lost per global. Also this is a commonly used path so it's strange that this memory is not being reported lost in other ways (i.e. leakcheck).

Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

I haven't got any further with working out what's going on here.

The JS engine does its own memory accounting checks in debug builds and I turned this on for the valgrind build to see if it detected the leak, but it did not.

Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

I haven't been able to track down what's going on here.

I don't think this is related to the changes in bug 1828455 as this would have caused leaks to show up elsewhere as this is a pervasive change.

The presence of mozJSModuleLoader::CreateLoaderGlobal in the allocation stack is suggestive as there is custom code to unlink this on shutdown to prevent a memory leak. I wasn't able to find anything actually wrong though.

Assignee: jcoppeard → nobody
Flags: needinfo?(jcoppeard)

There have been 69 total failures in the last 7 days. All of them are Linux x64 WebRender opt related.

Recent failure log.

[task 2023-06-26T02:54:44.262Z] 02:54:44     INFO -  ==27663== HEAP SUMMARY:
[task 2023-06-26T02:54:44.262Z] 02:54:44     INFO -  ==27663==     in use at exit: 11,257,224 bytes in 65,296 blocks
[task 2023-06-26T02:54:44.263Z] 02:54:44     INFO -  ==27663==   total heap usage: 6,612,902 allocs, 6,547,606 frees, 4,063,563,201 bytes allocated
[task 2023-06-26T02:54:44.263Z] 02:54:44     INFO -  ==27663==
[task 2023-06-26T02:54:44.301Z] 02:54:44     INFO -  ==27663== Searching for pointers to 64,133 not-freed blocks
[task 2023-06-26T02:54:44.917Z] 02:54:44     INFO -  ==27663== Checked 340,610,128 bytes
[task 2023-06-26T02:54:44.917Z] 02:54:44     INFO -  ==27663==
[task 2023-06-26T02:54:46.009Z] 02:54:46     INFO -  TEST-UNEXPECTED-FAIL | valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc
[task 2023-06-26T02:54:46.009Z] 02:54:46     INFO -  ==27663== 16 bytes in 1 blocks are definitely lost in loss record 4,089 of 21,974
[task 2023-06-26T02:54:46.009Z] 02:54:46     INFO -  ==27663==    at 0x48397B5: malloc+117 (vg_replace_malloc.c:393)
[task 2023-06-26T02:54:46.009Z] 02:54:46     INFO -  ==27663==    by 0xFA14C93: js_arena_malloc (dist/include/js/Utility.h:366)
[task 2023-06-26T02:54:46.009Z] 02:54:46     INFO -  ==27663==    by 0xFA14C93: js_pod_arena_malloc<unsigned char> (dist/include/js/Utility.h:576)
[task 2023-06-26T02:54:46.009Z] 02:54:46     INFO -  ==27663==    by 0xFA14C93: maybe_pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:57)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xFA14C93: pod_arena_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:109)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xFA14C93: pod_malloc<unsigned char> (checkouts/gecko/js/src/vm/MallocProvider.h:127)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xFA14C93: js::Nursery::allocateBuffer(JS::Zone*, JSObject*, unsigned long)+67 (checkouts/gecko/js/src/gc/Nursery.cpp:624)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xF66FD81: AllocateObjectBuffer<js::HeapSlot> (checkouts/gecko/js/src/gc/Nursery-inl.h:113)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xF66FD81: allocateSlots (checkouts/gecko/js/src/vm/NativeObject.cpp:348)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xF66FD81: js::NativeObject::setOrUpdateUniqueId(JSContext*, unsigned long)+65 (checkouts/gecko/js/src/vm/NativeObject.cpp:241)
[task 2023-06-26T02:54:46.010Z] 02:54:46     INFO -  ==27663==    by 0xF71E559: SetObjectIsUsedAsPrototype (checkouts/gecko/js/src/vm/Shape.cpp:1015)
[task 2023-06-26T02:54:46.011Z] 02:54:46     INFO -  ==27663==    by 0xF71E559: JSObject::setProtoUnchecked(JSContext*, JS::Handle<JSObject*>, JS::Handle<js::TaggedProto>)+121 (checkouts/gecko/js/src/vm/Shape.cpp:1039)
[task 2023-06-26T02:54:46.011Z] 02:54:46     INFO -  ==27663==    by 0xF64B55F: js::SetPrototype(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>, JS::ObjectOpResult&)+575 (checkouts/gecko/js/src/vm/JSObject.cpp:1980)
[task 2023-06-26T02:54:46.011Z] 02:54:46     INFO -  ==27663==    by 0xF64B5DE: js::SetPrototype(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>)+46 (checkouts/gecko/js/src/vm/JSObject.cpp:1989)
[task 2023-06-26T02:54:46.011Z] 02:54:46     INFO -  ==27663==    by 0xB9B3141: XPCWrappedNative::WrapNewGlobal(JSContext*, xpcObjectHelper&, nsIPrincipal*, bool, JS::RealmOptions&, XPCWrappedNative**)+689 (checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:212)
[task 2023-06-26T02:54:46.011Z] 02:54:46     INFO -  ==27663==    by 0xB9AABC4: xpc::InitClassesWithNewWrappedGlobal(JSContext*, nsISupports*, nsIPrincipal*, unsigned int, JS::RealmOptions&, JS::MutableHandle<JSObject*>)+164 (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:558)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB960A46: mozJSModuleLoader::CreateLoaderGlobal(JSContext*, nsTSubstring<char> const&, JS::MutableHandle<JSObject*>)+278 (checkouts/gecko/js/xpconnect/loader/mozJSModuleLoader.cpp:608)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB960D7F: mozJSModuleLoader::GetSharedGlobal(JSContext*)+175 (checkouts/gecko/js/xpconnect/loader/mozJSModuleLoader.cpp:650)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB992A2C: XPCJSRuntime::LoaderGlobal()+92 (checkouts/gecko/js/xpconnect/src/XPCJSRuntime.cpp:3157)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB96BBD5: mozilla::ScriptPreloader::InitCache(nsTSubstring<char16_t> const&)+101 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:454)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB96A5B0: mozilla::ScriptPreloader::GetChildSingleton()+272 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:160)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB96BABE: mozilla::ScriptPreloader::GetSingleton()+238 (checkouts/gecko/js/xpconnect/loader/ScriptPreloader.cpp:122)
[task 2023-06-26T02:54:46.012Z] 02:54:46     INFO -  ==27663==    by 0xB9BE135: InitJSContext (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:102)
[task 2023-06-26T02:54:46.013Z] 02:54:46     INFO -  ==27663==    by 0xB9BE135: xpc::InitializeJSContext()+53 (checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:107)
[task 2023-06-26T02:54:46.013Z] 02:54:46     INFO -  ==27663==    by 0xF46F0AF: XREMain::XRE_mainRun()+1231 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5376)
[task 2023-06-26T02:54:46.013Z] 02:54:46     INFO -  ==27663==    by 0xF470013: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)+1235 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5872)
[task 2023-06-26T02:54:46.013Z] 02:54:46     INFO -  ==27663==    by 0xF4703A1: XRE_main(int, char**, mozilla::BootstrapConfig const&)+193 (checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5928)
[task 2023-06-26T02:54:46.013Z] 02:54:46     INFO -  ==27663==    by 0x12D839: do_main (checkouts/gecko/browser/app/nsBrowserApp.cpp:227)
[task 2023-06-26T02:54:46.013Z] 02:54:46     INFO -  ==27663==    by 0x12D839: main+1065 (checkouts/gecko/browser/app/nsBrowserApp.cpp:445)

Hello Will! Any chance you could help us assign this to someone?

Thank you!

Flags: needinfo?(wmedina)
Summary: High frequency valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc → High frequency Linux valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

Update

There have been 33 failures within the last 7 days, all of them on Linux x64 WebRender opt.

Recent log: https://treeherder.mozilla.org/logviewer?job_id=422877489&repo=mozilla-central&lineNumber=71111

Flags: needinfo?(wmedina) → needinfo?(jcoppeard)

Update

There have been 54 failures within the last 7 days, all of them on Linux x64 WebRender opt.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=424268144&repo=autoland&lineNumber=71357

Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

Update

There have been 40 total failures within the last 7 days, all of them on Linux x64 WebRender opt.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=425063843&repo=mozilla-central&lineNumber=72394

Jon, do you have a bit of time to look into this?
It has reached our disable-recommended queue.
Thank you.

Flags: needinfo?(jcoppeard)
Flags: needinfo?(jcoppeard)

Update

There have been 65 failures within the last 7 days, on Linux x64 WebRender opt.

Recent log: https://treeherder.mozilla.org/logviewer?job_id=427155694&repo=mozilla-central&lineNumber=73327

This is permafailing now, and it seems that this is going on for some time now. Last green run of this valgrind job(at least on mozilla-central) was here.

Summary: High frequency Linux valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc → Perma Linux valgrind-test | 16 bytes in 1 blocks are definitely lost at malloc / js_arena_malloc / js_pod_arena_malloc / maybe_pod_arena_malloc

(In reply to Jon Coppeard (:jonco) from comment #29)
I've spent some more time looking into this bug haven't got beyond my previous investigation.

It looks like there was always some kind of memory leak going on but it is only since bug 1828455 that it is causing the test to fail in this way.

Flags: needinfo?(jcoppeard)
Severity: -- → S3
Priority: -- → P2

Mike, could you add a suppression for this, please?

Flags: needinfo?(mh+mozilla)

After looking at this from many different sides and being very close to patch valgrind to try to dig deeper, it just struck me what's happening: All the "leaked" allocations are 16 bytes. All the slot allocations larger than 16 bytes are also detected as possible leaks by valgrind, but it doesn't display them because we don't make valgrind show them by default.
So, why are those slot allocations designated as (possible) leaks? Because nothing is storing their pointer. What's stored is a pointer inside the allocation, and valgrind considers that in its leak analysis: when it sees no pointer to the allocation but a pointer inside it, it counts it as a possible leak rather than a definite one.
So what's stored? A pointer sizeof(ObjectSlots) in the allocation (per https://searchfox.org/mozilla-central/rev/6602bdf9fff5020fbc8e248c963ddddf09a77b1b/js/src/vm/NativeObject.h#515). What is sizeof(ObjectSlots)? 16. See where this is going? Yep, 16 "inside" an allocation of 16 is... outside the allocation. So for valgrind, there is no pointer inside the allocation, so it's a definite leak.
OTOH, what this means is that it's essentially empty slots, so there's no point for that allocation in the first place.

Flags: needinfo?(mh+mozilla)

And sure enough, bug 1828455 added https://searchfox.org/mozilla-central/rev/6602bdf9fff5020fbc8e248c963ddddf09a77b1b/js/src/vm/NativeObject.cpp#241 which would explain why it made it permanent. I suppose there are other cases where you can end up with capacity = 0 that would have caused this intermittently in the past. So yes, it would seem like suppressions would be the only course of action, on the other hand, there doesn't seem to be one unique specific code path that could be used for a suppression that would pinpoint to slot allocations specifically.

Flags: needinfo?(jcoppeard)

(In reply to Mike Hommey [:glandium] from comment #83)
Thank you for figuring this out! I must admit it didn't occur to me that we were in fact storing a pointer past the end of the allocation for zero capacity dynamic slots.

For objects with dynamic slots allocations, NativeObject::slots_ stores a
pointer that points just past the end of the slots header. For zero-capacity
allocations this pointer points outside the allocation itself.

Currently this causes valgrind to think that the slots allocation is leaked. To
fix this the patch adds an extra unused slot to zero capacity slots allocations
on valgrind builds only.

The above patch fixes the leak warning related to the JS engine.

Recently another leak has appeared in the logs however, so that patch won't make this green again on its own:

[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  TEST-UNEXPECTED-FAIL | valgrind-test | 40 (24 direct, 16 indirect) bytes in 1 blocks are definitely lost at malloc / moz_xmalloc / operator / nsDynamicAtom::Create
[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  ==30205== 40 (24 direct, 16 indirect) bytes in 1 blocks are definitely lost in loss record 10,944 of 21,975
[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  ==30205==    at 0x48407B4: malloc+116 (vg_replace_malloc.c:393)
[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  ==30205==    by 0x12F3ED: moz_xmalloc+13 (checkouts/gecko/memory/mozalloc/mozalloc.cpp:52)
[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  ==30205==    by 0xA78EBE6: operator new (dist/include/mozilla/cxxalloc.h:33)
[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  ==30205==    by 0xA78EBE6: nsDynamicAtom::Create(nsTSubstring<char16_t> const&, unsigned int)+150 (checkouts/gecko/xpcom/ds/nsAtomTable.cpp:100)
[task 2023-09-27T11:33:09.929Z] 11:33:09     INFO -  ==30205==    by 0xA78F9E8: nsAtomTable::Atomize(nsTSubstring<char> const&)+264 (checkouts/gecko/xpcom/ds/nsAtomTable.cpp:569)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xA88F5B7: nsLanguageAtomService::LookupLanguage(nsTSubstring<char> const&)+87 (checkouts/gecko/intl/locale/nsLanguageAtomService.cpp:102)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xB398B1A: gfxFcPlatformFontList::TryLangForGroup(nsTSubstring<char> const&, nsAtom*, nsTSubstring<char>&, bool)+378 (checkouts/gecko/gfx/thebes/gfxFcPlatformFontList.cpp:2710)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xB393AE1: gfxFcPlatformFontList::GetSampleLangForGroup(nsAtom*, nsTSubstring<char>&, bool)+753 (checkouts/gecko/gfx/thebes/gfxFcPlatformFontList.cpp:2775)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xB396A71: gfxFcPlatformFontList::FindGenericFamilies(nsPresContext*, nsTString<char> const&, nsAtom*)+113 (checkouts/gecko/gfx/thebes/gfxFcPlatformFontList.cpp:2499)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xB3969B1: gfxFcPlatformFontList::GetDefaultFontForPlatform(nsPresContext*, gfxFontStyle const*, nsAtom*)+81 (checkouts/gecko/gfx/thebes/gfxFcPlatformFontList.cpp:2134)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xB3F61DF: gfxPlatformFontList::GetDefaultFontLocked(nsPresContext*, gfxFontStyle const*)+47 (checkouts/gecko/gfx/thebes/gfxPlatformFontList.cpp:2487)
[task 2023-09-27T11:33:09.930Z] 11:33:09     INFO -  ==30205==    by 0xB3F3DE4: gfxPlatformFontList::InitFontList()+1172 (checkouts/gecko/gfx/thebes/gfxPlatformFontList.cpp:638)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xB3F3815: gfxPlatformFontList::Initialize(gfxPlatformFontList*)+69 (checkouts/gecko/gfx/thebes/gfxPlatformFontList.cpp:282)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xB3A0300: gfxPlatform::Init()+2880 (checkouts/gecko/gfx/thebes/gfxPlatform.cpp:976)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xB39F78F: gfxPlatform::GetPlatform()+31 (checkouts/gecko/gfx/thebes/gfxPlatform.cpp:461)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xD43A1E1: mozilla::widget::GfxInfoBase::GetContentBackend(nsTSubstring<char16_t>&)+33 (checkouts/gecko/widget/GfxInfoBase.cpp:1852)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xA819265: ??? (xptcinvoke_asm_x86_64_unix.S:101)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xAFAAB0A: Invoke (checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1627)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xAFAAB0A: Call (checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1180)
[task 2023-09-27T11:33:09.931Z] 11:33:09     INFO -  ==30205==    by 0xAFAAB0A: XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode)+3994 (checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1126)
[task 2023-09-27T11:33:09.932Z] 11:33:09     INFO -  ==30205==    by 0xAFAC37A: GetAttribute (checkouts/gecko/js/xpconnect/src/xpcprivate.h:1450)

The first failing build was this one on 27th September: https://treeherder.mozilla.org/jobs?repo=autoland&revision=a1a8c2eeff55a4651fa01530fa3ec3ab3bec9b31&selectedTaskRun=GhnCLs_wTdG21wt9dlWCAA.0

Flags: needinfo?(jcoppeard)

(In reply to Jon Coppeard (:jonco) from comment #87)

Recently another leak has appeared in the logs however, so that patch won't make this green again on its own:

That one was fixed in https://hg.mozilla.org/mozilla-central/rev/54e0ec2f1ca453575bbc7895bba5138e054f634b

Pushed by jcoppeard@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/027cbc1f6378
Stop valgrind thinking zero-capacity slots allocations are leaked r=jandem
Assignee: nobody → jcoppeard
Status: NEW → RESOLVED
Closed: 9 months ago
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → 120 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: