test() errors on unexpected output (#7847)

[0xtch]

Closes #7847

test() now captures output and fails with Test <num> produced unexpected output when a test produces output without using either output= or notOutput=. Such output checking is skipped when datatable.verbose=TRUE. To confirm this exception is necessary, I ran test.data.table(verbose=TRUE) manually. Without the exception, 4546 of 12876 tests failed on my machine:

Error in test.data.table(verbose = TRUE) :

  4546 errors out of 12876. Search inst/tests/tests.Rraw for test numbers 1.2, 2.1, 2.2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 18.1, 18.2, 19.1, 19.2, 20.1, 20.2, 21.1, 21.2, 22.1, 22.2, 23.1, 23.2, 24.1, 24.2, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42.1, 42.2, 43.1, 43.2, 45.1, 45.2, 46.1, 46.2, 47.1, 47.2, 48.1, 48.2, 49.1, 49.2, 50.1, 50.2, 51.1, 51.2, 52.1, 52.2, 53, 54, 55, 56, 57, 59, 68, 69.1, 69.2, 69.3, 69.4, 69.7, 70, 71, 72, 73, 79.1, 83, 83.1, 83.2, 84, 86, 87, 88, 88.5, 90, 90.5, 91, 93, 94, 95, 96, 97, 98, 99, 100, 101, 102, 103, 104.1, 104.2, 112, 116, 117, 127, 128, 129, 130, 131, 133, 136, 137, 138, 139, 141, 142, 144, 148, 149, 154, 157, 158, 158.5, 159, 160, 161, 162, 163, 164, 168.1, 168.2, 168.3, 169, 170, 171.2, 171.3, 172, 173.1, 173.2, 173.3, 174, 175, 180, 181, 182, 183, 184, 202, 203, 204, 205, 212, 213, 215, 216, 217, 218, 220, 221, 222, 223, 224, 225, 228, 229, 229.1, 231, 232, 233, 234, 235, 236, 237, 238, 239,

With the exception, all 12876 tests pass.

This is my first pull request. I'd appreciate any suggestions or corrections.

[codecov]

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 99.02%. Comparing base (fd3a72d) to head (9936090).

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #7884      +/-   ##
==========================================
- Coverage   99.02%   99.02%   -0.01%     
==========================================
  Files          88       88              
  Lines       17376    17375       -1     
==========================================
- Hits        17206    17205       -1     
  Misses        170      170              

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[MichaelChirico]

Looks basically good, I'm only puzzled about the datatable.verbose part. Could you share some example failures?

I'm not even sure why we have test.data.table(verbose=TRUE) to set datatable.verbose=TRUE universally... any recollection @jangorecki? Seems added in a19037c / some more context in 7c7c96a. But all of that predates output= and notOutput=, maybe it can be removed?

[0xtch]

Could you share some example failures?

Sorry for the late reply. I just got back from vacation.

I'll first try to explain my earlier comment more clearly. Based on my understanding, test() currently has two rules about console output:

1. If output= is given, out must contain it;
2. If notOutput= is given, out must not contain it.

What I'm attempting to add is a third case:

3. If neither output= nor notOutput= is given, out must be empty.

But this rule needs an exception under verbose. As far as I can tell there is no way to distinguish output produced by the tested expression from verbose diagnostics, so rule 3 would cause existing tests to fail. That's why I added !isTRUE(getOption("datatable.verbose")) to disable this check in that mode.

Take test(2.1, TESTDT[SJ(4,6),v,mult="first"], 3L) as an example. In verbose mode TESTDT[SJ(4,6), v, mult="first"] produces:

verbose output for test 2.1

forder.c received 1 rows and 2 columns
forderReuseSorting: opt=-1, took 0.000s
forder took 0.001 sec
x is already ordered by these columns, no need to call reorder
Coercing double column i.V1 (which contains no fractions) to type integer to match type of x.a.
Assigning to all 1 rows
RHS_list_of_columns == false
Direct plonk of unnamed RHS, no copy. MAYBE_REFERENCED==1, MAYBE_SHARED==0
Assigning to all 1 rows
RHS_list_of_columns == false
RHS for item 1 has been duplicated because MAYBE_REFERENCED==1 MAYBE_SHARED==1 ALTREP==0, but then is being plonked. length(values)==1; length(cols)==1
Coercing double column i.V2 (which contains no fractions) to type integer to match type of x.b.
Assigning to all 1 rows
RHS_list_of_columns == false
Direct plonk of unnamed RHS, no copy. MAYBE_REFERENCED==1, MAYBE_SHARED==0
Assigning to all 1 rows
RHS_list_of_columns == false
RHS for item 1 has been duplicated because MAYBE_REFERENCED==1 MAYBE_SHARED==1 ALTREP==0, but then is being plonked. length(values)==1; length(cols)==1
on= matches existing key, using key
Starting bmerge ...
forder.c received 1 rows and 2 columns
forderReuseSorting: opt=-1, took 0.000s
bmerge: looping bmerge_r took 0.000s
bmerge: took 0.000s
bmerge done in 0.001s elapsed (0.000s cpu)
Detected that j uses these columns: [v]

Since rule 3 requires out to be empty, this would fail the test, hence the exception.