Closed Bug 1602469 Opened 4 years ago Closed 4 years ago

Intermittent PID 10384 | Assertion failure: NS_IsMainThread() (Should only queue idle runnables on main thread), at z:/build/build/src/xpcom/threads/PrioritizedEventQueue.cpp:69

Categories

(Core :: XPCOM, defect, P5)

Product:
Core
Component:
XPCOM
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1600331

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression,
URL
)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

http log
6.70 MB, text/plain
Details

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

task 2019-12-09T12:05:01.842Z] 12:05:01 INFO - TEST-START | /fetch/stale-while-revalidate/stale-image.html
[task 2019-12-09T12:05:01.861Z] 12:05:01 INFO - Closing window 33
[task 2019-12-09T12:05:02.107Z] 12:05:02 INFO - PID 10384 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-12-09T12:05:02.149Z] 12:05:02 INFO - PID 10384 | [Child 5812, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file z:/build/build/src/layout/base/nsPresContext.cpp, line 847
[task 2019-12-09T12:05:02.472Z] 12:05:02 INFO - PID 10384 | DLL blocklist was unable to intercept AppInit DLLs.
[task 2019-12-09T12:05:02.491Z] 12:05:02 INFO - PID 10384 | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1575890899\appdata\local\temp\tmpvnmwaf.mozrunner\runtests_leaks_10204_tab_pid8100.log
[task 2019-12-09T12:05:02.509Z] 12:05:02 INFO - PID 10384 | [Child 8100, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 727
[task 2019-12-09T12:05:02.671Z] 12:05:02 INFO - PID 10384 | [Child 5812, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1378
[task 2019-12-09T12:05:02.671Z] 12:05:02 INFO - PID 10384 | [Child 5812, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1378
[task 2019-12-09T12:05:02.680Z] 12:05:02 INFO - PID 10384 | nsStringStats
[task 2019-12-09T12:05:02.681Z] 12:05:02 INFO - PID 10384 | => mAllocCount: 29095
[task 2019-12-09T12:05:02.681Z] 12:05:02 INFO - PID 10384 | => mReallocCount: 0
[task 2019-12-09T12:05:02.681Z] 12:05:02 INFO - PID 10384 | => mFreeCount: 29095
[task 2019-12-09T12:05:02.682Z] 12:05:02 INFO - PID 10384 | => mShareCount: 106302
[task 2019-12-09T12:05:02.682Z] 12:05:02 INFO - PID 10384 | => mAdoptCount: 838
[task 2019-12-09T12:05:02.682Z] 12:05:02 INFO - PID 10384 | => mAdoptFreeCount: 842
[task 2019-12-09T12:05:02.682Z] 12:05:02 INFO - PID 10384 | => Process ID: 2700, Thread ID: 9744
[task 2019-12-09T12:05:02.765Z] 12:05:02 INFO - PID 10384 | [Parent 1100, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file z:/build/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-12-09T12:05:03.782Z] 12:05:03 INFO - PID 10384 | Assertion failure: NS_IsMainThread() (Should only queue idle runnables on main thread), at z:/build/build/src/xpcom/threads/PrioritizedEventQueue.cpp:69
[task 2019-12-09T12:05:04.579Z] 12:05:04 INFO - IOError on command, setting status to CRASH
[task 2019-12-09T12:05:04.579Z] 12:05:04 INFO - mozcrash Copy/paste: Z:\task_1575890899\build\win32-minidump_stackwalk.exe c:\users\task_1575890899\appdata\local\temp\tmpvnmwaf.mozrunner\minidumps\4a1df044-b8df-4a01-9297-fe44bc3dd211.dmp Z:\task_1575890899\build\symbols
[task 2019-12-09T12:05:20.369Z] 12:05:20 INFO - mozcrash Saved minidump as Z:\task_1575890899\build\blobber_upload_dir\4a1df044-b8df-4a01-9297-fe44bc3dd211.dmp
[task 2019-12-09T12:05:20.369Z] 12:05:20 INFO - mozcrash Saved app info as Z:\task_1575890899\build\blobber_upload_dir\4a1df044-b8df-4a01-9297-fe44bc3dd211.extra
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - PROCESS-CRASH | /fetch/stale-while-revalidate/stale-image.html | application crashed [@ mozilla::PrioritizedEventQueue::PutEvent(already_AddRefed<nsIRunnable> &&,mozilla::EventQueuePriority,mozilla::BaseAutoLock<mozilla::Mutex &> const &,mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator> *)]
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - Crash dump filename: c:\users\task_1575890899\appdata\local\temp\tmpvnmwaf.mozrunner\minidumps\4a1df044-b8df-4a01-9297-fe44bc3dd211.dmp
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - Operating system: Windows NT
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - 10.0.17134
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - CPU: amd64
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - family 6 model 85 stepping 7
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - 8 CPUs
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO -
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO - GPU: UNKNOWN
[task 2019-12-09T12:05:20.410Z] 12:05:20 INFO -
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - Crash reason: EXCEPTION_BREAKPOINT
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - Crash address: 0x7ffe81d94a78
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - Process uptime: 73 seconds
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO -
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - Thread 17 (crashed)
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - 0 xul.dll!mozilla::PrioritizedEventQueue::PutEvent(already_AddRefed<nsIRunnable> &&,mozilla::EventQueuePriority,mozilla::BaseAutoLock<mozilla::Mutex &> const &,mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator> *) [PrioritizedEventQueue.cpp:8a285497c16992995f515e43166432b0c765ea72 : 68 + 0x0]
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rax = 0x00007ffec2d27cb0 rdx = 0x00007ffed752a640
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rcx = 0x00007ffe93a33145 rbx = 0x000002801bd7b120
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rsi = 0x0000009ded65eeb0 rdi = 0x0000028028e1b580
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rbp = 0x0000000000000000 rsp = 0x0000009ded65ee00
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r8 = 0x0000009ded658d98 r9 = 0x0000000000000000
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000009ded65a3f0
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r12 = 0x0000028030ff18d0 r13 = 0x0000009ded65f424
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r14 = 0x0000000000000000 r15 = 0x0000028030ff1768
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rip = 0x00007ffe81d94a78
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - Found by: given as instruction pointer in context
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - 1 xul.dll!mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue>::PutEventInternal(already_AddRefed<nsIRunnable> &&,mozilla::EventQueuePriority,mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue>::NestedSink *) [ThreadEventQueue.cpp:8a285497c16992995f515e43166432b0c765ea72 : 113 + 0x19]
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rsp = 0x0000009ded65ee80 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe81e01c0e
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - 2 xul.dll!nsThread::DispatchToQueue(already_AddRefed<nsIRunnable>,mozilla::EventQueuePriority) [nsThread.cpp:8a285497c16992995f515e43166432b0c765ea72 : 959 + 0x10]
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - rsp = 0x0000009ded65ef10 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.411Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe81dd9a0e
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - 3 xul.dll!NS_DispatchToThreadQueue(already_AddRefed<nsIRunnable> &&,nsIThread *,mozilla::EventQueuePriority) [nsThreadUtils.cpp:8a285497c16992995f515e43166432b0c765ea72 : 293 + 0x14]
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rsp = 0x0000009ded65ef90 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe81de8edf
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - 4 xul.dll!NS_DispatchToMainThreadQueue(already_AddRefed<nsIRunnable> &&,mozilla::EventQueuePriority) [nsThreadUtils.cpp:8a285497c16992995f515e43166432b0c765ea72 : 315 + 0xb]
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rsp = 0x0000009ded65f010 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe81df206c
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - 5 xul.dll!mozilla::net::nsHttpChannel::PerformBackgroundCacheRevalidation() [nsHttpChannel.cpp:8a285497c16992995f515e43166432b0c765ea72 : 10528 + 0xa]
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rsp = 0x0000009ded65f080 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe82c5d9d7
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - 6 xul.dll!mozilla::net::nsHttpChannel::OnCacheEntryCheck(nsICacheEntry *,nsIApplicationCache *,unsigned int *) [nsHttpChannel.cpp:8a285497c16992995f515e43166432b0c765ea72 : 4575 + 0x10]
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - rsp = 0x0000009ded65f0f0 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.412Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe82c592f1
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - 7 xul.dll!mozilla::net::CacheEntry::InvokeCallback(mozilla::net::CacheEntry::Callback &) [CacheEntry.cpp:8a285497c16992995f515e43166432b0c765ea72 : 740 + 0x14]
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rsp = 0x0000009ded65f3e0 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe8288b7ab
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - 8 xul.dll!mozilla::net::CacheEntry::InvokeCallbacks(bool) [CacheEntry.cpp:8a285497c16992995f515e43166432b0c765ea72 : 667 + 0x1c]
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rsp = 0x0000009ded65f480 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe8288a26f
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - 9 xul.dll!mozilla::net::CacheEntry::InvokeCallbacks() [CacheEntry.cpp:8a285497c16992995f515e43166432b0c765ea72 : 609 + 0xe]
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rsp = 0x0000009ded65f570 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe82884beb
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - 10 xul.dll!mozilla::net::CacheEntry::OnFileReady(nsresult,bool) [CacheEntry.cpp:8a285497c16992995f515e43166432b0c765ea72 : 497 + 0x14]
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - rsp = 0x0000009ded65f5a0 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.413Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe828886e0
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - 11 xul.dll!mozilla::net::CacheFile::OnMetadataRead(nsresult) [CacheFile.cpp:8a285497c16992995f515e43166432b0c765ea72 : 635 + 0xc]
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - rsp = 0x0000009ded65f680 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe828a78e5
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - Found by: call frame info
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - 12 xul.dll!mozilla::net::CacheFileMetadata::OnDataRead(mozilla::net::CacheFileHandle *,char *,nsresult) [CacheFileMetadata.cpp:8a285497c16992995f515e43166432b0c765ea72 : 757 + 0x8]
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - rbx = 0x000002801bd7b120 rbp = 0x0000000000000000
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - rsp = 0x0000009ded65f730 r12 = 0x0000028030ff18d0
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - r13 = 0x0000009ded65f424 r14 = 0x0000000000000000
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - r15 = 0x0000028030ff1768 rip = 0x00007ffe82914404
[task 2019-12-09T12:05:20.414Z] 12:05:20 INFO - Found by: call frame info

Bughunter reproduced this on Linux and Windows in Nightly using

https://www.thegatewaypundit.com/2019/12/update-bill-barr-indicts-8-including-mueller-top-witness-for-funneling-millions-in-foreign-donations-to-adam-schiff-hillary-clinton-and-top-senate-democrats/

I reproduced locally on Linux. Load the url in a debug build and wait perhaps a couple of minutes to reproduce.

Assertion failure: NS_IsMainThread() (Should only queue idle runnables on main thread), at /builds/worker/workspace/build/src/xpcom/threads/PrioritizedEventQueue.cpp:69
#01: mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue>::PutEventInternal(already_AddRefed<nsIRunnable>&&, mozilla::EventQueuePriority, mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue>::NestedSink*) [xpcom/threads/ThreadEventQueue.cpp:0]
#02: nsThread::DispatchToQueue(already_AddRefed<nsIRunnable>, mozilla::EventQueuePriority) [xpcom/threads/nsThread.cpp:965]
#03: NS_DispatchToThreadQueue(already_AddRefed<nsIRunnable>&&, nsIThread*, mozilla::EventQueuePriority) [xpcom/threads/nsThreadUtils.cpp:293]
#04: NS_DispatchToMainThreadQueue(already_AddRefed<nsIRunnable>&&, mozilla::EventQueuePriority) [xpcom/threads/nsThreadUtils.cpp:315]
#05: mozilla::net::nsHttpChannel::PerformBackgroundCacheRevalidation() [netwerk/protocol/http/nsHttpChannel.cpp:10528]
#06: mozilla::net::nsHttpChannel::OnCacheEntryCheck(nsICacheEntry*, nsIApplicationCache*, unsigned int*) [netwerk/protocol/http/nsHttpChannel.cpp:4575]
#07: mozilla::net::CacheEntry::InvokeCallback(mozilla::net::CacheEntry::Callback&) [netwerk/cache2/CacheEntry.cpp:740]
#08: mozilla::net::CacheEntry::InvokeCallbacks(bool) [netwerk/cache2/CacheEntry.cpp:667]
#09: mozilla::net::CacheEntry::InvokeCallbacks() [netwerk/cache2/CacheEntry.cpp:609]
#10: mozilla::net::CacheEntry::OnFileReady(nsresult, bool) [netwerk/cache2/CacheEntry.cpp:500]
#11: non-virtual thunk to mozilla::net::CacheEntry::OnFileReady(nsresult, bool) [netwerk/cache2/CacheEntry.cpp:0]
#12: mozilla::net::CacheFile::OnMetadataRead(nsresult) [netwerk/cache2/CacheFile.cpp:637]
#13: non-virtual thunk to mozilla::net::CacheFile::OnMetadataRead(nsresult) [netwerk/cache2/CacheFile.cpp:0]
#14: mozilla::net::CacheFileMetadata::OnDataRead(mozilla::net::CacheFileHandle*, char*, nsresult) [netwerk/cache2/CacheFileMetadata.cpp:0]
#15: mozilla::net::ReadEvent::Run() [netwerk/cache2/CacheFileIOManager.cpp:701]
#16: mozilla::net::CacheIOThread::LoopOneLevel(unsigned int) [netwerk/cache2/CacheIOThread.cpp:547]
#17: mozilla::net::CacheIOThread::ThreadFunc() [netwerk/cache2/CacheIOThread.cpp:483]
#18: mozilla::net::CacheIOThread::ThreadFunc(void*) [netwerk/cache2/CacheIOThread.cpp:425]
#19: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]
#20: libpthread.so.0 + 0x9669
#21: libc.so.6 + 0x122323
#22: ??? (???:???)
URL: https://www.thegatewaypundit.com/2019...
Attached file http log —

I also reproduced this locally when loading https://geekflare.com/.

I'm systematically hitting this on my local build since yesterday. We're calling nsHttpChannel::PerformBackroundCacheRevalidation() on the "Cache2 I/O" thread. This is dispatching an event to the main thread here. And we're hitting the assertion here.

What I find odd is that the assertion enforces idle tasks to be submitted only from the main thread (not just only to the main thread).

Boris, it seems that the assertion we're hitting was introduced in bug 1597158. I'm unsure what's the right fix here since this code seem to predate bug 1597158. I assume the original intention was to schedule an idle task, which means that we'll have to proxy the scheduling to the main thread (which is a bit roundabout considering that we were already using this task to proxy an operation to the main thread).

Flags: needinfo?(bzbarsky)
Regressed by: 1597158
Has Regression Range: --- → yes
Keywords: regression

I also just realized that we're not hitting the assertion on release because it's just not there... but IIUC bug 1597158 correctly this means that instead we have a race here between the "Cache2 I/O" thread and the main one.

Status: NEW → RESOLVED
Closed: 4 years ago
Flags: needinfo?(bzbarsky)
Resolution: --- → DUPLICATE

I'll follow up in bug 1600331; sorry for the lag there. But yes, the answer will be to run a non-idle task on the main thread to schedule an idle task... It'll just happen automatically.

Note that the race has been there all along; it's just that now we actually assert when it happens.

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

Attachment

General

Creator:
Created:
Updated:
Size: