From fa6905ef0016475c08334735eea4957bcb2ba59b Mon Sep 17 00:00:00 2001 From: n1474335 Date: Fri, 29 Dec 2017 17:32:23 +0000 Subject: [PATCH] Added more comprehensive logging to FlowControl ops and added '>' prefix to all ChefWorker logs to improve clarity --- package-lock.json | 28 ++++++++++++++++++++++++++++ package.json | 1 + src/core/ChefWorker.js | 11 ++++++++++- src/core/FlowControl.js | 20 ++++++++++++++------ src/core/Recipe.js | 3 ++- src/web/App.js | 4 +++- src/web/Manager.js | 2 +- src/web/RecipeWaiter.js | 6 ++++-- src/web/WorkerWaiter.js | 4 +++- 9 files changed, 66 insertions(+), 13 deletions(-) diff --git a/package-lock.json b/package-lock.json index a90959be..f42d9aa3 100644 --- a/package-lock.json +++ b/package-lock.json @@ -2436,12 +2436,31 @@ "event-emitter": "0.3.5" } }, + "es6-object-assign": { + "version": "1.1.0", + "resolved": "https://registry.npmjs.org/es6-object-assign/-/es6-object-assign-1.1.0.tgz", + "integrity": "sha1-wsNYJlYkfDnqEHyx5mUrb58kUjw=" + }, + "es6-polyfills": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/es6-polyfills/-/es6-polyfills-2.0.0.tgz", + "integrity": "sha1-fzWP04jYyIjQDPyaHuqJ+XFoOTE=", + "requires": { + "es6-object-assign": "1.1.0", + "es6-promise-polyfill": "1.2.0" + } + }, "es6-promise": { "version": "4.0.5", "resolved": "https://registry.npmjs.org/es6-promise/-/es6-promise-4.0.5.tgz", "integrity": "sha1-eILzCt3lskDM+n99eMVIMwlRrkI=", "dev": true }, + "es6-promise-polyfill": { + "version": "1.2.0", + "resolved": "https://registry.npmjs.org/es6-promise-polyfill/-/es6-promise-polyfill-1.2.0.tgz", + "integrity": "sha1-84kl8jyz4+jObNqP93T867sJDN4=" + }, "es6-set": { "version": "0.1.5", "resolved": "https://registry.npmjs.org/es6-set/-/es6-set-0.1.5.tgz", @@ -6134,6 +6153,15 @@ "resolved": "https://registry.npmjs.org/loglevel/-/loglevel-1.6.0.tgz", "integrity": "sha1-rgyqVhERSYxboTcj1vtjHSQAOTQ=" }, + "loglevel-message-prefix": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/loglevel-message-prefix/-/loglevel-message-prefix-3.0.0.tgz", + "integrity": "sha1-ER/bltlPlh2PyLiqv7ZrBqw+dq0=", + "requires": { + "es6-polyfills": "2.0.0", + "loglevel": "1.6.0" + } + }, "longest": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/longest/-/longest-1.0.1.tgz", diff --git a/package.json b/package.json index 99fcccd4..8e51c01c 100644 --- a/package.json +++ b/package.json @@ -88,6 +88,7 @@ "jsrsasign": "8.0.4", "lodash": "^4.17.4", "loglevel": "^1.6.0", + "loglevel-message-prefix": "^3.0.0", "moment": "^2.20.1", "moment-timezone": "^0.5.14", "node-md6": "^0.1.0", diff --git a/src/core/ChefWorker.js b/src/core/ChefWorker.js index 899f6664..9e9f8a30 100644 --- a/src/core/ChefWorker.js +++ b/src/core/ChefWorker.js @@ -11,6 +11,15 @@ import Chef from "./Chef.js"; import OperationConfig from "./config/MetaConfig.js"; import OpModules from "./config/modules/Default.js"; +// Add ">" to the start of all log messages in the Chef Worker +import loglevelMessagePrefix from "loglevel-message-prefix"; + +loglevelMessagePrefix(log, { + prefixes: [], + staticPrefixes: [">"], + prefixFormat: "%p" +}); + // Set up Chef instance self.chef = new Chef(); @@ -91,7 +100,7 @@ async function bake(data) { ); self.postMessage({ - action: "bakeSuccess", + action: "bakeComplete", data: response }); } catch (err) { diff --git a/src/core/FlowControl.js b/src/core/FlowControl.js index bba5eaf1..f847ab25 100755 --- a/src/core/FlowControl.js +++ b/src/core/FlowControl.js @@ -56,6 +56,7 @@ const FlowControl = { // Run recipe over each tranche for (i = 0; i < inputs.length; i++) { + log.debug(`Entering tranche ${i + 1} of ${inputs.length}`); const dish = new Dish(inputs[i], inputType); try { progress = await recipe.execute(dish, 0); @@ -169,16 +170,19 @@ const FlowControl = { * @returns {Object} The updated state of the recipe. */ runJump: function(state) { - let ings = state.opList[state.progress].getIngValues(), - jmpIndex = FlowControl._getLabelIndex(ings[0], state), - maxJumps = ings[1]; + const ings = state.opList[state.progress].getIngValues(), + label = ings[0], + maxJumps = ings[1], + jmpIndex = FlowControl._getLabelIndex(label, state); if (state.numJumps >= maxJumps || jmpIndex === -1) { + log.debug("Maximum jumps reached or label cannot be found"); return state; } state.progress = jmpIndex; state.numJumps++; + log.debug(`Jumping to label '${label}' at position ${jmpIndex} (jumps = ${state.numJumps})`); return state; }, @@ -194,14 +198,16 @@ const FlowControl = { * @returns {Object} The updated state of the recipe. */ runCondJump: function(state) { - let ings = state.opList[state.progress].getIngValues(), + const ings = state.opList[state.progress].getIngValues(), dish = state.dish, regexStr = ings[0], invert = ings[1], - jmpIndex = FlowControl._getLabelIndex(ings[2], state), - maxJumps = ings[3]; + label = ings[2], + maxJumps = ings[3], + jmpIndex = FlowControl._getLabelIndex(label, state); if (state.numJumps >= maxJumps || jmpIndex === -1) { + log.debug("Maximum jumps reached or label cannot be found"); return state; } @@ -210,6 +216,7 @@ const FlowControl = { if (!invert && strMatch || invert && !strMatch) { state.progress = jmpIndex; state.numJumps++; + log.debug(`Jumping to label '${label}' at position ${jmpIndex} (jumps = ${state.numJumps})`); } } @@ -249,6 +256,7 @@ const FlowControl = { /** * Returns the index of a label. * + * @private * @param {Object} state * @param {string} name * @returns {number} diff --git a/src/core/Recipe.js b/src/core/Recipe.js index c9128118..877c0ac1 100755 --- a/src/core/Recipe.js +++ b/src/core/Recipe.js @@ -146,10 +146,11 @@ Recipe.prototype.lastOpIndex = function(startIndex) { Recipe.prototype.execute = async function(dish, startFrom) { startFrom = startFrom || 0; let op, input, output, numJumps = 0, numRegisters = 0; + log.debug(`[*] Executing recipe of ${this.opList.length} operations, starting at ${startFrom}`); for (let i = startFrom; i < this.opList.length; i++) { op = this.opList[i]; - log.debug(`[${i}] ${op.name}`); + log.debug(`[${i}] ${op.name} ${JSON.stringify(op.getIngValues())}`); if (op.isDisabled()) { log.debug("Operation is disabled, skipping"); continue; diff --git a/src/web/App.js b/src/web/App.js index eb174e72..f60420ae 100755 --- a/src/web/App.js +++ b/src/web/App.js @@ -49,9 +49,11 @@ App.prototype.setup = function() { this.manager.setup(); this.resetLayout(); this.setCompileMessage(); - this.loadURIParams(); + log.debug("App loaded"); this.appLoaded = true; + + this.loadURIParams(); this.loaded(); }; diff --git a/src/web/Manager.js b/src/web/Manager.js index c19ddaf5..bf3f4acd 100755 --- a/src/web/Manager.js +++ b/src/web/Manager.js @@ -119,7 +119,7 @@ Manager.prototype.initialiseEventListeners = function() { this.addDynamicListener(".op-list .op-icon", "mouseover", this.ops.opIconMouseover, this.ops); this.addDynamicListener(".op-list .op-icon", "mouseleave", this.ops.opIconMouseleave, this.ops); this.addDynamicListener(".op-list", "oplistcreate", this.ops.opListCreate, this.ops); - this.addDynamicListener("li.operation", "operationadd", this.recipe.opAdd.bind(this.recipe)); + this.addDynamicListener("li.operation", "operationadd", this.recipe.opAdd, this.recipe); // Recipe this.addDynamicListener(".arg:not(select)", "input", this.recipe.ingChange, this.recipe); diff --git a/src/web/RecipeWaiter.js b/src/web/RecipeWaiter.js index 3400fa32..be7ace65 100755 --- a/src/web/RecipeWaiter.js +++ b/src/web/RecipeWaiter.js @@ -253,7 +253,7 @@ RecipeWaiter.prototype.breakpointClick = function(e) { */ RecipeWaiter.prototype.operationDblclick = function(e) { e.target.remove(); - window.dispatchEvent(this.manager.statechange); + this.opRemove(e); }; @@ -266,7 +266,7 @@ RecipeWaiter.prototype.operationDblclick = function(e) { */ RecipeWaiter.prototype.operationChildDblclick = function(e) { e.target.parentNode.remove(); - window.dispatchEvent(this.manager.statechange); + this.opRemove(e); }; @@ -421,6 +421,7 @@ RecipeWaiter.prototype.dropdownToggleClick = function(e) { * @param {event} e */ RecipeWaiter.prototype.opAdd = function(e) { + log.debug(`'${e.target.querySelector(".arg-title").textContent}' added to recipe`); window.dispatchEvent(this.manager.statechange); }; @@ -433,6 +434,7 @@ RecipeWaiter.prototype.opAdd = function(e) { * @param {event} e */ RecipeWaiter.prototype.opRemove = function(e) { + log.debug("Operation removed from recipe"); window.dispatchEvent(this.manager.statechange); }; diff --git a/src/web/WorkerWaiter.js b/src/web/WorkerWaiter.js index 7d4dbf2f..1473e101 100644 --- a/src/web/WorkerWaiter.js +++ b/src/web/WorkerWaiter.js @@ -45,7 +45,7 @@ WorkerWaiter.prototype.handleChefMessage = function(e) { log.debug("Receiving '" + r.action + "' from ChefWorker"); switch (r.action) { - case "bakeSuccess": + case "bakeComplete": this.bakingComplete(r.data); break; case "bakeError": @@ -56,6 +56,7 @@ WorkerWaiter.prototype.handleChefMessage = function(e) { break; case "workerLoaded": this.app.workerLoaded = true; + log.debug("ChefWorker loaded"); this.app.loaded(); break; case "statusMessage": @@ -118,6 +119,7 @@ WorkerWaiter.prototype.bakingComplete = function(response) { this.app.progress = response.progress; this.manager.recipe.updateBreakpointIndicator(response.progress); this.manager.output.set(response.result, response.type, response.duration); + log.debug("--- Bake complete ---"); };