You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-user@db.apache.org by Andrew Lawrenson <an...@coppereye.com> on 2008/02/29 11:47:49 UTC
Derby, identity columns & locks on syscolumns
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
RE: Derby, identity columns & locks on syscolumns
Posted by Jim Newsham <jn...@referentia.com>.
> 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."
Ah-ha! This answers something for me. In our application, I just recently
started using dynamically created tables (created on demand as needed).
However, when table creation occurred, I would see a large number of
deadlocks for other, concurrent transactions which were inserting into
*unrelated* tables. This essentially ground everything to a halt, similar
to Andrew's experience.
My reaction was/is, "This is ridiculous", but I didn't have time to pursue
it further at the time. My workaround was to use a global shared/exclusive
(read/write) lock for all database access, locking exclusively when creating
tables. This was acceptable in our case because as it turns out, table
creation happens very seldom. Nevertheless, this appears to be a weak point
for Derby... it shouldn't be necessary to do this type of global/external
locking for table creation.
Comments? Advice? Is there a better way for Derby to manage this, so that
it doesn't produce lock contention across unrelated tables?
Regards,
Jim
Re: Derby, identity columns & locks on syscolumns
Posted by Øystein Grøvlen <Oy...@Sun.COM>.
Andrew Lawrenson wrote:
> I've done some more experimentation & testing.
>
> At the moment, when syscolumns is updated, if a sub-transction is done, the update is done with an expicit no-wait on locks.
> I've tried changing this so that it will use the same wait policy as the parent transaction - when this is done, I see none of the problems reported, and can have up to 100 concurrent threads inserting without any failing (whereas before this would instantly lock up).
>
> So the question now is: "is the no-wait for the sub-transaction actually necessary?".
>
> Personally, I can't see why it is, although I'm not exactly a guru at derby internals. If the reason why is simply to increase concurrency, then I think it's flawed, as it forces more updates to be carried out by the parent transaction, which will hold the lock much longer before committing...
>
> Any ideas? Or is this the wrong list to be asking - should I pose this on derby-developers instead?
>
I think derby-dev is more appropriate for this discussion. I do not
know why there is a no-wait for subtransactions, maybe it is done to
avoid risks of deadlocks. You could try running the Derby test suites
to see if some problems are revealed.
--
Øystein
RE: Derby, identity columns & locks on syscolumns
Posted by Andrew Lawrenson <an...@coppereye.com>.
I've done some more experimentation & testing.
At the moment, when syscolumns is updated, if a sub-transction is done, the update is done with an expicit no-wait on locks.
I've tried changing this so that it will use the same wait policy as the parent transaction - when this is done, I see none of the problems reported, and can have up to 100 concurrent threads inserting without any failing (whereas before this would instantly lock up).
So the question now is: "is the no-wait for the sub-transaction actually necessary?".
Personally, I can't see why it is, although I'm not exactly a guru at derby internals. If the reason why is simply to increase concurrency, then I think it's flawed, as it forces more updates to be carried out by the parent transaction, which will hold the lock much longer before committing...
Any ideas? Or is this the wrong list to be asking - should I pose this on derby-developers instead?
Many thanks,
Andrew Lawrenson
-----Original Message-----
From: Andrew Lawrenson [mailto:andrew.lawrenson@coppereye.com]
Sent: 29 February 2008 14:56
To: Derby Discussion
Subject: RE: Derby, identity columns & locks on syscolumns
I think I've found my own answer:
When the updating of identity column is done, a sub-transaction is started for updating syscolumns. This transaction normally (for me) lasts at most 1ms. However, sometimes under a heavy load, it's taken longer (I've seen about 1/3 of a second). Whilst the first transaction is locking syscolumns, any other insert causing an update of the identity column will fail immediately, as the lock timeout is immediate for the sub-transaction.
When the sub-transactions fail, the updating of syscolumns is done under the parent transaction - which may not be committed for several seconds (for me, under heavy load). And during this time, of course, all other inserts will start failing under the sub-transactions, which then get re-executed on the main transaction, eaching holding a lock on the index for their entire transaction.
What I see is that when one update of syscolumns via the sub-transaction fails, the entire system locks up & most of the transactions inserting records fail (as you suddenly get this cascade of locks being held), although once clients start failing the system gradually recovers.
So... Is this something I just have to live with, or is it an issue? Any potential workarounds that don't involve replacing identity columns with GUIDs or similar?
thanks in advance,
Andrew Lawrenson
-----Original Message-----
From: Andrew Lawrenson [mailto:andrew.lawrenson@coppereye.com]
Sent: 29 February 2008 10:48
To: derby-user@db.apache.org
Subject: Derby, identity columns & locks on syscolumns
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
RE: Derby, identity columns & locks on syscolumns
Posted by Andrew Lawrenson <an...@coppereye.com>.
I think I've found my own answer:
When the updating of identity column is done, a sub-transaction is started for updating syscolumns. This transaction normally (for me) lasts at most 1ms. However, sometimes under a heavy load, it's taken longer (I've seen about 1/3 of a second). Whilst the first transaction is locking syscolumns, any other insert causing an update of the identity column will fail immediately, as the lock timeout is immediate for the sub-transaction.
When the sub-transactions fail, the updating of syscolumns is done under the parent transaction - which may not be committed for several seconds (for me, under heavy load). And during this time, of course, all other inserts will start failing under the sub-transactions, which then get re-executed on the main transaction, eaching holding a lock on the index for their entire transaction.
What I see is that when one update of syscolumns via the sub-transaction fails, the entire system locks up & most of the transactions inserting records fail (as you suddenly get this cascade of locks being held), although once clients start failing the system gradually recovers.
So... Is this something I just have to live with, or is it an issue? Any potential workarounds that don't involve replacing identity columns with GUIDs or similar?
thanks in advance,
Andrew Lawrenson
-----Original Message-----
From: Andrew Lawrenson [mailto:andrew.lawrenson@coppereye.com]
Sent: 29 February 2008 10:48
To: derby-user@db.apache.org
Subject: Derby, identity columns & locks on syscolumns
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