Time Watcher

[Tibor17]

If you want to measure time spent by a test, you have to do one of the following:

• use try-finally and measure the time within the test; or
• use @before and @after, cache the start time, and compute the time spent in @after. Good luck with parallel tests, because there you have to use ThreadLocal.

The Rules is an elegant solution for that.

[Tibor17]

@dharkness

I changed the following.
I am fine with the name Stopwatch, you proposed. No problem to change it. I just want to listen @marcphilipp if he also likes it. The only reason why TimeWatcher is that the class extends TestWatcher.

fixed Javadoc "its"
micros -> toMicros, millis -> toMillis, seconds -> toSeconds
fixed Javadoc 3 lines to tab
startTime -> startNanos
endTime -> endNanos
enum SUCCEEDED - > PASSED
equalTo -> is(equalTo)

[dharkness]

@Tibor17 - Good point about TestWatcher. I'm not very familiar with the JUnit internals. All my experience with it comes from being a long-time user. :)

[Tibor17]

@dharkness

Works fine for me.

[marcphilipp]

The indentation looks off here and on the following lines.

[marcphilipp]

Maybe simply overriding finished would make a more simple example?

[Tibor17]

I think, only simply overriding the method is not enough. I tried to put some example of use since i think the people mostly want to log the time.

The reason why i started this pull now was that i needed some benchmark testing for ParallelComputer into our wiki. I am missing such feature in the JUnit.
So i do not want to use try-finally in our tests for such benchmark tests.
This Stopwatch would help others as well.

[marcphilipp]

I think TimeWatcher is easily confused with TestWatcher. Thus, I would vote for Stopwatch as well.

[Tibor17]

@marcphilipp
@dharkness
I also think the Stopwatch looks more intuitive to users thinking of what this test rule is doing.
I will update accordingly.

[dharkness]

The only caveat with Stopwatch is the class from Guava, com.google.common.base.Stopwatch, but it performs a similar function which I like. I doubt there's any problem here but figured it's better to point it out. :)

[marcphilipp]

@dharkness There's also a class with that name somewhere in Spring but, as you said, as it performs a similar function, I think that will do no harm.

[Tibor17]

@marcphilipp

We should have all changes done now.

• renamed to Stopwatch, StopwatchTest and AbstractStopwatchTest
• renamed fields to stopwatch
• renamed enum PASSED to SUCCEEDED
• is(not(0L)) -> timeSpent > 0
• is(equalTo()) -> is()
• #starting(), #stopping()
• TimeUnit conversions

[marcphilipp]

I think extracting these static members into an own class, say Recording, would make the whole test easier to read. That way, you could simply assign a new instance to a single static field in the @Before method. What do you think?

[Tibor17]

No problem to modify this style of code.
thx.

[Tibor17]

@marcphilipp
Can we continue on this?

[marcphilipp]

IMHO this pull is almost ready to be merged.

@dsaff Can you please take a look?

[dsaff]

Sorry to come in so late. What would you think about, rather than putting nanos in overridden methods from TestWatcher, instead exposing the time spent through a protected method? The current approach means that subclasses have the option of overriding one of two skipped, failed, etc. methods.

[Tibor17]

@dsaff
I have no problem to extend the TestWatcher by overriding methods -the new idea makes sense to me.
The thing I like in this Rule is the name of the class, because the user can clearly see what he is looking for in the API/package.

@dharkness
@marcphilipp
Would you put like/dislike to a new idea given by @dsaff ?
This would help me if I should I touch the code now.
Thx.

[dsaff]

Oops. I think I may have misled you. I like this idea of this being a different class. I'm just imagining a slightly different API. Where you have

public Stopwatch stopwatch= new Stopwatch() {
  @Override protected void succeeded(long nanos, Description description) {
     logInfo(description.getMethodName(), "succeeded", nanos);
   }

I'm imagining:

public Stopwatch stopwatch= new Stopwatch() {
  @Override protected void succeeded(Description description) {
     logInfo(description.getMethodName(), "succeeded", getRunTime());
   }

That said, I'm also wondering if this belongs in the core. While rules can be used for timing and such things, they're somewhat unwieldy, since they have to be added to each class that you want timed.

[Tibor17]

I can see a technical problem to get the value returned by RunTime(), because we currently override the succeeded, failed, skipped in order to get the fEndNanos.

If you override any of these methods, then getNanos() and RunTime() will return negative -fStartNanos.
Other possibility would be to copy the try-catch from TestWatcher here which means duplicate code.

A solution would be to make private methods package-private startingQuietly, succeededQuietly, failedQuietly, finishedQuietly and override them here and call fEndNanos= System.getNanos(); super.failedQuietly();

Now it looks like i am complicating it too much.
If you have a better idea pls explain.

[dsaff]

Ah, you're right. I hadn't thought of that. Back to review...

[dsaff]

Thanks!

[Tibor17]

@dsaff
Additionally, maybe we can return non-constant long value by getRuntime() as a time taken from start of the test until the call has been made.

The test may use it as

@Test public void test() {...; duration= rule.getRuntime() ; ... ;...}

Whould it be enough interresting feature?

[dsaff]

I could see that as an interesting follow-on commit, yes.