Closed
Bug 1615121
Opened 5 years ago
Closed 4 years ago
Intermittent GECKO(1119) | SUMMARY: ThreadSanitizer: data race /builds/worker/workspace/build/src/netwerk/cache2/CacheEntry.cpp:1436:33 in mozilla::net::CacheEntry::MetaDataReady()
Categories
(Core :: Networking: Cache, defect, P2)
Core
Networking: Cache
Tracking
()
RESOLVED
FIXED
mozilla80
Tracking | Status | |
---|---|---|
firefox80 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: mayhemer)
References
(Blocks 1 open bug)
Details
(Whiteboard: [necko-triaged])
Attachments
(1 file)
(deleted),
text/x-phabricator-request
|
Details |
Filed by: choller [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=288618016&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ft_NABKqTye18W03sm9GRg/runs/1/artifacts/public/logs/live_backing.log
Comment 1•5 years ago
|
||
This occurred on autoland, did not show up in previous try pushes. It looks like a race on mState
in CacheEntry::MetaDataReady
vs. CacheEntry::Purge
.
Updated•5 years ago
|
Priority: P5 → P2
Whiteboard: [necko-triaged]
Updated•5 years ago
|
Flags: needinfo?(michal.novotny) → needinfo?(honzab.moz)
Assignee | ||
Comment 3•5 years ago
|
||
Updated•5 years ago
|
Assignee: nobody → honzab.moz
Status: NEW → ASSIGNED
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 5•5 years ago
|
||
Unfortunately, the try run shows a problem:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=288769153&repo=try&lineNumber=7334
[task 2020-02-13T17:39:43.962Z] 17:39:43 INFO - GECKO(624) | ###!!! ERROR: Potential deadlock detected:
[task 2020-02-13T17:39:43.962Z] 17:39:43 INFO - GECKO(624) | === Cyclical dependency starts at
[task 2020-02-13T17:39:43.962Z] 17:39:43 INFO - GECKO(624) | --- Mutex : CacheStorageService.mLock calling context
[task 2020-02-13T17:39:43.963Z] 17:39:43 INFO - GECKO(624) | [stack trace unavailable]
[task 2020-02-13T17:39:43.963Z] 17:39:43 INFO - GECKO(624) | --- Next dependency:
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | --- Mutex : CacheEntry calling context
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | [stack trace unavailable]
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | --- Next dependency:
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | --- Mutex : CacheEntry (currently acquired)
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | calling context
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | [stack trace unavailable]
[task 2020-02-13T17:39:43.964Z] 17:39:43 INFO - GECKO(624) | === Cycle completed at
[task 2020-02-13T17:39:43.965Z] 17:39:43 INFO - GECKO(624) | --- Mutex : CacheStorageService.mLock calling context
[task 2020-02-13T17:39:43.965Z] 17:39:43 INFO - GECKO(624) | [stack trace unavailable]
[task 2020-02-13T17:39:43.965Z] 17:39:43 INFO - GECKO(624) | Deadlock may happen for some other execution
[task 2020-02-13T17:39:43.966Z] 17:39:43 INFO - GECKO(624) | [Parent 7600, Cache2 I/O] WARNING: Potential deadlock detected:
[task 2020-02-13T17:39:43.966Z] 17:39:43 INFO - GECKO(624) | Cyclical dependency starts at
[task 2020-02-13T17:39:43.966Z] 17:39:43 INFO - GECKO(624) | Mutex : CacheStorageService.mLock
[task 2020-02-13T17:39:43.967Z] 17:39:43 INFO - GECKO(624) | Next dependency:
[task 2020-02-13T17:39:43.967Z] 17:39:43 INFO - GECKO(624) | Mutex : CacheEntry
[task 2020-02-13T17:39:43.968Z] 17:39:43 INFO - GECKO(624) | Next dependency:
[task 2020-02-13T17:39:43.968Z] 17:39:43 INFO - GECKO(624) | Mutex : CacheEntry (currently acquired)
[task 2020-02-13T17:39:43.968Z] 17:39:43 INFO - GECKO(624) | Cycle completed at
[task 2020-02-13T17:39:43.968Z] 17:39:43 INFO - GECKO(624) | Mutex : CacheStorageService.mLock
[task 2020-02-13T17:39:43.969Z] 17:39:43 INFO - GECKO(624) | Deadlock may happen for some other execution
[task 2020-02-13T17:39:43.969Z] 17:39:43 INFO - GECKO(624) | : file z:/build/build/src/xpcom/threads/BlockingResourceBase.cpp, line 250
...
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - Operating system: Windows NT
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - 10.0.17134
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - CPU: amd64
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - family 6 model 85 stepping 4
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - 8 CPUs
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO -
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - GPU: UNKNOWN
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO -
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - Crash reason: EXCEPTION_ACCESS_VIOLATION_READ
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - Crash address: 0x76a51578
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - Process uptime: 206 seconds
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO -
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - Thread 19 (crashed)
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - 0 xul.dll!mozilla::BlockingResourceBase::Print(nsTSubstring<char>&) const [BlockingResourceBase.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 124 + 0xf]
[task 2020-02-13T17:40:05.405Z] 17:40:05 INFO - rax = 0xffffffffe5e5e5e5 rdx = 0x000000ad0085f740
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rcx = 0x000002342cc84f28 rbx = 0x00000000476ee300
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rsi = 0x000000ad0085f740 rdi = 0x000002342cc84f28
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rbp = 0x00007ffe7ee007b0 rsp = 0x000000ad0085f6c0
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r8 = 0x0000000000000009 r9 = 0x00007ffe79c5cdd8
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r10 = 0x00007ffe47761642 r11 = 0x000002342c6ec4f7
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r12 = 0x00007ffe47761642 r13 = 0x000000ad0085f740
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r14 = 0xe5e5e5e5e5e5e5e5 r15 = 0x00007ffe4775e650
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rip = 0x00007ffe3f1dc1c0
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - Found by: given as instruction pointer in context
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - 1 xul.dll!mozilla::BlockingResourceBase::CheckAcquire() [BlockingResourceBase.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 236 + 0x104]
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rsp = 0x000000ad0085f710 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f1dcc22
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - 2 xul.dll!mozilla::OffTheBooksMutex::Lock() [BlockingResourceBase.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 317 + 0xc]
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - rsp = 0x000000ad0085f7f0 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.406Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f1dd435
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - 3 xul.dll!mozilla::net::CacheStorageService::RemoveEntry(mozilla::net::CacheEntry*, bool) [CacheStorageService.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 1105 + 0x13]
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - rsp = 0x000000ad0085f830 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f70338f
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - 4 xul.dll!mozilla::net::CacheEntry::Purge(unsigned int) [CacheEntry.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 1670 + 0xb]
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - rsp = 0x000000ad0085f980 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f6b08eb
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - 5 xul.dll!mozilla::net::CacheStorageService::MemoryPool::PurgeByFrecency(bool&, unsigned int) [CacheStorageService.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 1454 + 0xb]
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - rsp = 0x000000ad0085f9e0 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f704dab
[task 2020-02-13T17:40:05.407Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - 6 xul.dll!mozilla::net::CacheStorageService::MemoryPool::PurgeOverMemoryLimit() [CacheStorageService.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 1404 + 0x13]
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - rsp = 0x000000ad0085fa70 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f704994
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - 7 xul.dll!mozilla::net::CacheStorageService::PurgeOverMemoryLimit() [CacheStorageService.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 1369 + 0x5]
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - rsp = 0x000000ad0085fb00 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f70480b
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - 8 xul.dll!mozilla::detail::RunnableMethodImpl<mozilla::net::CacheStorageService *,void (mozilla::net::CacheStorageService::*)(),1,mozilla::RunnableKind::Standard>::Run() [nsThreadUtils.h:dce82130ce121c237ee48a275acde94f87dce505 : 1212 + 0xa]
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - rsp = 0x000000ad0085fb70 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f711b7a
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.408Z] 17:40:05 INFO - 9 xul.dll!mozilla::net::CacheIOThread::LoopOneLevel(unsigned int) [CacheIOThread.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 535 + 0x6]
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - rsp = 0x000000ad0085fba0 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f6e6da7
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - 10 xul.dll!mozilla::net::CacheIOThread::ThreadFunc() [CacheIOThread.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 473 + 0x8]
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - rbx = 0x00000000476ee300 rbp = 0x00007ffe7ee007b0
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - rsp = 0x000000ad0085fc40 r12 = 0x00007ffe47761642
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - r13 = 0x000000ad0085f740 r14 = 0xe5e5e5e5e5e5e5e5
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - r15 = 0x00007ffe4775e650 rip = 0x00007ffe3f6e66ba
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - Found by: call frame info
[task 2020-02-13T17:40:05.409Z] 17:40:05 INFO - 11 xul.dll!static mozilla::net::CacheIOThread::ThreadFunc(void*) [CacheIOThread.cpp:dce82130ce121c237ee48a275acde94f87dce505 : 414 + 0x8]
Flags: needinfo?(honzab.moz)
Comment 6•5 years ago
|
||
There's a r+ patch which didn't land and no activity in this bug for 2 weeks.
:mayhemer, could you have a look please?
For more information, please visit auto_nag documentation.
Flags: needinfo?(honzab.moz)
Pushed by honzab.moz@firemni.cz:
https://hg.mozilla.org/integration/autoland/rev/b00050ccb953
Keep CacheEntry.mLock when reading its mState to prevent a race, r=michal,necko-reviewers
Comment 8•4 years ago
|
||
bugherder |
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox80:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla80
Assignee | ||
Updated•4 years ago
|
Flags: needinfo?(honzab.moz)
You need to log in
before you can comment on or make changes to this bug.
Description
•