chore: fix alignment issues of the duration output

Author: asambstack

bin/helpers/sync/specsSummary.js

@@ -33,7 +33,8 @@ let printSpecsRunSummary = (data, machines, customErrorsToPrint) => {
     });
 
     logger.info(`Total tests: ${summary.total}, passed: ${summary.passed}, failed: ${summary.failed}, skipped: ${summary.skipped}, passed_with_skipped: ${summary.passed_with_skipped}, pending: ${summary.pending}`);
-    logger.debug(`CLI calculated duration: ${data.duration/1000} seconds using ${machines} machines\n`);
+    logger.info(`Done in ${data.duration} seconds using ${data.parallels} machines\n`);
+    winstonlogger.debug(`CLI calculated duration is ${data.cliDuration}\n`);
 
     if (customErrorsToPrint && customErrorsToPrint.length > 0) {
       for (const error of customErrorsToPrint) {

bin/helpers/sync/syncSpecsLogs.js

@@ -14,6 +14,8 @@ let specSummary = {
   "buildError": null,
   "specs": [],
   "duration": null,
+  "parallels": null,
+  "cliDuration": null,
   "customErrorsToPrint": []
 }
 
@@ -120,7 +122,7 @@ let printSpecsStatus = (bsConfig, buildDetails, rawArgs, buildReportData) => {
           }
         }
         logger.info(lineSeparator);
-        specSummary.duration =  endTime - startTime
+        specSummary.cliDuration =  endTime - startTime
         resolve(specSummary);
       }
     );
@@ -196,7 +198,8 @@ let showSpecsStatus = (data, statusCode) => {
     const buildDetails = specData.buildData;
     const totalDuration = buildDetails.duration?.total_duration
     const parallels = buildDetails.parallels
-    logger.info(`Done in ${totalDuration} seconds with ${parallels} parallels.\n`);
+    specSummary.duration = totalDuration;
+    specSummary.parallels = parallels;
   } else {
     logger.debug(`Build details not sent`)
   }

test/unit/bin/helpers/sync/specSummary.js

@@ -29,7 +29,7 @@ describe("printSpecsRunSummary", () => {
   });
 
   context("with data", () => {
-    let time = 6000,
+    let time = 6,
         machines = 2,
         specs = [
           {specName: 'spec2.name.js', status: 'Failed', combination: 'Win 10 / Chrome 78', sessionId: '3d3rdf3r...'},
@@ -40,24 +40,23 @@ describe("printSpecsRunSummary", () => {
         data = {
           specs: specs,
           duration: time,
+          parallels: machines,
           exitCode: 0
         };
 
     it('returns passed specs data', () => {
       var loggerInfoSpy = sinon.spy(logger, 'info');
-      var loggerDebugSpy = sinon.spy(logger, 'debug');
 
       specSummary.printSpecsRunSummary(data, machines);
       sinon.assert.calledWith(loggerInfoSpy, 'Total tests: 4, passed: 1, failed: 2, skipped: 1, passed_with_skipped: 0, pending: 0');
-      sinon.assert.calledWith(loggerDebugSpy, `CLI calculated duration: ${time / 1000} seconds using ${machines} machines\n`);
+      sinon.assert.calledWith(loggerInfoSpy, `Done in ${data.duration} seconds using ${data.parallels} machines\n`);
 
       loggerInfoSpy.restore();
-      loggerDebugSpy.restore();
     });
   });
 
   context("with custom error data", () => {
-    let time = 6000,
+    let time = 6,
         machines = 2,
         specs = [
           {specName: 'spec2.name.js', status: 'Failed', combination: 'Win 10 / Chrome 78', sessionId: '3d3rdf3r...'},
@@ -68,6 +67,7 @@ describe("printSpecsRunSummary", () => {
         data = {
           specs: specs,
           duration: time,
+          parallels: machines,
           exitCode: 0
         },
         customErrorsToPrint = [
@@ -76,16 +76,15 @@ describe("printSpecsRunSummary", () => {
 
     it('prints the custom error message along with build details', () => {
       var loggerInfoSpy = sinon.spy(logger, 'info');
-      var loggerDebugSpy = sinon.spy(logger, 'debug');
       var loggerWarnSpy = sinon.spy(winstonLogger, 'warn');
 
       specSummary.printSpecsRunSummary(data, machines, customErrorsToPrint);
       sinon.assert.calledWith(loggerInfoSpy, 'Total tests: 4, passed: 1, failed: 2, skipped: 1, passed_with_skipped: 0, pending: 0');
-      sinon.assert.calledWith(loggerDebugSpy, `CLI calculated duration: ${time / 1000} seconds using ${machines} machines\n`);
+      sinon.assert.calledWith(loggerInfoSpy, `Done in ${data.duration} seconds using ${data.parallels} machines\n`);
+
       sinon.assert.calledWith(loggerWarnSpy, `custom error message`);
 
       loggerInfoSpy.restore();
-      loggerDebugSpy.restore();
       loggerWarnSpy.restore();
     });
   });

test/unit/bin/helpers/sync/syncSpecsLogs.js

@@ -93,6 +93,8 @@ describe("syncSpecsLogs", () => {
       "buildError": null,
       "specs": [],
       "duration": null,
+      "parallels": null,
+      "cliDuration": null,
       "customErrorsToPrint": [
         { id: "custom_error_1", type: "custom_errors_to_print", level: "warn", should_be_unique: true, message: "custom error message" }
       ]
@@ -268,26 +270,6 @@ describe("syncSpecsLogs", () => {
       expect(printInitialLog.calledOnce).to.be.true;
       expect(addCustomErrorToPrint.calledOnce).to.be.true;
     });
-
-    it('should add custom error, print initial and spec details when spec related data and duration is sent in polling response', () => {
-      let specResult = JSON.stringify({"path": "path"})
-      let customError = { id: "custom_error_1", type: "custom_errors_to_print", level: "warn", should_be_unique: true, message: "custom error message" }
-      var loggerInfoSpy = sinon.spy(logger, 'info');
-      syncSpecsLogs.__set__('buildStarted', false)
-      let data = JSON.stringify({ "specData": ["created", specResult, customError], "buildData": {"duration": {"total_duration": "87"}, "parallels": "2"}})
-      var printSpecData = sandbox.stub();
-      syncSpecsLogs.__set__('printSpecData', printSpecData);
-      var printInitialLog = sandbox.stub();
-      syncSpecsLogs.__set__('printInitialLog', printInitialLog);
-      var addCustomErrorToPrint = sandbox.stub();
-      syncSpecsLogs.__set__('addCustomErrorToPrint', addCustomErrorToPrint);
-      showSpecsStatus(data, buildCompletedStatusCode);
-      expect(printSpecData.calledOnce).to.be.true;
-      expect(printInitialLog.calledOnce).to.be.true;
-      expect(addCustomErrorToPrint.calledOnce).to.be.true;
-      sinon.assert.calledWith(loggerInfoSpy, 'Done in 87 seconds with 2 parallels.\n');
-      loggerInfoSpy.restore();
-    });
   });
 
   context("printSpecsStatus", () => {
@@ -330,7 +312,7 @@ describe("syncSpecsLogs", () => {
         expect(tableStream.calledOnce).to.be.true;
         expect(whileProcess.calledOnce).to.be.false;
         expect(specSummary.specs).deep.to.equal([])
-        expect(specSummary.duration).to.eql(endTime - startTime);
+        expect(specSummary.cliDuration).to.eql(endTime - startTime);
       });
     });
 
@@ -345,7 +327,7 @@ describe("syncSpecsLogs", () => {
         expect(getTableConfig.calledOnce).to.be.true;
         expect(tableStream.calledOnce).to.be.true;
         expect(whileProcess.callCount).to.eql(3);
-        expect(specSummary.duration).to.eql(endTime - startTime);
+        expect(specSummary.cliDuration).to.eql(endTime - startTime);
       });
     });
   });