no way to tell a passing todo test event from a failing one

[karenetheridge]

example script:

use strict;
use warnings;
use Test::More;
use Test2::API 'intercept';

my $events = intercept {
  TODO: {
    local $TODO = 'my todo message';
    fail 'this is a failing test that should todo';
  }
};

use Data::Dumper;
local $Data::Dumper::Sortkeys = 1;
local $Data::Dumper::Maxdepth = 4;
print STDERR "### events ", Dumper($events);

done_testing;

produces:

### events $VAR1 = [
          bless( {
                   '_eid' => '28047~0~1596665436~7',
                   '_meta' => {
                                'Test::Builder' => {
                                                     'actual_ok' => 0,
                                                     'name' => 'this is a failing test that should todo',
                                                     'ok' => 0,
                                                     'reason' => '',
                                                     'type' => ''
                                                   }
                              },
                   'effective_pass' => 0,
                   'hubs' => [
                               {
                                 'buffered' => 0,
                                 'details' => 'Test2::Hub::Interceptor',
                                 'hid' => '28047~0~1596665436~5',
                                 'ipc' => 0,
                                 'nested' => 0,
                                 'pid' => 28047,
                                 'tid' => 0,
                                 'uuid' => undef
                               }
                             ],
                   'name' => 'this is a failing test that should todo',
                   'pass' => 0,
                   'trace' => bless( {
                                       'buffered' => 0,
                                       'cid' => '28047~0~1596665436~6',
                                       'frame' => [
                                                    'main',
                                                    'foo.t',
                                                    10,
                                                    'Test::More::fail'
                                                  ],
                                       'hid' => '28047~0~1596665436~5',
                                       'nested' => 0,
                                       'pid' => 28047,
                                       'tid' => 0
                                     }, 'Test2::EventFacet::Trace' )
                 }, 'Test2::Event::Ok' ),
          bless( {
                   '_eid' => '28047~0~1596665436~8',
                   'hubs' => [
                               {
                                 'buffered' => 0,
                                 'details' => 'Test2::Hub::Interceptor',
                                 'hid' => '28047~0~1596665436~5',
                                 'ipc' => 0,
                                 'nested' => 0,
                                 'pid' => 28047,
                                 'tid' => 0,
                                 'uuid' => undef
                               }
                             ],
                   'message' => '  Failed (TODO) test \'this is a failing test that should todo\'
  at foo.t line 10.
',
                   'trace' => bless( {
                                       'buffered' => 0,
                                       'cid' => '28047~0~1596665436~6',
                                       'frame' => $VAR1->[0]{'trace'}{'frame'},
                                       'hid' => '28047~0~1596665436~5',
                                       'nested' => 0,
                                       'pid' => 28047,
                                       'tid' => 0
                                     }, 'Test2::EventFacet::Trace' )
                 }, 'Test2::Event::Diag' )
        ];
1..0

Without the intercept, the test output is:

not ok 1 - this is a failing test that should todo # TODO my todo message
#   Failed (TODO) test 'this is a failing test that should todo'
#   at foo.t line 10.
1..1

Issues:

• the value of $TODO appears nowhere in the captured Test2::Event::Ok event
• there is no way to tell that the test harness will be given a passing test result rather than a fail, due to that failing test being wrapped in a TODO. The Test::Builder hash in _meta should have actual_ok => 0 and ok => 1, but actually it has ok => 0, and at the Test2::Event::Ok level, I would expect effective_pass => 0 and ok => 1.

The only way that I can see to test that this is a passing test rather than failing is to parse the Test2::Event::Diag message for Failed (TODO) test, which seems fragile.

[exodist]

Ah, this is a bug.

• Test2 does TODO differently, todo is a state applied to the active event hub.
• Intercept does its best to give tools a clean slate, which means starting with a new hub that has nothing the real hub has.
• Test::Builder adds a hook to the real hub to notice $TODO and modify the event

These things combined mean a TODO test that is marked as such by Test::Builder/More's $TODO variable is not properly marked inside an intercept. If you used Test2's todo system it would work fine, and you would see an 'amnesty' facet on the event which had the todo info.

Obviously this is a bad experience, I will fix this when I have a moment, hopefully this week. I have an idea of how I want to fix it and expect it to be a simple patch.

You see the todo info in the diag because Test::Builder has separate assertion and diag events, and legacy code used the todo state to make the diag.

[karenetheridge]

What is Test2's todo system? I thought Test::More was an interface to both the legacy and new systems.

I've also noticed that passing TODO tests are even harder to detect, because there is no accompanying Test2::Event::Diag that is generated for them.

[exodist]

TODO and SKIP both fall under a facet called "amnesty". Amnesty is typically granted externally from the tool that generates the assertion. For example, you do not want to have to write every is(), ok, is_deeply, cmp_ok, etc to check $TODO. You do not want new tools that generate new custom events to do this check. But the TODO state does need to be set sooner rather than later because local $TODO will revert when the scope ends, so if you inspect the event after that it is too late to check $TODO. In Test::Builder the issue was solved by all assertions eventually going to $TB->ok. Test2's event system has no such guarantee.

The way it works in Test2 is you have a hub, the moment a tool generates an event it is sent to the hub for processing. $ctx->ok, $ctx->pass, $ctx->diag, etc all send the event to the hub. This is all the tools like is() care about is sending their event, which makes an assertion which is true or false, and may have associated diagnostics, etc.

Todo/skip, etc in Test2 work by adding a callback to the hub that is triggered on all received events, these callbacks look at the event and decide if they want to modify it, or pass it unchanged. The Test2 TODO tools are scoped, either an object that goes away when scope ends (object with destructor, not a localized global) or a function that calls a sub you define:

todo "will fix this" => sub {
    ...
};

{
    my $todo = todo "Will fix this";
    ...
}

In both these cases the todo() tool adds a callback to the hub that adds the todo amnesty facet to any events that have assertions. Once the scope ends (either the object is destroyed, or the subref you passed in returns) the callback is removed from the hub. This means non-todo tests are slightly faster as they callback is never used when there is no todo state.

Test::Builder's use of a $TODO variable that is localized to a defined value to set the state obviously cannot work this way, there is no way to capture that scope. So Test::Builder, when loaded, adds the todo callback to the hub, and it is always called, even when $TODO is not set, it just does nothing in that case. When $TODO is set is does the same thing as the Test2 tools and adds amnesty.

Hubs are a stack. When you start a subtast a new subtest hub is pushed onto the stack. Those hub callbacks I mentioned, the ones that do todo, they are set to be inherited, so when you start a subtest it will inherit the todo callbacks, so subtests still work with the $TODO variable.

intercept is intentionally different. With intercept it creates a new hub that is not based on whatever is at the top of the stack. It is like this specifically so that it is a virgin state in which you can test things like hub callbacks. The Test2 todo works fine here because when you call todo() it modifies the topmost hub, which is the virgin one. However $TODO from Test::More does not work because the callback that is not added and removed, but always present, has not been added again for the intercepte hub.

This is a non-issue when using intercept to test Test2 tools, they do not use global variables that get localized. The design specifically avoids such things. This is also not a problem for anyone using test tools as regular hub pushes (subtests) inherit callbacks like the one Test::Builder sets. This is only a problem when you are using Test2's intercept() to test Test::Builder based tools.

The problem is, simply having intercept inherit the Test::Builder todo callback would break the guarantee that tools tested in intercept() get a virgin hub with no other tools contamination. However my plan to solve that is to add a new option for hub callbacks, intercept_inherit => sub { ...; $_[0]->() }. If set then intercept() will inherit the callbacks, but will pass the intercept {block} into the subref, the subref can then do whatever it needs to to insure things are clean for intercept(). In the Test::Builder todo callback I will set it to sub { local $TODO; $_[0]->() } So that if you had $TODO set outside intercept() it would not be set in intercept, so there will be no leak, but using $TODO inside the intercept still works as intended.

[exodist]

gah, digging in now, some technical details of the solution I wrote above need to change, but not drastically.

[karenetheridge]

Okay, so how do I detect that a particular test failed but will be considered to be a pass because it was marked TODO? I still see pass => 1, effective_pass => 1 on all Test2::Event::Ok tests that failed.

[exodist]

The assert facet will always be false if a test failed. However there will be one or more amnesty facets if it is todo, and those contain the todo info. I also believe Test2::Event has a "causes_fail" or similarly named method (cannot look it up right now) that returns true if there is a failed assertion, but returns false if there is also an amnesty facet.

…

On Thu, Aug 6, 2020, 11:35 AM Karen Etheridge ***@***.***> wrote: Okay, so how do I detect that a particular test failed but will be considered to be a pass because it was marked TODO? I still see pass => 1, effective_pass => 1 on all Test2::Event::Ok tests that failed. — You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub <#862 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAASBOTWS6YFFD2RE76LFTDR7LZXZANCNFSM4PV6VR6A> .

[exodist]

Can you show me the line(s) in your test that generated that event?

[exodist]

The event seems to indicate it did pass, and was also todo, so a passing todo. So if the test actually failed then there is absolutely a bug somewhere.

[karenetheridge]

I deleted the last paste.. I think I had an error (I will try to boil down my tests to get a clearer repro case to demonstrate the issue if there is one).

I see there is a Test2::Event method 'causes_fail', but it is documented as legacy, and also that it is expected to return false. Is this the right method to use to check if the test actually passed/failed? Will this check the 'pass' and 'effective_pass' keys on the ::Ok object?

What method should I use to check the 'todo' key on the ::Ok object? I cannot find a todo method in the documentation or code.

[exodist]

You have stumbled upon a rough edge, one I need to correct.

Currently, this is how Test2 checks these things in events, and I think I failed to provide a helpful/shortcut API to do what Test2 does, so I need to write that.

• Test2 grabs $event->facet_data, does not matter what class the event is, ::Ok, ::Diag, etc, it only looks at facet_data. The older events types (::ok, ::Diag, etc) which Test::Builder generates boil their data down into facet_data when asked.
• Test2 exclusively uses the facet_data
• If there is an assertion facet Test2 uses it to increment test count, and then checks pass, however it also looks at amnesty, if there is amnesty it honors that to forgive a failure.
• The TAP output is generated from the facet data.

See https://github.com/Test-More/test-more/blob/master/lib/Test2/Formatter/TAP.pm#L240 to see how the facets for an 'OK' are used.

So, basically you check $e->facet_data->{assert}->{pass} to check if the assertion was passing or failing BEFORE any TODO state is applied. Then you check if $e->facet_data->{amnesty} exists and has any content (if present it will be an arrayref). If it does then that means the failed assertion does not actually cause a failure. The amnesty items will have the todo messages.

I realize that while this is very expressive for tools, and allows a lot of flexibility, it makes it difficult for you to test the events you are intercepting. This is what I was hoping to fix with a better testing tool that I have not finished yet. If I have time this weekend I will try to at least get a minimum helper out that you can use to avoid jumping through these hoops.

Test2::Event::* (Except Test2::Event::Ev2) are legacy interfaces, all that really matters to test2 is the $e->facet_data hash structure.

[exodist]

Here is another bit of code to look at: https://github.com/Test-More/test-more/blob/master/lib/Test2/Hub.pm#L345 this is where Test2 maintains its internal pass/fail state from each event