warnings from while() condition are reported from wrong line

[p5pRT]

Migrated from rt.perl.org#60954 (status was 'open')

Searchable as RT60954$

[p5pRT]

From @timbunce

Reproduced on perl5.8.6 and v5.11.0 DEVEL34703.

After executing the last statement in a while() block perl doesn't
update its concept of the current line number when it evaluates the
while condition. So any warnings generated by the condition are
reported as being from whatever line was last executed within the block​:

#!perl
$a = 3;
while(warn("while"), $a--) { # first warn reports this line
  $a;
  $a; # subsequent warns report this line
}

# the 'current line' is whatever line was last executed
$a = 3;
while(warn("while"), $a--) { # first warn reports this line
  $a;
  next; # subsequent warns report this line
  $a;
}

# adding a continue block avoids the problem
$a = 3;
while((warn "while"), $a--) { # all warns report this line
  $a;
  $a;
}
continue {
}

This may seem like a minor issue but I've rated it 'high' because it has a
significant impact on accuracy of statement based profilers like NYTProf.

Seems like OP_UNSTACK needs to be smarter.

Naturally any solution shouldn't slow perl down.

If a slowdown is unavoidable then perhaps only implement it if $^P & 0x2
(line-by-line debugging) is true at compile time.

Perl Info

Flags:
    category=core
    severity=high

Site configuration information for perl v5.8.6:

Configured by timbo at Thu May 25 17:26:37 IST 2006.

Summary of my perl5 (revision 5 version 8 subversion 6) configuration:
  Platform:
    osname=darwin, osvers=8.5.2, archname=darwin-thread-multi-2level
    uname='darwin ppp-117.la.vclk.net 8.5.2 darwin kernel version 8.5.2: mon feb 13 16:31:48 pst 2006; root:xnu-792.8.37.obj~1release_i386 i386 i386 '
    config_args='-des -Dprefix=/usr/local/perl58-i -Doptimize=-g -Duseithreads -Dusemultiplicity'
    hint=recommended, useposix=true, d_sigaction=define
    usethreads=define use5005threads=undef useithreads=define usemultiplicity=define
    useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
    use64bitint=undef use64bitall=undef uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cc', ccflags ='-fno-common -DPERL_DARWIN -no-cpp-precomp -DDEBUGGING -fno-strict-aliasing -pipe -I/usr/local/include -I/opt/local/include',
    optimize='-g',
    cppflags='-no-cpp-precomp -fno-common -DPERL_DARWIN -no-cpp-precomp -DDEBUGGING -fno-strict-aliasing -pipe -I/usr/local/include -I/opt/local/include'
    ccversion='', gccversion='4.0.1 (Apple Computer, Inc. build 5250)', gccosandvers=''
    intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
    ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='env MACOSX_DEPLOYMENT_TARGET=10.3 cc', ldflags =' -L/usr/local/lib -L/opt/local/lib'
    libpth=/usr/local/lib /opt/local/lib /usr/lib
    libs=-lgdbm -ldbm -ldl -lm -lc
    perllibs=-ldl -lm -lc
    libc=/usr/lib/libc.dylib, so=dylib, useshrplib=false, libperl=libperl.a
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_dyld.xs, dlext=bundle, d_dlsymun=undef, ccdlflags=' '
    cccdlflags=' ', lddlflags=' -bundle -undefined dynamic_lookup -L/usr/local/lib -L/opt/local/lib'

Locally applied patches:
    


@INC for perl v5.8.6:
    /usr/local/perl58-i/lib/5.8.6/darwin-thread-multi-2level
    /usr/local/perl58-i/lib/5.8.6
    /usr/local/perl58-i/lib/site_perl/5.8.6/darwin-thread-multi-2level
    /usr/local/perl58-i/lib/site_perl/5.8.6
    /usr/local/perl58-i/lib/site_perl
    .


Environment for perl v5.8.6:
    HOME=/Users/timbo
    LANG=en_IE.UTF-8
    LANGUAGE (unset)
    LC_ALL=en_IE.UTF-8
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=/Users/timbo/bin:/usr/local/perl58-i/bin:/usr/local/mysql/bin:/usr/local/bin:/opt/local/bin:/opt/local/sbin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin
    PERLCRITIC=/Users/timbo/.setdev/perlcriticrc
    PERLTIDY=/Users/timbo/.setdev/perltidyrc
    PERL_BADLANG (unset)
    SHELL=/bin/bash

[p5pRT]

From @timbunce

Another example​:

  while ( foo() ) {
  ...
  ... # calls to foo() appear to come from this line
  }

his impacts stack traces and the NYTProf subroutine profiler.

[p5pRT]

@timbunce - Status changed from 'new' to 'open'

[p5pRT]

From @rgs

2008/12/1 via RT Tim Bunce <perlbug-followup@​perl.org>​:

After executing the last statement in a while() block perl doesn't
update its concept of the current line number when it evaluates the
while condition. So any warnings generated by the condition are
reported as being from whatever line was last executed within the block​:

Maybe the same trick that I used in change 33710 can be used there. It
has no run-time impact except a little more memory used for an extra
null op.

Change 33710 by rgs@​stcosmo on 2008/04/18 10​:42​:17

  Fix the line-number-in-elsif longstanding bug.
  This patch does two things :
  - newSTATEOP now nullifies the state op it
  just created if OPf_SPECIAL is passed to it
  in flags
  - the parser now inserts a nullified stateop
  in the expression block of an elsif

[p5pRT]

From @timbunce

On Tue, Dec 02, 2008 at 01​:05​:26AM -0800, Rafael Garcia-Suarez via RT wrote​:

2008/12/1 via RT Tim Bunce <perlbug-followup@​perl.org>​:

After executing the last statement in a while() block perl doesn't
update its concept of the current line number when it evaluates the
while condition. So any warnings generated by the condition are
reported as being from whatever line was last executed within the block​:

Maybe the same trick that I used in change 33710 can be used there. It
has no run-time impact except a little more memory used for an extra
null op.

Change 33710 by rgs@​stcosmo on 2008/04/18 10​:42​:17

    Fix the line\-number\-in\-elsif longstanding bug\.
    This patch does two things :
    \- newSTATEOP now nullifies the state op it
      just created if OPf\_SPECIAL is passed to it
      in flags
    \- the parser now inserts a nullified stateop
      in the expression block of an elsif

Sounds plausible.

How does that actually work though?

Googling that change led me to the old discussion, including some
TODO tests that cover the same problem as this bug​:
http​://www.nntp.perl.org/group/perl.perl5.porters/2008/04/msg136236.html

Tim.

[p5pRT]

From @nwc10

On Tue, Dec 02, 2008 at 10​:56​:42AM +0000, Tim Bunce wrote​:

On Tue, Dec 02, 2008 at 01​:05​:26AM -0800, Rafael Garcia-Suarez via RT wrote​:

2008/12/1 via RT Tim Bunce <perlbug-followup@​perl.org>​:

After executing the last statement in a while() block perl doesn't
update its concept of the current line number when it evaluates the
while condition. So any warnings generated by the condition are
reported as being from whatever line was last executed within the block​:

Maybe the same trick that I used in change 33710 can be used there. It
has no run-time impact except a little more memory used for an extra
null op.

Change 33710 by rgs@​stcosmo on 2008/04/18 10​:42​:17

    Fix the line\-number\-in\-elsif longstanding bug\.
    This patch does two things :
    \- newSTATEOP now nullifies the state op it
      just created if OPf\_SPECIAL is passed to it
      in flags
    \- the parser now inserts a nullified stateop
      in the expression block of an elsif

Sounds plausible.

How does that actually work though?

Googling that change led me to the old discussion, including some
TODO tests that cover the same problem as this bug​:
http​://www.nntp.perl.org/group/perl.perl5.porters/2008/04/msg136236.html

I *think* (but don't quote me on that), that​:

Line numbers in errors reports are calcuated by S_closest_cop() in util.c.
It treats STATEOPs and nullified STATEOPs equally, walking the compile-time
generated optree to do this.

However, something else (not sure what) must be reporting line numbers based
on PL_curcop, which is set at run time by pp_nextstate. That, of course, is
not invoked for nullified STATEOPs, just real STATEOPs.

So I infer that this is a bit of a hack to find a way of storing a line
number that one can see, and the other can not.

Nicholas Clark

[p5pRT]

From @rgs

2009/3/25 Nicholas Clark <nick@​ccl4.org>​:

On Tue, Dec 02, 2008 at 10​:56​:42AM +0000, Tim Bunce wrote​:

On Tue, Dec 02, 2008 at 01​:05​:26AM -0800, Rafael Garcia-Suarez via RT wrote​:

2008/12/1 via RT Tim Bunce <perlbug-followup@​perl.org>​:

After executing the last statement in a while() block perl doesn't
update its concept of the current line number when it evaluates the
while condition.  So any warnings generated by the condition are
reported as being from whatever line was last executed within the block​:

Maybe the same trick that I used in change 33710 can be used there. It
has no run-time impact except a little more memory used for an extra
null op.

Change 33710 by rgs@​stcosmo on 2008/04/18 10​:42​:17

        Fix the line-number-in-elsif longstanding bug.
        This patch does two things :
        - newSTATEOP now nullifies the state op it
          just created if OPf_SPECIAL is passed to it
          in flags
        - the parser now inserts a nullified stateop
          in the expression block of an elsif

Sounds plausible.

How does that actually work though?

Googling that change led me to the old discussion, including some
TODO tests that cover the same problem as this bug​:
http​://www.nntp.perl.org/group/perl.perl5.porters/2008/04/msg136236.html

I *think* (but don't quote me on that), that​:

Line numbers in errors reports are calcuated by S_closest_cop() in util.c.
It treats STATEOPs and nullified STATEOPs equally, walking the compile-time
generated optree to do this.

However, something else (not sure what) must be reporting line numbers based
on PL_curcop, which is set at run time by pp_nextstate. That, of course, is
not invoked for nullified STATEOPs, just real STATEOPs.

Both warnings and errors go through Perl_vmess. The line number found
by closest_cop depends on the last cop executed (PL_curcop). That
should explain why the warning is not reported from the same point at
the first and subsequent iterations of the loop. The first time,
PL_curcop points at the ";" before the while; the next times, at the
";" after the last statement of the while (in a figured way). A
nullified stateop after the enterloop is likely to solve this.

[p5pRT]

From @timbunce

On Mon, Dec 01, 2008 at 03​:07​:42AM -0800, Tim Bunce wrote​:

# <URL​: http​://rt.perl.org/rt3/Ticket/Display.html?id=60954 >

This is still open (and affecting NYTProf).

Any chance it could be fixed for 5.12?

Tim.

[p5pRT]

From @obra

On Fri, Nov 27, 2009 at 11​:03​:11AM +0000, Tim Bunce wrote​:

On Mon, Dec 01, 2008 at 03​:07​:42AM -0800, Tim Bunce wrote​:

# <URL​: http​://rt.perl.org/rt3/Ticket/Display.html?id=60954 >

This is still open (and affecting NYTProf).

Any chance it could be fixed for 5.12?

At least for now, I've added this to the blocks-5.12 list

[p5pRT]

From @timbunce

On Fri, Nov 27, 2009 at 01​:17​:46PM -0500, jesse wrote​:

On Fri, Nov 27, 2009 at 11​:03​:11AM +0000, Tim Bunce wrote​:

On Mon, Dec 01, 2008 at 03​:07​:42AM -0800, Tim Bunce wrote​:

# <URL​: http​://rt.perl.org/rt3/Ticket/Display.html?id=60954 >

This is still open (and affecting NYTProf).

Any chance it could be fixed for 5.12?

At least for now, I've added this to the blocks-5.12 list

Any news on this one?

Tim.

[p5pRT]

From @nwc10

On Tue, Dec 22, 2009 at 08​:09​:34PM +0000, Tim Bunce wrote​:

On Fri, Nov 27, 2009 at 01​:17​:46PM -0500, jesse wrote​:

On Fri, Nov 27, 2009 at 11​:03​:11AM +0000, Tim Bunce wrote​:

On Mon, Dec 01, 2008 at 03​:07​:42AM -0800, Tim Bunce wrote​:

# <URL​: http​://rt.perl.org/rt3/Ticket/Display.html?id=60954 >

This is still open (and affecting NYTProf).

Any chance it could be fixed for 5.12?

At least for now, I've added this to the blocks-5.12 list

Any news on this one?

To the best of my knowledge, "no". (I think that Jesse would be the best
person to answer this, but I believe that he's currently indisposed,
visiting relatives, and I'm not sure for how long.)

At various times the list has been pleasantly surprised by patches appearing
from various (thank-you) individuals to fix various open bugs, but no-one is
jumping up to volunteer to systematically work through and solve the bugs on
the list of blockers.

(I certainly don't have time)

For many of the bugs, it's a skilled job to diagnose and fix them.

A job.

Nicholas Clark

[p5pRT]

From @iabyn

On Wed, Dec 23, 2009 at 03​:16​:51PM +0000, Nicholas Clark wrote​:

This is still open (and affecting NYTProf).

Any chance it could be fixed for 5.12?

At least for now, I've added this to the blocks-5.12 list

I can't really see that this is a 5.12 showstopper.

It's present in 5.8.x, and is just one of a whole class of bugs wherein
perl misreports line numbers. It really needs fixing as part of a general
post-5.12 overhaul of the line number reporting system, rather than
throwing another one-off hack at it.

--
I've often wanted to drown my troubles, but I can't get my wife to go
swimming.

[p5pRT]

From @obra

Based on comments from Tim Bunce, I'm removing this as a 5.12 blocker.
It's still an issue for NYTProf but not one that should block a release

[p5pRT]

From @obra

Based on comments from Tim Bunce, I'm removing this as a 5.12 blocker.
It's still an issue for NYTProf but not one that should block a release

[p5pRT]

From @timbunce

On Mon, Jan 11, 2010 at 11​:04​:03PM +0000, Dave Mitchell wrote​:

On Wed, Dec 23, 2009 at 03​:16​:51PM +0000, Nicholas Clark wrote​:

This is still open (and affecting NYTProf).

Any chance it could be fixed for 5.12?

At least for now, I've added this to the blocks-5.12 list

I can't really see that this is a 5.12 showstopper.

It's present in 5.8.x, and is just one of a whole class of bugs wherein
perl misreports line numbers. It really needs fixing as part of a general
post-5.12 overhaul of the line number reporting system, rather than
throwing another one-off hack at it.

I'd just like to wave the flag for this bug again.

Tim.