Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Eclipse Projects » EclipseLink » (Dead)lock in v2.4.2 with hsqldb and mysql
(Dead)lock in v2.4.2 with hsqldb and mysql [message #1097878] Fri, 30 August 2013 09:22
ronald Mising name is currently offline ronald Mising name
Messages: 52
Registered: July 2009
Member
Hi,

I'm experiencing deadlock problems using EclipseLInk 2.4.2 and either HSQLDB 2.2.9 or MySql 5.6.4.
Below is the console log for MySQL as created by a JUnit test case. The testcase is a AbstractTransactionalJUnit4SpringContextTests testcase from the Spring 3.2.3.RELEASE.
Before each test (Using @Before) I use the executeSqlScript method to reset the database to a certain test point, which basically deletes all records and inserts new ones.
There's no transaction statement in this sql code.

The repositories use a @org.springframework.transaction.annotation.Transactional on the save method

I'm using these logging properties in the persistence.xml file.

<property name="eclipselink.logging.level.sql" value="ALL"/>
<property name="eclipselink.logging.exceptions" value="true"/>
<property name="eclipselink.logging.timestamp" value="true"/>
<property name="eclipselink.logging.thread" value="true"/>
<property name="eclipselink.logging.session" value="true"/>
<property name="eclipselink.logging.level.thread" value="ALL"/>
<property name="eclipselink.logging.level.session" value="ALL"/>
<property name="eclipselink.logging.level.transaction" value="ALL"/>
<property name="eclipselink.logging.level.cache" value="ALL"/>
<property name="eclipselink.logging.parameters" value="true"/>

The question is: Is there any additional logging that I can use to find out what's locking what and where/why, either in eclipselink or in HSQLDB/MySql?


[EL Finer]: transaction: 2013-08-30 09:56:59.798--UnitOfWork(371623079)--Thread(Thread[main,5,main])--begin unit of work flush
[EL Finer]: transaction: 2013-08-30 09:56:59.799--UnitOfWork(371623079)--Thread(Thread[main,5,main])--end unit of work flush
[EL Fine]: sql: 2013-08-30 09:56:59.802--ClientSession(986643277)--Connection(327823898)--Thread(Thread[main,5,main])--SELECT ID, NAME, COMPANY_ID FROM DOCUMENT
[EL Fine]: sql: 2013-08-30 09:56:59.812--ClientSession(986643277)--Connection(327823898)--Thread(Thread[main,5,main])--SELECT ID, ADDRESS, CITY FROM COMPANY WHERE (ID = ?)
bind => [2]
[EL Fine]: sql: 2013-08-30 09:56:59.819--ClientSession(986643277)--Connection(327823898)--Thread(Thread[main,5,main])--SELECT ID, ADDRESS, CITY FROM COMPANY WHERE (ID = ?)
bind => [1]
[EL Finer]: transaction: 2013-08-30 09:56:59.84--UnitOfWork(371623079)--Thread(Thread[main,5,main])--begin unit of work flush
[EL Finer]: transaction: 2013-08-30 09:56:59.844--UnitOfWork(371623079)--Thread(Thread[main,5,main])--end unit of work flush
[EL Fine]: sql: 2013-08-30 09:56:59.844--ClientSession(986643277)--Connection(327823898)--Thread(Thread[main,5,main])--SELECT ID, EVENTTYPE, INFO, TIMESTAMP, DOCUMENT_ID, PERSON_ID FROM EVENTLOG
[EL Finer]: transaction: 2013-08-30 09:56:59.864--UnitOfWork(371623079)--Thread(Thread[main,5,main])--begin unit of work flush
[EL Finer]: transaction: 2013-08-30 09:56:59.864--UnitOfWork(371623079)--Thread(Thread[main,5,main])--end unit of work flush
[EL Fine]: sql: 2013-08-30 09:56:59.865--ClientSession(986643277)--Connection(327823898)--Thread(Thread[main,5,main])--SELECT ID, EMAIL, HASHCODE, NAME DOCUMENT_ID FROM PERSON
[EL Finer]: transaction: 2013-08-30 09:56:59.873--UnitOfWork(371623079)--Thread(Thread[main,5,main])--begin unit of work flush
[EL Finer]: transaction: 2013-08-30 09:56:59.873--UnitOfWork(371623079)--Thread(Thread[main,5,main])--end unit of work flush
[EL Fine]: sql: 2013-08-30 09:56:59.874--ClientSession(986643277)--Connection(327823898)--Thread(Thread[main,5,main])--SELECT ID, DTYPE, status, DOCUMENT_ID, PERSON_ID FROM AUTHBLOCK
[EL Finer]: transaction: 2013-08-30 09:57:00.617--ClientSession(372085158)--Thread(Thread[qtp323521790-25,5,main])--acquire unit of work: 687571210
[EL Fine]: sql: 2013-08-30 09:57:00.63--ServerSession(430392299)--Connection(446685093)--Thread(Thread[qtp323521790-25,5,main])--SELECT ID, ADDRESS, CITY FROM COMPANY WHERE (USERNAME = ?)
bind => [funbv]
[EL Finer]: transaction: 2013-08-30 09:57:00.637--UnitOfWork(687571210)--Thread(Thread[qtp323521790-25,5,main])--release unit of work
[EL Finer]: transaction: 2013-08-30 09:57:00.648--ClientSession(226370994)--Thread(Thread[qtp323521790-25,5,main])--acquire unit of work: 985272373
[EL Finer]: transaction: 2013-08-30 09:57:00.648--ClientSession(226370994)--Connection(1423757321)--Thread(Thread[qtp323521790-25,5,main])--begin transaction
[EL Finest]: transaction: 2013-08-30 09:57:00.752--UnitOfWork(985272373)--Thread(Thread[qtp323521790-25,5,main])--persist() operation called on: nl.app.model.Document@4e810f0c.
[EL Finest]: transaction: 2013-08-30 09:57:00.753--UnitOfWork(985272373)--Thread(Thread[qtp323521790-25,5,main])--persist() operation called on: nl.app.model.EmailBlock@7b030517.
[EL Finest]: transaction: 2013-08-30 09:57:00.754--UnitOfWork(985272373)--Thread(Thread[qtp323521790-25,5,main])--persist() operation called on: nl.app.model.SmsBlock@3436819.
[EL Finest]: transaction: 2013-08-30 09:57:00.754--UnitOfWork(985272373)--Thread(Thread[qtp323521790-25,5,main])--persist() operation called on: nl.app.model.Person@3e6742fb.
[EL Finer]: transaction: 2013-08-30 09:57:00.755--UnitOfWork(985272373)--Thread(Thread[qtp323521790-25,5,main])--begin unit of work flush
[EL Fine]: sql: 2013-08-30 09:57:00.762--ClientSession(226370994)--Connection(1271841225)--Thread(Thread[qtp323521790-25,5,main])--INSERT INTO DOCUMENT (NAME, COMPANY_ID) VALUES (?, ?)
bind => [name, 3]
[EL Fine]: sql: 2013-08-30 09:57:51.814--ClientSession(226370994)--Thread(Thread[qtp323521790-25,5,main])--SELECT 1
[EL Warning]: 2013-08-30 09:57:51.815--UnitOfWork(985272373)--Thread(Thread[qtp323521790-25,5,main])--Local Exception Stack:
Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
Error Code: 1205
Call: INSERT INTO DOCUMENT (NAME, COMPANY_ID) VALUES (?, ?)
bind => [name, 3]
Query: InsertObjectQuery(nl.app.model.Document@4e810f0c)
at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:324)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:851)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:913)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:594)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:537)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1805)
at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:286)
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:207)
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:193)
at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.insertObject(DatasourceCallQueryMechanism.java:342)
at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:162)
at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:177)
at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:471)
at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80)
at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90)
at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:286)
at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58)
at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:852)
at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:751)
at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108)
at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2879)
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1607)
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1589)
at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1540)
at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:226)
at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsForClassWithChangeSet(CommitManager.java:193)
at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:138)
at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:3945)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1423)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.commitToDatabase(RepeatableWriteUnitOfWork.java:638)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkImpl.java:1569)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.writeChanges(RepeatableWriteUnitOfWork.java:445)
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:798)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:241)
at com.sun.proxy.$Proxy76.flush(Unknown Source)
at nl.app.repository.impl.DocumentRepositoryImpl.save(DocumentRepositoryImpl.java:71)


Ronald
Previous Topic:[resolved] Problem with Inserting/Updating in DescriptorEventListener callback methods
Next Topic:JPA 2.1 load/fetch graph without effect
Goto Forum:
  


Current Time: Thu Sep 18 21:52:30 GMT 2014

Powered by FUDForum. Page generated in 0.08827 seconds
.:: Contact :: Home ::.

Powered by: FUDforum 3.0.2.
Copyright ©2001-2010 FUDforum Bulletin Board Software