1247641 - New Tab page creates thousands of requests to my server

Status: RESOLVED FIXED

(Firefox :: New Tab Page, defect)

Description

[Matt Kacskos]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/47.0.2526.111 Safari/537.36

Steps to reproduce:

1.  Navigate to a website.
2.  Navigate to a different page.
3.  Click menu > History > Clear recent history, select everything, and click clear all.
4.  Open new tab.


Actual results:

Firefox continually sent requests (over 1000) to the website in step 1 in order to get a preview of the page.  (The site tries to set a cookie on the page that Firefox wants to give a preview of, and--looking at the cookies saved-- Firefox does not appear to be saving it.)


Expected results:

Firefox sends one request to the site.

Comment 1

[Kelly]

I too, can confirm this behavior.

It appears the New Tab (Tiles Tab) does not send cookies to the thumbnail sites even if FF has a valid cookie already stored.  However, since the Tile Tab does follow redirects, it gets stuck in a loop if the website redirects in order to set a session cookie.

Comment 2

[:Gijs (he/him)]

(In reply to Kelly from comment #1)
> I too, can confirm this behavior.
> 
> It appears the New Tab (Tiles Tab) does not send cookies to the thumbnail
> sites even if FF has a valid cookie already stored.

Correct. Doing so would violate users' privacy.

>  However, since the Tile
> Tab does follow redirects, it gets stuck in a loop if the website redirects
> in order to set a session cookie.

Wouldn't the same thing happen if people visited your website with cookies disabled?


(In reply to Matt Kacskos from comment #0)
> Actual results:
> 
> Firefox continually sent requests (over 1000) to the website in step 1 in
> order to get a preview of the page.  (The site tries to set a cookie on the
> page that Firefox wants to give a preview of, and--looking at the cookies
> saved-- Firefox does not appear to be saving it.)

Can you actually provide a link to the website and page in question?

Is that site / page doing the same thing as comment #1 ? Are all the over 1000 requests to the exact same URL, or is it fetching subresources (styles, images, scripts, etc.) ?

Comment 3

[Kelly]

This seems to be new behavior with just FF44.  I don't have an old one to test myself, but I don't see previous versions looping in my web logs.  I checked logs back to Jan 1 and this all started approx Jan 29 with 44+.  I do see a few FF45 and FF46 looping.  I guess those are pre-release versions some users are running.

You are welcome to try it here:  https://mygateway.umsl.edu

We use a commercial Tomcat-based product, so I don't have a way to alter the initial redirects that happen to get you a guest session.

>> It appears the New Tab (Tiles Tab) does not send cookies to the thumbnail
>> sites even if FF has a valid cookie already stored.

>Correct. Doing so would violate users' privacy.

Well, I guess it's okay to not send a valid cookie from my own cookie store (I don't really see a privacy problem there), but the New Tab has to either use separate cookie store that works or stop following the redirects.  

I'm still wondering what the pre 44 behavior was.  I'll try to find one to test.

Comment 4

[Matt Kacskos]

> Can you actually provide a link to the website and page in question?

I can give you the address to our dev site: bbdev.niunt.niu.edu. (I don't want to try to add any more volume to production.)

>Are all the over 1000 requests to the exact same URL, or is it fetching subresources (styles, images, scripts, etc.) ?

Here are the two looping log entries that I observe from our tomcat access logs:

--1--
10.159.109.111 10.4.2.250 http-nio-8084-exec-38 {unset id} [05/Feb/2016:00:08:08 -0600] "GET /webapps/portal/execute/defaultTab HTTP/1.1" 200 1074 "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:44.0) Gecko/20100101 Firefox/44.0" "-" 0 1074
--2--
10.159.109.111 10.4.2.250 http-nio-8084-exec-66 {unset id} [05/Feb/2016:00:08:08 -0600] "GET /webapps/login/?new_loc=%2Fwebapps%2Fportal%2Fexecute%2FdefaultTab HTTP/1.1" 200 1012 "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:44.0) Gecko/20100101 Firefox/44.0" "-" 16 1012

No requests for scripts, images, etc.

Here's a wireshark from me opening the new tab page: http://go.niu.edu/l6qpu5

Comment 5

[:Gijs (he/him)]

(In reply to Matt Kacskos from comment #4)
> > Can you actually provide a link to the website and page in question?
> 
> I can give you the address to our dev site: bbdev.niunt.niu.edu. (I don't
> want to try to add any more volume to production.)
> 
> >Are all the over 1000 requests to the exact same URL, or is it fetching subresources (styles, images, scripts, etc.) ?
> 
> Here are the two looping log entries that I observe from our tomcat access
> logs:
 
> Here's a wireshark from me opening the new tab page: http://go.niu.edu/l6qpu5

OK. I can try to look at this the beginning of next week, or, and this might be quicker, you or Kelly could try running mozregression: http://mozilla.github.io/mozregression/ to narrow down when the behaviour here changed, as Kelly pointed out this is new in 44.

Another option that might be quicker than me having another look next week: Drew, do you know what happened here?

(In reply to Kelly from comment #3)
> >> It appears the New Tab (Tiles Tab) does not send cookies to the thumbnail
> >> sites even if FF has a valid cookie already stored.
> 
> >Correct. Doing so would violate users' privacy.
> 
> Well, I guess it's okay to not send a valid cookie from my own cookie store
> (I don't really see a privacy problem there)

Consider a banking website and us taking a screenshot (and continually showing that on the new tab page) of your balance (after you've logged out, because of course we don't refetch the screenshots every time you open the new tab page). Or a screenshot of an email, or your social networking messages, or ...

>, but the New Tab has to either
> use separate cookie store that works or stop following the redirects.

It should be using a separate cookie store, I think... though of course it's always possible that something broke. :-\

Comment 6

[Kelly]

(In reply to :Gijs Kruitbosch from comment #5)
> Consider a banking website and us taking a screenshot (and continually
> showing that on the new tab page) of your balance (after you've logged out,
> because of course we don't refetch the screenshots every time you open the
> new tab page). Or a screenshot of an email, or your social networking
> messages, or ...

Well, I see you're point about not showing sensitive thumbnails.  However, I believe the new tab page _IS_ refetching the screenshots every time you open it, maybe subject to a timer.  It doesn't happen if I open the new tab immediately following one that looped, but if I'm idle a few minutes, then open a new tab, the refetch (and looping) happens all over again.

I'll try mozregression and see if I can make it work for me.  However, I was able to download and install FF43 and the behavior is good there.  I open the new tab and get exactly one loop cycle in my web logs.  I do not see the FF43 new tab sending any cookies to the web log either, tho.  Somehow FF43 is just stopping the loop.

Comment 7

[Kelly]

Okay, I think I got mozregression to work.  I walked through several bisection versions marking them Good or Bad until it finally stopped.  Not sure how much of the log your really need.  Here are the last couple chunks (but I have the whole thing if needed):

2016-02-12T11:29:30: INFO : platform_version: 45.0a1
2016-02-12T11:39:00: INFO : Narrowed inbound regression window from [d0da0df3, f6b31718] (5 revisions) to [8060eb50, f6b31718] (3 revisions) (~1 steps left)
2016-02-12T11:39:00: INFO : Running mozilla-inbound build built on 2015-10-30 19:41:05.482000, revision 89c9c63c
2016-02-12T11:39:02: INFO : Launching c:\users\cronek\appdata\local\temp\tmplxcu5r\firefox\firefox.exe
2016-02-12T11:39:02: INFO : application_buildid: 20151030115535
2016-02-12T11:39:02: INFO : application_changeset: 89c9c63c76543e3900e06640cc6e365edfeb4881
2016-02-12T11:39:02: INFO : application_display_name: Nightly
2016-02-12T11:39:02: INFO : application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
2016-02-12T11:39:02: INFO : application_name: Firefox
2016-02-12T11:39:02: INFO : application_remotingname: firefox
2016-02-12T11:39:02: INFO : application_repository: https://hg.mozilla.org/integration/mozilla-inbound
2016-02-12T11:39:02: INFO : application_vendor: Mozilla
2016-02-12T11:39:02: INFO : application_version: 45.0a1
2016-02-12T11:39:02: INFO : platform_buildid: 20151030115535
2016-02-12T11:39:02: INFO : platform_changeset: 89c9c63c76543e3900e06640cc6e365edfeb4881
2016-02-12T11:39:02: INFO : platform_repository: https://hg.mozilla.org/integration/mozilla-inbound
2016-02-12T11:39:02: INFO : platform_version: 45.0a1
2016-02-12T11:40:39: INFO : Narrowed inbound regression window from [8060eb50, f6b31718] (3 revisions) to [89c9c63c, f6b31718] (2 revisions) (~1 steps left)
2016-02-12T11:40:39: DEBUG : Starting merge handling...
2016-02-12T11:40:39: DEBUG : Using url: https://hg.mozilla.org/integration/mozilla-inbound/json-pushes?changeset=f6b31718d94d59bb3eb3c27386fea90701a6772a&full=1
2016-02-12T11:40:39: DEBUG : Found commit message:
Bug 1215659. Use destination canvas for thumbnail size if provided one. r=adw

Comment 8

[:Gijs (he/him)]

(In reply to Kelly from comment #7)
> Okay, I think I got mozregression to work.  I walked through several
> bisection versions marking them Good or Bad until it finally stopped.  Not
> sure how much of the log your really need.  Here are the last couple chunks
> (but I have the whole thing if needed):

> 2016-02-12T11:40:39: DEBUG : Using url:
> https://hg.mozilla.org/integration/mozilla-inbound/json-
> pushes?changeset=f6b31718d94d59bb3eb3c27386fea90701a6772a&full=1
> 2016-02-12T11:40:39: DEBUG : Found commit message:
> Bug 1215659. Use destination canvas for thumbnail size if provided one. r=adw

Great, many thanks!

Adding :mchang to the needinfo list.

I suspect that this:

https://hg.mozilla.org/integration/mozilla-inbound/rev/f6b31718d94d59bb3eb3c27386fea90701a6772a#l2.13

         (flags & Ci.nsIWebProgressListener.STATE_STOP) &&
-        this._currentCapture) {
+        this._currentCapture && Components.isSuccessCode(status)) {

makes the thumbnail capture code unhappy about the redirects, but I haven't looked at it in detail.

(In reply to Mason Chang [:mchang] from bug 1215659 comment #3)
> Also, sometimes, we'd get a black canvas because nsIProgressWatcher would
> actually give us an error, but we'd continue to snapshot the page. The web
> content wasn't actually ready, so we'd snapshot nothing.

Kelly, based on this, out of curiosity, were previews for your pages black on 43 / "good" versions?

Comment 9

[:Gijs (he/him)]

Hmm, it also seems like bug 1231518 then changed this code some more, but that fix didn't make it into 44. Can you still reproduce the problem with Firefox 45? ( https://beta.mozilla.org/ )

Comment 10

[Matt Kacskos]

(In reply to :Gijs Kruitbosch from comment #9)
> Hmm, it also seems like bug 1231518 then changed this code some more, but
> that fix didn't make it into 44. Can you still reproduce the problem with
> Firefox 45? ( https://beta.mozilla.org/ )

Yes, I can still replicate it with 45.0b4.

Comment 11

[Mason Chang [Inactive] [:mchang]]

> 
> (In reply to Mason Chang [:mchang] from bug 1215659 comment #3)
> > Also, sometimes, we'd get a black canvas because nsIProgressWatcher would
> > actually give us an error, but we'd continue to snapshot the page. The web
> > content wasn't actually ready, so we'd snapshot nothing.
> 
> Kelly, based on this, out of curiosity, were previews for your pages black
> on 43 / "good" versions?

Comment 12

[Mason Chang [Inactive] [:mchang]]

Matt were your pages also black on 43?

Comment 13

[Kelly]

(In reply to :Gijs Kruitbosch from comment #8)
> (In reply to Kelly from comment #7)

> 
> Kelly, based on this, out of curiosity, were previews for your pages black
> on 43 / "good" versions?

Yes, previews are black on "good" and white on "bad" versions.

Comment 14

[Matt Kacskos]

(In reply to Mason Chang [:mchang] from comment #12)
> Matt were your pages also black on 43?

Yes, the preview is black on 43.  The problem is not present with FF 43.

Comment 15

[Drew Willcoxon :adw]

Attachment: load about:blank asyncly on failure

If you look at the file before we added the isSuccessCode check [1], the difference in this case is that we used to call _captureCurrentPage, and now we call _loadAboutBlank.  _captureCurrentPage itself calls _loadAboutBlank, so what's the problem?  The only difference is that _captureCurrentPage calls _loadAboutBlank asyncly.  So we used to call _loadAboutBlank asyncly in this case, and now we call it syncly, while onStateChange is still on the stack.

So I modified the call to _loadAboutBlank to be done in a timer callback, and sure enough, that fixes it when I test with the URL in comment 3.  Shrug.

[1] http://mxr.mozilla.org/mozilla-central/source/toolkit/components/thumbnails/content/backgroundPageThumbsContent.js?rev=d6793bb3e45b

Comment 16

[Drew Willcoxon :adw]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=54ff05d74f49

Comment 17

[Drew Willcoxon :adw]

Thanks for filing the bug and commenting by the way.  This is a crazy bug.

Comment 18

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8719103 [details] [diff] [review]
load about:blank asyncly on failure

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

heh - *shrug* indeed

Comment 19

[:Gijs (he/him)]

Thanks Drew!

Comment 20

[Drew Willcoxon :adw]

Attachment: patch v2

This patch fixes the browser_thumbnails_bg_queueing.js failure on try, for me locally.  It's a small change so I'll carry forward the r+.  If the capture is already canceled, then about:blank is being loaded, so we should not attempt to load it again.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=8f7ca6add265

The diff between the previous patch and this one is:

> diff --git a/toolkit/components/thumbnails/content/backgroundPageThumbsContent.js b/toolkit/components/thumbnails/content/backgroundPageThumbsContent.js
> --- a/toolkit/components/thumbnails/content/backgroundPageThumbsContent.js
> +++ b/toolkit/components/thumbnails/content/backgroundPageThumbsContent.js
> @@ -112,17 +112,18 @@ const backgroundPageThumbsContent = {
>            this._startNextCapture();
>          }
>        }
>        else if (this._state == STATE_LOADING &&
>                 Components.isSuccessCode(status)) {
>          // The requested page has loaded.  Capture it.
>          this._state = STATE_CAPTURING;
>          this._captureCurrentPage();
> -      } else {
> +      }
> +      else if (this._state != STATE_CANCELED) {
>          // Something went wrong.  Cancel the capture.  Loading about:blank
>          // while onStateChange is still on the stack does not actually stop
>          // the request if it redirects, so do it asyncly.
>          this._state = STATE_CANCELED;
>          if (!this._cancelTimer) {
>            this._cancelTimer =
>              Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer);
>            this._cancelTimer.init(() => {

Comment 21

[Drew Willcoxon :adw]

Well there were leaks on ASAN on try but they seemed to have gone away after refreshing my tree.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=eae1114fc2d0
https://hg.mozilla.org/integration/fx-team/rev/bf152107a11d

Comment 22

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/bf152107a11d

Comment 23

[Drew Willcoxon :adw]

Comment on attachment 8719916 [details] [diff] [review]
patch v2

Approval Request Comment
[Feature/regressing bug #]: bug 1215659
[User impact if declined]: No user-facing impact really, but sites that redirect when Firefox tries to capture a background thumbnail may see endless requests
[Describe test coverage new/current, TreeHerder]: No new tests for this bug, but thumbnailing has existing tests
[Risks and why]: Low risk, small patch
[String/UUID change made/needed]: none

Comment 24

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8719916 [details] [diff] [review]
patch v2

Important impact on both the website and the user system, taking it.
Should be in 45 beta 9.

Comment 25

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/f91ceb63900a

Comment 26

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/1089db7db84d

Comment 27

[Kazi Nuzhat Tasnem]

I have reproduced this bug with Firefox nightly 47.0a1(build id:20160211030242)on
windows 7(64 bit)

I have verified this bug as fixed with Firefox beta 46.0b2(build id:20160316065941)
User Agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0

[testday-20160318]

Comment 28

[Bolaram Paul [:ancon]]

The bug is now verified on Latest Beta 46.0b2!

Build ID: 20160316065941
User Agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0

Comment 29

[Mayur Patil]

bugday-20160323]

Status: RESOLVED,FIXED -> VERIFIED

Comments:
Test Successful

Component: 
Name			Firefox
Version			46.0b9
Build ID		20160322075646
Update Channel          beta
User Agent		Mozilla/5.0 (Windows NT 6.1; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0
OS			Windows 7 SP1 x86_64

Expected Results: 
Yes

Actual Results: 
As expected

Comment 30

[Comorasu Cristian]

Tested on Windows 10 x64,using using the build from 2016-02-11, it was reproducible.
Retested in using the build 47.0b3 and the bug was fixed.
[testday-20160506]