Closed
Bug 1284511
Opened 8 years ago
Closed 8 years ago
Slow script/Unresponsive Script dialogs appear frequently when resuming app
Categories
(Core :: JavaScript Engine, defect)
Tracking
()
RESOLVED
FIXED
mozilla51
People
(Reporter: snorp, Assigned: arai)
References
Details
(Keywords: regression)
Attachments
(6 files)
6.10 KB,
patch
|
mrbkap
:
review+
|
Details | Diff | Splinter Review |
6.00 KB,
patch
|
arai
:
review+
Sylvestre
:
approval-mozilla-aurora+
|
Details | Diff | Splinter Review |
6.00 KB,
patch
|
arai
:
review+
Sylvestre
:
approval-mozilla-beta+
|
Details | Diff | Splinter Review |
12.22 KB,
patch
|
Details | Diff | Splinter Review | |
12.13 KB,
patch
|
lizzard
:
approval-mozilla-aurora+
|
Details | Diff | Splinter Review |
12.19 KB,
patch
|
lizzard
:
approval-mozilla-beta+
lizzard
:
approval-mozilla-release+
|
Details | Diff | Splinter Review |
I've noticed recently I get a 'slow script' dialog frequently if I switch back to Fennec after being in another app. Seems to happen no matter what sites I have open. Not reproducible.
Reporter | ||
Updated•8 years ago
|
tracking-fennec: --- → ?
Reporter | ||
Updated•8 years ago
|
status-firefox51:
--- → affected
Reporter | ||
Comment 1•8 years ago
|
||
:bkelly says this might be because we throttle timers[0] on mac/win but not on Android. Apparently we need to send some stuff on NS_WIDGET_SLEEP_OBSERVER_TOPIC[0] when sleeping/resuming.
[0] https://dxr.mozilla.org/mozilla-central/source/xpcom/threads/TimerThread.cpp#441
[1] https://dxr.mozilla.org/mozilla-central/search?q=NS_WIDGET_SLEEP_OBSERVER_TOPIC
Reporter | ||
Updated•8 years ago
|
Assignee: nobody → snorp
Reporter | ||
Comment 2•8 years ago
|
||
OK all of that is super old so maybe unrelated
Reporter | ||
Comment 3•8 years ago
|
||
I saw this on Windows 10 laptop after sleep, though, so doesn't seem to be Fennec-specific. Moving to JS for lack of a better place.
Component: General → JavaScript Engine
Product: Firefox for Android → Core
Comment 4•8 years ago
|
||
Jim, Brad, here's another recent slow script related bug. Related to the e10s work we did for slow script dialogs?
Reporter | ||
Comment 5•8 years ago
|
||
tracking-fennec: ? → 50+
Flags: needinfo?(jmathies)
Flags: needinfo?(blassey.bugs)
Comment 6•8 years ago
|
||
This is in the fennec product? I don't see how our e10s related work for desktop plays into this.
Flags: needinfo?(jmathies)
Reporter | ||
Comment 7•8 years ago
|
||
Brad came up with some telemetry that seems to show badness starting on June 2
https://telemetry.mozilla.org/new-pipeline/evo.html#!aggregates=median&cumulative=0&end_date=2016-08-01&keys=!__none__!__none__&max_channel_version=nightly%252F50&measure=SLOW_SCRIPT_NOTICE_COUNT&min_channel_version=nightly%252F48&product=Fennec&sanitize=1&sort_keys=submissions&start_date=2016-06-07&trim=1&use_submission_date=0
Reporter | ||
Comment 8•8 years ago
|
||
Bug 1276626 looks likely.
:arai, what do you think?
Flags: needinfo?(arai.unmht)
Reporter | ||
Comment 9•8 years ago
|
||
Input from :mrbkap would be useful as well (see comment #7 and #8)
Flags: needinfo?(blassey.bugs) → needinfo?(mrbkap)
Assignee | ||
Comment 10•8 years ago
|
||
Triggered a build with logging.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=c901052c3da3
will test once the build finishes.
Updated•8 years ago
|
status-firefox49:
--- → ?
Assignee | ||
Comment 11•8 years ago
|
||
okay, I got it.
the algorithm I used was wrong.
we need to calculate "how many times the half timeout happens" and "how long time elapsed from last RecordRuntimeActivity" separately.
will prepare a patch.
Assignee | ||
Comment 12•8 years ago
|
||
The bug in previous approach was that we increment mSlowScriptSecondHalfCount only by 1 even if long time elapsed, and it hits timeout everytime we check in watch dog, until RecordRuntimeActivity is called.
Then, I tried to increment mSlowScriptSecondHalfCount with proper amount, but I bumped into another issue:
if timeout is 10 seconds, we check every 5 seconds.
if 99.9 seconds elapsed without RecordRuntimeActivity because of sleep,
we would wait only extra 0.1 seconds before invoking interrupt, even if we increment mSlowScriptSecondHalfCount properly.
So, I changed the approach.
It would be simpler to record the last TimeSinceLastRuntimeStateChange value, and check the elapsed time from the that, and flip mSlowScriptSecondHalf every timeout.
This is the almost same approach that was used before bug 1276626 patch, in XPCJSRuntime.
https://hg.mozilla.org/mozilla-central/rev/8272530c90ef
Assignee: snorp → arai.unmht
Status: NEW → ASSIGNED
Flags: needinfo?(arai.unmht)
Attachment #8787275 -
Flags: review?(mrbkap)
This was deemed blocking for 49 at the channel meeting today. Marking it as such.
tracking-firefox49:
--- → blocking
Assignee | ||
Comment 14•8 years ago
|
||
It might be better just backing out bug 1276626 patch, at least for 49, as the case fixed by the patch should be less critical than this.
Assignee | ||
Updated•8 years ago
|
Blocks: 1276626
Keywords: regression
Comment 15•8 years ago
|
||
OK. It looks like the fix in 1276626 was for a specific case. Maybe we can backout as you suggest. The risk from my point of view is that, since the fix in that bug landed 3 months ago, in the time in between, we have landed more patches from something like 6000 other bugs. So, I don't know how to tell quickly if something else depends on the work in bug 1276626. We can try the backout, for the RC build and release on Tuesday, then we have the rest of that week to uncover any regressions.
Updated•8 years ago
|
Attachment #8787275 -
Flags: review?(mrbkap) → review+
Updated•8 years ago
|
Flags: needinfo?(mrbkap)
Assignee | ||
Comment 16•8 years ago
|
||
try run on beta branch with backout bug 1276626 patch:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=40c0efa59bb0
will land the attachment 8787275 [details] [diff] [review] patch shortly to m-i, after test,
and also trigger another try run on beta branch with the patch.
Assignee | ||
Comment 17•8 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/2872d7dca33b68a7c49adffeb2b671c28820ac60
Bug 1284511 - Fix slow script check to use elapsed time from last check. r=mrbkap
Assignee | ||
Comment 18•8 years ago
|
||
try run on beta branch with attachment 8787275 [details] [diff] [review]
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cc5bf464f737
Assignee | ||
Comment 19•8 years ago
|
||
so far I don't see any test regression on beta tries.
can anyone test with actual case (laptop or android sleep) on those binaries? or next nightly?
Assignee | ||
Comment 20•8 years ago
|
||
or, can anyone provide the steps to reproduce?
I cannot reproduce the issue on Windows 10 laptop with 49.0b8.
(I opened treeherder in 2 tabs and tries sleep with ~1 minutes several times)
snorp, do you know?
Flags: needinfo?(snorp)
Comment 21•8 years ago
|
||
bugherder |
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla51
Assignee | ||
Comment 22•8 years ago
|
||
for now, attaching backported patches.
I'm still trying to reproduce the issue, but no luck...
Attachment #8787972 -
Flags: review+
Assignee | ||
Comment 23•8 years ago
|
||
Attachment #8787973 -
Flags: review+
Updated•8 years ago
|
Summary: Slow script dialogs appear frequently when resuming app → Slow script/Unresponsive Script dialogs appear frequently when resuming app
Assignee | ||
Comment 24•8 years ago
|
||
Comment on attachment 8787972 [details] [diff] [review]
(mozilla-aurora) Fix slow script check to use elapsed time from last check. r=mrbkap
for now, requesting uplift.
once someone verified the fix, I will rewrite the uplift request message.
Approval Request Comment
> [Feature/regressing bug #]
Bug 1276626.
> [User impact if declined]
Slow script dialog may be shown after sleep
> [Describe test coverage new/current, TreeHerder]
This needs manual test, as it's related to sleep, and it cannot be done in automated tests.
> [Risks and why]
Medium, as this is not yet tested on the env that hits the issue.
I cannot reproduce the issue locally with affectes builds (aurora/nightly).
> [String/UUID change made/needed]
None
Attachment #8787972 -
Flags: approval-mozilla-aurora?
Assignee | ||
Comment 25•8 years ago
|
||
Comment on attachment 8787973 [details] [diff] [review]
(mozilla-beta) Fix slow script check to use elapsed time from last check. r=mrbkap
Approval Request Comment
> [Feature/regressing bug #]
Bug 1276626.
> [User impact if declined]
Slow script dialog may be shown after sleep
> [Describe test coverage new/current, TreeHerder]
This needs manual test, as it's related to sleep, and it cannot be done in automated tests.
> [Risks and why]
Medium, as this is not yet tested on the env that hits the issue.
I cannot reproduce the issue locally with affected builds (aurora/nightly).
> [String/UUID change made/needed]
None
Attachment #8787973 -
Flags: approval-mozilla-beta?
Comment 26•8 years ago
|
||
Comment on attachment 8787973 [details] [diff] [review]
(mozilla-beta) Fix slow script check to use elapsed time from last check. r=mrbkap
OK, let's try with this patch, taking it to 49 rc 1
FYI, we will have to do a second rc anyway for bug 1297687
Attachment #8787973 -
Flags: approval-mozilla-beta? → approval-mozilla-beta+
Updated•8 years ago
|
Attachment #8787972 -
Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Comment 27•8 years ago
|
||
Reporter | ||
Comment 28•8 years ago
|
||
I don't have solid STR. I tried for a while to find some, but wasn't able to come up with anything.
Flags: needinfo?(snorp)
Reporter | ||
Comment 29•8 years ago
|
||
We should be able to use telemetry to figure out if the patch helps or not.
Comment 30•8 years ago
|
||
*Almost* every time I come back from sleep on Windows 10 running Aurora I see a slow script dialog for IRCCloud in a pinned tab. Weak STR but maybe useful.
Comment 31•8 years ago
|
||
(In reply to Andrew Overholt [:overholt] from comment #30)
> *Almost* every time I come back from sleep on Windows 10 running Aurora I
> see a slow script dialog for IRCCloud in a pinned tab. Weak STR but maybe
> useful.
I've noticed more frequent slow script dialogs too on Aurora, often in the browser/base/content/browser.js script. I wasn't doing anything and Firefox wasn't being slow or anything, so it looked like a false positive.
Assignee | ||
Comment 32•8 years ago
|
||
Thanks.
now I'm testing on IRCCloud, but so far I don't see the dialog.
Does the issue still happen on today's aurora?
Comment 33•8 years ago
|
||
Just came up for me on 49 RC1 on a gmail tab after resuming from sleep with this error: Script: https://plus.google.com/_/scs/…cCMjOvovKNJ3foLAYjuM34xrVTC2sw:114 . I don't particularly use google plus. But I think this is from the little red g+ notification number in the upper corner of gmail. Some sort of push notification thing?
Assignee | ||
Comment 34•8 years ago
|
||
should we try backing out whole patches (this bug and bug 1276626) then?
Assignee | ||
Comment 35•8 years ago
|
||
this bug's patch should be able to be backed out cleanly.
Here are patches that backout bug 1276626 patch.
Assignee | ||
Comment 36•8 years ago
|
||
Assignee | ||
Comment 37•8 years ago
|
||
Assignee | ||
Comment 38•8 years ago
|
||
Comment on attachment 8789180 [details] [diff] [review]
(mozilla-aurora) Backed out changeset 8272530c90ef (bug 1276626)
about mozilla-central, I'll land backout patches shortly.
asking approval for backing out bug 1284511 patch and this bug's patch:
https://hg.mozilla.org/releases/mozilla-aurora/rev/37c314d53f82
https://hg.mozilla.org/releases/mozilla-aurora/rev/8272530c90ef
this patch backs out 8272530c90ef.
37c314d53f82 should be able to be backed out cleanly.
Approval Request Comment
> [Feature/regressing bug #]
bug 1284511 and this bug
bug 1284511 caused the issue, tried a fix on this bug, but it didn't work.
> [User impact if declined]
Slow script dialog may be shown after sleep
> [Describe test coverage new/current, TreeHerder]
This needs manual test, as it's related to sleep, and it cannot be done in automated tests.
> [Risks and why]:
Medium, as this is not yet tested on the env that hits the issue.
I still cannot reproduce the issue locally with affected builds.
> [String/UUID change made/needed]
None
Attachment #8789180 -
Flags: approval-mozilla-aurora?
Assignee | ||
Comment 39•8 years ago
|
||
Comment on attachment 8789181 [details] [diff] [review]
(mozilla-beta) Backed out changeset 8272530c90ef (bug 1276626)
also, asking approval for backing out bug 1284511 patch and this bug's patch:
https://hg.mozilla.org/releases/mozilla-beta/rev/9aa5886a1563
https://hg.mozilla.org/releases/mozilla-beta/rev/8272530c90ef
this patch backout 8272530c90ef.
9aa5886a1563 should be able to be backed out cleanly.
Approval Request Comment
> [Feature/regressing bug #]
bug 1284511 and this bug
bug 1284511 caused the issue, tried a fix on this bug, but it didn't work.
> [User impact if declined]
Slow script dialog may be shown after sleep
> [Describe test coverage new/current, TreeHerder]
This needs manual test, as it's related to sleep, and it cannot be done in automated tests.
> [Risks and why]:
Medium, as this is not yet tested on the env that hits the issue.
I still cannot reproduce the issue locally with affected builds.
> [String/UUID change made/needed]
None
Attachment #8789181 -
Flags: approval-mozilla-beta?
Assignee | ||
Comment 40•8 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/4248b124b502f12f1a31179aa2703da95161091e
Backed out changeset 2872d7dca33b (bug 1284511) r=blassey
Assignee | ||
Comment 41•8 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/c0a3eb567948034fe6871a814cdad0dbb127d08e
Backed out changeset 8272530c90ef (bug 1276626) for bug 1284511 r=blassey
(In reply to Andrew Overholt [:overholt] from comment #30)
> *Almost* every time I come back from sleep on Windows 10 running Aurora I
> see a slow script dialog for IRCCloud in a pinned tab. Weak STR but maybe
> useful.
+1 to these STR from Andrew. In my case though, on RC1, I have yet to see the slow script dialog pop up. So I for one feel the change we landed in RC1 worked, especially on win10.
Are we certain everyone is testing against RC1 and not the earlier builds?
Comment 43•8 years ago
|
||
I am getting the slow script warning in gmail and google docs after resuming from sleep (Mac, 10.11, with the RC2 build today) But I am just one person so consider that anecdotal, and I can't reproduce it every time.
I think Brad was judging from the Nightly telemetry data that the fix in nightly didn't decrease the slow script reports.
Comment 45•8 years ago
|
||
backout bugherder |
Comment 46•8 years ago
|
||
Comment on attachment 8789180 [details] [diff] [review]
(mozilla-aurora) Backed out changeset 8272530c90ef (bug 1276626)
Let's uplift the backout to aurora as well, and see if we get any useful user feedback. And, we should know more from telemetry on nightly by Monday.
Attachment #8789180 -
Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Comment 47•8 years ago
|
||
Comment 48•8 years ago
|
||
I don't know if this is related, but the Fidelity.com website is so slow, it's been rendered virtually unusable in v. 49 beta. It works fine in ESR and is a bit better in Nightly.
Comment 49•8 years ago
|
||
In relation to my previous comment, I'm talking about after one logs in. Ummmmm, sorry, but I'm not going to send you my log-in data so you can test it.
;-)
I don't, however, get the message that a script is slowing down Fx. It's just that the elements take forever to load and every time I try to visit the page, at one point or another, I get the message in the title bar (which eventually goes away) "Program not responding".
By the way, I'm using the very latest version of 49 beta (07 Sep).
Comment 50•8 years ago
|
||
Sorry, I should have mentioned this earlier (I still find it stupid that there's no way to edit comments): With a new profile it works fine, but I've removed No Script and UBlock Origin, and this hasn't helped.
Comment 51•8 years ago
|
||
Is bug 1294782 related to this? It's not from the resuming though, just put Firefox on background for a while and I will receive unresponsive script error.
Comment 52•8 years ago
|
||
After discussion about telemetry results with chutten, I think we will go ahead and try uplifting the backout for the RC3 build. He will post more details soon.
Comment 53•8 years ago
|
||
Comment on attachment 8789181 [details] [diff] [review]
(mozilla-beta) Backed out changeset 8272530c90ef (bug 1276626)
[Triage Comment]
Let's bring the backout to beta and release for the RC3 build.
Attachment #8789181 -
Flags: approval-mozilla-release+
Attachment #8789181 -
Flags: approval-mozilla-beta?
Attachment #8789181 -
Flags: approval-mozilla-beta+
Comment 54•8 years ago
|
||
At :lizzard's and :bsmedberg's behest, I analyzed [1] the current data we have on the probe SLOW_SCRIPT_NOTICE_COUNT (which counts the number of times a user sees the slow script dialog). It is a comparison between nightly 0910 and nightly 0903 (Saturdays, to maintain day-of-week volume comparability).
This analysis is as-of-yet unreviewed, but shows data consistent with what's seen on telemetry.mozilla.org[2]. Specifically, that the number of reports (and clients submitting those reports) of slow script notices has dropped to 20% of previous figures. I suspect not all pings and clients have reported in for the build, but assuming that the pings and clients are representative, we can say the following about rates:
There are now more pings from fewer clients reporting more notices. Or, to put it colloquially, it seems as though we have traded a nightly where some people had poor experiences for a nightly where few people had hideous experiences.
All that with the needle on the notices-per-usage-hour barely moving at all.
This seems to be a return of this measure to the values and volumes experienced earlier this year until the beginning of June, which is consistent with the patchset backed out.
[1]: https://gist.github.com/chutten/feb43ea722a7a0dcacfe399ba03a1ffe
[2]: https://mzl.la/2cHTHfX
Comment 55•8 years ago
|
||
backout bugherder uplift |
Comment 56•8 years ago
|
||
backout bugherder uplift |
Comment 57•8 years ago
|
||
(In reply to Chris H-C :chutten from comment #54)
> There are now more pings from fewer clients reporting more notices. Or, to
> put it colloquially, it seems as though we have traded a nightly where some
> people had poor experiences for a nightly where few people had hideous
> experiences.
Thanks for all the details! Is there a bug already filed for helping those people?
Flags: needinfo?(chutten)
Comment 58•8 years ago
|
||
(In reply to David Bolter [:davidb] from comment #57)
> (In reply to Chris H-C :chutten from comment #54)
>
> > There are now more pings from fewer clients reporting more notices. Or, to
> > put it colloquially, it seems as though we have traded a nightly where some
> > people had poor experiences for a nightly where few people had hideous
> > experiences.
>
> Thanks for all the details! Is there a bug already filed for helping those
> people?
I think bug 1276626 may be that bug, as it was the effort to try and improve what was thought to be the cause.
Flags: needinfo?(chutten)
You need to log in
before you can comment on or make changes to this bug.
Description
•