add better internal logging for requeests & actions

packages/embark-deploy-tracker/package.json

@@ -48,7 +48,8 @@
   },
   "dependencies": {
     "embark-utils": "^4.1.0-beta.5",
-    "fs-extra": "7.0.1"
+    "fs-extra": "7.0.1",
+    "web3": "1.0.0-beta.37"
   },
   "devDependencies": {
     "eslint": "5.7.0",

packages/embark-deploy-tracker/src/index.js

@@ -1,127 +1,127 @@
 import { __ } from 'embark-i18n';
 import { dappPath, sha3 } from 'embark-utils';
-import * as fs from 'fs-extra';
+const Web3 = require('web3');
 
 class DeployTracker {
 
   constructor(embark, options) {
     this.logger = embark.logger;
     this.events = embark.events;
+    this.plugins = options.plugins;
+    this.fs = embark.fs;
     this.embark = embark;
     this.trackContracts = (options.trackContracts !== false);
 
-    // TODO: unclear where it comes from
+    // TODO: unclear where env comes from
+    // TODO: we should be getting the env from a request to the config
     this.env = options.env;
     this.chainConfig = {};
     this.chainFile = embark.config.contractsConfig.tracking;
-    // this.loadChainTrackerFile();
-    // this.registerEvents();
+
+    this.events.on("blockchain:started", this.loadChainTrackerFile.bind(this));
+    this.embark.registerActionForEvent('deployment:deployContracts:beforeAll', this.setCurrentChain.bind(this));
+    // this.embark.registerActionForEvent("deployment:contract:deployed", this.trackAndSaveContract.bind(this));
+    // this.embark.registerActionForEvent("deploy:contract:shouldDeploy", this.checkIfDeploymentIsNeeded.bind(this));
+  }
+
+  trackAndSaveContract(params, cb) {
+    if (!this.embark.config.contractsConfig.tracking) return;
+    let contract = params.contract;
+    this.trackContract(contract.className, contract.realRuntimeBytecode, contract.realArgs, contract.deployedAddress);
+    this.save();
+  }
+
+  checkIfDeploymentIsNeeded(params, cb) {
+    if (!this.embark.config.contractsConfig.tracking) return;
+    if (!this.trackContracts) {
+      return cb(null, params);
+    }
+
+    let contract = params.contract;
+    let trackedContract = this.getContract(contract.className, contract.realRuntimeBytecode, contract.realArgs);
+    if (trackedContract) {
+      params.contract.address = trackedContract.address;
+    }
+    if (params.shouldDeploy && trackedContract) {
+      params.shouldDeploy = true;
+    }
+    cb(null, params);
   }
 
   loadChainTrackerFile() {
     if (this.chainFile === false) return;
     if (this.chainFile === undefined) this.chainFile = ".embark/chains.json";
     this.chainFile = dappPath(this.chainFile);
-    if (!fs.existsSync(this.chainFile)) {
+    if (!this.fs.existsSync(this.chainFile)) {
       this.logger.info(this.chainFile + ' ' + __('file not found, creating it...'));
-      fs.outputJSONSync(this.chainFile, {});
+      this.fs.outputJSONSync(this.chainFile, {});
     }
 
-    this.chainConfig = fs.readJSONSync(this.chainFile);
+    this.chainConfig = this.fs.readJSONSync(this.chainFile);
   }
 
-  registerEvents() {
+  setCurrentChain(_params, callback) {
+    if (!this.embark.config.contractsConfig.tracking) return;
     if (this.chainFile === false) return;
-    const self = this;
-
-    // TODO: re-add
-    // this.embark.registerActionForEvent("deploy:beforeAll", this.setCurrentChain.bind(this));
-
-    this.events.on("deploy:contract:deployed", (contract) => {
-      self.trackContract(contract.className, contract.realRuntimeBytecode, contract.realArgs, contract.deployedAddress);
-      self.save();
-    });
-
-    self.embark.registerActionForEvent("deploy:contract:shouldDeploy", (params, cb) => {
-      if (!self.trackContracts) {
-        return cb(null, params);
-      }
-
-      let contract = params.contract;
-      let trackedContract = self.getContract(contract.className, contract.realRuntimeBytecode, contract.realArgs);
-      if (trackedContract) {
-        params.contract.address = trackedContract.address;
-      }
-      if (params.shouldDeploy && trackedContract) {
-         params.shouldDeploy = true;
-      }
-      cb(null, params);
-    });
-  }
-
-  setCurrentChain(callback) {
-    const self = this;
     if (this.chainConfig === false) {
       this.currentChain = {contracts: []};
       return callback();
     }
 
-    function getBlock(blockNum, cb) {
-      self.events.request("blockchain:block:byNumber", blockNum, (err, block) => {
-        if (err) {
-          return cb(err);
-        }
-        let chainId = block.hash;
-
-        if (self.chainConfig[chainId] === undefined) {
-          self.chainConfig[chainId] = {contracts: {}};
-        }
-
-        self.currentChain = self.chainConfig[chainId];
-
-        self.currentChain.name = self.env;
-        cb();
-      });
-    }
-
-    getBlock(0, (err) => {
+    this.getBlock(0, (err) => {
       if (err) {
         // Retry with block 1 (Block 0 fails with Ganache-cli using the --fork option)
-        return getBlock(1, callback);
+        return this.getBlock(1, callback);
       }
       callback();
     });
   }
 
+  async getBlock(blockNum, cb) {
+    let provider = await this.events.request2("blockchain:client:provider", "ethereum");
+    var web3 = new Web3(provider);
+
+    try {
+      let block = await web3.eth.getBlock(blockNum, true);
+      let chainId = block.hash;
+
+      if (self.chainConfig[chainId] === undefined) {
+        self.chainConfig[chainId] = { contracts: {} };
+      }
+
+      self.currentChain = self.chainConfig[chainId];
+
+      self.currentChain.name = self.env;
+      cb();
+    } catch (err) {
+      return cb(err);
+    }
+  }
+
   loadConfig(config) {
     this.chainConfig = config;
     return this;
   }
 
-  trackContract(contractName, code, args, address) {
+  trackContract(name, code, args, address) {
     if (!this.currentChain) return false;
-    this.currentChain.contracts[sha3(code + contractName + args.join(','))] = {
-      name: contractName,
-      address: address
-    };
+    this.currentChain.contracts[sha3(code + name + args.join(','))] = { name, address };
   }
 
-  getContract(contractName, code, args) {
+  getContract(name, code, args) {
     if (!this.currentChain) return false;
-    let contract = this.currentChain.contracts[sha3(code + contractName + args.join(','))];
+    let contract = this.currentChain.contracts[sha3(code + name + args.join(','))];
     if (contract && contract.address === undefined) {
       return false;
     }
     return contract;
   }
 
-  // TODO: abstract this
-  // chainConfig can be an abstract PersistentObject
   save() {
     if (this.chainConfig === false) {
       return;
     }
-    fs.writeJSONSync(this.chainFile, this.chainConfig, {spaces: 2});
+    this.fs.writeJSONSync(this.chainFile, this.chainConfig, {spaces: 2});
   }
 
 }

packages/embark/src/cmd/cmd_controller.js

@@ -174,8 +174,7 @@ class EmbarkController {
         engine.registerModuleGroup("filewatcher");
         engine.registerModuleGroup("storage");
         engine.registerModuleGroup("communication");
-        engine.registerModulePackage('embark-deploy-tracker');
-
+        engine.registerModulePackage('embark-deploy-tracker', {plugins: engine.plugins});
 
         engine.events.on('deployment:deployContracts:afterAll', () => {
           console.dir("--- generating files...")

packages/embark/src/lib/core/events.js

@@ -2,6 +2,8 @@ import { __ } from 'embark-i18n';
 var EventEmitter = require('events');
 const cloneDeep = require('lodash.clonedeep');
 
+const fs = require('fs-extra');
+
 function warnIfLegacy(eventName) {
   const legacyEvents = [];
   if (legacyEvents.indexOf(eventName) >= 0) {
@@ -9,15 +11,41 @@ function warnIfLegacy(eventName) {
   }
 }
 
-function log(eventType, eventName) {
+function getOrigin() {
+  let origin = ((new Error().stack).split("at ")[3]).trim();
+  origin = origin.split("(")[0].trim();
+  return origin;
+}
+
+function log(eventType, eventName, origin) {
+  if (!(process && process.env && process.env.DEBUGEVENTS)) return;
   if (['end', 'prefinish', 'error', 'new', 'demo', 'block', 'version'].indexOf(eventName) >= 0) {
     return;
   }
   if (eventType.indexOf("log") >= 0) {
     return;
   }
+  // fs.appendFileSync(".embark/events.log", (new Error().stack) + "\n");
+  if (!origin && origin !== "") {
+    origin = ((new Error().stack).split("at ")[3]).trim();
+    origin = origin.split("(")[0].trim();
+    // origin = getOrigin();
+  }
+
+  fs.appendFileSync(".embark/events.log", eventType + ": " + eventName + " -- (" + origin + ")\n");
 }
 
+const cmdNames = {};
+
+function trackCmd(cmdName) {
+  if (!(process && process.env && process.env.DEBUGEVENTS)) return;
+  let origin = ((new Error().stack).split("at ")[3]).trim();
+  origin = origin.split("(")[0].trim();
+  cmdNames[cmdName] = origin;
+}
+
+EventEmitter.prototype.log  = log;
+
 EventEmitter.prototype._maxListeners = 350;
 const _on         = EventEmitter.prototype.on;
 const _once       = EventEmitter.prototype.once;
@@ -32,50 +60,32 @@ EventEmitter.prototype.removeAllListeners = function(requestName) {
 };
 
 EventEmitter.prototype.on = function(requestName, cb) {
-  log("listening to event: ", requestName);
+  // log("EVENT LISTEN", requestName);
   warnIfLegacy(requestName);
   return _on.call(this, requestName, cb);
 };
 
 EventEmitter.prototype.once = function(requestName, cb) {
-  log("listening to event (once): ", requestName);
+  // log("EVENT LISTEN ONCE", requestName);
   warnIfLegacy(requestName);
   return _once.call(this, requestName, cb);
 };
 
 EventEmitter.prototype.setHandler = function(requestName, cb) {
-  log("setting handler for: ", requestName);
+  log("SET HANDLER", requestName);
   warnIfLegacy(requestName);
   return _setHandler.call(this, requestName, cb);
 };
 
-EventEmitter.prototype.get = function() {
-  let requestName = arguments[0];
-  let other_args = [].slice.call(arguments, 1);
-
-   log("get: ", requestName);
-  warnIfLegacy(requestName);
-  const listenerName = 'get:' + requestName;
-
-  let promise = new Promise((resolve, reject) => {
-    return this.emit(listenerName, ...other_args, (err, res) => {
-      if (err) return reject(err);
-      return resolve(res);
-    })
-  });
-
-   return promise;
-};
-
 EventEmitter.prototype.request2 = function() {
   let requestName = arguments[0];
   let other_args = [].slice.call(arguments, 1);
 
-  log("requesting: ", requestName);
+  log("\nREQUEST", requestName);
   console.log("requesting: " + requestName);
   warnIfLegacy(requestName);
   if (this._events && !this._events['request:' + requestName]) {
-    log("made request without listener: " + requestName)
+    log("NO REQUEST LISTENER", requestName)
     console.log("made request without listener: " + requestName)
     console.trace();
   }
@@ -106,11 +116,11 @@ EventEmitter.prototype.request = function() {
   let requestName = arguments[0];
   let other_args = [].slice.call(arguments, 1);
 
-  log("requesting: ", requestName);
+  log("\nREQUEST(OLD)", requestName);
   console.log("requesting: " + requestName);
   warnIfLegacy(requestName);
   if (this._events && !this._events['request:' + requestName]) {
-    log("made request without listener: " + requestName)
+    log("NO REQUEST LISTENER", requestName)
     console.log("made request without listener: " + requestName)
     console.trace();
   }
@@ -131,9 +141,22 @@ EventEmitter.prototype.request = function() {
   return this.emit(listenerName, ...other_args);
 };
 
+// TODO: ensure that it's only possible to create 1 command handler
 EventEmitter.prototype.setCommandHandler = function(requestName, cb) {
-  log("setting command handler for: " + requestName);
+  log("SET COMMAND HANDLER", requestName);
+
+  // let origin = ((new Error().stack).split("at ")[3]).trim();
+  // origin = origin.split("(")[0].trim();
+  let origin = getOrigin();
+
   let listener = function(_cb) {
+    log("== REQUEST RESPONSE", requestName, origin);
+    console.dir(requestName)
+    // console.dir(cb)
+    // console.dir(Object.getOwnPropertyNames(cb))
+    // console.dir(cb.length)
+   // console.dir(Object.values(cb))
+    // process.exit(0)
     cb.call(this, ...arguments);
   };
   const listenerName = 'request:' + requestName;
@@ -141,6 +164,7 @@ EventEmitter.prototype.setCommandHandler = function(requestName, cb) {
   // unlike events, commands can only have 1 handler
   _removeAllListeners.call(this, listenerName);
 
+  // TODO: remove this, it will lead to illusion of things working when this situatio shouldnt' hapepn in the first place
   // if this event was requested prior to the command handler
   // being set up,
   // 1. delete the premature request(s) from the toFire array so they are not fired again
@@ -161,7 +185,7 @@ EventEmitter.prototype.setCommandHandler = function(requestName, cb) {
 };
 
 EventEmitter.prototype.setCommandHandlerOnce = function(requestName, cb) {
-  log("setting command handler for: ", requestName);
+  log("SET COMMAND HANDLER ONCE", requestName);
 
   const listenerName = 'request:' + requestName;
 

packages/embark/src/lib/core/plugins.js

@@ -161,18 +161,68 @@ Plugins.prototype.getPluginsProperty = function(pluginType, property, sub_proper
   return matchingProperties.reduce((a,b) => { return a.concat(b); }) || [];
 };
 
+Plugins.prototype.getPluginsPropertyAndPluginName = function(pluginType, property, sub_property) {
+  let matchingPlugins = this.plugins.filter(function(plugin) {
+    return plugin.has(pluginType);
+  });
+
+  // Sort internal plugins first
+  matchingPlugins.sort((a, b) => {
+    if (a.isInternal) {
+      return -1;
+    }
+    if (b.isInternal) {
+      return 1;
+    }
+    return 0;
+  });
+
+  let matchingProperties = []
+  matchingPlugins.map((plugin) => {
+    if (sub_property) {
+      let newList = []
+      for (let kall of (plugin[property][sub_property] || [])) {
+        matchingProperties.push([kall, plugin.name])
+      }
+      return newList;
+    }
+
+    let newList = []
+    for (let kall of (plugin[property] || [])) {
+      matchingProperties.push([kall, plugin.name])
+    }
+    return newList;
+  });
+
+  // Remove empty properties
+  matchingProperties = matchingProperties.filter((property) => property[0]);
+
+  //return flattened list
+  if (matchingProperties.length === 0) return [];
+  // return matchingProperties.reduce((a,b) => { return a.concat(b); }) || [];
+  return matchingProperties;
+};
+
+
 // TODO: because this is potentially hanging, we should issue a trace warning if the event does not exists
 Plugins.prototype.runActionsForEvent = function(eventName, args, cb) {
+  const self = this;
   if (typeof (args) === 'function') {
     cb = args;
   }
-  let actionPlugins = this.getPluginsProperty('eventActions', 'eventActions', eventName);
+  let actionPlugins = this.getPluginsPropertyAndPluginName('eventActions', 'eventActions', eventName);
 
   if (actionPlugins.length === 0) {
     return cb(null, args);
   }
 
-  async.reduce(actionPlugins, args, function(current_args, plugin, nextEach) {
+  this.events.log("ACTION", eventName, "");
+
+  async.reduce(actionPlugins, args, function(current_args, pluginObj, nextEach) {
+    const [plugin, pluginName] = pluginObj;
+
+    self.events.log("== ACTION FOR " + eventName, plugin.name, pluginName);
+
     if (typeof (args) === 'function') {
       plugin.call(plugin, (...params) => {
         nextEach(...params || current_args);