add simple loading time benchmark detail

src/playground/benchmark.js

@@ -1,5 +1,19 @@
+// Track loading time with timestamps and if possible the performance api.
+if (window.performance) {
+    // Mark with the performance API when benchmark.js and its dependecies start
+    // evaluation. This can tell us once measured how long the code spends time
+    // turning into execution code for the first time. Skipping evaluation of
+    // some of the code can help us make it faster.
+    performance.mark('Scratch.EvalStart');
+}
+
 const ScratchStorage = require('scratch-storage');
 const VirtualMachine = require('..');
+const Runtime = require('../engine/runtime');
+
+const ScratchRender = require('scratch-render');
+const AudioEngine = require('scratch-audio');
+const ScratchSVGRenderer = require('scratch-svg-renderer');
 
 const Scratch = window.Scratch = window.Scratch || {};
 
@@ -68,19 +82,48 @@ class LoadingProgress {
         this.callback = callback;
     }
 
-    on (storage) {
+    on (storage, vm) {
         const _this = this;
         const _load = storage.webHelper.load;
         storage.webHelper.load = function (...args) {
+            if (_this.complete === 0 && window.performance) {
+                // Mark in browser inspectors how long it takes to load the
+                // projects initial data file.
+                performance.mark('Scratch.LoadDataStart');
+            }
+
             const result = _load.call(this, ...args);
             _this.total += 1;
             _this.callback(_this);
             result.then(() => {
+                if (_this.complete === 0 && window.performance) {
+                    // How long did loading the data file take?
+                    performance.mark('Scratch.LoadDataEnd');
+                    performance.measure('Scratch.LoadData', 'Scratch.LoadDataStart', 'Scratch.LoadDataEnd');
+                }
+
                 _this.complete += 1;
                 _this.callback(_this);
             });
             return result;
         };
+        vm.runtime.on(Runtime.PROJECT_LOADED, () => {
+            // Currently LoadingProgress tracks when the data has been loaded
+            // and not when the data has been decoded. It may be difficult to
+            // track that but it isn't hard to track when its all been decoded.
+            if (window.performance) {
+                // How long did it take to load the html, js, and all the
+                // project assets?
+                performance.mark('Scratch.LoadEnd');
+                performance.measure('Scratch.Load', 'Scratch.LoadStart', 'Scratch.LoadEnd');
+            }
+
+            window.ScratchVMLoadEnd = Date.now();
+
+            // With this event lets update LoadingProgress a final time so its
+            // displayed loading time is accurate.
+            _this.callback(_this);
+        });
     }
 }
 
@@ -458,7 +501,9 @@ const runBenchmark = function () {
             .innerText = progress.total;
         document.getElementsByClassName('loading-complete')[0]
             .innerText = progress.complete;
-    }).on(storage);
+        document.getElementsByClassName('loading-time')[0]
+            .innerText = `(${(window.ScratchVMLoadEnd || Date.now()) - window.ScratchVMLoadStart}ms)`;
+    }).on(storage, vm);
 
     let warmUpTime = 4000;
     let maxRecordedTime = 6000;
@@ -479,10 +524,10 @@ const runBenchmark = function () {
 
     // Instantiate the renderer and connect it to the VM.
     const canvas = document.getElementById('scratch-stage');
-    const renderer = new window.ScratchRender(canvas);
+    const renderer = new ScratchRender(canvas);
     Scratch.renderer = renderer;
     vm.attachRenderer(renderer);
-    const audioEngine = new window.AudioEngine();
+    const audioEngine = new AudioEngine();
     vm.attachAudioEngine(audioEngine);
     vm.attachV2SVGAdapter(new ScratchSVGRenderer.SVGRenderer());
     vm.attachV2BitmapAdapter(new ScratchSVGRenderer.BitmapAdapter());
@@ -577,3 +622,10 @@ window.onload = function () {
 window.onhashchange = function () {
     location.reload();
 };
+
+if (window.performance) {
+    performance.mark('Scratch.EvalEnd');
+    performance.measure('Scratch.Eval', 'Scratch.EvalStart', 'Scratch.EvalEnd');
+}
+
+window.ScratchVMEvalEnd = Date.now();

src/playground/index.html

@@ -5,6 +5,18 @@
     <meta charset="utf-8">
     <title>Scratch VM Benchmark</title>
     <link rel="stylesheet" href="./benchmark.css" type="text/css" media="screen">
+    <script>
+        // Track loading time with timestamps and if possible the performance
+        // api.
+
+        // Start tracking loading of Scratch before the body dom is evaluated.
+        window.ScratchVMLoadStart = Date.now();
+        if (window.performance) {
+            // Mark for browser performance inspectors and if we want to use
+            // other performance apis.
+            performance.mark('Scratch.LoadStart');
+        }
+    </script>
 </head>
 <body>
   <h2>Scratch VM Benchmark</h2>
@@ -30,7 +42,7 @@
 
   <div class="loading">
     <label>Loading:</label>
-    <span class="loading-complete">0</span> / <span class="loading-total">0</span>
+    <span class="loading-complete">0</span> / <span class="loading-total">0</span> <span class="loading-time">(--ms)</span>
   </div>
   <div class="profile-count-group">
     <div class="profile-count">