From 991acbb36a60677acba6e2e8fd1bf87a3da7c04e Mon Sep 17 00:00:00 2001 From: "Michael \"Z\" Goddard" Date: Thu, 31 Jan 2019 17:56:46 -0500 Subject: [PATCH] benchmark more loading stats - Display time to load just the (json) data - Display progress and time for content - Display progress and time hydrating the downloaded assets --- src/playground/benchmark.js | 156 +++++++++++++++++++++++++++++++----- src/playground/index.html | 58 +++++++++----- 2 files changed, 173 insertions(+), 41 deletions(-) diff --git a/src/playground/benchmark.js b/src/playground/benchmark.js index c7d48aa36..7c5322461 100644 --- a/src/playground/benchmark.js +++ b/src/playground/benchmark.js @@ -7,6 +7,42 @@ if (window.performance) { performance.mark('Scratch.EvalStart'); } +class LoadingMiddleware { + constructor () { + this.middleware = []; + this.host = null; + this.original = null; + } + + install (host, original) { + this.host = host; + this.original = original; + const {middleware} = this; + return function (...args) { + let i = 0; + const next = function (_args) { + if (i >= middleware.length) { + return original.call(host, ..._args); + } + return middleware[i++](_args, next); + }; + return next(args); + }; + } + + push (middleware) { + this.middleware.push(middleware); + } +} + +const importLoadCostume = require('../import/load-costume'); +const costumeMiddleware = new LoadingMiddleware(); +importLoadCostume.loadCostume = costumeMiddleware.install(importLoadCostume, importLoadCostume.loadCostume); + +const importLoadSound = require('../import/load-sound'); +const soundMiddleware = new LoadingMiddleware(); +importLoadSound.loadSound = soundMiddleware.install(importLoadSound, importLoadSound.loadSound); + const ScratchStorage = require('scratch-storage'); const VirtualMachine = require('..'); const Runtime = require('../engine/runtime'); @@ -77,32 +113,92 @@ const getAssetUrl = function (asset) { class LoadingProgress { constructor (callback) { - this.total = 0; - this.complete = 0; + this.dataLoaded = 0; + this.contentTotal = 0; + this.contentComplete = 0; + this.hydrateTotal = 0; + this.hydrateComplete = 0; + this.memoryCurrent = 0; + this.memoryPeak = 0; this.callback = callback; } + sampleMemory () { + if (window.performance && window.performance.memory) { + this.memoryCurrent = window.performance.memory.usedJSHeapSize; + this.memoryPeak = Math.max(this.memoryCurrent, this.memoryPeak); + } + } + + attachHydrateMiddleware (middleware) { + const _this = this; + middleware.push((args, next) => { + _this.hydrateTotal += 1; + _this.sampleMemory(); + _this.callback(_this); + return Promise.resolve(next(args)) + .then(value => { + _this.hydrateComplete += 1; + _this.sampleMemory(); + _this.callback(_this); + return value; + }); + }); + } + on (storage, vm) { const _this = this; + + this.attachHydrateMiddleware(costumeMiddleware); + this.attachHydrateMiddleware(soundMiddleware); + const _load = storage.webHelper.load; storage.webHelper.load = function (...args) { - if (_this.complete === 0 && window.performance) { + if (_this.dataLoaded === 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'); + + if (_this.dataLoaded) { + if (_this.contentTotal === 0 && window.performance) { + performance.mark('Scratch.DownloadStart'); } - _this.complete += 1; + _this.contentTotal += 1; + } + _this.sampleMemory(); + _this.callback(_this); + + result.then(() => { + if (_this.dataLoaded === 0) { + if (window.performance) { + // How long did loading the data file take? + performance.mark('Scratch.LoadDataEnd'); + performance.measure('Scratch.LoadData', 'Scratch.LoadDataStart', 'Scratch.LoadDataEnd'); + } + + _this.dataLoaded = 1; + + window.ScratchVMLoadDataEnd = Date.now(); + } else { + _this.contentComplete += 1; + } + + if (_this.contentComplete && _this.contentComplete === _this.contentTotal) { + if (window.performance) { + // How long did it take to download the html, js, and + // all the project assets? + performance.mark('Scratch.DownloadEnd'); + performance.measure('Scratch.Download', 'Scratch.DownloadStart', 'Scratch.DownloadEnd'); + } + + window.ScratchVMDownloadEnd = Date.now(); + } + + _this.sampleMemory(); _this.callback(_this); }); return result; @@ -112,8 +208,8 @@ class LoadingProgress { // 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? + // How long did it take to load and hydrate the html, js, and + // all the project assets? performance.mark('Scratch.LoadEnd'); performance.measure('Scratch.Load', 'Scratch.LoadStart', 'Scratch.LoadEnd'); } @@ -122,6 +218,7 @@ class LoadingProgress { // With this event lets update LoadingProgress a final time so its // displayed loading time is accurate. + _this.sampleMemory(); _this.callback(_this); }); } @@ -497,12 +594,33 @@ const runBenchmark = function () { vm.attachStorage(storage); new LoadingProgress(progress => { - document.getElementsByClassName('loading-total')[0] - .innerText = progress.total; - document.getElementsByClassName('loading-complete')[0] - .innerText = progress.complete; - document.getElementsByClassName('loading-time')[0] - .innerText = `(${(window.ScratchVMLoadEnd || Date.now()) - window.ScratchVMLoadStart}ms)`; + const setElement = (name, value) => { + document.getElementsByClassName(name)[0].innerText = value; + }; + const sinceLoadStart = key => ( + `(${(window[key] || Date.now()) - window.ScratchVMLoadStart}ms)` + ); + + setElement('loading-total', 1); + setElement('loading-complete', progress.dataLoaded); + setElement('loading-time', sinceLoadStart('ScratchVMLoadDataEnd')); + + setElement('loading-content-total', progress.contentTotal); + setElement('loading-content-complete', progress.contentComplete); + setElement('loading-content-time', sinceLoadStart('ScratchVMDownloadEnd')); + + setElement('loading-hydrate-total', progress.hydrateTotal); + setElement('loading-hydrate-complete', progress.hydrateComplete); + setElement('loading-hydrate-time', sinceLoadStart('ScratchVMLoadEnd')); + + if (progress.memoryPeak) { + setElement('loading-memory-current', + `${(progress.memoryCurrent / 1000000).toFixed(0)}MB` + ); + setElement('loading-memory-peak', + `${(progress.memoryPeak / 1000000).toFixed(0)}MB` + ); + } }).on(storage, vm); let warmUpTime = 4000; diff --git a/src/playground/index.html b/src/playground/index.html index 2df079dc7..8459fcdda 100644 --- a/src/playground/index.html +++ b/src/playground/index.html @@ -40,31 +40,45 @@
-
- - 0 / 0 (--ms) -
-
-
- - ... +
+
+ + 0 / 0 (--ms)
-
- - ... +
+ + 0 / 0 (--ms)
-
- - ... +
+ + 0 / 0 (--ms) +
+
+ + -- / -- +
+
+
+ + ... +
+
+ + ... +
+
+ + ... +
+ +
- -