Closed Bug 976147 Opened 6 years ago Closed 6 years ago

crash in mozilla::net::CacheFileIOManager::Read(mozilla::net::CacheFileHandle*, __int64, char*, int, mozilla::net::CacheFileIOListener*)

Categories

(Core :: Networking: Cache, defect, critical)

All
Windows NT
defect
Not set
critical

Tracking

()

RESOLVED FIXED
mozilla30

People

(Reporter: mayhemer, Assigned: michal)

References

Details

(Keywords: crash)

Crash Data

Attachments

(2 files)

This bug was filed from the Socorro interface and is 
report bp-5b105600-e305-45c3-a12c-743222140220.
=============================================================

Seems like aHandle is null sometimes, the crash address is:
0x1a on amd64
0xe on x86
Just hit this in a debugger, opt build (but unfortunately no log).  Gum + few small local patches.  Interesting is that the CacheFile has mOpeningFile = true and mHandle = nullptr.  mStatus = NS_OK.  Seems like the file is still being open..?

This is expanded CacheFileInputStream instance.

-		this	0x17b20eb0 {mRefCnt={mValue={...} } _mOwningThread={mThread=0x06c67358 } mFile={mRawPtr=0x11d95ce8 {...} } ...}	mozilla::net::CacheFileInputStream *
+		nsIAsyncInputStream	{...}	nsIAsyncInputStream
+		nsISeekableStream	{...}	nsISeekableStream
+		mozilla::net::CacheFileChunkListener	{...}	mozilla::net::CacheFileChunkListener
+		mRefCnt	{mValue={...} }	mozilla::ThreadSafeAutoRefCnt
+		_mOwningThread	{mThread=0x06c67358 }	nsAutoOwningThread
-		mFile	{mRawPtr=0x11d95ce8 {mRefCnt={mValue={...} } _mOwningThread={mThread=0x00538980 } mLock={...} ...} }	nsRefPtr<mozilla::net::CacheFile>
-		mRawPtr	0x11d95ce8 {mRefCnt={mValue={...} } _mOwningThread={mThread=0x00538980 } mLock={...} ...}	mozilla::net::CacheFile *
+		mozilla::net::CacheFileChunkListener	{...}	mozilla::net::CacheFileChunkListener
+		mozilla::net::CacheFileIOListener	{...}	mozilla::net::CacheFileIOListener
+		mozilla::net::CacheFileMetadataListener	{...}	mozilla::net::CacheFileMetadataListener
-		mRefCnt	{mValue={...} }	mozilla::ThreadSafeAutoRefCnt
-		mValue	{...}	mozilla::Atomic<unsigned long,2,void>
-		mozilla::detail::AtomicBaseIncDec<unsigned long,2>	{...}	mozilla::detail::AtomicBaseIncDec<unsigned long,2>
+		mozilla::detail::AtomicBase<unsigned long,2>	{mValue=5 }	mozilla::detail::AtomicBase<unsigned long,2>
+		_mOwningThread	{mThread=0x00538980 }	nsAutoOwningThread
+		mLock	{...}	mozilla::Mutex
		mOpeningFile	true	bool
		mReady	true	bool
		mMemoryOnly	false	bool
		mDataAccessed	true	bool
		mDataIsDirty	false	bool
		mWritingMetadata	false	bool
		mDontCacheChunks	true	bool
		mStatus	NS_OK (0)	tag_nsresult
		mDataSize	5331	__int64
+		mKey	{...}	nsCString
+		mHandle	{mRawPtr=0x00000000 <NULL> }	nsRefPtr<mozilla::net::CacheFileHandle>
-		mMetadata	{mRawPtr=0x199167e0 {mRefCnt={mValue={...} } _mOwningThread={mThread=0x00538980 } mHandle={mRawPtr=0x00000000 <NULL> } ...} }	nsRefPtr<mozilla::net::CacheFileMetadata>
-		mRawPtr	0x199167e0 {mRefCnt={mValue={...} } _mOwningThread={mThread=0x00538980 } mHandle={mRawPtr=0x00000000 <NULL> } ...}	mozilla::net::CacheFileMetadata *
+		mozilla::net::CacheFileIOListener	{...}	mozilla::net::CacheFileIOListener
+		mozilla::net::CacheMemoryConsumer	{mReportedMemoryConsumption=0 }	mozilla::net::CacheMemoryConsumer
+		mRefCnt	{mValue={...} }	mozilla::ThreadSafeAutoRefCnt
+		_mOwningThread	{mThread=0x00538980 }	nsAutoOwningThread
+		mHandle	{mRawPtr=0x00000000 <NULL> }	nsRefPtr<mozilla::net::CacheFileHandle>
+		mKey	{...}	nsCString
+		mHashArray	0x11e88150 {3537}	unsigned short *
		mHashArraySize	64	unsigned int
		mHashCount	1	unsigned int
		mOffset	0	__int64
+		mBuf	0x126d44f8 "request-method"	char *
		mBufSize	250	unsigned int
+		mWriteBuf	0x00000000 <NULL>	char *
+		mMetaHdr	{mVersion=2 mFetchCount=1 mLastFetched=0 ...}	mozilla::net::CacheFileMetadataHeader
		mElementsSize	250	unsigned int
		mIsDirty	true	bool
		mAnonymous	false	bool
		mInBrowser	false	bool
		mAppId	0	unsigned int
+		mListener	{...}	nsCOMPtr<mozilla::net::CacheFileMetadataListener>
+		mListener	{...}	nsCOMPtr<mozilla::net::CacheFileListener>
+		mDoomAfterOpenListener	{...}	nsCOMPtr<mozilla::net::CacheFileIOListener>
+		mChunks	{...}	nsRefPtrHashtable<nsUint32HashKey,mozilla::net::CacheFileChunk>
+		mChunkListeners	{...}	nsClassHashtable<nsUint32HashKey,mozilla::net::ChunkListeners>
+		mCachedChunks	{...}	nsRefPtrHashtable<nsUint32HashKey,mozilla::net::CacheFileChunk>
+		mInputs	{...}	nsTArray<mozilla::net::CacheFileInputStream *>
+		mOutput	0x00000000 <NULL>	mozilla::net::CacheFileOutputStream *
+		mObjsToRelease	{...}	nsTArray<nsISupports *>
+		mChunk	{mRawPtr=0x00000000 <NULL> }	nsRefPtr<mozilla::net::CacheFileChunk>
		mPos	0	__int64
		mClosed	false	bool
		mStatus	NS_OK (0)	tag_nsresult
		mWaitingForUpdate	false	bool
		mListeningForChunk	-1	__int64
		mInReadSegments	false	bool
+		mCallback	{...}	nsCOMPtr<nsIInputStreamCallback>
		mCallbackFlags	0	unsigned int
+		mCallbackTarget	{...}	nsCOMPtr<nsIEventTarget>



Callstack (Main thread):

 	xul.dll!mozilla::net::CacheFileIOManager::Read(mozilla::net::CacheFileHandle * aHandle=0x00000000, __int64 aOffset=0, char * aBuf=0x124a3958, int aCount=5331, mozilla::net::CacheFileIOListener * aCallback=0x0badcfb8) Line 1747	C++
 	xul.dll!mozilla::net::CacheFileChunk::Read(mozilla::net::CacheFileHandle * aHandle=0x00000000, unsigned int aLen=5331, unsigned short aHash=53517, mozilla::net::CacheFileChunkListener * aCallback=0x11d95ce8) Line 205	C++
 	xul.dll!mozilla::net::CacheFile::GetChunkLocked(unsigned int aIndex=0, bool aWriter=false, mozilla::net::CacheFileChunkListener * aCallback=0x17b20eb8, mozilla::net::CacheFileChunk * * _retval=0x17b20ec8) Line 1014	C++
 	xul.dll!mozilla::net::CacheFileInputStream::EnsureCorrectChunk(bool aReleaseOnly=false) Line 527	C++
>	xul.dll!mozilla::net::CacheFileInputStream::AsyncWait(nsIInputStreamCallback * aCallback=0x17fe1b1c, unsigned int aFlags=0, unsigned int aRequestedCount=0, nsIEventTarget * aEventTarget=0x00628ed0) Line 324	C++
 	xul.dll!nsInputStreamPump::EnsureWaiting() Line 143	C++
 	xul.dll!nsInputStreamPump::AsyncRead(nsIStreamListener * listener=0x088ecc70, nsISupports * ctxt=0x00000000) Line 383	C++
 	xul.dll!mozilla::net::nsHttpChannel::ReadFromCache(bool alreadyMarkedValid=176) Line 3569	C++
 	xul.dll!mozilla::net::nsHttpChannel::ContinueConnect() Line 343	C++
 	xul.dll!mozilla::net::nsHttpChannel::OnCacheEntryAvailableInternal(nsICacheEntry * entry=0x0917c058, bool aNew=false, nsIApplicationCache * aAppCache=0x00000000, tag_nsresult status=NS_OK) Line 3071	C++
 	xul.dll!mozilla::net::nsHttpChannel::OnCacheEntryAvailable(nsICacheEntry * entry=0x0917c058, bool aNew=false, nsIApplicationCache * aAppCache=0x00000000, tag_nsresult status=NS_OK) Line 3017	C++
 	xul.dll!mozilla::net::CacheEntry::InvokeAvailableCallback(const mozilla::net::CacheEntry::Callback & aCallback={...}) Line 708	C++
 	xul.dll!mozilla::net::CacheEntry::AvailableCallbackRunnable::Run() Line 174	C++




STR (once): set memory pool size to 0 (browser.cache.memory_limit), with a cleaned cache (but with net predictions filled from previous browsing) load few pages like bbc, cnn, wiki.m.o etc.  Then I have a locally running server (fast localhost access!).  I went to a simple front page on that local server and hit this crash instantly.  The request is however for favicon, in detail for "http://test.local.i7/favicon.ico#-moz-resolution=16,16" which is usually not the first request (we do some 3 favicon requests almost simultaneously, all sharing or creating/throwing away a single cache entry).  And definitely not in cache!  I will try to reproduce with logging on...
Have the log.  Looking into it.
So, this won't be just about a null checking...

OK, I think I have it and also I think I know why this is so low volume crash.  Some of my local changes reveals this.  I have a local patch that doesn't cache chunks (selectively, but for this particular load - the favicon - it just doesn't keep chunks in mCachedChunks).  So, in CacheFile::RemoveChunk() the chunk we obtain from the output stream goes away - data are lost.  In the wild this situation may happen when cached chunks are purged because of the memory pool is full - very corner case.

Scenario:
- we have an existing entry for favicon
- the entry is first revalidated
- we get 404
- http channel recreates the entry
- it means we immediately create a new entry and write to it (actual file is being open later to write the data)
- another http channel doing another request for the same favicon gets a ready cache entry and wants to read from it (no further validation)
- we create an input stream on the entry
- that input stream wants to load the chunk, since it is not found in the mCachedChunks nor in mChunks

xul.dll!mozilla::net::CacheFileIOManager::Read(0x00000000, 0, 0x1dea4b70, 5331, 0x088442e8) Line 1747	C++
xul.dll!mozilla::net::CacheFileChunk::Read(0x00000000, 5331, 53517, 0x125e1c28) Line 205	C++
xul.dll!mozilla::net::CacheFile::GetChunkLocked(0, false, 0x11fb9210, 0x11fb9220) Line 1014	C++
xul.dll!mozilla::net::CacheFileInputStream::EnsureCorrectChunk(false) Line 527	C++
xul.dll!mozilla::net::CacheFileInputStream::AsyncWait(0x19d4b784, 0, 0, 0x00424f08) Line 324	C++

- and CacheFile->mHandle is still null

It means that:
- CacheFile::RemoveChunk must keep the chunk in mChunks, there is a branching on value of mOpeningFile, but I don't understand how and when the cached chunk is written after the file is open and why it is actually moved to the cached chunks list and not left in mChunks list
- CacheFile::GetChunkLocked has to wait for file to open
Attached file log
Well, it might be that this part of the code is not tested very well, but as far as I understand the comments above, you're reporting bug that you've introduce by your local change.

In short:
- cached chunks are released only in CacheFile::ThrowMemoryCachedData() which fails when we're still opening the file
- once we get the file, we write all cached chunks to disk, see http://hg.mozilla.org/mozilla-central/annotate/ff96e428da76/netwerk/cache2/CacheFile.cpp#l480

So back to your change, there is no problem to not cache the chunks once they have been written, but you must cache them when mOpenFile == true.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INVALID
Reopening since I understood incorrectly that all reports were from Honza.
Status: RESOLVED → REOPENED
Resolution: INVALID → ---
Attached patch patch v1Splinter Review
For explanation see the comments in the patch.

https://tbpl.mozilla.org/?tree=Try&rev=c51e2090393e
Attachment #8388559 - Flags: review?(honzab.moz)
Attachment #8388559 - Flags: review?(honzab.moz) → review+
Summary of the steps that "probably" leads to this crash:

- CacheEntry initializes CacheFile that should use the disk
- CacheFile opens a file on disk but for whatever reason it fails, so the CacheFile is switched to memory-only mode
- CacheEntry thinks this CacheFile uses disk and at some point it calls CacheFile::ThrowMemoryCachedData()
- later when we read the data from the entry the chunk is not found in mCachedChunks in CacheFile::GetChunkLocked() so we create a new chunk that starts reading the data, but the handle is null
https://hg.mozilla.org/mozilla-central/rev/8266c1727c89
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla30
You need to log in before you can comment on or make changes to this bug.