Getting further into this bug... I set
NSPR_LOG_MODULES=nsSocketTransport:5,nsHttp:5
The disconnect appears to happen between these two methods.
From nsHttpTransaction.cpp
290 void
291 nsHttpTransaction::OnTransportStatus(nsresult status, PRUint64 progress)
292 {
293 LOG(("nsHttpTransaction::OnSocketStatus [this=%x status=%x
progress=%llu]\n",
294 this, status, progress));
295
296 if (!mTransportSink)
297 return;
298
299 NS_ASSERTION(PR_GetCurrentThread() == gSocketThread, "wrong
thread");
300
301 // nsHttpChannel synthesizes progress events in OnDataAvailable
302 if (status == nsISocketTransport::STATUS_RECEIVING_FROM)
303 return;
304
305 nsUint64 progressMax;
306
307 if (status == nsISocketTransport::STATUS_SENDING_TO) {
308 // suppress progress when only writing request headers
309 if (!mHasRequestBody)
310 return;
311
312 // when uploading, we include the request headers in the
progress
313 // notifications.
314 progressMax = mRequestSize; // XXX mRequestSize is 32-bit!
315 }
316 else {
317 progress = LL_ZERO;
318 progressMax = 0;
319 }
320
321 mTransportSink->OnTransportStatus(nsnull, status, progress,
progressMax);
322 }
From nsHttpChannel.cpp
4027 NS_IMETHODIMP
4028 nsHttpChannel::OnTransportStatus(nsITransport *trans, nsresult status,
4029 PRUint64 progress, PRUint64
progressMax)
4030 {
4031 // block socket status event after Cancel or OnStopRequest has
been called.
4032 if (mProgressSink && NS_SUCCEEDED(mStatus) && mIsPending &&
!(mLoadFlags & LOAD_BACKGROUND)) {
4033 LOG(("sending status notification [this=%x status=%x
progress=%llu/%llu]\n",
4034 this, status, progress, progressMax));
4035
4036 nsCAutoString host;
4037 mURI->GetHost(host);
4038 mProgressSink->OnStatus(this, nsnull, status,
4039 NS_ConvertUTF8toUTF16(host).get());
4040
4041 if (progress > 0)
4042 mProgressSink->OnProgress(this, nsnull, progress,
progressMax);
4043 }
4044 #ifdef DEBUG
4045 else
4046 LOG(("skipping status notification [this=%x sink=%x
pending=%u background=%x]\n",
4047 this, mProgressSink.get(), mIsPending, (mLoadFlags &
LOAD_BACKGROUND)));
4048 #endif
4049
4050 return NS_OK;
4051 }
3344[106e8d8]: nsSocketTransport::SendStatus [this=22edea8 status=804b0003]
3344[106e8d8]: nsHttpTransaction::OnSocketStatus [this=22c8400
status=804b0003 progress=0]
3344[106e8d8]: nsSocketTransport::OnSocketEvent [this=22edea8 type=0
status=0 param=0]
3344[106e8d8]: MSG_ENSURE_CONNECT
3344[106e8d8]: ignoring redundant event
3344[106e8d8]: calling PR_Poll [active=0 idle=0]
0[274a98]: sending status notification [this=2280508 status=804b0003
progress=0/0]
4080[13b4c10]: nsSocketTransport::PostEvent [this=22edea8 type=1
status=0 param=231fa90]
4080[13b4c10]: nsSocketTransportService::PostEvent [event=231fb30]
3344[106e8d8]: nsSocketTransport::OnSocketEvent [this=22edea8 type=1
status=0 param=231fa90]
3344[106e8d8]: MSG_DNS_LOOKUP_COMPLETE
3344[106e8d8]: nsSocketTransport::InitiateSocket [this=22edea8]
3344[106e8d8]: nsSocketTransport::BuildSocket [this=22edea8]
3344[106e8d8]: nsSocketTransportService::AttachSocket [handler=22edea8]
3344[106e8d8]: nsSocketTransportService::AddToIdleList [handler=22edea8]
3344[106e8d8]: active=0 idle=1
3344[106e8d8]: advancing to STATE_CONNECTING
3344[106e8d8]: nsSocketTransport::SendStatus [this=22edea8 status=804b0007]
3344[106e8d8]: nsHttpTransaction::OnSocketStatus [this=22c8400
status=804b0007 progress=0]
3344[106e8d8]: trying address: 216.109.126.22
3344[106e8d8]: idle [0] { handler=22edea8 condition=0 pollflags=6 }
3344[106e8d8]: nsSocketTransportService::AddToPollList [handler=22edea8]
3344[106e8d8]: active=1 idle=1
3344[106e8d8]: nsSocketTransportService::RemoveFromIdleList
[handler=22edea8]
3344[106e8d8]: active=1 idle=0
3344[106e8d8]: calling PR_Poll [active=1 idle=0]
3344[106e8d8]: nsSocketTransport::OnSocketReady [this=22edea8 outFlags=2]
3344[106e8d8]: advancing to STATE_TRANSFERRING
3344[106e8d8]: nsSocketTransport::SendStatus [this=22edea8 status=804b0004]
3344[106e8d8]: nsHttpTransaction::OnSocketStatus [this=22c8400
status=804b0004 progress=0]
3344[106e8d8]: active [0] { handler=22edea8 condition=0 pollflags=7 }
3344[106e8d8]: calling PR_Poll [active=1 idle=0]
3344[106e8d8]: nsSocketTransport::OnSocketReady [this=22edea8 outFlags=2]
3344[106e8d8]: nsSocketOutputStream::OnSocketReady [this=22edf58 cond=0]
3344[106e8d8]: nsHttpConnection::OnSocketWritable [this=22edd70]
3344[106e8d8]: writing transaction request stream
3344[106e8d8]: nsSocketOutputStream::Write [this=22edf58 count=1049]
3344[106e8d8]: calling PR_Write [count=1049]
3344[106e8d8]: PR_Write returned [n=1049]
3344[106e8d8]: nsSocketTransport::SendStatus [this=22edea8 status=804b0005]
3344[106e8d8]: nsHttpTransaction::OnSocketStatus [this=22c8400
status=804b0005 progress=1049]
3344[106e8d8]: ReadSegments returned [rv=0 read=1049 sock-cond=0]
3344[106e8d8]: writing transaction request stream
3344[106e8d8]: ReadSegments returned [rv=0 read=0 sock-cond=0]
3344[106e8d8]: nsHttpTransaction::OnSocketStatus [this=22c8400
status=804b000a progress=0]
3344[106e8d8]: nsSocketInputStream::AsyncWait [this=22edf3c]
3344[106e8d8]: active [0] { handler=22edea8 condition=0 pollflags=5 }
3344[106e8d8]: calling PR_Poll [active=1 idle=0]
0[274a98]: sending status notification [this=2280508 status=804b000a
progress=0/0]
I don't see the 'sending status notification' log entries for each
nsHttpTransaction::OnSocketStatus log entry. The only one that seems to
be specifically excluded is the nsISocketTransport::STATUS_SENDING_TO
status (804b0005)
Is nsHttpTransaction::mTransportSink a proxy fpr the real sink? I notice
the 'sending status notification' entries are on the main thread, but
nsHttpTransaction is not. Is it possible that some events are collapsed
in the event queue? If so, why would gecko want to do that?
Thanks
LeRoy
_______________________________________________
Mozilla-netlib mailing list
Mozilla-netlib@mozilla.org
http://mail.mozilla.org/listinfo/mozilla-netlib
