2

I have a pretty big perl program, packed with PAR::Packer to an executable. It uses quite a lot of modules.

Usually, when perl gives me a warning, like use of undefined value, it prints the location of the error, and then it's easy to go deeper and debug it.

However, I now face an error (introduced in 5.22, I think), and when that happens, I get no location:

Use of each() on hash after insertion without resetting hash iterator results in undefined behaviour, Perl interpreter: 0xa94010

I tried setting use warnings FATAL=>'all';, but nothing changes, the program does not die.

Maybe it comes from a module? How else can I determine location of the warning?

Vit Spinka
  • 21
  • 2

3 Answers3

2

The warnings pragma emits warnings for legal code, from a set of given categories. While the FATAL changes them into fatal errors, it does not change how warn works. Since it is not known how this is emitted there's a good chance that overriding the __WARN__ hook may help

local $SIG{__WARN__} = \&Carp::confess;   # or just die

or you may as well drop local just this one time.

Another thing to try is to override CORE::GLOBAL::warn

BEGIN { *CORE::GLOBAL::warn = sub { die } }  # before use Module;

This affects modules as well, as will the __WARN__ signal if set in BEGIN before modules.

Note that Carp::Always accomplishes this, and more. Also, it is normally activiated simply when running the program, with -MCarp::Always. Thanks to ikegami for a clarification.

See warn and %SIG hash in perlvar, and this Effective Perler article.

Finally, just how many calls to each do you have? Check them all.


It is explained in comments that prints come from XS, found via debugger, but it is still unknown what code triggers this. Then try tie-ing the stream to a class, where a trace is triggered on relevant text. A minimal example

TraceError.pm

package TraceError;
use warnings;
use strict;
use Carp qw(longmess confess);

sub TIEHANDLE { bless {} }

sub PRINT {
    my $self = shift;
    my $prn = join '', @_;

    # print "STDERR: $prn";   # TEST
    print @_;                 # or   print STDERR @_;

    # if ($prn =~ /\QUse of each() on hash after insertion/)  # in your code
    if ($prn =~ /TRACE/) {                                    # test
        print longmess(@_);
    }
}

1;

Change to the commented out if line so to scan prints for the text of your error message. The rest below is just a test of this. In your code you need the first two lines from main.pl, to use this class and tie the stream (filehandle) to it and then all prints (to STDERR) go by way of PRINT above.

main.pl

use TraceError;
tie *STDERR,'TraceError';

use warnings;
use strict;
use Pack qw(issue_warn);

call_for_err(Pack->new);

sub call_for_err {
    my ($pck) = @_; 
    $pck->issue_warn("TRACE call_for_err()");  # should catch this print
    $pck->issue_warn("from call_for_err()");   # but not this
};

Pack.pm

package Pack;
use warnings;
use strict;

use Exporter qw(import);
our @EXPORT_OK = qw(issue_warn);

sub new { bless {}, $_[0] }

sub issue_warn { 
    my $self = shift;
    warn "In ", __PACKAGE__, ", issue_warn(@_).";
}

1;

Output

In Pack, issue_warn(TRACE, call_for_err()). at Pack.pm line 12.
 at Pack.pm line 12.
    Pack::issue_warn('Pack=HASH(0x7016e8)', 'TRACE call_for_err()') called at main.pl line 12
    main::call_for_err('Pack=HASH(0x7016e8)') called at main.pl line 8

The tie-ing class should be written far more nicely, firstly to take arguments (text to search for, stream or handle to print to). See perltie and Tie::Handle, discussions on perlmonks, posts on SO such as this one, and above all the chapter "Tying Filehandles" in Camel (3rd Ed).

Community
  • 1
  • 1
zdim
  • 64,580
  • 5
  • 52
  • 81
  • `-MCarp::Always` basically does this and more :) – ikegami Mar 28 '17 at 19:42
  • @ikegami I got it, thank you! The source is just beautiful, a couple dozen lines :) – zdim Mar 28 '17 at 19:51
  • So `-MCarp::Always` does not help, either. Still no location info. As to `each` calls - I went through my code; no `each` at all at none of `foreach` looks suspicious. I am leaning towards some module/XS code (esp. since usually, I get proper location if it happens in my code). – Vit Spinka Mar 29 '17 at 00:16
  • @VitSpinka OK. Did you try with `CORE::GLOBAL::warn`? That changes how _every_ `warn` works, while `Carp::Always` does something different. Just in case -- does this come out on `STDERR` or `STDOUT`? (If you redirect the output to a file, does it sill print on the console?) I'll look into more ways. – zdim Mar 29 '17 at 03:32
  • @VitSpinka The source may be using `CORE::warn`, exactly the prevent these games, in which case this won't help. Or, far more likely, the line info is stripped in some other way after `warn` is emitted. – zdim Mar 29 '17 at 05:11
  • The warning is generated by `Perl_ck_warner_d` in `Perl_hv_iternext_flags` in `hv.c` in Perl source. And if I modify the source code to add a `Perl_croak`, it does indeed die - but it still does not show any location. Not sure if relevant, but the stack trace is `Perl_pp_entersub->XS_threads__shared__tie_NEXTKEY->Perl_hv_iternext_flags->Perl_ck_warner_d`. I did try `CORE::GLOBAL::warn` first, that did not do any difference. – Vit Spinka Mar 29 '17 at 06:46
  • @VitSpinka Wow. Good job -- how did you find it? Did you also find the user code that triggers this? The missing line info may be a bug to be reported. – zdim Mar 29 '17 at 06:57
  • Perhaps @ikegami can advise on whether this is a bug? – zdim Mar 29 '17 at 06:58
  • Well, 5.24 does display the line as you can see from my answer. But I don't know what happens if the function is called from XS instead of Perl. Will test tomorrow – ikegami Mar 29 '17 at 07:03
  • @zdim I grepped Perl source code, then ran it under gdb and set breakpoint, confirming it is indeed the right place. I still have no idea what user code triggers it. my_perl->Icurcop->cop_file and my_perl->Icurcop->cop_line are NULL/0. Calling `Perl_eval_pv($thread_context, "require Carp;Carp::cluck('Hi')", 0)` got me `SIGSEGV`. (Perl version: 5.24.0.) – Vit Spinka Mar 29 '17 at 07:23
  • @VitSpinka Nice. I added a working (crude) example for tie-ing `STDERR`. You need to change one line, to match your text. With prints coming from C code may be this can help to find the error in user code. – zdim Mar 29 '17 at 09:21
  • @zdim The tie-ing does not seem to work... from further work with dbg (looking at the key value of the hash), I theorise that the user code is about concurrent access/modification of a shared hash. (So far I don't know how to identify which user-code-hash corresponds to a `HV*`, even their `HASH(0xaddress)` don't seem to match the `HV*`) – Vit Spinka Mar 30 '17 at 04:33
  • @VitSpinka Oh, threads. Streams work across, but it of course depends entirely on what they do. Btw, "not seem to work" -- does it not work at all, or it can't locate the error? (I updated, added `else { print @_ }`, otherwise it wasn't printing anything to `STDERR`.) – zdim Mar 30 '17 at 04:59
  • I get a line number even when called from XS. – ikegami Mar 30 '17 at 14:30
  • @VitSpinka The shared hash is a good guess for errors -- there are things to watch out for with that. (For one thing, `shared` wipes out previous data.) Also, `each` in particular has issues with it. Given ikegami's finding above you'd have to just look through relevant code (say, search for `%.*share` or `shared\(%` or such). Also, if the `tie`-ing in this answer somehow isn't working (at all) it may be worthed seeing why, as it may well help. I added a (commented out) line for a basic test. – zdim Mar 30 '17 at 19:37
  • @zdim @ikegami The tie-ing works for a test like `print STDERR "Test"`, but it's not invoked when the `Use of each()...` warning is printed. Yes, my plan is to use a) my perl source edits (printing value of the hash key), b) edit the source code (modify the keys to be more unique among the hashes) c) look at all shared hashes, esp. the suspicious from a)+b). However, as it's usual with all race conditions/thread programming, it happens randomly, often takes hours to occur and you never know you found all the cases :-( – Vit Spinka Mar 31 '17 at 03:12
1
use strict;
use warnings;

sub g {
   my %h = ( a => 4, b => 5 );

   my $done = 0;
   while (my ($k, $v) = each(%h)) {
      print("$k\n");
      $h{c} = 6 if !$done++;
   }
}

sub f {
  g();
}

f();

You should have gotten a line number!

>perl a.pl
a
Use of each() on hash after insertion without resetting hash iterator results in undefined behavior, Perl interpreter: 0xe688d8 at a.pl line 8.
b
c

Carp::Always will extend that into a stack trace.

>perl -MCarp::Always a.pl
a
Use of each() on hash after insertion without resetting hash iterator results in undefined behavior, Perl interpreter: 0x1e88d8 at a.pl line 8.
        main::g() called at a.pl line 15
        main::f() called at a.pl line 18
c
b
ikegami
  • 367,544
  • 15
  • 269
  • 518
-1

I think you can use diagnostics or splain. I have used diagnostics and it helps in case we are not able to track from where a warning is being generated.

You only need to put the line use diagnostics; in your code that's it. You can find detailed explanation for this from the Perl Maven Site - Link.

Thanks.

Mohit
  • 608
  • 4
  • 19
  • 5
    All that does is take the warning and look it up in the source of `perldoc perldiag` and display that text. That doesn't help find where in the perl sources and modules the warning is coming from. – ysth Mar 28 '17 at 06:13