Capture the execution time of steps

Thanks for considering this feature as part of Jbehave framework.

I have few queries on this feature. Is there any way to create and add the @Profiled annotation by our own in Jbehave framework ?. If yes, could you give us the procedure/steps to create and add this annotation in jbehave framework.

Because, we have created custom annotation using Spring and AOP and integrated it with Jbehave. But, the custom annotation is not identified by Jbehave and hence, our goal is satisfied yet. Could you please provide the way to add custom annotaion with Jbeave. May be it give temporary solution for us.

BTW, may i know when the ver 4.x release will happen?

One can add a Perf4J (for example) annotation to your Steps classes now. The problem that you then run into is the enhancement request to work with AOP-enhanced Steps classes. This kind of integration would leave all performance reporting up to you as part of your Perf4J integration (this by the way is what I'd like to show for AOP integration). If you want the reporting of timings included in the JBehave reports - then I think we have to have a deeper integration with Perf4J or write our own.

This enhancement would probably better be addressed with Perf4J integration and deal with the AOP issue - my 2c.

Thanks Brian Repko. Right now, I would like to log the step method execution time details. So, could please explain how to create AOP-enhanced Steps classes?. Any additional configuration required for this?

If you have some demos /references to work with AOP-enhanced Steps and Perf4j annotation, could you share me?.

Thanks in advance

I'm more oriented on a simpler approach that does not use neither AOP, nor Spring, nor Perf4J. Simply time the execution interval before and after a step execution. In fact, given it's a small overhead, I'm thinking that it could be done by default on all steps and reported in the StepResult.

There is no mechanism at present to define custom annotations by the user. We could think about this feature in 4.x. A first beta of 4.0 could be out relatively soon but no date has been yet set.

I've added the capture of the step duration in millis in the step result (in the jbehave-4.x branch)

The step results are currently serialised in the target/jbehave/view/tree.

files.

I'm thinking the @Profiled annotation may be redundant if just used to trigger the duration capture, although we could use it to add more features relative to profiling.

Thanks. That is nice. Is it possible to share the relevant dependencies/jar's because you have done capturing duration of step result?. Otherwise, could you please tell me some temporary solution to fix this issue using annotation in Jbehave framework?.

Mauro - agreed - the overhead of timing is small, so just doing it all the time and adding it to StepResult makes tons of sense. We could do that in the 3.6 branch as well (its backward compatible). Once we decide where to code this (4.x AND? 3.6), then I would request to close this issue (make it about timing). We may want to open up the issue of AOP steps as an enhancement if it doesn't already exist. I know that it was asked on the user list (Christian Zulehner) a while back but I'm not sure that we have it captured as an enhancement. The issue is that the JBehave framework doesn't recognize those steps classes as the AOP wipes out the JBehave annotations and we talked about an unwrap method on some interface to get to the actual class.

The results are now produced by the CrossReference class, and called xref.xml or xml.json. This file is produced in the target/jbehave/view at every execution. You can share it however you feel most appropriate.

There is no easy way to do this in 3.x branch, as this approach relies on the tree structure to collect the results. I think it'd be preferable to focus on the new functionality in 4.x rather than trying to port it to 3.x in a half-baked way. In the end, the execution times of single steps is not such a fundamental functionality, and we have the execution times of the stories implemented.

Sure, we can discuss the use of AOP although we need to clarify what behaviour we are trying to obtain by it.

As an aside, in 3.x one could implement a custom StoryReporter implementation that timed the steps using the beforeStep() to start the time and the successful() or failed() methods to stop it.

Hi Mauro Talevi , If you have some solution to get the execution time of step method using AOP, could share please?

Thanks,
Prem

prem - there is no solution using AOP in JBehave 3 and its built-in to JBehave 4 which is not released. As Mauro, mentions above with JBehave 3, you can implement the StoryReporter interface to start a timer in beforeStep() and stop the timer in successful() and failed(). Hope that helps.

Available from 4.0-beta-1.

It'd be more useful to get a bean passed to StoryReporter.beforeStep() and friends rather than just the string. In my case, it would be useful to collect timings per method, rather than after the step's placeholders have been replaced.

Of course, that's potentially harder to change now that the existing methods are already in a stable release. Any thoughts, or is this a case of "wait until JBehave 4 is stable"?

Hi James,

we're not going to change the 3.x StoryReporter interface.

4.0-beta-1 is pretty stable, with the notable exception of the story navigator which has yet to be upgraded.

You can try it out and use if it works for you. And of course if you find problems, we're here to help.

Thanks Mauro. We have been trying 4.0 – the only bug I'm aware of that's preventing us from upgrading is JBEHAVE-811 – if you can give me some pointers I'll have a go at patching it myself.

I'll look into fixing it and pushing out another beta.