From: Michael Fuhr <mike@fuhr.org>
To: Craig A. James <cjames@modgraph-usa.com>
Cc: Pgsql-Performance <pgsql-performance@postgresql.org>
Subject: Re: Perl DBD and an alarming problem
Date: Wed, 16 Nov 2005 17:23:45 -0700
Message-ID: <20051117002344.GA55377@winnie.fuhr.org> (raw)
In-Reply-To: <437B9DA9.2030806@modgraph-usa.com>
References: <BF9F6C0E.13B4A%llonergan@greenplum.com>
<1132136225.5711.4.camel@Panoramix>
<437B9DA9.2030806@modgraph-usa.com>
On Wed, Nov 16, 2005 at 12:59:21PM -0800, Craig A. James wrote:
> eval {
> local $SIG{ALRM} = sub {die("Timeout");};
> $time = gettimeofday;
> alarm 20;
> $sth = $dbh->prepare("a query that may take a long time...");
> $sth->execute();
> alarm 0;
> };
> if ($@ && $@ =~ /Timeout/) {
> my $elapsed = gettimeofday - $time;
> print "Timed out after $elapsed seconds";
> }
>
> Now the mystery: It works, but it hardly matters what time I use for the
> alarm call, the actual alarm event always happens at 26 seconds. I can set
> "alarm 1" or "alarm 20", and it almost always hits right at 26 seconds.
High-level languages' signal handlers don't always work well with
low-level libraries. I haven't dug into the Perl source code but
I'd guess that since only certain things are safe to do in a signal
handler, Perl's handler simply sets some kind of state that the
interpreter will examine later during normal execution. If you're
using only Perl facilities then that probably happens fairly timely,
but if you're stuck in a low-level library (e.g., libpq) then you
might have to wait until that library returns control to Perl before
Perl recognizes that a signal occurred.
As an example, if I run code such as yours with alarm(2) and a query
that takes 5 seconds, I see the following in a process trace (from
ktrace/kdump on FreeBSD):
55395 perl 0.000978 CALL poll(0xbfbfe1b8,0x1,0xffffffff)
55395 perl 1.996629 RET poll -1 errno 4 Interrupted system call
55395 perl 0.000013 PSIG SIGALRM caught handler=0x281be22c mask=0x0 code=0x0
55395 perl 0.000050 CALL sigprocmask(0x1,0,0x805411c)
55395 perl 0.000005 RET sigprocmask 0
55395 perl 0.000020 CALL sigreturn(0xbfbfde60)
55395 perl 0.000007 RET sigreturn JUSTRETURN
55395 perl 0.000019 CALL poll(0xbfbfe1b8,0x1,0xffffffff)
55395 perl 3.004065 RET poll 1
55395 perl 0.000024 CALL recvfrom(0x3,0x81c6000,0x4000,0,0,0)
55395 perl 0.000016 GIO fd 3 read 60 bytes
The poll() call is interrupted by SIGALRM after 2 seconds but then
it starts again and doesn't return until the query completes after
the remaining 3 seconds. Only sometime later does Perl invoke the
ALRM handler I installed, presumably because it can't do so until
the low-level code returns control to Perl.
Is there a reason you're using alarm() in the client instead of
setting statement_timeout on the server?
--
Michael Fuhr
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-performance@postgresql.org
Cc: mike@fuhr.org, cjames@modgraph-usa.com
Subject: Re: Perl DBD and an alarming problem
In-Reply-To: <20051117002344.GA55377@winnie.fuhr.org>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox