confused about transactions and connection pools

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

David