136216 - [viewpoint] GetURL fails on https file when the file is partially in the browser's memory cache

Status: VERIFIED FIXED

(Core Graveyard :: Plug-ins, defect, P1)

Description

[Ari Berger]

From Bugzilla Helper:
User-Agent: Mozilla/4.0 (compatible; MSIE 5.5; Windows NT 5.0)
BuildID:    .9.9

This content includes a very large (approx. 500K) file 
(https://192.168.2.81/ari/byterange/byterange.mtx)
which we download through GetURLNotify.  If the user leaves the page before the 
content is fully downloaded, it will be sitting partially downloaded in the 
browser memory cache.
When we come back to the page, we will request the file again.  We get NO 
response- no newstream, no urlnotify.
If I clear the memory cache, THEN try to view the page again, it all works fine.

Reproducible: Always
Steps to Reproduce:
1.Install Viewpoint plugin if you don't have it 
(http://cole.viewpoint.com/~aberger/builds/vpt.zip)
2.View https://192.168.2.81/ari/byterange/byterange.html
3.quickly, before you see the content, hit back.
4. Make sure that you gave it time to start downloading the file but not 
complete.  I assume you can see this on the mozilla end- you have starting 
passing data to the plugin, then cancelled the stream.  Or you can look to see 
if part of the file is present in the Viewpoint Resources directory.  Let me 
know if you need more info.
5. Go back to the content.  Plugin makes a GetURL request, no response, no 
content.
If you waited to long to hit back, so the entire file was downloaded and you 
saw the content, and want to try the test again, clear the mozilla memory cache 
AND the viewpoint cache.  To clear the viewpoint cache, just delte the Program 
Files\Viewpoint\Viewpoint Media Player(or Viewpoint Experience Technology)
\Resources directory.

Comment 1

[Peter Lubczynski]

I wonder if we should be purging the cache entry on failure?

Comment 2

[Darin Fisher]

oh, interesting.  since this is a HTTPS site, the content will be stored only in
the memory cache.  this means that the plugin code will use its own temp
directory for the downloaded data provided this plugin expects a file path to
the location of the content?!  is that what's going on here?

Comment 3

[serge (gone)]

plugin code will save plugin's content into temp file 
only if
http://lxr.mozilla.org/mozilla/source/modules/plugin/base/src/nsPluginHostImpl.c
pp#2012
nsCOMPtr<nsICachingChannel> cacheChannel = do_QueryInterface(channel, &rv);
failed.

BTW: I'm getting "connection refused" for 
https://192.168.2.81/ari/byterange/byterange.mtx

Comment 4

[Darin Fisher]

and the call to SetCacheAsFile should fail for memory cache entries.  so, we
need to verify then that partial downloads result in deleting the temporary file.

Comment 5

[Matthias Versen [:Matti]]

192.168.x is a private network and is not working outside this network because
the router drops the packet

Comment 6

[serge (gone)]

>and the call to SetCacheAsFile should fail for memory cache entries
it does fail, and nothing goes into memory cache
just tested local https://pki.mcom.com/pingform.pdf

>we need to verify then that partial downloads result in deleting the temporary 
>file
we delete this temp file nsPluginStreamInfo::~nsPluginStreamInfo()
1319      if(NS_SUCCEEDED(res))
1320        localFile->Remove(PR_FALSE);
---
so it'll be removed on any reload.

Comment 7

[Ari Berger]

I apoogize.  I forgot that the IP was internal to our network.
Here is the external IP:
208.185.86.81

Comment 8

[serge (gone)]

>and nothing goes into memory cache
I was wrong, it goes into memory cache, even if
2014       rv = cacheChannel->SetCacheAsFile(PR_TRUE);
returns false and plugin code saves the file it into temp file,
but about:cache?device=memory also shows
           Key: https://pki.mcom.com/pingform.pdf
     Data size: 587330 Bytes
   Fetch count: 2
 Last Modified: 04/08/02 14:36:51
       Expires: 04/20/02 09:41:26
---
Darin, is this how it suppose to be? 

Comment 9

[Darin Fisher]

yeah, necko caches the document in the memory cache automatically. 
SetCacheAsFile fails because it's not permissible to store a HTTPS document in
the disk cache.  it's unfortunate that our plugin API requires us to put HTTPS
documents on disk at all.

Comment 10

[serge (gone)]

thanks Darin,
>it's unfortunate that our plugin API requires us to put HTTPS
>documents on disk at all
100% agreed.

Comment 11

[serge (gone)]

I cannot reproduce this with 20020404 w2k build,
here is output from plugins log file
grep "NPP URLNotify called:" pluginLog.txt | grep byterange.mtx
0[304fd8]: NPP URLNotify called: this=416f908, npp=412e230, notify=59a02f0, 
reason=2, 
url=https://208.185.86.81/ari/byterange/byterange.mtx
0[304fd8]: NPP URLNotify called: this=4064d50, npp=496a8a8, notify=59a02f0, 
reason=0, 
url=https://208.185.86.81/ari/byterange/byterange.mtx
---
first NPP URLNotify called with reason=2 (NPRES_USER_BREAK)
stream for byterange.mtx was canceled, no content.
dir C:\Program Files\
Viewpoint\Viewpoint Experience Technology\Resources\ResourceFolder_02
04/08/2002  05:58p             311,296 -1050740563.mtx
04/08/2002  05:58p                 294 URLCache.ini
---
about:cache?device=memory
           Key: https://208.185.86.81/ari/byterange/byterange.mtx
     Data size: 294912 Bytes
   Fetch count: 1
 Last Modified: 04/08/02 17:58:21
       Expires: 04/09/02 01:36:18
---
second  NPP URLNotify with  reason=0 (NPRES_DONE)
I can see the content.
dir C:\Program Files\
\Viewpoint\Viewpoint xperien Technology\Resources\ResourceFolder_02
04/08/2002  06:00p                 294 URLCache.ini
04/08/2002  06:00p             553,055 -1050740563.mtx
---
about:cache?device=memory
           Key: https://208.185.86.81/ari/byterange/byterange.mtx
     Data size: 553055 Bytes
   Fetch count: 1
 Last Modified: 04/08/02 18:00:16
       Expires: 04/09/02 01:38:25
---
Ari, could you try the latest build please?

Comment 12

[Ari Berger]

I will try that build.  My results are from a Mozilla pull from last Friday.

Comment 13

[serge (gone)]

>from last Friday
2000405 yours build is newer then mine, and mine doesn't have the patch for 
bug 131626, let me try to see what I'll get with than patch in

Comment 14

[serge (gone)]

debug build I mentioned above has only plugins source from 20020404,
it doesn't have a fix for bug 116365 [Cache partial documents; automatically 
issue byte range requests], which looks like a cause of this regression.
here is how it fails:
http://lxr.mozilla.org/mozilla/source/modules/plugin/base/src/nsPluginHostImpl.c
pp
for memory partial cache (I have not check disk cache yet) first call of 
1957 nsPluginStreamListenerPeer::OnStartRequest(nsIRequest *request, 
nsISupports* aContext)
...
1984   nsCOMPtr<nsIHttpChannel> httpChannel(do_QueryInterface(channel));
...
1987   if (httpChannel) {
1988     PRUint32 responseCode = 0;
1989     rv = httpChannel->GetResponseStatus(&responseCode);
fails here, because of 
nsHttpChannel::GetResponseStatus(PRUint32 *value){
    if (!mResponseHead)
        return NS_ERROR_NOT_AVAILABLE;
mResponseHead == 0
--
is necko fires OnStartRequest too early?
Darin, any thoughts? 

Comment 15

[serge (gone)]

the next change seems to fix the problem:
RCS file: /cvsroot/mozilla/netwerk/protocol/http/src/nsHttpChannel.cpp,v
retrieving revision 1.107
diff -u -r1.107 nsHttpChannel.cpp
--- nsHttpChannel.cpp   9 Apr 2002 00:03:23 -0000       1.107
+++ nsHttpChannel.cpp   9 Apr 2002 19:24:30 -0000
@@ -2733,7 +2733,7 @@
         this, request, mStatus));

     // don't enter this block if we're reading from the cache...
-    if (NS_SUCCEEDED(mStatus) && !mCacheReadRequest && mTransaction) {
+    if (NS_SUCCEEDED(mStatus) && !mCachedContentIsPartial && mTransaction) {
         // grab the security info from the connection object; the transaction
         // is guaranteed to own a reference to the connection.
         mSecurityInfo = mTransaction->SecurityInfo();

Comment 16

[rubydoo123]

adding nsbeta1+ to this one

Comment 17

[Darin Fisher]

hmm.. that's very strange.  mResponseHead should not be NULL when OnStartRequest
is called.  can you generate a HTTP log corresponding to this problem?

set NSPR_LOG_MODULES=nsHttp:5
set NSPR_LOG_FILE=c:\http.log

thx!

Comment 18

[Darin Fisher]

restoring keyword, target milestone, and priority changes that i just trampled on.

Comment 19

[serge (gone)]

Attachment: http log

about:cache?device=memory
https://208.185.86.81/ari/byterange/byterange.html
<Back>
<Forward>

Comment 20

[serge (gone)]

Attachment: patch v1

here is how
nsHttpChannel.cpp:2741 nsHttpChannel::OnStartRequest(nsIRequest *request,
nsISupports *ctxt) cleans up mResponseHead:
on first nsHttpChannel::ReadFromCache() mCacheReadRequest is not set yet
so we go inside if() line 2753, and null mResponseHead on line 2760
   2752     // don't enter this block if we're reading from the cache...
   2753     if (NS_SUCCEEDED(mStatus) && !mCacheReadRequest && mTransaction) {
...
   2760 	mResponseHead = mTransaction->TakeResponseHead();
...
this patch seems to help.
Darin, what do you think?

Comment 21

[Darin Fisher]

serge: can you explain how that patch helps?  thx!

Comment 22

[serge (gone)]

I'm trying to put some comments on the stack trace,
hopefully it'll explain what's happening.
lines start with "["   are source code
lines start with "[*" are  my comments

nsHttpChannel::OnStartRequest(nsHttpChannel * const 0x03bbfb6c, nsIRequest * 
0x03ea0b98, nsISupports * 
0x00000000) line 2753
[* we do actually read from the cache, but w/o patch mCacheReadRequest is 0,
[* it will be set only after nsStorageTransport::nsReadRequest::Process() 
[    // don't enter this block if we're reading from the cache...
[    if (NS_SUCCEEDED(mStatus) && !mCacheReadRequest && mTransaction) {
[        // grab the security info from the connection object; the transaction
[        // is guaranteed to own a reference to the connection.
[        mSecurityInfo = mTransaction->SecurityInfo();
[        // all of the response headers have been acquired, so we can take 
[ownership
[        // of them from the transaction.
[        mResponseHead = mTransaction->TakeResponseHead();
[* mResponseHead == 0
[        // the response head may be null if the transaction was cancelled.  in
[        // which case we just need to call OnStartRequest/OnStopRequest.
[       if (mResponseHead)
[          return ProcessResponse();
[    }
[    // there won't be a response head if we've been cancelled
[    nsresult rv = mListener->OnStartRequest(this, mListenerContext);
[* here nsPluginStreamListenerPeer::OnStartRequest() is getting called with 
[* mResponseHead==0
[* and we are canceling the stream.

nsStorageTransport::nsReadRequest::Process() line 465
nsStorageTransport::AsyncRead(nsStorageTransport * const 0x03f08e38, 
nsIStreamListener * 0x03bbfb6c, 
nsISupports * 0x00000000, unsigned int 0, unsigned int 4294967295, unsigned int 
0, nsIRequest * * 0x03bbfc40) 
line 381 + 8 bytes
[* assign nsHttpChannel.mCacheReadRequest = *aRequest =  reader;
[* before reader->Process()
[    rv = reader->SetListener(aListener, aContext);
[    if (NS_SUCCEEDED(rv)) {
[      *aRequest = reader;
[      rv = reader->Process();

nsCacheEntryDescriptor::nsTransportWrapper::AsyncRead(nsCacheEntryDescriptor::ns
TransportWrapper * const 
0x0529ee9c, nsIStreamListener * 0x03bbfb6c, nsISupports * 0x00000000, unsigned 
int 0, unsigned int 
4294967295, unsigned int 0, nsIRequest * * 0x03bbfc40) line 567
nsHttpChannel::ReadFromCache() line 1217 + 105 bytes
[* mCacheReadRequest == 0
[    // Pump the cache data downstream
[    return mCacheTransport->AsyncRead(this, mListenerContext,
[                                      0, PRUint32(-1), 0,
[                                      getter_AddRefs(mCacheReadRequest));

nsHttpChannel::ProcessPartialContent() line 680 + 8 bytes
nsHttpChannel::ProcessResponse() line 499 + 8 bytes
nsHttpChannel::OnStartRequest(nsHttpChannel * const 0x03bbfb6c, nsIRequest * 
0x053e083c, nsISupports * 
0x00000000) line 2764 + 11 bytes
nsOnStartRequestEvent::HandleEvent() line 161 + 53 bytes
nsARequestObserverEvent::HandlePLEvent(PLEvent * 0x03ffd974) line 116
PL_HandleEvent(PLEvent * 0x03ffd974) line 596 + 10 bytes
PL_ProcessPendingEvents(PLEventQueue * 0x01593f48) line 526 + 9 bytes
_md_EventReceiverProc(HWND__ * 0x002b0518, unsigned int 49350, unsigned int 0, 
long 22626120) line 1077 + 
9 bytes
USER32! UserCallWinProc@20 + 24 bytes
USER32! DispatchMessageWorker@8 + 244 bytes
USER32! DispatchMessageA@4 + 11 bytes
nsAppShell::Run(nsAppShell * const 0x01b0f410) line 115
nsAppShellService::Run(nsAppShellService * const 0x01b23158) line 309
main1(int 3, char * * 0x003077b8, nsISupports * 0x00000000) line 1415 + 32 bytes
main(int 3, char * * 0x003077b8) line 1763 + 37 bytes
mainCRTStartup() line 338 + 17 bytes

Comment 23

[Darin Fisher]

ah, so the real problem is actually the fact that the OnStartRequest is called
before AsyncRead returns.  that violates the rules of nsITransport,
nsIRequestObserver (which need to be documented!!).  anyways, the solution is to
call OnStartRequest via mListenerProxy instead of mListener.  can you try that
and see if it also solves this bug?  thx!

Comment 24

[serge (gone)]

nsStorageTransport::nsReadRequest::Process()
{
    nsresult rv = NS_OK;

    // this method must always be called on the client's thread
    NS_ENSURE_TRUE(mTransport, NS_ERROR_NOT_INITIALIZED);

    // always clear this flag initially
    mWaitingForWrite = PR_FALSE;

    if (!mOnStartFired) {
        // no need to proxy this callback
        mListener->OnStartRequest(this, mListenerContext);
---
[* I've tried to change it here, it screws everything:(

Comment 25

[Darin Fisher]

doh!  of course, because mListenerProxy is a proxy back to |this|... and
nsStorageTransport::nsReadRequest::OnStartRequest is not implemented.  it wasn't
implemented because it was never expected to be called.  however, if we just
implement it like so:

{
    NS_ASSERTION(mListener, "no listener");
    mListener->OnStartRequest(aRequest, aContext);
}

my suggestion to call mListenerProxy->OnStartRequest instead of
mListener->OnStartRequest from Process() should work.  can you give this a try?

Comment 26

[Darin Fisher]

Attachment: suggested patch

Comment 27

[serge (gone)]

Comment on attachment 78920 [details] [diff] [review]
suggested patch

yep, it works, r=serge

Comment 28

[serge (gone)]

reassign to darin as an author of the patch. thanks

Comment 29

[rpotts (gone)]

Comment on attachment 78920 [details] [diff] [review]
suggested patch

sr=[e-mail]

Comment 30

[Asa Dotzler [:asa]]

Comment on attachment 78920 [details] [diff] [review]
suggested patch

a=asa (on behalf of drivers) for checkin to the 1.0 branch

Comment 31

[Jaime Rodriguez, Jr.]

Pls land this on the trunk tonight. Once, Shir has verified the fix resolves the
issue, and causes no other regressions, pls update the bug.

Comment 32

[Darin Fisher]

fixed-on-trunk

Comment 33

[Darin Fisher]

shrir: can you please verify this bug ASAP... it is important that we fix this
on the 1.0 branch for RC1, but ADT requires that you verify this before i land
it on the 1.0 branch.  thx!

Comment 34

[Ari Berger]

I'll try this out tomorrow also. Thanks for all of your work on this.

Comment 35

[shrirang khanzode]

sure, will try first thing tomorrow morning 

Comment 36

[shrirang khanzode]

Ok, I verified this exactly as Ari has mentioned in his steps above. I used the
url in the url field since the other url did not work for me. I made the file
'1050740563.mtx' load partially and then confirmed that was the case ( Prog
files/viewpoint..."; 16kb) and then revisited the page. The file loaded
completely (541 kb) and the cube displayed just fine. However, I see some mouse
flicker as the cube is rotated, but surely there is another bug filed for that.
Used 0416 trunk build on NT.

Comment 37

[Ari Berger]

This works for me. Thank's again.
Shrir- you are correct- there is another bug open for the mousing problems 
(135737).

Comment 38

[scottputterman]

adding adt1.0.0+.  Please check this into the branch as soon as possible and add
the fixed1.0.0 keyword.

Comment 39

[Darin Fisher]

looks like this fix has resulted in a topcrasher on the trunk (bug 138280)...
holding off on landing this on the branch until bug 138280 is resolved.

Comment 40

[Darin Fisher]

fixed-on-branch

Comment 41

[shrirang khanzode]

verif on branch 0426 build .