search

LucidDB / luciddb

DEFUNCT: See README
https://github.com/LucidDB/luciddb
Apache License 2.0
53 stars 24 forks source link

[LDB-118] deadlocks got while running concurrent query and ddl statements #203

Closed dynamobi-build closed 12 years ago

dynamobi-build commented 12 years ago

[reporter="kvu", created="Mon, 17 Jul 2006 11:55:23 -0500 (GMT-05:00)"] The below script caused a deadlock (notes: the script was ok if run without thread r1)

To reproduce the issue:
    go to open/luciddb/test/sql/concurrency
    add the below script cretdrp-write.mtsql to the above directory
    edit test.xml: add these lines before cleanup hook:
------------------------------------------------------------------------------------------------------------------------
         
        <junit-sql
          file="${open.dir}/luciddb/test/sql/concurrency/cretdrp-write.mtsql"/>
      
------------------------------------------------------------------------------------------------------------------------

----------------------------------------
script cretdrp-write.mtsql:
----------------------------------------

@nolockstep


@setup
-- check ddl vs read and write

  SET SCHEMA 'concurrency';
  select * from t1;
  select * from t2;

@end

---------------------------------------------------------

@thread comp
  set schema 'concurrency';
-- @sync
  @sync
  @sync
  select * from t1;
  select * from t2;
  select * from t11;
  select * from t12;
  select * from t13;
  select * from t14;
  select * from t15;
  select * from t21;
  select * from t22;
  select * from t23;
  select * from t24;
  select * from t25;
  select * from t31;
  select * from t32;
  select * from t33;
  select * from t34;
  select * from t35;
  select * from t41;
  select * from t42;
  select * from t43;
  select * from t44;
  select * from t45;
  select * from t51;
  select * from t52;
  select * from t53;
  select * from t54;
  select * from t55;

  drop index t11idx;
  drop index t12idx;
  drop index t13idx;
  drop index t14idx;
  drop index t15idx;
  drop index t21idx;
  drop index t22idx;
  drop index t23idx;
  drop index t24idx;
  drop index t25idx;
  drop index t31idx;
  drop index t32idx;
  drop index t33idx;
  drop index t34idx;
  drop index t35idx;
  drop index t41idx;
  drop index t42idx;
  drop index t43idx;
  drop index t44idx;
  drop index t45idx;
  drop index t51idx;
  drop index t52idx;
  drop index t53idx;
  drop index t54idx;
  drop index t55idx;

  drop table t11;
  drop table t12;
  drop table t13;
  drop table t14;
  drop table t15;
  drop table t21;
  drop table t22;
  drop table t23;
  drop table t24;
  drop table t25;
  drop table t31;
  drop table t32;
  drop table t33;
  drop table t34;
  drop table t35;
  drop table t41;
  drop table t42;
  drop table t43;
  drop table t44;
  drop table t45;
  drop table t51;
  drop table t52;
  drop table t53;
  drop table t54;
  drop table t55;

@end

---------------------------------------------------------

@thread ddl1
  SET SCHEMA 'concurrency';
-- @sync
  @sync
  create table t11 (n integer);
  create table t12 (n integer);
  create table t13 (n integer);
  create table t14 (n integer);
  create table t15 (n integer);
  create index t11idx on t11(n);
  create index t12idx on t12(n);
  create index t13idx on t13(n);
  create index t14idx on t14(n);
  create index t15idx on t15(n);
  @sync

@end

---------------------------------------------------------

@thread ddl2
  SET SCHEMA 'concurrency';
-- @sync
  @sync
  create table t21 (n integer);
  create table t22 (n integer);
  create table t23 (n integer);
  create table t24 (n integer);
  create table t25 (n integer);
  create index t21idx on t21(n);
  create index t22idx on t22(n);
  create index t23idx on t23(n);
  create index t24idx on t24(n);
  create index t25idx on t25(n);
  @sync

@end

---------------------------------------------------------

@thread ddl3
  SET SCHEMA 'concurrency';
-- @sync
  @sync
  create table t31 (n integer);
  create table t32 (n integer);
  create table t33 (n integer);
  create table t34 (n integer);
  create table t35 (n integer);
  create index t31idx on t31(n);
  create index t32idx on t32(n);
  create index t33idx on t33(n);
  create index t34idx on t34(n);
  create index t35idx on t35(n);
  @sync

@end

---------------------------------------------------------

@thread ddl4
  SET SCHEMA 'concurrency';
-- @sync
  @sync
  create table t41 (n integer);
  create table t42 (n integer);
  create table t43 (n integer);
  create table t44 (n integer);
  create table t45 (n integer);
  create index t41idx on t41(n);
  create index t42idx on t42(n);
  create index t43idx on t43(n);
  create index t44idx on t44(n);
  create index t45idx on t45(n);
  @sync

@end

---------------------------------------------------------

@thread ddl5
  SET SCHEMA 'concurrency';
-- @sync
  @sync
  create table t51 (n integer);
  create table t52 (n integer);
  create table t53 (n integer);
  create table t54 (n integer);
  create table t55 (n integer);
  create index t51idx on t51(n);
  create index t52idx on t52(n);
  create index t53idx on t53(n);
  create index t54idx on t54(n);
  create index t55idx on t55(n);
  @sync

@end

---------------------------------------------------------

@thread r1
  set schema 'concurrency';
  
  @sync
  insert into t1 values (1),(2),(3);
  insert into t2 select * from t1;
  @sync
-- @sync

@end


----------------------------
The thread dump:
----------------------------

       [bh] ===== FULL THREAD DUMP ===============
       [bh] Mon Jul 17 11:34:27 2006
       [bh] BEA JRockit(R) R26.3.0-32-58710-1.5.0_06-20060308-2022-linux-ia32

       [bh] "Main Thread" id=1 idx=0x2 tid=10145 prio=5 alive, in native, waiting
       [bh] -- Waiting for notification on: net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor@0xcf81b30[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at java/lang/Object.wait(J)V(Native Method)
       [bh] at java/lang/Thread.join(J)V(Unknown Source)
       [bh] ^-- Lock released while waiting: net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor@0xcf81b30[fat lock]
       [bh] at java/lang/Thread.join()V(Unknown Source)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentTestCase.executeTest(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator;Z)V(FarragoTestConcurrentTestCase.java:183)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedTestCase.runScript(Ljava/lang/String;)V(FarragoTestConcurrentScriptedTestCase.java:85)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentTest.runTest()V(FarragoTestConcurrentTest.java:117)
       [bh] at com/lucidera/luciddb/test/SqlTest$MtsqlTestCase.go()V(SqlTest.java:413)
       [bh] at com/lucidera/luciddb/test/SqlTest.runMtsqlTest()V(SqlTest.java:207)
       [bh] at com/lucidera/luciddb/test/SqlTest.testSql()V(SqlTest.java:149)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] at jrockit/reflect/NativeMethodInvoker.invoke0(Ljava/lang/Object;ILjava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Native Method)
       [bh] at jrockit/reflect/NativeMethodInvoker.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/reflect/VirtualNativeMethodInvoker.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at java/lang/reflect/Method.invoke(Ljava/lang/Object;[Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)
       [bh] at junit/framework/TestCase.runTest()V(TestCase.java:164)
       [bh] at junit/framework/TestCase.runBare()V(TestCase.java:130)
       [bh] at junit/framework/TestResult$1.protect()V(TestResult.java:110)
       [bh] at junit/framework/TestResult.runProtected(Ljunit/framework/Test;Ljunit/framework/Protectable;)V(TestResult.java:128)
       [bh] at junit/framework/TestResult.run(Ljunit/framework/TestCase;)V(TestResult.java:113)
       [bh] at junit/framework/TestCase.run(Ljunit/framework/TestResult;)V(TestCase.java:120)
       [bh] at junit/framework/TestSuite.runTest(Ljunit/framework/Test;Ljunit/framework/TestResult;)V(TestSuite.java:228)
       [bh] at junit/framework/TestSuite.run(Ljunit/framework/TestResult;)V(TestSuite.java:223)
       [bh] at org/eigenbase/blackhawk/extension/exectask/junit/JUnitRunner.run()V(JUnitRunner.java:78)
       [bh] at org/eigenbase/blackhawk/extension/exectask/junit/JunitTestLogicTask.run(Lorg/eigenbase/blackhawk/task/TaskContext;)Lorg/eigenbase/blackhawk/task/TaskContext;(JunitTestLogicTask.java:56)
       [bh] at org/eigenbase/blackhawk/core/test/AbstractTestLogicTask.runtask(Lorg/eigenbase/blackhawk/task/TaskContext;)Lorg/eigenbase/blackhawk/task/TaskContext;(AbstractTestLogicTask.java:169)
       [bh] at org/eigenbase/blackhawk/core/test/vehicle/LocalTestVehicle.runTask(Lorg/eigenbase/blackhawk/task/Task;Lorg/eigenbase/blackhawk/task/TaskContext;)Lorg/eigenbase/blackhawk/task/TaskContext;(LocalTestVehicle.java:64)
       [bh] at org/eigenbase/blackhawk/core/test/vehicle/LocalTestVehicle.runTask(Lorg/eigenbase/blackhawk/task/Task;)Lorg/eigenbase/blackhawk/task/TaskContext;(LocalTestVehicle.java:58)
       [bh] at org/eigenbase/blackhawk/core/test/vehicle/LocalTestVehicle.run(Lorg/eigenbase/blackhawk/core/process/ProcessHandler;Lorg/eigenbase/blackhawk/core/test/TestLogicTask;)V(LocalTestVehicle.java:39)
       [bh] at org/eigenbase/blackhawk/core/ExecutionTaskHelper.runTestLogic()V(ExecutionTaskHelper.java:141)
       [bh] at org/eigenbase/blackhawk/core/AbstractExecutionTask.runWithoutTimeout()V(AbstractExecutionTask.java:660)
       [bh] at org/eigenbase/blackhawk/core/AbstractExecutionTask.run()Z(AbstractExecutionTask.java:601)
       [bh] at org/eigenbase/blackhawk/core/BaseTwoPassTask.callHooks()V(BaseTwoPassTask.java:85)
       [bh] at org/eigenbase/blackhawk/core/BaseTwoPassTask.execute()V(BaseTwoPassTask.java:56)
       [bh] at org/apache/tools/ant/Task.perform()V(Task.java:364)
       [bh] at org/eigenbase/blackhawk/util/AntUtils.perform(Ljava/util/Collection;)V(AntUtils.java:33)
       [bh] at org/eigenbase/blackhawk/core/BaseTaskContainer.preAlwaysDo()Z(BaseTaskContainer.java:196)
       [bh] at org/eigenbase/blackhawk/core/BaseTwoPassTask.callHooks()V(BaseTwoPassTask.java:83)
       [bh] at org/eigenbase/blackhawk/core/BaseTwoPassTask.execute()V(BaseTwoPassTask.java:56)
       [bh] at org/apache/tools/ant/Task.perform()V(Task.java:364)
       [bh] at org/eigenbase/blackhawk/core/TestRunner.run()Z(TestRunner.java:77)
       [bh] at org/eigenbase/blackhawk/core/BaseTwoPassTask.callHooks()V(BaseTwoPassTask.java:85)
       [bh] at org/eigenbase/blackhawk/core/BaseTwoPassTask.execute()V(BaseTwoPassTask.java:56)
       [bh] at org/apache/tools/ant/UnknownElement.execute()V(UnknownElement.java:275)
       [bh] at org/apache/tools/ant/Task.perform()V(Task.java:364)
       [bh] at org/apache/tools/ant/Target.execute()V(Target.java:341)
       [bh] at org/apache/tools/ant/Target.performTasks()V(Target.java:369)
       [bh] at org/apache/tools/ant/Project.executeSortedTargets(Ljava/util/Vector;)V(Project.java:1216)
       [bh] at org/apache/tools/ant/Project.executeTarget(Ljava/lang/String;)V(Project.java:1185)
       [bh] at org/apache/tools/ant/helper/DefaultExecutor.executeTargets(Lorg/apache/tools/ant/Project;[Ljava/lang/String;)V(DefaultExecutor.java:40)
       [bh] at org/apache/tools/ant/Project.executeTargets(Ljava/util/Vector;)V(Project.java:1068)
       [bh] at org/apache/tools/ant/Main.runBuild(Ljava/lang/ClassLoader;)V(Main.java:668)
       [bh] at org/apache/tools/ant/Main.startAnt([Ljava/lang/String;Ljava/util/Properties;Ljava/lang/ClassLoader;)V(Main.java:187)
       [bh] at org/apache/tools/ant/Main.start([Ljava/lang/String;Ljava/util/Properties;Ljava/lang/ClassLoader;)V(Main.java:150)
       [bh] at org/apache/tools/ant/Main.main([Ljava/lang/String;)V(Main.java:240)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "(Signal Handler)" id=2 idx=0x4 tid=10148 prio=5 alive, in native, daemon

       [bh] "(Code Generation Thread 1)" id=3 idx=0x6 tid=10149 prio=5 alive, in native, native_waiting, daemon

       [bh] "(Code Optimization Thread 1)" id=4 idx=0x8 tid=10150 prio=5 alive, in native, native_waiting, daemon

       [bh] "(GC Main Thread)" id=5 idx=0xa tid=10151 prio=5 alive, in native, daemon

       [bh] "(GC Worker Thread 1)" id=? idx=0xc tid=10152 prio=5 alive, native_waiting, daemon

       [bh] "(VM Periodic Task)" id=6 idx=0xe tid=10153 prio=10 alive, in native, daemon

       [bh] "Finalizer" id=7 idx=0x10 tid=10154 prio=8 alive, in native, native_waiting, daemon
       [bh] at jrockit/memory/Finalizer.getPendingFinalizee(Z)Ljava/lang/Object;(Native Method)
       [bh] at jrockit/memory/Finalizer.access$100(Z)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/memory/Finalizer$4.run()V(Unknown Source)
       [bh] at java/lang/Thread.run()V(Unknown Source)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Reference Handler" id=8 idx=0x12 tid=10155 prio=10 alive, in native, native_waiting, daemon
       [bh] at java/lang/ref/Reference.getPending()Ljava/lang/ref/Reference;(Native Method)
       [bh] at java/lang/ref/Reference.access$000()Ljava/lang/ref/Reference;(Unknown Source)
       [bh] at java/lang/ref/Reference$ReferenceHandler.run()V(Unknown Source)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Active Reference Queue Daemon" id=14 idx=0x14 tid=10163 prio=1 alive, in native, waiting, daemon
       [bh] -- Waiting for notification on: java/lang/ref/ReferenceQueue$Lock@0x848d358[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at java/lang/Object.wait(J)V(Native Method)
       [bh] at java/lang/ref/ReferenceQueue.remove(J)Ljava/lang/ref/Reference;(ReferenceQueue.java:116)
       [bh] ^-- Lock released while waiting: java/lang/ref/ReferenceQueue$Lock@0x848d358[fat lock]
       [bh] at org/openide/util/Utilities$ActiveQueue.run()V(Utilities.java:2442)
       [bh] at java/lang/Thread.run()V(Unknown Source)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "HSQLDB Timer @10b4d61" id=15 idx=0x16 tid=10164 prio=5 alive, in native, waiting, daemon
       [bh] -- Waiting for notification on: org/hsqldb/lib/HsqlTimer@0x8513b08[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at java/lang/Object.wait(J)V(Native Method)
       [bh] at org/hsqldb/lib/HsqlTimer.nextTask()Lorg/hsqldb/lib/HsqlTimer$Task;(Unknown Source)
       [bh] ^-- Lock released while waiting: org/hsqldb/lib/HsqlTimer@0x8513b08[fat lock]
       [bh] at org/hsqldb/lib/HsqlTimer$TaskRunner.run()V(Unknown Source)
       [bh] at java/lang/Thread.run()V(Unknown Source)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "MDR event dispatcher" id=16 idx=0x18 tid=10167 prio=5 alive, in native, waiting, daemon
       [bh] -- Waiting for notification on: java/util/LinkedList@0xa0f5380[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.wait(Ljava/lang/Object;J)V(Unknown Source)
       [bh] at java/lang/Object.wait()V(Native Method)
       [bh] at org/netbeans/mdr/util/EventNotifier$EventsDelivery.run()V(EventNotifier.java:257)
       [bh] ^-- Lock released while waiting: java/util/LinkedList@0xa0f5380[fat lock]
       [bh] at java/lang/Thread.run()V(Unknown Source)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Timer-0" id=17 idx=0x1a tid=10172 prio=5 alive, in native, waiting
       [bh] -- Waiting for notification on: java/util/TaskQueue@0xc0af8e0[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at java/lang/Object.wait(J)V(Native Method)
       [bh] at java/util/TimerThread.mainLoop()V(Timer.java:509)
       [bh] ^-- Lock released while waiting: java/util/TaskQueue@0xc0af8e0[fat lock]
       [bh] at java/util/TimerThread.run()V(Timer.java:462)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor comp" id=25 idx=0x1c tid=10194 prio=5 alive, in native, waiting
       [bh] -- Waiting for notification on: net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor$Sync@0xcf839e0[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.wait(Ljava/lang/Object;J)V(Unknown Source)
       [bh] at java/lang/Object.wait()V(Native Method)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor$Sync.waitForOthers()V(FarragoTestConcurrentCommandExecutor.java:299)
       [bh] ^-- Lock released while waiting: net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor$Sync@0xcf839e0[fat lock]
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$SynchronizationCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:641)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor ddl1" id=26 idx=0x1e tid=10195 prio=5 alive, in native, blocked
       [bh] -- Blocked trying to get lock: java/lang/Integer@0x8535e48[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.fatLockBlockOrSpin(ILjrockit/vm/ObjectMonitor;II)V(Unknown Source)
       [bh] at jrockit/vm/Locks.lockFat(Ljava/lang/Object;ILjrockit/vm/ObjectMonitor;Z)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at net/sf/farrago/db/FarragoDbSession.prepare(Lnet/sf/farrago/db/FarragoDbStmtContextBase;Ljava/lang/String;Lnet/sf/farrago/util/FarragoAllocationOwner;ZLnet/sf/farrago/session/FarragoSessionAnalyzedSql;)Lnet/sf/farrago/session/FarragoSessionExecutableStmt;(FarragoDbSession.java:810)
       [bh] at net/sf/farrago/db/FarragoDbStmtContext.prepare(Ljava/lang/String;Z)V(FarragoDbStmtContext.java:108)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEngineConnection.prepareStatement(Ljava/lang/String;)Ljava/sql/PreparedStatement;(FarragoJdbcEngineConnection.java:327)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedCommandGenerator$SqlCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentScriptedCommandGenerator.java:1041)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor ddl2" id=27 idx=0x20 tid=10196 prio=5 alive, in native
       [bh] at net/sf/farrago/fennel/FennelStorage.executeJavaCmd(Lnet/sf/farrago/fem/fennel/FemCmd;)J(Native Method)
       [bh] at net/sf/farrago/fennel/FennelCmdExecutorImpl.executeJavaCmd(Lnet/sf/farrago/fem/fennel/FemCmd;)J(FennelCmdExecutorImpl.java:45)
       [bh] at net/sf/farrago/fennel/FennelDbHandle.executeCmd(Lnet/sf/farrago/fem/fennel/FemCmd;)J(FennelDbHandle.java:252)
       [bh] at net/sf/farrago/fennel/FennelTxnContext.commit()V(FennelTxnContext.java:152)
       [bh] at net/sf/farrago/db/FarragoDbSession.commitImpl()V(FarragoDbSession.java:612)
       [bh] at net/sf/farrago/db/FarragoDbSession.executeDdl(Lnet/sf/farrago/session/FarragoSessionDdlValidator;Lnet/sf/farrago/catalog/FarragoReposTxnContext;Lnet/sf/farrago/session/FarragoSessionDdlStmt;)V(FarragoDbSession.java:956)
       [bh] at net/sf/farrago/db/FarragoDbSession.prepareImpl(Ljava/lang/String;Lnet/sf/farrago/util/FarragoAllocationOwner;ZLnet/sf/farrago/session/FarragoSessionAnalyzedSql;Lnet/sf/farrago/session/FarragoSessionStmtValidator;Lnet/sf/farrago/catalog/FarragoReposTxnContext;[Z)Lnet/sf/farrago/session/FarragoSessionExecutableStmt;(FarragoDbSession.java:913)
       [bh] at net/sf/farrago/db/FarragoDbSession.prepare(Lnet/sf/farrago/db/FarragoDbStmtContextBase;Ljava/lang/String;Lnet/sf/farrago/util/FarragoAllocationOwner;ZLnet/sf/farrago/session/FarragoSessionAnalyzedSql;)Lnet/sf/farrago/session/FarragoSessionExecutableStmt;(FarragoDbSession.java:829)
       [bh] ^-- Holding lock: java/lang/Integer@0x8535e48[fat lock]
       [bh] at net/sf/farrago/db/FarragoDbStmtContext.prepare(Ljava/lang/String;Z)V(FarragoDbStmtContext.java:108)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEnginePreparedDdl.executeDdl()V(FarragoJdbcEnginePreparedDdl.java:91)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEnginePreparedDdl.executeUpdate()I(FarragoJdbcEnginePreparedDdl.java:80)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedCommandGenerator$SqlCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentScriptedCommandGenerator.java:1047)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor ddl3" id=28 idx=0x22 tid=10197 prio=5 alive, in native, blocked
       [bh] -- Blocked trying to get lock: java/lang/Integer@0x8535e48[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.fatLockBlockOrSpin(ILjrockit/vm/ObjectMonitor;II)V(Unknown Source)
       [bh] at jrockit/vm/Locks.fatLockReacquire(Ljava/lang/Object;Ljava/lang/Thread;)Ljrockit/vm/ObjectMonitor;(Unknown Source)
       [bh] at jrockit/vm/Locks.lockFat(Ljava/lang/Object;ILjrockit/vm/ObjectMonitor;Z)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at net/sf/farrago/db/FarragoDbSession.prepare(Lnet/sf/farrago/db/FarragoDbStmtContextBase;Ljava/lang/String;Lnet/sf/farrago/util/FarragoAllocationOwner;ZLnet/sf/farrago/session/FarragoSessionAnalyzedSql;)Lnet/sf/farrago/session/FarragoSessionExecutableStmt;(FarragoDbSession.java:810)
       [bh] at net/sf/farrago/db/FarragoDbStmtContext.prepare(Ljava/lang/String;Z)V(FarragoDbStmtContext.java:108)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEngineConnection.prepareStatement(Ljava/lang/String;)Ljava/sql/PreparedStatement;(FarragoJdbcEngineConnection.java:327)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedCommandGenerator$SqlCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentScriptedCommandGenerator.java:1041)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor ddl4" id=29 idx=0x24 tid=10198 prio=5 alive, in native, blocked
       [bh] -- Blocked trying to get lock: java/lang/Integer@0x8535e48[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.fatLockBlockOrSpin(ILjrockit/vm/ObjectMonitor;II)V(Unknown Source)
       [bh] at jrockit/vm/Locks.lockFat(Ljava/lang/Object;ILjrockit/vm/ObjectMonitor;Z)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at net/sf/farrago/db/FarragoDbSession.prepare(Lnet/sf/farrago/db/FarragoDbStmtContextBase;Ljava/lang/String;Lnet/sf/farrago/util/FarragoAllocationOwner;ZLnet/sf/farrago/session/FarragoSessionAnalyzedSql;)Lnet/sf/farrago/session/FarragoSessionExecutableStmt;(FarragoDbSession.java:810)
       [bh] at net/sf/farrago/db/FarragoDbStmtContext.prepare(Ljava/lang/String;Z)V(FarragoDbStmtContext.java:108)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEngineConnection.prepareStatement(Ljava/lang/String;)Ljava/sql/PreparedStatement;(FarragoJdbcEngineConnection.java:327)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedCommandGenerator$SqlCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentScriptedCommandGenerator.java:1041)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor ddl5" id=30 idx=0x26 tid=10199 prio=5 alive, in native, blocked
       [bh] -- Blocked trying to get lock: java/lang/Integer@0x8535e48[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.fatLockBlockOrSpin(ILjrockit/vm/ObjectMonitor;II)V(Unknown Source)
       [bh] at jrockit/vm/Locks.lockFat(Ljava/lang/Object;ILjrockit/vm/ObjectMonitor;Z)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at net/sf/farrago/db/FarragoDbSession.prepare(Lnet/sf/farrago/db/FarragoDbStmtContextBase;Ljava/lang/String;Lnet/sf/farrago/util/FarragoAllocationOwner;ZLnet/sf/farrago/session/FarragoSessionAnalyzedSql;)Lnet/sf/farrago/session/FarragoSessionExecutableStmt;(FarragoDbSession.java:810)
       [bh] at net/sf/farrago/db/FarragoDbStmtContext.prepare(Ljava/lang/String;Z)V(FarragoDbStmtContext.java:108)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEngineConnection.prepareStatement(Ljava/lang/String;)Ljava/sql/PreparedStatement;(FarragoJdbcEngineConnection.java:327)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedCommandGenerator$SqlCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentScriptedCommandGenerator.java:1041)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] "Command Executor r1" id=31 idx=0x28 tid=10200 prio=5 alive, in native, waiting
       [bh] -- Waiting for notification on: org/netbeans/mdr/util/MultipleReadersMutex@0xa1016c8[fat lock]
       [bh] at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)
       [bh] at jrockit/vm/Locks.wait(Ljava/lang/Object;J)V(Unknown Source)
       [bh] at java/lang/Object.wait()V(Native Method)
       [bh] at org/netbeans/mdr/util/MultipleReadersMutex.enter(Z)V(MultipleReadersMutex.java:113)
       [bh] ^-- Lock released while waiting: org/netbeans/mdr/util/MultipleReadersMutex@0xa1016c8[fat lock]
       [bh] at org/netbeans/mdr/NBMDRepositoryImpl.beginTrans(Z)V(NBMDRepositoryImpl.java:227)
       [bh] at net/sf/farrago/catalog/FarragoMdrReposImpl.beginReposTxn(Z)V(FarragoMdrReposImpl.java:231)
       [bh] at net/sf/farrago/runtime/FarragoRuntimeContext.getStreamHandle(Ljava/lang/String;Z)Lnet/sf/farrago/fennel/FennelStreamHandle;(FarragoRuntimeContext.java:567)
       [bh] at net/sf/farrago/runtime/FarragoRuntimeContext.newFennelTupleIter(Lnet/sf/farrago/runtime/FennelTupleReader;Ljava/lang/String;ILjava/lang/Object;)Lorg/eigenbase/runtime/TupleIter;(FarragoRuntimeContext.java:502)
       [bh] at net/sf/farrago/dynamic/stmt22057/ExecutableStmt.execute(Lnet/sf/farrago/runtime/FarragoRuntimeContext;)Ljava/lang/Object;(Unknown Source)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] at jrockit/reflect/NativeMethodInvoker.invoke0(Ljava/lang/Object;ILjava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Native Method)
       [bh] at jrockit/reflect/NativeMethodInvoker.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
       [bh] at java/lang/reflect/Method.invoke(Ljava/lang/Object;[Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)
       [bh] at net/sf/farrago/query/FarragoExecutableJavaStmt.execute(Lnet/sf/farrago/session/FarragoSessionRuntimeContext;)Ljava/sql/ResultSet;(FarragoExecutableJavaStmt.java:135)
       [bh] at net/sf/farrago/db/FarragoDbStmtContext.execute()V(FarragoDbStmtContext.java:211)
       [bh] at net/sf/farrago/jdbc/engine/FarragoJdbcEnginePreparedNonDdl.executeUpdate()I(FarragoJdbcEnginePreparedNonDdl.java:101)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentScriptedCommandGenerator$SqlCommand.doExecute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentScriptedCommandGenerator.java:1047)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandGenerator$AbstractCommand.execute(Lnet/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor;)V(FarragoTestConcurrentCommandGenerator.java:592)
       [bh] at net/sf/farrago/test/concurrent/FarragoTestConcurrentCommandExecutor.run()V(FarragoTestConcurrentCommandExecutor.java:154)
       [bh] at jrockit/vm/RNI.c2java(IIII)V(Native Method)
       [bh] -- end of trace

       [bh] Blocked lock chains
       [bh] ===================
       [bh] Chain 2:
       [bh] "Command Executor ddl3" id=28 idx=0x22 tid=10197 waiting for java/lang/Integer@0x8535e48 held by:
       [bh] "Command Executor ddl2" id=27 idx=0x20 tid=10196 in chain 1

       [bh] Chain 3:
       [bh] "Command Executor ddl4" id=29 idx=0x24 tid=10198 waiting for java/lang/Integer@0x8535e48 held by:
       [bh] "Command Executor ddl2" id=27 idx=0x20 tid=10196 in chain 1

       [bh] Chain 4:
       [bh] "Command Executor ddl5" id=30 idx=0x26 tid=10199 waiting for java/lang/Integer@0x8535e48 held by:
       [bh] "Command Executor ddl2" id=27 idx=0x20 tid=10196 in chain 1

       [bh] Open lock chains
       [bh] ================
       [bh] Chain 1:
       [bh] "Command Executor ddl1" id=26 idx=0x1e tid=10195 waiting for java/lang/Integer@0x8535e48 held by:
       [bh] "Command Executor ddl2" id=27 idx=0x20 tid=10196 (active)

       [bh] ===== END OF THREAD DUMP ===============

dynamobi-build commented 12 years ago

[author="jvs", created="Tue, 18 Jul 2006 00:40:41 -0500 (GMT-05:00)"] OK, the deadlock is clear:

r1 waits for the repository mutex while holding the checkpoint lock
ddl2 waits for the checkpoint lock while holding the repository mutex

The best way to fix this one is to carry out a task I've been putting off for a while, namely replacing the transient repository storage with JmiMemFactory.

Once that is done, the repository locking will no longer be a problem.

However, I won't be able to get to this for a few weeks. So Khanh, you can check in the test disabled, and I'll re-enable it once my fix is ready.
Or check it in with just r1 commented out.

dynamobi-build commented 12 years ago

[author="kvu", created="Mon, 21 Aug 2006 16:54:46 -0500 (GMT-05:00)"] After this issued is fixed, please
(1) remove "notImplemented" tags in concurrency test.xml, sanity.xml
(2) remove parts commented out in .mtsql file as noted in test.xml

dynamobi-build commented 12 years ago

[author="jvs", created="Sun, 10 Dec 2006 15:37:38 -0500 (GMT-05:00)"] Fixed in eigenchange 8304. I re-enabled the tests in sanity.xml (and the commented-out code in cretdrp-write.mtsql) for checkin acceptance, and some of the short tests in test.xml (nightlies).

I left the longer tests disabled; some of them are doing things like sleeping for 5 seconds for every row of a big table, which would take way too much time. Liz/Khanh to review and decide what to do about those.