Thread: pl/perl error

I have a perl script running as a daemon.  It's using DBD::Pg (1.43) to
connect to my Postgres server (8.0.7) running on the same box and talking
over a socket.  When I start the server, it runs fine for about a day, and
then at some point I start getting this error repeatedly:

DBD::Pg::db do failed: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.

There are only two calls to DBI->do in my script which amount to:

update foo set ipaddr = null where ipaddr = '$ip' and mac != '$mac'

and

update foo set ipaddr = '$ip' where mac = '$mac'

The first statement is run fairly often and I believe it's the one
resulting in the error.  Usually when it is run, it doesn't actually modify
the database, i.e. mac will == $mac.

As soon as I restart my script, it runs fine again for about a day and then
it blows up in the same fashion.

My table is set up like:

CREATE TABLE foo (
    mac    macaddr UNIQUE,
    ipaddr inet    UNIQUE
);

There are two triggers on this table:

create trigger new_mac
 AFTER INSERT OR UPDATE ON foo
 FOR EACH ROW EXECUTE PROCEDURE new_foo_fx();

create trigger remove_mac
 BEFORE DELETE ON macs
 FOR EACH ROW EXECUTE PROCEDURE remove_foo_fx();

Neither of these procedures modify what the statement does to the database.
They make some external changes and then "return;".  The only hit I see in
Google for this error message refers to the trigger documentation which
talks about the return value of triggers.  However, section 32.1 (Overview
of Trigger Behavior) and section 37.6 (PL/Perl Triggers) seem to disagree.
I went with the PL/Perl example assuming that it does the Right Thing
behind the scenes.

At first I thought this was my script losing connection to the database, so
I started using DBI->connect_cached but that didn't change anything.
Neither of my calls to DBI->do() seem to throw an error, i.e.

$dbh->do($statement) or  { warn $dbh->errstr }

doesn't output anything.

I just increased my postgres debug to -d 2 to see if that provides any
useful information.  Does anyone else have any debugging suggestions or
know what might be causing this problem?

Thanks,
Frank

Frank <archon@forbidden.dough.net> writes:

> I have a perl script running as a daemon.  It's using DBD::Pg (1.43) to
> connect to my Postgres server (8.0.7) running on the same box and talking
> over a socket.  When I start the server, it runs fine for about a day, and
> then at some point I start getting this error repeatedly:
>
> DBD::Pg::db do failed: server closed the connection unexpectedly
> This probably means the server terminated abnormally
> before or while processing the request.

There should be something in the server logs that corresponds to
this--what do they say?

-Doug

Frank <archon@forbidden.dough.net> writes:
> I have a perl script running as a daemon.  It's using DBD::Pg (1.43) to
> connect to my Postgres server (8.0.7) running on the same box and talking
> over a socket.  When I start the server, it runs fine for about a day, and
> then at some point I start getting this error repeatedly:

> DBD::Pg::db do failed: server closed the connection unexpectedly
> This probably means the server terminated abnormally
> before or while processing the request.

Do you see any complaint in the postmaster log when this happens?  If so
what?

I'd personally wonder about a memory leak or something like that in your
trigger functions.

            regards, tom lane

On Sun, Apr 09, 2006 at 06:22:40PM -0400, Tom Lane wrote:
> Frank <archon@forbidden.dough.net> writes:
> > I have a perl script running as a daemon.  It's using DBD::Pg (1.43) to
> > connect to my Postgres server (8.0.7) running on the same box and talking
> > over a socket.  When I start the server, it runs fine for about a day, and
> > then at some point I start getting this error repeatedly:
>
> > DBD::Pg::db do failed: server closed the connection unexpectedly
> > This probably means the server terminated abnormally
> > before or while processing the request.
>
> Do you see any complaint in the postmaster log when this happens?  If so
> what?
>
> I'd personally wonder about a memory leak or something like that in your
> trigger functions.
>
>             regards, tom lane
>

After running with debugging at level 2, I saw that the script died at
00:57:35.  Attached is the log from that time.  I noticed specifically the
following lines:

Apr  9 00:57:35 MYSERVER postgres[7881]: [511892-1] LOG:  disconnection: session time: 9:33:45.60 user=dbuser
database=mydbhost=[local] port= 
Apr  9 00:57:35 MYSERVER postgres[7874]: [13-1] DEBUG:  server process (PID 7881) exited with exit code 0
Apr  9 00:57:35 MYSERVER postgres[7874]: [14-1] DEBUG:  forked new backend, pid=10009 socket=7

I don't see those lines at all before the problems begin, but I notice them
very often afterwards.  Would I see the memory leak in the postgres
footprint?  I will attempt to monitor the server's memory usage.  Any other
debugging tips?

Thanks,
Frank