gauge icon indicating copy to clipboard operation
gauge copied to clipboard

Include the test step execution time as part of the ExecutionContext object

Open shortstacked opened this issue 3 years ago • 1 comments

Is your feature request related to a problem? Please describe. I'm looking for a way to get the execution time taken for a test step via the test context. I would like to be able to get this data and then export it to datadog, so I can track various metrics and figure out which tests take longer at a glance.

Describe the solution you'd like I would like if the "ExecutionContext" of a test step also included a "elapsedTime" property, or something similar.

Describe alternatives you've considered Creating a custom reporter to export test results to Datadog/Kibana etc.

Additional context Add any other context or screenshots about the feature request here.

shortstacked avatar Jun 02 '21 09:06 shortstacked

I would like this feature too.

Currently I have implemented this as follows, but it only logs the time, does not report to a data collector like Elastic Search. I used Spring StopWatch class for the timing info. scenarioData mentioned in the code below is reference to gauge's ScenarioDataStore.java

@BeforeStep
public void beforeStep(ExecutionContext context)
{
    super.beforeStep(context);
    startTimer(getStepText(context));
}

@AfterStep
public void afterStep(ExecutionContext context)
{
    String duration = stopTimer();
    String status = context.getCurrentStep().getIsFailing() ? "FAIL" : "PASS";
    String step = getStepText(context);

    logger.info("[{}] [{}] {}", status, duration, step);
    if (context.getCurrentStep().getIsFailing())
    {
        logger.info("\t\t --> Failure: {}", context.getCurrentStep().getErrorMessage());
    }
    super.afterStep(context);
}

private String getStepText(ExecutionContext context)
{
    if (null == context)
    {
        return "-";
    }
    String step = context.getCurrentStep().getDynamicText();
    if (100 < step.length())
    {
        step = step.substring(0, 100) + " ...";
    }
    return step;
}

public void startTimer(String step)
{
    StopWatch watch = new StopWatch();
    getSimpleDriver().storage().scenarioData().put(STOP_WATCH_KEY, watch);
    watch.start(step);
}

private String stopTimer()
{
    StopWatch watch = getSimpleDriver().storage().scenarioData().get(STOP_WATCH_KEY);
    if (null == watch)
    {
        logger.error("Stop Watch should not be null!!!");
        return "-";
    }
    watch.stop();
    getSimpleDriver().storage().scenarioData().put(STOP_WATCH_KEY, null);
    double timeSeconds = watch.getLastTaskInfo().getTimeSeconds();
    return  String.format ("%.03fs", timeSeconds);
}

Output

Log Statement Explanation:

[Log Level] [Current Time] [Test Step Status] [Elapsed time for step] [Step Name]

Actual Output

[ INFO] [16:28:32] [PASS] [0.561s] Go to URL "${app.url}".
[ INFO] [16:28:33] [PASS] [0.775s] Click on Login using Landing Page.
[ INFO] [16:28:34] [PASS] [1.475s] Enter username "${LoginID}".

Hope this helps...

alpha1592 avatar Jul 14 '21 20:07 alpha1592