Closed Bug 266532 Opened 20 years ago Closed 10 years ago

###!!! ASSERTION: unexpected progress values: 'progress <= progressMax', file r:/mozilla/netwerk/protocol/http/src/nsHttpChannel.cpp, line 3796

Categories

(Core :: Networking: HTTP, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla29

People

(Reporter: timeless, Assigned: mcmanus)

References

()

Details

(Keywords: assertion, reproducible)

Attachments

(1 file)

###!!! ASSERTION: unexpected progress values: 'progress <= progressMax', file
r:/mozilla/netwerk/protocol/http/src/nsHttpChannel.cpp, line 3796
Break: at file r:/mozilla/netwerk/protocol/http/src/nsHttpChannel.cpp, line 3796

 	xpcom_core.dll!nsDebug::Assertion(const char * aStr=0x012db8a8, const char *
aExpr=0x012db8c4, const char * aFile=0x012dae50, int aLine=0x00000ed4)  Line 109	C++
 	necko.dll!nsHttpChannel::OnDataAvailable(nsIRequest * request=0x031fb740,
nsISupports * ctxt=0x00000000, nsIInputStream * input=0x034dc330, unsigned int
offset=0x00000000, unsigned int count=0x0000052d)  Line 3796 + 0x2d	C++
>	necko.dll!nsInputStreamPump::OnStateTransfer()  Line 438	C++
 	necko.dll!nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream *
stream=0x034dc330)  Line 339	C++
 	xpcom_core.dll!nsInputStreamReadyEvent::EventHandler(PLEvent *
plevent=0x0326e194)  Line 119	C++
 	xpcom_core.dll!PL_HandleEvent(PLEvent * self=0x0326e194)  Line 693	C
 	xpcom_core.dll!PL_ProcessPendingEvents(PLEventQueue * self=0x01062af8)  Line 628	C
 	xpcom_core.dll!_md_EventReceiverProc(HWND__ * hwnd=0x00272420, unsigned int
uMsg=0x0000c14e, unsigned int wParam=0x00000000, long lParam=0x01062af8)  Line
1434	C
 	user32.dll!77d43a50() 	
 	user32.dll!77d43b1f() 	
 	user32.dll!GetMessageW()  + 0x125	
 	user32.dll!DispatchMessageW()  + 0xb	
 	appshell.dll!nsAppShellService::Run()  Line 484	C++
 	mozilla.exe!main1(int argc=0x00000000, char * * argv=0x80000000, nsISupports *
nativeApp=0x031fb744)  Line 1336	C++
 	mozilla.exe!main(int argc=0x00000001, char * * argv=0x003f7c10)  Line 1827 +
0x16	C++
 	mozilla.exe!mainCRTStartup()  Line 400 + 0x11	C
 	kernel32.dll!TermsrvAppInstallMode()  + 0x269	

+	progressMax	{mValue=0x0000000000000437 }	nsTInt64<unsigned __int64>
+	progress	{mValue=0x000000000000052d }	nsTInt64<unsigned __int64>

-	this	0x031fb744 {mRefCnt={mValue=0x00000002 }
_mOwningThread={mThread=0x003f5c80 } mState=0x00000002 ...}	nsInputStreamPump *
const
|+	nsIInputStreamPump	{...}	nsIInputStreamPump
|+	nsIInputStreamCallback	{...}	nsIInputStreamCallback
|+	mRefCnt	{mValue=0x00000002 }	nsAutoRefCnt
|+	_mOwningThread	{mThread=0x003f5c80 }	nsAutoOwningThread
|	mState	0x00000002	unsigned int
|+	mLoadGroup	{mRawPtr=0x00000000 }	nsCOMPtr<nsILoadGroup>
|-	mListener	{mRawPtr=0x02d41930 {mRefCnt={mValue=0x00000002 }
_mOwningThread={mThread=0x003f5c80 } mOriginalURI={mRawPtr=0x03549558
{mRefCnt={...} _mOwningThread={...} mSpec={...} ...} } ...} }
nsCOMPtr<nsIStreamListener>
|\-	mRawPtr	0x02d41930 {mRefCnt={mValue=0x00000002 }
_mOwningThread={mThread=0x003f5c80 } mOriginalURI={mRawPtr=0x03549558
{mRefCnt={mValue=0x00000003 } _mOwningThread={mThread=0x003f5c80 } mSpec={...}
...} } ...}	nsIStreamListener *
| |-	[nsHttpChannel]	{mRefCnt={mValue=0x00000002 }
_mOwningThread={mThread=0x003f5c80 } mOriginalURI={mRawPtr=0x03549558
{mRefCnt={mValue=0x00000003 } _mOwningThread={mThread=0x003f5c80 } mSpec={...}
...} } ...}	nsHttpChannel
| ||+	nsIHttpChannel	{...}	nsIHttpChannel
| ||+	nsIHttpChannelInternal	{...}	nsIHttpChannelInternal
| ||+	nsIStreamListener	{...}	nsIStreamListener
| ||+	nsICachingChannel	{...}	nsICachingChannel
| ||+	nsIUploadChannel	{...}	nsIUploadChannel
| ||+	nsICacheListener	{...}	nsICacheListener
| ||+	nsIEncodedChannel	{...}	nsIEncodedChannel
| ||+	nsITransportEventSink	{...}	nsITransportEventSink
| ||+	nsIResumableChannel	{...}	nsIResumableChannel
| ||+	mRefCnt	{mValue=0x00000002 }	nsAutoRefCnt
| ||+	_mOwningThread	{mThread=0x003f5c80 }	nsAutoOwningThread
| ||+	mOriginalURI	{mRawPtr=0x03549558 {mRefCnt={mValue=0x00000003 }
_mOwningThread={mThread=0x003f5c80 } mSpec={...} ...} }	nsCOMPtr<nsIURI>
| ||+	mURI	{mRawPtr=0x03261c88 {mRefCnt={mValue=0x00000001 }
_mOwningThread={mThread=0x003f5c80 } mSpec={...} ...} }	nsCOMPtr<nsIURI>
| ||+	mDocumentURI	{mRawPtr=0x03e87cc0 {mRefCnt={mValue=0x0000000c }
_mOwningThread={mThread=0x003f5c80 } mSpec={...} ...} }	nsCOMPtr<nsIURI>
| ||+	mListener	{mRawPtr=0x03f90a28 {mRefCnt={mValue=0x00000001 }
_mOwningThread={mThread=0x003f5c80 } mInputTee={mRawPtr=0x00000000 } ...} }
nsCOMPtr<nsIStreamListener>
| ||+	mListenerContext	{...}	nsCOMPtr<nsISupports>
| ||+	mLoadGroup	{mRawPtr=0x00000000 }	nsCOMPtr<nsILoadGroup>
| ||+	mOwner	{...}	nsCOMPtr<nsISupports>
| ||+	mCallbacks	{mRawPtr=0x043592c0 }	nsCOMPtr<nsIInterfaceRequestor>
| ||+	mProgressSink	{mRawPtr=0x029baf80 {mRefCnt={mValue=0x0000001b }
_mOwningThread={mThread=0x003f5c80 } mDocumentRequest={mRawPtr=0x02ca4ff0
{mRefCnt={...} _mOwningThread={...} mOriginalURI={...} ...} } ...} }
nsCOMPtr<nsIProgressEventSink>
| ||+	mHttpEventSink	{mRawPtr=0x029baf8c {mRefCnt={mValue=0x0000001b }
_mOwningThread={mThread=0x003f5c80 } mDocumentRequest={mRawPtr=0x02ca4ff0
{mRefCnt={...} _mOwningThread={...} mOriginalURI={...} ...} } ...} }
nsCOMPtr<nsIHttpEventSink>
| ||+	mUploadStream	{mRawPtr=0x00000000 }	nsCOMPtr<nsIInputStream>
| ||+	mReferrer	{mRawPtr=0x031b9038 {mRefCnt={mValue=0x00000001 }
_mOwningThread={mThread=0x003f5c80 } mSpec={...} ...} }	nsCOMPtr<nsIURI>
| ||+	mSecurityInfo	{...}	nsCOMPtr<nsISupports>
| ||+	mEventQ	{mRawPtr=0x01062a38 {mRefCnt={mValue=0x0000001f }
_mOwningThread={mThread=0x003f5c80 } mEventQueue=0x01062af8 {name=0x00390c08
"Thread event queue..." queue={next=0x039effa0 prev=0x04387b38 }
monitor=0x01062b48 ...} ...} }	nsCOMPtr<nsIEventQueue>
| ||-	mRequestHead	{mHeaders={mHeaders={mAutoBuf=0x02d41994 "" } }
mMethod={_val=0x012da804 "GET" } mVersion=0x0b '␋' ...}	nsHttpRequestHead
| |||+	mHeaders	{mHeaders={mAutoBuf=0x02d41994 "" } }	nsHttpHeaderArray
| |||+	mMethod	{_val=0x012da804 "GET" }	nsHttpAtom
| |||	mVersion	0x0b '␋'	unsigned char
| ||\-	mRequestURI	{...}	nsCString
| || \-	nsCSubstring	{...}	nsCSubstring
| ||  \-	nsACString	{mVTable=0x00394a58 const nsObsoleteACStringThunk::`vftable'
mData=0x04119b98
"/?0.6883918567393155&s=130479&im=103&r=http%3A//webtools.mozilla.org/buster/test_url_27.html&pg=http%3A//www.dp.ru/index.php&c=Y&j=N&wh=1600x1200&px=16&js=1.3&"
mLength=0x0000009f ...}	nsACString
| ||   |	mVTable	0x00394a58 const nsObsoleteACStringThunk::`vftable'	const void *
| ||   |+	mData	0x04119b98
"/?0.6883918567393155&s=130479&im=103&r=http%3A//webtools.mozilla.org/buster/test_url_27.html&pg=http%3A//www.dp.ru/index.php&c=Y&j=N&wh=1600x1200&px=16&js=1.3&"
char *
| ||   |	mLength	0x0000009f	unsigned int
| ||   \	mFlags	0x00000005	unsigned int
| ||-	mResponseHead	0x03f907c0 {mHeaders={mHeaders={mAutoBuf=0x03f907c8 "" } }
mVersion=0x0b '␋' mStatus=0x00c8 ...}	nsHttpResponseHead *
| |||-	mHeaders	{mHeaders={mAutoBuf=0x03f907c8 "" } }	nsHttpHeaderArray
| |||\-	mHeaders	{mAutoBuf=0x03f907c8 "" }	nsAutoVoidArray
| ||| |-	nsVoidArray	{mImpl=0x039f02b0 {mBits=0x80000010 mCount=0x0000000d
mArray=0x039f02b8 } }	nsVoidArray
| ||| ||+	__vfptr	0x00387ca4 const nsAutoVoidArray::`vftable'	*
| ||| |\-	mImpl	0x039f02b0 {mBits=0x80000010 mCount=0x0000000d
mArray=0x039f02b8 }	nsVoidArray::Impl *
| ||| | |	mBits	0x80000010	unsigned int
| ||| | |	mCount	0x0000000d	int
| ||| | \+	mArray	0x039f02b8	void * [1]
| ||| \+	mAutoBuf	0x03f907c8 ""	char [40]
| |||	mVersion	0x0b '␋'	unsigned char
| |||	mStatus	0x00c8	unsigned short
| |||+	mStatusText	{...}	nsCString
| |||	mContentLength	0x0000000000000437	__int64
| |||-	mContentType	{...}	nsCString
| |||\-	nsCSubstring	{...}	nsCSubstring
| ||| \-	nsACString	{mVTable=0x00394a58 const nsObsoleteACStringThunk::`vftable'
mData=0x02960a48 "image/gif" mLength=0x00000009 ...}	nsACString
| |||  |	mVTable	0x00394a58 const nsObsoleteACStringThunk::`vftable'	const void *
| |||  |+	mData	0x02960a48 "image/gif"	char *
| |||  |	mLength	0x00000009	unsigned int
| |||  \	mFlags	0x00000005	unsigned int
| |||+	mContentCharset	{...}	nsCString
| |||	mCacheControlNoStore	0x00	unsigned char
| |||	mCacheControlNoCache	0x01 '␁'	unsigned char
| ||\	mPragmaNoCache	0x01 '␁'	unsigned char
| ||+	mTransactionPump	{mRawPtr=0x031fb740 {mRefCnt={mValue=0x00000002 }
_mOwningThread={mThread=0x003f5c80 } mState=0x00000002 ...} }
nsCOMPtr<nsIInputStreamPump>
| ||+	mTransaction	0x034cccb8 {mRefCnt={mValue=0x00000001 }
_mOwningThread={mThread=0x003f5c80 } mCallbacks={mRawPtr=0x043592c0 } ...}
nsHttpTransaction *
| ||+	mConnectionInfo	0x01912e48 {mRef=0x00000003 mHashKey={...} mHost={...}
...}	nsHttpConnectionInfo *
| ||+	mSpec	{...}	nsCString
| ||	mLoadFlags	0x00040000	unsigned int
| ||	mStatus	0x00000000	unsigned int
| ||+	mLogicalOffset	{mValue=0x0000000000000000 }	nsTInt64<unsigned __int64>
| ||	mCaps	0x01 '␁'	unsigned char
| ||+	mContentTypeHint	{...}	nsCString
| ||+	mContentCharsetHint	{...}	nsCString
| ||+	mCacheEntry	{mRawPtr=0x03aa8700 {mRefCnt={mValue=0x00000002 }
_mOwningThread={mThread=0x003f5c80 } mCacheEntry=0x02bb9f38 {mKey=0x04010ef0
mFetchCount=0x00000001 mLastFetched=0x41811ee5 ...} ...} }
nsCOMPtr<nsICacheEntryDescriptor>
| ||+	mCachePump	{mRawPtr=0x00000000 }	nsCOMPtr<nsIInputStreamPump>
| ||+	mCachedResponseHead	0x00000000 {mHeaders={mHeaders={mAutoBuf=0x00000008
<Bad Ptr> } } mVersion=??? mStatus=??? ...}	nsHttpResponseHead *
| ||	mCacheAccess	0x00000002	int
| ||	mPostID	0x00000000	unsigned int
| ||	mRequestTime	0x41811ee5	unsigned int
| ||+	mAuthContinuationState	0x00000000	nsISupports *
| ||+	mAuthType	{...}	nsCString
| ||+	mIdent	{mUser=0x00000000 <Bad Ptr> mPass=0x00000000 <Bad Ptr>
mDomain=0x00000000 <Bad Ptr> }	nsHttpAuthIdentity
| ||+	mProxyIdent	{mUser=0x00000000 <Bad Ptr> mPass=0x00000000 <Bad Ptr>
mDomain=0x00000000 <Bad Ptr> }	nsHttpAuthIdentity
| ||+	mEntityID	{...}	nsCString
| ||	mStartPos	0xffffffffffffffff	unsigned __int64
| ||	mRedirectionLimit	0x13 '␓'	unsigned char
| ||	mIsPending	0x00000001	unsigned int
| ||	mApplyConversion	0x00000001	unsigned int
| ||	mAllowPipelining	0x00000001	unsigned int
| ||	mCachedContentIsValid	0x00000000	unsigned int
| ||	mCachedContentIsPartial	0x00000000	unsigned int
| ||	mResponseHeadersModified	0x00000000	unsigned int
| ||	mCanceled	0x00000000	unsigned int
| ||	mTransactionReplaced	0x00000000	unsigned int
| ||	mUploadStreamHasHeaders	0x00000000	unsigned int
| ||	mAuthRetryPending	0x00000000	unsigned int
| ||	mSuppressDefensiveAuth	0x00000000	unsigned int
| |\	mResuming	0x00000000	unsigned int
| \+	nsIRequestObserver	{...}	nsIRequestObserver
|+	mListenerContext	{...}	nsCOMPtr<nsISupports>
|+	mEventQ	{mRawPtr=0x01062a38 {mRefCnt={mValue=0x0000001f }
_mOwningThread={mThread=0x003f5c80 } mEventQueue=0x01062af8 {name=0x00390c08
"Thread event queue..." queue={next=0x039effa0 prev=0x04387b38 }
monitor=0x01062b48 ...} ...} }	nsCOMPtr<nsIEventQueue>
|+	mStream	{mRawPtr=0x00000000 }	nsCOMPtr<nsIInputStream>
|+	mAsyncStream	{mRawPtr=0x034dc330 {mPipe=0x034dc320
{mRefCnt={mValue=0x00000005 } _mOwningThread={mThread=0x003f5c80 }
mInput={mPipe=0x034dc320 mReaderRefCnt=0x00000004 mLogicalOffset={...} ...} ...}
mReaderRefCnt=0x00000004 mLogicalOffset={mValue=0x0000000000000000 } ...} }
nsCOMPtr<nsIAsyncInputStream>
|+	mStreamOffset	{mValue=0x0000000000000000 }	nsTInt64<unsigned __int64>
|+	mStreamLength	{mValue=0xffffffffffffffff }	nsTInt64<unsigned __int64>
|	mSegSize	0x00000000	unsigned int
|	mSegCount	0x00000000	unsigned int
|	mStatus	0x00000000	unsigned int
|	mSuspendCount	0x00000000	unsigned int
|	mLoadFlags	0x00000000	unsigned int
|	mIsPending	0xcd 'Í'	unsigned char
|	mWaiting	0x01 '␁'	unsigned char
\	mCloseWhenDone	0x00	unsigned char
TestProtocols "http://servedby.advertising.com/site=0000195695/mnum=0000252367/c
str=58087413=_42522e52,3691142943,195695%5E252367_/rimp=1"
15 <= 13

self.close();
1234567890123XY
X = \r
Y = \n
-> default owner
Assignee: darin → nobody
Component: Networking: HTTP → Networking
QA Contact: networking.http → networking
Confirmed on Mac trunk: loading

http://hb.lycos.com/header?VID=6105&LHIG=1&ord=178853

triggers this assertion.

I also see it if I load http://hotbot.com/.
Component: Networking → Networking: HTTP
OS: Windows XP → All
QA Contact: networking → networking.http
Hardware: PC → All
OK, in comment 0 the HTTP version in question was 0xb = 11 = NS_HTTP_VERSION_1_1, so this is not limited to HTTP/1.0 servers. Unfortunately I can't tell if keep-alive was used or not.

(context:  Bug 475444)
Loading those hotbot URLs no longer triggers this assertion for me.
I hit this assertion failure in Firefox 28 every time I use the "DownThemAll" addon.

STR:
1. Install https://addons.mozilla.org/en-US/firefox/addon/downthemall/
2. Load any website with images, such as http://imgur.com, http://pinterest.com/all, or even http://cnn.com
3. Select Tools > DownThemAll Tools > DownThemAll menu item
4. In the DownThemAll dialog, select "Pictures and Media" then click the "Start" button

RESULT:

Assertion failure because, in one example, progress was 60462 but progressMax was 32116.

[Parent 65106] WARNING: unexpected progress values - is server exceeding content length?: file /Users/cpeterson/Code/mozilla/inbound/netwerk/protocol/http/nsHttpChannel.cpp, line 5279
Assertion failure: progress <= progressMax (unexpected progress values), at /Users/cpeterson/Code/mozilla/inbound/netwerk/protocol/http/nsHttpChannel.cpp:5407

0 mozilla::net::nsHttpChannel::OnTransportStatus(nsITransport*, tag_nsresult, unsigned long long, unsigned long long) + 1159 (nsHttpChannel.cpp:5381)
1 mozilla::net::nsHttpChannel::OnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) + 343 (nsHttpChannel.cpp:5282)
2 nsInputStreamPump::OnStateTransfer() + 559 (nsInputStreamPump.cpp:592)
3 nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream*) + 280 (nsInputStreamPump.cpp:431)
4 nsInputStreamReadyEvent::Run() + 41 (nsCOMPtr.h:494)
5 nsThread::ProcessNextEvent(bool, bool*) + 1272 (nsThread.cpp:612)
6 NS_ProcessPendingEvents(nsIThread*, unsigned int) + 77 (nsThreadUtils.cpp:210)
7 nsBaseAppShell::NativeEventCallback() + 106 (nsBaseAppShell.cpp:96)
8 nsAppShell::ProcessGeckoEvents(void*) + 191 (nsAppShell.mm:389)
...
Keywords: reproducible
re comment 7 - this is a bug in downthemall.. the OnDataAvailable handler in that addon is not consuming all of the data presented to it which it is required by contract to do:

https://mxr.mozilla.org/mozilla-central/source/netwerk/base/public/nsIStreamListener.idl#19

you will see that nsInputStreamPump is tolerant to this
https://mxr.mozilla.org/mozilla-central/source/netwerk/base/src/nsInputStreamPump.cpp#561

however, nsHttpChannel.cpp isn't.

I think its a good idea to make httpchannel robust to it, but I'll put in an annoying NS_WARNING when the contract is violated.
Assignee: nobody → mcmanus
Status: NEW → ASSIGNED
Comment on attachment 8343128 [details] [diff] [review]
addons with broken OnDataAvailable contract break http channel progress offsets

Review of attachment 8343128 [details] [diff] [review]:
-----------------------------------------------------------------

Good stuff.  A couple nits/ideas.

::: netwerk/protocol/http/nsHttpChannel.cpp
@@ +5309,5 @@
>                                                    count);
> +        if (NS_SUCCEEDED(rv)) {
> +            // by contract mListener must read all of "count" bytes, but
> +            // nsInputStreamPump is tolerant to seekable streams that violate that
> +            // and it will redliver incompletely read data. So we need to do

greenliver. (Am I bikeshedding here?)

@@ +5315,5 @@
> +            int64_t offsetAfter, delta;
> +            if (seekable && NS_SUCCEEDED(seekable->Tell(&offsetAfter))) {
> +                delta = offsetAfter - offsetBefore;
> +                if (delta != count) {
> +                    NS_WARNING("Listener OnDataAvailable contract violation");

Given that addons are the most obvious culprits here, would it be worth dumping this warning to the web console instead/additionally?
Attachment #8343128 - Flags: review?(jduell.mcbugs) → review+
added a console log and fixed the typo

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/0d7d5af0b1b1
c:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/netwerk/protocol/http/nsHttpChannel.cpp(5328) : error C2308: concatenating mismatched strings
        Concatenating wide "http channel Listener OnDataAvailable " with narrow "contract violation"

Apparently NS_LITERAL_STRING("foo " "bar") runs into problems in preprocessor land on windows.. this was the review nit fixup.

try with new syntax:
remote:   https://tbpl.mozilla.org/?tree=Try&rev=c36ac780dc8c
https://hg.mozilla.org/mozilla-central/rev/0bfe8d0cc435
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla29
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: