| Summary: | Delete fails with DB constraint violation due to an internal update | ||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | z_Archived | Reporter: | Lloyd Fernandes <lloyd> | ||||||||||||
| Component: | Eclipselink | Assignee: | Nobody - feel free to take it <nobody> | ||||||||||||
| Status: | CLOSED FIXED | QA Contact: | |||||||||||||
| Severity: | normal | ||||||||||||||
| Priority: | P2 | CC: | dsaisuresh, eclipselink.orm-inbox, ikari.shinji.eva, jamesssss, lloyd, michael, tom.ware | ||||||||||||
| Version: | unspecified | ||||||||||||||
| Target Milestone: | --- | ||||||||||||||
| Hardware: | PC | ||||||||||||||
| OS: | Windows Vista | ||||||||||||||
| Whiteboard: | submitted_patch | ||||||||||||||
| Attachments: |
|
||||||||||||||
|
Description
Lloyd Fernandes
Can you please provde some sample entities and the code that causes the issue. The actual call is org.eclipse.persistence.internal.queries.updateForeignKeyFieldBeforeDelete() the stack trace is at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:324) at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:840) at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:906) at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:592) at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:535) at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1702) at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:234) 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.updateObject(DatasourceCallQueryMechanism.java:750) at org.eclipse.persistence.internal.queries.StatementQueryMechanism.updateObject(StatementQueryMechanism.java:432) at org.eclipse.persistence.internal.queries.CallQueryMechanism.updateForeignKeyFieldBeforeDelete(CallQueryMechanism.java:393) at org.eclipse.persistence.queries.DeleteObjectQuery.executeDatabaseQuery(DeleteObjectQuery.java:147) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:807) at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:709) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) at org.eclipse.persistence.queries.DeleteObjectQuery.executeInUnitOfWorkObjectLevelModifyQuery(DeleteObjectQuery.java:115) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2840) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1501) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1483) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1443) at org.eclipse.persistence.queries.DeleteObjectQuery.executeDatabaseQuery(DeleteObjectQuery.java:190) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:807) at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:709) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) at org.eclipse.persistence.queries.DeleteObjectQuery.executeInUnitOfWorkObjectLevelModifyQuery(DeleteObjectQuery.java:115) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2840) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1501) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1483) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1443) at org.eclipse.persistence.internal.sessions.CommitManager.deleteAllObjects(CommitManager.java:334) at org.eclipse.persistence.internal.sessions.CommitManager.deleteAllObjects(CommitManager.java:288) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1407) at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.commitToDatabase(RepeatableWriteUnitOfWork.java:627) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithChangeSet(UnitOfWorkImpl.java:1490) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.issueSQLbeforeCompletion(UnitOfWorkImpl.java:3112) at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.issueSQLbeforeCompletion(RepeatableWriteUnitOfWork.java:337) at org.eclipse.persistence.transaction.AbstractSynchronizationListener.beforeCompletion(AbstractSynchronizationListener.java:157) at org.eclipse.persistence.transaction.JTASynchronizationListener.beforeCompletion(JTASynchronizationListener.java:68) at org.apache.geronimo.transaction.manager.TransactionImpl.beforeCompletion(TransactionImpl.java:514) at org.apache.geronimo.transaction.manager.TransactionImpl.beforeCompletion(TransactionImpl.java:498) at org.apache.geronimo.transaction.manager.TransactionImpl.beforePrepare(TransactionImpl.java:400) at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:257) at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:245) Changing to enhancement I dont understand why this is an enhancement. Core JPA permits delete of object without cascade delete of ALL relationships nor does it require that non-cascaded deletes be nullable. Perhaps I do not understand the issue. Can you please provide either a test case, or exact details of the mappings, the contents of the DB, the code that you are running that shows the problem and the SQL that is logged (persitence unit property eclipselink.logging.level=FINER will get you the SQL) Unfortunately, I am not permitted to provide the code I am working on. If the following does not help then I will create a complete test case to address resolve the issue I think the best way to do this is to modify existing tests ( http://dev.eclipse.org/svnroot/rt/org.eclipse.persistence/trunk/jpa/eclipselink.jpa.test/src/org/eclipse/persistence/testing/models/jpa/cascadedeletes/ ) modify MachineState.java to add a new attribute and related getter/setter @ManyToOne(optional=false) ThreadInfo mainThread modify model to include non-nullable mainThread column and appropriate foreign key in test http://dev.eclipse.org/svnroot/rt/org.eclipse.persistence/trunk/jpa/eclipselink.jpa.test/src/org/eclipse/persistence/testing/tests/jpa/cascadedeletes/CascadeDeletesJUnitTestSuite.java after the line ms.getThreads().add(new ThreadInfo(1, "main")); add ms.setMainThread(ms.GetThreads().get(0))); I have attached the stack trace the call is org.eclipse.persistence.internal.queries.CallQueryMechanism. Thread [main] (Suspended) ExpressionQueryMechanism(CallQueryMechanism).updateForeignKeyFieldBeforeDelete() line: 380 DeleteObjectQuery.executeDatabaseQuery() line: 147 DeleteObjectQuery(DatabaseQuery).execute(AbstractSession, AbstractRecord) line: 807 DeleteObjectQuery(DatabaseQuery).executeInUnitOfWork(UnitOfWorkImpl, AbstractRecord) line: 709 DeleteObjectQuery(ObjectLevelModifyQuery).executeInUnitOfWorkObjectLevelModifyQuery(UnitOfWorkImpl, AbstractRecord) line: 108 DeleteObjectQuery.executeInUnitOfWorkObjectLevelModifyQuery(UnitOfWorkImpl, AbstractRecord) line: 115 DeleteObjectQuery(ObjectLevelModifyQuery).executeInUnitOfWork(UnitOfWorkImpl, AbstractRecord) line: 85 RepeatableWriteUnitOfWork(UnitOfWorkImpl).internalExecuteQuery(DatabaseQuery, AbstractRecord) line: 2840 RepeatableWriteUnitOfWork(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord, int) line: 1501 RepeatableWriteUnitOfWork(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord) line: 1483 RepeatableWriteUnitOfWork(AbstractSession).executeQuery(DatabaseQuery) line: 1443 DeleteObjectQuery.executeDatabaseQuery() line: 190 DeleteObjectQuery(DatabaseQuery).execute(AbstractSession, AbstractRecord) line: 807 DeleteObjectQuery(DatabaseQuery).executeInUnitOfWork(UnitOfWorkImpl, AbstractRecord) line: 709 DeleteObjectQuery(ObjectLevelModifyQuery).executeInUnitOfWorkObjectLevelModifyQuery(UnitOfWorkImpl, AbstractRecord) line: 108 DeleteObjectQuery.executeInUnitOfWorkObjectLevelModifyQuery(UnitOfWorkImpl, AbstractRecord) line: 115 DeleteObjectQuery(ObjectLevelModifyQuery).executeInUnitOfWork(UnitOfWorkImpl, AbstractRecord) line: 85 RepeatableWriteUnitOfWork(UnitOfWorkImpl).internalExecuteQuery(DatabaseQuery, AbstractRecord) line: 2840 RepeatableWriteUnitOfWork(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord, int) line: 1501 RepeatableWriteUnitOfWork(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord) line: 1483 RepeatableWriteUnitOfWork(AbstractSession).executeQuery(DatabaseQuery) line: 1443 CommitManager.deleteAllObjects(Class, List, AbstractSession) line: 334 CommitManager.deleteAllObjects(List) line: 288 RepeatableWriteUnitOfWork(UnitOfWorkImpl).commitToDatabase(boolean) line: 1407 RepeatableWriteUnitOfWork.commitToDatabase(boolean) line: 627 RepeatableWriteUnitOfWork(UnitOfWorkImpl).commitToDatabaseWithChangeSet(boolean) line: 1490 RepeatableWriteUnitOfWork(UnitOfWorkImpl).issueSQLbeforeCompletion(boolean) line: 3112 RepeatableWriteUnitOfWork.issueSQLbeforeCompletion() line: 337 JTASynchronizationListener(AbstractSynchronizationListener).beforeCompletion() line: 157 JTASynchronizationListener.beforeCompletion() line: 68 TransactionImpl.beforeCompletion(List) line: 514 TransactionImpl.beforeCompletion() line: 498 TransactionImpl.beforePrepare() line: 400 TransactionImpl.commit() line: 257 If you look at the comments on the call org.eclipse.persistence.internal.queries.CallQueryMechanism.updateForeignKeyFieldBeforeDelete() it should clarify the issue It's not clear to me what our other options are. Here's the SQL: [EL Fine]: 2011-04-28 14:08:07.381--ClientSession(5444480)--Connection(28846567)--Thread(Thread[main,5,main])--UPDATE MACHINESTATE SET MAINTHREAD_ID = ? WHERE (ID = ?) bind => [null, 1] [EL Fine]: 2011-04-28 14:08:07.381--ClientSession(5444480)--Connection(28846567)--Thread(Thread[main,5,main])--DELETE FROM THREADINFO WHERE (ID = ?) bind => [1] [EL Fine]: 2011-04-28 14:08:07.396--ClientSession(5444480)--Connection(28846567)--Thread(Thread[main,5,main])--DELETE FROM MACHINESTATE WHERE (ID = ?) The issue I see is that if there is an Foreign Key constraint from MAINTHREAD_ID to THREAD we need to null out MAINTHREAD_ID to be able to delete THREADINFO It might be possible for us to build an enhancement that allowed you to tell us there was not FK Constraint if there was enough community support. Am I missing something? Incidentally... From the JPA Specification section 2.9: "The relationship modeling annotation constrains the use of the cascade=REMOVE specification. The cascade=REMOVE specification should only be applied to associations that are specified as One- ToOne or OneToMany. Applications that apply cascade=REMOVE to other associations are not portable." you should be able to detect that this is an unidirectional and 1. not do the update statement 2. change the delete order to DELETE FROM MACHINESTATE WHERE (ID = ?) DELETE FROM THREADINFO WHERE (ID = ?) Agreed... but due to the above Spec quote I still believe this is an enhancement. I disagree with the reference to the spec. The issue is happenning with an attribute that does NOT have the cascade.REMOVE Come to think of it the delete order should not matter. Most Databases(smart ones atleast) would not give a constraint error if both the deletes were within a single transaction Unforutnately, we have to support all databases, not just smart ones :-) I'll move it back to being a bug for now. As with our other bugs, community, please vote for it if you consider it important. Workaround is stated above: Make the FK field nullable. This bug requires a very valid database constraint (non-nullable) to be removed in order for the product to work. As I have stated this causes potential business data integrity concerns. I therefore request that this be elevated to Major/Critical in 2.3 I think the simple and correct fix would be to update the class org.eclipse.persistence.mappings.ManyToOneMapping to override the method addPreDeleteMapping() to do nothing An addtional workaround: - Map mainThread as a ManyToMany instead (we will generate the commit order you are looking for) ManyToMany would violate OOP as I would need a list/collection. instead I have only an element Sorry for the typo... the workaround is to map your unidirectional OneToMany as a ManyToMany, not the unidirectional ManyToOne It may work in the test case because it is a bidirectional. I do not have a bidirectional only unidirectional. Both mappings in the test case are unidirectional. It is bidirectional from an OOP perspective. In my case I do not have bidirectional as the referenced class (Thread in your case) does not have a pointer to the referencing class(Machine in your case). In other words I am pointing to reference data not dependent/child data. Please give an example that descibes the difference.
In the below what do I change to ManyToMany
class A{
int aId;
@ManyToOne
B ref;
}
class B{
int bId;
String desc;
}
well, that's a different use case entirely than the one in the test case. The one in the test case deletes the mainThread as a result of the cascade delete on the threads list and the OneToMany is integral in our commit order calculation. What code do you run to delete? I updated the test case to be more reflective of what you are describing. Here are the classes:
@Entity
public class MachineState {
@Id
private long id;
@ManyToOne(optional=false)
ThreadInfo mainThread;
...
@Entity
public class ThreadInfo {
@Id
private long id;
private String name;
...
On the latest build, I run this code:
beginTransaction(em);
ms = em.find(MachineState.class, 1L);
em.remove(ms.getMainThread());
em.remove(ms);
commitTransaction(em);
And get this SQL:
(11379670)--Thread(Thread[main,5,main])--DELETE FROM MACHINESTATE WHERE (ID = ?)
bind => [1]
(11379670)--Thread(Thread[main,5,main])--DELETE FROM THREADINFO WHERE (ID = ?)
I cannot reproduce your issue.
Please try the latest build. If it does not solve your problem, I think we'll need more details about what is going on, ideally a small recreation.
FYI: The other objects related to class A and class B and the other mappings in class A and class B will affect the commit order and may be the reason we have to do the commits in a different order. The original bug was about the null constraint (caused by an update during delete). I donot want this to turn inot a commit order discussion until after the update has been resolved. Are you saying you have been able to get past the update issue Commit order is integral to whether we have to run the update or not. If we delete one object first, we do not need to run the update, if we delete the other object first we need the upate. I am saying that I do not see the update in the test case with the mappings I have described. I do not see any differences between the test case I have described and the one you have described. If you need further investigation of this issue, please provide a recreatable test case that demonstrates the issue. Can you send me the test code you have, including the foreign key constraints setup and I will expand on it. It is the same code you refer to earlier in this bug.
All you need to do is add the code you suggested for mainThread and remove the "threads" variable. (ThreadInfo is unchanged)
@Entity
public class MachineState {
@Id
private long id;
@ManyToOne(optional=false)
ThreadInfo mainThread;
public ThreadInfo getMainThread() {
return mainThread;
}
public void setMainThread(ThreadInfo mainThread) {
this.mainThread = mainThread;
}
public MachineState() {
}
public long getId() {
return id;
}
public void setId(long id) {
this.id = id;
}
}
The test now looks like this:
public void testRemoveMachineState(){
EntityManager em = createEntityManager("cascade-deletes");
beginTransaction(em);
MachineState ms = new MachineState();
ms.setId(1);
ThreadInfo info = new ThreadInfo(1, "main");
ms.setMainThread(info);
em.persist(info);
em.persist(ms);
commitTransaction(em);
beginTransaction(em);
ms = em.find(MachineState.class, 1L);
em.remove(ms.getMainThread());
em.remove(ms);
commitTransaction(em);
}
can you send me the FK and NOT NULL constraint code. (PS: I normally do not do it thru java code. I use db scripts) You can use persistence unit properties to generate DDL
<property name="eclipselink.ddl-generation" value="drop-and-create-tables"/>
Check the javadoc for the PersistenceUnitProperties class for more options
Just a note, for a normal ManyToOne relationship, where both objects were deleted, EclipseLink will just issue two deletes, first delete the source, then the target. The only issue occurs when you have a cycle in your relationships, such as A has a ManyToOne to B and B has a ManyToOne to A. It could be a more complex cycle as well. This make deletion more difficult. Before 2.3, we would delete A first, causing a foreign key constraint error. In 2.3 this was fixed to first update A and set the foreign key value to null, then delete B, then A. If there is no cycle, then there is no issue. The update only occurs only if there is a cycle. For a cycle, you can control which side of the relationship is updated using the API addConstraintDependency() on ClassDescriptor using a DescriptorCustomizer. Or remove the cycle in your object model, or remove (or defer) the not-null constraint. You can also control the order of deletion using flush(), just remove the first object, then call flush(), then remove the second. Some database do support deferring constraints, but it is not the default on any database, and not commonly done. If you want to defer the foreign key constraint, then can't you also defer the not-null constraint? James, Appreciate your feedback. 1. I will try and work my issue by using a DescriptorCustomizer. If you have a specific example I would appreciate it. 2. I would recommend that even in a cycle case, any attribute with an annotation of optional=false (i.e ManyToOne(Optional=false)) should NOT be forced to NULL internally. Just to clarify my thoughts 1. This should be a bug to be fixed ASAP in 2.3 2. The fix should be NOT do an internal update to NULL when the attribute has an 'optional=false' annotation value assigned to it.(i.e ManyToOne(Optional=false)) Based on the current information we have, there is no bug. 1. I cannot recreate the issue with a single ManyToOne, if you can provide a recreation with a single ManyToOne we would reconsider 2. In a tool that is designed to work on multiple databases, not all of which support ignoring the constraint until transaction commit time, we have no choice but to do the update for a set of relationships with a cycle. We need to deal with the possibiliity of a foreign key constraint and as mentioned, assuming that the database will figure out we are deleting both rows is NOT an option. Based on the above, can you provide a recreation that shows a bug? I was hoping james's explaination will help you recreate the issue or refere to the issue for which the 'update' was put. I see now that I have to create a specific example for you. I will do that and send it to you. Again, I need to clarify the fundamental issue here. AN IMPLEMENTATION SHOULD NOT MODIFY THE UNDERLYING BUSINESS DATA UNDER ANY CIRCUMSTANCES. It should be the job of the data modeler, object modeler and business programmer to work out those issues. If there object model results in constraint issues, then the business programmer should do an explicit setting of null or do the delete thru a stored procedure. Also note that in my case I have database update triggers that mess things up when I set the field to NULL I want to be clear hear. The scenario James mentions is the "cycle" scenario (described in #2 above). In that scenario our only real option is to update the relationship field to null. Doing anything else will cause foreign key constraint errors because the cycle will mean there are foreign keys pointing both ways. It is true that some databases support deferring the foreign key constraint checks until transaction commit time, but this is neither commonly used nor available in all database systems. As a result, a change that took advantage of that feature would be considered an enhancement/feature rather than a bug fix. It would also have to deal with many other types of mappings and therefore be potentially a fairly big feature. If you have a recreation, for us to consider this a bug, it will have to be a non-cycle scenario or, at least, a scenario where there are not potential foreign keys that are effectively on both sides of the relationship. Assuming your scenario is a cycle, you have several potential workarounds. 1. If there are relationships in your model that can be set to null, use our constraint dependency API to control which objects get deleted first and avoid the unwanted updates. 2. Don't map the problematic mapping and, instead, use a JPA query to retreive the data 3. Alter your triggers to account for the possible null and change your database to defer the null constraint check to transaction commit time 4. Alter your triggers and allow null in your database column I am currently leaving this bug open because you have discovered one non-cycle scenario where we have an issue. That scenario with the unidirectional 1-M and the unidirection M-1 pointing to the same object. (The MachineState -> ThreadInfo model you initially suggested) Having said that, based on your comments, I do not think that fixing that issue will help you. It is, however possible, that there other scenarios that might be a problem - I just want to caution you about what is possible if your issue turns out to be the result of a cycle. Please feel free to file, and vote for an enhancement request that asks us to allow settings that tell us you will defer foreign key constraints in the database and asks us to avoid updates in that case. One other workaround - use Native SQL or a Stored Procedure call to do the delete. On the cycle case I disagree that the only option is to set null. The other options are 1. The option you had before 2.3 worked as well. In that case the data modeler/object modeler would decide on how to deal with the business data (relationship). 2. You could honor the the option=false and NOT do the setting NULL for those specific attributes. 3. The change made in 2.3 should have been done as an enhancement (annotation or DescriptorCustomizer) with the developer having to explicitly permit the data to be set to null In my opinion it is unacceptable for an implementation to make implicit decisions on values of business data I think you have this backwards. Whatever you did in 2.3 to fix the cycle issue is an enhancement and this is a bug. I am working on test case and will get back to you on that. Created attachment 194578 [details]
Classes for reproducing bug
I have attached a file with the classes. The log below shows aId being set to NULL (in addition to bId). There is no cycle relationship between SourceClass and TargetA class. [EL Finer]: 2011-05-03 09:32:47.566--Thread(Thread[main,5,main])--fixUNC: before fixing: url = file:/C:/FDM/projects/eclipselink/target/classes/, authority = , file = /C:/FDM/projects/eclipselink/target/classes/ (There is no English translation for this message.) [EL Finer]: 2011-05-03 09:32:47.566--Thread(Thread[main,5,main])--fixUNC: after fixing: url = file:/C:/FDM/projects/eclipselink/target/classes/, authority = null, file = /C:/FDM/projects/eclipselink/target/classes/ (There is no English translation for this message.) [EL Finer]: 2011-05-03 09:32:47.566--Thread(Thread[main,5,main])--fixUNC: before fixing: url = file:/C:/FDM/projects/SECCore/target/classes/, authority = , file = /C:/FDM/projects/SECCore/target/classes/ (There is no English translation for this message.) [EL Finer]: 2011-05-03 09:32:47.566--Thread(Thread[main,5,main])--fixUNC: after fixing: url = file:/C:/FDM/projects/SECCore/target/classes/, authority = null, file = /C:/FDM/projects/SECCore/target/classes/ (There is no English translation for this message.) [EL Finest]: 2011-05-03 09:32:47.645--ServerSession(9040869)--Thread(Thread[main,5,main])--Begin predeploying Persistence Unit EclipselinkTest; session file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest; state Predeployed; factoryCount 1 [EL Finest]: 2011-05-03 09:32:47.645--ServerSession(9040869)--Thread(Thread[main,5,main])--End predeploying Persistence Unit EclipselinkTest; session file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest; state Predeployed; factoryCount 2 [EL Finest]: 2011-05-03 09:32:47.645--ServerSession(9040869)--Thread(Thread[main,5,main])--Begin deploying Persistence Unit EclipselinkTest; session file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest; state Predeployed; factoryCount 2 [EL Finer]: 2011-05-03 09:32:47.692--ServerSession(9040869)--Thread(Thread[main,5,main])--Could not initialize Validation Factory. Encountered following exception: javax.validation.ValidationException: Could not create Configuration. [EL Finest]: 2011-05-03 09:32:47.692--ServerSession(9040869)--Thread(Thread[main,5,main])--property=eclipselink.target-server; value=org.apache.openejb.eclipselink.JTATransactionController [EL Finest]: 2011-05-03 09:32:47.692--ServerSession(9040869)--Thread(Thread[main,5,main])--property=eclipselink.logging.level; value=FINEST; translated value=FINEST [EL Finest]: 2011-05-03 09:32:47.692--ServerSession(9040869)--Thread(Thread[main,5,main])--property=eclipselink.logging.level; value=FINEST; translated value=FINEST [EL Finest]: 2011-05-03 09:32:47.692--ServerSession(9040869)--Thread(Thread[main,5,main])--property=eclipselink.target-database; value=SQLServer; translated value=org.eclipse.persistence.platform.database.SQLServerPlatform [EL Info]: 2011-05-03 09:32:47.739--ServerSession(9040869)--Thread(Thread[main,5,main])--EclipseLink, version: Eclipse Persistence Services - 2.3.0.v20110329-r9183 [EL Config]: 2011-05-03 09:32:47.848--ServerSession(9040869)--Connection(1042529)--Thread(Thread[main,5,main])--connecting(DatabaseLogin( platform=>SQLServerPlatform user name=> "" connector=>JNDIConnector datasource name=>null )) [EL Config]: 2011-05-03 09:32:48.051--ServerSession(9040869)--Connection(33072381)--Thread(Thread[main,5,main])--Connected: jdbc:jtds:sqlserver://localhost:1433/FDM_LOCAL User: webFDM Database: Microsoft SQL Server Version: 10.50.1600 Driver: jTDS Type 4 JDBC Driver for MS SQL Server and Sybase Version: 1.2.4 [EL Finest]: 2011-05-03 09:32:48.051--ServerSession(9040869)--Connection(18351099)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.051--ServerSession(9040869)--Connection(18351099)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Config]: 2011-05-03 09:32:48.051--ServerSession(9040869)--Connection(28149392)--Thread(Thread[main,5,main])--connecting(DatabaseLogin( platform=>SQLServerPlatform user name=> "" connector=>JNDIConnector datasource name=>null )) [EL Config]: 2011-05-03 09:32:48.097--ServerSession(9040869)--Connection(24671125)--Thread(Thread[main,5,main])--Connected: jdbc:jtds:sqlserver://localhost:1433/FDM_LOCAL User: webFDM Database: Microsoft SQL Server Version: 10.50.1600 Driver: jTDS Type 4 JDBC Driver for MS SQL Server and Sybase Version: 1.2.4 [EL Info]: 2011-05-03 09:32:48.207--ServerSession(9040869)--Thread(Thread[main,5,main])--file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest login successful [EL Finest]: 2011-05-03 09:32:48.253--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="ALTER TABLE tblTestSource DROP CONSTRAINT FK_tblTestSource_aId") [EL Finest]: 2011-05-03 09:32:48.253--ServerSession(9040869)--Connection(20194674)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.253--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.253--ServerSession(9040869)--Connection(8822415)--Thread(Thread[main,5,main])--ALTER TABLE tblTestSource DROP CONSTRAINT FK_tblTestSource_aId [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Connection(20194674)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="ALTER TABLE tblTestSource DROP CONSTRAINT FK_tblTestSource_bId") [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Connection(11373565)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Connection(29477340)--Thread(Thread[main,5,main])--ALTER TABLE tblTestSource DROP CONSTRAINT FK_tblTestSource_bId [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Connection(11373565)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="ALTER TABLE tblTestTargetB DROP CONSTRAINT tblTestTargetBsourceId") [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Connection(28007789)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.331--ServerSession(9040869)--Connection(25340734)--Thread(Thread[main,5,main])--ALTER TABLE tblTestTargetB DROP CONSTRAINT tblTestTargetBsourceId [EL Finest]: 2011-05-03 09:32:48.347--ServerSession(9040869)--Connection(28007789)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.347--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="DROP TABLE tblTestSource") [EL Finest]: 2011-05-03 09:32:48.347--ServerSession(9040869)--Connection(30730860)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.347--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.347--ServerSession(9040869)--Connection(23761097)--Thread(Thread[main,5,main])--DROP TABLE tblTestSource [EL Finest]: 2011-05-03 09:32:48.394--ServerSession(9040869)--Connection(30730860)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.394--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="CREATE TABLE tblTestSource (sourceId VARCHAR(255) NOT NULL, DESCRIPTION VARCHAR(255) NULL, aId VARCHAR(255) NULL, bId VARCHAR(255) NULL, PRIMARY KEY (sourceId))") [EL Finest]: 2011-05-03 09:32:48.394--ServerSession(9040869)--Connection(19697685)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.394--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.394--ServerSession(9040869)--Connection(10967412)--Thread(Thread[main,5,main])--CREATE TABLE tblTestSource (sourceId VARCHAR(255) NOT NULL, DESCRIPTION VARCHAR(255) NULL, aId VARCHAR(255) NULL, bId VARCHAR(255) NULL, PRIMARY KEY (sourceId)) [EL Finest]: 2011-05-03 09:32:48.503--ServerSession(9040869)--Connection(19697685)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.503--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="DROP TABLE tblTestTargetB") [EL Finest]: 2011-05-03 09:32:48.503--ServerSession(9040869)--Connection(9146717)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.503--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.503--ServerSession(9040869)--Connection(16020223)--Thread(Thread[main,5,main])--DROP TABLE tblTestTargetB [EL Finest]: 2011-05-03 09:32:48.503--ServerSession(9040869)--Connection(9146717)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="CREATE TABLE tblTestTargetB (bId VARCHAR(255) NOT NULL, DESCRIPTION VARCHAR(255) NULL, sourceId VARCHAR(255) NULL, PRIMARY KEY (bId))") [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Connection(14870151)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Connection(9232618)--Thread(Thread[main,5,main])--CREATE TABLE tblTestTargetB (bId VARCHAR(255) NOT NULL, DESCRIPTION VARCHAR(255) NULL, sourceId VARCHAR(255) NULL, PRIMARY KEY (bId)) [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Connection(14870151)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="DROP TABLE tblTestTargetA") [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Connection(33523907)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.519--ServerSession(9040869)--Connection(23853518)--Thread(Thread[main,5,main])--DROP TABLE tblTestTargetA [EL Finest]: 2011-05-03 09:32:48.628--ServerSession(9040869)--Connection(33523907)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.628--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="CREATE TABLE tblTestTargetA (aId VARCHAR(255) NOT NULL, DESCRIPTION VARCHAR(255) NULL, PRIMARY KEY (aId))") [EL Finest]: 2011-05-03 09:32:48.628--ServerSession(9040869)--Connection(9733797)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.628--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.628--ServerSession(9040869)--Connection(18071830)--Thread(Thread[main,5,main])--CREATE TABLE tblTestTargetA (aId VARCHAR(255) NOT NULL, DESCRIPTION VARCHAR(255) NULL, PRIMARY KEY (aId)) [EL Finest]: 2011-05-03 09:32:48.66--ServerSession(9040869)--Connection(9733797)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.66--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="ALTER TABLE tblTestSource ADD CONSTRAINT FK_tblTestSource_aId FOREIGN KEY (aId) REFERENCES tblTestTargetA (aId)") [EL Finest]: 2011-05-03 09:32:48.66--ServerSession(9040869)--Connection(18606925)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.66--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.66--ServerSession(9040869)--Connection(32841014)--Thread(Thread[main,5,main])--ALTER TABLE tblTestSource ADD CONSTRAINT FK_tblTestSource_aId FOREIGN KEY (aId) REFERENCES tblTestTargetA (aId) [EL Finest]: 2011-05-03 09:32:48.676--ServerSession(9040869)--Connection(18606925)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.676--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="ALTER TABLE tblTestSource ADD CONSTRAINT FK_tblTestSource_bId FOREIGN KEY (bId) REFERENCES tblTestTargetB (bId)") [EL Finest]: 2011-05-03 09:32:48.676--ServerSession(9040869)--Connection(30516062)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.676--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.676--ServerSession(9040869)--Connection(12728642)--Thread(Thread[main,5,main])--ALTER TABLE tblTestSource ADD CONSTRAINT FK_tblTestSource_bId FOREIGN KEY (bId) REFERENCES tblTestTargetB (bId) [EL Finest]: 2011-05-03 09:32:48.769--ServerSession(9040869)--Connection(30516062)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.785--ServerSession(9040869)--Thread(Thread[main,5,main])--Execute query DataModifyQuery(sql="ALTER TABLE tblTestTargetB ADD CONSTRAINT tblTestTargetBsourceId FOREIGN KEY (sourceId) REFERENCES tblTestSource (sourceId)") [EL Finest]: 2011-05-03 09:32:48.785--ServerSession(9040869)--Connection(2293257)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:48.785--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.785--ServerSession(9040869)--Connection(22293510)--Thread(Thread[main,5,main])--ALTER TABLE tblTestTargetB ADD CONSTRAINT tblTestTargetBsourceId FOREIGN KEY (sourceId) REFERENCES tblTestSource (sourceId) [EL Finest]: 2011-05-03 09:32:48.785--ServerSession(9040869)--Connection(2293257)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finer]: 2011-05-03 09:32:48.832--ServerSession(9040869)--Thread(Thread[main,5,main])--Canonical Metamodel class [eclipselink.Source_] not found during initialization. [EL Finer]: 2011-05-03 09:32:48.832--ServerSession(9040869)--Thread(Thread[main,5,main])--Canonical Metamodel class [eclipselink.TargetA_] not found during initialization. [EL Finer]: 2011-05-03 09:32:48.847--ServerSession(9040869)--Thread(Thread[main,5,main])--Canonical Metamodel class [eclipselink.TargetB_] not found during initialization. [EL Finest]: 2011-05-03 09:32:48.847--ServerSession(9040869)--Thread(Thread[main,5,main])--End deploying Persistence Unit EclipselinkTest; session file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest; state Deployed; factoryCount 2 [EL Finer]: 2011-05-03 09:32:48.894--ServerSession(9040869)--Thread(Thread[main,5,main])--client acquired: 13350418 [EL Finer]: 2011-05-03 09:32:48.941--UnitOfWork(28398471)--Thread(Thread[main,5,main])--TX binding to tx mgr, status=STATUS_ACTIVE [EL Finer]: 2011-05-03 09:32:48.941--ClientSession(13350418)--Thread(Thread[main,5,main])--acquire unit of work: 28398471 [EL Finest]: 2011-05-03 09:32:48.941--UnitOfWork(28398471)--Thread(Thread[main,5,main])--persist() operation called on: eclipselink.TargetA@e2da7a. [EL Finest]: 2011-05-03 09:32:48.941--UnitOfWork(28398471)--Thread(Thread[main,5,main])--persist() operation called on: eclipselink.Source@e02fc4. [EL Finest]: 2011-05-03 09:32:48.941--UnitOfWork(28398471)--Thread(Thread[main,5,main])--persist() operation called on: eclipselink.TargetB@600a08. [EL Finer]: 2011-05-03 09:32:48.941--UnitOfWork(28398471)--Thread(Thread[main,5,main])--TX beforeCompletion callback, status=STATUS_ACTIVE [EL Finer]: 2011-05-03 09:32:48.941--UnitOfWork(28398471)--Thread(Thread[main,5,main])--begin unit of work commit [EL Finer]: 2011-05-03 09:32:48.956--ClientSession(13350418)--Thread(Thread[main,5,main])--TX beginTransaction, status=STATUS_ACTIVE [EL Finest]: 2011-05-03 09:32:48.956--UnitOfWork(28398471)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(eclipselink.TargetA@e2da7a) [EL Finest]: 2011-05-03 09:32:48.956--ServerSession(9040869)--Connection(20184669)--Thread(Thread[main,5,main])--Connection acquired from connection pool [default]. [EL Finest]: 2011-05-03 09:32:48.956--ClientSession(13350418)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:48.956--ClientSession(13350418)--Connection(8427409)--Thread(Thread[main,5,main])--INSERT INTO tblTestTargetA (aId, DESCRIPTION) VALUES (?, ?) bind => [1, Target Class A] [EL Finest]: 2011-05-03 09:32:48.972--UnitOfWork(28398471)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(eclipselink.TargetB@600a08) [EL Finest]: 2011-05-03 09:32:48.972--UnitOfWork(28398471)--Thread(Thread[main,5,main])--Execute query WriteObjectQuery(eclipselink.Source@e02fc4) [EL Finest]: 2011-05-03 09:32:48.972--UnitOfWork(28398471)--Thread(Thread[main,5,main])--Execute query WriteObjectQuery(eclipselink.TargetB@600a08) [EL Fine]: 2011-05-03 09:32:48.972--ClientSession(13350418)--Connection(8427409)--Thread(Thread[main,5,main])--INSERT INTO tblTestTargetB (bId, DESCRIPTION, sourceId) VALUES (?, ?, ?) bind => [1, Target Class B, null] [EL Fine]: 2011-05-03 09:32:48.972--ClientSession(13350418)--Connection(8427409)--Thread(Thread[main,5,main])--INSERT INTO tblTestSource (sourceId, DESCRIPTION, aId, bId) VALUES (?, ?, ?, ?) bind => [1, Source Class, 1, 1] [EL Fine]: 2011-05-03 09:32:48.988--ClientSession(13350418)--Connection(8427409)--Thread(Thread[main,5,main])--UPDATE tblTestTargetB SET sourceId = ? WHERE (bId = ?) bind => [1, 1] [EL Finest]: 2011-05-03 09:32:49.596--ServerSession(9040869)--Connection(20184669)--Thread(Thread[main,5,main])--Connection released to connection pool [default]. [EL Finer]: 2011-05-03 09:32:49.596--UnitOfWork(28398471)--Thread(Thread[main,5,main])--TX afterCompletion callback, status=COMMITTED [EL Finer]: 2011-05-03 09:32:49.596--UnitOfWork(28398471)--Thread(Thread[main,5,main])--end unit of work commit [EL Finer]: 2011-05-03 09:32:49.596--UnitOfWork(28398471)--Thread(Thread[main,5,main])--initialize identitymaps [EL Finer]: 2011-05-03 09:32:49.596--ClientSession(13350418)--Thread(Thread[main,5,main])--initialize identitymaps [EL Finer]: 2011-05-03 09:32:49.596--UnitOfWork(28398471)--Thread(Thread[main,5,main])--release unit of work [EL Finer]: 2011-05-03 09:32:49.596--ClientSession(13350418)--Thread(Thread[main,5,main])--client released [EL Finer]: 2011-05-03 09:32:49.596--ServerSession(9040869)--Thread(Thread[main,5,main])--client acquired: 23392283 [EL Finer]: 2011-05-03 09:32:49.596--UnitOfWork(30390483)--Thread(Thread[main,5,main])--TX binding to tx mgr, status=STATUS_ACTIVE [EL Finer]: 2011-05-03 09:32:49.596--ClientSession(23392283)--Thread(Thread[main,5,main])--acquire unit of work: 30390483 [EL Finest]: 2011-05-03 09:32:49.596--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Merge clone with references eclipselink.Source@e02fc4 [EL Finest]: 2011-05-03 09:32:49.612--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query ReadObjectQuery(referenceClass=Source ) [EL Finest]: 2011-05-03 09:32:49.627--ServerSession(9040869)--Connection(26338149)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:49.627--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:49.627--ServerSession(9040869)--Connection(15213484)--Thread(Thread[main,5,main])--SELECT sourceId, DESCRIPTION, aId, bId FROM tblTestSource WHERE (sourceId = ?) bind => [1] [EL Finest]: 2011-05-03 09:32:49.627--ServerSession(9040869)--Connection(26338149)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:49.627--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query ReadObjectQuery(name="tarA" referenceClass=TargetA ) [EL Finest]: 2011-05-03 09:32:49.643--ServerSession(9040869)--Connection(3623254)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:49.643--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:49.643--ServerSession(9040869)--Connection(28306377)--Thread(Thread[main,5,main])--SELECT aId, DESCRIPTION FROM tblTestTargetA WHERE (aId = ?) bind => [1] [EL Finest]: 2011-05-03 09:32:49.847--ServerSession(9040869)--Connection(3623254)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query ReadObjectQuery(name="tarB" referenceClass=TargetB ) [EL Finest]: 2011-05-03 09:32:49.847--ServerSession(9040869)--Connection(9851613)--Thread(Thread[main,5,main])--Connection acquired from connection pool [read]. [EL Finest]: 2011-05-03 09:32:49.847--ServerSession(9040869)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:49.847--ServerSession(9040869)--Connection(18507774)--Thread(Thread[main,5,main])--SELECT bId, DESCRIPTION, sourceId FROM tblTestTargetB WHERE (bId = ?) bind => [1] [EL Finest]: 2011-05-03 09:32:49.847--ServerSession(9040869)--Connection(9851613)--Thread(Thread[main,5,main])--Connection released to connection pool [read]. [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query ReadObjectQuery(name="src" referenceClass=Source ) [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--remove() operation called on: eclipselink.Source@14a4639 [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--remove() operation called on: eclipselink.TargetB@130cda4 [EL Finer]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--TX beforeCompletion callback, status=STATUS_ACTIVE [EL Finer]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--begin unit of work commit [EL Finer]: 2011-05-03 09:32:49.847--ClientSession(23392283)--Thread(Thread[main,5,main])--TX beginTransaction, status=STATUS_ACTIVE [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query DeleteObjectQuery(eclipselink.Source@14a4639) [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query DeleteObjectQuery(eclipselink.TargetB@130cda4) [EL Finest]: 2011-05-03 09:32:49.847--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query DeleteObjectQuery(eclipselink.Source@14a4639) [EL Finest]: 2011-05-03 09:32:51.609--ServerSession(9040869)--Connection(20866423)--Thread(Thread[main,5,main])--Connection acquired from connection pool [default]. [EL Finest]: 2011-05-03 09:32:51.609--ClientSession(23392283)--Thread(Thread[main,5,main])--reconnecting to external connection pool [EL Fine]: 2011-05-03 09:32:51.609--ClientSession(23392283)--Connection(24604005)--Thread(Thread[main,5,main])--UPDATE tblTestSource SET aId = ?, bId = ? WHERE (sourceId = ?) bind => [null, null, 1] [EL Fine]: 2011-05-03 09:32:51.61--ClientSession(23392283)--Connection(24604005)--Thread(Thread[main,5,main])--DELETE FROM tblTestTargetB WHERE (bId = ?) bind => [1] [EL Fine]: 2011-05-03 09:32:51.61--ClientSession(23392283)--Connection(24604005)--Thread(Thread[main,5,main])--DELETE FROM tblTestSource WHERE (sourceId = ?) bind => [1] [EL Finest]: 2011-05-03 09:32:51.642--UnitOfWork(30390483)--Thread(Thread[main,5,main])--Execute query DeleteObjectQuery(eclipselink.TargetB@130cda4) [EL Finest]: 2011-05-03 09:32:51.642--ServerSession(9040869)--Connection(20866423)--Thread(Thread[main,5,main])--Connection released to connection pool [default]. [EL Finer]: 2011-05-03 09:32:52.125--UnitOfWork(30390483)--Thread(Thread[main,5,main])--TX afterCompletion callback, status=COMMITTED [EL Finer]: 2011-05-03 09:32:52.125--UnitOfWork(30390483)--Thread(Thread[main,5,main])--end unit of work commit [EL Finer]: 2011-05-03 09:32:52.125--UnitOfWork(30390483)--Thread(Thread[main,5,main])--initialize identitymaps [EL Finer]: 2011-05-03 09:32:52.125--ClientSession(23392283)--Thread(Thread[main,5,main])--initialize identitymaps [EL Finer]: 2011-05-03 09:32:52.125--UnitOfWork(30390483)--Thread(Thread[main,5,main])--release unit of work [EL Finer]: 2011-05-03 09:32:52.125--ClientSession(23392283)--Thread(Thread[main,5,main])--client released [EL Finest]: 2011-05-03 09:32:52.141--ServerSession(9040869)--Thread(Thread[Thread-1,5,main])--Begin undeploying Persistence Unit EclipselinkTest; session file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest; state Deployed; factoryCount 2 [EL Finest]: 2011-05-03 09:32:52.141--ServerSession(9040869)--Thread(Thread[Thread-1,5,main])--End undeploying Persistence Unit EclipselinkTest; session file:/C:/FDM/projects/eclipselink/target/classes/_EclipselinkTest; state Deployed; factoryCount 1 May 3, 2011 9:32:52 AM mil.army.us.sec.testfixture.ShutdownHook shutdownOpenEJB INFO: Shutdown Handler invoked I suspect the targetA Class does not have an effect on this recreation. If it does, it is likely just affects the order in which we calculate our dependencies and means we pick a different order for a relationship that eclipselink believes can occur in either order. It seems like the cyclical relationship between Source and TargetB is the reason for the SQL you are seeing. Since the targetB.src mapping does not have the optional=false tag, I assume an update the sets it's foreign key to null would not be a problem. You should be able to acheive this by simply adding a constraint dependancy using our constaint api between Source and TargetB. You can use a DescriptorCustomizer to do this. The api on Descriptor is addConstraintDependency(Class) I am not sure where he explaination is leading( setting targetClassA to null is a issue). I would summarize the final bug as follows If a class has N relationships and only 1 of them is a cyclic relationship, the attribute values for ALL N of them are being set to null. Per your 2.3 change only 1 should be set to null. I still insist that the setting of the 1 attribute to null should done by an explicit setting of an attribute or annotation. I think doing this only when option=true (default for relationship attributes) is a reasonable compromise. Have you considered trying any of the workarounds? The reason we propose workarounds is that bug fixes are prioritized among the other things the committers on the project have to do such as featurs and work required by our actual employers as well as among the other bugs. Bug fixes take time, so even a bug fix stared right away will not be immediately available away and even when the bug fix appears you will need to wait for the next release to get it in a fully tested product. Our goal is to help you get your application into working shape as soon as possible on a fully tested version of EclipseLink. Still in the debating process. Need to evaluate various aspects and figure if it is more cost effective to do a workaround or revert the migration from hibernate. In addition to this issue we also need to evaluate the quality of the support for generics and the time/energy it takes to report bugs. In the attached recreation if I added a descrptor customizer for TargetA with the following code, I no longer see the issue:
public void customize(ClassDescriptor descriptor) throws Exception {
descriptor.addConstraintDependency(Source.class);
}
1. I have tooooooo many classes that I now have to write customizers for. 2. Have to see what the side affects are to adding a constraint dependency - have to see if it is worth the time - especially in terms of using non-standard features Option of adding customizer to target class is not an option. Amon the many issues one is that the target classes are packaged/provided in a manner that have no dependency on the source classes and so the compilation will fail. A customizer is an independant class and it is specified at the persistence unit level. Adding a customizer will not add a compile dependency between model classes. In order to put a customizer annotation on TargetA, TargetA class has to have access to the custom descriptor class - which refers to source.class You can refer to the customizer in the persistence.xml instead. See http://wiki.eclipse.org/Using_EclipseLink_JPA_Extensions_%28ELUG%29#Using_EclipseLink_JPA_Extensions_for_Customization_and_Optimization for the docs. e.g. Under: eclipselink.descriptor.customizer.<ENTITY> <property name="eclipselink.descriptor.customizer.Order" value="acme.sessions.MyDescriptorCustomizer"/> 1. Will you update the API documentation for addConstraintDependency() to cover this case so I can be assured(somewhat) that the next build will not break my code 2. How will this bug be ultimately be resolved? We can certainly update the Javadoc. What, in particular are you hoping to see? To the person who ultimately address this bug. Addressing this issue likely means taking into account the optional=false argument that is available in several JPA annotations. The specification is quite vague about what that argument should do. e.g. For @Basic "The optional element is a hint as to whether the value of the field or property may be null. It is disregarded for primitive types." For @ManyToOne "(Optional) Whether the association is optional. If set to false then a non-null relationship must always exist." I can find no further documentation about how these constaints are expected to be implementated. At the moment EclipseLink implements this only in DDL generation. We use the Optional annotation to determine whether to add a constraint to the database table. There would be value in taking the "option=false" setting into account when there are two classes for which we have no other way of determining the commit order and ensuring that we choose the commit order in such a way as to avoid writing an Update statement to update the column that is not optional. In the case where the commit order is picked because of other existing mappings we will have to decide what we think this attribute means. i.e. should we execute the update statement as we do now, or throw an exception (we would do this if we agree that this attribute means we should not update the database column to null) Perhaps the next version of the JPA specification will expand the symantics around this property. Switched to Hibernate due to poor support for complex generics and too much difficulty in getting issues resolved Created attachment 204130 [details]
Patch for Bug
The patch skips update of foriegn keys to null for OneToOne and ManyToOne that are not optional
The other options:
1. Using customizer does not work consistently
2. Setting columns to Nullable is NOT ACCEPTABLE
Any idea when this patch will be reviewed/incorporated I am taking a look at what kind of change we could make to accomodate your use case now. Any change we made would be in different code than the submitted patch changes. The process of doing an update of the keys to null and then a delete, is what we call a shallow delete. In the case of a cycle, there is code that detects that this has to happen. Any change we made would occur where the detection code is. In case it was not obvious above, explicitly stating another workaround: Some databases allow the deferral of contraints. Deferring a NOT NULL the NOT NULL constraint until the transaction commits will address this issue as well. We have discussed this some more amoung some members of the committer group here. The spec is very vague about what optional means and as a result, we think that it is possible to interpret the meaning of this setting in multiple ways. Because of that, making optional=false require deferred foreign key constraints by default could cause regressions for some users. As a result, we believe there are several components to the change that would be required to make this use case work by default. 1. A setting either at the persistence unit level or the mapping level that indicates not to do the shallow delete 2. Code that detects whether a descriptor contains no non-optional mappings and avoids building the update query in the case where the setting above is set 3. The code that is included in your patch - for descriptors that have both optional and non-optional mappings I think NULLing column as part of shallow delete was introduced in 2.3 and not there before that. In hind sight I think the global option should have been introduced at that time to permit NULLing of non-optional columns as part of shallow delete. Targetting for our next major release for now. We only add annotations and/or persistence unit properties in major releases. I still think that the simplest solution is to defer not null constraints until the commit. Is that possible in the database you are using? It seems that you are already doing that for foreign key constratints. Is there a specific reason you cannot do that. There are two different databases I am using. One does and the other doesn't. I will build a local copy with the patch for use as I cannot wait for a major release. *** Bug 361309 has been marked as a duplicate of this bug. *** Is this slated for any particular 2.4 build??? We have not started work on this. Any Idea when I can expect traction on this issue? We have been discussing this bug over the last week or so. Our current plan is to deal with this issue by respecting NOT NULL constraints on columns rather than looking at the "optional" setting. i.e. if you specify a column as NOT NULL, it will not be included in the update statements that are referred to above. Created attachment 216373 [details]
Suggested patch.
The patch based on "nullable" option of JoinColumn:
@JoinColumn(name="A_ID", nullable= false)
It makes sure that the column marked as non nullable will not be nullified for resolving a cycle when insert and delete.
Note that there are no changes in commit order.
Test: EntityManagerJUnitTestSuite.testCycleReferencesWithNonNullableField
Created attachment 216437 [details]
Updated patch.
Defined DatabaseMapping.writeFromObjectIntoRowForUpdateBeforeShallowDelete and ObjectBuilder.buildRowForUpdateBeforeShallowDelete
Checked the patch into trunk 2.5 (revision: 11548) and into 2.4 (revision: 11547). Reviewed by James. Created attachment 216540 [details]
Additional patch
Contains additional changes to be applied on top of the previous patch.
Defines writeFromObjectIntoRowForUpdateAfterShallowInsert for all mappings that override writeFromObjectIntoRowForShallowInsert method defined in DatabaseMapping class (EISOneToManyMapping, VariableOneToOneMapping and NestedTableMapping).
Note that no attempt to handle nullable fields was made for the first two of these mappings.
Checked the additional patch into both trunk and 2.4. Does this actually work for anybody? It does not work for us, even though nullable=true is added to @JoinColumn on both sides of the bidirectional @OneToMany relationship. At least not in EclipseLink 2.4.2.v20130306-4d428ad nor in 2.5.0.v20130312-9664d23. (In reply to comment #78) > Does this actually work for anybody? It does not work for us, even though > nullable=true is added to @JoinColumn on both sides of the bidirectional > @OneToMany relationship. At least not in EclipseLink > 2.4.2.v20130306-4d428ad nor in 2.5.0.v20130312-9664d23. Should use nullable=false (not true) Note that the tests in all code streams are in jpa/fieldsaccess/advanced, the patch has the tests in jpa/advanced. Backported the fix to 2.3.4. > Should use nullable=false (not true)
Of course, I did use nullable=false - just wrote it wrong here. Yet it does not work. It's just working for simpler entity structures. I have not figured out yet what makes the difference. There is definitely no cycle.
The Eclipselink project has moved to Github: https://github.com/eclipse-ee4j/eclipselink |