Closed Bug 595785 Opened 10 years ago Closed 9 years ago

Getting a download's nsIChannel appears unreliable

Categories

(Toolkit :: Downloads API, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla5

People

(Reporter: sparky, Assigned: zcrendel)

References

()

Details

Attachments

(1 file, 3 obsolete files)

User-Agent:       Mozilla/5.0 (X11; Linux x86_64; rv:2.0b6pre) Gecko/20100912 Firefox/4.0b6pre
Build Identifier: 

This is somewhat of a continuation of Bug 593553.

I'm using an nsIDownloadProgressListener's onStateChange to obtain the modification time from the request, and onDownloadStateChange to update the downloaded file.

However, sometimes onStateChange is passed null instead of an nsIChannel. For example, as far as my testing goes:

http://b.fanfiction.net/static/ficons/feed.png
This has a valid nsIChannel for both STATE_START and STATE_STOP

ftp://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/latest-mozilla-central/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
Only has a valid nsIChannel on STATE_START

ftp://ftp.mozilla.org/pub/mozilla.org/ls-lR.gz
Gets no valid nsIChannel

I also added a debug message for onProgressChange as well, and it also appears to be unreliable.

I would think that the nsDownload, or what ever is generating these events, would be able to hang onto the nsIChannel long enough to dispatch and process these events.

Reproducible: Always
All we do is pass whatever we are given:
http://mxr.mozilla.org/mozilla-central/source/toolkit/components/downloads/src/nsDownloadManager.cpp#2534

Maybe it has to do with the content type?  It's not clear to me when we are supposed to be able to QI the nsIWebProgress to an nsIChannel
You mean QI the nsIRequest, right?  Should generally work.

Whoever can reproduce this problem (given that comment 0 doesn't actually have useful STR), can you just set a breakpoint in your code and examine what the stack looks like, who calls you, and how they decide what to pass for the nsIRequest?
Steps to Reproduce:
1. Install the extension
2. In extension preferences, change logging verbosity to Debug
3. Open the error console
4. Clear the error console
5. Download http://b.fanfiction.net/static/ficons/feed.png
6. Download ftp://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/latest-mozilla-central/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
7. Download ftp://ftp.mozilla.org/pub/mozilla.org/ls-lR.gz

The log events you're interested in looking at are:

PDMTS: Network status changed - 0x50001 (ERR: 0)

and

PDMTS: Network status changed - 0x50010 (ERR: 0)

Some downloads have both, some only have the first, and some have neither.
Here are my results



PDMTS: Download status changed - 5
	/tmp/feed.png
 ----------
PDMTS: Network status changed - 0x50001 (ERR: 0)
	http://b.fanfiction.net/static/ficons/feed.png
 ----------
PDMTS: File downloading via HTTP://
	/tmp/feed.png
 ----------
PDMTS: Download status changed - 0
	/tmp/feed.png
 ----------
PDMTS: Download status changed - 1
	/tmp/feed.png
 ----------
PDMTS: Download finished, updating timestamp
	/tmp/feed.png
 ----------
PDMTS: Last modified time now Wed, 17 Mar 2010 22:37:00 GMT
	/tmp/feed.png
 ----------
PDMTS: Network status changed - 0x50010 (ERR: 0)
	http://b.fanfiction.net/static/ficons/feed.png



PDMTS: Download status changed - 5
	/tmp/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
 ----------
PDMTS: Network status changed - 0x50001 (ERR: 0)
	ftp://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/latest-mozilla-central/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
 ----------
PDMTS: File downloading via FTP://
	/tmp/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
 ----------
PDMTS: Download status changed - 0
	/tmp/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
 ----------
PDMTS: Download status changed - 1
	/tmp/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
 ----------
PDMTS: Download finished, updating timestamp
	/tmp/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2
 ----------
PDMTS: Last modified time now Mon, 13 Sep 2010 08:26:53 GMT
	/tmp/firefox-4.0b6pre.en-US.linux-x86_64.tar.bz2



PDMTS: Download status changed - 5
	/tmp/ls-lR.gz
 ----------
PDMTS: Download status changed - 0
	/tmp/ls-lR.gz
 ----------
PDMTS: Download status changed - 1
	/tmp/ls-lR.gz
 ----------
PDMTS: Download finished, updating timestamp
	/tmp/ls-lR.gz
 ----------
PDMTS: Last modified time unavailable
	/tmp/ls-lR.gz
Here's the relevant listener, so you don't need to look in the extension. In testing, I put a debug statement in before the first return and I did verify that "req" is null.

onStateChange: function(prog, req, flags, status, dl)
{
  // We only want to look at the URI we know about
  // Basically, ignore "Web page, complete" downloads
  // Also handle case where req is null
  if(!(req instanceof CI.nsIChannel)
  || !(dl.source.equals(req.URI) || dl.source.equals(req.originalURI)))
  {
	return;
  }

  this.log(LOG_DEBUG, "net.stat", [flags.toString(16), status], req.URI.spec);

  // Only rely on STATE_START and STATE_STOP... and STATE_STOP might come
  // after DOWNLOAD_FINISHED. So wait for STATE_START.
  if(!(flags & CI.nsIWebProgressListener.STATE_START))
  {
	return;
  }

  ...
}
Ok.  What are you adding that listener in comment 5 to?
It's an nsIDownloadProgressListener registered with @mozilla.org/download-manager;1 (via addListener).
OK.

Shawn, what's nsDownloadManager registering with to get its web progress notifications?
And seriously, someone should do what I suggest in comment 2.  I can try to get to it, but it might not happen this week.... and it really can be done by anyone with a debug build.
(In reply to comment #8)
> Shawn, what's nsDownloadManager registering with to get its web progress
> notifications?
Assuming we are going through nsExternalHelperAppService, we do so here:
http://mxr.mozilla.org/mozilla-central/source/uriloader/exthandler/nsExternalHelperAppService.cpp#1288
Oh, I see.  The external helper app service definitely sends state notifications with a null request.  See the end of ExecuteDesiredAction.  By that point, mRequest is null.  I suppose we could try rejiggering that code to hold on to it until then, instead....
That's interesting. I hadn't realized there were [at least] 2 separate download paths. I've done a bit more poking around, and so far I've found:


* Downloads that go through internalSave (saveURL, saveImageURL, saveDocument) in chrome://global/content/contentAreaUtils.js use an nsIWebBrowserPersist. The user picks the target location, it's added to the download manager, and then the download is started.

These downloads appear to reliably get a valid nsIChannel on STATE_START. However, getting an nsIChannel on STATE_STOP is unreliable.


* Downloads that go through nsExternalHelperAppService look to be in-progress as soon as they're clicked on. They are added to the download manager once the user chooses the desired action and/or download directory.

If the download completes before it's added to the download manager, the nsIChannel will be null on STATE_START. And from the implementation, it looks like it's always null on STATE_STOP.


So, at the very least, it looks like the nsExternalHelperAppService needs to be a bit more intelligent about how long it hangs onto an nsIChannel.
Status: UNCONFIRMED → NEW
Ever confirmed: true
(In reply to comment #12)

Is this bug still actual? I found that nsExternalHelperAppService has been updated to hold nsIChannel. I tried to save all three URLs from comment #3 and add-in updated timestamps correctly for each file. Checked with Firefox 4 only.
I still see problems when the download finishes before it's added to the download manager. The nsiIRequest for STATE_START is still null.
Confirmed. The problem still exists. I'm looking for solution.
Here the explanation of the problem. We have 2 ways to download a file. 
1. Use "Save as.."
2. Click on file and wait for helper dialog to appear.

1 one works perfectly, 2 has a problem with nsiIRequest = null. This is related to dialog modality. Let's review the functions call chain for both cases:

1. "Save as..." case:

***** OnStartRequest()
SaveToDisk
PromptForSaveToFile
(Here we have "Save as.." dialog and choose file destination)
CreateProgressListener()
InitializeDownload
PDMTS: Download status changed - 5
        /tmp/index.html.en
CreateProgressListener()
PDMTS: Network status changed - 0x50001 (ERR: 0)
        http://localhost/index.html.en
PDMTS: File downloading via HTTP://
        /tmp/index.html.en
***** OnStartRequest() end
PDMTS: Download status changed - 0
        /tmp/index.html.en
***** OnStopRequest() (Note! AFTER THIS CALL nsiRequest is NULL, but we don't need it since dowload process has been  started)
ExecuteDesiredAction
PDMTS: Download status changed - 1
        /tmp/index.html.en
PDMTS: Download finished, updating timestamp
        /tmp/index.html.en
PDMTS: Last modified time now Sun, 31 Dec 2006 11:42:37 GMT
        /tmp/index.html.en
***** OnStopRequest() end

2. "Click on file and wait for helper dialog to appear" case:
***** OnStartRequest()
***** OnStartRequest() end
***** OnStopRequest()
ExecuteDesiredAction
***** OnStopRequest() end (Note! AFTER THIS CALL nsiRequest is NULL, but we STILL NEED it since download process wasn't started)
ExecuteDesiredAction
Heights: 323, 293
(Here we have helper dialog and choose 'to save' file or to 'open it with')
SaveToDisk
PromptForSaveToFile
CreateProgressListener()
InitializeDownload
PDMTS: Download status changed - 5
        /misc/archive/downloads/unsorted/index.html(1).de
CreateProgressListener()
ExecuteDesiredAction
PDMTS: Download status changed - 0
        /misc/archive/downloads/unsorted/index.html(1).de
PDMTS: Download status changed - 1
        /misc/archive/downloads/unsorted/index.html(1).de
PDMTS: Download finished, updating timestamp
        /misc/archive/downloads/unsorted/index.html(1).de
PDMTS: Last modified time unavailable
        /misc/archive/downloads/unsorted/index.html(1).de

Why second case doesn't work like first one? Because helper dialog isn't in modal mode and I believe it can't be turned into modal mode. Thus the possible solution I see to keep nsiRequest alive after OnStopRequest (or store it in other class member variable) in case if helper dialog is created.
Here is the patch that makes it work as expected. 

Don't know to who ask to review (supereview) it, please let me know if you know.

Regards,
Grigory
Comment on attachment 517251 [details] [diff] [review]
Fixes nsiRequest null for STATE_START

Probably me.  Likely be about a week before I can get to it, however.
Attachment #517251 - Flags: review?(sdwilsh)
This patch doesn't cover all the cases mentioned in comment 12 thought, right?  It only deals with the second case.

Also, this patch has very little context, which makes it difficult to review.  Could you create it as per the instructions here please: https://developer.mozilla.org/en/Creating_a_patch
> This patch doesn't cover all the cases mentioned in comment 12 thought, right? 

It's because comment 12 is about nsiChannel (which is fixed, according to comment 13), but this patch fixes a different problem related to nsiRequest.

> Also, this patch has very little context, which makes it difficult to review. 
Could you create it as per the instructions here please:

I have created this patch for 'default' branch of repository with 'hg diff' command in 'mozilla-central' directory.

What does mean 'little context'? What should I change to make right context patch?

Anyway, if you review the patch content you will see - here is only about 5 lines of changes in 2 files, so it can be easy doable manually or let me know how to produce right patch.
(In reply to comment #20)
> I have created this patch for 'default' branch of repository with 'hg diff'
> command in 'mozilla-central' directory.
The wiki page I linked to says to run 'hg diff -U 8 -p'.  -U 8 means there are 8 lines of context for each diff section, and -p says to include function headers.  Line numbers aren't usually terribly reliable.
Thank you for explanations. I will make a new patch in few minutes.
Here is the patch.
Attachment #517251 - Attachment is obsolete: true
Attachment #517774 - Flags: review?(sdwilsh)
Attachment #517251 - Flags: review?(sdwilsh)
Assignee: nobody → zcrendel
Status: NEW → ASSIGNED
(In reply to comment #20)
> It's because comment 12 is about nsiChannel (which is fixed, according to
> comment 13), but this patch fixes a different problem related to nsiRequest.
So this is dealing with the issue mentioned in comment 14 now, correct?
That's right!
Comment on attachment 517774 [details] [diff] [review]
This patch fixes nsiRequest = null problem for STATE_START

>+++ b/uriloader/exthandler/nsExternalHelperAppService.cpp	Tue Mar 08 20:28:22 2011 +0300
> NS_IMETHODIMP nsExternalAppHandler::OnStopRequest(nsIRequest *request, nsISupports *aCtxt, 
>                                                   nsresult aStatus)
> {
>   mStopRequestIssued = PR_TRUE;
>-  mRequest = nsnull;
>+
>+  if (mKeepRequestAlive)
>+    mKeepRequestAlive = PR_FALSE;
No reason to flip this here; just null out mRequest if mKeepRequestAlive is false.

r=sdwilsh with that change.  bz should probably look at this too since I'm a bit rusty with this code.
Attachment #517774 - Flags: review?(sdwilsh)
Attachment #517774 - Flags: review?(bzbarsky)
Attachment #517774 - Flags: review+
Comment on attachment 517774 [details] [diff] [review]
This patch fixes nsiRequest = null problem for STATE_START

r=me.  Thanks for the patch!

Shawn, are you going to push this when the tree reopens, or should I?
Attachment #517774 - Flags: review?(bzbarsky) → review+
(In reply to comment #26)
> Comment on attachment 517774 [details] [diff] [review]
> This patch fixes nsiRequest = null problem for STATE_START
> 
> >+++ b/uriloader/exthandler/nsExternalHelperAppService.cpp	Tue Mar 08 20:28:22 2011 +0300
> > NS_IMETHODIMP nsExternalAppHandler::OnStopRequest(nsIRequest *request, nsISupports *aCtxt, 
> >                                                   nsresult aStatus)
> > {
> >   mStopRequestIssued = PR_TRUE;
> >-  mRequest = nsnull;
> >+
> >+  if (mKeepRequestAlive)
> >+    mKeepRequestAlive = PR_FALSE;
> No reason to flip this here; just null out mRequest if mKeepRequestAlive is
> false.
> 
> r=sdwilsh with that change.  bz should probably look at this too since I'm a
> bit rusty with this code.
You are right. I recheck this code, this part can be reduced. Will provide patch without it right now.
This is the same patch, but the part:

+  if (mKeepRequestAlive)
+    mKeepRequestAlive = PR_FALSE;
+  else
+    mRequest = nsnull;

reduced to:

+  if (!mKeepRequestAlive)
+    mRequest = nsnull;
Attachment #517774 - Attachment is obsolete: true
Attachment #518270 - Flags: review?(sdwilsh)
Attachment #518270 - Flags: review?(bzbarsky)
Comment on attachment 518270 [details] [diff] [review]
This patch fixes nsiRequest = null problem for STATE_START

r=me again (though note that the places where we null out mRequest we don't need to null-check it.  If it's already null and we set it to null again that's ok!
Attachment #518270 - Flags: review?(bzbarsky) → review+
That's right! How did I missed it? It's just a habit to check :-) Last patch is for your review.
Attachment #518270 - Attachment is obsolete: true
Attachment #518492 - Flags: review?(sdwilsh)
Attachment #518270 - Flags: review?(sdwilsh)
Attachment #518492 - Flags: review?(bzbarsky)
Attachment #518492 - Flags: review?(bzbarsky) → review+
Comment on attachment 518492 [details] [diff] [review]
This patch fixes nsiRequest = null problem for STATE_START

r=sdwilsh
Attachment #518492 - Flags: review?(sdwilsh) → review+
(In reply to comment #27)
> Shawn, are you going to push this when the tree reopens, or should I?
I don't yet have a good way to track bugs to do that, so if you do, please, by all means, land it.
OK.  Taking bug temporarily so I can track it.  Will reassign when I land the patch.
Assignee: zcrendel → bzbarsky
Whiteboard: [need gk2 ship]
Pushed http://hg.mozilla.org/mozilla-central/rev/1ceb81527a08
Assignee: bzbarsky → zcrendel
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Flags: in-testsuite?
Resolution: --- → FIXED
Whiteboard: [need gk2 ship]
Target Milestone: --- → mozilla2.2
Thanks!
Thank you for writing the patch!
You need to log in before you can comment on or make changes to this bug.