Hi all,
as I understand it, when you insert a row into a table with an identity
column, it has to lock syscolumns to update the identity value - from the docs:
"Derby keeps track of the last increment value for a column in a cache. It also
stores the value of what the next increment value will be for the column on
disk in the AUTOINCREMENTVALUE column of the SYS.SYSCOLUMNS system table.
Rolling back a transaction does not undo this value, and thus rolled-back
transactions can leave "gaps" in the values automatically inserted into an
identity column. Derby behaves this way to avoid locking a row in
SYS.SYSCOLUMNS for the duration of a transaction and keeping concurrency high."
However, what I'm seeing looks like a row is being locked in sys.syscolumns for
the duration of the transaction.
When performing lots of inserts in parallel, I'm getting lock timeouts on
syscolumns for the inserts, e.g.:
transaction A performs an insert in table T1.
transaction B performs an insert in table T1.
1 minute later, transaction B fails, due to an exclusive lock held on
syscolumns by transaction A.
(Transaction A is itself blocked by an insert on another table - the same
issue, which is why it hasn't committed)
Now, to me, this looks like the locks on syscolumns _are_ being held for the
duration of the transaction - is this correct, or is something else likely to
be to blame?
This is using Derby 10.3.2.1 on Solaris 10 (x86).
Exerpts from the derby log file are as follows:
2008-02-29 09:36:53.652 GMT Thread[btpool0-77,5,main] (XID = 5599782),
(SESSIONID = 176), (DATABASE = DRSPRI), (DRDAID = null), Executing prepared
statement: insert into authorisation( authorisationtype, authorisedname,
userid, teamid, urnRef, reqRef, spocRef, reasonid, loggeddate, notes,
requestmethod, status, lastuser, authorityid, authoritygroupid ) values
(?,?,?,?,?,?,?,?,CURRENT_TIMESTAMP,?,?,?,?,?,? ) :End prepared statement with
14 parameters begin parameter #1: 1 :end parameter begin parameter #2: :end
parameter begin parameter #3: 611 :end parameter begin parameter #4: 101 :end
parameter begin parameter #5: U15-1204277813126 :end parameter begin parameter
#6: :end parameter begin parameter #7: :end parameter begin parameter #8:
null :end parameter begin parameter #9: :end parameter begin parameter #10:
:end parameter begin parameter #11: OPEN :end parameter begin parameter #12:
611 :end parameter begin parameter #13: 10000 :end parameter begin parameter
#14: 1 :end parameter
2008-02-29 09:36:53.658 GMT Thread[btpool0-77,5,main] (XID = 5599782),
(SESSIONID = 176), (DATABASE = DRSPRI), (DRDAID = null), Executing prepared
statement: VALUES IDENTITY_VAL_LOCAL() :End prepared statement
2008-02-29 09:36:53.704 GMT Thread[btpool0-108,5,main] (XID = 5599789),
(SESSIONID = 173), (DATABASE = DRSPRI), (DRDAID = null), Executing prepared
statement: insert into authorisation( authorisationtype, authorisedname,
userid, teamid, urnRef, reqRef, spocRef, reasonid, loggeddate, notes,
requestmethod, status, lastuser, authorityid, authoritygroupid ) values
(?,?,?,?,?,?,?,?,CURRENT_TIMESTAMP,?,?,?,?,?,? ) :End prepared statement with
14 parameters begin parameter #1: 1 :end parameter begin parameter #2: :end
parameter begin parameter #3: 611 :end parameter begin parameter #4: 101 :end
parameter begin parameter #5: U1-1204278042611 :end parameter begin parameter
#6: :end parameter begin parameter #7: :end parameter begin parameter #8:
null :end parameter begin parameter #9: :end parameter begin parameter #10:
:end parameter begin parameter #11: OPEN :end parameter begin parameter #12:
611 :end parameter begin parameter #13: 10000 :end parameter begin parameter
#14: 1 :end parameter
2008-02-29 09:37:53.819 GMT Thread[btpool0-108,5,main] (XID = 5599789),
(SESSIONID = 173), (DATABASE = DRSPRI), (DRDAID = null), Failed Statement is:
insert into authorisation( authorisationtype, authorisedname, userid, teamid,
urnRef, reqRef, spocRef, reasonid, loggeddate, notes, requestmethod, status,
lastuser, authorityid, authoritygroupid ) values
(?,?,?,?,?,?,?,?,CURRENT_TIMESTAMP,?,?,?,?,?,? ) with 14 parameters begin
parameter #1: 1 :end parameter begin parameter #2: :end parameter begin
parameter #3: 611 :end parameter begin parameter #4: 101 :end parameter begin
parameter #5: U1-1204278042611 :end parameter begin parameter #6: :end
parameter begin parameter #7: :end parameter begin parameter #8: null :end
parameter begin parameter #9: :end parameter begin parameter #10: :end
parameter begin parameter #11: OPEN :end parameter begin parameter #12: 611
:end parameter begin parameter #13: 10000 :end parameter begin parameter #14: 1
:end parameter
ERROR 40XL2: A lock could not be obtained within the time requested. The
lockTable dump is:
2008-02-29 09:37:53.737 GMT
XID |TYPE |MODE|LOCKCOUNT|LOCKNAME
|STATE|TABLETYPE / LOCKOBJ
|INDEXNAME / CONTAINER_ID / (MODE for LATCH only) |TABLENAME / CONGLOM_ID
|
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
*** The following row is the victim ***
5599789 |ROW |X |0 |(17,16)
|WAIT |S
|NULL |SYSCOLUMNS
|
*** The above row is the victim ***
5599782 |ROW |X |2 |(17,16)
|GRANT|S
|NULL |SYSCOLUMNS
|
Many thanks,
Andrew Lawrenson
