Find out how often we syntax-parse when we should full-parse immediately

RESOLVED FIXED in Firefox 55

Status

()

Core
JavaScript Engine
RESOLVED FIXED
a year ago
a year ago

People

(Reporter: Yoric, Assigned: Yoric)

Tracking

(Blocks: 1 bug)

unspecified
mozilla55
Points:
---

Firefox Tracking Flags

(firefox55 fixed)

Details

MozReview Requests

()

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(2 attachments, 1 obsolete attachment)

There is a suspicion that we are sometimes performing a syntax parse followed almost immediately by a full parse. If this is true, we are wasting time and we should immediately full parse.

We should add Telemetry to find out whether (or how often) this is the case.
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)

Comment 3

a year ago
hg error in cmd: hg push -r . -f try: pushing to ssh://hg.mozilla.org/try
searching for changes
remote: waiting for lock on working directory of /repo/hg/mozilla/try held by process '5081' on host 'hgssh4.dmz.scl3.mozilla.com'
remote: abort: working directory of /repo/hg/mozilla/try: timed out waiting for lock held by hgssh4.dmz.scl3.mozilla.com:5081
abort: stream ended unexpectedly (got 0 bytes, expected 4)
Attachment #8842832 - Flags: review?(shu)
Comment hidden (mozreview-request)

Comment 5

a year ago
mozreview-review
Comment on attachment 8842832 [details]
Bug 1343483 - Report how long lazy code remains lazy

https://reviewboard.mozilla.org/r/116610/#review118966

BytecodeCompiler isn't the right place to instrument syntax parsing. Some overview on syntax parsing below.

Syntax parsing is done on a per-function basis instead of a per ScriptSource basis. This is organized in code as follows. For a top-level script, there is a pair of parsers: a Parser<FullParseHandler> and a Parser<SyntaxParseHandler>. Initially, the top-level script is parsed using the full parser. As inner functions are encountered, a new ParseContext is allocated on-stack and we try to parse the inner function lazily, without allocating an AST or emitting bytecode, with the lazy parser. This happens in Parser<T>::trySyntaxParseInnerFunction. This is a "try" because some things still cannot be syntax parsed. When that happens, we restart parsing of the inner function with the full parser. The biggest feature that cannot be syntax parsed right now is destructuring, which we should fix eventually. If the syntax parse succeeds, we create a LazyScript that records the span of its source code, and attach it to a JSFunction. When that JSFunction gets executed for the first time, we "delazify": do a full parse of that function (but not any nested inner lazy functions!) and generate bytecode.

So that gives us 2 perf cliffs, in order of badness:

1. We tried to syntax parse an inner function, found an unsupported feature (e.g. destructuring or modules), and had to restart.
2. We successfully syntax parsed, but then had to immediately execute the function, wasting syntax parsing time.

1 is mainly a powering-through-implementation issue. 2 is what we're trying to determine here.

So all that said, BytecodeCompiler isn't the right place to instrument. The easiest is inside the ParseContext<ParseHandler> constructor. ParseContext<SyntaxParseHandler> is for syntax-parsing inner functions. To correlate that with delazifying functions, you could use the JSFunction in functionBox()->function().

The telemetry part looks super useful. We can land that and get data from the web, right?
Attachment #8842832 - Flags: review?(shu)
Comment hidden (mozreview-request)
Attachment #8842832 - Attachment is obsolete: true
Assignee: nobody → dteller
Created attachment 8844199 [details]
A few minutes worth of browsing

Browsing a few minutes, here's what I get.

~21k delazifications, if we remove chrome:// and resource://.

Out of them,
* ~1300 delazifications occur 10ms or less after lazification
* ~1000 between 10ms and 20ms
* ~3000 between 20ms and 100ms
* ~10k above 10s
Note that function relazification might be an interesting wrinkle here: it could cause some functions to be parsed multiple times, in the same or different time buckets from comment 7.

We relazify some (or most, I guess) functions during GC, specifically those that weren't hot enough to get JIT compiled, but only for globals with not frames on the stack, plus some[1] other[2] conditions[3].

It'd be nice if we could use some better heuristics here, like some notion of call frequency or recency. That's not trivial though, so perhaps an easier thing to do would be to add a flag to JSScript that gets set whenever the interpreter runs the script, and reset on GC. Effectively we'd delay relazification by one GC, making it far less likely that we get into parse-relazify-parse-... cycles.

All of this only makes sense if we do in fact have these cycles with any frequency.


[1] http://searchfox.org/mozilla-central/source/js/src/jsfun.cpp#1420-1426
[2] http://searchfox.org/mozilla-central/source/js/src/jsfun.cpp#1539-1564
[3] http://searchfox.org/mozilla-central/source/js/src/jsscript.h#1514-1519
(In reply to Till Schneidereit [till] from comment #8)
 It'd be nice if we could use some better heuristics here, like some notion
> of call frequency or recency. That's not trivial though, so perhaps an
> easier thing to do would be to add a flag to JSScript that gets set whenever
> the interpreter runs the script, and reset on GC. Effectively we'd delay
> relazification by one GC, making it far less likely that we get into
> parse-relazify-parse-... cycles.

Note that I changed the relazification a while ago to only happen in shrinking GCs and these shouldn't happen too frequently, so hopefully these cycles aren't too bad. Definitely worth measuring though :)

Comment 10

a year ago
mozreview-review
Comment on attachment 8844175 [details]
Bug 1343483 - Determine how long functions remain syntax-parsed before they are full-parsed;

https://reviewboard.mozilla.org/r/117710/#review119526

Looks good!

::: js/src/frontend/BytecodeCompiler.cpp:682
(Diff revision 1)
> +    // after parsing below.
> +    if (!lazy->scriptSource()->parseEnded().IsNull()) {
> +        const mozilla::TimeDuration delta = mozilla::TimeStamp::Now() -
> +            lazy->scriptSource()->parseEnded();
> +        cx->runtime()->addTelemetry(JS_TELEMETRY_PARSER_COMPILE_LAZY_AFTER_MS,
> +            delta.ToMilliseconds()

Style nit: line up to 1 char past the (

::: js/src/frontend/BytecodeCompiler.cpp:685
(Diff revision 1)
> +            lazy->scriptSource()->parseEnded();
> +        cx->runtime()->addTelemetry(JS_TELEMETRY_PARSER_COMPILE_LAZY_AFTER_MS,
> +            delta.ToMilliseconds()
> +        );
> +    } else {
> +        MOZ_ASSERT(false);

A MOZ_ASSERT(!lazy->scriptSource->parseEnded().isNull()) and removing the if-else would be better.

::: js/src/jsscript.h:620
(Diff revision 1)
> +
> +    const mozilla::TimeStamp parseEnded() const {
> +        return parseEnded_;
> +    }
> +    // Inform `this` source that it has been fully parsed.
> +    void parseEnds() {

Name nit: would prefer |recordParseEnded()|
Attachment #8844175 - Flags: review?(shu) → review+

Comment 11

a year ago
For the FB news workload, we should also check if any LazyFunctions are delazified within the same "phase": between any two milestones that the workload reports.
I guess we could have a counter of number of relazifications. Do you think it's worth doing in this bug? Or can this wait for a followup?

(In reply to Till Schneidereit [till] from comment #8)
> It'd be nice if we could use some better heuristics here, like some notion
> of call frequency or recency. That's not trivial though, so perhaps an
> easier thing to do would be to add a flag to JSScript that gets set whenever
> the interpreter runs the script, and reset on GC. Effectively we'd delay
> relazification by one GC, making it far less likely that we get into
> parse-relazify-parse-... cycles.
Flags: needinfo?(till)
(In reply to David Teller [:Yoric] (please use "needinfo") from comment #12)
> I guess we could have a counter of number of relazifications. Do you think
> it's worth doing in this bug? Or can this wait for a followup?

I hadn't been aware of the changes jandem mentions in comment 9. With that, I think relazification is far less of a concern than I thought. Shrinking GCs are quite unlikely to happen during page initialization.
Flags: needinfo?(till)
Comment hidden (mozreview-request)

Comment 15

a year ago
mozreview-review
Comment on attachment 8844175 [details]
Bug 1343483 - Determine how long functions remain syntax-parsed before they are full-parsed;

https://reviewboard.mozilla.org/r/117710/#review119786

::: js/src/frontend/BytecodeCompiler.cpp:689
(Diff revision 2)
> +        // with optimization. Due to the number of calls to this function,
> +        // we use `cx->runningWithTrustedPrincipals`, which is fast but
> +        // will classify addons alongside with web-facing code.
> +        const int HISTOGRAM = cx->runningWithTrustedPrincipals() ?
> +            JS_TELEMETRY_PRIVILEGED_PARSER_COMPILE_LAZY_AFTER_MS :
> +            JS_TELEMETRY_WEB_PARSER_COMPILE_LAZY_AFTER_MS;

Style nit:

const int foo = condition
                ? foo
                : bar;
Comment hidden (mozreview-request)

Comment 17

a year ago
Pushed by dteller@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/45dc8c1db279
Determine how long functions remain syntax-parsed before they are full-parsed;r=shu

Comment 18

a year ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/45dc8c1db279
Status: NEW → RESOLVED
Last Resolved: a year ago
status-firefox55: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
All new Telemetry needs data collection review:
https://wiki.mozilla.org/Firefox/Data_Collection

Please follow up on this with one of the peers.
Flags: needinfo?(dteller)
Comment on attachment 8844175 [details]
Bug 1343483 - Determine how long functions remain syntax-parsed before they are full-parsed;

Thanks Georg.

Requesting additional review for Telemetry. It's a measure used to determine whether our JS loading strategy is adapted to webpages found in the wild, so I don't think it should be a problem.
Flags: needinfo?(dteller)
Attachment #8844175 - Flags: feedback?(rweiss)

Updated

a year ago
Blocks: 1345706

Comment 21

a year ago
:Yoric, a few questions:

1) How long are you going to have these probes stay on?  Which versions of Firefox, if not forever?

2) How will you be analyzing the data?  Who is primarily responsible for performing the desired analysis?

3) Will this be opt-in or opt-out on Release?
Flags: needinfo?(dteller)
(In reply to Rebecca Weiss from comment #21)
> :Yoric, a few questions:
> 
> 1) How long are you going to have these probes stay on?  Which versions of
> Firefox, if not forever?

For the moment, I've specified Firefox 70.

> 2) How will you be analyzing the data?  Who is primarily responsible for
> performing the desired analysis?

I'll be performing the analysis. Basically, our analysis is "if we have a high percentile of samples below a small duration, we need to fix our strategy." Actual numbers have not been determined yet, but a hunch would be around the 30th percentile and 50ms.


> 3) Will this be opt-in or opt-out on Release?

The idea is to make it opt-in. If I recall correctly, this is what happens when you don't do anything special in Histograms.json, right?
Flags: needinfo?(dteller) → needinfo?(rweiss)

Comment 23

a year ago
(In reply to David Teller [:Yoric] (please use "needinfo") from comment #22)
> (In reply to Rebecca Weiss from comment #21)
> > :Yoric, a few questions:
> > 
> > 1) How long are you going to have these probes stay on?  Which versions of
> > Firefox, if not forever?
> 
> For the moment, I've specified Firefox 70.
> 
> > 2) How will you be analyzing the data?  Who is primarily responsible for
> > performing the desired analysis?
> 
> I'll be performing the analysis. Basically, our analysis is "if we have a
> high percentile of samples below a small duration, we need to fix our
> strategy." Actual numbers have not been determined yet, but a hunch would be
> around the 30th percentile and 50ms.
> 
> 
> > 3) Will this be opt-in or opt-out on Release?
> 
> The idea is to make it opt-in. If I recall correctly, this is what happens
> when you don't do anything special in Histograms.json, right?

Yep.  What analysis tool do you intend to use to make that assessment?  I'll provisionally sign off on data review, but if you require additional data engineering work, you'll need to consult the data platform and tooling team.
Flags: needinfo?(rweiss)

Updated

a year ago
Attachment #8844175 - Flags: feedback?(rweiss) → feedback+
You need to log in before you can comment on or make changes to this bug.