Add new command-line option to specify a threshold for test duration printing #1910

jbytheway · 2020-04-13T12:46:27Z

Description

A test runner already has a --durations option to print durations. However, this isn't entirely satisfactory.

When there are many tests, this produces output spam which makes it hard to find the test failure output. Nevertheless, it is helpful to be informed of tests which are unusually slow.

Therefore, introduce a new option --min-duration that causes all durations above a certain threshold to be printed. This allows slow tests to be visible without mentioning every test.

In our CI we're currently emulating this with some ugly grep on the output, but this is a bit limited, and harder to use when running the tests outside of CI.

I've made a bunch of choices in this implementation that could have gone differently:

--min-duration is independent of --durations. Specifying either will cause things to be printed. I could have rolled them into a single option that takes either a string or numeric argument, or made --min-duration do nothing if --durations was not also given.
I made IConfig::shouldShowDuration a member function. It could have been a free function, but I wouldn't know where to put it.
--min-duration only affects the console and compact reporters, not e.g. the XML reporter, because I figured output spam is not an issue there.
It's tricky to test this change, because every test in SelfTest is so fast that it is printed as 0.000 s. So for now the test just verifies that no durations are printed if a minimum of 1s is specified. But it's written in such a way that it should do something more interesting if slower tests are ever added.

codecov · 2020-04-13T13:49:15Z

Codecov Report

Merging #1910 into master will increase coverage by 0.13%.
The diff coverage is 82.35%.

@@            Coverage Diff             @@
##           master    #1910      +/-   ##
==========================================
+ Coverage   88.61%   88.74%   +0.13%     
==========================================
  Files         138      138              
  Lines        5627     5629       +2     
==========================================
+ Hits         4986     4995       +9     
+ Misses        641      634       -7

include/reporters/catch_reporter_compact.cpp

horenmar · 2020-05-15T19:52:20Z

include/internal/catch_config.hpp

@@ -52,6 +52,7 @@ namespace Catch {
 Verbosity verbosity = Verbosity::Normal;
 WarnAbout::What warnings = WarnAbout::Nothing;
 ShowDurations::OrNot showDurations = ShowDurations::DefaultForReporter;
+ double minDuration = -1;


I think having 0. mean "turned off" is fine here. If an user wants all durations to be shown, they can set up showDurations::Always.

I'm always leery of using a value that might possibly have been intended as valid for a sentinel value. You never know when there might be extra layers between the user and the value (e.g. a GUI or a wrapper script) which makes it less easy to pass other arguments.

include/internal/catch_commandline.cpp

horenmar · 2020-05-15T19:54:31Z

I think IConfig::shouldShowDuration should be a free function somewhere in reporter interfaces/bases -- there is already precedent with some cross-reporter helpers being there.

For testing, I would suggest adding a hidden test non-approval test that sleeps for, say, 100 ms, and another that sleeps for 500 ms and then check that they are (not) reported as appropriate...

All in all the changes look reasonable, but I'll definitely need one more look later.

horenmar · 2020-05-17T11:08:17Z

Some extra thoughts on combining -d and -D:

ShowDurations::Always should take priority over values set by -D.
ShowDurations::Never should suppress printing any durations. (I also see only one place it is used, and I have some doubts about the usefulness there)
This implies that setting -D is only valid if -d is not set. The question is, should Catch2 stop you from specifying both?

jbytheway · 2020-06-02T02:03:15Z

For testing, I would suggest adding a hidden test non-approval test that sleeps for, say, 100 ms, and another that sleeps for 500 ms and then check that they are (not) reported as appropriate...

To verify I've understood you: by "hidden" do you mean "marked [.]"? So I could use e.g. `"[.min_duration_test]" for them and run them just when testing this feature?

jbytheway · 2020-06-02T02:06:00Z

I think IConfig::shouldShowDuration should be a free function somewhere in reporter interfaces/bases -- there is already precedent with some cross-reporter helpers being there.

In include/reporters/catch_reporter_bases.hpp I see getFormatterDuration. Is that the sort of place you were thinking?

jbytheway · 2020-06-02T02:11:43Z

This implies that setting -D is only valid if -d is not set. The question is, should Catch2 stop you from specifying both?

My instinct is not to prevent it. You might e.g. be calling the test runner through a wrapper script that uses -D and it would be annoying if you couldn't add -d to override.

horenmar · 2020-06-02T14:55:14Z

In include/reporters/catch_reporter_bases.hpp I see getFormatterDuration. Is that the sort of place you were thinking?

Yes.

To verify I've understood you: by "hidden" do you mean "marked [.]"? So I could use e.g. `"[.min_duration_test]" for them and run them just when testing this feature?

And yes. You will also need [approvals] to prevent them from being run during approvals.

A test runner already has a --durations option to print durations. However, this isn't entirely satisfactory. When there are many tests, this produces output spam which makes it hard to find the test failure output. Nevertheless, it is helpful to be informed of tests which are unusually slow. Therefore, introduce a new option --min-duration that causes all durations above a certain threshold to be printed. This allows slow tests to be visible without mentioning every test.

jbytheway · 2020-07-03T19:17:09Z

I have refactored and updated the tests as suggested. Over to you.

horenmar · 2020-07-06T09:34:51Z

There are some things I am still not quite happy with, but it will be fastest if I merge the PR as is and fix it later.

nandanvasudevan · 2022-03-16T03:50:14Z

Would it be possible to group the output according to the test case and tag?

horenmar · 2022-03-18T23:18:22Z

@nandanvasudevan Everything is possible with a custom reporter. 🤷

jbytheway changed the title ~~Test time threshold printing~~ Add new command-line option to specify a threshold for test duration printing Apr 13, 2020

jbytheway force-pushed the test_time_threshold_printing branch from 6533c60 to 33d1568 Compare April 14, 2020 12:45

horenmar reviewed May 15, 2020

View reviewed changes

include/reporters/catch_reporter_compact.cpp Outdated Show resolved Hide resolved

horenmar reviewed May 15, 2020

View reviewed changes

include/internal/catch_commandline.cpp Outdated Show resolved Hide resolved

horenmar added the Feature label May 15, 2020

jbytheway force-pushed the test_time_threshold_printing branch from 33d1568 to 08af3e6 Compare June 2, 2020 02:08

jbytheway added 2 commits July 3, 2020 15:16

Test for --min-duration

336e27c

jbytheway force-pushed the test_time_threshold_printing branch from 08af3e6 to 336e27c Compare July 3, 2020 19:16

horenmar merged commit 53d8af8 into catchorg:master Jul 6, 2020

horenmar mentioned this pull request Jul 7, 2020

Can't compile with gcc-7.4.0 #1975

Closed

jbytheway mentioned this pull request Jul 13, 2020

Update Catch2 to 2.13.0 CleverRaven/Cataclysm-DDA#42076

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add new command-line option to specify a threshold for test duration printing #1910

Add new command-line option to specify a threshold for test duration printing #1910

jbytheway commented Apr 13, 2020 •

edited

Loading

codecov bot commented Apr 13, 2020 •

edited

Loading

horenmar May 15, 2020

jbytheway Jun 2, 2020

horenmar commented May 15, 2020 •

edited

Loading

horenmar commented May 17, 2020

jbytheway commented Jun 2, 2020

jbytheway commented Jun 2, 2020

jbytheway commented Jun 2, 2020 •

edited

Loading

horenmar commented Jun 2, 2020 •

edited

Loading

jbytheway commented Jul 3, 2020

horenmar commented Jul 6, 2020

nandanvasudevan commented Mar 16, 2022 •

edited

Loading

horenmar commented Mar 18, 2022

Add new command-line option to specify a threshold for test duration printing #1910

Add new command-line option to specify a threshold for test duration printing #1910

Conversation

jbytheway commented Apr 13, 2020 • edited Loading

Description

codecov bot commented Apr 13, 2020 • edited Loading

Codecov Report

horenmar May 15, 2020

Choose a reason for hiding this comment

jbytheway Jun 2, 2020

Choose a reason for hiding this comment

horenmar commented May 15, 2020 • edited Loading

horenmar commented May 17, 2020

jbytheway commented Jun 2, 2020

jbytheway commented Jun 2, 2020

jbytheway commented Jun 2, 2020 • edited Loading

horenmar commented Jun 2, 2020 • edited Loading

jbytheway commented Jul 3, 2020

horenmar commented Jul 6, 2020

nandanvasudevan commented Mar 16, 2022 • edited Loading

horenmar commented Mar 18, 2022

jbytheway commented Apr 13, 2020 •

edited

Loading

codecov bot commented Apr 13, 2020 •

edited

Loading

horenmar commented May 15, 2020 •

edited

Loading

jbytheway commented Jun 2, 2020 •

edited

Loading

horenmar commented Jun 2, 2020 •

edited

Loading

nandanvasudevan commented Mar 16, 2022 •

edited

Loading