Tests fail with latest Test::More

[eserte]

My smokers started to report failures:

    # Failed test 'create_config_ok Baz'
    # at t/test_clustericious_config.t line 67.
    # +------+-------------------+---------------+--------+
    # | PATH | GOT               | CHECK         | LNs    |
    # +------+-------------------+---------------+--------+
    # |      | ARRAY(0x469f1f78) | <ARRAY>       | 58, 66 |
    # | [3]  | <DOES NOT EXIST>  | <EVENT: Diag> | 63, 63 |
    # +------+-------------------+---------------+--------+

# Failed test 'create_config_ok'
# at t/test_clustericious_config.t line 88.
    # Failed test 'create_directory_ok undef'
    # at t/test_clustericious_config.t line 126.
    # +------+-------------------+---------------+----------+
    # | PATH | GOT               | CHECK         | LNs      |
    # +------+-------------------+---------------+----------+
    # |      | ARRAY(0x469f1a98) | <ARRAY>       | 120, 125 |
    # | [2]  | <DOES NOT EXIST>  | <EVENT: Diag> | 123, 123 |
    # +------+-------------------+---------------+----------+

# Failed test 'create_directory_ok'
# at t/test_clustericious_config.t line 129.
# Seeded srand with seed '20171026' from local date.
# Looks like you failed 2 tests of 5.
t/test_clustericious_config.t ........................ 
Dubious, test returned 2 (wstat 512, 0x200)
Failed 2/5 subtests 
    # ERROR this should not appear
    # ERROR this should
    # ERROR main error
    # FATAL main fatal
    # ERROR main error
    # FATAL main fatal
    # ERROR message1
    # ERROR message2
    # Failed test 'log_like message3'
    # at t/test_clustericious_log.t line 145.
    # +---------------+-----+---------------+----+---------------+----------+
    # | PATH          | LNs | GOT           | OP | CHECK         | LNs      |
    # +---------------+-----+---------------+----+---------------+----------+
    # |               |     | ARRAY(0x45417 |    | <ARRAY>       | 133, 144 |
    # |               |     | 570)          |    |               |          |
    # |               |     |               |    |               |          |
    # | [3]           | 129 | Test2::Event: |    | <EVENT: Diag> | 138, 138 |
    # |               |     | :Diag=HASH(0x |    |               |          |
    # |               |     | 45419900)     |    |               |          |
    # |               |     |               |    |               |          |
    # | [3]->message( |     | ---\n         | eq | None of the e | 440      |
    # | )             |     | events:\n     |    | vents matched |          |
    # |               |     | - level: 4\n  |    |  the pattern: |          |
    # |               |     |   log4p_categ |    |               |          |
    # |               |     | ory: main\n   |    |               |          |
    # |               |     |   log4p_level |    |               |          |
    # |               |     | : ERROR\n     |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage1\n      |    |               |          |
    # |               |     |   name: TestX |    |               |          |
    # |               |     | \n            |    |               |          |
    # |               |     | - level: 4\n  |    |               |          |
    # |               |     |   log4p_categ |    |               |          |
    # |               |     | ory: main\n   |    |               |          |
    # |               |     |   log4p_level |    |               |          |
    # |               |     | : ERROR\n     |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage2\n      |    |               |          |
    # |               |     |   name: TestX |    |               |          |
    # |               |     | \n            |    |               |          |
    # |               |     | pattern:\n    |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage3\n      |    |               |          |
    # |               |     |               |    |               |          |
    # | [4]           |     | <DOES NOT EXI |    | <EVENT: Diag> | 141, 141 |
    # |               |     | ST>           |    |               |          |
    # +---------------+-----+---------------+----+---------------+----------+
    # Failed test 'log_unlike message1'
    # at t/test_clustericious_log.t line 177.
    # +---------------+-----+---------------+----+---------------+----------+
    # | PATH          | LNs | GOT           | OP | CHECK         | LNs      |
    # +---------------+-----+---------------+----+---------------+----------+
    # |               |     | ARRAY(0x45417 |    | <ARRAY>       | 165, 176 |
    # |               |     | 2b8)          |    |               |          |
    # |               |     |               |    |               |          |
    # | [3]           | 161 | Test2::Event: |    | <EVENT: Diag> | 170, 170 |
    # |               |     | :Diag=HASH(0x |    |               |          |
    # |               |     | 45419708)     |    |               |          |
    # |               |     |               |    |               |          |
    # | [3]->message( |     | ---\n         | eq | This event ma | 440      |
    # | )             |     | event:\n      |    | tched, but sh |          |
    # |               |     |   level: 4\n  |    | ould not have |          |
    # |               |     |   log4p_categ |    | :             |          |
    # |               |     | ory: main\n   |    |               |          |
    # |               |     |   log4p_level |    |               |          |
    # |               |     | : ERROR\n     |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage1\n      |    |               |          |
    # |               |     |   name: TestX |    |               |          |
    # |               |     | \n            |    |               |          |
    # |               |     | pattern:\n    |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage1\n      |    |               |          |
    # |               |     |               |    |               |          |
    # | [4]           |     | <DOES NOT EXI |    | <EVENT: Diag> | 173, 173 |
    # |               |     | ST>           |    |               |          |
    # +---------------+-----+---------------+----+---------------+----------+
    # Failed test 'log_unlike qr{message}'
    # at t/test_clustericious_log.t line 203.
    # +---------------+-----+---------------+----+---------------+----------+
    # | PATH          | LNs | GOT           | OP | CHECK         | LNs      |
    # +---------------+-----+---------------+----+---------------+----------+
    # |               |     | ARRAY(0x45414 |    | <ARRAY>       | 185, 202 |
    # |               |     | 678)          |    |               |          |
    # |               |     |               |    |               |          |
    # | [3]           | 181 | Test2::Event: |    | <EVENT: Diag> | 190, 190 |
    # |               |     | :Diag=HASH(0x |    |               |          |
    # |               |     | 454196a8)     |    |               |          |
    # |               |     |               |    |               |          |
    # | [3]->message( |     | ---\n         | eq | This event ma | 440      |
    # | )             |     | event:\n      |    | tched, but sh |          |
    # |               |     |   level: 4\n  |    | ould not have |          |
    # |               |     |   log4p_categ |    | :             |          |
    # |               |     | ory: main\n   |    |               |          |
    # |               |     |   log4p_level |    |               |          |
    # |               |     | : ERROR\n     |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage1\n      |    |               |          |
    # |               |     |   name: TestX |    |               |          |
    # |               |     | \n            |    |               |          |
    # |               |     | pattern:\n    |    |               |          |
    # |               |     |   message: !! |    |               |          |
    # |               |     | perl/regexp ( |    |               |          |
    # |               |     | ?^:message)\n |    |               |          |
    # |               |     |               |    |               |          |
    # | [4]           | 181 | Test2::Event: |    | <EVENT: Diag> | 193, 193 |
    # |               |     | :Diag=HASH(0x |    |               |          |
    # |               |     | 4541c3d8)     |    |               |          |
    # |               |     |               |    |               |          |
    # | [4]->message( |     | This event ma | =~ | (?^:^---)     | 193      |
    # | )             |     | tched, but sh |    |               |          |
    # |               |     | ould not have |    |               |          |
    # |               |     | :             |    |               |          |
    # |               |     |               |    |               |          |
    # | [5]           | 181 | Test2::Event: |    | <EVENT: Diag> | 196, 196 |
    # |               |     | :Diag=HASH(0x |    |               |          |
    # |               |     | 4541c3f0)     |    |               |          |
    # |               |     |               |    |               |          |
    # | [5]->message( |     | ---\n         | eq | This event ma | 440      |
    # | )             |     | event:\n      |    | tched, but sh |          |
    # |               |     |   level: 4\n  |    | ould not have |          |
    # |               |     |   log4p_categ |    | :             |          |
    # |               |     | ory: main\n   |    |               |          |
    # |               |     |   log4p_level |    |               |          |
    # |               |     | : ERROR\n     |    |               |          |
    # |               |     |   message: me |    |               |          |
    # |               |     | ssage2\n      |    |               |          |
    # |               |     |   name: TestX |    |               |          |
    # |               |     | \n            |    |               |          |
    # |               |     | pattern:\n    |    |               |          |
    # |               |     |   message: !! |    |               |          |
    # |               |     | perl/regexp ( |    |               |          |
    # |               |     | ?^:message)\n |    |               |          |
    # |               |     |               |    |               |          |
    # | [6]           |     | <DOES NOT EXI |    | <EVENT: Diag> | 199, 199 |
    # |               |     | ST>           |    |               |          |
    # +---------------+-----+---------------+----+---------------+----------+

# Failed test 'log_like'
# at t/test_clustericious_log.t line 210.
    # ERROR PLATYPUS-42
    # ERROR PLATYPUS-47
# detailed log
# [35039 I 7ms] /usr/home/cpansand/.cpan/build/2017102618/Clustericious-1.26-4/blib/lib/Clustericious/Log.pm:72 Initialized logger
# [35039 I 8ms] /usr/home/cpansand/.cpan/build/2017102618/Clustericious-1.26-4/blib/lib/Clustericious/Log.pm:73 Log config found : /var/tmp/cpansmoker-1023/2017102618/LUuF_7c6MN/home/cpansand/etc/log4perl.conf
# [35039 E 13ms] t/test_clustericious_log.t:19 this should not appear
# [35039 E 14ms] t/test_clustericious_log.t:27 this should
# [35039 T 15ms] t/test_clustericious_log.t:38 main trace
# [35039 D 15ms] t/test_clustericious_log.t:39 main debug
# [35039 I 15ms] t/test_clustericious_log.t:40 main info
# [35039 W 16ms] t/test_clustericious_log.t:41 main warn
# [35039 E 16ms] t/test_clustericious_log.t:42 main error
# [35039 F 17ms] t/test_clustericious_log.t:43 main fatal
# [35039 T 19ms] t/test_clustericious_log.t:84 main trace
# [35039 D 19ms] t/test_clustericious_log.t:85 main debug
# [35039 I 19ms] t/test_clustericious_log.t:86 main info
# [35039 W 20ms] t/test_clustericious_log.t:87 main warn
# [35039 E 20ms] t/test_clustericious_log.t:88 main error
# [35039 F 21ms] t/test_clustericious_log.t:89 main fatal
# [35039 E 22ms] t/test_clustericious_log.t:101 message1
# [35039 E 23ms] t/test_clustericious_log.t:102 message2
# [35039 E 76ms] t/test_clustericious_log.t:214 PLATYPUS-42
# [35039 E 76ms] t/test_clustericious_log.t:216 PLATYPUS-47
# Seeded srand with seed '20171026' from local date.
# Looks like you failed 1 test of 5.
t/test_clustericious_log.t ........................... 
Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/5 subtests 

Statistical analysis suggests that the problem happens with the latest Test::More (@exodist: FYI):

****************************************************************
Regression 'mod:Test::More'
****************************************************************
Name                   Theta          StdErr     T-stat
[0='const']           1.0000          0.0000    28363667951342848.00
[1='eq_1.302075']         0.0000          0.0000       7.71
[2='eq_1.302085']         0.0000          0.0000      11.07
[3='eq_1.302086']         0.0000          0.0000      12.16
[4='eq_1.302096']         0.0000          0.0000      13.95
[5='eq_1.302103']         0.0000          0.0000      10.50
[6='eq_1.302106']        -1.0000          0.0000    -26621873126112640.00

R^2= 1.000, N= 141, K= 7
****************************************************************

[exodist]

1.302104 merged a PR that combines multiple diags into a single diag. I was on the fence merging it because I was afraid this could happen if anyone had been testing Test::Builder things with Test2::API::intercept, though my downstream testing did not find any at the time.

This combination is rare enough that I would prefer to have projects like this one fix it on their end. If that is simply not viable please let me know and we can work out another solution.

[plicease]

I have been using Test2::API::Intercept to test Test::Builder things. Most of them have been migrated to Test2::API by now. I am going to migrate this to Test2::API now anyway. If this pops up in other projects I am happy to fix them there. I have noticed when migrating Test::Builder to Test2::API with intercept tests I get a different number of Diags, so this would be more consistent IMO.

[exodist]

yeah. Test2::API::Intercept "works" for Test::Builder, but it is not ideal as Test::Builder is a compatibility/abstraction layer, and what events it generates when may change in order to preserve legacy behavior (read-as: output, and non-Test2 interactions) as the rest of Test2 moves forward.

[plicease]

Most of the time I've written intercept tests for Test::Builder code just prior to migrating to Test2::API so that I can have confidence in the migration. (the one caveat had been extra Diags from Test::Builder version as mentioned). For the amount of time the the code was mismatched this has been acceptable. I think this is an exception where I wrote some intercept tests without immediately switching to Test2::API. I am also happy for this to be an excuse to switch to Test::API anywhere else that this pops up.