2042605 - I-loop in querySelector on sfgate.com

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect, P3)

Description

[Randell Jesup [:jesup] (needinfo me)]

Repeatable i-loop at https://www.sfgate.com/local/article/golden-gate-park-leech-22270623.php?utm_source=firefox-newtab-en-us in querySelector.

Profile: https://share.firefox.dev/43BhJ6Y

Comment 1

[Emilio Cobos Álvarez [:emilio]]

I can't repro this, can you repro on a clean profile / without extensions / etc?

Any chance you could take a profile with JS script urls / function names? Otherwise it's hard to reason about what is be going on from the profile alone.

Comment 2

[Andrew Creskey [:acreskey]]

I can repro on both my main profile Firefox nightly, and also a nearly new profile of a local build.
Having a hard time collecting a profile since it's locking up. (MacOS)
Loads fine in Firefox Release, 150.

Comment 3

[Andrew Creskey [:acreskey]]

(In reply to Emilio Cobos Álvarez [:emilio] from comment #1)

I can't repro this, can you repro on a clean profile / without extensions / etc?

Any chance you could take a profile with JS script urls / function names? Otherwise it's hard to reason about what is be going on from the profile alone.

This one, local build, nearly new user profile, has Javascript Sources enabled in the profiler
https://share.firefox.dev/4dwbcR2

Comment 4

[Emilio Cobos Álvarez [:emilio]]

It seems from that profile that they're trying to load a script and then loading https://snap.licdn.com/li.lms-analytics/insight.old.min.js when that fails or so... And when they do this they somehow trigger a document.querySelector("script[nonce]") which basically scans the whole DOM, and it happens over and over.

Oh, I can repro on a clean build, mozregression points to bug 2027803 which is believable given the above... Maybe when loading a dupe script we're firing the load event sync or so when we shouldn't, or something along those lines?

Command:

$ ./mach mozregression --good 150 -a "https://www.sfgate.com/local/article/golden-gate-park-leech-22270623.php?utm_source=firefox-newtab-en-us"

Comment 5

[BugBot [:suhaib / :marco]]

Set release status flags based on info from the regressing bug 2027803

Comment 6

[Tooru Fujisawa [:arai]]

I can reproduce the issue,
but even with the dom.script_loader.experimental.navigation_cache pref disabled, I'm seeing similar/suspicious behavior on the website.

The network monitor shows that website loads insight.min.js and insight.old.min.js three times (in addition to a crazy amount of continuous requests).
insight.min.js is loaded from gtm.js, and insight.old.min.js is loaded from insight.min.js.
The Inspector shows that there are multiple script elements with the same URLs.

If the pref is enabled, those scripts are continuously loaded forever, like 1000+ in ~10 seconds.

So, the question would be, why the website loads the same script multiple times in the first place, and how it stops at three, and how it doesn't.

Then, as a possible fix, I'll see if delaying the load event by 1 tick for cached scripts helps.

Comment 7

[Tooru Fujisawa [:arai]]

(In reply to Tooru Fujisawa [:arai] from comment #6)

Then, as a possible fix, I'll see if delaying the load event by 1 tick for cached scripts helps.

Almost same experiment has been done in bug 1999884. It was to avoid a performance regression.

Applying the same change, where the cached script becomes available only after one tick, doesn't resolve the issue.
So, it's not likely about simply sync vs async.

I'll look into how the script is loaded repeatedly.

Comment 8

[Tooru Fujisawa [:arai]]

I'm seeing that the insight.min.js script is loaded from the onload event handler for the insight.min.js script (or perhaps something else in some case?), in gtm.js, and the nesting is increased by 20 calls for each load.
This is happening regardless of the navigation cache pref.
Still not yet sure why it stops at 3 with the pref disabled tho.

Comment 9

[Tooru Fujisawa [:arai]]

I cannot handle this shortly.
forwarding to nbp.

Comment 10

[Nicolas B. Pierron [:nbp] {away}]

(In reply to Tooru Fujisawa [:arai] from comment #7)

Applying the same change, where the cached script becomes available only after one tick, doesn't resolve the issue.

I tried the same thing, with a minimal reproducing test case, and the change that made it work was to replace the NS_DispatchToCurrentThread by:

  if (mDocument) {
    mDocument->Dispatch(runnable.forget());
  } else {
    NS_DispatchToCurrentThread(runnable.forget());
  }

Surprisingly this seems to work, but I have no idea why given that the document dispatch should delegate to NS_DispatchToCurrentThread.

Comment 11

[Nicolas B. Pierron [:nbp] {away}]

Attachment: WIP: Bug 2042605 - Add test case.

Comment 12

[Nicolas B. Pierron [:nbp] {away}]

(In reply to Nicolas B. Pierron [:nbp] from comment #10)

  if (mDocument) {
    mDocument->Dispatch(runnable.forget());
  } else {
    NS_DispatchToCurrentThread(runnable.forget());
  }

This does not seems to be the fix after all, but only a weird timing issue on my laptop, despite running the test multiple times.
For some reason it was working yesterday, and no longer seems to be working anymore this morning.

Comment 13

[Nicolas B. Pierron [:nbp] {away}]

The problem seems to be a race between the network and the cache.

In the current test case a.js keeps on being loaded first because it is already cached, while b.js is still being fetched by the network and relatively speaking we can iterate as many times over a.js while waiting for b.js.

So, this is not an infinite loop, just a slow network compared to loading resources from our in-memory cache.

I do not know how to fix this properly. One simple idea would be to avoid repeated loads of identical resources from the same document. Thus having a counter associated with the document, and using this counter to prevent matching cache entries introduced by the same document.

However, the same problem could be made to work with 2 pages, one first loading a.js, and a second page loading a.js repeatedly until b.js gets loaded … which would result in the same loading loop.

At this point I would recommend some advocacy to tell Developers not to use this pattern, or to add an extra boolean to check whether the resource has already been loaded too many times, or to throttle their loads with a setTimeout / setInterval.

Comment 14

[Nicolas B. Pierron [:nbp] {away}]

Checking locally with and without a delay as done in bug 1999884 yields the following results:

• Without: ~1559 reloads
• With: ~22 reloads

Comment 15

[Ryan VanderMeulen [:RyanVM]]

Maybe we can ship a webcompat intervention for this site otherwise if outreach doesn't work?

Comment 16

[Thomas Wisniewski [:twisniewski]]

I'm not sure what an intervention could/should do, but if others make a suggestion I'll be happy to help implement one.

Comment 17

[Nicolas B. Pierron [:nbp] {away}]

This might be the source of the issue:
https://github.com/linkedin/linkedin-gtm-community-template/blob/b27413acdce0edfd21b46e45f79b147f46c78cea/template.tpl#L210-L216

Comment 18

[Tooru Fujisawa [:arai]]

(In reply to Nicolas B. Pierron [:nbp] {away} from comment #17)

This might be the source of the issue:
https://github.com/linkedin/linkedin-gtm-community-template/blob/b27413acdce0edfd21b46e45f79b147f46c78cea/template.tpl#L210-L216

The template is already fixed for the infinite loop
https://github.com/linkedin/linkedin-gtm-community-template/commit/d6d31ee6f8880ffd8037e4aea7146ccd7cbba27b

And the corresponding fix doesn't seem to be applied to sfgate's gtm.js

                [50, "t", [46],
                    [22, ["n"],
                        [46, [53, [52, "u", ["i", "lintrk"]],
                            [52, "v", [8, "tmsource", "gtmv2"]],
                            [43, [15, "v"], "conversion_url", [15, "m"]],
                            [22, [1, [17, [15, "k"], "length"],
                                    [24, [17, [15, "k"], "length"], 3]
                                ],
                                [46, [2, [15, "k"], "forEach", [7, [51, "", [7, "w"],
                                    [43, [15, "v"], "conversion_id", [15, "w"]],
                                    ["u", "track", [15, "v"]]
                                ]]]],
                                [46, ["u", "track", [15, "v"]]]
                            ]
                        ]],
                        [46, ["f", "_already_called_lintrk", true, true],
                            ["h", "https://snap.licdn.com/li.lms-analytics/insight.min.js", [15, "q"],
                                [15, "r"]
                            ]
                        ]
                    ]
                ],

Comment 19

[Tooru Fujisawa [:arai]]

Attachment: Bug 2042605 - Do not cache linkedin insight.min.js. r?nbp!

Comment 20

[Jeff Muizelaar [:jrmuizel]]

Tooru, why doesn't Chrome have the same problem?

Comment 21

[Tooru Fujisawa [:arai]]

All browsers are having similar problem, where the same script is loaded multiple times, depending on the time taken by the script load and the event handler call.

The navigation cache makes the situation extremely worse, given that the "load script => onload handler" turnaround time becomes almost immediate, which allows loading the script infinitely.

Comment 22

[Tooru Fujisawa [:arai]]

I'll apply another patch in bug 2043993 to make the infinite loop less severe (but it will still hang without this bug 's patch)

Comment 24

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/104b7372be8a
https://hg.mozilla.org/integration/autoland/rev/06c6f84c7ab7
Do not cache linkedin insight.min.js. r=bthrall

Comment 25

[amarc]

https://hg.mozilla.org/mozilla-central/rev/06c6f84c7ab7

Comment 26

[Tooru Fujisawa [:arai]]

Attachment: Bug 2042605 - Do not cache linkedin insight.min.js.

Original Revision: https://phabricator.services.mozilla.com/D305776

Comment 27

[Phabricator Automation]

firefox-beta Uplift Approval Request

• User impact if declined/Reason for urgency: The content process hangs when the stencil navigation cache pref is enabled and the user visits certain website which uses google tag manager with an outdated linked in template.
  The pref is disabled by default, but we're planning to perform an experiment there.
• Code covered by automated testing?: no
• Fix verified in Nightly?: yes
• Needs manual QE testing?: no
• Steps to reproduce for manual QE testing: none
• Risk associated with taking this patch: low
• Explanation of risk level: This just excludes certain file from the caching.
  The file keeps the current behavior.
• String changes made/needed?: none
• Is Android affected?: yes

Comment 28

[Pulsebot]

https://github.com/mozilla-firefox/firefox/commit/e2f733fa9012
https://hg.mozilla.org/releases/mozilla-beta/rev/608191c41b0c