Merge branch 'feature-logging'

.eslintrc.json

@@ -35,7 +35,6 @@
         }],
 
         // disable rules from base configurations
-        "no-console": "off",
         "no-control-regex": "off",
 
         // stylistic conventions
@@ -90,6 +89,7 @@
         "$": false,
         "jQuery": false,
         "moment": false,
+        "log": false,
 
         "COMPILE_TIME": false,
         "COMPILE_MSG": false,

package.json

@@ -87,6 +87,8 @@
     "jsonpath": "^1.0.0",
     "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",

src/core/Chef.js

@@ -34,6 +34,7 @@ const Chef = function() {
  * @returns {number} response.error - The error object thrown by a failed operation (false if no error)
 */
 Chef.prototype.bake = async function(input, recipeConfig, options, progress, step) {
+    log.debug("Chef baking");
     let startTime  = new Date().getTime(),
         recipe     = new Recipe(recipeConfig),
         containsFc = recipe.containsFlowControl(),
@@ -69,7 +70,7 @@ Chef.prototype.bake = async function(input, recipeConfig, options, progress, ste
     try {
         progress = await recipe.execute(this.dish, progress);
     } catch (err) {
-        console.log(err);
+        log.error(err);
         error = {
             displayStr: err.displayStr,
         };
@@ -112,6 +113,8 @@ Chef.prototype.bake = async function(input, recipeConfig, options, progress, ste
  * @returns {number} The time it took to run the silent bake in milliseconds.
 */
 Chef.prototype.silentBake = function(recipeConfig) {
+    log.debug("Running silent bake");
+
     let startTime = new Date().getTime(),
         recipe    = new Recipe(recipeConfig),
         dish      = new Dish("", Dish.STRING);

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();
@@ -42,6 +51,8 @@ self.postMessage({
 self.addEventListener("message", function(e) {
     // Handle message
     const r = e.data;
+    log.debug("ChefWorker receiving command '" + r.action + "'");
+
     switch (r.action) {
         case "bake":
             bake(r.data);
@@ -61,6 +72,9 @@ self.addEventListener("message", function(e) {
                 r.data.pos
             );
             break;
+        case "setLogLevel":
+            log.setLevel(r.data, false);
+            break;
         default:
             break;
     }
@@ -86,7 +100,7 @@ async function bake(data) {
         );
 
         self.postMessage({
-            action: "bakeSuccess",
+            action: "bakeComplete",
             data: response
         });
     } catch (err) {
@@ -121,7 +135,7 @@ function loadRequiredModules(recipeConfig) {
         let module = self.OperationConfig[op.op].module;
 
         if (!OpModules.hasOwnProperty(module)) {
-            console.log("Loading module " + module);
+            log.info("Loading module " + module);
             self.sendStatusMessage("Loading module " + module);
             self.importScripts(self.docURL + "/" + module + ".js");
         }

src/core/Dish.js

@@ -111,6 +111,7 @@ Dish.enumLookup = function(typeEnum) {
  * @param {number} type - The data type of value, see Dish enums.
  */
 Dish.prototype.set = function(value, type) {
+    log.debug("Dish type: " + Dish.enumLookup(type));
     this.value = value;
     this.type = type;
 
@@ -141,6 +142,8 @@ Dish.prototype.get = function(type) {
  * @param {number} toType - The data type of value, see Dish enums.
  */
 Dish.prototype.translate = function(toType) {
+    log.debug(`Translating Dish from ${Dish.enumLookup(this.type)} to ${Dish.enumLookup(toType)}`);
+
     // Convert data to intermediate byteArray type
     switch (this.type) {
         case Dish.STRING:

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}

src/core/Recipe.js

@@ -146,18 +146,23 @@ 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} ${JSON.stringify(op.getIngValues())}`);
         if (op.isDisabled()) {
+            log.debug("Operation is disabled, skipping");
             continue;
         }
         if (op.isBreakpoint()) {
+            log.debug("Pausing at breakpoint");
             return i;
         }
 
         try {
             input = dish.get(op.inputType);
+            log.debug("Executing operation");
 
             if (op.isFlowControl()) {
                 // Package up the current state
@@ -193,6 +198,7 @@ Recipe.prototype.execute = async function(dish, startFrom) {
         }
     }
 
+    log.debug("Recipe complete");
     return this.opList.length;
 };
 

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();
 };
 
@@ -91,7 +93,7 @@ App.prototype.loaded = function() {
  * @param {boolean} [logToConsole=false]
  */
 App.prototype.handleError = function(err, logToConsole) {
-    if (logToConsole) console.error(err);
+    if (logToConsole) log.error(err);
     const msg = err.displayStr || err.toString();
     this.alert(msg, "danger", this.options.errorTimeout, !this.options.showErrors);
 };
@@ -129,6 +131,7 @@ App.prototype.autoBake = function() {
     if (this.autoBakePause) return false;
 
     if (this.autoBake_ && !this.baking) {
+        log.debug("Auto-baking");
         this.bake();
     } else {
         this.manager.controls.showStaleIndicator();
@@ -569,7 +572,7 @@ App.prototype.isLocalStorageAvailable = function() {
 App.prototype.alert = function(str, style, timeout, silent) {
     const time = new Date();
 
-    console.log("[" + time.toLocaleString() + "] " + str);
+    log.info("[" + time.toLocaleString() + "] " + str);
     if (silent) return;
 
     style = style || "danger";

src/web/InputWaiter.js

@@ -215,6 +215,7 @@ InputWaiter.prototype.handleLoaderMessage = function(e) {
     }
 
     if (r.hasOwnProperty("fileBuffer")) {
+        log.debug("Input file loaded");
         this.fileBuffer = r.fileBuffer;
         window.dispatchEvent(this.manager.statechange);
     }

src/web/Manager.js

@@ -58,7 +58,7 @@ const Manager = function(app) {
     this.ops         = new OperationsWaiter(this.app, this);
     this.input       = new InputWaiter(this.app, this);
     this.output      = new OutputWaiter(this.app, this);
-    this.options     = new OptionsWaiter(this.app);
+    this.options     = new OptionsWaiter(this.app, this);
     this.highlighter = new HighlighterWaiter(this.app, this);
     this.seasonal    = new SeasonalWaiter(this.app, this);
     this.bindings    = new BindingsWaiter(this.app, this);
@@ -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);
@@ -172,6 +172,7 @@ Manager.prototype.initialiseEventListeners = function() {
     this.addDynamicListener(".option-item input[type=number]", "change", this.options.numberChange, this.options);
     this.addDynamicListener(".option-item select", "change", this.options.selectChange, this.options);
     document.getElementById("theme").addEventListener("change", this.options.themeChange.bind(this.options));
+    document.getElementById("logLevel").addEventListener("change", this.options.logLevelChange.bind(this.options));
 
     // Misc
     window.addEventListener("keydown", this.bindings.parseInput.bind(this.bindings));