Hi all,
I'm facing a problem that I assume to be an openJPA bug concerning some missing
SQL statements.
I'm using open JPA 2.2.2 version
First of all, my configuration in my persistence.xml file is the following:
<properties>
<property name="openjpa.ConnectionFactoryProperties" value="PrettyPrint=true,
PrettyPrintLineLength=120, PrintParameters=true" />
<property name="openjpa.InitializeEagerly" value="false" />
<property name="openjpa.Multithreaded" value="false" />
<property name="openjpa.DynamicEnhancementAgent" value="true" />
<property name="openjpa.RuntimeUnenhancedClasses"
value="unsupported" />
<property name="openjpa.Log" value="DefaultLevel=WARN,
Runtime=ERROR, Tool=INFO" />
<property name="openjpa.jdbc.MappingDefaults"
value="ForeignKeyDeleteAction=restrict,JoinForeignKeyDeleteAction=restrict" />
</properties>
Then, here are two classes B_ScheduleElement and B_ScheduleTrigger where
generators strategy is used for primary keys generation
B_ScheduleElement:
@Entity
@Table( name = "schedule_element" )
@TableGenerator( name = "scheduleElementIdGen", table = "pk_generators",
pkColumnValue = "scheduleElementId", initialValue = 1, allocationSize = 10 )
public class B_ScheduleElement implements Cloneable
{
/**
* The persistence identifier
*/
@Id
@GeneratedValue( strategy = GenerationType.TABLE, generator =
"scheduleElementIdGen" )
@Column( name = "id", nullable = false, updatable = false )
private long id;
/**
* The schedule element unique identifier.
*/
private UUID uuid;
/**
* Trigger for schedule start
*/
@OneToOne( cascade = CascadeType.ALL, orphanRemoval = true )
@JoinColumn( name = "plannedStartTriggerId" )
private B_ScheduleTrigger plannedStartTrigger =
null;
/**
* Trigger for schedule end
*/
@OneToOne( cascade = CascadeType.ALL, orphanRemoval = true )
@JoinColumn( name = "plannedEndTriggerId" )
private B_ScheduleTrigger plannedEndTrigger =
null;
/**
* The non persistent planable associated to the schedule element.
*/
@Transient
private B_Planable planable =
null;
}
B_ScheduleTrigger
/**
*
* B_ScheduleTrigger complex type.
*
*/
@Entity
@Table( name = "schedule_trigger" )
@TableGenerator( name = "scheduleTriggerIdGen", table = "pk_generators",
pkColumnValue = "scheduleTriggerId", initialValue = 1, allocationSize = 20 )
@Inheritance( strategy = InheritanceType.JOINED )
public abstract class B_ScheduleTrigger implements Cloneable
{
/**
* The persistence identifier
*/
@Id
@GeneratedValue( strategy = GenerationType.TABLE, generator =
"scheduleTriggerIdGen" )
@Column( name = "id", nullable = false, updatable = false )
private long id;
}
So, B_ScheduleElement has two attributes of B_ScheduleTrigger types.
When I first create a B_ScheduleElement, no problem, B_ScheduleTrigger are
correctly created before B_ScheduleElement.
But in some cases I can't explain, when I want to modify a B_ScheduleTrigger of
a B_ScheduleElement, I see that no new insert of B_ScheduleTrigger are done
before the update of the B_ScheduleElement.
I activate the log to see all SQL statements:
When the problem occurs, I have the following log:
173924 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> executing prepstmnt 8820448
UPDATE schedule_element
SET persistentPlanable = ?, plannedEndTriggerId = ?, plannedStartTriggerId
= ?
WHERE id = ?
[params=(byte[]) [B@1b7faf, (long) 0, (long) 0, (long) 224]
173924 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> [0 ms] spent
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> executing prepstmnt 82008
DELETE FROM schedule_trigger_date
WHERE id = ?
[params=(long) 604]
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> [0 ms] spent
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> executing prepstmnt 2591188
DELETE FROM schedule_trigger_duration
WHERE id = ?
[params=(long) 603]
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> [0 ms] spent
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> executing prepstmnt 30001058
DELETE FROM schedule_trigger
WHERE id = ?
[params=(long) 604]
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> [0 ms] spent
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> executing prepstmnt 5338416
DELETE FROM schedule_trigger
WHERE id = ?
[params=(long) 603]
173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - <t 26690957, conn
12233946> [0 ms] spent
ERROR: [2014/01/03 - 16:55:22] Error: An error appear while committing JPA
transaction<openjpa-2.2.2-r422266:1468616 fatal store error>
org.apache.openjpa.persistence.RollbackException: The transaction has been
rolled back. See the nested exceptions for details on the errors that occurred.
FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-224
ERROR: [2014/01/03 - 16:55:22] Error:
Exception stack trace:
<openjpa-2.2.2-r422266:1468616 fatal store error>
org.apache.openjpa.persistence.RollbackException: The transaction has been
rolled back. See the nested exceptions for details on the errors that occurred.
FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-224
at
org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:594)
at
xms.xserver.common.JPAPersistenceTool.commitTransaction(JPAPersistenceTool.java:193)
at
xms.xserver.fe.bus.planning.PlanningManager.updateScheduleElement(PlanningManager.java:2126)
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:606)
at
xms.common.util.annotationshandler.RmwoAnnotationHandler.invoke(RmwoAnnotationHandler.java:95)
at com.sun.proxy.$Proxy50.updateScheduleElement(Unknown Source)
at
xms.xserver.fe.bus.planning.actions.UpdateScheduleElementAction.execute(UpdateScheduleElementAction.java:63)
at xms.common.xcommand.XCommand.performAction(XCommand.java:219)
at
xms.xserver.fe.inter.impl.sys.session.I_Server_impl_tie.sendCommand(I_Server_impl_tie.java:715)
at
xms.xserver.fe.inter.gen.sys.session.I_ServerPOATie.sendCommand(I_ServerPOATie.java:204)
at
xms.xserver.fe.inter.gen.sys.session.I_ServerPOA._invoke_sendCommand(I_ServerPOA.java:350)
at
xms.xserver.fe.inter.gen.sys.session.I_ServerPOA.access$3500(I_ServerPOA.java:8)
at
xms.xserver.fe.inter.gen.sys.session.I_ServerPOA$Operation_sendCommand.invoke(I_ServerPOA.java:571)
at
xms.xserver.fe.inter.gen.sys.session.I_ServerPOA._invoke(I_ServerPOA.java:83)
at org.openorb.orb.adapter.poa.POA.dispatch(POA.java:1493)
at
org.openorb.orb.net.AbstractServerRequest.dispatch(AbstractServerRequest.java:889)
at
org.openorb.orb.net.ServerManagerImpl.serve_request(ServerManagerImpl.java:1601)
at
org.openorb.orb.net.ServerManagerImpl.thread_pool_main(ServerManagerImpl.java:1526)
at
org.openorb.orb.net.ServerManagerImpl.access$9(ServerManagerImpl.java:1382)
at
org.openorb.orb.net.ServerManagerImpl$PoolThread.run(ServerManagerImpl.java:2886)
Caused by: <openjpa-2.2.2-r422266:1468616 fatal general error>
org.apache.openjpa.persistence.PersistenceException: The transaction has been
rolled back. See the nested exceptions for details on the errors that occurred.
FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-224
at
org.apache.openjpa.kernel.BrokerImpl.newFlushException(BrokerImpl.java:2347)
at org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2184)
at org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:2082)
at
org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:2000)
at
org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81)
at org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1524)
at
org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:933)
at
org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:570)
... 22 more
Caused by: <openjpa-2.2.2-r422266:1468616 fatal general error>
org.apache.openjpa.persistence.PersistenceException: GDS Exception. 335544466.
violation of FOREIGN KEY constraint "INTEG_46" on table "SCHEDULE_ELEMENT"
Foreign key reference target does not exist {prepstmnt 8820448
UPDATE schedule_element
SET persistentPlanable = ?, plannedEndTriggerId = ?, plannedStartTriggerId
= ?
WHERE id = ?
[params=(byte[]) [B@1b7faf, (long) 0, (long) 0, (long) 224]} [code=335544466,
state=HY000]
FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-224
at
org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4962)
at
org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4922)
at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:136)
at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:78)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:144)
at
org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flushAndUpdate(BatchingPreparedStatementManagerImpl.java:79)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushInternal(PreparedStatementManagerImpl.java:100)
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flush(PreparedStatementManagerImpl.java:88)
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:550)
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:107)
at
org.apache.openjpa.jdbc.kernel.BatchingConstraintUpdateManager.flush(BatchingConstraintUpdateManager.java:59)
at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:105)
at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:78)
at
org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.java:732)
at
org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:131)
... 29 more
When the sequence is OK, I have the following log:
68034 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 15313840
INSERT INTO schedule_trigger (id)
VALUES (?)
[params=(long) 604]
68034 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68034 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 17226064
INSERT INTO schedule_trigger (id)
VALUES (?)
[params=(long) 603]
68049 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [15 ms] spent
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 10822163
INSERT INTO schedule_trigger_date (id, triggerTime, triggerTimezone)
VALUES (?, ?, ?)
[params=(long) 604, (Timestamp) 2014-01-03 22:00:00.0, (null) null]
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 23077963
INSERT INTO schedule_trigger_duration (id, duration)
VALUES (?, ?)
[params=(long) 603, (long) 3600000]
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 15646409
UPDATE schedule_element
SET persistentPlanable = ?, plannedEndTriggerId = ?, plannedStartTriggerId
= ?
WHERE id = ?
[params=(byte[]) [B@2f9009, (long) 603, (long) 604, (long) 224]
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 10056783
DELETE FROM schedule_trigger_duration
WHERE id = ?
[params=(long) 601]
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 10679288
DELETE FROM schedule_trigger_date
WHERE id = ?
[params=(long) 602]
68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 4149336
DELETE FROM schedule_trigger
WHERE id = ?
[params=(long) 602]
68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> executing prepstmnt 11794406
DELETE FROM schedule_trigger
WHERE id = ?
[params=(long) 601]
68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - <t 22442066, conn
12233946> [0 ms] spent
The code is something like that
beginTransaction
update schedule element
commit transaction
To solve the problem, I had to force the persistence of the B_ScheduleTrigger
when I detect that it has changed in my B_ScheduleElement. It gives:
beginTransaction
update schedule element
persist newTrigger if oldTrigger <> newTrigger
commit transaction
Can someone explain me why I need to force the persistence of the trigger to
force openJPA translating all the needed SQL statements ?
It seems thet OpenJPA forget that my B_ScheduleTrigger is a foreign key for
b_ScheduleElement.
That's the reason why I have the following exception:
Foreign key reference target does not exist {prepstmnt 8820448
UPDATE schedule_element
SET persistentPlanable = ?, plannedEndTriggerId = ?, plannedStartTriggerId
= ?
WHERE id = ?
[params=(byte[]) [B@1b7faf, (long) 0, (long) 0, (long) 224]} [code=335544466,
state=HY000]
Is my configuration wrong ?
Thanks for your help
Benoit DATIN
