1828427 - Assertion failure: !waitFor.IsZero(), at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/threads/TimerThread.cpp:854

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[:gerard-majax]

 0:02.00 GECKO(3170968) ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmprc_f5je1.mozrunner/runtests_leaks.log
 0:02.00 GECKO(3170968) [3170968, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /home/alex/codaz/Mozilla/gecko-cinnabar/tools/profiler/core/platform.cpp:345
 0:02.00 GECKO(3170968) *** You are running in chaos test mode. See ChaosMode.h. ***
 0:02.00 GECKO(3170968) *** You are running in headless mode.
 0:03.00 GECKO(3170968) [3170968, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsXREDirProvider.cpp:475
 0:03.00 GECKO(3170968) [3170968, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsXREDirProvider.cpp:475
 0:03.02 GECKO(3170968) [Parent 3170968, Main Thread] WARNING: Rejected attempt to change type of pref extensions.formautofill.creditCards.available's user value from bool to string: file /home/alex/codaz/Mozilla/gecko-cinnabar/modules/libpref/Preferences.cpp:1896
 0:03.05 GECKO(3170968) [Parent 3170968, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsXREDirProvider.cpp:475
 0:03.08 GECKO(3170968) [Parent 3170968, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsXREDirProvider.cpp:475
 0:03.08 GECKO(3170968) [Parent 3170968, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsXREDirProvider.cpp:475
 0:03.79 GECKO(3170968) [WARN  rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
 0:03.82 GECKO(3170968) Assertion failure: !waitFor.IsZero(), at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/threads/TimerThread.cpp:854
Initializing stack-fixing for the first stack frame, this may take a while...
 0:18.23 GECKO(3170968) #01: TimerThread::Run() (/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/threads/TimerThread.cpp:854)
 0:18.23 GECKO(3170968) #02: nsThread::ProcessNextEvent(bool, bool*) (/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/threads/nsThread.cpp:1234)
 0:18.24 GECKO(3170968) #03: NS_ProcessNextEvent(nsIThread*, bool) (/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/threads/nsThreadUtils.cpp:479)
 0:18.24 GECKO(3170968) #04: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) (/home/alex/codaz/Mozilla/gecko-cinnabar/ipc/glue/MessagePump.cpp:301)
 0:18.24 GECKO(3170968) #05: MessageLoop::Run() (/home/alex/codaz/Mozilla/gecko-cinnabar/ipc/chromium/src/base/message_loop.cc:345)
 0:18.24 GECKO(3170968) #06: nsThread::ThreadFunc(void*) (/home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/threads/nsThread.cpp:393)
 0:18.26 GECKO(3170968) #07: _pt_root (/home/alex/codaz/Mozilla/gecko-cinnabar/nsprpub/pr/src/pthreads/ptthread.c:204)
 0:18.32 GECKO(3170968) #08: set_alt_signal_stack_and_start(PthreadCreateParams*) (/home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/crashreporter/pthread_create_interposer/pthread_create_interposer.cpp:80)
 0:18.32 GECKO(3170968) #09: ??? (/lib/x86_64-linux-gnu/libc.so.6 + 0x90402)
 0:18.32 GECKO(3170968) #10: ??? (/lib/x86_64-linux-gnu/libc.so.6 + 0x11f590)
 0:18.32 GECKO(3170968) #11: ??? (???:???)
 0:18.32 GECKO(3170968) ExceptionHandler::GenerateDump cloned child 3171009
 0:18.32 GECKO(3170968) ExceptionHandler::SendContinueSignalToChild sent continue signal to child
 0:18.32 GECKO(3170968) ExceptionHandler::WaitForContinueSignal waiting for continue signal...

Happened to me trying to work on bug 1827894: MOZ_CHAOSMODE=0 BUILD_DEBUG=1 ./mach test --headless dom/canvas/test/webgl-conf/generated/test_2_conformance__textures__image_bitmap_from_video__tex-2d-alpha-alpha-unsigned_byte.html

 2:02.11 CRASH: pid:3170821. Test:automation.py. Minidump analysed:False. Signature:[@ libxul.so + 0x0000000005c69135]
Mozilla crash reason: MOZ_ASSERT(!waitFor.IsZero())
Crash dump filename: /tmp/tmprc_f5je1.mozrunner/minidumps/1cd7a3f5-2cf8-8651-9bbd-74612187c721.dmp
Operating system: Linux
                  5.19.0-35-generic #36-Ubuntu SMP PREEMPT_DYNAMIC Fri Feb 3 18:36:56 UTC 2023
CPU: amd64
     family 25 model 80 stepping 0
     16 CPUs
Linux Ubuntu 22.10 - kinetic (Ubuntu 22.10)

Crash reason:  SIGSEGV / SEGV_MAPERR
Crash address: 0x0
Crashing instruction: `mov dword [0x0], 0x356`
Memory accessed by instruction:
  0. Address: 0x0000000000000000
     Size: 4
Process uptime: not available

Thread 9 Timer (crashed)
 0  libxul.so + 0x5c69135
     rax = 0x00007f62c3b0b921    rdx = 0x0000000000000001
     rcx = 0x0000563f143b9420    rbx = 0x0000000000000001
     rsi = 0x0000000000000001    rdi = 0x00007f62d55f8a00
     rbp = 0x00007f62c1a71910    rsp = 0x00007f62c1a71460
      r8 = 0x0000000000000000     r9 = 0x0000000000000003
     r10 = 0x0000000000000002    r11 = 0x0000000000000293
     r12 = 0x0000000000000000    r13 = 0x0000000000000008
     r14 = 0x00007f62d53a8300    r15 = 0x0000000000000000
     rip = 0x00007f62c8469135
    Found by: given as instruction pointer in context
 1  libxul.so + 0x5c6fed1
     rbp = 0x00007f62c1a71a70    rsp = 0x00007f62c1a71920
     rip = 0x00007f62c846fed2
    Found by: previous frame's frame pointer
 2  libxul.so + 0x5c73987
     rbp = 0x00007f62c1a71aa0    rsp = 0x00007f62c1a71a80
     rip = 0x00007f62c8473988
    Found by: previous frame's frame pointer
 3  libxul.so + 0x64f5441
     rbp = 0x00007f62c1a71af0    rsp = 0x00007f62c1a71ab0
     rip = 0x00007f62c8cf5442
    Found by: previous frame's frame pointer
 4  libxul.so + 0x646728c
     rbp = 0x00007f62c1a71b30    rsp = 0x00007f62c1a71b00
     rip = 0x00007f62c8c6728d
    Found by: previous frame's frame pointer
 5  libxul.so + 0x5c6c9b3
     rbp = 0x00007f62c1a71d90    rsp = 0x00007f62c1a71b40
     rip = 0x00007f62c846c9b4
    Found by: previous frame's frame pointer
 6  libnspr4.so + 0x36d29
     rbp = 0x00007f62c1a71de0    rsp = 0x00007f62c1a71da0
     rip = 0x00007f62d5aaad2a
    Found by: previous frame's frame pointer
 7  firefox + 0xeee09
     rbp = 0x00007f62c1a71e90    rsp = 0x00007f62c1a71df0
     rip = 0x0000563f143b2e0a
    Found by: previous frame's frame pointer
 8  libnspr4.so + 0x36bb4
     rbp = 0x00007f62c1a71e90    rsp = 0x00007f62c1a71e30
     rip = 0x00007f62d5aaabb5
    Found by: stack scanning
 9  libc.so.6 + 0x90401
     rsp = 0x00007f62c1a71ea0    rip = 0x00007f62d5490402
    Found by: stack scanning
10  libc.so.6 + 0x9010f
     rsp = 0x00007f62c1a71f30    rip = 0x00007f62d5490110
    Found by: stack scanning
11  libc.so.6 + 0x11f58f
     rsp = 0x00007f62c1a71f40    rip = 0x00007f62d551f590
    Found by: stack scanning

Comment 1

[:gerard-majax]

Justin, it looks like some assertion you added in https://phabricator.services.mozilla.com/D173102 for bug 1783405 ?

Comment 2

[:gerard-majax]

So we assert for !waitFor.IsZero() and on https://searchfox.org/mozilla-central/rev/31f5847a4494b3646edabbdd7ea39cb88509afe2/xpcom/threads/TimerThread.cpp#853 we set it with the value from https://searchfox.org/mozilla-central/rev/31f5847a4494b3646edabbdd7ea39cb88509afe2/xpcom/threads/TimerThread.cpp#850-852 that depends on https://searchfox.org/mozilla-central/rev/31f5847a4494b3646edabbdd7ea39cb88509afe2/xpcom/threads/TimerThread.cpp#849 and https://searchfox.org/mozilla-central/rev/31f5847a4494b3646edabbdd7ea39cb88509afe2/xpcom/threads/TimerThread.cpp#816-817

So it means if ChaosMode::randomUint32LessThan(ArrayLength(sChaosFractions)) gets us 0 then we use the first element of double sChaosFractions[] = {0.0, 0.25, 0.5, 0.75, 1.0, 1.75, 2.75}; which is 0. I'm not sure what is the correct fix here, but that looks like we can have waitFor to be 0.

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 4

[Justin Link]

Thanks for pointing this out. In this case, I think that it is the assert that is in error. As you point out, in chaos mode, it is completely expected that the sleep time might be zero. I will remove it.

Comment 5

[Justin Link]

Attachment: Bug 1828427 - Removed incorrect assertion r=smaug,gerard-majax

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c8e2af0e23e7
Removed incorrect assertion r=gerard-majax

Comment 7

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/c8e2af0e23e7