feat: dump timing data for loader (#2521) (#2621)

Ref #1898

lib/egg.js

@@ -61,6 +61,7 @@ class EggApplication extends EggCore {
     this.ready(() => process.nextTick(() => {
       const dumpStartTime = Date.now();
       this.dumpConfig();
+      this.dumpTiming();
       this.coreLogger.info('[egg:core] dump config after ready, %s', ms(Date.now() - dumpStartTime));
     }));
     this._setupTimeoutTimer();
@@ -353,6 +354,17 @@ class EggApplication extends EggCore {
     }
   }
 
+  dumpTiming() {
+    try {
+      const json = this.timing.toJSON();
+      const rundir = this.config.rundir;
+      const dumpFile = path.join(rundir, `${this.type}_timing_${process.pid}.json`);
+      fs.writeFileSync(dumpFile, CircularJSON.stringify(json, null, 2));
+    } catch (err) {
+      this.coreLogger.warn(`dumpTiming error: ${err.message}`);
+    }
+  }
+
   get [EGG_PATH]() {
     return path.join(__dirname, '..');
   }

test/lib/egg.test.js

@@ -109,6 +109,29 @@ describe('test/lib/egg.test.js', () => {
       assert(/\[egg:core] dump config after load, \d+ms/.test(content));
       assert(/\[egg:core] dump config after ready, \d+ms/.test(content));
     });
+
+    it('should read timing data', function* () {
+      let json = readJson(path.join(baseDir, `run/agent_timing_${process.pid}.json`));
+      assert(json.length === 31);
+      assert(json[0].name === 'Application Start');
+      assert(json[0].pid === process.pid);
+
+      json = readJson(path.join(baseDir, `run/application_timing_${process.pid}.json`));
+      assert(json.length === 62);
+      assert(json[0].name === 'Application Start');
+      assert(json[0].pid === process.pid);
+    });
+
+    it('should ignore error when dumpTiming', done => {
+      mm(fs, 'writeFileSync', () => {
+        throw new Error('mock error');
+      });
+      mm(app.coreLogger, 'warn', msg => {
+        assert(msg === 'dumpTiming error: mock error');
+        done();
+      });
+      app.dumpTiming();
+    });
   });
 
   describe('dumpConfig() dynamically', () => {