Thread: Pg + perl + apache

I'm having some odd issues, but I'm not sure exactly the cause of them,
but postgres is the component in the system that is throwing the errors,
so I thought I'd start here.

I have built a web application that uses postgres (7.3.2) as its
backend, with the front being an Apache2/mod_perl solution.  I've
printed what I think the relevant versions are below.

Anway, DBD::Pg throws random errors into my logs, along the lines of
what is below (the lines beginning with SQL are debug statements from
the script, and are the lines references by the DBD error.

SQL: SELECT session_key FROM session WHERE user_id = 101 at
/home/dragon/public_html/iactweb/lib/perl/Apache/IACT/AuthUtil.pm line 38.
DBD::Pg::db selectrow_array failed: ERROR:  current transaction is
aborted, queries ignored until end of transaction block at
/home/dragon/public_html/iactweb/lib/perl/Apache/IACT/AuthUtil.pm line 40.
[Thu Feb 12 18:48:13 2004] [error] [client 127.0.0.1] DBD::Pg::db
selectrow_array failed: ERROR:  current transaction is aborted, queries
ignored until end of transaction block at
/home/dragon/public_html/iactweb/lib/perl/Apache/IACT/AuthUtil.pm line 40.

with the corresponding postgresql.log entry being

LOG:  statement: SELECT session_key FROM session WHERE user_id = 101
ERROR:  current transaction is aborted, queries ignored until end of
transaction block

This seems to randomly happen in my application, resulting in an error
page being returned to the user.  However, if the user refreshes their
browser (sometimes more than once), it seems to come back fine.  I have
seen it happen with DBD::Pg::db st, selectrow_array, selectrow_arrayref,
and selectrow_hashref.

The components of the system currently are (upgraded this morning to the
latest):

DBI 1.40
DBD::Pg 1.31
Apache::DBI 0.93
Apache 2.0.48 and 2.0.47
mod_perl 1.99.11 and 1.99.12
PostgreSQL 7.4.1 and 7.3.2

I'm leaning towards blaming the interaction between DBI and Apache::DBI
(persists DB connections within apache), but I'd like to rule out
postgres as the problem, if anyone can do that conclusively.  I never
disconnect from my DB handles, since Apache::DBI caches them, so I was
wondering about the whole 'ping' method.  I wrote a script to exercise
one of my scripts from the command line, and ran it 10000 times without
error, so I am pretty sure that there is some interaction error going on
in the system.

If anyone has seen anything like this before (i.e. random errors in a
similar apache/mod_perl) situation, or might have any pointers as to
where to look next, let me know.  What would cause postgres to return an
error for a selectrow_array, or one of those others mentioned?

Thanks
-Mike

On Sat, Feb 14, 2004 at 04:35:58PM -0500, Michael L. Artz wrote:
> I'm having some odd issues, but I'm not sure exactly the cause of them,
> but postgres is the component in the system that is throwing the errors,
> so I thought I'd start here.

<snip>
> with the corresponding postgresql.log entry being
>
> LOG:  statement: SELECT session_key FROM session WHERE user_id = 101
> ERROR:  current transaction is aborted, queries ignored until end of
> transaction block

This happens when, within a transaction gets an error, you don't notice and
keep blindly sending queries.

Scroll up to find the actual error.

If it's the first transaction in a session, that means someone forgot to
clear their transaction. I guess you could fix it then by sending "abort"
as the first query.

Hope this helps,

--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> If the Catholic church can survive the printing press, science fiction
> will certainly weather the advent of bookwarez.
>    http://craphound.com/ebooksneitherenorbooks.txt - Cory Doctorow

"Michael L. Artz" <dragon@october29.net> writes:
> Anway, DBD::Pg throws random errors into my logs, along the lines of
> what is below (the lines beginning with SQL are debug statements from
> the script, and are the lines references by the DBD error.

> LOG:  statement: SELECT session_key FROM session WHERE user_id = 101
> ERROR:  current transaction is aborted, queries ignored until end of
> transaction block

This error cannot occur unless some other error occurred previously in
the same transaction.

My bet is that you are using some sort of connection-pooling mechanism,
and are being sloppy about handing off database connections from one
Apache thread to another.  Specifically, some thread is getting an error
and then letting go of the connection without rolling back the failed
transaction on the database side.  The next guy who gets that connection
from the pool fails as above.

            regards, tom lane

On Saturday 14 February 2004 22:35, Michael L. Artz wrote:
(...)
> If anyone has seen anything like this before (i.e. random errors in a
> similar apache/mod_perl) situation, or might have any pointers as to
> where to look next, let me know.  What would cause postgres to return an
> error for a selectrow_array, or one of those others mentioned?

Just checking, but do all your scripts have :

  use strict;
  use warnings;

at the top?


Ian Barwick
barwick@gmx.net

Thanks, that did help to debug the application.  I found that my errors
weren't so random after all ... if I went to a page with a bad query,
then I would start getting the error.

So, basically, if I grab a DB connection and issue a bad query, then
every other query issued via that DB connection will not work because
they are in the same transaction?  So the following perl snippet:

----------------------------
my $dbh = DBI->connect(@database);

# invalid SQL
my $sql = "SELECT crap;";
my $sth = $dbh->prepare($sql);
$sth->execute();

$sql = "SELECT 1;";
my ($should_be_one) = $dbh->selectrow_array($sql);

$dbh->disconnect();
-----------------------------

should throw an error for *both* queries?  So I guess I need to issue a
commit after I do my queries, or else turn autocommit on.

And yes, always using strict and warnings in my scripts, and using
Apache::DBI's connection pooling to cache my DB connections.

Thanks
-Mike

Martijn van Oosterhout wrote:

>On Sat, Feb 14, 2004 at 04:35:58PM -0500, Michael L. Artz wrote:
>
>
>>I'm having some odd issues, but I'm not sure exactly the cause of them,
>>but postgres is the component in the system that is throwing the errors,
>>so I thought I'd start here.
>>
>>
>
><snip>
>
>
>>with the corresponding postgresql.log entry being
>>
>>LOG:  statement: SELECT session_key FROM session WHERE user_id = 101
>>ERROR:  current transaction is aborted, queries ignored until end of
>>transaction block
>>
>>
>
>This happens when, within a transaction gets an error, you don't notice and
>keep blindly sending queries.
>
>Scroll up to find the actual error.
>
>If it's the first transaction in a session, that means someone forgot to
>clear their transaction. I guess you could fix it then by sending "abort"
>as the first query.
>
>Hope this helps,
>
>
>

You could try something like this:

Assuming you are using perl+DBI (as per your examples).

If you are using modperl:
[modperl can override the "connect to db" for connection reuse/pooling]

begin cgi web app:
connect to db
rollback
do stuff
do more stuff
commit if ok
by default rollback
disconnect.

If you are using fastcgi:
[fastcgi - explicit DB connection reuse]
connect to db
while (fastcgi connection) {
  rollback
  do stuff
  do more stuff
  commit if ok
  by default rollback
}
rollback
disconnect

You probably want to do a rollback before you do stuff so that the
transaction times are correct. AFAIK Perl DBI automatically does a BEGIN
after a rollback or commit, so if the previous transaction was rolled back
or committed 1 hour ago, you'd be reusing a transaction that begun 1 hour
ago for something that's happening now.

This would cause select 'now'::timestamp or SELECT CURRENT_TIMESTAMP return
times that are 1 hour ago, which is usually not what you want.

Hope that helps,
At 12:40 AM 2/16/2004 -0500, Michael L. Artz wrote:

>Thanks, that did help to debug the application.  I found that my errors
>weren't so random after all ... if I went to a page with a bad query, then
>I would start getting the error.
>
>should throw an error for *both* queries?  So I guess I need to issue a
>commit after I do my queries, or else turn autocommit on.

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1


> You probably want to do a rollback before you do stuff so that the
> transaction times are correct. AFAIK Perl DBI automatically does a
> BEGIN after a rollback or commit

This was true until very recently, but the DBD::Pg code has been
rewritten so that we no longer hang around in a transaction, but
only issue a BEGIN when we need to, e.g. right before we execute
something. This will be in version 1.32, which should be released
to CPAN in about a week.

- --
Greg Sabino Mullane greg@turnstep.com
PGP Key: 0x14964AC8 200402180653

-----BEGIN PGP SIGNATURE-----

iD8DBQFAM1I+vJuQZxSWSsgRAucWAKDXkRiHX6dJRf+y3GwPgZSZ7CvB2ACfYgnt
QLhSuv8tvIrzs6mlcLEHxOU=
=oz4E
-----END PGP SIGNATURE-----