From vincent@vinc17.net

Created by vincent@vinc17.net

When a signal is received while a __WARN__ handler is being run and
the signal handler contains a "warn" call, the __WARN__ handler is
disabled for this call.

The perlvar(1) man page says that the __WARN__ handler is disabled
during a "warn" call, so that one can call "warn" from this handler,
but the case reported here is different, because the signal handler
is independent from the initial "warn". I would expect that the
__WARN__ handler be enabled in the signal handler, or at least the
behavior should be documented.

The problem can be reproduced with the following script. This script
spends much time in the __WARN__ handler, but in an non-test script,
I get the same kind of problem with

  $SIG{__WARN__} = sub { warn strftime("[%Y-%m-%d %T] ", gmtime).$_[0] };

probably because pending signals (e.g. SIGTERM) are received together
with SIGCONT.

#!/usr/bin/env perl

use strict;

sub wout ($)
  { print STDERR $_[0] }

$SIG{__WARN__} = sub { wout "warn​: $_[0]"; sleep 2; };

my $term = 0;

sub handler
  {
  $_[0] eq 'TERM' and $term = 1;
  my $s = "SIG$_[0] received.\n";
  wout "wout​: $s";
  warn $s;
  }

$SIG{'TERM'} = \&handler;
$SIG{'CONT'} = \&handler;

print "__WARN__ test, using perl $^V under $^O.\n";

my $pid = fork;
defined $pid or die "can't fork ($!)\n";

if ($pid)
  {
  kill 'CONT', $pid;
  sleep 1;
  kill 'STOP', $pid;
  sleep 2;
  kill 'TERM', $pid;
  sleep 1;
  kill 'CONT', $pid;
  waitpid $pid, 0;
  }
else
  {
  until ($term)
  { }
  sleep 1;
  }

__END__

One gets​:

$ ./warn-hook.pl
__WARN__ test, using perl v5.14.2 under linux.
wout​: SIGCONT received.
warn​: SIGCONT received.
wout​: SIGTERM received.
SIGTERM received.
wout​: SIGCONT received.
warn​: SIGCONT received.

Flags:
    category=core
    severity=low

Site configuration information for perl 5.14.2:

Configured by Debian Project at Sun Jan 29 19:10:47 UTC 2012.

Summary of my perl5 (revision 5 version 14 subversion 2) configuration:
   
  Platform:
    osname=linux, osvers=2.6.32-5-amd64, archname=x86_64-linux-gnu-thread-multi
    uname='linux barber 2.6.32-5-amd64 #1 smp mon jan 9 20:49:59 utc 2012 x86_64 gnulinux '
    config_args='-Dusethreads -Duselargefiles -Dccflags=-DDEBIAN -Dcccdlflags=-fPIC -Darchname=x86_64-linux-gnu -Dprefix=/usr -Dprivlib=/usr/share/perl/5.14 -Darchlib=/usr/lib/perl/5.14 -Dvendorprefix=/usr -Dvendorlib=/usr/share/perl5 -Dvendorarch=/usr/lib/perl5 -Dsiteprefix=/usr/local -Dsitelib=/usr/local/share/perl/5.14.2 -Dsitearch=/usr/local/lib/perl/5.14.2 -Dman1dir=/usr/share/man/man1 -Dman3dir=/usr/share/man/man3 -Dsiteman1dir=/usr/local/man/man1 -Dsiteman3dir=/usr/local/man/man3 -Duse64bitint -Dman1ext=1 -Dman3ext=3perl -Dpager=/usr/bin/sensible-pager -Uafs -Ud_csh -Ud_ualarm -Uusesfio -Uusenm -Ui_libutil -DDEBUGGING=-g -Doptimize=-O2 -Duseshrplib -Dlibperl=libperl.so.5.14.2 -des'
    hint=recommended, useposix=true, d_sigaction=define
    useithreads=define, usemultiplicity=define
    useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
    use64bitint=define, use64bitall=define, uselongdouble=undef
    usemymalloc=n, bincompat5005=undef
  Compiler:
    cc='cc', ccflags ='-D_REENTRANT -D_GNU_SOURCE -DDEBIAN -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64',
    optimize='-O2 -g',
    cppflags='-D_REENTRANT -D_GNU_SOURCE -DDEBIAN -fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include'
    ccversion='', gccversion='4.6.2', gccosandvers=''
    intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
    ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
    alignbytes=8, prototype=define
  Linker and Libraries:
    ld='cc', ldflags =' -fstack-protector -L/usr/local/lib'
    libpth=/usr/local/lib /lib/x86_64-linux-gnu /lib/../lib /usr/lib/x86_64-linux-gnu /usr/lib/../lib /lib /usr/lib
    libs=-lgdbm -lgdbm_compat -ldb -ldl -lm -lpthread -lc -lcrypt
    perllibs=-ldl -lm -lpthread -lc -lcrypt
    libc=, so=so, useshrplib=true, libperl=libperl.so.5.14.2
    gnulibc_version='2.13'
  Dynamic Linking:
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E'
    cccdlflags='-fPIC', lddlflags='-shared -O2 -g -L/usr/local/lib -fstack-protector'

Locally applied patches:
    


@INC for perl 5.14.2:
    /home/vlefevre/lib/site_perl/x86_64-linux-gnu-thread-multi
    /home/vlefevre/lib/site_perl
    /etc/perl
    /usr/local/lib/perl/5.14.2
    /usr/local/share/perl/5.14.2
    /usr/lib/perl5
    /usr/share/perl5
    /usr/lib/perl/5.14
    /usr/share/perl/5.14
    /usr/local/lib/site_perl
    .


Environment for perl 5.14.2:
    HOME=/home/vlefevre
    LANG=POSIX
    LANGUAGE (unset)
    LC_CHARMAP=UTF-8
    LC_COLLATE=POSIX
    LC_CTYPE=en_US.UTF-8
    LC_TIME=en_DK
    LD_LIBRARY_PATH=/lib64:/home/vlefevre/x86_64/lib
    LOGDIR (unset)
    PATH=/home/vlefevre/eftests/bin:/home/vlefevre/bin:/home/vlefevre/x86_64/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin:/usr/games:.
    PERL5LIB=/home/vlefevre/lib/site_perl
    PERL_BADLANG (unset)
    SHELL=/bin/zsh

From @doy

I'm not sure this is really fixable - this is just how signals work.
Consider this slight modification of your script​:

  $SIG{__WARN__} = sub {
  local $SIG{__WARN__} = sub {
  warn "inner​: $_[0]";
  sleep 2;
  };
  warn "outer​: $_[0]";
  };

  $SIG{USR1} = sub {
  warn "caught USR1";
  };

  $SIG{USR2} = sub {
  warn "caught USR2";
  };

  if (my $pid = fork) {
  kill USR1 => $pid;
  sleep 1;
  kill USR2 => $pid;
  wait;
  }
  else {
  sleep 5;
  }

This prints​:

  inner​: outer​: caught USR1 at test.pl line 14.
  caught USR2 at test.pl line 18.

Do you think the second warning should be "inner​: outer​: caught USR2" or
"inner​: caught USR2"? How do you determine which warn handler to restore
during the execution of the signal? I think this is just another example
of the complications involved in using signals, and probably can't be
fixed in any sane way. If nobody points out anything dumb I'm missing,
I'll probably close this as wontfix in a while.

-doy

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

From vincent@vinc17.net

On 2012-06-26 16​:52​:01 -0700, Jesse Luehrs via RT wrote​:

I'm not sure this is really fixable - this is just how signals work.
Consider this slight modification of your script​:

$SIG{__WARN__} = sub {
local $SIG{__WARN__} = sub {
warn "inner​: $_[0]";
sleep 2;
};
warn "outer​: $_[0]";
};

$SIG{USR1} = sub {
warn "caught USR1";
};

$SIG{USR2} = sub {
warn "caught USR2";
};

if (my $pid = fork) {
kill USR1 => $pid;
sleep 1;
kill USR2 => $pid;
wait;
}
else {
sleep 5;
}

This prints​:

inner​: outer​: caught USR1 at test.pl line 14.
caught USR2 at test.pl line 18.

Do you think the second warning should be "inner​: outer​: caught USR2" or
"inner​: caught USR2"?

Here this is a bit particular because of the "local". I don't think
that code executed in a signal handler should be affected by a local
(dynamic) variable that has been set outside the handler execution,
otherwise one could get obscure side effects. For instance, consider

#!/usr/bin/env perl

$SIG{USR1} = sub {
  open FILE, "/etc/crontab" or die;
  my $line = <FILE>;
  print $line;
  close FILE or die;
  exit;
};

print "$$\n";
my $file = do { local $/; <STDIN> };
print $file;

The current behavior when the USR1 signal is received in the do block
is that /etc/crontab is printed entirely. I don't think this is what
the user expects. Also remember that modules may also use local() for
internal implementation, so that handlers written by a user may not
be reliable if they depend on Perl variables.

So, in your example, for USR2,

sub {
  local $SIG{__WARN__} = sub {
  warn "inner​: $_[0]";
  sleep 2;
  };
  warn "outer​: $_[0]";
  };

should be executed and give "inner​: outer​: caught USR2".

How do you determine which warn handler to restore during the
execution of the signal?

The global one should be restored (more generally, any local should
lose its effect, as if it never occurred).

--
Vincent Lefèvre <vincent@​vinc17.net> - Web​: <http​://www.vinc17.net/>
100% accessible validated (X)HTML - Blog​: <http​://www.vinc17.net/blog/>
Work​: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)