646259 - "###!!! ASSERTION: Potential deadlock detected" in nsCacheService

Status: RESOLVED FIXED

(Core :: Networking: Cache, defect)

Description

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: Output from test

The patches in bug 645263 have the cache service participate in deadlock detection.  The cache service has an invalid lock ordering, apparently somewhere around shutdown.  Relevant output is 

$ make SOLO_FILE="test_clearHistory_shutdown.js" -C ../ff-dbg/browser/components/places/tests/ check-one
[snip]
WARNING: Resource acquired at calling context
  mozilla::Mutex::Lock() at BlockingResourceBase.cpp:258
  nsCacheService::Lock() at nsCacheService.cpp:2212
  nsCacheServiceAutoLock at nsCacheService.h:306
  nsCacheService::EvictEntriesForClient(char const*, int) at nsCacheService.cpp:1195
  nsCacheService::EvictEntries(int) at nsCacheService.cpp:1326
[snip]
is being released in non-LIFO order; why?

###!!! ERROR: Potential deadlock detected:
=== Cyclical dependency starts at
--- Mutex : nsCacheService.mLock calling context
  mozilla::Mutex::Lock() at BlockingResourceBase.cpp:258
  nsCacheService::Lock() at nsCacheService.cpp:2212
  nsCacheServiceAutoLock at nsCacheService.h:306
  nsCacheService::SetDiskCacheCapacity(int) at nsCacheService.cpp:2073
  nsCacheProfilePrefObserver::Observe(nsISupports*, char const*, unsigned short const*) at nsCacheService.cpp:429
[snip]
--- Next dependency:
--- Monitor : nsCacheService.mMonitor (currently acquired)
 calling context
  mozilla::Monitor::Enter() at BlockingResourceBase.cpp:290
  MonitorAutoEnter at Monitor.h:217
  nsCacheService::SyncWithCacheIOThread() at nsCacheService.cpp:818
  nsDiskCacheDevice::Shutdown_Private(int) at nsDiskCacheDevice.cpp:434
  nsDiskCacheDevice::ClearDiskCache() at nsDiskCacheDevice.cpp:966
  nsDiskCacheDevice::EvictEntries(char const*) at nsDiskCacheDevice.cpp:888
  nsCacheService::EvictEntriesForClient(char const*, int) at nsCacheService.cpp:1206
  nsCacheService::EvictEntries(int) at nsCacheService.cpp:1326
[snip]
=== Cycle completed at
--- Mutex : nsCacheService.mLock calling context
  mozilla::Mutex::Lock() at BlockingResourceBase.cpp:258
  nsCacheService::Lock() at nsCacheService.cpp:2212
  nsCacheService::SyncWithCacheIOThread() at nsCacheService.cpp:835
  nsDiskCacheDevice::Shutdown_Private(int) at nsDiskCacheDevice.cpp:434
  nsDiskCacheDevice::ClearDiskCache() at nsDiskCacheDevice.cpp:966
  nsDiskCacheDevice::EvictEntries(char const*) at nsDiskCacheDevice.cpp:888
  nsCacheService::EvictEntriesForClient(char const*, int) at nsCacheService.cpp:1206
  nsCacheService::EvictEntries(int) at nsCacheService.cpp:1326
[snip]

Full output is attached.  Not sure yet how severe this bug is.

Comment 1

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: Some trivial formatting fixes to deadlock detector output

Minor fixes, would land the second part without this patch.

Comment 2

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: Fix nsCacheService to use a CondVar for notifying

This is a patch khuey wrote for bug 493146, with some minor style nits changed.  I understand this problem somewhat better now and feel more comfortable reviewing this patch (it's actually a pretty trivial change).

And if it's wrong, it'll blow up the deadlock detector ;).

Comment 4

[Bjarne (:bjarne)]

Adding myself to CC since I was involved in reviewing bug #493146 and also introduced the nsCacheService::SyncWithCacheIOThread() mechanism which seems to be the culprit here.

A question to clarify: Does this show up only with the patch by khuey from bug #493146 (i.e. does it enable the deadlock-detection)? Or does that patch resolve the issue seen here?

Are there any examples of this actually causing Fx to deadlock in practice btw?

Comment 5

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

(In reply to comment #4)
> Does this show up only with the patch by khuey from bug
> #493146 (i.e. does it enable the deadlock-detection)? Or does that patch
> resolve the issue seen here?

Well, the assertion failure here shows up after enabling lock-order checking of the mutex+monitor in nsCacheService, which is a patch that khuey wrote, and khuey also wrote a fix for the new assertion failure.  The latter is the patch attached here.

> Are there any examples of this actually causing Fx to deadlock in practice btw?

Not sure.

Comment 6

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

http://hg.mozilla.org/mozilla-central/rev/4beec31b9ea9
http://hg.mozilla.org/mozilla-central/rev/36242c02cfc4

Comment 7

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Increased frequency of intermittent orange bug 618052, backed out

http://hg.mozilla.org/mozilla-central/rev/e03c3a6df3cb

Sigh.

Comment 8

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

http://hg.mozilla.org/mozilla-central/rev/1a89509e25e4

Comment 9

[Julian Seward [:jseward]]

With M-C of 6 Apr 2011 I can no longer repro this either on Helgrind
(iow, independent confirmation of fix)