[RFC ...] elapsed time in progress reporters - WIP FOR DISCUSSION

packages/core/src/reporters/ProgressAppendOnlyReporter.ts

@@ -20,7 +20,7 @@ export default class ProgressAppendOnlyReporter extends ProgressKeeper {
 
   private render() {
     process.stdout.write(
-      `Mutation testing ${this.getPercentDone()} (ETC ${this.getEtc()}) ` +
+      `Mutation testing ${this.getPercentDone()} (elapsed: ${this.getElapsedTime()}) (remaining: ${this.getEtc()}) ` +
         `${this.progress.tested}/${this.progress.total} tested (${this.progress.survived} survived, ${this.progress.timedOut} timed out)` +
         os.EOL
     );

packages/core/src/reporters/ProgressKeeper.ts

@@ -32,32 +32,36 @@ abstract class ProgressKeeper implements Reporter {
     }
   }
 
+  protected getElapsedTime() {
+    const elapsedSeconds = this.timer.elapsedSeconds();
+
+    return this.formatTime(
+      // hours:
+      Math.floor(elapsedSeconds / 3600),
+      // minutes up to 2 decimal places:
+      Math.floor(((elapsedSeconds % 3600) * 100) / 60) / 100
+    );
+  }
+
   protected getEtc() {
     const totalSecondsLeft = Math.floor((this.timer.elapsedSeconds() / this.progress.tested) * (this.progress.total - this.progress.tested));
 
     if (isFinite(totalSecondsLeft) && totalSecondsLeft > 0) {
-      const hours = Math.floor(totalSecondsLeft / 3600);
-      const minutes = Math.floor((totalSecondsLeft / 60) % 60);
-      const seconds = Math.floor(totalSecondsLeft % 60);
-
-      return this.formatEtc(hours, minutes, seconds);
+      return this.formatTime(
+        // minutes up to 2 decimal places:
+        Math.floor(totalSecondsLeft / 3600),
+        // minutes up to 2 decimal places:
+        Math.floor(((totalSecondsLeft % 3600) * 100) / 60) / 100
+      );
     } else {
       return 'n/a';
     }
   }
 
-  private formatEtc(hours: number, minutes: number, seconds: number) {
-    let output;
-
-    if (hours > 0) {
-      output = `${hours}h, ${minutes}m, ${seconds}s`;
-    } else if (minutes > 0) {
-      output = `${minutes}m, ${seconds}s`;
-    } else {
-      output = `${seconds}s`;
-    }
-
-    return output;
+  private formatTime(hours: number, minutes: number) {
+    return hours > 0 // conditional time formatting
+      ? `${hours}h, ${minutes}m`
+      : `${minutes}m`;
   }
 }
 export default ProgressKeeper;

packages/core/src/reporters/ProgressReporter.ts

@@ -8,7 +8,8 @@ export default class ProgressBarReporter extends ProgressKeeper {
 
   public onAllMutantsMatchedWithTests(matchedMutants: readonly MatchedMutant[]): void {
     super.onAllMutantsMatchedWithTests(matchedMutants);
-    const progressBarContent = 'Mutation testing  [:bar] :percent (ETC :etc) :tested/:total tested (:survived survived, :timedOut timed out)';
+    const progressBarContent =
+      'Mutation testing  [:bar] :percent (elapsed: :et) (remaining: :etc) :tested/:total tested (:survived survived, :timedOut timed out)';
 
     this.progressBar = new ProgressBar(progressBarContent, {
       complete: '=',
@@ -23,7 +24,7 @@ export default class ProgressBarReporter extends ProgressKeeper {
     const ticksBefore = this.progress.tested;
     super.onMutantTested(result);
 
-    const progressBarContent = { ...this.progress, etc: this.getEtc() };
+    const progressBarContent = { ...this.progress, et: this.getElapsedTime(), etc: this.getEtc() };
 
     if (ticksBefore < this.progress.tested) {
       this.tick(progressBarContent);

packages/core/test/unit/reporters/ProgressAppendOnlyReporter.spec.ts

@@ -22,46 +22,56 @@ describe('ProgressAppendOnlyReporter', () => {
     sinon.stub(process.stdout, 'write');
   });
 
-  describe('onAllMutantsMatchedWithTests() with 2 mutant to test', () => {
+  describe('onAllMutantsMatchedWithTests() with 3 mutants to test', () => {
     beforeEach(() => {
-      sut.onAllMutantsMatchedWithTests([matchedMutant(1), matchedMutant(1)]);
+      sut.onAllMutantsMatchedWithTests([matchedMutant(1), matchedMutant(1), matchedMutant(1)]);
     });
 
     it('should not show show progress directly', () => {
       expect(process.stdout.write).to.not.have.been.called;
     });
 
-    it('should log zero progress after ten seconds without completed tests', () => {
+    it('should log correct info after ten seconds without completed tests', () => {
       sinon.clock.tick(TEN_SECONDS);
-      expect(process.stdout.write).to.have.been.calledWith('Mutation testing 0% (ETC n/a) ' + `0/2 tested (0 survived, 0 timed out)${os.EOL}`);
+      expect(process.stdout.write).to.have.been.calledWith(
+        `Mutation testing 0% (elapsed: 0.16m) (remaining: n/a) 0/3 tested (0 survived, 0 timed out)${os.EOL}`
+      );
     });
 
-    it('should log 50% with 10s ETC after ten seconds with 1 completed test', () => {
+    it('should log correct info after ten seconds with 1 completed test', () => {
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
       expect(process.stdout.write).to.not.have.been.called;
       sinon.clock.tick(TEN_SECONDS);
-      expect(process.stdout.write).to.have.been.calledWith(`Mutation testing 50% (ETC 10s) 1/2 tested (0 survived, 0 timed out)${os.EOL}`);
+      expect(process.stdout.write).to.have.been.calledWith(
+        `Mutation testing 33% (elapsed: 0.16m) (remaining: 0.33m) 1/3 tested (0 survived, 0 timed out)${os.EOL}`
+      );
     });
 
-    it('should log 50% with "1m, 40s" ETC after hundred seconds with 1 completed test', () => {
+    it('should log correct info after a hundred seconds with 1 completed test', () => {
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
       expect(process.stdout.write).to.not.have.been.called;
       sinon.clock.tick(HUNDRED_SECONDS);
-      expect(process.stdout.write).to.have.been.calledWith(`Mutation testing 50% (ETC 1m, 40s) 1/2 tested (0 survived, 0 timed out)${os.EOL}`);
+      expect(process.stdout.write).to.have.been.calledWith(
+        `Mutation testing 33% (elapsed: 1.66m) (remaining: 3.33m) 1/3 tested (0 survived, 0 timed out)${os.EOL}`
+      );
     });
 
-    it('should log 50% with "10m, 40s" ETC after thousand seconds with 1 completed test', () => {
+    it('should log correct info after a thousand seconds with 1 completed test', () => {
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
       expect(process.stdout.write).to.not.have.been.called;
       sinon.clock.tick(THOUSAND_SECONDS);
-      expect(process.stdout.write).to.have.been.calledWith(`Mutation testing 50% (ETC 10m, 40s) 1/2 tested (0 survived, 0 timed out)${os.EOL}`);
+      expect(process.stdout.write).to.have.been.calledWith(
+        `Mutation testing 33% (elapsed: 16.66m) (remaining: 33.33m) 1/3 tested (0 survived, 0 timed out)${os.EOL}`
+      );
     });
 
-    it('should log 50% with "2h, 46m, 40s" ETC after ten thousand seconds with 1 completed test', () => {
+    it('should log correct info after ten thousand seconds with 1 completed test', () => {
       sut.onMutantTested(mutantResult({ status: MutantStatus.TimedOut }));
       expect(process.stdout.write).to.not.have.been.called;
       sinon.clock.tick(TEN_THOUSAND_SECONDS);
-      expect(process.stdout.write).to.have.been.calledWith(`Mutation testing 50% (ETC 2h, 46m, 40s) 1/2 tested (0 survived, 1 timed out)${os.EOL}`);
+      expect(process.stdout.write).to.have.been.calledWith(
+        `Mutation testing 33% (elapsed: 2h, 46.66m) (remaining: 5h, 33.33m) 1/3 tested (0 survived, 1 timed out)${os.EOL}`
+      );
     });
   });
 });

packages/core/test/unit/reporters/ProgressReporter.spec.ts

@@ -19,7 +19,8 @@ describe('ProgressReporter', () => {
   let sut: ProgressReporter;
   let matchedMutants: MatchedMutant[];
   let progressBar: Mock<ProgressBar>;
-  const progressBarContent = 'Mutation testing  [:bar] :percent (ETC :etc) :tested/:total tested (:survived survived, :timedOut timed out)';
+  const progressBarContent =
+    'Mutation testing  [:bar] :percent (elapsed: :et) (remaining: :etc) :tested/:total tested (:survived survived, :timedOut timed out)';
 
   beforeEach(() => {
     sinon.useFakeTimers();
@@ -94,41 +95,41 @@ describe('ProgressReporter', () => {
     });
   });
 
-  describe('ProgressBar estimate time', () => {
+  describe('ProgressBar estimated time for 3 mutants', () => {
     beforeEach(() => {
-      sut.onAllMutantsMatchedWithTests([matchedMutant(1), matchedMutant(1)]);
+      sut.onAllMutantsMatchedWithTests([matchedMutant(1), matchedMutant(1), matchedMutant(1)]);
     });
 
-    it('should show to an estimate of "10s" in the progressBar after ten seconds and 1 mutants tested', () => {
+    it('should show correct time info after ten seconds and 1 mutants tested', () => {
       sinon.clock.tick(TEN_SECONDS);
 
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
 
-      expect(progressBar.tick).to.have.been.calledWithMatch({ etc: '10s' });
+      expect(progressBar.tick).to.have.been.calledWithMatch({ et: '0.16m', etc: '0.33m' });
     });
 
-    it('should show to an estimate of "1m, 40s" in the progressBar after hundred seconds and 1 mutants tested', () => {
+    it('should show correct time info after a hundred seconds and 1 mutants tested', () => {
       sinon.clock.tick(HUNDRED_SECONDS);
 
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
 
-      expect(progressBar.tick).to.have.been.calledWithMatch({ etc: '1m, 40s' });
+      expect(progressBar.tick).to.have.been.calledWithMatch({ et: '1.66m', etc: '3.33m' });
     });
 
-    it('should show to an estimate of "2h, 46m, 40s" in the progressBar after ten thousand seconds and 1 mutants tested', () => {
+    it('should show correct time info after ten thousand seconds and 1 mutants tested', () => {
       sinon.clock.tick(TEN_THOUSAND_SECONDS);
 
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
 
-      expect(progressBar.tick).to.have.been.calledWithMatch({ etc: '2h, 46m, 40s' });
+      expect(progressBar.tick).to.have.been.calledWithMatch({ et: '2h, 46.66m', etc: '5h, 33.33m' });
     });
 
-    it('should show to an estimate of "1h, 0m, 0s" in the progressBar after an hour and 1 mutants tested', () => {
+    it('should show correct time info after an hour and 1 mutants tested', () => {
       sinon.clock.tick(ONE_HOUR);
 
       sut.onMutantTested(mutantResult({ status: MutantStatus.Killed }));
 
-      expect(progressBar.tick).to.have.been.calledWithMatch({ etc: '1h, 0m, 0s' });
+      expect(progressBar.tick).to.have.been.calledWithMatch({ et: '1h, 0m', etc: '2h, 0m' });
     });
   });
 });