feat: pick commit from 3.x (#166)

* feat: add timing data for loader (#160)
* refactor: add timing to extend (#162)
* fix: Loader can be instantiated without timing (#161)
* fix: convert symbol to string (#163)
* fix: timing can be started multiple times (#164)

Author: popomore

.eslintignore

@@ -2,4 +2,4 @@ node_modules
 coverage
 benchmark
 fixtures
-.vscode
+.vscode

.gitignore

@@ -4,4 +4,5 @@ coverage
 npm-debug.log
 .vscode
 .DS_Store
-yarn.lock
+yarn.lock
+test/fixtures/egg/node_modules/egg-core

.travis.yml

@@ -2,7 +2,7 @@ sudo: false
 language: node_js
 node_js:
   - '8'
-  - '9'
+  - '10'
 install:
   - npm i npminstall && npminstall
 script:

appveyor.yml

@@ -1,7 +1,7 @@
 environment:
   matrix:
     - nodejs_version: '8'
-    - nodejs_version: '9'
+    - nodejs_version: '10'
 
 install:
   - ps: Install-Product node $env:nodejs_version

lib/egg.js

@@ -10,7 +10,7 @@ const co = require('co');
 const BaseContextClass = require('./utils/base_context_class');
 const utils = require('./utils');
 const Router = require('./utils/router');
-
+const Timing = require('./utils/timing');
 
 const DEPRECATE = Symbol('EggCore#deprecate');
 const CLOSESET = Symbol('EggCore#closeSet');
@@ -19,7 +19,7 @@ const CLOSE_PROMISE = Symbol('EggCore#closePromise');
 const ROUTER = Symbol('EggCore#router');
 const EGG_LOADER = Symbol.for('egg#loader');
 const INIT_READY = Symbol('EggCore#initReady');
-const EGG_READY_TIMEOUT_ENV = Symbol('EggCore#eggReadyTimeoutEnv');
+
 
 class EggCore extends KoaApplication {
 
@@ -43,16 +43,17 @@ class EggCore extends KoaApplication {
 
     super();
 
+    this.timing = new Timing();
+
     // register a close set
     this[CLOSESET] = new Set();
     // cache deprecate object by file
     this[DEPRECATE] = new Map();
 
-    // get app timeout from env or use default timeout 10 second
-    const eggReadyTimeoutEnv = process.env.EGG_READY_TIMEOUT_ENV;
-    this[EGG_READY_TIMEOUT_ENV] = Number.parseInt(eggReadyTimeoutEnv || 10000);
+    this[INIT_READY]();
 
-    assert(Number.isInteger(this[EGG_READY_TIMEOUT_ENV]), `process.env.EGG_READY_TIMEOUT_ENV ${eggReadyTimeoutEnv} should be able to parseInt.`);
+    this.timing.start('Application Start');
+    this.ready(() => this.timing.end('Application Start'));
 
     /**
      * @member {Object} EggCore#options
@@ -124,8 +125,6 @@ class EggCore extends KoaApplication {
       logger: this.console,
       serverScope: options.serverScope,
     });
-
-    this[INIT_READY]();
   }
 
   /**
@@ -216,16 +215,26 @@ class EggCore extends KoaApplication {
 
     // get filename from stack
     const name = utils.getCalleeFromStack(true);
+    const timingkey = 'Before Start in ' + utils.getResolvedFilename(name, this.options.baseDir);
+
+    this.timing.start(timingkey);
+
     const done = this.readyCallback(name);
 
     // ensure scope executes after load completed
     process.nextTick(() => {
-      utils.callFn(scope).then(() => done(), done);
+      utils.callFn(scope).then(() => {
+        done();
+        this.timing.end(timingkey);
+      }, err => {
+        done(err);
+        this.timing.end(timingkey);
+      });
     });
   }
 
   /**
-   * Close all, it will close
+   * Close all, it wisll close
    * - callbacks registered by beforeClose
    * - emit `close` event
    * - remove add listeners
@@ -281,6 +290,10 @@ class EggCore extends KoaApplication {
      * });
      */
 
+    // get app timeout from env or use default timeout 10 second
+    const eggReadyTimeoutEnv = Number.parseInt(process.env.EGG_READY_TIMEOUT_ENV || 10000);
+    assert(Number.isInteger(eggReadyTimeoutEnv), `process.env.EGG_READY_TIMEOUT_ENV ${process.env.EGG_READY_TIMEOUT_ENV} should be able to parseInt.`);
+
     /**
      * If a client starts asynchronously, you can register `readyCallback`,
      * then the application will wait for the callback to ready
@@ -294,15 +307,13 @@ class EggCore extends KoaApplication {
      * const done = app.readyCallback('mysql');
      * mysql.ready(done);
      */
-    require('ready-callback')({ timeout: this[EGG_READY_TIMEOUT_ENV] }).mixin(this);
+    require('ready-callback')({ timeout: eggReadyTimeoutEnv }).mixin(this);
 
     this.on('ready_stat', data => {
       this.console.info('[egg:core:ready_stat] end ready task %s, remain %j', data.id, data.remain);
     }).on('ready_timeout', id => {
-      this.console.warn('[egg:core:ready_timeout] %s seconds later %s was still unable to finish.', this[EGG_READY_TIMEOUT_ENV] / 1000, id);
+      this.console.warn('[egg:core:ready_timeout] %s seconds later %s was still unable to finish.', eggReadyTimeoutEnv / 1000, id);
     });
-
-    this.ready(() => debug('egg emit ready, application started'));
   }
 
   /**

lib/loader/egg_loader.js

@@ -10,6 +10,9 @@ const FileLoader = require('./file_loader');
 const ContextLoader = require('./context_loader');
 const utility = require('utility');
 const utils = require('../utils');
+const Timing = require('../utils/timing');
+
+const REQUIRE_COUNT = Symbol('EggLoader#requireCount');
 
 
 class EggLoader {
@@ -30,6 +33,8 @@ class EggLoader {
     assert(this.options.logger, 'options.logger is required');
 
     this.app = this.options.app;
+    this.timing = this.app.timing || new Timing();
+    this[REQUIRE_COUNT] = 0;
 
     /**
      * @member {Object} EggLoader#pkg
@@ -286,10 +291,25 @@ class EggLoader {
       return null;
     }
 
-    const ret = utils.loadFile(filepath);
     // function(arg1, args, ...) {}
     if (inject.length === 0) inject = [ this.app ];
-    return isFunction(ret) ? ret(...inject) : ret;
+
+    let ret = this.requireFile(filepath);
+    ret = isFunction(ret) ? ret(...inject) : ret;
+    return ret;
+  }
+
+  /**
+   * @param {String} filepath - fullpath
+   * @return {Object} exports
+   * @private
+   */
+  requireFile(filepath) {
+    const timingKey = `Require(${this[REQUIRE_COUNT]++}) ${utils.getResolvedFilename(filepath, this.options.baseDir)}`;
+    this.timing.start(timingKey);
+    const ret = utils.loadFile(filepath);
+    this.timing.end(timingKey);
+    return ret;
   }
 
   /**
@@ -355,7 +375,11 @@ class EggLoader {
       target,
       inject: this.app,
     }, opt);
+
+    const timingKey = `Load "${String(property)}" to Application`;
+    this.timing.start(timingKey);
     new FileLoader(opt).load();
+    this.timing.end(timingKey);
   }
 
   /**
@@ -371,7 +395,11 @@ class EggLoader {
       property,
       inject: this.app,
     }, opt);
+
+    const timingKey = `Load "${String(property)}" to Context`;
+    this.timing.start(timingKey);
     new ContextLoader(opt).load();
+    this.timing.end(timingKey);
   }
 
   /**

lib/loader/mixin/config.js

@@ -5,6 +5,7 @@ const path = require('path');
 const extend = require('extend2');
 const assert = require('assert');
 
+
 const SET_CONFIG_META = Symbol('Loader#setConfigMeta');
 
 module.exports = {
@@ -18,6 +19,7 @@ module.exports = {
    * @since 1.0.0
    */
   loadConfig() {
+    this.timing.start('Load Config');
     this.configMeta = {};
 
     const target = {};
@@ -50,6 +52,7 @@ module.exports = {
     target.appMiddleware = target.appMiddlewares = target.middleware || [];
 
     this.config = target;
+    this.timing.end('Load Config');
   },
 
   _preloadAppConfig() {

lib/loader/mixin/controller.js

@@ -6,6 +6,7 @@ const utility = require('utility');
 const utils = require('../../utils');
 const FULLPATH = require('../file_loader').FULLPATH;
 
+
 module.exports = {
 
   /**
@@ -14,6 +15,7 @@ module.exports = {
    * @since 1.0.0
    */
   loadController(opt) {
+    this.timing.start('Load Controller');
     opt = Object.assign({
       caseStyle: 'lower',
       directory: path.join(this.options.baseDir, 'app/controller'),
@@ -46,6 +48,7 @@ module.exports = {
 
     this.loadToApp(controllerBase, 'controller', opt);
     this.options.logger.info('[egg:loader] Controller loaded: %s', controllerBase);
+    this.timing.end('Load Controller');
   },
 
 };

lib/loader/mixin/custom.js

@@ -2,6 +2,7 @@
 
 const path = require('path');
 
+
 module.exports = {
 
   /**
@@ -21,16 +22,20 @@ module.exports = {
    * @since 1.0.0
    */
   loadCustomApp() {
+    this.timing.start('Load app.js');
     this.getLoadUnits()
       .forEach(unit => this.loadFile(this.resolveModule(path.join(unit.path, 'app'))));
+    this.timing.end('Load app.js');
   },
 
   /**
    * Load agent.js, same as {@link EggLoader#loadCustomApp}
    */
   loadCustomAgent() {
+    this.timing.start('Load agent.js');
     this.getLoadUnits()
       .forEach(unit => this.loadFile(this.resolveModule(path.join(unit.path, 'agent'))));
+    this.timing.end('Load agent.js');
   },
 
 };

lib/loader/mixin/extend.js

@@ -89,6 +89,7 @@ module.exports = {
    * @since 1.0.0
    */
   loadExtend(name, proto) {
+    this.timing.start(`Load extend/${name}.js`);
     // All extend files
     const filepaths = this.getExtendFilePaths(name);
     // if use mm.env and serverEnv is not unittest
@@ -109,7 +110,7 @@ module.exports = {
         deprecate(`app/extend/${name}/index.js is deprecated, use app/extend/${name}.js instead`);
       }
 
-      const ext = this.loadFile(filepath);
+      const ext = this.requireFile(filepath);
 
       const properties = Object.getOwnPropertyNames(ext)
         .concat(Object.getOwnPropertySymbols(ext));
@@ -145,5 +146,6 @@ module.exports = {
       }
       debug('merge %j to %s from %s', Object.keys(ext), name, filepath);
     }
+    this.timing.end(`Load extend/${name}.js`);
   },
 };