Filename | /home/micha/.plenv/versions/5.38.2/lib/perl5/site_perl/5.38.2/Test2/API.pm |
Statements | Executed 341 statements in 3.95ms |
Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
---|---|---|---|---|---|
1 | 1 | 1 | 1.99ms | 8.02ms | BEGIN@51 | Test2::API::
1 | 1 | 1 | 475µs | 631µs | BEGIN@100 | Test2::API::
1 | 1 | 1 | 456µs | 1.89ms | BEGIN@5 | Test2::API::
1 | 1 | 1 | 429µs | 660µs | BEGIN@89 | Test2::API::
1 | 1 | 1 | 419µs | 535µs | BEGIN@95 | Test2::API::
1 | 1 | 1 | 403µs | 5.20ms | BEGIN@92 | Test2::API::
1 | 1 | 1 | 397µs | 586µs | BEGIN@88 | Test2::API::
1 | 1 | 1 | 230µs | 333µs | BEGIN@97 | Test2::API::
1 | 1 | 1 | 224µs | 306µs | BEGIN@99 | Test2::API::
8 | 1 | 1 | 221µs | 400µs | context | Test2::API::
1 | 1 | 1 | 206µs | 296µs | BEGIN@96 | Test2::API::
1 | 1 | 1 | 202µs | 284µs | BEGIN@93 | Test2::API::
1 | 1 | 1 | 200µs | 281µs | BEGIN@94 | Test2::API::
1 | 1 | 1 | 176µs | 239µs | BEGIN@98 | Test2::API::
1 | 1 | 1 | 110µs | 145µs | BEGIN@86 | Test2::API::
3 | 3 | 3 | 31µs | 188µs | test2_set_is_end | Test2::API::
1 | 1 | 1 | 25µs | 25µs | INIT | Test2::API::
4 | 3 | 2 | 14µs | 18µs | test2_in_preload | Test2::API::
1 | 1 | 1 | 10µs | 12µs | BEGIN@2 | Test2::API::
3 | 3 | 1 | 7µs | 18µs | release | Test2::API::
1 | 1 | 1 | 7µs | 7µs | BEGIN@179 | Test2::API::
1 | 1 | 1 | 7µs | 7µs | BEGIN@8 | Test2::API::
3 | 2 | 2 | 6µs | 491µs | test2_load | Test2::API::
1 | 1 | 1 | 5µs | 27µs | BEGIN@102 | Test2::API::
1 | 1 | 1 | 5µs | 18µs | BEGIN@71 | Test2::API::
1 | 1 | 1 | 5µs | 6µs | _context_release_callbacks_ref | Test2::API::
1 | 1 | 1 | 5µs | 8µs | test2_formatter_add | Test2::API::
1 | 1 | 1 | 5µs | 6µs | test2_stack | Test2::API::
1 | 1 | 1 | 4µs | 18µs | BEGIN@103 | Test2::API::
1 | 1 | 1 | 4µs | 18µs | BEGIN@6 | Test2::API::
1 | 1 | 1 | 4µs | 14µs | BEGIN@76 | Test2::API::
1 | 1 | 1 | 4µs | 21µs | BEGIN@3 | Test2::API::
1 | 1 | 1 | 4µs | 18µs | BEGIN@104 | Test2::API::
1 | 1 | 1 | 4µs | 5µs | test2_init_done | Test2::API::
1 | 1 | 1 | 3µs | 21µs | test2_formatter | Test2::API::
1 | 1 | 1 | 3µs | 3µs | BEGIN@75 | Test2::API::
1 | 1 | 1 | 3µs | 11µs | test2_add_callback_post_load | Test2::API::
1 | 1 | 1 | 2µs | 3µs | _contexts_ref | Test2::API::
1 | 1 | 1 | 2µs | 2µs | BEGIN@90 | Test2::API::
1 | 1 | 1 | 2µs | 5µs | test2_add_callback_context_aquire | Test2::API::
1 | 1 | 1 | 2µs | 3µs | test2_has_ipc | Test2::API::
1 | 1 | 1 | 2µs | 4µs | test2_add_callback_exit | Test2::API::
1 | 1 | 1 | 2µs | 4µs | test2_ipc | Test2::API::
1 | 1 | 1 | 2µs | 2µs | BEGIN@85 | Test2::API::
2 | 2 | 2 | 2µs | 2µs | _add_uuid_via_ref | Test2::API::
1 | 1 | 1 | 1µs | 2µs | test2_load_done | Test2::API::
1 | 1 | 1 | 700ns | 700ns | test2_unset_is_end | Test2::API::
1 | 1 | 1 | 600ns | 600ns | test2_stdout | Test2::API::
1 | 1 | 1 | 500ns | 500ns | test2_stderr | Test2::API::
0 | 0 | 0 | 0s | 0s | CLONE | Test2::API::
0 | 0 | 0 | 0s | 0s | __ANON__[:257] | Test2::API::
0 | 0 | 0 | 0s | 0s | __ANON__[:613] | Test2::API::
0 | 0 | 0 | 0s | 0s | __ANON__[:679] | Test2::API::
0 | 0 | 0 | 0s | 0s | __ANON__[:698] | Test2::API::
0 | 0 | 0 | 0s | 0s | _canon_error | Test2::API::
0 | 0 | 0 | 0s | 0s | _context_acquire_callbacks_ref | Test2::API::
0 | 0 | 0 | 0s | 0s | _context_init_callbacks_ref | Test2::API::
0 | 0 | 0 | 0s | 0s | _depth_error | Test2::API::
0 | 0 | 0 | 0s | 0s | _existing_error | Test2::API::
0 | 0 | 0 | 0s | 0s | _intercept | Test2::API::
0 | 0 | 0 | 0s | 0s | _set_ipc | Test2::API::
0 | 0 | 0 | 0s | 0s | context_do | Test2::API::
0 | 0 | 0 | 0s | 0s | intercept | Test2::API::
0 | 0 | 0 | 0s | 0s | intercept_deep | Test2::API::
0 | 0 | 0 | 0s | 0s | no_context | Test2::API::
0 | 0 | 0 | 0s | 0s | run_subtest | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_add_callback_context_acquire | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_add_callback_context_init | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_add_callback_context_release | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_add_callback_pre_subtest | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_add_callback_testing_done | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_add_uuid_via | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_disable_trace_stamps | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_enable_trace_stamps | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_formatter_set | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_formatters | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_get_is_end | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_add_driver | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_disable | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_disable_polling | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_disabled | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_drivers | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_enable_polling | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_enable_shm | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_get_pending | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_get_timeout | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_polling | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_set_pending | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_set_timeout | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_wait_disable | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_wait_enable | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_ipc_wait_enabled | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_is_testing_done | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_context_acquire_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_context_aquire_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_context_init_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_context_release_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_exit_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_post_load_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_list_pre_subtest_callbacks | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_no_wait | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_pid | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_post_preload_reset | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_reset_io | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_start_preload | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_stop_preload | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_tid | Test2::API::
0 | 0 | 0 | 0s | 0s | test2_trace_stamps_enabled | Test2::API::
Line | State ments |
Time on line |
Calls | Time in subs |
Code |
---|---|---|---|---|---|
1 | package Test2::API; | ||||
2 | 2 | 21µs | 2 | 14µs | # spent 12µs (10+2) within Test2::API::BEGIN@2 which was called:
# once (10µs+2µs) by Test::Builder::BEGIN@18 at line 2 # spent 12µs making 1 call to Test2::API::BEGIN@2
# spent 2µs making 1 call to strict::import |
3 | 2 | 18µs | 2 | 38µs | # spent 21µs (4+17) within Test2::API::BEGIN@3 which was called:
# once (4µs+17µs) by Test::Builder::BEGIN@18 at line 3 # spent 21µs making 1 call to Test2::API::BEGIN@3
# spent 17µs making 1 call to warnings::import |
4 | |||||
5 | 2 | 80µs | 2 | 3.18ms | # spent 1.89ms (456µs+1.44) within Test2::API::BEGIN@5 which was called:
# once (456µs+1.44ms) by Test::Builder::BEGIN@18 at line 5 # spent 1.89ms making 1 call to Test2::API::BEGIN@5
# spent 1.28ms making 1 call to Time::HiRes::import |
6 | 2 | 32µs | 2 | 33µs | # spent 18µs (4+14) within Test2::API::BEGIN@6 which was called:
# once (4µs+14µs) by Test::Builder::BEGIN@18 at line 6 # spent 18µs making 1 call to Test2::API::BEGIN@6
# spent 14µs making 1 call to Exporter::import |
7 | |||||
8 | # spent 7µs within Test2::API::BEGIN@8 which was called:
# once (7µs+0s) by Test::Builder::BEGIN@18 at line 11 | ||||
9 | 1 | 3µs | $ENV{TEST_ACTIVE} ||= 1; | ||
10 | 1 | 4µs | $ENV{TEST2_ACTIVE} = 1; | ||
11 | 1 | 130µs | 1 | 7µs | } # spent 7µs making 1 call to Test2::API::BEGIN@8 |
12 | |||||
13 | 1 | 400ns | our $VERSION = '1.302198'; | ||
14 | |||||
15 | |||||
16 | 1 | 200ns | my $INST; | ||
17 | 1 | 100ns | my $ENDING = 0; | ||
18 | 1 | 3µs | # spent 700ns within Test2::API::test2_unset_is_end which was called:
# once (700ns+0s) by Test::Builder::reset at line 434 of Test/Builder.pm | ||
19 | sub test2_get_is_end { $ENDING } | ||||
20 | |||||
21 | # spent 188µs (31+156) within Test2::API::test2_set_is_end which was called 3 times, avg 63µs/call:
# once (30µs+156µs) by Test2::API::END at line 1 of (eval 56)[Test2/API.pm:72]
# once (800ns+0s) by Test2::API::Instance::END at line 1 of (eval 7)[Test2/API/Instance.pm:319]
# once (400ns+0s) by Test2::API::END at line 55 | ||||
22 | 3 | 500ns | my $before = $ENDING; | ||
23 | 3 | 1µs | ($ENDING) = @_ ? @_ : (1); | ||
24 | |||||
25 | # Only send the event in a transition from false to true | ||||
26 | 3 | 2µs | return if $before; | ||
27 | 1 | 200ns | return unless $ENDING; | ||
28 | |||||
29 | 1 | 200ns | return unless $INST; | ||
30 | 1 | 2µs | 1 | 1µs | my $stack = $INST->stack or return; # spent 1µs making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
31 | 1 | 2µs | 1 | 2µs | my $root = $stack->root or return; # spent 2µs making 1 call to Test2::API::Stack::root |
32 | |||||
33 | 1 | 800ns | 1 | 500ns | return unless $root->count; # spent 500ns making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
34 | |||||
35 | 1 | 3µs | 1 | 2µs | return unless $$ == $INST->pid; # spent 2µs making 1 call to Test2::API::Instance::pid |
36 | 1 | 5µs | 2 | 2µs | return unless get_tid() == $INST->tid; # spent 1µs making 1 call to Test2::API::Instance::tid
# spent 800ns making 1 call to Test2::Util::__ANON__ |
37 | |||||
38 | 1 | 4µs | 1 | 12µs | my $trace = Test2::EventFacet::Trace->new( # spent 12µs making 1 call to Test2::Util::HashBase::_new |
39 | frame => [__PACKAGE__, __FILE__, __LINE__, __PACKAGE__ . '::test2_set_is_end'], | ||||
40 | ); | ||||
41 | 1 | 1µs | 1 | 21µs | my $ctx = Test2::API::Context->new( # spent 21µs making 1 call to Test2::Util::HashBase::_new |
42 | trace => $trace, | ||||
43 | hub => $root, | ||||
44 | ); | ||||
45 | |||||
46 | 1 | 3µs | 1 | 116µs | $ctx->send_ev2(control => { phase => 'END', details => 'Transition to END phase' }); # spent 116µs making 1 call to Test2::API::Context::send_ev2 |
47 | |||||
48 | 1 | 4µs | 1 | 700ns | 1; # spent 700ns making 1 call to Test2::API::Context::DESTROY |
49 | } | ||||
50 | |||||
51 | 2 | 137µs | 2 | 8.05ms | # spent 8.02ms (1.99+6.04) within Test2::API::BEGIN@51 which was called:
# once (1.99ms+6.04ms) by Test::Builder::BEGIN@18 at line 51 # spent 8.02ms making 1 call to Test2::API::BEGIN@51
# spent 26µs making 1 call to Test2::API::Instance::import |
52 | |||||
53 | # Set the exit status | ||||
54 | END { | ||||
55 | 1 | 400ns | 1 | 400ns | test2_set_is_end(); # See gh #16 # spent 400ns making 1 call to Test2::API::test2_set_is_end |
56 | 1 | 3µs | 1 | 113µs | $INST->set_exit(); # spent 113µs making 1 call to Test2::API::Instance::set_exit |
57 | } | ||||
58 | |||||
59 | sub CLONE { | ||||
60 | my $init = test2_init_done(); | ||||
61 | my $load = test2_load_done(); | ||||
62 | |||||
63 | return if $init && $load; | ||||
64 | |||||
65 | require Carp; | ||||
66 | Carp::croak "Test2 must be fully loaded before you start a new thread!\n"; | ||||
67 | } | ||||
68 | |||||
69 | # See gh #16 | ||||
70 | { | ||||
71 | 2 | 34µs | 2 | 32µs | # spent 18µs (5+13) within Test2::API::BEGIN@71 which was called:
# once (5µs+13µs) by Test::Builder::BEGIN@18 at line 71 # spent 18µs making 1 call to Test2::API::BEGIN@71
# spent 13µs making 1 call to warnings::unimport |
72 | 1 | 25µs | # spent 25µs within Test2::API::INIT which was called:
# once (25µs+0s) by main::RUNTIME at line 0 of /home/micha/Projekt/spreadsheet-parsexlsx/t/bug-md-11.t # spent 4µs executing statements in string eval # includes 8µs spent executing 2 calls to 1 sub defined therein. | ||
73 | } | ||||
74 | |||||
75 | 1 | 400ns | # spent 3µs within Test2::API::BEGIN@75 which was called:
# once (3µs+0s) by Test::Builder::BEGIN@18 at line 83 | ||
76 | 2 | 45µs | 2 | 24µs | # spent 14µs (4+10) within Test2::API::BEGIN@76 which was called:
# once (4µs+10µs) by Test::Builder::BEGIN@18 at line 76 # spent 14µs making 1 call to Test2::API::BEGIN@76
# spent 10µs making 1 call to warnings::unimport |
77 | 1 | 3µs | if($] ge '5.014' || $ENV{T2_CHECK_DEPTH} || $Test2::API::DO_DEPTH_CHECK) { | ||
78 | *DO_DEPTH_CHECK = sub() { 1 }; | ||||
79 | } | ||||
80 | else { | ||||
81 | *DO_DEPTH_CHECK = sub() { 0 }; | ||||
82 | } | ||||
83 | 1 | 13µs | 1 | 3µs | } # spent 3µs making 1 call to Test2::API::BEGIN@75 |
84 | |||||
85 | 2 | 10µs | 1 | 2µs | # spent 2µs within Test2::API::BEGIN@85 which was called:
# once (2µs+0s) by Test::Builder::BEGIN@18 at line 85 # spent 2µs making 1 call to Test2::API::BEGIN@85 |
86 | 2 | 82µs | 1 | 145µs | # spent 145µs (110+34) within Test2::API::BEGIN@86 which was called:
# once (110µs+34µs) by Test::Builder::BEGIN@18 at line 86 # spent 145µs making 1 call to Test2::API::BEGIN@86 |
87 | |||||
88 | 2 | 68µs | 1 | 586µs | # spent 586µs (397+188) within Test2::API::BEGIN@88 which was called:
# once (397µs+188µs) by Test::Builder::BEGIN@18 at line 88 # spent 586µs making 1 call to Test2::API::BEGIN@88 |
89 | 2 | 68µs | 1 | 660µs | # spent 660µs (429+231) within Test2::API::BEGIN@89 which was called:
# once (429µs+231µs) by Test::Builder::BEGIN@18 at line 89 # spent 660µs making 1 call to Test2::API::BEGIN@89 |
90 | 2 | 10µs | 1 | 2µs | # spent 2µs within Test2::API::BEGIN@90 which was called:
# once (2µs+0s) by Test::Builder::BEGIN@18 at line 90 # spent 2µs making 1 call to Test2::API::BEGIN@90 |
91 | |||||
92 | 2 | 102µs | 1 | 5.20ms | # spent 5.20ms (403µs+4.80) within Test2::API::BEGIN@92 which was called:
# once (403µs+4.80ms) by Test::Builder::BEGIN@18 at line 92 # spent 5.20ms making 1 call to Test2::API::BEGIN@92 |
93 | 2 | 68µs | 1 | 284µs | # spent 284µs (202+83) within Test2::API::BEGIN@93 which was called:
# once (202µs+83µs) by Test::Builder::BEGIN@18 at line 93 # spent 284µs making 1 call to Test2::API::BEGIN@93 |
94 | 2 | 69µs | 1 | 281µs | # spent 281µs (200+81) within Test2::API::BEGIN@94 which was called:
# once (200µs+81µs) by Test::Builder::BEGIN@18 at line 94 # spent 281µs making 1 call to Test2::API::BEGIN@94 |
95 | 2 | 74µs | 1 | 535µs | # spent 535µs (419+116) within Test2::API::BEGIN@95 which was called:
# once (419µs+116µs) by Test::Builder::BEGIN@18 at line 95 # spent 535µs making 1 call to Test2::API::BEGIN@95 |
96 | 2 | 68µs | 1 | 296µs | # spent 296µs (206+90) within Test2::API::BEGIN@96 which was called:
# once (206µs+90µs) by Test::Builder::BEGIN@18 at line 96 # spent 296µs making 1 call to Test2::API::BEGIN@96 |
97 | 2 | 72µs | 1 | 333µs | # spent 333µs (230+103) within Test2::API::BEGIN@97 which was called:
# once (230µs+103µs) by Test::Builder::BEGIN@18 at line 97 # spent 333µs making 1 call to Test2::API::BEGIN@97 |
98 | 2 | 68µs | 1 | 239µs | # spent 239µs (176+63) within Test2::API::BEGIN@98 which was called:
# once (176µs+63µs) by Test::Builder::BEGIN@18 at line 98 # spent 239µs making 1 call to Test2::API::BEGIN@98 |
99 | 2 | 71µs | 1 | 306µs | # spent 306µs (224+83) within Test2::API::BEGIN@99 which was called:
# once (224µs+83µs) by Test::Builder::BEGIN@18 at line 99 # spent 306µs making 1 call to Test2::API::BEGIN@99 |
100 | 2 | 80µs | 1 | 631µs | # spent 631µs (475+156) within Test2::API::BEGIN@100 which was called:
# once (475µs+156µs) by Test::Builder::BEGIN@18 at line 100 # spent 631µs making 1 call to Test2::API::BEGIN@100 |
101 | |||||
102 | 2 | 19µs | 2 | 50µs | # spent 27µs (5+22) within Test2::API::BEGIN@102 which was called:
# once (5µs+22µs) by Test::Builder::BEGIN@18 at line 102 # spent 27µs making 1 call to Test2::API::BEGIN@102
# spent 22µs making 1 call to Exporter::import |
103 | 2 | 16µs | 2 | 32µs | # spent 18µs (4+14) within Test2::API::BEGIN@103 which was called:
# once (4µs+14µs) by Test::Builder::BEGIN@18 at line 103 # spent 18µs making 1 call to Test2::API::BEGIN@103
# spent 14µs making 1 call to Exporter::import |
104 | 2 | 73µs | 2 | 33µs | # spent 18µs (4+15) within Test2::API::BEGIN@104 which was called:
# once (4µs+15µs) by Test::Builder::BEGIN@18 at line 104 # spent 18µs making 1 call to Test2::API::BEGIN@104
# spent 15µs making 1 call to Exporter::import |
105 | |||||
106 | 1 | 4µs | our @EXPORT_OK = qw{ | ||
107 | context release | ||||
108 | context_do | ||||
109 | no_context | ||||
110 | intercept intercept_deep | ||||
111 | run_subtest | ||||
112 | |||||
113 | test2_init_done | ||||
114 | test2_load_done | ||||
115 | test2_load | ||||
116 | test2_start_preload | ||||
117 | test2_stop_preload | ||||
118 | test2_in_preload | ||||
119 | test2_is_testing_done | ||||
120 | |||||
121 | test2_set_is_end | ||||
122 | test2_unset_is_end | ||||
123 | test2_get_is_end | ||||
124 | |||||
125 | test2_pid | ||||
126 | test2_tid | ||||
127 | test2_stack | ||||
128 | test2_no_wait | ||||
129 | test2_ipc_wait_enable | ||||
130 | test2_ipc_wait_disable | ||||
131 | test2_ipc_wait_enabled | ||||
132 | |||||
133 | test2_add_uuid_via | ||||
134 | |||||
135 | test2_add_callback_testing_done | ||||
136 | |||||
137 | test2_add_callback_context_aquire | ||||
138 | test2_add_callback_context_acquire | ||||
139 | test2_add_callback_context_init | ||||
140 | test2_add_callback_context_release | ||||
141 | test2_add_callback_exit | ||||
142 | test2_add_callback_post_load | ||||
143 | test2_add_callback_pre_subtest | ||||
144 | test2_list_context_aquire_callbacks | ||||
145 | test2_list_context_acquire_callbacks | ||||
146 | test2_list_context_init_callbacks | ||||
147 | test2_list_context_release_callbacks | ||||
148 | test2_list_exit_callbacks | ||||
149 | test2_list_post_load_callbacks | ||||
150 | test2_list_pre_subtest_callbacks | ||||
151 | |||||
152 | test2_ipc | ||||
153 | test2_has_ipc | ||||
154 | test2_ipc_disable | ||||
155 | test2_ipc_disabled | ||||
156 | test2_ipc_drivers | ||||
157 | test2_ipc_add_driver | ||||
158 | test2_ipc_polling | ||||
159 | test2_ipc_disable_polling | ||||
160 | test2_ipc_enable_polling | ||||
161 | test2_ipc_get_pending | ||||
162 | test2_ipc_set_pending | ||||
163 | test2_ipc_get_timeout | ||||
164 | test2_ipc_set_timeout | ||||
165 | |||||
166 | test2_formatter | ||||
167 | test2_formatters | ||||
168 | test2_formatter_add | ||||
169 | test2_formatter_set | ||||
170 | |||||
171 | test2_stdout | ||||
172 | test2_stderr | ||||
173 | test2_reset_io | ||||
174 | |||||
175 | test2_enable_trace_stamps | ||||
176 | test2_disable_trace_stamps | ||||
177 | test2_trace_stamps_enabled | ||||
178 | }; | ||||
179 | 2 | 1.97ms | 1 | 7µs | # spent 7µs within Test2::API::BEGIN@179 which was called:
# once (7µs+0s) by Test::Builder::BEGIN@18 at line 179 # spent 7µs making 1 call to Test2::API::BEGIN@179 |
180 | |||||
181 | 1 | 2µs | 1 | 2µs | my $STACK = $INST->stack; # spent 2µs making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
182 | 1 | 600ns | 1 | 500ns | my $CONTEXTS = $INST->contexts; # spent 500ns making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
183 | 1 | 400ns | 1 | 500ns | my $INIT_CBS = $INST->context_init_callbacks; # spent 500ns making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
184 | 1 | 500ns | 1 | 400ns | my $ACQUIRE_CBS = $INST->context_acquire_callbacks; # spent 400ns making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
185 | |||||
186 | 1 | 1µs | 1 | 48µs | my $STDOUT = clone_io(\*STDOUT); # spent 48µs making 1 call to Test2::Util::clone_io |
187 | 1 | 800ns | 1 | 22µs | my $STDERR = clone_io(\*STDERR); # spent 22µs making 1 call to Test2::Util::clone_io |
188 | 1 | 1µs | # spent 600ns within Test2::API::test2_stdout which was called:
# once (600ns+0s) by Test2::Formatter::TAP::_open_handles at line 57 of Test2/Formatter/TAP.pm | ||
189 | 1 | 6µs | # spent 500ns within Test2::API::test2_stderr which was called:
# once (500ns+0s) by Test2::Formatter::TAP::_open_handles at line 58 of Test2/Formatter/TAP.pm | ||
190 | |||||
191 | sub test2_post_preload_reset { | ||||
192 | test2_reset_io(); | ||||
193 | $INST->post_preload_reset; | ||||
194 | } | ||||
195 | |||||
196 | sub test2_reset_io { | ||||
197 | $STDOUT = clone_io(\*STDOUT); | ||||
198 | $STDERR = clone_io(\*STDERR); | ||||
199 | } | ||||
200 | |||||
201 | 1 | 3µs | 1 | 1µs | # spent 5µs (4+1) within Test2::API::test2_init_done which was called:
# once (4µs+1µs) by Test::Builder::BEGIN@20 at line 21 of Test/Builder.pm # spent 1µs making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
202 | 1 | 1µs | 1 | 700ns | # spent 2µs (1+700ns) within Test2::API::test2_load_done which was called:
# once (1µs+700ns) by Test::Builder::BEGIN@20 at line 21 of Test/Builder.pm # spent 700ns making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
203 | |||||
204 | 3 | 6µs | 3 | 485µs | # spent 491µs (6+485) within Test2::API::test2_load which was called 3 times, avg 164µs/call:
# 2 times (3µs+483µs) by Test::Builder::Module::import at line 78 of Test/Builder/Module.pm, avg 243µs/call
# once (3µs+2µs) by Test::Builder::INIT at line 134 of Test/Builder.pm # spent 485µs making 3 calls to Test2::API::Instance::load, avg 162µs/call |
205 | sub test2_start_preload { $ENV{T2_IN_PRELOAD} = 1; $INST->start_preload } | ||||
206 | sub test2_stop_preload { $ENV{T2_IN_PRELOAD} = 0; $INST->stop_preload } | ||||
207 | 4 | 10µs | 4 | 4µs | # spent 18µs (14+4) within Test2::API::test2_in_preload which was called 4 times, avg 5µs/call:
# 2 times (8µs+2µs) by Test::Builder::Module::import at line 78 of Test/Builder/Module.pm, avg 5µs/call
# once (4µs+2µs) by Test::Builder::INIT at line 134 of Test/Builder.pm
# once (2µs+600ns) by Test::Builder::reset at line 443 of Test/Builder.pm # spent 4µs making 4 calls to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84], avg 1µs/call |
208 | |||||
209 | sub test2_pid { $INST->pid } | ||||
210 | sub test2_tid { $INST->tid } | ||||
211 | 1 | 3µs | 1 | 1µs | # spent 6µs (5+1) within Test2::API::test2_stack which was called:
# once (5µs+1µs) by Test::Builder::create at line 168 of Test/Builder.pm # spent 1µs making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
212 | sub test2_ipc_wait_enable { $INST->set_no_wait(0) } | ||||
213 | sub test2_ipc_wait_disable { $INST->set_no_wait(1) } | ||||
214 | sub test2_ipc_wait_enabled { !$INST->no_wait } | ||||
215 | |||||
216 | sub test2_enable_trace_stamps { $INST->test2_enable_trace_stamps } | ||||
217 | sub test2_disable_trace_stamps { $INST->test2_disable_trace_stamps } | ||||
218 | sub test2_trace_stamps_enabled { $INST->test2_trace_stamps_enabled } | ||||
219 | |||||
220 | sub test2_is_testing_done { | ||||
221 | # No instance? VERY DONE! | ||||
222 | return 1 unless $INST; | ||||
223 | |||||
224 | # No stack? tests must be done, it is created pretty early | ||||
225 | my $stack = $INST->stack or return 1; | ||||
226 | |||||
227 | # Nothing on the stack, no root hub yet, likely have not started testing | ||||
228 | return 0 unless @$stack; | ||||
229 | |||||
230 | # Stack has a slot for the root hub (see above) but it is undefined, likely | ||||
231 | # garbage collected, test is done | ||||
232 | my $root_hub = $stack->[0] or return 1; | ||||
233 | |||||
234 | # If the root hub is ended than testing is done. | ||||
235 | return 1 if $root_hub->ended; | ||||
236 | |||||
237 | # Looks like we are still testing! | ||||
238 | return 0; | ||||
239 | } | ||||
240 | |||||
241 | sub test2_no_wait { | ||||
242 | $INST->set_no_wait(@_) if @_; | ||||
243 | $INST->no_wait; | ||||
244 | } | ||||
245 | |||||
246 | sub test2_add_callback_testing_done { | ||||
247 | my $cb = shift; | ||||
248 | |||||
249 | test2_add_callback_post_load(sub { | ||||
250 | my $stack = test2_stack(); | ||||
251 | $stack->top; # Ensure we have a hub | ||||
252 | my ($hub) = Test2::API::test2_stack->all; | ||||
253 | |||||
254 | $hub->set_active(1); | ||||
255 | |||||
256 | $hub->follow_up($cb); | ||||
257 | }); | ||||
258 | |||||
259 | return; | ||||
260 | } | ||||
261 | |||||
262 | sub test2_add_callback_context_acquire { $INST->add_context_acquire_callback(@_) } | ||||
263 | 1 | 2µs | 1 | 3µs | # spent 5µs (2+3) within Test2::API::test2_add_callback_context_aquire which was called:
# once (2µs+3µs) by Test::Builder::new at line 154 of Test/Builder.pm # spent 3µs making 1 call to Test2::API::Instance::add_context_acquire_callback |
264 | sub test2_add_callback_context_init { $INST->add_context_init_callback(@_) } | ||||
265 | sub test2_add_callback_context_release { $INST->add_context_release_callback(@_) } | ||||
266 | 1 | 2µs | 1 | 3µs | # spent 4µs (2+3) within Test2::API::test2_add_callback_exit which was called:
# once (2µs+3µs) by Test::Builder::new at line 156 of Test/Builder.pm # spent 3µs making 1 call to Test2::API::Instance::add_exit_callback |
267 | 1 | 2µs | 1 | 8µs | # spent 11µs (3+8) within Test2::API::test2_add_callback_post_load which was called:
# once (3µs+8µs) by Test::Builder::new at line 149 of Test/Builder.pm # spent 8µs making 1 call to Test2::API::Instance::add_post_load_callback |
268 | sub test2_add_callback_pre_subtest { $INST->add_pre_subtest_callback(@_) } | ||||
269 | sub test2_list_context_aquire_callbacks { @{$INST->context_acquire_callbacks} } | ||||
270 | sub test2_list_context_acquire_callbacks { @{$INST->context_acquire_callbacks} } | ||||
271 | sub test2_list_context_init_callbacks { @{$INST->context_init_callbacks} } | ||||
272 | sub test2_list_context_release_callbacks { @{$INST->context_release_callbacks} } | ||||
273 | sub test2_list_exit_callbacks { @{$INST->exit_callbacks} } | ||||
274 | sub test2_list_post_load_callbacks { @{$INST->post_load_callbacks} } | ||||
275 | sub test2_list_pre_subtest_callbacks { @{$INST->pre_subtest_callbacks} } | ||||
276 | |||||
277 | sub test2_add_uuid_via { | ||||
278 | $INST->set_add_uuid_via(@_) if @_; | ||||
279 | $INST->add_uuid_via(); | ||||
280 | } | ||||
281 | |||||
282 | 1 | 2µs | 1 | 3µs | # spent 4µs (2+3) within Test2::API::test2_ipc which was called:
# once (2µs+3µs) by Test2::API::Stack::new_hub at line 33 of Test2/API/Stack.pm # spent 3µs making 1 call to Test2::API::Instance::__ANON__[Test2/API/Instance.pm:60] |
283 | 1 | 2µs | 1 | 1µs | # spent 3µs (2+1) within Test2::API::test2_has_ipc which was called:
# once (2µs+1µs) by Test::Builder::new at line 158 of Test/Builder.pm # spent 1µs making 1 call to Test2::API::Instance::has_ipc |
284 | sub test2_ipc_disable { $INST->ipc_disable } | ||||
285 | sub test2_ipc_disabled { $INST->ipc_disabled } | ||||
286 | sub test2_ipc_add_driver { $INST->add_ipc_driver(@_) } | ||||
287 | sub test2_ipc_drivers { @{$INST->ipc_drivers} } | ||||
288 | sub test2_ipc_polling { $INST->ipc_polling } | ||||
289 | sub test2_ipc_enable_polling { $INST->enable_ipc_polling } | ||||
290 | sub test2_ipc_disable_polling { $INST->disable_ipc_polling } | ||||
291 | sub test2_ipc_get_pending { $INST->get_ipc_pending } | ||||
292 | sub test2_ipc_set_pending { $INST->set_ipc_pending(@_) } | ||||
293 | sub test2_ipc_set_timeout { $INST->set_ipc_timeout(@_) } | ||||
294 | sub test2_ipc_get_timeout { $INST->ipc_timeout() } | ||||
295 | sub test2_ipc_enable_shm { 0 } | ||||
296 | |||||
297 | # spent 21µs (3+18) within Test2::API::test2_formatter which was called:
# once (3µs+18µs) by Test2::API::Stack::new_hub at line 31 of Test2/API/Stack.pm | ||||
298 | 1 | 300ns | if ($ENV{T2_FORMATTER} && $ENV{T2_FORMATTER} =~ m/^(\+)?(.*)$/) { | ||
299 | my $formatter = $1 ? $2 : "Test2::Formatter::$2"; | ||||
300 | my $file = pkg_to_file($formatter); | ||||
301 | require $file; | ||||
302 | return $formatter; | ||||
303 | } | ||||
304 | |||||
305 | 1 | 2µs | 1 | 18µs | return $INST->formatter; # spent 18µs making 1 call to Test2::API::Instance::__ANON__[Test2/API/Instance.pm:60] |
306 | } | ||||
307 | |||||
308 | sub test2_formatters { @{$INST->formatters} } | ||||
309 | 1 | 3µs | 1 | 3µs | # spent 8µs (5+3) within Test2::API::test2_formatter_add which was called:
# once (5µs+3µs) by Test2::Formatter::import at line 14 of Test2/Formatter.pm # spent 3µs making 1 call to Test2::API::Instance::add_formatter |
310 | sub test2_formatter_set { | ||||
311 | my ($formatter) = @_; | ||||
312 | croak "No formatter specified" unless $formatter; | ||||
313 | croak "Global Formatter already set" if $INST->formatter_set; | ||||
314 | $INST->set_formatter($formatter); | ||||
315 | } | ||||
316 | |||||
317 | # Private, for use in Test2::API::Context | ||||
318 | 1 | 2µs | 1 | 500ns | # spent 3µs (2+500ns) within Test2::API::_contexts_ref which was called:
# once (2µs+500ns) by Test::Builder::BEGIN@18 at line 34 of Test2/API/Context.pm # spent 500ns making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
319 | sub _context_acquire_callbacks_ref { $INST->context_acquire_callbacks } | ||||
320 | sub _context_init_callbacks_ref { $INST->context_init_callbacks } | ||||
321 | 1 | 3µs | 1 | 1µs | # spent 6µs (5+1) within Test2::API::_context_release_callbacks_ref which was called:
# once (5µs+1µs) by Test::Builder::BEGIN@18 at line 33 of Test2/API/Context.pm # spent 1µs making 1 call to Test2::Util::HashBase::__ANON__[Test2/Util/HashBase.pm:84] |
322 | 2 | 6µs | # spent 2µs within Test2::API::_add_uuid_via_ref which was called 2 times, avg 800ns/call:
# once (900ns+0s) by Test::Builder::BEGIN@18 at line 370
# once (700ns+0s) by Test2::Hub::init at line 48 of Test2/Hub.pm | ||
323 | |||||
324 | # Private, for use in Test2::IPC | ||||
325 | sub _set_ipc { $INST->set_ipc(@_) } | ||||
326 | |||||
327 | sub context_do(&;@) { | ||||
328 | my $code = shift; | ||||
329 | my @args = @_; | ||||
330 | |||||
331 | my $ctx = context(level => 1); | ||||
332 | |||||
333 | my $want = wantarray; | ||||
334 | |||||
335 | my @out; | ||||
336 | my $ok = eval { | ||||
337 | $want ? @out = $code->($ctx, @args) : | ||||
338 | defined($want) ? $out[0] = $code->($ctx, @args) : | ||||
339 | $code->($ctx, @args) ; | ||||
340 | 1; | ||||
341 | }; | ||||
342 | my $err = $@; | ||||
343 | |||||
344 | $ctx->release; | ||||
345 | |||||
346 | die $err unless $ok; | ||||
347 | |||||
348 | return @out if $want; | ||||
349 | return $out[0] if defined $want; | ||||
350 | return; | ||||
351 | } | ||||
352 | |||||
353 | sub no_context(&;$) { | ||||
354 | my ($code, $hid) = @_; | ||||
355 | $hid ||= $STACK->top->hid; | ||||
356 | |||||
357 | my $ctx = $CONTEXTS->{$hid}; | ||||
358 | delete $CONTEXTS->{$hid}; | ||||
359 | my $ok = eval { $code->(); 1 }; | ||||
360 | my $err = $@; | ||||
361 | |||||
362 | $CONTEXTS->{$hid} = $ctx; | ||||
363 | weaken($CONTEXTS->{$hid}); | ||||
364 | |||||
365 | die $err unless $ok; | ||||
366 | |||||
367 | return; | ||||
368 | }; | ||||
369 | |||||
370 | 1 | 700ns | 1 | 900ns | my $UUID_VIA = _add_uuid_via_ref(); # spent 900ns making 1 call to Test2::API::_add_uuid_via_ref |
371 | # spent 400µs (221+179) within Test2::API::context which was called 8 times, avg 50µs/call:
# 8 times (221µs+179µs) by Test::Builder::ctx at line 193 of Test/Builder.pm, avg 50µs/call | ||||
372 | # We need to grab these before anything else to ensure they are not | ||||
373 | # changed. | ||||
374 | 8 | 12µs | my ($errno, $eval_error, $child_error, $extended_error) = (0 + $!, $@, $?, $^E); | ||
375 | |||||
376 | 8 | 14µs | my %params = (level => 0, wrapped => 0, @_); | ||
377 | |||||
378 | # If something is getting a context then the sync system needs to be | ||||
379 | # considered loaded... | ||||
380 | 8 | 2µs | $INST->load unless $INST->{loaded}; | ||
381 | |||||
382 | 8 | 1µs | croak "context() called, but return value is ignored" | ||
383 | unless defined wantarray; | ||||
384 | |||||
385 | 8 | 3µs | my $stack = $params{stack} || $STACK; | ||
386 | 8 | 5µs | 1 | 157µs | my $hub = $params{hub} || (@$stack ? $stack->[-1] : $stack->top); # spent 157µs making 1 call to Test2::API::Stack::top |
387 | |||||
388 | # Catch an edge case where we try to get context after the root hub has | ||||
389 | # been garbage collected resulting in a stack that has a single undef | ||||
390 | # hub | ||||
391 | 8 | 4µs | if (!($hub && $hub->{hid}) && !exists($params{hub}) && @$stack) { | ||
392 | my $msg; | ||||
393 | |||||
394 | if ($hub && !$hub->{hid}) { | ||||
395 | $msg = Carp::longmess("$hub has no hid! (did you attempt a testing event after done_testing?). You may be relying on a tool or plugin that was based off an old Test2 that did not require hids."); | ||||
396 | } | ||||
397 | else { | ||||
398 | $msg = Carp::longmess("Attempt to get Test2 context after testing has completed (did you attempt a testing event after done_testing?)"); | ||||
399 | } | ||||
400 | |||||
401 | # The error message is usually masked by the global destruction, so we have to print to STDER | ||||
402 | print STDERR $msg; | ||||
403 | |||||
404 | # Make sure this is a failure, we are probably already in END, so set $? to change the exit code | ||||
405 | $? = 1; | ||||
406 | |||||
407 | # Now we actually die to interrupt the program flow and avoid undefined his warnings | ||||
408 | die $msg; | ||||
409 | } | ||||
410 | |||||
411 | 8 | 2µs | my $hid = $hub->{hid}; | ||
412 | 8 | 2µs | my $current = $CONTEXTS->{$hid}; | ||
413 | |||||
414 | 8 | 11µs | 8 | 7µs | $_->(\%params) for @$ACQUIRE_CBS; # spent 7µs making 8 calls to Test::Builder::__ANON__[Test/Builder.pm:154], avg 862ns/call |
415 | 8 | 2µs | map $_->(\%params), @{$hub->{_context_acquire}} if $hub->{_context_acquire}; | ||
416 | |||||
417 | # This is for https://github.com/Test-More/test-more/issues/16 | ||||
418 | # and https://rt.perl.org/Public/Bug/Display.html?id=127774 | ||||
419 | 8 | 5µs | my $phase = ${^GLOBAL_PHASE} || 'NA'; | ||
420 | 8 | 4µs | my $end_phase = $ENDING || $phase eq 'END' || $phase eq 'DESTRUCT'; | ||
421 | |||||
422 | 8 | 2µs | my $level = 1 + $params{level}; | ||
423 | 8 | 20µs | my ($pkg, $file, $line, $sub, @other) = $end_phase ? caller(0) : caller($level); | ||
424 | 8 | 900ns | unless ($pkg || $end_phase) { | ||
425 | confess "Could not find context at depth $level" unless $params{fudge}; | ||||
426 | ($pkg, $file, $line, $sub, @other) = caller(--$level) while ($level >= 0 && !$pkg); | ||||
427 | } | ||||
428 | |||||
429 | 8 | 1µs | my $depth = $level; | ||
430 | 8 | 16µs | $depth++ while DO_DEPTH_CHECK && !$end_phase && (!$current || $depth <= $current->{_depth} + $params{wrapped}) && caller($depth + 1); | ||
431 | 8 | 2µs | $depth -= $params{wrapped}; | ||
432 | 8 | 2µs | my $depth_ok = !DO_DEPTH_CHECK || $end_phase || !$current || $current->{_depth} < $depth; | ||
433 | |||||
434 | 8 | 1µs | if ($current && $params{on_release} && $depth_ok) { | ||
435 | $current->{_on_release} ||= []; | ||||
436 | push @{$current->{_on_release}} => $params{on_release}; | ||||
437 | } | ||||
438 | |||||
439 | # I know this is ugly.... | ||||
440 | 8 | 25µs | ($!, $@, $?, $^E) = ($errno, $eval_error, $child_error, $extended_error) and return bless( | ||
441 | { | ||||
442 | %$current, | ||||
443 | _is_canon => undef, | ||||
444 | errno => $errno, | ||||
445 | eval_error => $eval_error, | ||||
446 | child_error => $child_error, | ||||
447 | _is_spawn => [$pkg, $file, $line, $sub], | ||||
448 | }, | ||||
449 | 'Test2::API::Context' | ||||
450 | ) if $current && $depth_ok; | ||||
451 | |||||
452 | # Handle error condition of bad level | ||||
453 | 4 | 700ns | if ($current) { | ||
454 | unless (${$current->{_aborted}}) { | ||||
455 | _canon_error($current, [$pkg, $file, $line, $sub, $depth]) | ||||
456 | unless $current->{_is_canon}; | ||||
457 | |||||
458 | _depth_error($current, [$pkg, $file, $line, $sub, $depth]) | ||||
459 | unless $depth_ok; | ||||
460 | } | ||||
461 | |||||
462 | $current->release if $current->{_is_canon}; | ||||
463 | |||||
464 | delete $CONTEXTS->{$hid}; | ||||
465 | } | ||||
466 | |||||
467 | # Directly bless the object here, calling new is a noticeable performance | ||||
468 | # hit with how often this needs to be called. | ||||
469 | my $trace = bless( | ||||
470 | { | ||||
471 | frame => [$pkg, $file, $line, $sub], | ||||
472 | pid => $$, | ||||
473 | tid => get_tid(), | ||||
474 | cid => gen_uid(), | ||||
475 | hid => $hid, | ||||
476 | nested => $hub->{nested}, | ||||
477 | buffered => $hub->{buffered}, | ||||
478 | |||||
479 | full_caller => [$pkg, $file, $line, $sub, @other], | ||||
480 | |||||
481 | $INST->{trace_stamps} ? (stamp => time()) : (), | ||||
482 | |||||
483 | $$UUID_VIA ? ( | ||||
484 | huuid => $hub->{uuid}, | ||||
485 | 4 | 28µs | 4 | 10µs | uuid => ${$UUID_VIA}->('context'), # spent 10µs making 4 calls to Test2::Util::gen_uid, avg 2µs/call |
486 | ) : (), | ||||
487 | }, | ||||
488 | 'Test2::EventFacet::Trace' | ||||
489 | ); | ||||
490 | |||||
491 | # Directly bless the object here, calling new is a noticeable performance | ||||
492 | # hit with how often this needs to be called. | ||||
493 | 4 | 700ns | my $aborted = 0; | ||
494 | $current = bless( | ||||
495 | { | ||||
496 | _aborted => \$aborted, | ||||
497 | stack => $stack, | ||||
498 | hub => $hub, | ||||
499 | trace => $trace, | ||||
500 | _is_canon => 1, | ||||
501 | _depth => $depth, | ||||
502 | errno => $errno, | ||||
503 | eval_error => $eval_error, | ||||
504 | child_error => $child_error, | ||||
505 | 4 | 11µs | $params{on_release} ? (_on_release => [$params{on_release}]) : (), | ||
506 | }, | ||||
507 | 'Test2::API::Context' | ||||
508 | ); | ||||
509 | |||||
510 | 4 | 2µs | $CONTEXTS->{$hid} = $current; | ||
511 | 4 | 19µs | 4 | 5µs | weaken($CONTEXTS->{$hid}); # spent 5µs making 4 calls to Scalar::Util::weaken, avg 1µs/call |
512 | |||||
513 | 4 | 2µs | $_->($current) for @$INIT_CBS; | ||
514 | 4 | 1µs | map $_->($current), @{$hub->{_context_init}} if $hub->{_context_init}; | ||
515 | |||||
516 | 4 | 900ns | $params{on_init}->($current) if $params{on_init}; | ||
517 | |||||
518 | 4 | 7µs | ($!, $@, $?, $^E) = ($errno, $eval_error, $child_error, $extended_error); | ||
519 | |||||
520 | 4 | 9µs | return $current; | ||
521 | } | ||||
522 | |||||
523 | sub _depth_error { | ||||
524 | _existing_error(@_, <<" EOT"); | ||||
525 | context() was called to retrieve an existing context, however the existing | ||||
526 | context was created in a stack frame at the same, or deeper level. This usually | ||||
527 | means that a tool failed to release the context when it was finished. | ||||
528 | EOT | ||||
529 | } | ||||
530 | |||||
531 | sub _canon_error { | ||||
532 | _existing_error(@_, <<" EOT"); | ||||
533 | context() was called to retrieve an existing context, however the existing | ||||
534 | context has an invalid internal state (!_canon_count). This should not normally | ||||
535 | happen unless something is mucking about with internals... | ||||
536 | EOT | ||||
537 | } | ||||
538 | |||||
539 | sub _existing_error { | ||||
540 | my ($ctx, $details, $msg) = @_; | ||||
541 | my ($pkg, $file, $line, $sub, $depth) = @$details; | ||||
542 | |||||
543 | my $oldframe = $ctx->{trace}->frame; | ||||
544 | my $olddepth = $ctx->{_depth}; | ||||
545 | |||||
546 | # Older versions of Carp do not export longmess() function, so it needs to be called with package name | ||||
547 | my $mess = Carp::longmess(); | ||||
548 | |||||
549 | warn <<" EOT"; | ||||
550 | $msg | ||||
551 | Old context details: | ||||
552 | File: $oldframe->[1] | ||||
553 | Line: $oldframe->[2] | ||||
554 | Tool: $oldframe->[3] | ||||
555 | Depth: $olddepth | ||||
556 | |||||
557 | New context details: | ||||
558 | File: $file | ||||
559 | Line: $line | ||||
560 | Tool: $sub | ||||
561 | Depth: $depth | ||||
562 | |||||
563 | Trace: $mess | ||||
564 | |||||
565 | Removing the old context and creating a new one... | ||||
566 | EOT | ||||
567 | } | ||||
568 | |||||
569 | # spent 18µs (7+10) within Test2::API::release which was called 3 times, avg 6µs/call:
# once (2µs+5µs) by Test::Builder::done_testing at line 620 of Test/Builder.pm
# once (3µs+3µs) by Test::Builder::current_test at line 1464 of Test/Builder.pm
# once (2µs+2µs) by Test::Builder::use_numbers at line 1229 of Test/Builder.pm | ||||
570 | 3 | 2µs | 3 | 10µs | $_[0]->release; # spent 10µs making 3 calls to Test2::API::Context::release, avg 3µs/call |
571 | 3 | 4µs | return $_[1]; | ||
572 | } | ||||
573 | |||||
574 | sub intercept(&) { | ||||
575 | my $code = shift; | ||||
576 | my $ctx = context(); | ||||
577 | |||||
578 | my $events = _intercept($code, deep => 0); | ||||
579 | |||||
580 | $ctx->release; | ||||
581 | |||||
582 | return $events; | ||||
583 | } | ||||
584 | |||||
585 | sub intercept_deep(&) { | ||||
586 | my $code = shift; | ||||
587 | my $ctx = context(); | ||||
588 | |||||
589 | my $events = _intercept($code, deep => 1); | ||||
590 | |||||
591 | $ctx->release; | ||||
592 | |||||
593 | return $events; | ||||
594 | } | ||||
595 | |||||
596 | sub _intercept { | ||||
597 | my $code = shift; | ||||
598 | my %params = @_; | ||||
599 | my $ctx = context(); | ||||
600 | |||||
601 | my $ipc; | ||||
602 | if (my $global_ipc = test2_ipc()) { | ||||
603 | my $driver = blessed($global_ipc); | ||||
604 | $ipc = $driver->new; | ||||
605 | } | ||||
606 | |||||
607 | my $hub = Test2::Hub::Interceptor->new( | ||||
608 | ipc => $ipc, | ||||
609 | no_ending => 1, | ||||
610 | ); | ||||
611 | |||||
612 | my @events; | ||||
613 | $hub->listen(sub { push @events => $_[1] }, inherit => $params{deep}); | ||||
614 | |||||
615 | $ctx->stack->top; # Make sure there is a top hub before we begin. | ||||
616 | $ctx->stack->push($hub); | ||||
617 | |||||
618 | my $trace = $ctx->trace; | ||||
619 | my $state = {}; | ||||
620 | $hub->clean_inherited(trace => $trace, state => $state); | ||||
621 | |||||
622 | my ($ok, $err) = (1, undef); | ||||
623 | T2_SUBTEST_WRAPPER: { | ||||
624 | # Do not use 'try' cause it localizes __DIE__ | ||||
625 | $ok = eval { $code->(hub => $hub, context => $ctx->snapshot); 1 }; | ||||
626 | $err = $@; | ||||
627 | |||||
628 | # They might have done 'BEGIN { skip_all => "whatever" }' | ||||
629 | if (!$ok && $err =~ m/Label not found for "last T2_SUBTEST_WRAPPER"/ || (blessed($err) && $err->isa('Test2::Hub::Interceptor::Terminator'))) { | ||||
630 | $ok = 1; | ||||
631 | $err = undef; | ||||
632 | } | ||||
633 | } | ||||
634 | |||||
635 | $hub->cull; | ||||
636 | $ctx->stack->pop($hub); | ||||
637 | |||||
638 | $hub->restore_inherited(trace => $trace, state => $state); | ||||
639 | |||||
640 | $ctx->release; | ||||
641 | |||||
642 | die $err unless $ok; | ||||
643 | |||||
644 | $hub->finalize($trace, 1) | ||||
645 | if $ok | ||||
646 | && !$hub->no_ending | ||||
647 | && !$hub->ended; | ||||
648 | |||||
649 | require Test2::API::InterceptResult; | ||||
650 | return Test2::API::InterceptResult->new_from_ref(\@events); | ||||
651 | } | ||||
652 | |||||
653 | sub run_subtest { | ||||
654 | my ($name, $code, $params, @args) = @_; | ||||
655 | |||||
656 | $_->($name,$code,@args) | ||||
657 | for Test2::API::test2_list_pre_subtest_callbacks(); | ||||
658 | |||||
659 | $params = {buffered => $params} unless ref $params; | ||||
660 | my $inherit_trace = delete $params->{inherit_trace}; | ||||
661 | |||||
662 | my $ctx = context(); | ||||
663 | |||||
664 | my $parent = $ctx->hub; | ||||
665 | |||||
666 | # If a parent is buffered then the child must be as well. | ||||
667 | my $buffered = $params->{buffered} || $parent->{buffered}; | ||||
668 | |||||
669 | $ctx->note($name) unless $buffered; | ||||
670 | |||||
671 | my $stack = $ctx->stack || $STACK; | ||||
672 | my $hub = $stack->new_hub( | ||||
673 | class => 'Test2::Hub::Subtest', | ||||
674 | %$params, | ||||
675 | buffered => $buffered, | ||||
676 | ); | ||||
677 | |||||
678 | my @events; | ||||
679 | $hub->listen(sub { push @events => $_[1] }); | ||||
680 | |||||
681 | if ($buffered) { | ||||
682 | if (my $format = $hub->format) { | ||||
683 | my $hide = $format->can('hide_buffered') ? $format->hide_buffered : 1; | ||||
684 | $hub->format(undef) if $hide; | ||||
685 | } | ||||
686 | } | ||||
687 | |||||
688 | if ($inherit_trace) { | ||||
689 | my $orig = $code; | ||||
690 | $code = sub { | ||||
691 | my $base_trace = $ctx->trace; | ||||
692 | my $trace = $base_trace->snapshot(nested => 1 + $base_trace->nested); | ||||
693 | my $st_ctx = Test2::API::Context->new( | ||||
694 | trace => $trace, | ||||
695 | hub => $hub, | ||||
696 | ); | ||||
697 | $st_ctx->do_in_context($orig, @args); | ||||
698 | }; | ||||
699 | } | ||||
700 | |||||
701 | my $start_stamp = time; | ||||
702 | |||||
703 | my ($ok, $err, $finished); | ||||
704 | T2_SUBTEST_WRAPPER: { | ||||
705 | # Do not use 'try' cause it localizes __DIE__ | ||||
706 | $ok = eval { $code->(@args); 1 }; | ||||
707 | $err = $@; | ||||
708 | |||||
709 | # They might have done 'BEGIN { skip_all => "whatever" }' | ||||
710 | if (!$ok && $err =~ m/Label not found for "last T2_SUBTEST_WRAPPER"/ || (blessed($err) && blessed($err) eq 'Test::Builder::Exception')) { | ||||
711 | $ok = undef; | ||||
712 | $err = undef; | ||||
713 | } | ||||
714 | else { | ||||
715 | $finished = 1; | ||||
716 | } | ||||
717 | } | ||||
718 | |||||
719 | my $stop_stamp = time; | ||||
720 | |||||
721 | if ($params->{no_fork}) { | ||||
722 | if ($$ != $ctx->trace->pid) { | ||||
723 | warn $ok ? "Forked inside subtest, but subtest never finished!\n" : $err; | ||||
724 | exit 255; | ||||
725 | } | ||||
726 | |||||
727 | if (get_tid() != $ctx->trace->tid) { | ||||
728 | warn $ok ? "Started new thread inside subtest, but thread never finished!\n" : $err; | ||||
729 | exit 255; | ||||
730 | } | ||||
731 | } | ||||
732 | elsif (!$parent->is_local && !$parent->ipc) { | ||||
733 | warn $ok ? "A new process or thread was started inside subtest, but IPC is not enabled!\n" : $err; | ||||
734 | exit 255; | ||||
735 | } | ||||
736 | |||||
737 | $stack->pop($hub); | ||||
738 | |||||
739 | my $trace = $ctx->trace; | ||||
740 | |||||
741 | my $bailed = $hub->bailed_out; | ||||
742 | |||||
743 | if (!$finished) { | ||||
744 | if ($bailed && !$buffered) { | ||||
745 | $ctx->bail($bailed->reason); | ||||
746 | } | ||||
747 | elsif ($bailed && $buffered) { | ||||
748 | $ok = 1; | ||||
749 | } | ||||
750 | else { | ||||
751 | my $code = $hub->exit_code; | ||||
752 | $ok = !$code; | ||||
753 | $err = "Subtest ended with exit code $code" if $code; | ||||
754 | } | ||||
755 | } | ||||
756 | |||||
757 | $hub->finalize($trace->snapshot(huuid => $hub->uuid, hid => $hub->hid, nested => $hub->nested, buffered => $buffered), 1) | ||||
758 | if $ok | ||||
759 | && !$hub->no_ending | ||||
760 | && !$hub->ended; | ||||
761 | |||||
762 | my $pass = $ok && $hub->is_passing; | ||||
763 | my $e = $ctx->build_event( | ||||
764 | 'Subtest', | ||||
765 | pass => $pass, | ||||
766 | name => $name, | ||||
767 | subtest_id => $hub->id, | ||||
768 | subtest_uuid => $hub->uuid, | ||||
769 | buffered => $buffered, | ||||
770 | subevents => \@events, | ||||
771 | start_stamp => $start_stamp, | ||||
772 | stop_stamp => $stop_stamp, | ||||
773 | ); | ||||
774 | |||||
775 | my $plan_ok = $hub->check_plan; | ||||
776 | |||||
777 | $ctx->hub->send($e); | ||||
778 | |||||
779 | $ctx->failure_diag($e) unless $e->pass; | ||||
780 | |||||
781 | $ctx->diag("Caught exception in subtest: $err") unless $ok; | ||||
782 | |||||
783 | $ctx->diag("Bad subtest plan, expected " . $hub->plan . " but ran " . $hub->count) | ||||
784 | if defined($plan_ok) && !$plan_ok; | ||||
785 | |||||
786 | $ctx->bail($bailed->reason) if $bailed && $buffered; | ||||
787 | |||||
788 | $ctx->release; | ||||
789 | return $pass; | ||||
790 | } | ||||
791 | |||||
792 | # There is a use-cycle between API and API/Context. Context needs to use some | ||||
793 | # API functions as the package is compiling. Test2::API::context() needs | ||||
794 | # Test2::API::Context to be loaded, but we cannot 'require' the module there as | ||||
795 | # it causes a very noticeable performance impact with how often context() is | ||||
796 | # called. | ||||
797 | 1 | 82µs | require Test2::API::Context; | ||
798 | |||||
799 | 1 | 6µs | 1; | ||
800 | |||||
801 | __END__ |