Skip to content

Commit

Permalink
avoid identical stack traces
Browse files Browse the repository at this point in the history
GH #15109

The output of caller() (e.g. as produced by carp::Confess) produces
multiple identical outputs when within a nested use/require. This is
because at the time of calling the 'BEGIN { require ... }', PL_curcop is
set to &PL_compiling, which is a fixed buffer within the interpreter,
whose individual file and line fields are saved and restored when doing
a new require/eval. This means that within the innermost require,
PL_compiling has file:lineno of the innermost source file, and multiple
saved PL_curcop values in the context stack frames all point to the same
&PL_copmpiling.  So all levels of the stack trace appear to come from the
innermost file.

This commit fixes this (after a fashion) by, at the start of calling a
BEGIN, making PL_curcop point to a temporary copy of PL_compiling
instead.

This is all a bit of a hack.
  • Loading branch information
iabyn committed Dec 13, 2019
1 parent 2f580e4 commit f2f32cd
Show file tree
Hide file tree
Showing 6 changed files with 63 additions and 2 deletions.
3 changes: 3 additions & 0 deletions MANIFEST
Expand Up @@ -5602,6 +5602,9 @@ t/lib/feature/nonesuch Tests for enabling/disabling nonexistent feature
t/lib/feature/removed Tests for enabling/disabling removed feature
t/lib/feature/say Tests for enabling/disabling say feature
t/lib/feature/switch Tests for enabling/disabling switch feature
t/lib/GH_15109/Apack.pm test Module for caller.t
t/lib/GH_15109/Bpack.pm test Module for caller.t
t/lib/GH_15109/Cpack.pm test Module for caller.t
t/lib/h2ph.h Test header file for h2ph
t/lib/h2ph.pht Generated output from h2ph.h by h2ph, for comparison
t/lib/locale/latin1 Part of locale.t in Latin 1
Expand Down
24 changes: 23 additions & 1 deletion op.c
Expand Up @@ -11525,10 +11525,32 @@ S_process_special_blocks(pTHX_ I32 floor, const char *const fullname,
(void)CvGV(cv);
if (floor) LEAVE_SCOPE(floor);
ENTER;

SAVEVPTR(PL_curcop);
if (PL_curcop == &PL_compiling) {
/* Avoid pushing the "global" &PL_compiling onto the
* context stack. For example, a stack trace inside
* nested use's would show all calls coming from whoever
* most recently updated PL_compiling.cop_file and
* cop_line. So instead, temporarily set PL_curcop to a
* private copy of &PL_compiling. PL_curcop will soon be
* set to point back to &PL_compiling anyway but only
* after the temp value has been pushed onto the context
* stack as blk_oldcop.
* This is slightly hacky, but necessary. Note also
* that in the brief window before PL_curcop is set back
* to PL_compiling, IN_PERL_COMPILETIME/IN_PERL_RUNTIME
* will give the wrong answer.
*/
Newx(PL_curcop, 1, COP);
StructCopy(&PL_compiling, PL_curcop, COP);
PL_curcop->op_slabbed = 0;
SAVEFREEPV(PL_curcop);
}

PUSHSTACKi(PERLSI_REQUIRE);
SAVECOPFILE(&PL_compiling);
SAVECOPLINE(&PL_compiling);
SAVEVPTR(PL_curcop);

DEBUG_x( dump_sub(gv) );
Perl_av_create_and_push(aTHX_ &PL_beginav, MUTABLE_SV(cv));
Expand Down
4 changes: 4 additions & 0 deletions t/lib/GH_15109/Apack.pm
@@ -0,0 +1,4 @@
# for use by caller.t for GH #15109
package Apack;
use Bpack;
1;
4 changes: 4 additions & 0 deletions t/lib/GH_15109/Bpack.pm
@@ -0,0 +1,4 @@
# for use by caller.t for GH #15109
package Bpack;
use Cpack;
1;
11 changes: 11 additions & 0 deletions t/lib/GH_15109/Cpack.pm
@@ -0,0 +1,11 @@
# for use by caller.t for GH #15109
package Cpack;


my $i = 0;

while (my ($package, $file, $line) = caller($i++)) {
push @Cpack::callers, "$file:$line";
}

1;
19 changes: 18 additions & 1 deletion t/op/caller.t
Expand Up @@ -5,7 +5,7 @@ BEGIN {
chdir 't' if -d 't';
require './test.pl';
set_up_inc('../lib');
plan( tests => 97 ); # some tests are run in a BEGIN block
plan( tests => 109 ); # some tests are run in a BEGIN block
}

my @c;
Expand Down Expand Up @@ -335,6 +335,22 @@ $::testing_caller = 1;

do './op/caller.pl' or die $@;

# GH #15109
# See that callers within a nested series of 'use's gets the right
# filenames.
{
local @INC = 'lib/GH_15109/';
# Apack use's Bpack which use's Cpack which populates @Cpack::caller
# with the file:N of all the callers
eval 'use Apack; 1';
is($@, "", "GH #15109 - eval");
is (scalar(@Cpack::callers), 10, "GH #15109 - callers count");
like($Cpack::callers[$_], qr{GH_15109/Bpack.pm:3}, "GH #15109 level $_") for 0..2;
like($Cpack::callers[$_], qr{GH_15109/Apack.pm:3}, "GH #15109 level $_") for 3..5;
like($Cpack::callers[$_], qr{\(eval \d+\):1}, "GH #15109 level $_") for 6..8;
like($Cpack::callers[$_], qr{caller\.t}, "GH #15109 level $_") for 9;
}

{
package RT129239;
BEGIN {
Expand All @@ -348,3 +364,4 @@ do './op/caller.pl' or die $@;
#line 12345 "virtually/op/caller.t"
}
}

3 comments on commit f2f32cd

@demerphq
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Re:

             * This is slightly hacky, but necessary. Note also
             * that in the brief window before PL_curcop is set back
             * to PL_compiling, IN_PERL_COMPILETIME/IN_PERL_RUNTIME
             * will give the wrong answer.

I wonder if we couldn't attache a bit of information to the COP to resolve this. I see that there is an unused bit:
https://github.com/Perl/perl5/blob/blead/op.h#L56

Awesome patch btw, this will make understanding the stack trace of code that dies in a use dependency graph much much easier. Thank you so much!

cheers.
Yves

@iabyn
Copy link
Contributor Author

@iabyn iabyn commented on f2f32cd Dec 25, 2019 via email

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@xsawyerx
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for this, Dave. :)

Please sign in to comment.