Re: confused about transactions and connection pools

[Dave Cramer <pg(at)fastcrypt(dot)com>]

On 30-Oct-06, at 6:17 AM, David Goodenough wrote:

> I am running a servlet on Tomcat 5.5 which talks to a PostgreSQL DB  
> (8.1)
> using the Jdbc3 driver.
>
> The database is accessed using a DataSource, and so at the start of  
> each
> servlet doPost call I get a new connection, do a setAutoCommit 
> ( false) and
> then get on with the processing.  At the end if it works I do a commit
> otherwise I do a rollback.  Then I setAutoCommit( true) and write to a
> log table (a single insert which I always want to do) and close the
> connection.  The servlet is entirely stateless, it keeps nothing from
> one invocation to the next other than the DataSource which it opens
> during its init( ) method along with a few configuration parameters.
>
> I turned on postgresql logging and for the first request (the two  
> requests and
> their responses were identical - both failed) the postgresql log  
> said:-
>
> LOG:  statement: BEGIN
> LOG:  statement: SELECT password, role, proxy, pool, company FROM  
> users WHERE
> id = $1
> LOG:  statement: INSERT INTO users( created, phone, password, role,  
> origin,
> xml, updated, id) VALUES( $1, $2, $3, $4, $5, $6, $7, $8)
> LOG:  statement: INSERT INTO users( created, phone, password, role,  
> origin,
> xml, updated, id) VALUES( $1, $2, $3, $4, $5, $6, $7, $8)
> ERROR:  duplicate key violates unique constraint "users_pkey"
> LOG:  statement: ROLLBACK
> LOG:  statement: INSERT INTO logs( userid, ip, request, response,  
> at, success)
> VALUES( $1, $2, $3, $4, $5, $6)
> LOG:  statement: SELECT 1 FROM ONLY "public"."users" x WHERE "id" =  
> $1 FOR
> UPDATE OF x
> CONTEXT:  SQL statement "SELECT 1 FROM ONLY "public"."users" x  
> WHERE "id" = $1
> FOR UPDATE OF x"
>
> and for the second one it said:
>
> LOG:  statement: SELECT password, role, proxy, pool, company FROM  
> users WHERE
> id = $1
> LOG:  statement: INSERT INTO users( created, phone, password, role,  
> origin,
> xml, updated, id) VALUES( $1, $2, $3, $4, $5, $6, $7, $8)
> LOG:  statement: INSERT INTO users( created, phone, password, role,  
> origin,
> xml, updated, id) VALUES( $1, $2, $3, $4, $5, $6, $7, $8)
> ERROR:  duplicate key violates unique constraint "users_pkey"
> LOG:  statement: INSERT INTO logs( userid, ip, request, response,  
> at, success)
> VALUES( $1, $2, $3, $4, $5, $6)
>
> which is slightly different.
>
> Now the first thing I notice about this is that the first one has  
> the BEGIN
> I would expect, followed by a select (which I recognise) followed  
> by the
> insert that fails (quite why it logs it twice I do not know, it is  
> certainly
> not issued twice) followed by the rollback (because it failed) and  
> the insert
> into the logs table.
>
> Then comes an odd SELECT statement (the one SELECT 1) which I do  
> not recognise
> and I can not find anywhere in my code.

Are you using hibernate ? Either way the select 1 is locking the  
users table.
> It is referencing one of my tables
> (users) and it says both LOG: and CONTEXT: which I do not  
> understand.  Given
> that the autoCommit was turned off after the rollback this should  
> have had
> no effect.
>
> The we get to the second time through the servlet.  First thing -  
> no BEGIN
> or ROLLBACK, but the code went through a call to  
> connection.setAutoCommit(
> false).  Secondly this odd statement that I do not recognise id no  
> longer
> there.
>
> My reason for investigating this is that I had an odd problem with the
> log table being left with a lock on it, when none should exist as the
> insert is done outside a transaction.
>
> I have tried the same thing with a transaction that works (you just  
> do not
> get the ERROR: and in the first case you get a COMMIT not a  
> ROLLBACK.  Also
> in that case the INSERT is not repeated in the log so I guess that  
> is an
> artifact of the failure.
>
> Obviously I am doing something wrong, but for the life of me I can  
> not see
> what.  Anyone got any ideas?
First of all I'd suggest you add pid to the logs so you can see which  
connection is doing what. The server logs sequentially in the order  
it sees things. You could have 2 connections logs interleaved there.

Dave
> David
>
> ---------------------------(end of  
> broadcast)---------------------------
> TIP 2: Don't 'kill -9' the postmaster