From sdewey@factset.com

Created by sdewey@factset.com

I have provided a full description of the bug on StackOverflow
at https://stackoverflow.com/q/50651331/783314. I will keep that
question up-to-date in case I come across anything new.

For convenience, here is what I wrote there​:
I have isolated a case where Perl provides a very misleading line number in a warning message. I tested the below in Strawberry Perl 5.16.3.

use strict;
use warnings;

my $choice = 0;

while ($choice == 0){

  #Pretend the user provided this via STDIN
  $choice = '5,6,7';

  if ($choice eq '-4'){
  print "This isn't going to happen\n";
  }
}

When you run this, you will get the warning message Argument "5,6,7" isn't numeric in numeric eq (==) at example.pl line 11. But line 11 corresponds to the line if ($choice eq '-4'){ which cannot possibly cause this warning message because it does not contain a numeric comparison.

It seems what's actually happening is that Perl advances to the next comparison, while ($choice == 0){, but the line counter used for the warning message does not advance.

What makes this particular case worse is that, since the "bad" comparison is the loop condition, it is actually far away from the provided line. In my (pre-simplification) script, it was hundreds of lines away from the provided line number.

Is this a bug or just an unfortunate limitation of the parser?

Flags:
    category=core
    severity=medium

Site configuration information for perl 5.16.3:

Configured by strawberry-perl at Tue Mar 12 12:12:58 2013.

Summary of my perl5 (revision 5 version 16 subversion 3) configuration:

  Platform:
    osname=MSWin32, osvers=4.0, archname=MSWin32-x64-multi-thread
    uname='Win32 strawberry-perl 5.16.3.1 #1 Tue Mar 12 12:12:07 2013 x64'
    config_args='undef'
    hint=recommended, useposix=true, d_sigaction=undef
    useithreads=define, usemultiplicity=define
    useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
    use64bitint=define, use64bitall=undef, uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='gcc', ccflags =' -s -O2 -DWIN32 -DWIN64 -DCONSERVATIVE  -DPERL_TEXTMODE_SCRIPTS -DPERL_IMPLICIT_CONTEXT -DPERL_IMPLICIT_SYS -fno-strict-aliasing -mms-bitfields',
    optimize='-s -O2',
    cppflags='-DWIN32'
    ccversion='', gccversion='4.6.3', gccosandvers=''
    intsize=4, longsize=4, ptrsize=8, doublesize=8, byteorder=12345678
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
    ivtype='long long', ivsize=8, nvtype='double', nvsize=8, Off_t='long long', lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='g++.exe', ldflags ='-s -L"C:\berrybrew\5.16.3_64\perl\lib\CORE" -L"C:\berrybrew\5.16.3_64\c\lib"'
    libpth=C:\berrybrew\5.16.3_64\c\lib C:\berrybrew\5.16.3_64\c\x86_64-w64-mingw32\lib
    libs=-lmoldname -lkernel32 -luser32 -lgdi32 -lwinspool -lcomdlg32 -ladvapi32 -lshell32 -lole32 -loleaut32 -lnetapi32 -luuid -lws2_32 -lmpr -lwinmm -lversion -lodbc32 -lodbccp32 -lcomctl32
    perllibs=-lmoldname -lkernel32 -luser32 -lgdi32 -lwinspool -lcomdlg32 -ladvapi32 -lshell32 -lole32 -loleaut32 -lnetapi32 -luuid -lws2_32 -lmpr -lwinmm -lversion -lodbc32 -lodbccp32 -lcomctl32
    libc=, so=dll, useshrplib=true, libperl=libperl516.a
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_win32.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' '
    cccdlflags=' ', lddlflags='-mdll -s -L"C:\berrybrew\5.16.3_64\perl\lib\CORE" -L"C:\berrybrew\5.16.3_64\c\lib"'

Locally applied patches:



@INC for perl 5.16.3:
    C:/berrybrew/5.16.3_64/perl/site/lib
    C:/berrybrew/5.16.3_64/perl/vendor/lib
    C:/berrybrew/5.16.3_64/perl/lib
    .


Environment for perl 5.16.3:
    HOME (unset)
    LANG (unset)
    LANGUAGE (unset)
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=C:\berrybrew\5.16.3_64\c\bin;C:\berrybrew\5.16.3_64\perl\bin;C:\berrybrew\5.16.3_64\perl\site\bin;C:\windows\system32;C:\windows;C:\windows\System32\Wbem;C:\windows\System32\WindowsPowerShell\v1.0\;C:\windows\System32\WindowsPowerShell\v1.0\;C:\windows\SysWOW64\~FDSTools;C:\windows\SysWOW64\~FDSTools\SysinternalsSuite;C:\Program Files (x86)\Graphviz2.38\bin;C:\Program Files\Perforce;C:\Program Files\Microsoft SQL Server\Client SDK\ODBC\110\Tools\Binn\;C:\Program Files (x86)\Microsoft SQL Server\120\Tools\Binn\ManagementStudio\;C:\Program Files (x86)\Microsoft SQL Server\120\Tools\Binn\;C:\Program Files\Microsoft SQL Server\120\Tools\Binn\;C:\Program Files (x86)\Microsoft SQL Server\120\DTS\Binn\;C:\Program Files\Microsoft SQL Server\120\DTS\Binn\;C:\Program Files\PuTTY\;C:\Program Files (x86)\WinMerge;C:\Users\sdewey\AppData\Local\Continuum\Anaconda3;C:\Users\sdewey\AppData\Local\Continuum\Anaconda3\Scripts;C:\Users\sdewey\AppData\Local\Continuum\Anaconda3\Library\bin;C:\Program Files (x86)\FAHClient;C:\Program Files\MiKTeX 2.9\miktex\bin\x64\;C:\Program Files (x86)\Calibre2\;C:\Program Files\Git\cmd;C:\Program Files\nodejs\;C:\Program Files\MATLAB\R2017b\bin;C:\Users\sdewey\berrybrew\bin;C:\Program Files\Java\jdk1.8.0_121\bin;C:\Program Files\apache-maven-3.5.3\bin;C:\Program Files\Spring\spring-2.0.1.BUILD-SNAPSHOT\bin;c:\python27\scripts;C:\Users\sdewey\Documents\berrybrew\bin;C:\Users\sdewey\scoop\shims;C:\Program Files (x86)\Graphviz2.38\bin;C:\Users\sdewey\AppData\Local\Continuum\Anaconda3;C:\Users\sdewey\AppData\Local\Continuum\Anaconda3\Scripts;C:\Users\sdewey\AppData\Local\Continuum\Anaconda3\Library\bin;C:\Program Files (x86)\FAHClient;C:\Users\sdewey\AppData\Local\atom\bin;C:\Users\sdewey\AppData\Local\Programs\Fiddler;C:\Users\sdewey\AppData\Roaming\factsetio\bin\;C:\Users\sdewey\AppData\Roaming\npm
    PERL_BADLANG (unset)
    SHELL (unset)

From @Grinnz

I can reproduce on 5.26.2.

The RT System itself - Status changed from 'new' to 'open'

From @iabyn

On Fri, Jun 01, 2018 at 03​:22​:18PM -0700, Stephen E. Dewey (via RT) wrote​:

I have provided a full description of the bug on StackOverflow
at https://stackoverflow.com/q/50651331/783314. I will keep that
question up-to-date in case I come across anything new.

For convenience, here is what I wrote there​:
I have isolated a case where Perl provides a very misleading line number in a warning message. I tested the below in Strawberry Perl 5.16.3.

use strict;
use warnings;

my $choice = 0;

while ($choice == 0){

\#Pretend the user provided this via STDIN
$choice = '5\,6\,7';

if \($choice eq '\-4'\)\{
    print "This isn't going to happen\\n";
\}

}

When you run this, you will get the warning message Argument "5,6,7" isn't numeric in numeric eq (==) at example.pl line 11. But line 11 corresponds to the line if ($choice eq '-4'){ which cannot possibly cause this warning message because it does not contain a numeric comparison.

It seems what's actually happening is that Perl advances to the next comparison, while ($choice == 0){, but the line counter used for the warning message does not advance.

What makes this particular case worse is that, since the "bad" comparison is the loop condition, it is actually far away from the provided line. In my (pre-simplification) script, it was hundreds of lines away from the provided line number.

Is this a bug or just an unfortunate limitation of the parser?

It's a well-known limitation that needs to be addressed at some point.
The current implementation only records the line number of the start of
each statement. At runtime, each time the interpreter is about to start
executing a statement, it records the line number associated with that
statement. In warnings and error messages, the last recorded line number
is used.

--
"I do not resent criticism, even when, for the sake of emphasis,
it parts for the time with reality".
  -- Winston Churchill, House of Commons, 22nd Jan 1941.

From @rocky

On Tue, Jun 19, 2018 at 4​:36 AM, Dave Mitchell <davem@​iabyn.com> wrote​:

On Fri, Jun 01, 2018 at 03​:22​:18PM -0700, Stephen E. Dewey (via RT) wrote​:

I have provided a full description of the bug on StackOverflow
at https://stackoverflow.com/q/50651331/783314. I will keep that
question up-to-date in case I come across anything new.

For convenience, here is what I wrote there​:
I have isolated a case where Perl provides a very misleading line number
in a warning message. I tested the below in Strawberry Perl 5.16.3.

use strict;
use warnings;

my $choice = 0;

while ($choice == 0){

\#Pretend the user provided this via STDIN
$choice = '5\,6\,7';

if \($choice eq '\-4'\)\{
    print "This isn't going to happen\\n";
\}

}

When you run this, you will get the warning message Argument "5,6,7"
isn't numeric in numeric eq (==) at example.pl line 11. But line 11
corresponds to the line if ($choice eq '-4'){ which cannot possibly cause
this warning message because it does not contain a numeric comparison.

It seems what's actually happening is that Perl advances to the next
comparison, while ($choice == 0){, but the line counter used for the
warning message does not advance.

What makes this particular case worse is that, since the "bad"
comparison is the loop condition, it is actually far away from the provided
line. In my (pre-simplification) script, it was hundreds of lines away from
the provided line number.

Is this a bug or just an unfortunate limitation of the parser?

It's a well-known limitation that needs to be addressed at some point.

The fact that it is a well-known limitation that has existed since, is it
5.008 (for 16 years!?) suggests that fixing this might be non trivial and
disruptive.

There is perhaps another, possibly less intrusive way, that this might be
addressed (or at least ameliorated) - As we say in Perl​: there is more than
one way to do things.

At the point of error Perl knows what instruction it was working on.
Suppose you could register an error handler hook to get called with that op
address...

I have been working on a deparser that will show you at runtime where you
are when given that OP address. Right now I have this hooked into the
Devel​::Trepan <https://metacpan.org/pod/Devel::Trepan> debugger, so I'll
show how it works there.

trepan.pl /tmp/bug.pl
-- main​::(/tmp/bug.pl​:4 @​0x1c69f78)
my $choice = 0;
set auto eval is on.
(trepanpl)​: disasm
Package Main

  #4​: my $choice = 0;
  COP (0x1c69ed0) dbstate
  BINOP (0x1c69f30) sassign
=> SVOP (0x1c69f78) const IV (0x1c63740) 0
  OP (0x1c69fb8) padsv [1]
  #6​: while ($choice == 0){
  COP (0x3f68280) dbstate
  BINOP (0x3f682e0) leaveloop
  LOOP (0x3f68328) enterloop
  UNOP (0x3f68388) null
  LOGOP (0x3f683c8) and
  BINOP (0x1c6a670) eq <<< this is the instruction that
errors
  OP (0x1c69e20) padsv [1]
  SVOP (0x1c6a6b8) const IV (0x1c63788) 0
  LISTOP (0x1c6a508) lineseq
  #9​: $choice = '5,6,7';
  ...
(trepanpl)​: deparse 0x1c6a670
binary operator ==, eq
while ($choice == 0) {
  ------------
(trepanpl)​:

Notice that you not only get the text of the line but also where in the
line there was a problem. If the code had been

while ($choice == 0 && $i_feel_pretty == 3) {

the deparsing would indicate *which *of the two conditions had the problem,
even though they are both on the same line.

The current implementation only records the line number of the start of
each statement. At runtime, each time the interpreter is about to start
executing a statement, it records the line number associated with that
statement. In warnings and error messages, the last recorded line number
is used.

--
"I do not resent criticism, even when, for the sake of emphasis,
it parts for the time with reality".
-- Winston Churchill, House of Commons, 22nd Jan 1941.

From @rocky

Apparently, I wasn't clear in describing what I was proposing. There were
two parts to what I wrote​:

  1. A suggstion to add some sort of mechanism whereby a user can write a
  custom error/warning handler, and then
  2. a suggestiion on how to use this to provide a better error location
  indication

Let me elaborate a little on 1.

Currently Perl has an END block which is close, but has a couple of
problems here. First, there was a warning, so execution continues and we
don't trap on the END immediately. If you were to change the code so that
it produces an error that terminates, such as changing the condition to a
divide by 0, then END does get called, and caller() gives a line number
of where it thinks it was called*,* but I am not sure how to get the OP
address which is needed for deparsing. Devel​::Callsite fails here. And
interestingly Devel​::Caller reports​: "was expecting a pushmark or a
padrange, not a[sic] enterloop" which is promising.

But if this were fixed, how would we get the "Illegal division by zero"
message? It isn't contained in $!.

On Tue, Jun 19, 2018 at 5​:20 PM, Rocky Bernstein <rocky.bernstein@​gmail.com>
wrote​:

On Tue, Jun 19, 2018 at 4​:36 AM, Dave Mitchell <davem@​iabyn.com> wrote​:

On Fri, Jun 01, 2018 at 03​:22​:18PM -0700, Stephen E. Dewey (via RT) wrote​:

I have provided a full description of the bug on StackOverflow
at https://stackoverflow.com/q/50651331/783314. I will keep that
question up-to-date in case I come across anything new.

For convenience, here is what I wrote there​:
I have isolated a case where Perl provides a very misleading line
number in a warning message. I tested the below in Strawberry Perl 5.16.3.

use strict;
use warnings;

my $choice = 0;

while ($choice == 0){

\#Pretend the user provided this via STDIN
$choice = '5\,6\,7';

if \($choice eq '\-4'\)\{
    print "This isn't going to happen\\n";
\}

}

When you run this, you will get the warning message Argument "5,6,7"
isn't numeric in numeric eq (==) at example.pl line 11. But line 11
corresponds to the line if ($choice eq '-4'){ which cannot possibly cause
this warning message because it does not contain a numeric comparison.

It seems what's actually happening is that Perl advances to the next
comparison, while ($choice == 0){, but the line counter used for the
warning message does not advance.

What makes this particular case worse is that, since the "bad"
comparison is the loop condition, it is actually far away from the provided
line. In my (pre-simplification) script, it was hundreds of lines away from
the provided line number.

Is this a bug or just an unfortunate limitation of the parser?

It's a well-known limitation that needs to be addressed at some point.

The fact that it is a well-known limitation that has existed since, is it
5.008 (for 16 years!?) suggests that fixing this might be non trivial and
disruptive.

There is perhaps another, possibly less intrusive way, that this might be
addressed (or at least ameliorated) - As we say in Perl​: there is more than
one way to do things.

At the point of error Perl knows what instruction it was working on.
Suppose you could register an error handler hook to get called with that op
address...

I have been working on a deparser that will show you at runtime where you
are when given that OP address. Right now I have this hooked into the
Devel​::Trepan <https://metacpan.org/pod/Devel::Trepan> debugger, so I'll
show how it works there.

trepan.pl /tmp/bug.pl
-- main​::(/tmp/bug.pl​:4 @​0x1c69f78)
my $choice = 0;
set auto eval is on.
(trepanpl)​: disasm
Package Main
------------
#4​: my $choice = 0;
COP (0x1c69ed0) dbstate
BINOP (0x1c69f30) sassign
=> SVOP (0x1c69f78) const IV (0x1c63740) 0
OP (0x1c69fb8) padsv [1]
#6​: while ($choice == 0){
COP (0x3f68280) dbstate
BINOP (0x3f682e0) leaveloop
LOOP (0x3f68328) enterloop
UNOP (0x3f68388) null
LOGOP (0x3f683c8) and
BINOP (0x1c6a670) eq <<< this is the instruction
that errors
OP (0x1c69e20) padsv [1]
SVOP (0x1c6a6b8) const IV (0x1c63788) 0
LISTOP (0x1c6a508) lineseq
#9​: $choice = '5,6,7';
...
(trepanpl)​: deparse 0x1c6a670
binary operator ==, eq
while ($choice == 0) {
------------
(trepanpl)​:

Notice that you not only get the text of the line but also where in the
line there was a problem. If the code had been

while ($choice == 0 && $i_feel_pretty == 3) {

the deparsing would indicate *which *of the two conditions had the
problem, even though they are both on the same line.

The current implementation only records the line number of the start of
each statement. At runtime, each time the interpreter is about to start
executing a statement, it records the line number associated with that
statement. In warnings and error messages, the last recorded line number
is used.

--
"I do not resent criticism, even when, for the sake of emphasis,
it parts for the time with reality".
-- Winston Churchill, House of Commons, 22nd Jan 1941.

From @iabyn

On Wed, Jun 20, 2018 at 06​:15​:25AM -0400, Rocky Bernstein wrote​:

Apparently, I wasn't clear in describing what I was proposing. There were
two parts to what I wrote​:

1. A suggstion to add some sort of mechanism whereby a user can write a
custom error/warning handler, and then
2. a suggestiion on how to use this to provide a better error location
indication

Let me elaborate a little on 1.

Currently Perl has an END block which is close, but has a couple of
problems here.

I don't understand what END blocks have to do with this.

On the other hand, the pre-existing $SIG{__WARN__} and $SIG{__DIE__} sound
close to what you want. The main issue seems that the value of PL_op is
not available at the time the handler is called, even if the handler is an
XS sub (PL_op gets saved, then set to a faked up OP_ENTERSUB for the
purposes of calling the handler).

Perhaps perl should set an interpreter variable, PL_warn_err_op, say, before
calling the warn/die hook?

PS I'm assuming you're not suggesting that perl itself does (2)?

--
This email is confidential, and now that you have read it you are legally
obliged to shoot yourself. Or shoot a lawyer, if you prefer. If you have
received this email in error, place it in its original wrapping and return
for a full refund. By opening this email, you accept that Elvis lives.

From @rocky

On Wed, Jun 20, 2018 at 7​:28 AM, Dave Mitchell <davem@​iabyn.com> wrote​:

On Wed, Jun 20, 2018 at 06​:15​:25AM -0400, Rocky Bernstein wrote​:

Apparently, I wasn't clear in describing what I was proposing. There were
two parts to what I wrote​:

1. A sugg[e]stion to add some sort of mechanism whereby a user can
write a
custom error/warning handler, and then
2. a suggestiion on how to use this to provide a better error location
indication

Let me elaborate a little on 1.

Currently Perl has an END block which is close, but has a couple of
problems here.

I don't understand what END blocks have to do with this.

On the other hand, the pre-existing $SIG{__WARN__} and $SIG{__DIE__} sound
close to what you want. The main issue seems that the value of PL_op is
not available at the time the handler is called, even if the handler is an
XS sub (PL_op gets saved, then set to a faked up OP_ENTERSUB for the
purposes of calling the handler).

Perhaps perl should set an interpreter variable, PL_warn_err_op, say,
before
calling the warn/die hook?

That would be fantastic.

PS I'm assuming you're not suggesting that perl itself does (2)?

I don't want to get sidetracked on this. More important to the community
should be fact that this bug has been around for 16 years and honestly
probably won't be addressed soon. Therefore addressing (1) provides users
with at least an alternative remedy.

From @ikegami

On Tue, Jun 19, 2018 at 4​:36 AM, Dave Mitchell <davem@​iabyn.com> wrote​:

On Fri, Jun 01, 2018 at 03​:22​:18PM -0700, Stephen E. Dewey (via RT) wrote​:

I have provided a full description of the bug on StackOverflow
at https://stackoverflow.com/q/50651331/783314. I will keep that
question up-to-date in case I come across anything new.

For convenience, here is what I wrote there​:
I have isolated a case where Perl provides a very misleading line number
in a warning message. I tested the below in Strawberry Perl 5.16.3.

use strict;
use warnings;

my $choice = 0;

while ($choice == 0){

\#Pretend the user provided this via STDIN
$choice = '5\,6\,7';

if \($choice eq '\-4'\)\{
    print "This isn't going to happen\\n";
\}

}

When you run this, you will get the warning message Argument "5,6,7"
isn't numeric in numeric eq (==) at example.pl line 11. But line 11
corresponds to the line if ($choice eq '-4'){ which cannot possibly cause
this warning message because it does not contain a numeric comparison.

It seems what's actually happening is that Perl advances to the next
comparison, while ($choice == 0){, but the line counter used for the
warning message does not advance.

What makes this particular case worse is that, since the "bad"
comparison is the loop condition, it is actually far away from the provided
line. In my (pre-simplification) script, it was hundreds of lines away from
the provided line number.

Is this a bug or just an unfortunate limitation of the parser?

It's a well-known limitation that needs to be addressed at some point.
The current implementation only records the line number of the start of
each statement. At runtime, each time the interpreter is about to start
executing a statement, it records the line number associated with that
statement. In warnings and error messages, the last recorded line number
is used.

It's the nextstate ops that record the line numbers, right? Couldn't one be
added to the start of the while expression?

From @rocky

On Wed, Jun 20, 2018 at 5​:19 PM, Eric Brine <ikegami@​adaelis.com> wrote​:

On Tue, Jun 19, 2018 at 4​:36 AM, Dave Mitchell <davem@​iabyn.com> wrote​:

On Fri, Jun 01, 2018 at 03​:22​:18PM -0700, Stephen E. Dewey (via RT) wrote​:

I have provided a full description of the bug on StackOverflow
at https://stackoverflow.com/q/50651331/783314. I will keep that
question up-to-date in case I come across anything new.

For convenience, here is what I wrote there​:
I have isolated a case where Perl provides a very misleading line
number in a warning message. I tested the below in Strawberry Perl 5.16.3.

use strict;
use warnings;

my $choice = 0;

while ($choice == 0){

\#Pretend the user provided this via STDIN
$choice = '5\,6\,7';

if \($choice eq '\-4'\)\{
    print "This isn't going to happen\\n";
\}

}

When you run this, you will get the warning message Argument "5,6,7"
isn't numeric in numeric eq (==) at example.pl line 11. But line 11
corresponds to the line if ($choice eq '-4'){ which cannot possibly cause
this warning message because it does not contain a numeric comparison.

It seems what's actually happening is that Perl advances to the next
comparison, while ($choice == 0){, but the line counter used for the
warning message does not advance.

What makes this particular case worse is that, since the "bad"
comparison is the loop condition, it is actually far away from the provided
line. In my (pre-simplification) script, it was hundreds of lines away from
the provided line number.

Is this a bug or just an unfortunate limitation of the parser?

It's a well-known limitation that needs to be addressed at some point.
The current implementation only records the line number of the start of
each statement. At runtime, each time the interpreter is about to start
executing a statement, it records the line number associated with that
statement. In warnings and error messages, the last recorded line number
is used.

It's the nextstate ops that record the line numbers, right?

Yes, I believe so.

Couldn't one be added to the start of the while expression?

Proably - why not make the modification and let us know if that fixes
things?

Note though that in https://stackoverflow.com/a/50651543/546218 another
possibility was mentioned and used in Perl 5.006​: add a nextstate to the
end of the loop. There are probably other possibilities as well.

That said, I think it was Reini Urban who mentioned that adding
nextstate/dbstate as instructions in the optree rather than as a side table
outside of the optree slows execution down for various reasons that he can
probably better elaborate on.

One of the cool things about using this novel decompilation at runtime
technique is that you can get greater accuracy in location while also
reducing runtime overhead in the normal cases when there are no warnings or
errors. And it works when there is no source code file such as inside
eval().

Given the historical baggage of Perl and the environment that a large
number of packages and modules currently expect, I don't think
decompilation will be a be total replacement for the current COP file/line
approach. But I think it could be a welcome adjunct.