MAGETWO-59587: Debugging and profiling tools for UI Components and Javascript modules

VladimirZaets · VladimirZaets · commit d99043c09781 · 2017-04-07T17:34:32.000+03:00
diff --git a/app/code/Magento/Ui/view/base/web/js/core/renderer/layout.js b/app/code/Magento/Ui/view/base/web/js/core/renderer/layout.js
@@ -8,8 +8,9 @@ define([
     'jquery',
     'mageUtils',
     'uiRegistry',
-    './types'
-], function (_, $, utils, registry, types) {
+    './types',
+    '../../lib/logger/console-logger'
+], function (_, $, utils, registry, types, consoleLogger) {
     'use strict';
 
     var templates = registry.create(),
@@ -70,7 +71,25 @@ define([
      * @returns {jQueryPromise}
      */
     function loadDeps(node) {
-        var loaded = $.Deferred();
+        var loaded = $.Deferred(),
+            loggerUtils = consoleLogger.utils;
+
+        if (node.deps) {
+            consoleLogger.utils.asyncLog(
+                loaded,
+                {
+                    data: {
+                        component: node.name,
+                        deps: node.deps
+                    },
+                    messages: loggerUtils.createMessages(
+                        'depsStartRequesting',
+                        'depsFinishRequesting',
+                        'depsLoadingFail'
+                    )
+                }
+            );
+        }
 
         registry.get(node.deps, function (deps) {
             node.provider = node.extendProvider ? deps && deps.name : node.provider;
@@ -90,8 +109,19 @@ define([
         var loaded = $.Deferred(),
             source = node.component;
 
+        consoleLogger.info('componentStartLoading', {
+            component: node.component
+        });
+
         require([source], function (constr) {
+            consoleLogger.info('componentFinishLoading', {
+                component: node.component
+            });
             loaded.resolve(node, constr);
+        }, function (err) {
+            consoleLogger.error('componentLoadingFail', {
+                component: node.component
+            });
         });
 
         return loaded.promise();
@@ -106,6 +136,11 @@ define([
     function initComponent(node, Constr) {
         var component = new Constr(_.omit(node, 'children'));
 
+        consoleLogger.info('componentStartInitialization', {
+            component: node.component,
+            componentName: node.name
+        });
+
         registry.set(node.name, component);
     }
 
diff --git a/app/code/Magento/Ui/view/base/web/js/lib/knockout/bindings/scope.js b/app/code/Magento/Ui/view/base/web/js/lib/knockout/bindings/scope.js
@@ -7,18 +7,22 @@ define([
     'ko',
     'uiRegistry',
     'mage/translate',
-    '../template/renderer'
-], function (ko, registry, $t, renderer) {
+    '../template/renderer',
+    'jquery',
+    '../../logger/console-logger'
+], function (ko, registry, $t, renderer, $, consoleLogger) {
     'use strict';
 
     /**
      * Creates child context with passed component param as $data. Extends context with $t helper.
      * Applies bindings to descendant nodes.
      * @param {HTMLElement} el - element to apply bindings to.
      * @param {ko.bindingContext} bindingContext - instance of ko.bindingContext, passed to binding initially.
+     * @param {Promise} promise - instance of jQuery promise
      * @param {Object} component - component instance to attach to new context
      */
-    function applyComponents(el, bindingContext, component) {
+    function applyComponents(el, bindingContext, promise, component) {
+        promise.resolve();
         component = bindingContext.createChildContext(component);
 
         ko.utils.extend(component, {
@@ -53,9 +57,25 @@ define([
          */
         update: function (el, valueAccessor, allBindings, viewModel, bindingContext) {
             var component = valueAccessor(),
-                apply = applyComponents.bind(this, el, bindingContext);
+                promise = $.Deferred(),
+                apply = applyComponents.bind(this, el, bindingContext, promise),
+                loggerUtils = consoleLogger.utils;
 
             if (typeof component === 'string') {
+                loggerUtils.asyncLog(
+                    promise,
+                    {
+                        data: {
+                            component: component
+                        },
+                        messages: loggerUtils.createMessages(
+                            'requestingComponent',
+                            'requestingComponentIsLoaded',
+                            'requestingComponentIsFailed'
+                        )
+                    }
+                );
+
                 registry.get(component, apply);
             } else if (typeof component === 'function') {
                 component(apply);
diff --git a/app/code/Magento/Ui/view/base/web/js/lib/knockout/template/engine.js b/app/code/Magento/Ui/view/base/web/js/lib/knockout/template/engine.js
@@ -6,8 +6,9 @@ define([
     'ko',
     'underscore',
     './observable_source',
-    './renderer'
-], function (ko, _, Source, renderer) {
+    './renderer',
+    '../../logger/console-logger'
+], function (ko, _, Source, renderer, consoleLogger) {
     'use strict';
 
     var RemoteTemplateEngine,
@@ -36,9 +37,12 @@ define([
      * Caches template after it's unique name and renders in once.
      * If template name is not typeof string, delegates work to knockout.templateSources.anonymousTemplate.
      * @param  {*} template
+     * @param  {HTMLElement} templateDocument - document
+     * @param  {Object} options - options, passed to template binding
+     * @param  {ko.bindingContext} bindingContext
      * @returns {TemplateSource} Object with methods 'nodes' and 'data'.
      */
-    RemoteTemplateEngine.prototype.makeTemplateSource = function (template) {
+    RemoteTemplateEngine.prototype.makeTemplateSource = function (template, templateDocument, options, bindingContext) {
         var source,
             templateId;
 
@@ -48,13 +52,36 @@ define([
 
             if (!source) {
                 source = new Source(template);
+                source.requestedBy = bindingContext.$data.name;
                 sources[templateId] = source;
 
+                consoleLogger.info('templateStartLoading', {
+                    template: templateId,
+                    component: bindingContext.$data.name
+                });
+
                 renderer.render(template).done(function (rendered) {
+                    consoleLogger.info('templateLoadedFromServer', {
+                        template: templateId,
+                        component: bindingContext.$data.name
+                    });
                     source.nodes(rendered);
+                }).fail(function (err) {
+                    consoleLogger.error('templateLoadingFail', {
+                        template: templateId,
+                        component: bindingContext.$data.name
+                    });
                 });
             }
 
+            if (source.requestedBy !== bindingContext.$data.name) {
+                consoleLogger.info('templateLoadedFromCache', {
+                    template: templateId,
+                    component: bindingContext.$data.name
+                });
+            }
+
+
             return source;
         } else if (template.nodeType === 1 || template.nodeType === 8) {
             source = new ko.templateSources.anonymousTemplate(template);
@@ -87,7 +114,7 @@ define([
      * @return {Array} - array of html elements
      */
     RemoteTemplateEngine.prototype.renderTemplate = function (template, bindingContext, options, templateDocument) {
-        var templateSource = this.makeTemplateSource(template, templateDocument, options);
+        var templateSource = this.makeTemplateSource(template, templateDocument, options, bindingContext);
 
         return this.renderTemplateSource(templateSource, bindingContext, options);
     };
diff --git a/app/code/Magento/Ui/view/base/web/js/lib/knockout/template/loader.js b/app/code/Magento/Ui/view/base/web/js/lib/knockout/template/loader.js
@@ -92,8 +92,9 @@ define([
 
             require([path], function (template) {
                 template = removeLicense(template);
-
                 loading.resolve(template);
+            }, function (err) {
+                loading.reject(err);
             });
 
             return loading.promise();
diff --git a/app/code/Magento/Ui/view/base/web/js/lib/logger/console-logger.js b/app/code/Magento/Ui/view/base/web/js/lib/logger/console-logger.js
@@ -6,8 +6,9 @@ define([
     './message-poll',
     './levels-poll',
     'Magento_Ui/js/lib/core/storage/local',
-    'underscore'
-], function (Logger, entryFactory, ConsoleHandler, Formatter, messagePoll, levelsPoll, storage, _) {
+    'underscore',
+    './logger-utils'
+], function (Logger, entryFactory, ConsoleHandler, Formatter, messagePoll, levelsPoll, storage, _, LoggerUtils) {
     'use strict';
 
     var STORAGE_NAMESPACE = 'CONSOLE_LOGGER';
@@ -20,14 +21,16 @@ define([
     function ConsoleLogger() {
         var formatter = new Formatter(),
             consoleHandler = new ConsoleHandler(formatter),
-            savedLevel = storage.get(STORAGE_NAMESPACE);
+            savedLevel = storage.get(STORAGE_NAMESPACE),
+            utils = new LoggerUtils(this);
 
         Logger.call(this, consoleHandler, entryFactory);
 
         if (savedLevel) {
             this.displayLevel_ = savedLevel;
         }
 
+        this.utils = utils;
         this.messages = messagePoll;
         this.levels = levelsPoll.getLevels();
     }
diff --git a/app/code/Magento/Ui/view/base/web/js/lib/logger/logger-utils.js b/app/code/Magento/Ui/view/base/web/js/lib/logger/logger-utils.js
@@ -0,0 +1,72 @@
+/**
+ * Copyright © 2013-2017 Magento, Inc. All rights reserved.
+ * See COPYING.txt for license details.
+ */
+define([], function () {
+    'use strict';
+
+    /**
+     * Utils methods for logger
+     * @param {Logger} logger
+     */
+    function LogUtils(logger) {
+        this.logger = logger;
+
+    }
+
+    /**
+     * Method for logging asynchronous operations
+     * @param {Promise} promise
+     * @param {object} config
+     */
+    LogUtils.prototype.asyncLog = function (promise, config) {
+        var levels,
+            messages,
+            wait;
+
+        config = config || {};
+        levels = config.levels || this.createLevels();
+        messages = config.messages || this.createMessages();
+        wait = config.wait || 5000;
+
+
+        this.logger[levels.requested](messages.requested, config.data);
+        setTimeout(function () {
+            promise.state() === 'pending' ?
+                this.logger[levels.failed](messages.failed, config.data):
+                this.logger[levels.loaded](messages.loaded, config.data);
+        }.bind(this), wait)
+    };
+
+    /**
+     * Method that creats object of messages
+     * @param {String} requested - log message that showing that request for class is started
+     * @param {String} loaded - log message that show when requested class is loaded
+     * @param {String} failded - log message that show when requested class is failed
+     * @returns {Object}
+     */
+    LogUtils.prototype.createMessages = function (requested, loaded, failded) {
+        return {
+            requested: requested || '',
+            loaded: loaded || '',
+            failed: failded || ''
+        }
+    };
+
+    /**
+     * Method that creats object of log levels
+     * @param {String} requested - log message that showing that request for class is started
+     * @param {String} loaded - log message that show when requested class is loaded
+     * @param {String} failded - log message that show when requested class is failed
+     * @returns {Object}
+     */
+    LogUtils.prototype.createLevels = function (requested, loaded, failded) {
+        return {
+            requested: requested || 'info',
+            loaded: loaded || 'info',
+            failed: failded || 'warn'
+        }
+    };
+
+    return LogUtils;
+});
diff --git a/app/code/Magento/Ui/view/base/web/js/lib/logger/message-poll.js b/app/code/Magento/Ui/view/base/web/js/lib/logger/message-poll.js
@@ -1,7 +1,26 @@
 define(function () {
     'use strict';
 
-    var MESSAGES = {};
+    var MESSAGES = {
+        templateStartLoading:
+            'The "${ $.template }" template requested by  the "${$.component}" component started loading.',
+        templateLoadedFromServer:
+            'The "${ $.template }" template requested by the "${$.component}" component  was loaded from server."',
+        templateLoadedFromCache:
+            'The "${ $.template }" template  requested by the "${$.component}" component was loaded from cache."',
+        templateLoadingFail: 'Failed to load the "${ $.template }" template requested by "${$.component}".',
+        componentStartInitialization:
+            'Component "${$.component}" start initialization with instance name "${$.componentName}".',
+        componentStartLoading: ' Started loading the "${$.component}" component.',
+        componentFinishLoading: 'The "${$.component}" component was loaded.',
+        componentLoadingFail: 'Failed to load the "${$.component}" component.',
+        depsLoadingFail: 'Could not get the declared "${$.deps}" dependency for the "${$.component}" instance.',
+        depsStartRequesting: 'Requesting the "${$.deps}" dependency for the "${$.component}" instance.',
+        depsFinishRequesting: 'The "${$.deps}" dependency for the "${$.component}" instance was received.',
+        requestingComponent: 'Requesting the "${$.component}" component.',
+        requestingComponentIsLoaded: 'The requested "${$.component}" component was received.',
+        requestingComponentIsFailed: 'Could not get the requested "${$.component}" component.'
+    };
 
     return {
         /**
diff --git a/lib/web/mage/requirejs/text.js b/lib/web/mage/requirejs/text.js
@@ -100,35 +100,35 @@ define(['module'], function (module) {
             }
         }
 
+        xhr.onreadystatechange = function (evt) {
+            var status, err;
+            //Do not explicitly handle errors, those should be
+            //visible via console output in the browser.
+            if (xhr.readyState === 4) {
+                status = xhr.status || 0;
+                if (status > 399 && status < 600) {
+                    //An http 4xx or 5xx error. Signal an error.
+                    err = new Error(url + ' HTTP status: ' + status);
+                    err.xhr = xhr;
+                    if (fail) {
+                        fail(err);
+                    }
+                } else {
+                    callback(xhr.responseText);
+
+                    if (defaultConfig.onXhrComplete) {
+                        defaultConfig.onXhrComplete(xhr, url);
+                    }
+                }
+            }
+        };
+
         /*eslint-enable max-depth */
 
         if (defaultConfig.onXhr) {
             defaultConfig.onXhr(xhr, url);
         }
 
-        /**
-         * onload handler
-         */
-        xhr.onload = function () {
-
-            callback(xhr.responseText);
-
-            if (defaultConfig.onXhrComplete) {
-                defaultConfig.onXhrComplete(xhr, url);
-            }
-        };
-
-        /**
-         * onerror handler
-         */
-        xhr.onerror = function (event) {
-            errorHandler(event);
-
-            if (defaultConfig.onXhrFailure) {
-                defaultConfig.onXhrFailure(xhr, url, event);
-            }
-        };
-
         xhr.send();
     }
 
