Bug 1343483 - Determine how long functions remain syntax-parsed before they are full-parsed;r?shu draft
authorDavid Teller <dteller@mozilla.com>
Mon, 06 Mar 2017 21:22:00 +0100
changeset 495236 44702db10f273ae3b4a9236b10ddb823e726544e
parent 494107 38239ac4b962e88ae0c5feba0e84d33c86a598f4
child 548326 2d8201c3bd5c6f64de38a48f4eb969404641dbc4
push id48277
push userdteller@mozilla.com
push dateWed, 08 Mar 2017 15:42:12 +0000
reviewersshu
bugs1343483
milestone54.0a1
Bug 1343483 - Determine how long functions remain syntax-parsed before they are full-parsed;r?shu In many cases, to speed up start, compiling a ScriptSource will not compile the functions themselves, but will rather syntax-parse them (to check for syntax errors), leaving full compilation for later. However, if we find ourselves in a case in which the function is needed almost immediately, we need to full-parse the function immediately after the syntax-parse, which is wasteful. This changeset intends to measure how often this happens, by exporting through Telemetry the duration between the end of the syntax-parse and the start of the full-parse for each function. As a memory optimization, instead of storing a timestamp for the syntax-parse of each function, we store a single timestamp for an entire ScriptSource. This assumes that all functions of the ScriptSource are syntax-parsed at approximately the same instant, which should be mostly true for everything except perhaps `eval` and `new Function`. Then, when time comes to delazify a function, we simply determine the time elapsed since the ScriptSource was compiled. Histogram JS_PARSER_COMPILE_LAZY_AFTER_MS starts at 10ms (anything smaller is often not measurable) and stops at 10s (anything larger can safely be said to be not wasteful). MozReview-Commit-ID: 6Ycy2OIIiAt
js/src/frontend/BytecodeCompiler.cpp
js/src/jsfriendapi.h
js/src/jsscript.h
js/xpconnect/src/XPCJSContext.cpp
toolkit/components/telemetry/Histograms.json
--- a/js/src/frontend/BytecodeCompiler.cpp
+++ b/js/src/frontend/BytecodeCompiler.cpp
@@ -392,16 +392,20 @@ BytecodeCompiler::compileScript(HandleOb
 
         // Reset UsedNameTracker state before trying again.
         usedNames->reset();
     }
 
     if (!maybeCompleteCompressSource())
         return nullptr;
 
+    // We have just finished parsing the source. Inform the source so that we
+    // can compute statistics (e.g. how much time our functions remain lazy).
+    script->scriptSource()->recordParseEnded();
+
     MOZ_ASSERT_IF(!cx->helperThread(), !cx->isExceptionPending());
 
     return script;
 }
 
 JSScript*
 BytecodeCompiler::compileGlobalScript(ScopeKind scopeKind)
 {
@@ -663,16 +667,34 @@ frontend::CompileLazyFunction(JSContext*
 
     CompileOptions options(cx, lazy->version());
     options.setMutedErrors(lazy->mutedErrors())
            .setFileAndLine(lazy->filename(), lazy->lineno())
            .setColumn(lazy->column())
            .setNoScriptRval(false)
            .setSelfHostingMode(false);
 
+    // Update statistics to find out if we are delazifying just after having
+    // lazified. Note that we are interested in the delta between end of
+    // syntax parsing and start of full parsing, so we do this now rather than
+    // after parsing below.
+    if (!lazy->scriptSource()->parseEnded().IsNull()) {
+        const mozilla::TimeDuration delta = mozilla::TimeStamp::Now() -
+            lazy->scriptSource()->parseEnded();
+
+        // Differentiate between web-facing and privileged code, to aid
+        // 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;
+        cx->runtime()->addTelemetry(HISTOGRAM, delta.ToMilliseconds());
+    }
+
     UsedNameTracker usedNames(cx);
     if (!usedNames.init())
         return false;
     Parser<FullParseHandler> parser(cx, cx->tempLifoAlloc(), options, chars, length,
                                     /* foldConstants = */ true, usedNames, nullptr, lazy);
     if (!parser.checkOptions())
         return false;
 
--- a/js/src/jsfriendapi.h
+++ b/js/src/jsfriendapi.h
@@ -131,16 +131,18 @@ enum {
     JS_TELEMETRY_GC_MINOR_REASON_LONG,
     JS_TELEMETRY_GC_MINOR_US,
     JS_TELEMETRY_GC_NURSERY_BYTES,
     JS_TELEMETRY_GC_PRETENURE_COUNT,
     JS_TELEMETRY_DEPRECATED_LANGUAGE_EXTENSIONS_IN_CONTENT,
     JS_TELEMETRY_DEPRECATED_LANGUAGE_EXTENSIONS_IN_ADDONS,
     JS_TELEMETRY_ADDON_EXCEPTIONS,
     JS_TELEMETRY_AOT_USAGE,
+    JS_TELEMETRY_PRIVILEGED_PARSER_COMPILE_LAZY_AFTER_MS,
+    JS_TELEMETRY_WEB_PARSER_COMPILE_LAZY_AFTER_MS,
     JS_TELEMETRY_END
 };
 
 typedef void
 (*JSAccumulateTelemetryDataCallback)(int id, uint32_t sample, const char* key);
 
 extern JS_FRIEND_API(void)
 JS_SetAccumulateTelemetryCallback(JSContext* cx, JSAccumulateTelemetryDataCallback callback);
--- a/js/src/jsscript.h
+++ b/js/src/jsscript.h
@@ -440,16 +440,24 @@ class ScriptSource
     // demand. If sourceRetrievable_ and hasSourceData() are false, it is not
     // possible to get source at all.
     bool sourceRetrievable_:1;
     bool hasIntroductionOffset_:1;
 
     const char16_t* chunkChars(JSContext* cx, UncompressedSourceCache::AutoHoldEntry& holder,
                                size_t chunk);
 
+    // Instant at which the first parse of this source ended, or null
+    // if the source hasn't been parsed yet.
+    //
+    // Used for statistics purposes, to determine how much time code spends
+    // syntax parsed before being full parsed, to help determine whether
+    // our syntax parse vs. full parse heuristics are correct.
+    mozilla::TimeStamp parseEnded_;
+
   public:
     explicit ScriptSource()
       : refs(0),
         data(SourceType(Missing())),
         filename_(nullptr),
         displayURL_(nullptr),
         sourceMapURL_(nullptr),
         mutedErrors_(false),
@@ -598,16 +606,25 @@ class ScriptSource
     // ScriptSource.
     bool xdrEncodeFunction(JSContext* cx, HandleFunction fun,
                            HandleScriptSource sourceObject);
 
     // Linearize the encoded content in the |buffer| provided as argument to
     // |xdrEncodeTopLevel|, and free the XDR encoder.  In case of errors, the
     // |buffer| is considered undefined.
     bool xdrFinalizeEncoder();
+
+    const mozilla::TimeStamp parseEnded() const {
+        return parseEnded_;
+    }
+    // Inform `this` source that it has been fully parsed.
+    void recordParseEnded() {
+        MOZ_ASSERT(parseEnded_.IsNull());
+        parseEnded_ = mozilla::TimeStamp::Now();
+    }
 };
 
 class ScriptSourceHolder
 {
     ScriptSource* ss;
   public:
     ScriptSourceHolder()
       : ss(nullptr)
--- a/js/xpconnect/src/XPCJSContext.cpp
+++ b/js/xpconnect/src/XPCJSContext.cpp
@@ -3149,16 +3149,22 @@ AccumulateTelemetryCallback(int id, uint
         Telemetry::Accumulate(Telemetry::JS_DEPRECATED_LANGUAGE_EXTENSIONS_IN_ADDONS, sample);
         break;
       case JS_TELEMETRY_ADDON_EXCEPTIONS:
         Telemetry::Accumulate(Telemetry::JS_TELEMETRY_ADDON_EXCEPTIONS, nsDependentCString(key), sample);
         break;
       case JS_TELEMETRY_AOT_USAGE:
         Telemetry::Accumulate(Telemetry::JS_AOT_USAGE, sample);
         break;
+      case JS_TELEMETRY_PRIVILEGED_PARSER_COMPILE_LAZY_AFTER_MS:
+        Telemetry::Accumulate(Telemetry::JS_PRIVILEGED_PARSER_COMPILE_LAZY_AFTER_MS, sample);
+        break;
+      case JS_TELEMETRY_WEB_PARSER_COMPILE_LAZY_AFTER_MS:
+        Telemetry::Accumulate(Telemetry::JS_WEB_PARSER_COMPILE_LAZY_AFTER_MS, sample);
+        break;
       default:
         MOZ_ASSERT_UNREACHABLE("Unexpected JS_TELEMETRY id");
     }
 }
 
 static void
 CompartmentNameCallback(JSContext* cx, JSCompartment* comp,
                         char* buf, size_t bufsize)
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -1079,16 +1079,36 @@
   },
   "JS_DEPRECATED_LANGUAGE_EXTENSIONS_IN_ADDONS": {
     "alert_emails": ["jdemooij@mozilla.com"],
     "expires_in_version": "never",
     "kind": "enumerated",
     "n_values": 10,
     "description": "Use of SpiderMonkey's deprecated language extensions in add-ons: ForEach=0, DestructuringForIn=1 (obsolete), LegacyGenerator=2, ExpressionClosure=3, LetBlock=4 (obsolete), LetExpression=5 (obsolete), NoSuchMethod=6 (obsolete), FlagsArgument=7 (obsolete), RegExpSourceProp=8 (obsolete), RestoredRegExpStatics=9 (obsolete), BlockScopeFunRedecl=10"
   },
+  "JS_PRIVILEGED_PARSER_COMPILE_LAZY_AFTER_MS": {
+    "alert_emails": ["dteller@mozilla.com"],
+    "expires_in_version": "70",
+    "bug_numbers": [1343483],
+    "kind": "exponential",
+    "low": 10,
+    "high": 10000,
+    "n_buckets": 10,
+    "description": "Time elapsed between the moment a function is lazy-parsed (end of parsing of the ScriptSource) and the moment it is recompiled as non-lazy (start of compilation), in milliseconds, for privileged code."
+  },
+  "JS_WEB_PARSER_COMPILE_LAZY_AFTER_MS": {
+    "alert_emails": ["dteller@mozilla.com"],
+    "expires_in_version": "70",
+    "bug_numbers": [1343483],
+    "kind": "exponential",
+    "low": 10,
+    "high": 10000,
+    "n_buckets": 10,
+    "description": "Time elapsed between the moment a function is lazy-parsed (end of parsing of the ScriptSource) and the moment it is recompiled as non-lazy (start of compilation), in milliseconds, for web code."
+  },
   "XUL_CACHE_DISABLED": {
     "expires_in_version": "default",
     "kind": "flag",
     "description": "XUL cache was disabled"
   },
   "MEMORY_RESIDENT_FAST": {
     "alert_emails": ["memshrink-telemetry-alerts@mozilla.com"],
     "expires_in_version": "never",