Closed Bug 1851938 Opened 1 years ago Closed 1 year ago

Intermittent application crashed [@ js::SharedImmutableStringsCache::StringBox::~StringBox] | single tracking bug

Categories

(Core :: JavaScript Engine, defect, P3)

defect

Tracking

()

RESOLVED FIXED
119 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox-esr115 --- unaffected
firefox117 --- unaffected
firefox118 --- unaffected
firefox119 --- fixed

People

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

References

(Blocks 1 open bug)

Details

(Keywords: crash, intermittent-failure, intermittent-testcase)

Crash Data

Attachments

(1 file, 1 obsolete file)

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


[task 2023-09-07T00:09:28.868Z] 00:09:28     INFO -  TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_xorigin_frame.js
[task 2023-09-07T00:09:28.913Z] 00:09:28  WARNING -  PROCESS-CRASH | application crashed [@ js::SharedImmutableStringsCache::StringBox::~StringBox] | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_contentscript_triggeringPrincipal.js
[task 2023-09-07T00:09:28.924Z] 00:09:28     INFO -  Process type: unknown
[task 2023-09-07T00:09:28.924Z] 00:09:28     INFO -  Process pid: 3860
[task 2023-09-07T00:09:28.924Z] 00:09:28     INFO -  Crash dump filename: C:\Users\task_169404297164491\AppData\Local\Temp\xpc-other-nugxomx0\1b5e7f04-f4f2-4c03-a420-f9d5d226003d.dmp
[task 2023-09-07T00:09:28.924Z] 00:09:28     INFO -  Operating system: Windows NT
[task 2023-09-07T00:09:28.924Z] 00:09:28     INFO -                    10.0.22621
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  CPU: amd64
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -       family 6 model 106 stepping 6
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -       8 CPUs
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  Crash address: 0x7fff0363fe6f
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  Crashing instruction: `int 0x3`
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  No memory accessed by instruction
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  Process uptime: 1 seconds
[task 2023-09-07T00:09:28.925Z] 00:09:28     INFO -  Thread 0 MainThread (crashed)
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -   0  xul.dll!js::SharedImmutableStringsCache::StringBox::~StringBox(void) + 0x8f
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -       rax = 0x00007fff0b8d318f    rdx = 0x0000000000000000
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -       rcx = 0x00007fff1b4ee2c0    rbx = 0x0000000000000010
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -       rsi = 0x0000026b4e6e93e0    rdi = 0x0000026b4c947208
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -       rbp = 0x00000000000003d0    rsp = 0x000000b52c1ff620
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -        r8 = 0x00000000000000ac     r9 = 0x00000000000000ab
[task 2023-09-07T00:09:28.926Z] 00:09:28     INFO -       r10 = 0x00000000ffffebff    r11 = 0x00000000000ca459
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -       r12 = 0x000000000000001b    r13 = 0x0000000000000003
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -       r14 = 0x0000000000000001    r15 = 0x0000026b43d03090
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -       rip = 0x00007fff0363fe6f
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -      Found by: given as instruction pointer in context
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -   1  xul.dll!mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> >::reset(js::SharedImmutableStringsCache::StringBox*) + 0x93
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -       rbx = 0x0000000000000010    rbp = 0x00000000000003d0
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -       rsp = 0x000000b52c1ff650    r12 = 0x000000000000001b
[task 2023-09-07T00:09:28.927Z] 00:09:28     INFO -       r13 = 0x0000000000000003    r14 = 0x0000000000000001
[task 2023-09-07T00:09:28.928Z] 00:09:28     INFO -       r15 = 0x0000026b43d03090    rip = 0x00007fff0363fdb4
[task 2023-09-07T00:09:28.928Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.929Z] 00:09:28     INFO -   2  xul.dll!mozilla::detail::HashTable<mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> > const, mozilla::HashSet<mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> >, js::SharedImmutableStringsCache::Hasher, js::SystemAllocPolicy>::SetHashPolicy, js::SystemAllocPolicy>::forEachSlot<`mozilla::detail::HashTable<mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> > const, mozilla::HashSet<mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> >, js::SharedImmutableStringsCache::Hasher, js::SystemAllocPolicy>::SetHashPolicy, js::SystemAllocPolicy>::destroyTable(js::SystemAllocPolicy&, char*, unsigned int)'::`1'::<lambda_1> >(char*, unsigned int, `mozilla::detail::HashTable<mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> > const, mozilla::HashSet<mozilla::UniquePtr<js::SharedImmutableStringsCache::StringBox, JS::DeletePolicy<js::SharedImmutableStringsCache::StringBox> >, js::SharedImmutableStringsCache::Hasher, js::SystemAllocPolicy>::SetHashPolicy, js::SystemAllocPolicy>::destroyTable(js::SystemAllocPolicy&, char*, unsigned int)'::`1'::<lambda_1>&&) + 0xae
[task 2023-09-07T00:09:28.929Z] 00:09:28     INFO -       rbx = 0x0000000000000010    rsi = 0x0000026b4c9471c0
[task 2023-09-07T00:09:28.929Z] 00:09:28     INFO -       rbp = 0x00000000000003d0    rsp = 0x000000b52c1ff680
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       r12 = 0x000000000000001b    r13 = 0x0000000000000003
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       r14 = 0x0000000000000001    r15 = 0x0000026b43d03090
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       rip = 0x00007fff037d834f
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -   3  xul.dll!js::SharedImmutableStringsCache::free(void) + 0xa4
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       rbx = 0x0000026b4c9471c0    rsi = 0x00007fff0d4a3d80
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       rdi = 0x0000026b4c90b060    rbp = 0x00000000000003d0
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       rsp = 0x000000b52c1ff6d0    r12 = 0x000000000000001b
[task 2023-09-07T00:09:28.930Z] 00:09:28     INFO -       r13 = 0x0000000000000003    r14 = 0x000000b52c1ff878
[task 2023-09-07T00:09:28.931Z] 00:09:28     INFO -       r15 = 0x0000026b43d03090    rip = 0x00007fff037a7375
[task 2023-09-07T00:09:28.931Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.931Z] 00:09:28     INFO -   4  xul.dll!JS_ShutDown(void) + 0x20
[task 2023-09-07T00:09:28.931Z] 00:09:28     INFO -       rbx = 0x000000b52c1ff780    rsi = 0x0000000000000000
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -       rdi = 0x0000026b43da8040    rbp = 0x00000000000003d0
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -       rsp = 0x000000b52c1ff720    r12 = 0x000000000000001b
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -       r13 = 0x0000000000000003    r14 = 0x000000b52c1ff878
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -       r15 = 0x0000026b43d03090    rip = 0x00007fff0354f8b1
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -   5  xul.dll!mozilla::ShutdownXPCOM(nsIServiceManager*) + 0x762
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -       rbx = 0x000000b52c1ff780    rsi = 0x0000000000000000
[task 2023-09-07T00:09:28.932Z] 00:09:28     INFO -       rbp = 0x00000000000003d0    rsp = 0x000000b52c1ff750
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -       r12 = 0x000000000000001b    r13 = 0x0000000000000003
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -       r14 = 0x000000b52c1ff878    r15 = 0x0000026b43d03090
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -       rip = 0x00007ffefa9b7e73
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -   6  xul.dll!XRE_InitChildProcess(int, char** const, XREChildData const*) + 0x870
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -       rbx = 0x000000000ca60401    rsi = 0x0000000000000001
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -       rdi = 0x0000026b43d51970    rbp = 0x00000000000003d0
[task 2023-09-07T00:09:28.933Z] 00:09:28     INFO -       rsp = 0x000000b52c1ff840    r12 = 0x000000000000001b
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -       r13 = 0x0000000000000003    r14 = 0x000000b52c1ff878
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -       r15 = 0x0000026b43d03090    rip = 0x00007fff031e1cf1
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -   7  plugin-container.exe!NS_internal_main(int, char**) + 0x22b
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -       rbx = 0x0000026b43d030d0    rsi = 0x0000026b43d05040
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -       rdi = 0x000000000000001a    rbp = 0x0000026b43d030b0
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -       rsp = 0x000000b52c1ffae0    r12 = 0x000000000000001b
[task 2023-09-07T00:09:28.934Z] 00:09:28     INFO -       r13 = 0x0000000000000003    r14 = 0x00000000000000d8
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -       r15 = 0x000000000000001b    rip = 0x00007ff63d2c155c
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -   8  plugin-container.exe!wmain + 0x26e
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -       rbx = 0x0000026b43d05040    rsi = 0x0000000000000000
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -       rdi = 0x0000026b43d05200    rbp = 0x0000026b43d030b0
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -       rsp = 0x000000b52c1ffb50    r12 = 0x000000000000001b
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -       r13 = 0x0000000000000003    r14 = 0x00000000000000d8
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -       r15 = 0x000000000000001b    rip = 0x00007ff63d2c126f
[task 2023-09-07T00:09:28.935Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -   9  plugin-container.exe!invoke_main() [exe_common.inl : 90]
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -      Found by: inlining
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -  10  plugin-container.exe!__scrt_common_main_seh() [exe_common.inl : 288 + 0x21]
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -       rbx = 0x0000026b439d6d00    rsi = 0x0000000000000000
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -       rdi = 0x0000026b439e1d10    rbp = 0x0000000000000000
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -       rsp = 0x000000b52c1ffc00    r12 = 0x0000000000000000
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -       r15 = 0x0000000000000000    rip = 0x00007ff63d2c3bb8
[task 2023-09-07T00:09:28.936Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -  11  kernel32.dll!BaseThreadInitThunk + 0x1c
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -       rbx = 0x0000000000000000    rsi = 0x0000000000000000
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -       rdi = 0x0000000000000000    rbp = 0x0000000000000000
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -       rsp = 0x000000b52c1ffc40    r12 = 0x0000000000000000
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -       r15 = 0x0000000000000000    rip = 0x00007fff420b269d
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -      Found by: call frame info
[task 2023-09-07T00:09:28.937Z] 00:09:28     INFO -  12  ntdll.dll!RtlUserThreadStart + 0x27
[task 2023-09-07T00:09:28.938Z] 00:09:28     INFO -       rbx = 0x0000000000000000    rsi = 0x0000000000000000
[task 2023-09-07T00:09:28.938Z] 00:09:28     INFO -       rdi = 0x0000000000000000    rbp = 0x0000000000000000
[task 2023-09-07T00:09:28.938Z] 00:09:28     INFO -       rsp = 0x000000b52c1ffc70    r12 = 0x0000000000000000
[task 2023-09-07T00:09:28.938Z] 00:09:28     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2023-09-07T00:09:28.938Z] 00:09:28     INFO -       r15 = 0x0000000000000000    rip = 0x00007fff4372a9f8
[task 2023-09-07T00:09:28.938Z] 00:09:28     INFO -      Found by: call frame info

Arai, could this be related to Bug 1786834 ?

So far the problem seems to be related to Windows 11 x64 22H2 CCov WebRender opt Xpcshell tests test-windows11-64-2009-ccov-qr/opt-xpcshell X5.

This might be related with the fact that in CCov builds we might have to keep the children process around to captured the code coverage content. Maybe this has an impact on the shutdown as well as the ref-count of shared immutable strings, which combined with some non-properly terminated runs holds the string cache for too long.

Severity: -- → S4
Flags: needinfo?(arai.unmht)
Priority: -- → P3

it's strange that, now SharedImmutableStringsCache::free is called only when there's no live runtime.
(which had been a problem with leaked runtime case in reftest)

https://searchfox.org/mozilla-central/rev/1cae9ca7cc7d17cfc92088dfc68e5ff391128caa/js/src/vm/SharedImmutableStringsCache.cpp#127-129

void SharedImmutableStringsCache::freeSingleton() {
  if (!JSRuntime::hasLiveRuntimes()) {
    singleton_.free();

So, if the assertion fails, it means there's no live runtime but the string is somehow kept alive.

anyway, I'll experiment with adding debug dump.

looks like the following content script and its URL is kept alive.

https://searchfox.org/mozilla-central/rev/fa219b9c1d6c2c64aa139a848573caa03bc81f25/toolkit/components/extensions/test/xpcshell/test_ext_contentscript_triggeringPrincipal.js#765-773

function getInjectionScript(tests, opts) {
  return `
    ${getElementData}
    ${createElement}
    ${testInlineCSS}
    (${injectElements})(${JSON.stringify(tests)},
                        ${JSON.stringify(opts)});
  `;
}

https://treeherder.mozilla.org/logviewer?job_id=429096323&repo=try&lineNumber=5049

[task 2023-09-14T10:12:27.194Z] 10:12:27     INFO -  PID 9612 | @@@@ refcount(1): moz-extension://a8ff092a-f1d5-4252-a4dd-52530b301e65/content_script.js\x00
[task 2023-09-14T10:12:27.194Z] 10:12:27     INFO -  PID 9612 | @@@@ refcount(1):
[task 2023-09-14T10:12:27.194Z] 10:12:27     INFO -  PID 9612 |     function getElementData(test, opts) {

the raw script source string is held by Stencil, and it's freed when compressing the source, or when a PrecompiledScript is deleted,
and the latter seems to be suspicious.
I'll check if all PrecompiledScript is deleted until that point.

https://searchfox.org/mozilla-central/rev/b741ddde6c678ca7025858952202d20664491555/js/xpconnect/loader/PrecompiledScript.h#27,55

class PrecompiledScript : public nsISupports, public nsWrapperCache {
...
  RefPtr<JS::Stencil> mStencil;

it looks like a stencil is created off-main-thread during shutdown.
that would mean that AsyncScriptCompiler's off-thread compilation task should is running while JS_Shutdown is called.
we should join AsyncScriptCompiler tasks before shutting down.

Assignee: nobody → arai.unmht
Status: NEW → ASSIGNED
Flags: needinfo?(arai.unmht)
See Also: → 1853613
See Also: → 1851146
Pushed by arai_a@mac.com: https://hg.mozilla.org/integration/autoland/rev/2d399b8bfcfc Cancel and join ongoing AsyncScriptCompileTasks during shutdown. r=nbp
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 119 Branch
Regressions: 1853971
Status: RESOLVED → REOPENED
Flags: needinfo?(arai.unmht)
Resolution: FIXED → ---
Target Milestone: 119 Branch → ---
Attachment #9354038 - Attachment is obsolete: true
Attachment #9354038 - Attachment is obsolete: false
Attachment #9353866 - Attachment is obsolete: true
Pushed by arai_a@mac.com: https://hg.mozilla.org/integration/autoland/rev/cd49a95d80fd Cancel and join ongoing AsyncScriptCompileTasks during shutdown. r=nbp
Pushed by arai_a@mac.com: https://hg.mozilla.org/integration/autoland/rev/1946f0a37c26 Cancel and join ongoing AsyncScriptCompileTasks during shutdown. r=nbp
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 119 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: