DBD:Pg (Postgres) + Apache::DBI

[Jonathan Vanasco <mo...@2xlp.com>]

I'm finishing up my migration to Postgres, and i noticed some odd  
behavior

I was hoping that someone could point me in the right direction:

a - 	i often lose a connection to the server for an apache child.  i  
can't seem to trace when where or why this happens
	i just get this in the log "DBD::Pg::st execute failed: no  
connection to the server"
	the other children are unaffected.  i'm wondering if this is a ping  
error, postgres shutting things down from too many invalid queries  
(i'm still on my dev box) , or something else

b- 	several times a handle seems to have been corrupted.  usually it  
seems to happen with a failed sequence operation ( adding a new  
record or retreiving a value )
	when this happens, the handle seems to not be reset by the cleanup  
handler ( ie - the automagic Apache::DBI issued rollback ).  i have  
to restart the server to clean the handle
	has this happened to anyone else?

c-	i was getting a bunch of "message type 0x49 arrived from server  
while idle" -> "message type 0x53 arrived from server while idle"
	looking on the net, i wasn't able to find much about it.  a lot of  
people had the issue on the perl DB lists, the Postgres lists, but  
there was no mention of what caused it.
	Then I finally came across somethig from the bricolage changelog:
		http://bricolage.sourceforge.net/docs/Bric/Changes.html
		Removed queries added in 1.7.2 that were running at Bricolage  
startup time. They could cause DBI to cache a database handle and  
return it after Apache forks, leading to strange errors such as  
``message type 0x49 arrived from server while idle'', and  
occaisionally a frozen server. [David]

	It turns out that I had a handle that was cached by accident ( i  
hadn't made a config only user yet, and the config handle was  
connecting with the same params as my writing handle).  Chances are ,  
thats probably the issue.  But does anyone know if there is a  
definitive cause for this?

Thanks.
Jonathan

Re: DBD:Pg (Postgres) + Apache::DBI

[Jonathan Vanasco <jo...@2xlp.com>]

On Mar 20, 2006, at 5:48 PM, Perrin Harkins wrote:
> Here's my guess -- are you calling you DBI->connect() on every  
> request?
yep.

> If this is all making you annoyed with Apache::DBI, just make your own
> cleanup handler that does a rollback.  It's easy to do, as long as you
> have a simple way to get the database handle.

well, i already have a cleanup handler that does some stuff with my  
db handle , so i'll just stuck a rollback in there.  problem solved.

and in solving it, I also found the issue. and ( of course )  it was  
entirely my fault .

	i connect as AutoCommit = 0 so I get the rollback

	then i have a db abstraction level that flips AutoCommit to 1 (shown  
below) and replaces the begin_work / rollback / commit -- because I  
need to explicitly declare those commands
	i *think* a bad  error trap missed the rollback, which would have  
flipped my autocommit.

anyways, thanks a ton.  this was killing me.  i've been porting 160+  
tables of a mysql-centric db layout to postgres, and having to redo a  
significant amount of sql statements to standard sql language.  so my  
db handles were corrupting nonstop.


	eval
	{
		$db->{'dbh'}->do($SQL) or die "Can not insert";
	};
	if ( $@ )
	{	
		$self->set_error( "Error: $@" )
		$db-> _dbwriter_endwork_rollback();
	}



sub _dbwriter_beginwork
{
	eval
	{
		$_[0]->{'DBH'}{AutoCommit} = 1;
		$_[0]->{'DBH'}->begin_work;
	};
	if ( $@ )
	{
		return 0;
	}
	return 1;
}

sub _dbwriter_endwork_rollback
{
	$_[0]->{'DBH'}->rollback;
	$_[0]->{'DBH'}{AutoCommit} = 0;
}

sub _dbwriter_endwork_commit
{
	$_[0]->{'DBH'}->commit;
	$_[0]->{'DBH'}{AutoCommit} = 0;
}

Re: DBD:Pg (Postgres) + Apache::DBI

[Perrin Harkins <pe...@elem.com>]

On Mon, 2006-03-20 at 17:29 -0500, Jonathan Vanasco wrote:
> I'm not even seeing an explicit rollback on the good handle, which  
> makes me think something odd happened on my config 

Here's my guess -- are you calling you DBI->connect() on every request?
If you don't, Apache::DBI won't work.  I've seen people put their $dbh
in a global or closure, not realizing that they have to call
DBI->connect at least once at the beginning of the request to trigger
Apache::DBI.

If this is all making you annoyed with Apache::DBI, just make your own
cleanup handler that does a rollback.  It's easy to do, as long as you
have a simple way to get the database handle.

- Perrin

Re: DBD:Pg (Postgres) + Apache::DBI

[Jonathan Vanasco <jo...@2xlp.com>]

On Mar 20, 2006, at 3:50 PM, Perrin Harkins wrote:
> It only does that if you connect with AutoCommit off.

my connect args are
	{ RaiseError => 0, AutoCommit => 0 , TraceLevel => 1 }

> Can you give an example of an invalid SQL command, and what was "bad"
> about the cached handle on the next page?


Something like:
	SELECT id_field AS validated FROM id_table WHERE id_field = ''; #  
where id_field is a int column

Gives me this
DBD::Pg::db do failed: ERROR:  invalid input syntax for integer: ""
DBD::Pg::st execute failed: ERROR:  current transaction is aborted,  
commands ignored until end of transaction block

which makes sense.  but all pages that child requests in the future  
are met with this:

	DBD::Pg::st execute failed: ERROR:  current transaction is aborted,  
commands ignored until end of transaction block

I'm pretty sure its because I'm catching the error before I issue a  
rollback (my fault).
But I was counting on the DBI rollback

Other invalid sql commands that trigger this are "	SELECT  
column__does_not_exist FROM table__does_not_exist "

> Also, set $Apache::DBI::DEBUG = 2 and it will tell you if it ran a

Thanks.  I just tried that.

On a good handle, I get
24572 Apache::DBI             need ping: yes
     <- ping= 1 at DBI.pm line 135
24572 Apache::DBI             already connected to  
'dbname=DBNAMEdbuserDBPASSAutoCommit=0PrintError=1RaiseError=0TraceLevel 
=1Username=DBUSER'
     <- STORE('RaiseError' 0)= 1 at DBI.pm line 664
     <- STORE('PrintError' 1)= 1 at DBI.pm line 664
     <- STORE('AutoCommit' 0)= 1 at DBI.pm line 664
     <- STORE('TraceLevel' 1)= 1 at DBI.pm line 667
     <> FETCH('TraceLevel')= 1 ('TraceLevel' from cache) at DBI.pm  
line 667
     <- STORE('Username' 'DBUSER')= 1 at DBI.pm line 667
     <> FETCH('Username')= 'DBUSER' ('Username' from cache) at DBI.pm  
line 667

Once a handle is corrupted, I see
24572 Apache::DBI             disconnect (overloaded)

I'm not even seeing an explicit rollback on the good handle, which  
makes me think something odd happened on my config ( i remember with  
mysql, it would send an "AutoCommit = 1 ; AutoCommit = 0;" to handle  
the rollback

Re: DBD:Pg (Postgres) + Apache::DBI

[Perrin Harkins <pe...@elem.com>]

On Mon, 2006-03-20 at 15:22 -0500, Jonathan Vanasco wrote:
> I did a bunch of tracing this morning it seems that apache::dbi isn't  
> always issuing the rollback at cleanup

It only does that if you connect with AutoCommit off.

> if there's an invalid sql command executed in my transaction though,
> ==============CLEANUP
> 
> is all i get.  no cleanup is issued (rollback/closure/etc) on the  
> dbi, and i'm still using a bad cached handle on subsequent page  
> views , necessitating a page start.

Can you give an example of an invalid SQL command, and what was "bad"
about the cached handle on the next page?

Also, set $Apache::DBI::DEBUG = 2 and it will tell you if it ran a
cleanup or not.

- Perrin

Re: DBD:Pg (Postgres) + Apache::DBI

[Jonathan Vanasco <jo...@2xlp.com>]

a) i fixed the 'message xxxx' errors - they were indeed from an  
accidentally preforked handle.  i'll try to make a note or something  
for apache docs this evening.

b)

I did a bunch of tracing this morning it seems that apache::dbi isn't  
always issuing the rollback at cleanup

I set a trace level on my dbi arg, and have a handler print a marker  
for the cleanup phase

  the bulk of time I get something like this:

==============CLEANUP    DBI::db=HASH(0x1a2c918) trace level set to  
0x0/1 (DBI @ 0x0/0) in DBI 1.50-ithread (pid 24285)
     <> FETCH('TraceLevel')= 1 ('TraceLevel' from cache) at DBI.pm  
line 667
     <- STORE('Username' 'XXXXX')= 1 at DBI.pm line 667
     <> FETCH('Username')= 'XXXXX' ('Username' from cache) at DBI.pm  
line 667
     <- STORE('dbi_connect_closure' CODE(0x1a2be3c))= 1 at DBI.pm  
line 683


if there's an invalid sql command executed in my transaction though,
==============CLEANUP

is all i get.  no cleanup is issued (rollback/closure/etc) on the  
dbi, and i'm still using a bad cached handle on subsequent page  
views , necessitating a page start.

the above arguments were with a TraceLevel1 - i also did a TraceLevel  
15, and saw no additional commands executed.

anyone have a suggestion on where I can look next?

Re: DBD:Pg (Postgres) + Apache::DBI

[Greg Sabino Mullane <gr...@turnstep.com>]

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


> c-      i was getting a bunch of "message type 0x49 arrived from server
> while idle" -> "message type 0x53 arrived from server while idle"

This is due to some errant forking. PostgreSQL (and most other databases
for that matter) does not support forking and then trying to talk to
two clients at once. One of those clients sends something, and the other
one notices the response and basically says "Hey! You talkin' to me?!?"

You are most likely connecting too early. This also explains the other errors
you are seeing. Make sure you use the latest version of DBD::Pg as well,
as some other obscure forking-related problems were recently fixed.

- --
Greg Sabino Mullane greg@turnstep.com
PGP Key: 0x14964AC8 200603191601
http://biglumber.com/x/web?pk=2529DF6AB8F79407E94445B4BC9B906714964AC8
-----BEGIN PGP SIGNATURE-----

iD8DBQFEHcdOvJuQZxSWSsgRAobzAJ9eThLlKi3esmLZcS52TZF5lsycjACdFZNY
Hngofu5QKVcU7k4XspLPsQY=
=raOP
-----END PGP SIGNATURE-----