db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Knut Anders Hatlen (Commented) (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DERBY-5430) Embedded nstest shows ERROR 40001: A lock could not be obtained due to a deadlock, in nstest
Date Wed, 28 Sep 2011 08:26:45 GMT

    [ https://issues.apache.org/jira/browse/DERBY-5430?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13116288#comment-13116288
] 

Knut Anders Hatlen commented on DERBY-5430:
-------------------------------------------

Rick, I think your reading of the deadlock trace is correct, and killing tx 1174407 isn't
helpful for breaking the cycle. Picking victims that already hold locks involved in the cycle
obviously would have resolved the deadlock quicker and with less victims. However, I think
the chosen victim technically may be part of the cycle.

It is blocked because there's one or more transactions ahead of it in the wait queue that
try to lock the same row exclusively (cannot tell exactly which transactions are ahead of
it, since that information isn't provided by the trace). That transaction is blocked by the
transactions that have been granted shared lock on the row. One (or more) of these transactions
is waiting for an exclusive lock on the row, and is right behind 1174407 in the wait queue,
and is therefore waiting for 1174407. This means 1174407 is indirectly waiting for itself,
and we have a cycle.

The deadlock detection algorithm picks the first tx it finds in the cycle as the victim. It
doesn't really try to find the "best" victim. I assume there would be two more deadlock exceptions
in the log not so long after this one, killing two of the transactions waiting for X locks.

An alternative reading of the stack trace (more in line with your reading, and since the order
of the wait queue isn't specified, just as reasonable) is that 1174407 attempted to lock the
row after the three transactions waiting for an exclusive lock had requested X locks. In that
case, none of the transactions are waiting for tx 1174407, and it should not have been picked
as a victim.
                
> Embedded nstest shows ERROR 40001: A lock could not be obtained due to a deadlock,  in
nstest
> ---------------------------------------------------------------------------------------------
>
>                 Key: DERBY-5430
>                 URL: https://issues.apache.org/jira/browse/DERBY-5430
>             Project: Derby
>          Issue Type: Bug
>    Affects Versions: 10.8.2.1
>         Environment: Windows XP, Suse Linux, NsTest Embedded, ibm 1.6 SR9 FP1.
>            Reporter: Myrna van Lunteren
>
> When running the nstest system test with Embedded with the 10.8.2.1 release candidate,
or a build sync-ed to the top of the 10.8 tree (at level: version: 10.8.2.2 - (1174879M) -
the M is to add checks (only do if not null) to number of PreparedStatement.close() calls),
I now see a number of deadlock errors if I capture the output to a file.
> The test run with network server did not show this problem.
> 10.7.1.1 and 10.8.1.2 did not show this problem.
> There's nothing in derby.log, but this is an example of the error to the console as captured
in a file:
> Thread 37 is now running
> ==========> Tester2Thread 37 THREAD starting <======
> Tester2Thread 37 is getting a connection to the database...
> -->Thread Tester2Thread 37 starting with url jdbc:derby:nstestdb;create=true;boo
> tPassword=12345678 <--
> Connection number: 44
> Tester2Thread 37 dbutil.pick_one() -> Obtained row from the table 35979
> Tester2Thread 37 attempting  to delete a row with serialkey = 35979
> Tester2Thread 37 deleted row with serialkey 35979 *** SUCCESS ***
> Tester2Thread 37 dbutil.pick_one() -> Obtained row from the table 35978
> java.sql.SQLTransactionRollbackException: A lock could not be obtained due to a
> deadlock, cycle of locks and waiters is:
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {1174407, S} , NSTEST,  insert into nstesttab (id, t_char, t_dat
> e, t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_larg
> e, t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?,
>  ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('00000000000000000000000000000000
> 031' as clob(1K)),cast(X'0000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 000000000000000000000000000000000000000000000000000000031' as blob(10K)))
>   Granted XID : {61356, S} , {75588, S} , {147655, S} , {204335, S} , {460963, S
> } , {511711, S} , {565264, S} , {727656, S} , {791364, S} , {1133117, S}
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {1133117, X} , NSTEST,  insert into nstesttab (id, t_char, t_dat
> e, t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_larg
> e, t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?,
>  ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('00000000000000000000000000000000
> 031' as clob(1K)),cast(X'0000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 000000000000000000000000000000000000000000000000000000031' as blob(10K)))
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {147655, X} , NSTEST,  insert into nstesttab (id, t_char, t_date
> , t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_large
> , t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?,
> ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('000000000000000000000000000000000
> 31' as clob(1K)),cast(X'00000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000031' as blob(10K)))
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {61356, X} , NSTEST,  insert into nstesttab (id, t_char, t_date,
>  t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_large,
>  t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?, ?
> , ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('0000000000000000000000000000000003
> 1' as clob(1K)),cast(X'000000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 0000000000000000000000000000000000000000000000000000031' as blob(10K)))
> . The selected victim is XID : 1174407.
>         at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unkn
> own Source)
>         at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source
> )
>         at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException
> (Unknown Source)
>         at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Un
> known Source)
>         at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown So
> urce)
>         at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown So
> urce)
>         at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown So
> urce)
>         at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Un
> known Source)
>         at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unkno
> wn Source)
>         at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil
> .java:201)
>         at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperat
> ion(TesterObject.java:148)
>         at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tes
> ter1.java:118)
>         at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
> Caused by: java.sql.SQLException: A lock could not be obtained due to a deadlock
> , cycle of locks and waiters is:
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {1174407, S} , NSTEST,  insert into nstesttab (id, t_char, t_dat
> e, t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_larg
> e, t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?,
>  ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('00000000000000000000000000000000
> 031' as clob(1K)),cast(X'0000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 000000000000000000000000000000000000000000000000000000031' as blob(10K)))
>   Granted XID : {61356, S} , {75588, S} , {147655, S} , {204335, S} , {460963, S
> } , {511711, S} , {565264, S} , {727656, S} , {791364, S} , {1133117, S}
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {1133117, X} , NSTEST,  insert into nstesttab (id, t_char, t_dat
> e, t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_larg
> e, t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?,
>  ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('00000000000000000000000000000000
> 031' as clob(1K)),cast(X'0000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 000000000000000000000000000000000000000000000000000000031' as blob(10K)))
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {147655, X} , NSTEST,  insert into nstesttab (id, t_char, t_date
> , t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_large
> , t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?,
> ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('000000000000000000000000000000000
> 31' as clob(1K)),cast(X'00000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000031' as blob(10K)))
> Lock : ROW, SYSCOLUMNS, (5,16)
>   Waiting XID : {61356, X} , NSTEST,  insert into nstesttab (id, t_char, t_date,
>  t_decimal, t_decimal_nn, t_double,  t_float, t_int, t_longint, t_numeric_large,
>  t_real, t_smallint, t_time, t_timestamp, t_varchar,t_clob,t_blob) values ( ?, ?
> , ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,cast('0000000000000000000000000000000003
> 1' as clob(1K)),cast(X'000000000000000000000000000000000000000000000000000000000
> 00000000000000000000000000000000000000000000000000000000000000000000000000000000
> 0000000000000000000000000000000000000000000000000000031' as blob(10K)))
> . The selected victim is XID : 1174407.
>         at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknow
> n Source)
>         at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransport
> AcrossDRDA(Unknown Source)
>         ... 13 more

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message