Re: DBD::Pg returns "DBD::Pg::st execute failed: connection not open"

Hello Greg --

On 05/02/2008, Greg Sabino Mullane <greg(at)turnstep(dot)com> wrote:
> Most likely a DBD::Pg bug. Some ideas:

Before we get to the particulars, I appreciate your assistance on
this. I am rapidly coming to the same conclusion that there's either
a bug in DBD::Pg itself, or (dare I even suggest it) DBI itself.

> 1) Try out the new version of DBD::Pg and see if it helps. If so, it's
> most likely an already-fixed bug.

I used DBD::Pg version 2.0.0_9 (seemed to be the latest) and even
bumped my version of Postgres to 8.3.0. Still the same error, alas.

> 2) Try setting trace to 10 and see if you can figure out the last thing it
> did before dying.

OK. Here's the DBI->trace(10) output:

http://edulinux.homeunix.org/~n6tadam/pg-dbd-debug.txt

There's two things going on here, and it's the first thing which is
drawing my attention (and exhibiting the error in question). All the
lines up to line 1780 show that the program is correctly executing
SELECT statements and returning values just fine. This is all normal
and expected.

Line 1780 shows the query as it is passed to PQexec. You'll note the
following output after that:

dbdpg: _sqlstate PQresultStatus returned 7
dbdpg: _sqlstate set imp_dbh->sqlstate to 22000
dbdpg: _sqlstate txn_status is 4
dbdpg: Invalid status returned (7)
dbdpg: pg_error (server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
) number=7
dbdpg: sqlstate 22000 error_num 7 error server closed the connection
unexpectedly

I've looked briefly through the DDB::Pg code and noticed that an error
return of 22000 indicates that it's either as a result of
PGRES_FATAL_ERROR or something else -- but I cannot get any
information further about what the PGRES_FATAL_ERROR might entail,
either from the trace output or a literal strace of the postgres
processes.

Note that taking the query verbatim from line 1780 and pasting it into
psql inserts it correctly without any error.

Taking this further, I then decided that I couldn't really get much
more information from the trace output (hopefully you can though!) so
I then decided to tcpdump what was on port 5432. What I found via
wireshark's analysis is that there's something odd (at times) between
the connection/disconnection mechanism. What should happen is
FIN/ACK/RET get sent to and from the client, but what I have seen with
this problem is that the connection is closed (from the client), the
server says it's received that (ACK) and closed the connection, but
the client then decides to try and INSERT data anyway.

Why this would be, I do not know, nor why it should happen. It could
be a red-herring for all I know, but I thought I would mention it.

> 3) Use gdb to see what it's dying on. Run "gdb perl core" after it coredumps
> and do a "backtrace".

Sorry --- but it crashing isn't happening on my test machine, alas.
It just exists abnormally without segfaulting.

What's the next step, Greg? I'm really at a loss here as to what's
going on. If you need any further information from me, do let me
know. If you can provide a pointer as to where I might look to help
you debug this, do also let me know.

-- Thomas Adam