Add runtime information to reporting

[luvarqpp]

Testing Problem

When running nontrivial tests (i.e. integration tests using jqwik-spring for example), runtime does matter. I would like to see average (or at least "wall time") runtime in statistics report at the end of the each property test.

Suggested Solution

Print avg time in milliseconds (seconds?) like here:

                              |-------------------jqwik-------------------
tries = 22                    | # of calls to property
checks = 22                   | # of not rejected calls
generation-mode = RANDOMIZED  | parameters are randomly generated
after-failure = PREVIOUS_SEED | use the previous seed
seed = -4298283179281868395   | random seed to reproduce generated values
average try time = 11123 ms   | wall time of property test divided by number of tries

(added single line at the end)

Discussion

Perhaps standard deviation of runs can be extreme and thus average try time is not best attribute to be shown.

[jlink]

Average runtime has little overhead because it only requires a single measurement and a division.

Advanced statistics require measurement per try which might or might not be noticeable. Which numbers do you think are most useful? I can think of:

• Average
• Mean
• Deviation
• Max
• Min

What else?

[luvarqpp]

In some cases whole duration histogram can be useful, but it is minor concern IMHO. I would keep things simple and add just easiest think (that also covers my need :). So just total runtime (and perhaps average per single try).

Other nice things would be anything like "used resources". Number of I/O, cpu cycles burnt, used memory, number of allocations, ... But that would make jqwik fuzzer framework...

[jlink]

Measuring time requires some decisions:

• Include the time needed for generating the parameters?
• Include the time needed for initializing and tearing down a property (e.g. in before / after hooks)?

[luvarqpp]

Report does include number of tries. There are all tries counted. This number is not affected by any hooks duration, nor time spent in parameters generation. It is easy.

You are asking, if burden (is it correct word?) of test condition preparation should be counted in time spent...

I think, that both times should be included or excluded, despite one is jqwik internal matter and second one is on test writer shoulders.

I have no universal answer. My personal opinion would be to include all times. Clear time of running just test logic is counted by JUnit framework and reported in xml file (if I am not wrong), but when I am searching for reasonable tries count I would like to work with actual time spent in property testing.

[jlink]

Including times is simpler so I'll go with that.

Scheduled for 1.3.1 -- if nothing more important comes along ;-)

[luvarqpp]

Thanks.

[osi]

I'd be interested in times for parameter generation. I had a complex arbitrary that was slow to build, and refactoring how it was generated help test time a lot.

[jlink]

@osi Are you interested in aggregated/average/median times or individual generation time?

[osi]

Aggregate statistics are fine. My goal is information that can be used to help tune overall test execution time.

[luvarqpp]

Hi, is this part of current jqwik? I see that timing is achievable using around property hook (example can be found here: https://jqwik.net/docs/current/user-guide.html#lifecycle-hook-types ). Also I see that there is an Timing annotation, which seems to do what is needed, but it is not part of library. Should I use approach where I use custom around hook, like in example here? https://github.com/jlink/jqwik/blob/bf1e4c08364f8d24806fe086cc0e6ca6fed54977/documentation/src/test/java/net/jqwik/docs/lifecycle/AroundPropertyHookExamples.java#L90

[jlink]

Hi, is this part of current jqwik?

I've not yet come around to implement it properly. Timing and MeasureTime are examples you can find in the repository but they are not in a state for including them in the library. Feel free to use them (by copy) in your own code if they serve your need.

[vlsi]

Measuring time requires some decisions: Include the time needed for generating the parameters? Include the time needed for initializing and tearing down a property (e.g. in before / after hooks)?

Of course, the more is collected the more overhead is, however, it would be nice to have:

1. "try duration" (including parameter preparation, lifecycle hook execution, property run)
2. "property duration" (~ the time it takes to execute @Property method)
3. "parameter preparation" (~ the time it takes to generate parameters for @Property method)
4. "shrink duration" (~ the time it takes to shrink the values). If @Property has two parameters, then I would expect shrink duration to be sum of both durations

I expect "mean time" should be a good start for the duration, however, capturing histograms and reporting percentiles in addition to mean might be good as well.

It might be that try duration should be split between regular try and shrink try. In other words, regular try duration == property duration + regular parameter preparation + some overhead while shrinking try duration == property duration + shrinking parameter preparation + some overhead.

Then adjustments to "caching", "generator tuning", could be weighted in terms of impact on try duration (e.g. see https://github.com/jlink/jqwik/issues/363 , https://github.com/jlink/jqwik/issues/339)