openjpa-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Michael Pflueger <Michael.Pflue...@sma.de>
Subject Re: concurrent thread exception plus deadlock on delete statement using slice
Date Thu, 09 Jun 2011 14:19:37 GMT
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
___________________________________________________


Mime
View raw message