Open p5pRT opened 18 years ago
Obligatory perl -V block...
Summary of my perl5 (revision 5 version 8 subversion 8) configuration: Platform: osname=solaris\, osvers=2.6\, archname=sun4-solaris uname='sunos softsrv 5.6 generic_105181-12 sun4u sparc sunw\,ultra-1 ' config_args='' hint=recommended\, useposix=true\, d_sigaction=define usethreads=undef use5005threads=undef useithreads=undef usemultiplicity=undef useperlio=define d_sfio=undef uselargefiles=define usesocks=undef use64bitint=undef use64bitall=undef uselongdouble=undef usemymalloc=n\, bincompat5005=undef Compiler: cc='cc'\, ccflags =' -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64'\, optimize='-xO4'\, cppflags='' ccversion='Sun WorkShop 6 update 2 C 5.3 2001/05/15'\, gccversion=''\, gccosandvers='' intsize=4\, longsize=4\, ptrsize=4\, doublesize=8\, byteorder=4321 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='cc'\, ldflags =' -L/usr1/SUNWspro/WS6U2/lib -L/usr/lib -L/usr/ccs/lib ' libpth=/usr1/SUNWspro/WS6U2/lib /usr/lib /usr/ccs/lib libs=-lsocket -lnsl -ldl -lm -lc perllibs=-lsocket -lnsl -ldl -lm -lc libc=/lib/libc.so\, so=so\, useshrplib=false\, libperl=libperl.a gnulibc_version='' Dynamic Linking: dlsrc=dl_dlopen.xs\, dlext=so\, d_dlsymun=undef\, ccdlflags=' ' cccdlflags='-KPIC'\, lddlflags='-G -L/usr1/SUNWspro/WS6U2/lib -L/usr/lib -L/usr/ccs/lib'
Characteristics of this binary (from libperl): Compile-time options: PERL_MALLOC_WRAP USE_LARGE_FILES USE_PERLIO Built under solaris Compiled at Mar 1 2006 13:48:00 %ENV:
PERL5LIB="/Export/dev/production/US/SunOS5.6_sun4/lib/perl5/fis:/Export/ dev/production/OPS/SunOS5.6_sun4/lib/perl5/fis" @INC: /Export/dev/production/US/SunOS5.6_sun4/lib/perl5/fis /Export/dev/production/OPS/SunOS5.6_sun4/lib/perl5/fis /usr/local/lib/perl5/5.8.8/sun4-solaris /usr/local/lib/perl5/5.8.8 /usr/local/lib/perl5/site_perl/5.8.8/sun4-solaris /usr/local/lib/perl5/site_perl/5.8.8 /usr/local/lib/perl5/site_perl .
As English as I can describe the issue:
When "use warnings FATAL => 'all'" is used\, AND there is a system or backtick (`) call to a non-existant entity\, then everything after the "use" and "BEGIN" blocks may be evaluated and executed twice. There are four samples below\, none use or require anything\, except the warnings and strict pragmas.
Background: I ran into an issue because a home-made module was running a back-tick to grab a default from a program that doesn't always exist. When that module was updated to "use warnings FATAL => 'all'"\, it broke under my login shell (as I didn't have the external program in my path). So\, the first sample is the super-stripped module execution version of the error. The others are encompassed in begin blocks.
The final one is a recreation of the error without the "FATAL" modifier.
This bug appears the same with 5.6.1\, 5.8.4 and 5.8.8 on Sun-Sparc-Solaris. It appeared on Generic-x86-Solaris native Perl build as well. It could not be duplicated on random tests against Cygwin\, Windows native\, Linux (Gentoo)\, and a MacOS 8 perl\, so it appears that this issue is specific to Solaris.
Sample #1: two files - If __END__ is added to shell_error.pl\, the declaration mask error and double execution goes away.
./ShellErr.pm +++++ package ShellErr; use strict; use warnings FATAL => 'all'; my $other = `nonesuch`; # nonesuch doesn't exist. 1; +++++ ./shell_error.pl +++++ use strict; use warnings; # turn on the re-declared $this warning
use ShellErr; CHECK { print "CHECK!\n"; } # prints twice
my $this = 'that'; print $this\, "\n"; +++++ OUTPUT: +++++ Can't exec "doesntexist": No such file or directory at ShellErr.pm line 5. Compilation failed in require at ./shell_error.pl line 7. BEGIN failed--compilation aborted at ./shell_error.pl line 7. "my" variable $this masks earlier declaration in same scope at ./shell_error.pl line 27. CHECK! CHECK! that that +++++
Sample #2: Removes the module\, same issue. Again __END__ will mitigate the double-execution.
shell2_err.pl +++++ use strict; use warnings; # turn on the re-declared $this warning
BEGIN { # Only happens during BEGIN use warnings FATAL => 'all'; # only happens with FATAL => 'all'; system('doesntexist'); # causes issues } CHECK { print "CHECK!\n"; } # prints twice
my $this = 'that'; # prints redeclaration error print $this\, "\n"; +++++ OUTPUT: +++++ Can't exec "doesntexist": No such file or directory at ./shell2_err.pl line 6. BEGIN failed--compilation aborted at ./shell2_err.pl line 7. "my" variable $this masks earlier declaration in same scope at ./shell2_err.pl line 14. CHECK! CHECK! that that +++++
Sample #3: hide errors with eval... this time it doesn't seem to be re-evaluating\, but it is completing execution twice (due to the lack of the declaration mask warning). Also\, this case is not mitigated with the addition of an __END__
shell3_err.pl +++++ use strict; use warnings; # turn on the re-declared $this warning
BEGIN { # Only happens during BEGIN use warnings FATAL => 'all'; # only happens with FATAL => 'all'; eval { system('doesntexist') }; # causes issues } CHECK { print "CHECK!\n"; } # prints twice
my $this = 'that'; print $this\, "\n"; +++++ OUTPUT: +++++ CHECK! that CHECK! that +++++
Sample #4: This one replicates the issue without using the "use warnings FATAL => 'all'" pragma\, and may be helpful in understanding what is really going wrong. Again\, on this example\, adding __END__ mitigates the double-execution. Some other things with the program below. If "close KID" moves out of the begin block\, the error changes significantly...
shell4_err.pl:
+++++
use strict;
use warnings; # need this for the redelcaration warning
my $status;
BEGIN { # only happens during BEGIN
die "Can't fork: $!" unless defined(my $pid = open(KID\, "-|"));
if ($pid) { # parent
$status = "PARENT";
close KID;
} else {
$status = "KID";
exec 'not_there' or die "cannot exec not_there: $!";
}
}
CHECK { print "$status: CHECK!\n"; } # prints twice INIT { print "$status: INIT\n" } # prints twice
my $this = 'that'; # prints a redeclaration warning my $i = 0; print "$status: $this\n"; # prints twice print $i++\, "\n"; +++++ OUTPUT: +++++ Can't exec "not_there": No such file or directory at shell4_err.pl line 11. cannot exec not_there: No such file or directory at shell4_err.pl line 11. BEGIN failed--compilation aborted at shell4_err.pl line 13. "my" variable $this masks earlier declaration in same scope at shell4_err.pl line 24. PARENT: CHECK! PARENT: CHECK! PARENT: INIT PARENT: INIT PARENT: that PARENT: that +++++
Thank you\, Gary Allen Vollink
To find out more about Reuters visit www.about.reuters.com
Any views expressed in this message are those of the individual sender\, except where the sender specifically states them to be the views of Reuters Ltd.
On Thu\, Aug 17\, 2006 at 07:39:07AM -0700\, Gary Vollink wrote:
Sample #4: This one replicates the issue without using the "use warnings FATAL => 'all'" pragma\, and may be helpful in understanding what is really going wrong. Again\, on this example\, adding __END__ mitigates the double-execution. Some other things with the program below. If "close KID" moves out of the begin block\, the error changes significantly...
Can't exec "not_there": No such file or directory at shell4_err.pl line 11. cannot exec not_there: No such file or directory at shell4_err.pl line 11. BEGIN failed--compilation aborted at shell4_err.pl line 13. "my" variable $this masks earlier declaration in same scope at shell4_err.pl line 24. PARENT: CHECK! PARENT: CHECK! PARENT: INIT PARENT: INIT PARENT: that PARENT: that
Most strange. truss shows that all the writes are in the parent:
1609: write(1\, " P A R E N T : C H E C"..\, 15) = 15 1609: write(1\, " P A R E N T : C H E C"..\, 15) = 15 1609: write(1\, " P A R E N T : I N I T"..\, 13) = 13 1609: write(1\, " P A R E N T : I N I T"..\, 13) = 13 1609: write(1\, " P A R E N T : t h a t"..\, 13) = 13 1609: write(1\, " 0\n"\, 2) = 2 1609: write(1\, " P A R E N T : t h a t"..\, 13) = 13 1609: write(1\, " 0\n"\, 2) = 2
So it's nothing as obvious as the child process failing to _exit() at the appropriate time.
Nicholas Clark
The RT System itself - Status changed from 'new' to 'open'
On Sun\, Aug 20\, 2006 at 07:47:34PM +0100\, Nicholas Clark wrote:
Most strange. truss shows that all the writes are in the parent:
1609: write(1\, " P A R E N T : C H E C"..\, 15) = 15 1609: write(1\, " P A R E N T : C H E C"..\, 15) = 15 1609: write(1\, " P A R E N T : I N I T"..\, 13) = 13 1609: write(1\, " P A R E N T : I N I T"..\, 13) = 13 1609: write(1\, " P A R E N T : t h a t"..\, 13) = 13 1609: write(1\, " 0\n"\, 2) = 2 1609: write(1\, " P A R E N T : t h a t"..\, 13) = 13 1609: write(1\, " 0\n"\, 2) = 2
So it's nothing as obvious as the child process failing to _exit() at the appropriate time.
B::Deparse shows that most of the program is duplicated. I think it's an interaction between fork() and the file position on the descriptor used to read the program. I can't remember exactly what the Solaris behaviour is\, but there's something it does differently from most other operating systems\, I think at child exit\, where it seeks file descriptors. Hopefully someone else can fill me in.
But what's happening is that the after the child exits\, the underlying Unix file descriptor that the interpreter is reading the program from has its position moved back\, because that descriptor was shared with the child. The interpreter first reads all the buffered data\, so you get the program compiled once. When the buffer is empty\, it is refilled from the underlying descriptor\, which "should" have been at EOF\, but now isn't. So parts of the program get read again.
I say "should" because I can't remember whose "fault" all this emergent behaviour is. It was discussed previously (in another context)
Nicholas Clark
On Sun Aug 20 12:02:54 2006\, nicholas wrote:
On Sun\, Aug 20\, 2006 at 07:47:34PM +0100\, Nicholas Clark wrote:
Most strange. truss shows that all the writes are in the parent:
1609: write(1\, " P A R E N T : C H E C"..\, 15) = 15 1609: write(1\, " P A R E N T : C H E C"..\, 15) = 15 1609: write(1\, " P A R E N T : I N I T"..\, 13) = 13 1609: write(1\, " P A R E N T : I N I T"..\, 13) = 13 1609: write(1\, " P A R E N T : t h a t"..\, 13) = 13 1609: write(1\, " 0\n"\, 2) = 2 1609: write(1\, " P A R E N T : t h a t"..\, 13) = 13 1609: write(1\, " 0\n"\, 2) = 2
So it's nothing as obvious as the child process failing to _exit() at the appropriate time.
B::Deparse shows that most of the program is duplicated. I think it's an interaction between fork() and the file position on the descriptor used to read the program. I can't remember exactly what the Solaris behaviour is\, but there's something it does differently from most other operating systems\, I think at child exit\, where it seeks file descriptors. Hopefully someone else can fill me in.
But what's happening is that the after the child exits\, the underlying Unix file descriptor that the interpreter is reading the program from has its position moved back\, because that descriptor was shared with the child. The interpreter first reads all the buffered data\, so you get the program compiled once. When the buffer is empty\, it is refilled from the underlying descriptor\, which "should" have been at EOF\, but now isn't. So parts of the program get read again.
I say "should" because I can't remember whose "fault" all this emergent behaviour is. It was discussed previously (in another context)
Nicholas Clark
This is still present in 5.14.2 and blead.
#3 here is actually an entirely separate issue\, reported at [perl #96332]. It happens because the warning about the exec() failing is generated by the child\, which expects to be able to call exit() after the warn\, but can't do that if the warning is turned into an exception (which unwinds the stack instead).
-doy
Migrated from rt.perl.org#40190 (status was 'open')
Searchable as RT40190$