cenfun / monocart-reporter

A playwright test reporter (Node.js)
https://cenfun.github.io/monocart-reporter/
MIT License
212 stars 12 forks source link

[Feature Request] Exclude idle time from merged test duration #141

Closed edumserrano closed 1 month ago

edumserrano commented 2 months ago

Describe the bug

After merging reports with the merge function from monocart-reporter, the duration for the test run shown at the top of the monocart reporter after the title and on the side bar under the Timeline section is incorrect.

To Reproduce

Expected behavior

I believe that the duration displayed should match the sum of the duration of the sharded reports right?

Errors or Screenshots

First shard: 1m 17s image

Second shard: 52.3s image

Third shard: 37.4s image

Fourth shard: 41.5s image

Merged report: 6m 23s image

The sum of the duration from the sharded reports does not add to 6m 23s.

edumserrano commented 2 months ago

I just noticed that the 6m 23s from the merged report seem to be calculated by doing the difference from when the first shard started which was at 17:42:47 and when the last shard ended which was at 17:49:10 (fourth shard start time plus its 41.5s of duration rounded up to 42). So 17:49:10 - 17:42:47 = 6m 23s.

Perhaps one can argue that there's no bug here, I can understand why the calculation is done like this but it wasn't immediately obvious to me where the merged duration was coming from.

Out of curiosity, why did you choose to implement it like this instead of doing the sum of the duration of all the sharded reports duration? If I think about it perhaps it's because you have the same logic for detecting duration whether the report is from merging sharded runs or from a single run. In a single run it makes sense that the duration of the report is the diff between its end time and start time but in a sharded run for me it would make more sense for the duration to be the sum of the sharded runs...

cenfun commented 2 months ago

Because shards are generally in parallel (to divide your tests to speed up test runtime) see test-sharding I've considered several options

The shards are running in parallel which should be similar to worker in parallel image

edumserrano commented 2 months ago

Thank you for the detailed description of the options you considered πŸ™Œ.

I agree with your current implementation. However, there's a catch and I believe the key here is excluding idle time from the total duration which happens when not all shard runs start at same time or have overlapping execution times with other shards.

Let me give you an example of what happens in my CI system. We have a limited number of agents which serve many pipelines and in my Playwright tests pipeline I use 3 shards. What happens often is that the 3 shards don't start running at the same time because of lack of available agents and at times it happens that one of the shard run stays in waiting for an available agent for some minutes. For sake of this example let's say 5 min.

What this means is that when I look at the time of the merged report it shows a very large time for the test execution than I expected. This time, thought technically correct for the total time the sharded run took, since the first shard started until the last shard ended, also contains waiting time for an agent that is irrelevant for the test time duration.

You can test this locally by running one shard, then waiting a few minutes and running another shard and lastly merging the monocart reports. Here's an example:

Wouldn't it be more correct for the merged report to NOT count with the idle time? If there's an improvement to be made is to account for idle time, if there is any. Does that make sense? Not sure how easy it is to calculate idle time though, specially when you have many shards.

Here's an example of detecting idle time:

gantt
    dateFormat HH:mm:ss
    axisFormat %H:%M:%S
    first shard          :s1, 22:00:00, 22:01:30
    second shard         :s2, 22:03:30, 22:04:30
    third shard          :s3, 22:01:00, 22:03:00
    idle time            :i1, 22:03:00, 22:03:30

Currently for the above example, the duration for the merged report would say 4min 30s but if it accounted for the idle time it would say 4min which I believe is more correct. Any thoughts?

cenfun commented 2 months ago

I believe that the current duration implementation is correct, no matter how these shards are executed, it always represents the total time needed to complete all tests. However I also wonder if there is a way to resolve the issue in your situation. This is a idea which is adding one more onData hook to handle the report data inlcudes calculating the duration as you wish.

import { merge, Util } from 'monocart-reporter';

const reportDataList = [
    'path-to/shard1/index.json',
    'path-to/shard2/index.json',
    'path-to/shard3/index.json'
];

await merge(reportDataList, {
    name: 'My Merged Report',
    outputFile: 'merged-report/index.html',

    onData: (reportData, dataList) => {
        // sum or do whatever you want
        reportData.duration = dataList.map(d => d.duration).reduce((p, a) => p + a, 0);
        // human-readable duration
        reportData.durationH = `${Util.TF(reportData.duration)} (Sum)`;
    },

    onEnd: async (reportData, helper) => {

    }
});
edumserrano commented 2 months ago

1) Shortly after I created this issue I realized that my naΓ―ve approach wasn't really what I wanted. I didn't want to see the sum of all sharded runs as the duration of the report.

2) It makes sense that the duration of the merged report is calculated as:

const startDate = Math.min.apply(null, startDates);
const endDate = Math.max.apply(null, endDates);
const duration = endDate - startDate;

3) Thank you for showing a way to customize the duration of the report when merging. Using this approach also seems possible to calculate the idle time and remove it from the report duration.

4) The only caveat for me with point number two, with the way the duration of the merged report is calculated, is that it doesn't account for what I described as idle time. However you said that:

I believe that the current duration implementation is correct, no matter how these shards are executed, it always represents the total time needed to complete all tests.

Which perhaps means that you believe that idle time is should also be part of the test duration?

I don't dispute that taking into account idle time helps you understand when the test execution finished, meaning when the last shard finished executing. For instance we can look at the start time of the report and add the duration of the merged report and we will know when the last shard finished executing. That's true.

But I do think that knowing that is not the same as the duration of the test execution in sharded runs unless idle time is taken removed:

const startDate = Math.min.apply(null, startDates);
const endDate = Math.max.apply(null, endDates);
cost idleTime = <calculate idle time>
const duration = endDate - startDate - idleTime; 

I believe this would be a more rigorous approach and if there is idle time the report could show it. Right now it only shows Start time and duration but it could show:

Feel free to close this issue without any further action if you believe this is not worth doing. I understand now that there is no bug here. Changing this to a feature request.

cenfun commented 2 months ago

Yes, I think the idle time is should also be part of the test duration. (These idle times are out of control, it depends on how your shard system works) I consider providing a hook that allows users to generate the data they expect.

cenfun commented 2 months ago

Please try monocart-reporter@2.8.0 with onData hook

import { merge, Util } from 'monocart-reporter';

const reportDataList = [
    'path-to/shard1/index.json',
    'path-to/shard2/index.json',
    'path-to/shard3/index.json'
];

await merge(reportDataList, {
    name: 'My Merged Report',
    outputFile: 'merged-report/index.html',

    onData: (reportData, dataList) => {
        // sum or do whatever you want
        reportData.duration = dataList.map(d => d.duration).reduce((p, a) => p + a, 0);
        // human-readable duration
        reportData.durationH = `${Util.TF(reportData.duration)} (Sum)`;
    },

    onEnd: async (reportData, helper) => {

    }
});
edumserrano commented 1 month ago

Hi @cenfun , sorry for my delayed response.

I'm unable to confirm I can use the onData function to perform a custom calculation for reports. What is happening to me is that the dataList parameter in your example above only has 1 entry, even though its merging two reports.

What I did was run Playwright test with 1/2 shards and then with 2/2 shards, then I used a config very similar to the one you have above and I used a console.log to see the length of the dataList and it came out as 1 instead of 2. It seems only the last shard is in that array. I say this because I also used console.log on the dataList object and one of the properties was jsonDir: 'shards/2' which indicated it was the report data for the second shard.

Perhaps there's some bug on the onData function and the rawData doesn not properly reflect all the reports data? Also, the data types for the onData function are of type any which makes it harder to understand the structure of the data and what we can do with it. If it was possible to have some types for this it would be awesome (but that perhaps is another issue if you think it's worth doing).

cenfun commented 1 month ago

Thanks for the feedback. It should be fixed in monocart-reporter@2.8.1

edumserrano commented 1 month ago

I can confirm that version 2.8.1 is working as expected now. I will also share how I used the onData hook to exclude idle time from the merged report duration in case anyone wants to do the same:

[!NOTE]

The part that matters is the calculateTestRunDuration function which sums the duration of each sharded test run excluding idle times and the usage of this function in the MonocartReporterOptions.onData function.

// This is the content of the JS merge CLI config file

const path = require("node:path");

/**
 * Start and end times of a sharded test run.
 * @typedef {{start:Date, end: Date}} ShardedTestRunTime
 */

/**
 * @returns {number} The total duration of all test runs in milliseconds excluding idle time.
 * @param {ShardedTestRunTime[]} shardedTestRunTimes
 */
function calculateTestRunDuration(shardedTestRunTimes) {
  if (shardedTestRunTimes.length === 0) return 0;

  // Step 1: Sort the test runs by start date
  shardedTestRunTimes.sort((a, b) => a.start.getTime() - b.start.getTime());

  // Step 2: Merge overlapping intervals
  const mergedDurations = [];
  let current = shardedTestRunTimes[0];

  for (let i = 1; i < shardedTestRunTimes.length; i++) {
      if (current.end >= shardedTestRunTimes[i].start) {
          // Overlapping intervals, merge them
          current.end = new Date(Math.max(current.end.getTime(), shardedTestRunTimes[i].end.getTime()));
      } else {
          // No overlap, push the current interval and move to the next
          mergedDurations.push(current);
          current = shardedTestRunTimes[i];
      }
  }
  // Push the last interval
  mergedDurations.push(current);

  // Step 3: Calculate the total duration
  let totalDurationInMilliseconds = 0;
  for (const duration of mergedDurations) {
      totalDurationInMilliseconds += duration.end.getTime() - duration.start.getTime();
  }

  return totalDurationInMilliseconds;
}

/**
 * @returns {string} The duration formatted as a string in the format "h m s" or "m s".
 * @param {number} milliseconds
 */
function formatDuration(milliseconds) {
  let seconds = Math.floor(milliseconds / 1000);
  let minutes = Math.floor(seconds / 60);
  let hours = Math.floor(minutes / 60);

  seconds = seconds % 60;
  minutes = minutes % 60;

  if (hours > 0) {
      return `${hours}h ${minutes}m ${seconds}s`;
  } else {
      return `${minutes}m ${seconds}s`;
  }
}

/**
 * @typedef {import('monocart-reporter').MonocartReporterOptions} MonocartReporterOptions
 * @returns {import('monocart-reporter').MonocartReporterOptions}
 * @param {string} reportersOutputDir
 */
function getMonocartReporterOptions(reportersOutputDir) {
  const monocartReporterOutputDir = path.resolve(reportersOutputDir, "monocart-reporter");
  /**
   * @type {MonocartReporterOptions}
   */
  const monocartOptions = {
    name: "Playground app for @ln/ngx-module-federation-tools",
    outputFile: path.resolve(monocartReporterOutputDir, "monocart-report.html"),
    onData: (reportData, dataList) => {
      if (dataList.length === undefined  || dataList.length <= 1) {
        return;
      }

      const shardedTestRunTimes = dataList.map(x => {
        return {
          start: new Date(x.system.timestampStart),
          end: new Date(x.system.timestampEnd),
        }
      });
      const totalDurationInMilliseconds = calculateTestRunDuration(shardedTestRunTimes);
      reportData.durationH = formatDuration(totalDurationInMilliseconds);
    },
  };

  return monocartOptions;
}

const reportersOutputDir = path.resolve("./test-reporters/playwright");
const options = getMonocartReporterOptions(reportersOutputDir);
module.exports = options;
edumserrano commented 1 month ago

With the above I got what I expected. Let's consider this simple example:

Which can be visualized as:

gantt
    dateFormat HH:mm:ss
    axisFormat %H:%M:%S
    first shard          :s1, 14:25:04, 14:26:57
    second shard         :s2, 14:32:38, 14:33:48
    idle time            :i1, 14:26:58, 14:32:37

Using the logic to exclude idle time I got a report duration of: 3m 04s.

image

Which to me makes more sense specially when looking at the time from each shard in the report.

1st shard run: image

2nd shard run: image

Without this custom logic to exclude idle time the merged report duration by default shows as 8m 44s.

edumserrano commented 1 month ago

@cenfun Even with the onData function logic updating the reportData.durationH to show the time I want on the report, the time that shows on the MR summary is still the time without my logic.

Given the example from the previous post, I updated the report text for the duration to be the string 3m 04s but the MR summary shows:

[MR] Playground app for @ln/ngx-module-federation-tools
β”Œβ”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”¬β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”
β”‚ Tests       β”‚ 354                  β”‚
β”‚ β”œ Passed    β”‚ 205 (57.9%)          β”‚
β”‚ β”œ Flaky     β”‚ 0   (0.0%)           β”‚
β”‚ β”œ Skipped   β”‚ 148 (41.8%)          β”‚
β”‚ β”” Failed    β”‚ 1   (0.3%)           β”‚
β”‚ Steps       β”‚ 18937                β”‚
β”‚ Suites      β”‚ 67                   β”‚
β”‚ β”œ Projects  β”‚ 3                    β”‚
β”‚ β”œ Files     β”‚ 22                   β”‚
β”‚ β”œ Describes β”‚ 0                    β”‚
β”‚ β”” Shards    β”‚ 2                    β”‚
β”‚ Retries     β”‚ 0                    β”‚
β”‚ Errors      β”‚ 150                  β”‚
β”‚ Logs        β”‚ 0                    β”‚
β”‚ Attachments β”‚ 3                    β”‚
β”‚ Artifacts   β”‚ 1                    β”‚
β”‚ Playwright  β”‚ v1.47.1              β”‚
β”‚ Date        β”‚ 18/09/2024, 15:25:04 β”‚
β”‚ Duration    β”‚ 8m 44s               β”‚
β””β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”΄β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”€β”˜

Notice that the last field of the summary, Duration, says 8m 44s instead of 3m 04s.

Is there a way to update that value for the MR summary? Or is this potentially a bug where the MR summary should read from the updated reportData.durationH field?

cenfun commented 1 month ago

try updating duration too

reportData.durationH = formatDuration(totalDurationInMilliseconds);
+ reportData.duration = totalDurationInMilliseconds;
edumserrano commented 1 month ago

That was it. And you had that already set in your initial demo, I just didn't notice that I had removed it when I was implementing it on my side.

Awesome as always @cenfun . Thank you πŸ’―