asset profiling

src/engine/runtime.js

@@ -534,6 +534,20 @@ class Runtime extends EventEmitter {
          * Total number of finished or errored scratch-storage load() requests since the runtime was created or cleared.
          */
         this.finishedAssetRequests = 0;
+
+        /**
+         * True if asset load time profiling is enabled.
+         * @type {boolean}
+         */
+        this.assetProfiling = true;
+
+        /**
+         * If asset load time profiling is enabled, a promise that will resolve/reject when the previous asset has
+         * loaded successfully or failed.
+         * @type {Promise<unknown>}
+         * @private
+         */
+        this._previousAsset = Promise.resolve();
     }
 
     /**
@@ -3460,10 +3474,11 @@ class Runtime extends EventEmitter {
     /**
      * Wrap an asset loading promise with progress support.
      * @template T
+     * @param {string} details
      * @param {() => Promise<T>} callback
      * @returns {Promise<T>}
      */
-    wrapAssetRequest (callback) {
+    wrapAssetRequest (details, callback) {
         this.totalAssetRequests++;
         this.emitAssetProgress();
 
@@ -3479,6 +3494,25 @@ class Runtime extends EventEmitter {
             throw error;
         };
 
+        if (this.assetProfiling) {
+            let startTime = 0;
+            this._previousAsset = this._previousAsset
+                .then(() => {
+                    startTime = performance.now();
+                })
+                .then(callback, callback)
+                .then(result => {
+                    const endTime = performance.now();
+                    const totalTime = endTime - startTime;
+
+                    (window.a||(window.a=[])).push(`${details.sprite} - ${details.type} - ${details.asset?.name},${totalTime}`);
+
+                    return result;
+                })
+                .then(onSuccess, onError);
+            return this._previousAsset;
+        }
+
         return callback().then(onSuccess, onError);
     }
 }

src/serialization/sb2.js

@@ -19,6 +19,7 @@ const Variable = require('../engine/variable');
 const MonitorRecord = require('../engine/monitor-record');
 const StageLayering = require('../engine/stage-layering');
 const ScratchXUtilities = require('../extension-support/tw-scratchx-utilities');
+const AssetProfilerDetails = require('./tw-asset-profiler-details');
 
 const {loadCostume} = require('../import/load-costume.js');
 const {loadSound} = require('../import/load-sound.js');
@@ -500,8 +501,9 @@ const parseScratchAssets = function (object, runtime, topLevel, zip) {
             // the file name of the costume should be the baseLayerID followed by the file ext
             const assetFileName = `${costumeSource.baseLayerID}.${ext}`;
             const textLayerFileName = costumeSource.textLayerID ? `${costumeSource.textLayerID}.png` : null;
-            costumePromises.push(runtime.wrapAssetRequest(() =>
-                deserializeCostume(costume, runtime, zip, assetFileName, textLayerFileName)
+            costumePromises.push(runtime.wrapAssetRequest(
+                AssetProfilerDetails.forCostume(object.objName, costume),
+                () => deserializeCostume(costume, runtime, zip, assetFileName, textLayerFileName)
                     .then(() => loadCostume(costume.md5, costume, runtime, 2 /* optVersion */))
             ));
         }
@@ -536,8 +538,9 @@ const parseScratchAssets = function (object, runtime, topLevel, zip) {
             // the file name of the sound should be the soundID (provided from the project.json)
             // followed by the file ext
             const assetFileName = `${soundSource.soundID}.${ext}`;
-            soundPromises.push(runtime.wrapAssetRequest(() =>
-                deserializeSound(sound, runtime, zip, assetFileName)
+            soundPromises.push(runtime.wrapAssetRequest(
+                AssetProfilerDetails.forSound(object.objName, sound),
+                () => deserializeSound(sound, runtime, zip, assetFileName)
                     .then(() => loadSound(sound, runtime, soundBank))
             ));
         }

src/serialization/sb3.js

@@ -17,6 +17,7 @@ const MathUtil = require('../util/math-util');
 const StringUtil = require('../util/string-util');
 const VariableUtil = require('../util/variable-util');
 const compress = require('./tw-compress-sb3');
+const AssetProfilerDetails = require('./tw-asset-profiler-details');
 
 const {loadCostume} = require('../import/load-costume.js');
 const {loadSound} = require('../import/load-sound.js');
@@ -1115,8 +1116,10 @@ const parseScratchAssets = function (object, runtime, zip) {
         // we're always loading the 'sb3' representation of the costume
         // any translation that needs to happen will happen in the process
         // of building up the costume object into an sb3 format
-        return runtime.wrapAssetRequest(() => deserializeCostume(costume, runtime, zip)
-            .then(() => loadCostume(costumeMd5Ext, costume, runtime)));
+        return runtime.wrapAssetRequest(
+            AssetProfilerDetails.forCostume(object.name, costume),
+            () => deserializeCostume(costume, runtime, zip).then(() => loadCostume(costumeMd5Ext, costume, runtime))
+        );
         // Only attempt to load the costume after the deserialization
         // process has been completed
     });
@@ -1140,8 +1143,10 @@ const parseScratchAssets = function (object, runtime, zip) {
         // we're always loading the 'sb3' representation of the costume
         // any translation that needs to happen will happen in the process
         // of building up the costume object into an sb3 format
-        return runtime.wrapAssetRequest(() => deserializeSound(sound, runtime, zip)
-            .then(() => loadSound(sound, runtime, assets.soundBank)));
+        return runtime.wrapAssetRequest(
+            AssetProfilerDetails.forSound(object.name, sound),
+            () => deserializeSound(sound, runtime, zip).then(() => loadSound(sound, runtime, assets.soundBank))
+        );
         // Only attempt to load the sound after the deserialization
         // process has been completed.
     });

src/serialization/tw-asset-profiler-details.js

@@ -0,0 +1,22 @@
+const forCostume = (spriteName, costume) => ({
+    type: 'costume',
+    sprite: spriteName,
+    asset: costume
+});
+
+const forSound = (spriteName, sound) => ({
+    type: 'sound',
+    sprite: spriteName,
+    asset: sound
+});
+
+const forFont = font => ({
+    type: 'font',
+    asset: font
+});
+
+module.exports = {
+    forCostume,
+    forSound,
+    forFont
+};

src/util/tw-asset-util.js

@@ -25,7 +25,7 @@ class AssetUtil {
             }
 
             if (file) {
-                return runtime.wrapAssetRequest(() => file.async('uint8array').then(data => runtime.storage.createAsset(
+                return runtime.wrapAssetRequest({}, () => file.async('uint8array').then(data => runtime.storage.createAsset(
                     assetType,
                     ext,
                     data,
@@ -35,7 +35,7 @@ class AssetUtil {
             }
         }
 
-        return runtime.wrapAssetRequest(() => runtime.storage.load(assetType, md5, ext));
+        return runtime.wrapAssetRequest({}, () => runtime.storage.load(assetType, md5, ext));
     }
 }
 

test/integration/tw_asset_progress.js

@@ -69,13 +69,13 @@ test('wrapAssetRequest', t => {
     });
 
     Promise.all([
-        runtime.wrapAssetRequest(() => Promise.resolve(1)),
-        runtime.wrapAssetRequest(() => Promise.resolve(2))
+        runtime.wrapAssetRequest({}, () => Promise.resolve(1)),
+        runtime.wrapAssetRequest({}, () => Promise.resolve(2))
     ]).then(results => {
         t.same(results, [1, 2]);
 
         // eslint-disable-next-line prefer-promise-reject-errors
-        runtime.wrapAssetRequest(() => Promise.reject(3)).catch(error => {
+        runtime.wrapAssetRequest({}, () => Promise.reject(3)).catch(error => {
             t.equal(error, 3);
             t.same(log, [
                 [0, 1],