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-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",
@@ -6132,8 +6151,16 @@
     "loglevel": {
       "version": "1.6.0",
       "resolved": "https://registry.npmjs.org/loglevel/-/loglevel-1.6.0.tgz",
-      "integrity": "sha1-rgyqVhERSYxboTcj1vtjHSQAOTQ=",
-      "dev": true
+      "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",

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));

src/web/OptionsWaiter.js

@@ -8,8 +8,9 @@
  * @constructor
  * @param {App} app - The main view object for CyberChef.
  */
-const OptionsWaiter = function(app) {
+const OptionsWaiter = function(app, manager) {
     this.app = app;
+    this.manager = manager;
 };
 
 
@@ -86,6 +87,7 @@ OptionsWaiter.prototype.switchChange = function(e, state) {
     const el = e.target;
     const option = el.getAttribute("option");
 
+    log.debug(`Setting ${option} to ${state}`);
     this.app.options[option] = state;
 
     if (this.app.isLocalStorageAvailable())
@@ -102,8 +104,10 @@ OptionsWaiter.prototype.switchChange = function(e, state) {
 OptionsWaiter.prototype.numberChange = function(e) {
     const el = e.target;
     const option = el.getAttribute("option");
+    const val = parseInt(el.value, 10);
 
-    this.app.options[option] = parseInt(el.value, 10);
+    log.debug(`Setting ${option} to ${val}`);
+    this.app.options[option] = val;
 
     if (this.app.isLocalStorageAvailable())
         localStorage.setItem("options", JSON.stringify(this.app.options));
@@ -120,6 +124,7 @@ OptionsWaiter.prototype.selectChange = function(e) {
     const el = e.target;
     const option = el.getAttribute("option");
 
+    log.debug(`Setting ${option} to ${el.value}`);
     this.app.options[option] = el.value;
 
     if (this.app.isLocalStorageAvailable())
@@ -149,6 +154,8 @@ OptionsWaiter.prototype.setWordWrap = function() {
 
 /**
  * Changes the theme by setting the class of the <html> element.
+ * 
+ * @param {Event} e
  */
 OptionsWaiter.prototype.themeChange = function (e) {
     const themeClass = e.target.value;
@@ -156,4 +163,16 @@ OptionsWaiter.prototype.themeChange = function (e) {
     document.querySelector(":root").className = themeClass;
 };
 
+
+/**
+ * Changes the console logging level.
+ * 
+ * @param {Event} e
+ */
+OptionsWaiter.prototype.logLevelChange = function (e) {
+    const level = e.target.value;
+    log.setLevel(level, false);
+    this.manager.worker.setLogLevel();
+};
+
 export default OptionsWaiter;

src/web/OutputWaiter.js

@@ -41,6 +41,7 @@ OutputWaiter.prototype.get = function() {
  * @param {boolean} [preserveBuffer=false] - Whether to preserve the dishBuffer
  */
 OutputWaiter.prototype.set = function(data, type, duration, preserveBuffer) {
+    log.debug("Output type: " + type);
     const outputText = document.getElementById("output-text");
     const outputHtml = document.getElementById("output-html");
     const outputFile = document.getElementById("output-file");
@@ -73,7 +74,7 @@ OutputWaiter.prototype.set = function(data, type, duration, preserveBuffer) {
                 try {
                     eval(scriptElements[i].innerHTML); // eslint-disable-line no-eval
                 } catch (err) {
-                    console.error(err);
+                    log.error(err);
                 }
             }
             break;

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);
 };
 

src/web/WorkerWaiter.js

@@ -21,8 +21,10 @@ const WorkerWaiter = function(app, manager) {
  * Sets up the ChefWorker and associated listeners.
  */
 WorkerWaiter.prototype.registerChefWorker = function() {
+    log.debug("Registering new ChefWorker");
     this.chefWorker = new ChefWorker();
     this.chefWorker.addEventListener("message", this.handleChefMessage.bind(this));
+    this.setLogLevel();
 
     let docURL = document.location.href.split(/[#?]/)[0];
     const index = docURL.lastIndexOf("/");
@@ -40,8 +42,10 @@ WorkerWaiter.prototype.registerChefWorker = function() {
  */
 WorkerWaiter.prototype.handleChefMessage = function(e) {
     const r = e.data;
+    log.debug("Receiving '" + r.action + "' from ChefWorker");
+
     switch (r.action) {
-        case "bakeSuccess":
+        case "bakeComplete":
             this.bakingComplete(r.data);
             break;
         case "bakeError":
@@ -52,12 +56,14 @@ WorkerWaiter.prototype.handleChefMessage = function(e) {
             break;
         case "workerLoaded":
             this.app.workerLoaded = true;
+            log.debug("ChefWorker loaded");
             this.app.loaded();
             break;
         case "statusMessage":
             this.manager.output.setStatusMsg(r.data);
             break;
         case "optionUpdate":
+            log.debug(`Setting ${r.data.option} to ${r.data.value}`);
             this.app.options[r.data.option] = r.data.value;
             break;
         case "setRegisters":
@@ -67,7 +73,7 @@ WorkerWaiter.prototype.handleChefMessage = function(e) {
             this.manager.highlighter.displayHighlights(r.data.pos, r.data.direction);
             break;
         default:
-            console.error("Unrecognised message from ChefWorker", e);
+            log.error("Unrecognised message from ChefWorker", e);
             break;
     }
 };
@@ -113,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 ---");
 };
 
 
@@ -145,7 +152,7 @@ WorkerWaiter.prototype.bake = function(input, recipeConfig, options, progress, s
  * Asks the ChefWorker to run a silent bake, forcing the browser to load and cache all the relevant
  * JavaScript code needed to do a real bake.
  *
- * @param {Objectp[]} [recipeConfig]
+ * @param {Object[]} [recipeConfig]
  */
 WorkerWaiter.prototype.silentBake = function(recipeConfig) {
     this.chefWorker.postMessage({
@@ -178,4 +185,19 @@ WorkerWaiter.prototype.highlight = function(recipeConfig, direction, pos) {
 };
 
 
+/**
+ * Sets the console log level in the worker.
+ *
+ * @param {string} level
+ */
+WorkerWaiter.prototype.setLogLevel = function(level) {
+    if (!this.chefWorker) return;
+
+    this.chefWorker.postMessage({
+        action: "setLogLevel",
+        data: log.getLevel()
+    });
+};
+
+
 export default WorkerWaiter;

src/web/html/index.html

@@ -372,6 +372,17 @@
                             <input type="number" option="outputFileThreshold" id="outputFileThreshold" />
                             <label for="outputFileThreshold"> Size threshold for treating the output as a file (KiB)</label>
                         </div>
+                        <div class="option-item">
+                            <select option="logLevel" id="logLevel">
+                                <option value="silent">Silent</option>
+                                <option value="error">Error</option>
+                                <option value="warn">Warn</option>
+                                <option value="info">Info</option>
+                                <option value="debug">Debug</option>
+                                <option value="trace">Trace</option>
+                            </select>
+                            <label for="logLevel"> Console logging level</label>
+                        </div>
                     </div>
                     <div class="modal-footer">
                         <button type="button" class="btn btn-default" id="reset-options">Reset options to default</button>

src/web/index.js

@@ -47,7 +47,8 @@ function main() {
         attemptHighlight:    true,
         theme:               "classic",
         useMetaKey:          false,
-        outputFileThreshold: 1024
+        outputFileThreshold: 1024,
+        logLevel:            "info"
     };
 
     document.removeEventListener("DOMContentLoaded", main, false);
@@ -55,9 +56,6 @@ function main() {
     window.app.setup();
 }
 
-// Fix issues with browsers that don't support console.log()
-window.console = console || {log: function() {}, error: function() {}};
-
 window.compileTime = moment.tz(COMPILE_TIME, "DD/MM/YYYY HH:mm:ss z", "UTC").valueOf();
 window.compileMessage = COMPILE_MSG;
 

test/index.js

@@ -1,3 +1,5 @@
+/* eslint no-console: 0 */
+
 /**
  * TestRunner.js
  *

webpack.config.js

@@ -35,7 +35,8 @@ module.exports = {
         new webpack.ProvidePlugin({
             $: "jquery",
             jQuery: "jquery",
-            moment: "moment-timezone"
+            moment: "moment-timezone",
+            log: "loglevel"
         }),
         new webpack.BannerPlugin({
             banner: banner,