Hi,
thanks for your help.
I did some further tests today. The problem already appears when I want to
delete entries of an already emtpy table of a simple test entity with only a
primary key as property.
I don't really believe in database errors yet, because I haven't seen any in my
MySQL logs, and when I manually enter the query OpenJPA sends to MySQL, it
works.
Also the fact that I don't get any exception but a deadlock when I enable
openjpa.Multithreaded somehow hints to a threading problem I think.
With openjpa.Multithreaded enabled, my application thread and both slice
threads seem to wait for a lock, I can post their stacktraces below.
Now I fiddled a bit with my configuration and noticed something, I had
openjpa.BrokerImpl set to non-finalizing.
When I comment out this property, the exception (or the deadlock with
multithreaded mode) is gone, and everything seems to work, at first glance.
Then however I noticed it does not delete the table, and checked my MySQL logs.
OpenJPA sends the delete table commands, but does not commit the change,
instead it issues a rollback only.
I have no idea why, and the OpenJPA log (with loglevel set to TRACE) shows no
exception, nothing that hints at a rollback.
I'll paste some log excerpts logs below.
I'm really puzzled.
Do you have any further ideas what I could try?
If not, I'll indeed try to create a minimal testcase to reproduce the problem
tomorrow.
Just a word about my System btw, I'm on a dualcore CPU running Windows XP and
Java 1.6.0_25.
Regards,
Michael
Stacktraces of the deadlock when in multithreaded mode:
My application thread:
Thread [main] (Suspended)
Unsafe.park(boolean, long) line: not available [native method]
LockSupport.park(Object) line: not available
FutureTask$Sync(AbstractQueuedSynchronizer).parkAndCheckInterrupt()
line: not available
FutureTask$Sync(AbstractQueuedSynchronizer).doAcquireSharedInterruptibly(int)
line: not available
FutureTask$Sync(AbstractQueuedSynchronizer).acquireSharedInterruptibly(int)
line: not available
FutureTask$Sync.innerGet() line: not available
FutureTask<V>.get() line: not available
DistributedStoreQuery$ParallelExecutor.executeDelete(StoreQuery,
Object[]) line: 219
QueryImpl.delete(StoreQuery, StoreQuery$Executor, Object[]) line: 1025
QueryImpl.execute(int, Object[]) line: 822
QueryImpl.deleteAll(Object[]) line: 888
QueryImpl.deleteAll() line: 884
DelegatingQuery.deleteAll() line: 558
QueryImpl<X>.executeUpdate() line: 362
CorrectionDemo.main(String[]) line: 25
Main-slice-1:
Thread [main-slice-1] (Suspended)
Unsafe.park(boolean, long) line: not available [native method]
LockSupport.park(Object) line: not available
ReentrantLock$NonfairSync(AbstractQueuedSynchronizer).parkAndCheckInterrupt()
line: not available
ReentrantLock$NonfairSync(AbstractQueuedSynchronizer).acquireQueued(AbstractQueuedSynchronizer$Node,
int) line: not available
ReentrantLock$NonfairSync(AbstractQueuedSynchronizer).acquire(int)
line: not available
ReentrantLock$NonfairSync.lock() line: not available
ReentrantLock.lock() line: not available
BrokerImpl.lock() line: 4398
BrokerImpl.beginOperation(boolean) line: 1907
BrokerImpl.beginStore() line: 1390
JDBCStoreQuery.executeBulkOperation(ClassMetaData[], boolean,
ExpressionFactory[], QueryExpressions[], Object[], Map) line: 566
JDBCStoreQuery.executeDelete(StoreQuery$Executor, ClassMetaData,
ClassMetaData[], boolean, ExpressionFactory[], QueryExpressions[], Object[])
line: 491
ExpressionStoreQuery$DataStoreExecutor.executeDelete(StoreQuery,
Object[]) line: 788
DistributedStoreQuery$DeleteExecutor.call() line: 283
DistributedStoreQuery$DeleteExecutor.call() line: 277
FutureTask$Sync.innerRun() line: not available
FutureTask<V>.run() line: not available
ThreadPoolExecutor$Worker.runTask(Runnable) line: not available
ThreadPoolExecutor$Worker.run() line: not available
SliceThread(Thread).run() line: not available
Main-slice-0:
Thread [main-slice-0] (Suspended)
Unsafe.park(boolean, long) line: not available [native method]
LockSupport.park(Object) line: not available
ReentrantLock$NonfairSync(AbstractQueuedSynchronizer).parkAndCheckInterrupt()
line: not available
ReentrantLock$NonfairSync(AbstractQueuedSynchronizer).acquireQueued(AbstractQueuedSynchronizer$Node,
int) line: not available
ReentrantLock$NonfairSync(AbstractQueuedSynchronizer).acquire(int)
line: not available
ReentrantLock$NonfairSync.lock() line: not available
ReentrantLock.lock() line: not available
BrokerImpl.lock() line: 4398
BrokerImpl.beginOperation(boolean) line: 1907
BrokerImpl.beginStore() line: 1390
JDBCStoreQuery.executeBulkOperation(ClassMetaData[], boolean,
ExpressionFactory[], QueryExpressions[], Object[], Map) line: 566
JDBCStoreQuery.executeDelete(StoreQuery$Executor, ClassMetaData,
ClassMetaData[], boolean, ExpressionFactory[], QueryExpressions[], Object[])
line: 491
ExpressionStoreQuery$DataStoreExecutor.executeDelete(StoreQuery,
Object[]) line: 788
DistributedStoreQuery$DeleteExecutor.call() line: 283
DistributedStoreQuery$DeleteExecutor.call() line: 277
FutureTask$Sync.innerRun() line: not available
FutureTask<V>.run() line: not available
ThreadPoolExecutor$Worker.runTask(Runnable) line: not available
ThreadPoolExecutor$Worker.run() line: not available
SliceThread(Thread).run() line: not available
OpenJPA log with "non-finalizing" commented out:
4125 openjpa TRACE [main] openjpa.Query - Executing query: delete from
PlantCorrection pc
4109 openjpa.One TRACE [main-slice-1] openjpa.jdbc.SQL - <t 22245100, conn
964388> executing prepstmnt 31098843 DELETE t0 FROM PlantCorrection t0
4109 openjpa.One TRACE [main-slice-1] openjpa.jdbc.SQL - <t 22245100, conn
964388> [0 ms] spent
4109 openjpa.One TRACE [main-slice-1] openjpa.jdbc.JDBC - <t 22245100, conn
0> [0 ms] close
3859 openjpa.Two TRACE [main-slice-0] openjpa.jdbc.SQL - <t 13969258, conn
9924771> executing prepstmnt 19874213 DELETE t0 FROM PlantCorrection t0
3859 openjpa.Two TRACE [main-slice-0] openjpa.jdbc.SQL - <t 13969258, conn
9924771> [0 ms] spent
3859 openjpa.Two TRACE [main-slice-0] openjpa.jdbc.JDBC - <t 13969258, conn
0> [0 ms] close
MySQL log:
1689 Query SET autocommit=0
1689 Query DELETE t0 FROM PlantCorrection t0
1689 Query rollback
1689 Query SET autocommit=1
1691 Query SET autocommit=0
1691 Query DELETE t0 FROM PlantCorrection t0
1691 Query rollback
1691 Query SET autocommit=1
___________________________________________________
SMA Solar Technology AG
Aufsichtsrat: Guenther Cramer (Vorsitzender)
Vorstand: Juergen Dolle, Roland Grebe, Uwe Hertel, Pierre-Pascal Urbon, Marko
Werner
Handelsregister: Amtsgericht Kassel HRB 3972
Sitz der Gesellschaft: 34266 Niestetal
USt-ID-Nr. DE 113 08 59 54
WEEE-Reg.-Nr. DE 95881150
___________________________________________________
