You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "Svata Dedic (JIRA)" <ji...@apache.org> on 2008/05/27 22:56:59 UTC
[jira] Created: (DERBY-3693) Deadlocks accessing DB metadata
Deadlocks accessing DB metadata
-------------------------------
Key: DERBY-3693
URL: https://issues.apache.org/jira/browse/DERBY-3693
Project: Derby
Issue Type: Bug
Components: JDBC
Affects Versions: 10.4.1.3, 10.3.3.0, 10.3.2.1
Environment: Linux amd64 or Windows 32bit
Reporter: Svata Dedic
My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
I am sometimes getting a deadlock with these operations:
2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
The lockTable dump is:
2008-04-16 19:50:47.796 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 ***
569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
*** The above row is the victim ***
The stacktrace of the operation causing the deadlock is
at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
---------%<-----------------------%<--------------
Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "David Capelle (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12614520#action_12614520 ]
David Capelle commented on DERBY-3693:
--------------------------------------
Hi Knut, Svata,
We have a similar problem with metadata.
Since we have added a new table in our schema, we always have a deadlock .
We have noticed that if we delete a table (regardless of wich table), than deadlock does't happend anymore.
Our scenario:
1. Create all the tables (including index)
2. For each table, check if there are new ForeignKey to create
3. Create all new foreignKeys.
Dealock happens in the second step. Only one thread is connected to Derby (and so one connection).
I will send you our derby.log file.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12615201#action_12615201 ]
Knut Anders Hatlen commented on DERBY-3693:
-------------------------------------------
Increasing derby.language.stalePlanCheckInterval could affect all statements, but I don't think it's likely that you'll notice any difference. What could be getting worse, is that it takes longer from the size of a table changes so that the chosen plan is not the most efficient one anymore, until Derby notices it and creates a new plan. On the other hand, increasing it could also improve the performance, since it'll lead to less checking of the plan at run time and less recompiling. I'd guess that in most cases the recompiling won't actually choose another plan, so doing it less frequently shouldn't hurt.
The timeout will only happen with meta-data queries and statements in triggers, though, since the execution plans for those queries are stored in the database. The execution plans for other SQL statements are stored in memory only, so there's no need to modify system tables when they are recompiled.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: deadlock.diff
It's just a guess, but perhaps the attached patch deadlock.diff solves the problem. Stored prepared statements (which are used for the meta-data queries) are compiled in a nested transaction so that locks on system tables can be released before the main transaction is completed. If the main transaction already has a lock on something the nested transaction also needs to lock, the nested transaction may get a lock timeout, in which case we retry the operation in the parent transaction. We don't retry if the nested transaction runs into a deadlock, which is what happens in Svata's case. I don't think it's possible that the nested transaction runs into a deadlock with the main transaction, since the main transaction isn't waiting for any locks while the nested transaction is executing, but it may perhaps happen if there are more threads involved?
Anyway, I just wanted to throw out the idea. The patch has not been tested.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: deadlock.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "David Capelle (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12615074#action_12615074 ]
David Capelle commented on DERBY-3693:
--------------------------------------
Thanks a lot for your investigations,
After lower derby.locks.waitTimeout to16 sec and derby.locks.deadlockTimeout to 15, we still have deadlock (in derby.log file) but we don't wait more than 15 seconds, so it's acceptable.
I also have tested the second workaround (derby.language.stalePlanCheckInterval). I have set it to 200. ThIs time, deadlock doesn't occur.
If I understand well, changing this last property only affect performance on metadata getTable method?
BR
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: dontWait.stat
dontWait.diff
Here's a patch (dontWait.diff) which attacks the problem from a different angle. Instead of preventing the invalidation from obtaining a lock on the system tables in the user transaction, this patch makes the nested transaction used for recompiling the meta-data query fail immediately in case of a lock conflict. The original code also attempts this, but only for table-level locks. This patch makes all lock requests in the nested transaction time out immediately if there's a lock conflict, so that there's no hang before we retry in the user transaction.
The approach taken is this:
The CompatibilitySpace class used in the lock manager has an owner field, which normally is the transaction object. This field is however of type java.lang.Object and can theoretically be anything. In the patch, I changed this field to be of the type LockOwner, which is a new interface under iapi.services.locks. The interface has a method noWait() that returns a boolean value. The lock manager will check the return value of this method if lockObject() or zeroDurationlockObject() can't lock the object immediately, and if it is true, a timeout exception is thrown instead of waiting.
In SPSDescriptor, I set a flag in the nested transaction so that it returns true from its noWait() method. This means we'll not see the lock conflicts between the nested transaction and its parent as hangs anymore.
I have successfully run the repro, the regression test that was added to DatabaseMetaDataTest, and a set of tests that had problems with the previous patches. Didn't see any problems in those tests. Will start the full regression test suite and report back.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Attachments: d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Bryan Pendleton (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12625185#action_12625185 ]
Bryan Pendleton commented on DERBY-3693:
----------------------------------------
Hi Knut, thanks for working on this problem. I think your approach is excellent -- good catch
on figuring out that the previous implementation was only working for table-level locks.
I read through dontWait.diff and it seems quite clear; the new LockOwner interface
seems like a straightforward way to increase the communication between the locking
services and the higher-level client code without introducing a lot of coupling, very nice.
I did feel, however, that the patch could use significantly more comments. Looking just
at the patch, without referring to the detailed comments in this JIRA report, I found it
hard to see when it would be appropriate to call setNoLockWait(true).
In other words, I think it would be nice if the patch could include sufficient comments
that future code which creates a nested transaction could determine when to use
this new API or not. Should *all* nested transactions use no-wait locking? If not, which
ones should, and why?
I think that the crucial bit of missing information involves the fact(s) that:
a) the nested transaction might be blocking on locks held by the parent transaction
b) some callers are smart enough to know that if a lock-related problem occurs with
the nested transaction, they can re-try the work using the parent transaction
If possible, I think that some useful places for such information would be:
- LockOwner.noWait: more information about why a lock owner might return true from noWait
(e.g., because its a nested transaction which might be blocking on its own parent)
- Xact.setNoLockWait: more information about why a client might want to configure
a transaction to use no-wait behavior, when that is appropriate, when it won't work,
and what the caller should be prepared to do when the lock requests fail rather than waiting
(e.g., catch the failure and retry the operation on the parent xact)
- SPSDescriptor.java: more information about why nested transactions which access
stored prepared statements are able to use lock-failure behavior (that is, because
the code is smart enough to catch the failure in the nested transaction and retry
the acces using the parent transaction)
Again, thanks *so* much for this fix, I think this is a big improvement.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.5.0.0
>
> Attachments: d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: nested_transaction_v2.diff
Here's a new version of the patch. Changes from the previous patch:
1) only invalidate in a nested transaction for INTERNAL_RECOMPILE_REQUEST
2) added regression test
Although (1) fixed most of the internal timeouts that were seen with the previous patch, I still see one timeout in GrantRevokeDDLTest (no error, since the retry in the parent transaction succeeds), so I don't think the patch should be committed yet. The timeout apparently happens because GrantRevokeConstantAction invalidates statements with INTERNAL_RECOMPILE_REQUEST while it's probably holding a lock in SYSSTATEMENTS.
The best way to fix this problem would be if we could make the logic to prevent waiting for locks in SPSDescriptor.updateSYSSTATEMENTS() work for row locks. Currently, it only prevents waiting for table locks. See also some discussion in DERBY-177.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12623683#action_12623683 ]
Knut Anders Hatlen commented on DERBY-3693:
-------------------------------------------
I ran suites.All and derbyall successfully with
nested_transaction.diff, but it took very long time for the tests to
complete. I think that the problem is that the patch attempts to
update SYSSTATEMENTS in a nested transaction every time an SPS is
invalidated, regardless of why the invalidation request was sent. In
some of those cases (like when makeInvalid() is called with action =
DependencyManager.CREATE_TRIGGER) the user transaction already holds
locks on rows in SYSSTATEMENTS and the nested transaction almost
definitely runs into a lock conflict with its parent.
To fix the reported issue without introducing hangs in other cases, we
can probably limit the use of nested transactions to the case where
makeInvalid() is called for recompile requests
(INTERNAL_RECOMPILE_REQUEST and possibly USER_RECOMPILE_REQUEST)
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java, nested_transaction.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Bryan Pendleton (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12625416#action_12625416 ]
Bryan Pendleton commented on DERBY-3693:
----------------------------------------
comments.diff looks excellent! Thanks for taking the time to clarify the doc. I can't think of anything else to add.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.4.2.0, 10.5.0.0
>
> Attachments: comments.diff, d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: comments.diff
Thanks for looking at the patch, Bryan, and for providing constructive feedback, as always!
I have tried to improve the comments (see the attached patch, committed with revision 688756) the following way:
- LockOwner.noWait(): Give more details and an example of when to return true.
- Transaction/TransactionController.setNoLockWait(): Added a (short) description of when/how to use it and linked it to LockOwner.noWait() with a @see javadoc tag.
- Xact/RAMTransaction.setNoLockWait(): Expanded the comments and cross references by inheriting javadoc comments from the interfaces.
- SPSDescription.getPreparedStatement(): Expanded comment right before the call to nestedTC.setNoLockWait(true). The method already has good comments from before the fix explaining the timeout/retry logic, so I tried to keep it short in order to avoid duplicating too much information.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.5.0.0
>
> Attachments: comments.diff, d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12607359#action_12607359 ]
Knut Anders Hatlen commented on DERBY-3693:
-------------------------------------------
Svata, if you can reproduce this problem reliably, it would be great if you could run with derby.language.logStatementText=true and derby.locks.deadlockTrace=true and post the full contents of derby.log. Then we might see which transaction is leaving a lock and causing the timeout.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12614889#action_12614889 ]
Knut Anders Hatlen commented on DERBY-3693:
-------------------------------------------
It seems like the plan for the meta-data query is invalidated in the user transaction. When the plan is invalidated, SYS.SYSSTATEMENTS is updated to reflect that the plan is invalid, hence the user transaction has an exclusive lock on a row in SYS.SYSSTATEMENTS. However, the meta-data query is recompiled in a sub-transaction, and therefore it runs into a lock conflict with the user transaction. Perhaps we could get around this problem by also performing the invalidation in a sub-transaction so that the exclusive lock is released once the plan has been marked as invalid. Statements within triggers probably also suffer from the same problem.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Assigned: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen reassigned DERBY-3693:
-----------------------------------------
Assignee: Knut Anders Hatlen
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java, nested_transaction.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Derby Info: (was: [Patch Available])
The regression tests passed on Java 1.4.2 as well, so I checked in the patch with revision 688274.
I think this fix should be back-ported since the problem was reported against 10.3, and DERBY-177, which is probably the same issue, was reported against 10.0. Will do that in a couple of days if the nightly regression tests don't show any problems and no one objects to the patch.
Some cleanups that should be performed before closing this issue:
- remove workaround for DERBY-177 in tests
- remove logic to prevent waiting for table locks in SPSDescriptor.updateSYSSTATEMENTS() since the new mechanism will prevent waiting for all types of locks
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.5.0.0
>
> Attachments: d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: d3693.java
Attached is a small test case that reproduces the problem. It creates a deadlock between two transactions by first obtaining shared locks on the rows in SYSSTATEMENTS for getTables and getColumns in both transactions. Then one transaction tries to obtain an exclusive lock on the getTables row (because it needs to compile getTables), and the other transaction on getColumns. This results in the following error and stack trace:
ERROR 40001: A lock could not be obtained due to a deadlock, cycle of locks and waiters is:
Lock : ROW, SYSSTATEMENTS, (15,7)
Waiting XID : {149, X} , APP, EXECUTE STATEMENT SYS."getTables"
Granted XID : {149, S} , {148, S}
Lock : ROW, SYSSTATEMENTS, (19,6)
Waiting XID : {148, X} , APP, EXECUTE STATEMENT SYS."getColumns"
Granted XID : {148, S} , {149, S}
. The selected victim is XID : 149.
at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:303)
at org.apache.derby.impl.services.locks.Deadlock.buildException(Deadlock.java:361)
at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(ConcurrentLockSet.java:613)
at org.apache.derby.impl.services.locks.AbstractPool.lockObject(AbstractPool.java:117)
at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(ConcurrentPool.java:28)
at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(RowLocking3.java:248)
at org.apache.derby.impl.store.access.heap.HeapController.lockRow(HeapController.java:504)
at org.apache.derby.impl.store.access.heap.HeapController.lockRow(HeapController.java:638)
at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(B2IRowLocking3.java:335)
at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(B2IRowLocking3.java:628)
at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(B2IRowLockingRR.java:112)
at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(BTreeForwardScan.java:304)
at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(BTreeScan.java:1809)
at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(TabInfoImpl.java:1085)
at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(TabInfoImpl.java:975)
at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(DataDictionaryImpl.java:4042)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(SPSDescriptor.java:1104)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(SPSDescriptor.java:728)
at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(SPSDescriptor.java:642)
at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(ExecSPSNode.java:177)
at org.apache.derby.impl.sql.GenericStatement.prepMinion(GenericStatement.java:447)
at org.apache.derby.impl.sql.GenericStatement.prepare(GenericStatement.java:88)
at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.prepareInternalStatement(GenericLanguageConnectionContext.java:794)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(EmbedPreparedStatement.java:128)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(EmbedPreparedStatement20.java:82)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(EmbedPreparedStatement30.java:63)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement40.<init>(EmbedPreparedStatement40.java:40)
at org.apache.derby.jdbc.Driver40.newEmbedPreparedStatement(Driver40.java:105)
at org.apache.derby.impl.jdbc.EmbedConnection.prepareMetaDataStatement(EmbedConnection.java:2624)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.prepareSPS(EmbedDatabaseMetaData.java:3657)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQueryUsingSystemTables(EmbedDatabaseMetaData.java:3493)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(EmbedDatabaseMetaData.java:3542)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(EmbedDatabaseMetaData.java:3567)
at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getTables(EmbedDatabaseMetaData.java:1708)
at d3693.T1(d3693.java:57)
at d3693.main(d3693.java:32)
I'm not sure how this could happen in a normal application, though.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "David Capelle (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
David Capelle updated DERBY-3693:
---------------------------------
Attachment: derby.log
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff, derby.log
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Fix Version/s: 10.5.0.0
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.5.0.0
>
> Attachments: d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Svata Dedic (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12606060#action_12606060 ]
Svata Dedic commented on DERBY-3693:
------------------------------------
Knut,
I tried your patch - the conditional code activates (I put a println in there), but only after a considerable timeout elapses -- so it does not solve the issue.
There are no other threads accessing the database at the time the deadlock occurs, the thread which waits (until timeout elapses and the lock is broken) is the only one working with Derby. The connection may handed to several threads in our app, but only one of them can get and use it at any given time.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: deadlock.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Resolved: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen resolved DERBY-3693.
---------------------------------------
Resolution: Fixed
Filed remaining tasks as DERBY-3850. Marking this bug as resolved.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.4.2.0, 10.5.0.0
>
> Attachments: comments.diff, d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Derby Info: (was: [Existing Application Impact])
I removed the "Existing Application Impact" flag since it refers to the impact of the fix, not the bug.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: deadlock.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: nested_transaction.diff
Invalidating the meta-data queries in a nested transaction seems to fix the problem. The attached patch (nested_transaction.diff) shows this approach, and the timeout is not seen in the repro (GetTables.java) anymore. I haven't run the regression tests or added new regression tests for this problem yet, and will probably not have time to do it in a couple of weeks, but I'm attaching the patch now for others to try and comment on.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java, nested_transaction.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12624864#action_12624864 ]
Knut Anders Hatlen commented on DERBY-3693:
-------------------------------------------
With the latest patch, we can probably remove the lowering of the lock timeout in some of the regression tests marked with DERBY-177. The tests affected by DERBY-177 can be found in DatabaseMetaDataTest and UpdatableResultSetTest.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Attachments: d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Derby Info: [Patch Available]
The regression tests passed on JDK 6. I'll start a test run on Java 1.4 as well, since a different code path is followed there.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Attachments: d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Dag H. Wanvik (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12600322#action_12600322 ]
Dag H. Wanvik commented on DERBY-3693:
--------------------------------------
Are are able to produce a repro program for this? I tried to make one based on your explanations, but no luck yet.
>From what you say, the problem is intermittent, so presumably more than one connection makes the
metadata queries? What isolation level are you running with? (default is read committed).
Is there more information in derby.log? Did the deadlock dump only show the victim?
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Fix Version/s: 10.4.2.0
I merged the fix to the 10.4 branch with revision 688766.
I guess the issue must be marked as resolved in order to show up in the list of fixed issues in the 10.4.2 release notes, and the release candidate will be built very soon. There are still some clean-up tasks related to this issue, but since they are not needed for the fix, I think I'll resolve this issue and open a new issue for the clean-up tasks.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Assignee: Knut Anders Hatlen
> Fix For: 10.4.2.0, 10.5.0.0
>
> Attachments: comments.diff, d3693.java, deadlock.diff, derby.log, dontWait.diff, dontWait.stat, GetTables.java, nested_transaction.diff, nested_transaction_v2.diff
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3693) Deadlocks accessing DB metadata
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3693?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Knut Anders Hatlen updated DERBY-3693:
--------------------------------------
Attachment: GetTables.java
Thanks David, that was a very useful piece of information! I think I (almost) see what's happening in your case.
Derby periodically checks whether a compiled plan should be recompiled (configurable with the derby.language.stalePlanCheckInterval property). When it detects that the size of SYS.SYSTABLES has changed considerably since getTables() was compiled the last time (because you have added more tables), it'll recompile the plan to see if it can create a plan that is more efficient.
The recompilation happens in a nested transaction, which runs into a lock conflict with the parent transaction when it tries to store the compiled plan in SYS.SYSSTATEMENTS, and therefore it hangs for the duration specified by derby.locks.waitTimeout. This hang is DERBY-177. This is the part I don't quite understand. The parent transaction shouldn't have any locks in this case, since it hasn't performed any operations before the call to getTables(). My guess is that it still holds some locks after querying the system tables to see if a recompilation is needed.
Normally, after the nested transaction times out, the timeout exception is intercepted and the recompilation is retried in the parent transaction. However, because derby.locks.deadlockTrace is set, the timeout exception has a different SQLState than what the retry logic expects (40XL2 instead of 40XL1), and the exception is not intercepted.
I have attached a java class (GetTables.java) that simulates your application. It has a loop which continuously executes CREATE TABLE and getTables(). If I run the class without derby.locks.deadlockTrace, I see a hang each time getTables() is recompiled. It continues with no error after the hang. If I run with derby.locks.deadlockTrace, it fails with a timeout exception the first time getTables() is recompiled.
Now, I think the patch I attached earlier (deadlock.diff) will help so that the timeout exception isn't thrown, but as Svata noted, you'll still see the hang.
I see the following possible workarounds:
1) Don't run with derby.locks.deadlockTrace. You'll still see the hangs, but it won't fail. You may also want to lower derby.locks.waitTimeout to reduce the problem with the hangs.
2) Increase the value of derby.language.stalePlanCheckInterval (default 100) so that you manage to create all your tables without recompiling getTables().
To fix the issue permanently, we need to find out why the parent transaction holds locks in the system tables before it recompiles the getTables() query, and find out how we can ensure that these locks don't conflict with the nested transaction.
> Deadlocks accessing DB metadata
> -------------------------------
>
> Key: DERBY-3693
> URL: https://issues.apache.org/jira/browse/DERBY-3693
> Project: Derby
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 10.3.2.1, 10.3.3.0, 10.4.1.3
> Environment: Linux amd64 or Windows 32bit
> Reporter: Svata Dedic
> Attachments: d3693.java, deadlock.diff, derby.log, GetTables.java
>
>
> My code changes DB structure (create a column), then immediately after setting autocommit back to true, the code rescans the DB metadata
> DatabaseMetaData.getColumns(catalog, schemaName, tableName, null);
> I am sometimes getting a deadlock with these operations:
> 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../a3/.config/localdb/db), (DRDAID = null), Cleanup action starting 2008-04-16 19:50:47.833 GMT Thread[Default RequestProcessor,1,system] (XID = 569844), (SESSIONID = 2), (DATABASE = /..../IJCProjects/a3/.config/localdb/db), (DRDAID = null), Failed Statement is: EXECUTE STATEMENT SYS."getColumns" ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> 2008-04-16 19:50:47.796 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 ***
> 569852 |ROW |X |0 |(44,7) |WAIT |S |NULL |SYSSTATEMENTS |
> *** The above row is the victim ***
> The stacktrace of the operation causing the deadlock is
> at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source)
> at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source)
> at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source)
> at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source)
> at org.apache.derby.impl.store.access.btree.BTreeScan.fetchNext(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.TabInfoImpl.updateRow(Unknown Source)
> at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.updateSPS(Unknown Source )
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.updateSYSSTATEMENTS(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.iapi.sql.dictionary.SPSDescriptor.getPreparedStatement(Unknown Source)
> at org.apache.derby.impl.sql.compile.ExecSPSNode.generate(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepMinion(Unknown Source)
> at org.apache.derby.impl.sql.GenericStatement.prepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.rePrepare(Unknown Source)
> at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetCols(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getColumns(Unknown Source)
> I've seen the deadlock occur during several get-metadata operations (getImportedKeys, ...), each time waiting on the SYSSTATEMENTS apparently because of internally constructed PreparedStatement. The lock eventually times out and the locked out operation completes without error.
> When the deadlock occurs, the "real" SQL into systables is being compiled (I traced this sql to be the value of "getColumns" key in org/apache/derby/impl/jdbc/metadata.properties file):
> ---------%<-----------------------%<--------------
> Begin compiling prepared statement: SELECT CAST ('' AS VARCHAR(128)) AS PKTABLE_CAT, S.SCHEMANAME AS PKTABLE_SCHEM, TABLENAME AS
> PKTABLE_NAME, COLS.COLUMNNAME AS PKCOLUMN_NAME, CAST ('' AS VARCHAR(128)) AS FKTABLE_CAT, FKTABLE_SCHEM, FKTABLE_NAME, FKCOLUMN_NAME, CAST ...
> ---------%<-----------------------%<--------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.