Re: confused about transactions and connection pools

On Monday 30 October 2006 11:35, Dave Cramer wrote:
> 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.

No, no hibernate.  I was using ha-jdbc but I turned it off for this
test am I am using the Postgresql JDBC driver directly.

>
> > 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.

This is on a test machine, and I am submitting the requests to it manually
(they are XML and I have a testrig that submits them), so I know that there
is only one thing going on at the time of the test.

However for completeness it would be good to turn on the pid, I guess I
need the log_line_prefix set up.  I will give it a go.

David

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