[DERBY-5430] Embedded nstest shows ERROR 40001: A lock could not be obtained due to a deadlock, in nstest

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Won't Fix
• Affects Version/s: 10.8.2.2
• Component/s: Test
• Environment: Windows XP, Suse Linux, NsTest Embedded, ibm 1.6 SR9 FP1.
• Urgency: Urgent
• Bug behavior facts: Regression Test Failure
• Assignee: Unassigned
• Reporter: Myrna van Lunteren
• Created: 26/Sep/11 17:14
• Updated: 01/Oct/12 22:38
• Resolved: 01/Oct/12 22:38

Description

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

Issue Links

• is related to: DERBY-5448 In the 10.8 branch, back out the concurrency improvements introduced by using SequenceUpdaters to allocate identity values.
• is related to: DERBY-5495 Master issue to track fixes to sequence generators
• relates to: DERBY-5671 NsTest does not run on trunk do multiple issues stemming from concurrency improvements
• relates to: DERBY-5454 ERROR 40001 deadlock in nstest on select max(serialkey)