Hi,

I've been converting some old CGI scripts for use with mod_perl and
Apache::DBI. These scripts access a Postgres database through DBI. I
didn't have any trouble until I began writing a new script which in the
development phase has generated a few bad SQL commands (my fault, not
the problem). This has had the unexpected side effect of preventing
*any* older script running in the same process from executing SQL! The
error messages for these (perfectly fine) scripts is "current
transaction is aborted, commands ignored until end of transaction
block," which I'm guessing means that Postgres is assuming I'm in the
same transaction as generated the original error, even though it's a
completely unrelated script.

So I looked into it and found that Apache::DBI is supposed to have a
'cleanup handler' that automatically does a rollback after a script has
been run. Shouldn't this take care of the "ignoring until end of block"
thing? I'm fairly new to the 'transactions' concept but I'm guessing
that a ROLLBACK or a COMMIT is the same thing as "ending the transaction
block", right?

So anyway, I recompiled mod_perl to ensure these kinds of handlers were
enabled, restarted the server with $Apache::DBI::DEBUG set to 2, and
sure enough, I started getting debug messages about rollbacks after each
script finished executing. Problem is.. they stopped, after awhile.
Mysteriously, about an hour after restarting, the cleanup handlers
either aren't running or aren't printing debug info anymore, and the
'transaction aborted' errors are back. Does anyone know what could cause
this, or how I could better diagnose my system?

I'm running Postgres 7.4, Perl 5.8.1, mod_perl 1.29 and Apache 1.3 on
Mac OS X Panther; mod_perl is using PerlRun and Apache::StatINC.

Brian



--
Report problems: http://perl.apache.org/bugs/
Mail list info: http://perl.apache.org/maillist/modperl.html
List etiquette: http://perl.apache.org/maillist/email-etiquette.html

--------------060703090105040306030108
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

Brian Dimeler wrote:

> So anyway, I recompiled mod_perl to ensure these kinds of handlers
> were enabled, restarted the server with $Apache::DBI::DEBUG set to 2,
> and sure enough, I started getting debug messages about rollbacks
> after each script finished executing. Problem is.. they stopped, after
> awhile. Mysteriously, about an hour after restarting, the cleanup
> handlers either aren't running or aren't printing debug info anymore,
> and the 'transaction aborted' errors are back. Does anyone know what
> could cause this, or how I could better diagnose my system?

Do you ever connect to a different database from your mod_perl scripts
-- or to the same database with different options? Or even use a
different form for the database hostname (hostname only vs.
fully-qualified domain name)?

If you do, please try this patch (inline and attached) against the
current Apache::DBI. I believe it fixes a bug in rolling back
transactions when more than one database handle is used.

Joe

--- DBI.pm.orig Tue Feb 17 16:18:50 2004
+++ DBI.pm Tue Aug 31 14:48:58 2004
[at] [at] -21,7 +21,6 [at] [at]
my %Rollback; # keeps track of pushed PerlCleanupHandler which can
do a rollback after the request has finished
my %PingTimeOut; # stores the timeout values per data_source, a
negative value de-activates ping, default = 0
my %LastPingTime; # keeps track of last ping per data_source
-my $Idx; # key of %Connected and %Rollback.


# supposed to be called in a startup script.
[at] [at] -67,7 +66,7 [at] [at]
my $dsn = "dbi:$drh->{Name}:$args[0]";
my $prefix = "$$ Apache::DBI ";

- $Idx = join $;, $args[0], $args[1], $args[2];
+ my $Idx = join $;, $args[0], $args[1], $args[2]; # key of
%Connected and %Rollback.

# the hash-reference differs between calls even in the same
# process, so de-reference the hash-reference
[at] [at] -96,7 +95,7 [at] [at]
# TODO - Fix mod_perl 2.0 here
if(!$Rollback{$Idx} and $needCleanup and
Apache->can('push_handlers')) {
print STDERR "$prefix push PerlCleanupHandler \n" if
$Apache::DBI::DEBUG > 1;
- Apache->push_handlers("PerlCleanupHandler", \&cleanup);
+ Apache->push_handlers("PerlCleanupHandler", sub { cleanup($Idx) });
# make sure, that the rollback is called only once for every
# request, even if the script calls connect more than once
$Rollback{$Idx} = 1;
[at] [at] -155,6 +154,7 [at] [at]
# Note: the PerlCleanupHandler runs after the response has been sent to
the client

sub cleanup {
+ my $Idx = shift;
my $prefix = "$$ Apache::DBI ";
print STDERR "$prefix PerlCleanupHandler \n" if $Apache::DBI::DEBUG
> 1;
my $dbh = $Connected{$Idx};


--------------060703090105040306030108
Content-Type: text/plain;
name="joetpatch"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
filename="joetpatch"


--- DBI.pm.orig Tue Feb 17 16:18:50 2004
+++ DBI.pm Tue Aug 31 14:48:58 2004
[at] [at] -21,7 +21,6 [at] [at]
my %Rollback; # keeps track of pushed PerlCleanupHandler which can do a rollback after the request has finished
my %PingTimeOut; # stores the timeout values per data_source, a negative value de-activates ping, default = 0
my %LastPingTime; # keeps track of last ping per data_source
-my $Idx; # key of %Connected and %Rollback.


# supposed to be called in a startup script.
[at] [at] -67,7 +66,7 [at] [at]
my $dsn = "dbi:$drh->{Name}:$args[0]";
my $prefix = "$$ Apache::DBI ";

- $Idx = join $;, $args[0], $args[1], $args[2];
+ my $Idx = join $;, $args[0], $args[1], $args[2]; # key of %Connected and %Rollback.

# the hash-reference differs between calls even in the same
# process, so de-reference the hash-reference
[at] [at] -96,7 +95,7 [at] [at]
# TODO - Fix mod_perl 2.0 here
if(!$Rollback{$Idx} and $needCleanup and Apache->can('push_handlers')) {
print STDERR "$prefix push PerlCleanupHandler \n" if $Apache::DBI::DEBUG > 1;
- Apache->push_handlers("PerlCleanupHandler", \&cleanup);
+ Apache->push_handlers("PerlCleanupHandler", sub { cleanup($Idx) });
# make sure, that the rollback is called only once for every
# request, even if the script calls connect more than once
$Rollback{$Idx} = 1;
[at] [at] -155,6 +154,7 [at] [at]
# Note: the PerlCleanupHandler runs after the response has been sent to the client

sub cleanup {
+ my $Idx = shift;
my $prefix = "$$ Apache::DBI ";
print STDERR "$prefix PerlCleanupHandler \n" if $Apache::DBI::DEBUG > 1;
my $dbh = $Connected{$Idx};


--------------060703090105040306030108
Content-Type: text/plain; charset=us-ascii

--
Report problems: http://perl.apache.org/bugs/
Mail list info: http://perl.apache.org/maillist/modperl.html
List etiquette: http://perl.apache.org/maillist/email-etiquette.html
--------------060703090105040306030108--

Thanks for the suggestion, but it's the same connection with the same
params every time. The connection code is actually in a Class::DBI
module, which gets use()'d by all of my scripts. This module isn't in my
startup script, so that each process keeps its own copy. So there are
multiple handles, but they should all be identical and used by different
interpreters.

Upon further investigation I've found that the rollback is only
executing once for each server process, and never again after that.
That's true even *without* the bad SQL and transaction aborted erors.
I'm assuming that isn't the intended behavior...

Also, I read on some newsgroup that cleanups don't run if there's been a
500 error or the user hit the 'stop' button. If true, why not? Isn't
following an error the best possible time to execute cleanup code? Is
there a way, either with the mod_perl API or some standard perl trick,
to force the server to run additional code after such an error?



Joe Thomas wrote:

> Do you ever connect to a different database from your mod_perl scripts
> -- or to the same database with different options? Or even use a
> different form for the database hostname (hostname only vs.
> fully-qualified domain name)?
>
> If you do, please try this patch (inline and attached) against the
> current Apache::DBI. I believe it fixes a bug in rolling back
> transactions when more than one database handle is used.
>
> Joe
>
> --- DBI.pm.orig Tue Feb 17 16:18:50 2004
> +++ DBI.pm Tue Aug 31 14:48:58 2004
> [at] [at] -21,7 +21,6 [at] [at]
> my %Rollback; # keeps track of pushed PerlCleanupHandler which can
> do a rollback after the request has finished
> my %PingTimeOut; # stores the timeout values per data_source, a
> negative value de-activates ping, default = 0
> my %LastPingTime; # keeps track of last ping per data_source
> -my $Idx; # key of %Connected and %Rollback.
>
>
> # supposed to be called in a startup script.
> [at] [at] -67,7 +66,7 [at] [at]
> my $dsn = "dbi:$drh->{Name}:$args[0]";
> my $prefix = "$$ Apache::DBI ";
>
> - $Idx = join $;, $args[0], $args[1], $args[2];
> + my $Idx = join $;, $args[0], $args[1], $args[2]; # key of
> %Connected and %Rollback.
>
> # the hash-reference differs between calls even in the same
> # process, so de-reference the hash-reference
> [at] [at] -96,7 +95,7 [at] [at]
> # TODO - Fix mod_perl 2.0 here
> if(!$Rollback{$Idx} and $needCleanup and
> Apache->can('push_handlers')) {
> print STDERR "$prefix push PerlCleanupHandler \n" if
> $Apache::DBI::DEBUG > 1;
> - Apache->push_handlers("PerlCleanupHandler", \&cleanup);
> + Apache->push_handlers("PerlCleanupHandler", sub { cleanup($Idx)
> });
> # make sure, that the rollback is called only once for every
> # request, even if the script calls connect more than once
> $Rollback{$Idx} = 1;
> [at] [at] -155,6 +154,7 [at] [at]
> # Note: the PerlCleanupHandler runs after the response has been sent to
> the client
>
> sub cleanup {
> + my $Idx = shift;
> my $prefix = "$$ Apache::DBI ";
> print STDERR "$prefix PerlCleanupHandler \n" if $Apache::DBI::DEBUG
> > 1;
> my $dbh = $Connected{$Idx};
>
>
> ------------------------------------------------------------ ------------
>
>
> --- DBI.pm.orig Tue Feb 17 16:18:50 2004
> +++ DBI.pm Tue Aug 31 14:48:58 2004
> [at] [at] -21,7 +21,6 [at] [at]
> my %Rollback; # keeps track of pushed PerlCleanupHandler which can do a rollback after the request has finished
> my %PingTimeOut; # stores the timeout values per data_source, a negative value de-activates ping, default = 0
> my %LastPingTime; # keeps track of last ping per data_source
> -my $Idx; # key of %Connected and %Rollback.
>
>
> # supposed to be called in a startup script.
> [at] [at] -67,7 +66,7 [at] [at]
> my $dsn = "dbi:$drh->{Name}:$args[0]";
> my $prefix = "$$ Apache::DBI ";
>
> - $Idx = join $;, $args[0], $args[1], $args[2];
> + my $Idx = join $;, $args[0], $args[1], $args[2]; # key of %Connected and %Rollback.
>
> # the hash-reference differs between calls even in the same
> # process, so de-reference the hash-reference
> [at] [at] -96,7 +95,7 [at] [at]
> # TODO - Fix mod_perl 2.0 here
> if(!$Rollback{$Idx} and $needCleanup and Apache->can('push_handlers')) {
> print STDERR "$prefix push PerlCleanupHandler \n" if $Apache::DBI::DEBUG > 1;
> - Apache->push_handlers("PerlCleanupHandler", \&cleanup);
> + Apache->push_handlers("PerlCleanupHandler", sub { cleanup($Idx) });
> # make sure, that the rollback is called only once for every
> # request, even if the script calls connect more than once
> $Rollback{$Idx} = 1;
> [at] [at] -155,6 +154,7 [at] [at]
> # Note: the PerlCleanupHandler runs after the response has been sent to the client
>
> sub cleanup {
> + my $Idx = shift;
> my $prefix = "$$ Apache::DBI ";
> print STDERR "$prefix PerlCleanupHandler \n" if $Apache::DBI::DEBUG > 1;
> my $dbh = $Connected{$Idx};
>
>


--
Report problems: http://perl.apache.org/bugs/
Mail list info: http://perl.apache.org/maillist/modperl.html
List etiquette: http://perl.apache.org/maillist/email-etiquette.html

On Tue, 2004-10-26 at 15:52, Brian Dimeler wrote:
> The connection code is actually in a Class::DBI
> module, which gets use()'d by all of my scripts.

Bingo, that's the problem. Class::DBI uses Ima::DBI, which does not
play well with Apache::DBI. It keeps its own connection cache in
closures and Apache::DBI doesn't know about it.

I plan to submit a patch for Ima::DBI to fix this, but in the meantime I
am handling it by overriding db_Main and doing the connections myself.
Here's the code I use:

my $db_options = {
RaiseError => 1,
AutoCommit => 0,
FetchHashKeyName => 'NAME_lc',
ShowErrorStatement => 1,
ChopBlanks => 1,
RootClass => 'DBIx::ContextualFetch'
};

# override default to avoid using Ima::DBI closure
sub db_Main {
my $dbh;
if ( $ENV{'MOD_PERL'} and !$Apache::ServerStarting ) {
$dbh = Apache->request()->pnotes('dbh');
}
if ( !$dbh ) {
# $config is my config object. replace with your own
settings...
$dbh = DBI->connect_cached(
$config->get('DbDSN'), $config->get('DbUser'),
$config->get('DbPass'), $db_options
);
if ( $ENV{'MOD_PERL'} and !$Apache::ServerStarting ) {
Apache->request()->pnotes( 'dbh', $dbh );
}
}
return $dbh;
}

sub dbi_commit {
my $self = shift;
$self->db_Main()->commit();
}

sub dbi_rollback {
my $self = shift;
$self->db_Main()->rollback();
}


Note that it was necessary to override dbi_commit and dbi_rollback as
well because now Ima::DBI doesn't know about this handle. I also
stashed the handle in pnotes() for some extra speed because Class::DBI
requests it so frequently. Stashing in pnotes() is safe because it gets
cleared out at the end of each request even if your code dies. Make
sure you keep the other db options intact or various things in
Class::DBI will break.

- Perrin


--
Report problems: http://perl.apache.org/bugs/
Mail list info: http://perl.apache.org/maillist/modperl.html
List etiquette: http://perl.apache.org/maillist/email-etiquette.html

Heyho,

I spent ages trying to track down a mysql/Apache::DBI
bug, and whilst I'm not sure what's going wrong with
your system, I found it useful to add the PID of the
individual mysql process (not sure if you can do this
with postgresql) to the $dbh and then implement a
error handler which logs the pid. Then (again not sure
if you can do this in postgres) trace that pid to a DB
log file. in mysql you can get the last run command of
that PID, and then see if something is amiss on the DB
end...

Anyway here's a quick brain dump, you'll probably have
to tailor this to your needs..


Regards

Marty


something like this:-

my $dbh;

my %attrs=();
$attrs{RaiseError}=1;

if ($DBI::VERSION >= 1.21)
{
#cos old DBI doesn't support this and we had
many versions running
#cluck ("Adding ErrorHandler as DBI (version
$DBI::VERSION) Supports this method\n");
$attrs{HandleError}=\&DBIErrorHandler;
}
else
{
#cluck ("Not Adding ErrorHandler Support as DBI
version ($DBI::VERSION) Does not support this
method\n")
;
}

eval
{
$dbh = DBI->connect(
$dsn,
$db_user,
$db_password,
\%attrs
);
}; #because our bug was in the connect, you may
not need this

my $c_id;
eval
{
my $stm_id = qq{SELECT connection_id()};
($c_id) = $dbh->selectrow_array($stm_id);
};

if ($ [at] )
{
#Probably older version of mysql, ignore
$c_id='UNKNOWN - PROBABLY AN OLD DB Server';
}

$dbh->{private_MY_HASH}->{connection_id}=$c_id;



sub DBIErrorHandler
{
my $sql = shift;
my $sth = shift;
my $value = shift;

my $dbh;
my $ref=ref($sth);

print STDERR "In DBIErrorHandler\n";
print STDERR "Incoming handle is '$ref'\n";
print STDERR Dumper( [at] _)."\n";

if ($ref =~ /DBI::st$/)
{
#print STDERR "IS a STH\n";
$dbh=$sth->{Database};
}
elsif($ref =~ /DBI::db$/)
{
#print STDERR "IS a DBH\n";
$dbh=$sth;
}
else
{
print STDERR "Unable to Determine db/sth from ".
Dumper($sth);
$dbh=$sth;
}

if (ref($dbh) eq 'HASH')
{
print STDERR "\nConnection ID is
'".$dbh->{private_MY_HASH}->{connection_id}."'\n";
}
else
{
print STDERR '\nConnection ID cannot be
established, $dbh is not a hashref';
}

return 0; #Return false so RaiseError is now
executed

}



--- Joe Thomas <joet [at] tellme.com> wrote:
> Brian Dimeler wrote:
>
> > So anyway, I recompiled mod_perl to ensure these
> kinds of handlers
> > were enabled, restarted the server with
> $Apache::DBI::DEBUG set to 2,
> > and sure enough, I started getting debug messages
> about rollbacks
> > after each script finished executing. Problem is..
> they stopped, after
> > awhile. Mysteriously, about an hour after
> restarting, the cleanup
> > handlers either aren't running or aren't printing
> debug info anymore,
> > and the 'transaction aborted' errors are back.
> Does anyone know what
> > could cause this, or how I could better diagnose
> my system?
>
> Do you ever connect to a different database from
> your mod_perl scripts
> -- or to the same database with different options?
> Or even use a
> different form for the database hostname (hostname
> only vs.
> fully-qualified domain name)?
>
> If you do, please try this patch (inline and
> attached) against the
> current Apache::DBI. I believe it fixes a bug in
> rolling back
> transactions when more than one database handle is
> used.
>
> Joe
>
> --- DBI.pm.orig Tue Feb 17 16:18:50 2004
> +++ DBI.pm Tue Aug 31 14:48:58 2004
> [at] [at] -21,7 +21,6 [at] [at]
> my %Rollback; # keeps track of pushed
> PerlCleanupHandler which can
> do a rollback after the request has finished
> my %PingTimeOut; # stores the timeout values per
> data_source, a
> negative value de-activates ping, default = 0
> my %LastPingTime; # keeps track of last ping per
> data_source
> -my $Idx; # key of %Connected and
> %Rollback.
>
>
> # supposed to be called in a startup script.
> [at] [at] -67,7 +66,7 [at] [at]
> my $dsn = "dbi:$drh->{Name}:$args[0]";
> my $prefix = "$$ Apache::DBI ";
>
> - $Idx = join $;, $args[0], $args[1], $args[2];
> + my $Idx = join $;, $args[0], $args[1],
> $args[2]; # key of
> %Connected and %Rollback.
>
> # the hash-reference differs between calls even
> in the same
> # process, so de-reference the hash-reference
> [at] [at] -96,7 +95,7 [at] [at]
> # TODO - Fix mod_perl 2.0 here
> if(!$Rollback{$Idx} and $needCleanup and
> Apache->can('push_handlers')) {
> print STDERR "$prefix push
> PerlCleanupHandler \n" if
> $Apache::DBI::DEBUG > 1;
> - Apache->push_handlers("PerlCleanupHandler",
> \&cleanup);
> + Apache->push_handlers("PerlCleanupHandler",
> sub { cleanup($Idx) });
> # make sure, that the rollback is called
> only once for every
> # request, even if the script calls connect
> more than once
> $Rollback{$Idx} = 1;
> [at] [at] -155,6 +154,7 [at] [at]
> # Note: the PerlCleanupHandler runs after the
> response has been sent to
> the client
>
> sub cleanup {
> + my $Idx = shift;
> my $prefix = "$$ Apache::DBI ";
> print STDERR "$prefix PerlCleanupHandler \n" if
> $Apache::DBI::DEBUG
> > 1;
> my $dbh = $Connected{$Idx};
>
> >
> --- DBI.pm.orig Tue Feb 17 16:18:50 2004
> +++ DBI.pm Tue Aug 31 14:48:58 2004
> [at] [at] -21,7 +21,6 [at] [at]
> my %Rollback; # keeps track of pushed
> PerlCleanupHandler which can do a rollback after the
> request has finished
> my %PingTimeOut; # stores the timeout values per
> data_source, a negative value de-activates ping,
> default = 0
> my %LastPingTime; # keeps track of last ping per
> data_source
> -my $Idx; # key of %Connected and
> %Rollback.
>
>
> # supposed to be called in a startup script.
> [at] [at] -67,7 +66,7 [at] [at]
> my $dsn = "dbi:$drh->{Name}:$args[0]";
> my $prefix = "$$ Apache::DBI ";
>
> - $Idx = join $;, $args[0], $args[1], $args[2];
> + my $Idx = join $;, $args[0], $args[1],
> $args[2]; # key of %Connected and %Rollback.
>
> # the hash-reference differs between calls even
> in the same
> # process, so de-reference the hash-reference
> [at] [at] -96,7 +95,7 [at] [at]
> # TODO - Fix mod_perl 2.0 here
> if(!$Rollback{$Idx} and $needCleanup and
> Apache->can('push_handlers')) {
> print STDERR "$prefix push
> PerlCleanupHandler \n" if $Apache::DBI::DEBUG > 1;
> - Apache->push_handlers("PerlCleanupHandler",
> \&cleanup);
> + Apache->push_handlers("PerlCleanupHandler",
> sub { cleanup($Idx) });
> # make sure, that the rollback is called
> only once for every
> # request, even if the script calls connect
> more than once
> $Rollback{$Idx} = 1;
> [at] [at] -155,6 +154,7 [at] [at]
> # Note: the PerlCleanupHandler runs after the
> response has been sent to the client
>
> sub cleanup {
> + my $Idx = shift;
> my $prefix = "$$ Apache::DBI ";
> print STDERR "$prefix PerlCleanupHandler \n" if
> $Apache::DBI::DEBUG > 1;
> my $dbh = $Connected{$Idx};
>
> > --
> Report problems: http://perl.apache.org/bugs/
> Mail list info:
> http://perl.apache.org/maillist/modperl.html
> List etiquette:
http://perl.apache.org/maillist/email-etiquette.html





___________________________________________________________A LL-NEW Yahoo! Messenger - all new features - even more fun! http://uk.messenger.yahoo.com

--
Report problems: http://perl.apache.org/bugs/
Mail list info: http://perl.apache.org/maillist/modperl.html
List etiquette: http://perl.apache.org/maillist/email-etiquette.html

Thanks! It seems to be working correctly after implementing your changes.

Brian


Perrin Harkins wrote:

> I plan to submit a patch for Ima::DBI to fix this, but in the meantime I
> am handling it by overriding db_Main and doing the connections myself.
> Here's the code I use:
>
> my $db_options = {
> RaiseError => 1,
> AutoCommit => 0,
> FetchHashKeyName => 'NAME_lc',
> ShowErrorStatement => 1,
> ChopBlanks => 1,
> RootClass => 'DBIx::ContextualFetch'
> };
>
> # override default to avoid using Ima::DBI closure
> sub db_Main {
> my $dbh;
> if ( $ENV{'MOD_PERL'} and !$Apache::ServerStarting ) {
> $dbh = Apache->request()->pnotes('dbh');
> }
> if ( !$dbh ) {
> # $config is my config object. replace with your own
> settings...
> $dbh = DBI->connect_cached(
> $config->get('DbDSN'), $config->get('DbUser'),
> $config->get('DbPass'), $db_options
> );
> if ( $ENV{'MOD_PERL'} and !$Apache::ServerStarting ) {
> Apache->request()->pnotes( 'dbh', $dbh );
> }
> }
> return $dbh;
> }
>
> sub dbi_commit {
> my $self = shift;
> $self->db_Main()->commit();
> }
>
> sub dbi_rollback {
> my $self = shift;
> $self->db_Main()->rollback();
> }
>
>
> Note that it was necessary to override dbi_commit and dbi_rollback as
> well because now Ima::DBI doesn't know about this handle. I also
> stashed the handle in pnotes() for some extra speed because Class::DBI
> requests it so frequently. Stashing in pnotes() is safe because it gets
> cleared out at the end of each request even if your code dies. Make
> sure you keep the other db options intact or various things in
> Class::DBI will break.
>
> - Perrin
>
>


--
Report problems: http://perl.apache.org/bugs/
Mail list info: http://perl.apache.org/maillist/modperl.html
List etiquette: http://perl.apache.org/maillist/email-etiquette.html