Assertion failure in cvs head.

I'm implementing savepoint support for the JDBC driver and I'm seeing an
assertion failure in cvs head this morning. It seems related to using
both savepoints and the v3 protocol.

LOG: statement: create table savepointtable (id int primary key)
NOTICE: CREATE TABLE / PRIMARY KEY will create implicit index
"savepointtable_pkey" for table "savepointtable"
LOG: statement: BEGIN
LOG: statement: INSERT INTO savepointtable VALUES ($1)
LOG: statement: SAVEPOINT JDBC_SAVEPOINT_0
LOG: statement: INSERT INTO savepointtable VALUES ($1)
ERROR: duplicate key violates unique constraint "savepointtable_pkey"
LOG: statement: ROLLBACK TO SAVEPOINT JDBC_SAVEPOINT_0
TRAP: FailedAssertion("!(portal->resowner == ((void *)0))", File:
"portalmem.c", Line: 694)

Note the line number in the error message appears accurate, but doesn't
exactly match that in the stacktrace. This is the same as the last time I
reported a problem of this type. I got them to match by building with a
different compiler version (which I can do again if necessary).

#0 0x402a6721 in kill () from /lib/libc.so.6
#1 0x402a64c5 in raise () from /lib/libc.so.6
#2 0x402a79e8 in abort () from /lib/libc.so.6
#3 0x08236092 in ExceptionalCondition (
conditionName=0x6 <Address 0x6 out of bounds>,
errorType=0x8259591 "FailedAssertion", fileName=0x403ac550 "`\022",
lineNumber=0) at assert.c:51
#4 0x0824c377 in AtSubCleanup_Portals () at portalmem.c:697
#5 0x080ab2c8 in CleanupSubTransaction () at xact.c:3180
#6 0x080a9955 in CleanupAbortedSubTransactions (returnName=1 '\001')
at xact.c:1815
#7 0x080a9807 in CommitTransactionCommand () at xact.c:1770
#8 0x081c2def in finish_xact_command () at postgres.c:1833
#9 0x081c291f in exec_execute_message (portal_name=0x837fd01 "",
max_rows=1)
at postgres.c:1680
#10 0x081c4342 in PostgresMain (argc=4, argv=0x833b348,
username=0x833b254 "test") at postgres.c:3016
#11 0x0819449d in BackendRun (port=0x834a210) at postmaster.c:2848
#12 0x08193e43 in BackendStartup (port=0x834a210) at postmaster.c:2470
#13 0x0819209a in ServerLoop () at postmaster.c:1215
#14 0x081911ae in PostmasterMain (argc=3, argv=0x833add8) at
postmaster.c:898
#15 0x0815b655 in main (argc=3, argv=0x833add8) at main.c:265

Kris Jurka

Kris Jurka <books(at)ejurka(dot)com> writes:
> I'm implementing savepoint support for the JDBC driver and I'm seeing an
> assertion failure in cvs head this morning. It seems related to using
> both savepoints and the v3 protocol.

Hmm, how are you issuing these commands exactly (what protocol message
sequence is being sent?).

I can't reproduce it using psql, but I suppose you knew that.

regards, tom lane

On Thu, 16 Sep 2004, Tom Lane wrote:

> Hmm, how are you issuing these commands exactly (what protocol message
> sequence is being sent?).
>

I've made the test case and the development version of the jar file
available here if you're interested: http://www.ejurka.com/pgsql/jars/tgl/

Here is the relevent section of the log file:

<=BE ReadyForQuery(T)
simple execute,
handler=org(dot)postgresql(dot)jdbc2(dot)AbstractJdbc2Statement$StatementResultHandler(at)133796,
maxRows=0, fetchSize=0, flags=5
FE=> Parse(stmt=null,query="INSERT INTO savepointtable VALUES
($1)",oids={23})
FE=> Bind(stmt=null,portal=null,$1=<1>)
FE=> Describe(portal=null)
FE=> Execute(portal=null,limit=1)
FE=> Sync
<=BE ParseComplete [null]
<=BE BindComplete [null]
<=BE NoData
<=BE CommandStatus(INSERT 66384 1)
<=BE ReadyForQuery(T)
simple execute,
handler=org(dot)postgresql(dot)jdbc2(dot)AbstractJdbc2Statement$StatementResultHandler(at)4741d6,
maxRows=0, fetchSize=0, flags=5
FE=> Parse(stmt=null,query="SAVEPOINT JDBC_SAVEPOINT_0",oids={})
FE=> Bind(stmt=null,portal=null)
FE=> Describe(portal=null)
FE=> Execute(portal=null,limit=1)
FE=> Sync
<=BE ParseComplete [null]
<=BE BindComplete [null]
<=BE NoData
<=BE CommandStatus(SAVEPOINT)
<=BE ReadyForQuery(T)
simple execute,
handler=org(dot)postgresql(dot)jdbc2(dot)AbstractJdbc2Statement$StatementResultHandler(at)337d0f,
maxRows=0, fetchSize=0, flags=5
FE=> Parse(stmt=null,query="INSERT INTO savepointtable VALUES
($1)",oids={23})
FE=> Bind(stmt=null,portal=null,$1=<1>)
FE=> Describe(portal=null)
FE=> Execute(portal=null,limit=1)
FE=> Sync
<=BE ParseComplete [null]
<=BE BindComplete [null]
<=BE NoData
<=BE ErrorMessage(ERROR: duplicate key violates unique constraint
"savepointtable_pkey"
Location: File: nbtinsert.c, Routine: _bt_check_unique, Line: 255
ServerSQLState: 23505)
java.sql.SQLException: ERROR: duplicate key violates unique constraint
"savepointtable_pkey"
Location: File: nbtinsert.c, Routine: _bt_check_unique, Line: 255
ServerSQLState: 23505
at
org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1141)
at
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:944)
at
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:139)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:346)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:294)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:249)
at SavepointTest.addRow(SavepointTest.java:8)
at SavepointTest.main(SavepointTest.java:25)
SQLException: SQLState(23505)
<=BE ReadyForQuery(E)
simple execute,
handler=org(dot)postgresql(dot)jdbc2(dot)AbstractJdbc2Statement$StatementResultHandler(at)1e4cbc4,
maxRows=0, fetchSize=0, flags=23
FE=> Parse(stmt=null,query="ROLLBACK TO SAVEPOINT
JDBC_SAVEPOINT_0",oids={})
FE=> Bind(stmt=null,portal=null)
FE=> Execute(portal=null,limit=1)
FE=> Sync
FE=> Terminate
org.postgresql.util.PSQLException: An I/O error occured while sending to
the backend

Kris Jurka

Kris Jurka <books(at)ejurka(dot)com> writes:
> I'm implementing savepoint support for the JDBC driver and I'm seeing an
> assertion failure in cvs head this morning. It seems related to using
> both savepoints and the v3 protocol.

After some study I've decided that that Assert is simply erroneous;
removing it is the easiest fix.

The reason the problem doesn't show up in psql is that the simple-Query
path in postgres.c always drops the Portal before doing finish_xact_command.
Extended query mode doesn't do that, and so we had a situation where an
already-aborted transaction owned a Portal that wasn't aborted (since it
hadn't existed when AtSubAbort_Portals() ran). PortalDrop is perfectly
capable of handling this, at least for a portal containing a ROLLBACK
command (which isn't going to own any resources of significance); so the
right answer is just to soldier on.

It occurs to me that the protocol documentation is a bit out of date in
this connection, since it says "a named portal object lasts till the end
of the current transaction", whereas it needs to say something more like
"till the end of the current transaction or subtransaction". Since we
are trying to pretend that there are no subtransactions, only
SAVEPOINTs, I'm not sure how to word it. Comments?

regards, tom lane