Return-Path: X-Original-To: apmail-openjpa-users-archive@minotaur.apache.org Delivered-To: apmail-openjpa-users-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id C3F9310264 for ; Wed, 5 Mar 2014 11:16:21 +0000 (UTC) Received: (qmail 23357 invoked by uid 500); 5 Mar 2014 11:16:21 -0000 Delivered-To: apmail-openjpa-users-archive@openjpa.apache.org Received: (qmail 23304 invoked by uid 500); 5 Mar 2014 11:16:05 -0000 Mailing-List: contact users-help@openjpa.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: users@openjpa.apache.org Delivered-To: mailing list users@openjpa.apache.org Received: (qmail 23253 invoked by uid 99); 5 Mar 2014 11:16:01 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 05 Mar 2014 11:16:01 +0000 X-ASF-Spam-Status: No, hits=-0.0 required=5.0 tests=SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: local policy) Received: from [46.218.205.227] (HELO mailfilter.thvnet.com) (46.218.205.227) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 05 Mar 2014 11:15:57 +0000 X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: AqIEAO0GF1MKC/8o/2dsb2JhbABRCYNBV8ELgS90giUBAQEDATpEBwQCAQgNBAQBAQsUCQchERQJCAEBBBMIh10DCRXGVw2GdhMEjDyBMQkqOAaDHoEUBJMygSCBfQGIX4VxiHWBaEI X-IronPort-AV: E=Sophos;i="4.97,592,1389740400"; d="scan'208";a="11967073" Received: from unknown (HELO srv0024.corp.thvnet.com) ([10.11.255.40]) by net0001.corp.thvnet.com with ESMTP; 05 Mar 2014 12:15:33 +0100 Received: from SRV0025.corp.thvnet.com ([fe80::159a:e77e:d9f8:8a9]) by srv0024.corp.thvnet.com ([fe80::5d97:89c7:879a:3297%13]) with mapi id 14.03.0158.001; Wed, 5 Mar 2014 12:15:33 +0100 From: Datin Benoit To: "users@openjpa.apache.org" Subject: RE: [Open JPA 2.2.2] Missing SQL statements Thread-Topic: [Open JPA 2.2.2] Missing SQL statements Thread-Index: Ac8yVRAFDnKdEqW1RPyDhiK40B6xDAFg/naAACGT1MA= Date: Wed, 5 Mar 2014 11:15:32 +0000 Message-ID: <77EEC52B4F9BB743A57D9A6C96766C30C26FEC4A@srv0025.corp.thvnet.com> References: <77EEC52B4F9BB743A57D9A6C96766C30C26FCDE0@srv0025.corp.thvnet.com> In-Reply-To: Accept-Language: fr-FR, en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-originating-ip: [10.11.244.147] Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 X-Virus-Checked: Checked by ClamAV on apache.org Hi Kevin, Thanks for your answer. Unfortunately, I had already tried these 2 workarounds in a recent past wit= h the same issue. Anyway, my new tests leads me to think that the problem seems to appear whe= n I try to update 2 entities in the same transaction (or appears more frequ= ently). And these tests confirm that I have no problem with adding or delet= ion entity, meaning that foreign keys are correctly managed in these cases. I have also seen a strange behavior around the primary keys generators. As explained below, I am using generators strategy with allocationSize set = to 10 or 20 depending the entity. After launching my application, as my data model is loaded from database, I= note that new primary key range is generated as soon as I need to create a= new instance of an entity. It is the logical behavior. But as a consequence, if the update of the 2 entities in the same transacti= on is the first operation after launching my application, I see that the IN= SERT sql statements are correctly called before the UPDATE ones. As if the = fact to generate a new range for primary keys force the INSERT statements t= o be done ! Then, I can perform many successive updates of 2 entities in th= e same transactions without issue, it is very strange. Obviously, I try to set allocationSize to 1, in order to force the generati= on of primary key for each new or update entity operation (as if I use IDEN= TITY strategy in fact). Sometimes it works, sometimes not ! So, any other idea about my problem regarding this new information ? Regards Benoit -----Original Message----- From: Kevin Sutter [mailto:kwsutter@gmail.com]=20 Sent: mardi 4 mars 2014 20:39 To: users@openjpa.apache.org Subject: Re: [Open JPA 2.2.2] Missing SQL statements Hi Datin, It sounds like you might be hitting a condition where OpenJPA doesn't prope= rly detect the FK's within your Entity definitions. Reference this JIRA fo= r the problem description and a couple of potential workarounds. Let us know if we're talking about the same issue and whether one of the wo= rkarounds does the trick for you. Thanks. https://issues.apache.org/jira/browse/OPENJPA-1936 Kevin On Tue, Feb 25, 2014 at 12:11 PM, Datin Benoit < benoit.datin@thomson-netwo= rks.com> wrote: > Hi all, > > I'm facing a problem that I assume to be an openJPA bug concerning=20 > 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 followin= g: > > > value=3D"PrettyPrint=3Dtrue, PrettyPrintLineLength=3D120, PrintParameters= =3Dtrue" /> > > > value=3D"true" /> > value=3D"unsupported" /> > Runtime=3DERROR, Tool=3DINFO" /> name=3D"openjpa.jdbc.MappingDefaults" > value=3D"ForeignKeyDeleteAction=3Drestrict,JoinForeignKeyDeleteAction=3Dr= estrict" > /> > > > Then, here are two classes B_ScheduleElement and B_ScheduleTrigger=20 > where generators strategy is used for primary keys generation > > B_ScheduleElement: > > @Entity > @Table( name =3D "schedule_element" ) > @TableGenerator( name =3D "scheduleElementIdGen", table =3D=20 > "pk_generators", pkColumnValue =3D "scheduleElementId", initialValue =3D= =20 > 1, allocationSize =3D 10 ) public class B_ScheduleElement implements=20 > Cloneable { > /** > * The persistence identifier > */ > @Id > @GeneratedValue( strategy =3D GenerationType.TABLE, generator =3D=20 > "scheduleElementIdGen" ) > @Column( name =3D "id", nullable =3D false, updatable =3D false ) > private long id; > > /** > * The schedule element unique identifier. > */ > private UUID uuid; > > /** > * Trigger for schedule start > */ > @OneToOne( cascade =3D CascadeType.ALL, orphanRemoval =3D true ) > @JoinColumn( name =3D "plannedStartTriggerId" ) > private B_ScheduleTrigger > plannedStartTrigger =3D null; > > /** > * Trigger for schedule end > */ > @OneToOne( cascade =3D CascadeType.ALL, orphanRemoval =3D true ) > @JoinColumn( name =3D "plannedEndTriggerId" ) > private B_ScheduleTrigger plannedEndTrigger > =3D null; > > /** > * The non persistent planable associated to the schedule element. > */ > @Transient > private B_Planable planable > =3D null; > > } > > B_ScheduleTrigger > > /** > * > * B_ScheduleTrigger complex type. > * > */ > @Entity > @Table( name =3D "schedule_trigger" ) > @TableGenerator( name =3D "scheduleTriggerIdGen", table =3D=20 > "pk_generators", pkColumnValue =3D "scheduleTriggerId", initialValue =3D= =20 > 1, allocationSize =3D 20 ) @Inheritance( strategy =3D=20 > InheritanceType.JOINED ) public abstract class B_ScheduleTrigger=20 > implements Cloneable { > > /** > * The persistence identifier > */ > @Id > @GeneratedValue( strategy =3D GenerationType.TABLE, generator =3D=20 > "scheduleTriggerIdGen" ) > @Column( name =3D "id", nullable =3D false, updatable =3D 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=20 > are correctly created before B_ScheduleElement. > But in some cases I can't explain, when I want to modify a=20 > B_ScheduleTrigger of a B_ScheduleElement, I see that no new insert of=20 > 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 - 26690957, conn 12233946> executing prepstmnt 8820448 UPDATE=20 > schedule_element > SET persistentPlanable =3D ?, plannedEndTriggerId =3D ?,=20 > plannedStartTriggerId =3D ? > WHERE id =3D ? > [params=3D(byte[]) [B@1b7faf, (long) 0, (long) 0, (long) 224] > 173924 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> [0 ms] spent > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> executing prepstmnt 82008 DELETE FROM=20 > schedule_trigger_date > WHERE id =3D ? > [params=3D(long) 604] > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> [0 ms] spent > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> executing prepstmnt 2591188 DELETE FROM=20 > schedule_trigger_duration > WHERE id =3D ? > [params=3D(long) 603] > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> [0 ms] spent > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> executing prepstmnt 30001058 DELETE FROM=20 > schedule_trigger > WHERE id =3D ? > [params=3D(long) 604] > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> [0 ms] spent > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> executing prepstmnt 5338416 DELETE FROM=20 > schedule_trigger > WHERE id =3D ? > [params=3D(long) 603] > 173955 planning TRACE [Pool thread #1] openjpa.jdbc.SQL - 26690957, conn 12233946> [0 ms] spent > ERROR: [2014/01/03 - 16:55:22] Error: An error appear while committing=20 > JPA > transaction > org.apache.openjpa.persistence.RollbackException: The transaction has=20 > been rolled back. See the nested exceptions for details on the errors=20 > that occurred. > FailedObject:=20 > xms.common.beans.bus.planning.schedule.B_ScheduleElement-224 > ERROR: [2014/01/03 - 16:55:22] Error: > Exception stack trace: > > org.apache.openjpa.persistence.RollbackException: The transaction has=20 > been rolled back. See the nested exceptions for details on the errors=20 > that occurred. > FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-22= 4 > at > org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl= .java:594) > at > xms.xserver.common.JPAPersistenceTool.commitTransaction(JPAPersistenceToo= l.java:193) > at > xms.xserver.fe.bus.planning.PlanningManager.updateScheduleElement(Plannin= gManager.java:2126) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java= :57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI= mpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > xms.common.util.annotationshandler.RmwoAnnotationHandler.invoke(RmwoAnnot= ationHandler.java:95) > at com.sun.proxy.$Proxy50.updateScheduleElement(Unknown Source) > at > xms.xserver.fe.bus.planning.actions.UpdateScheduleElementAction.execute(U= pdateScheduleElementAction.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_Ser= ver_impl_tie.java:715) > at > xms.xserver.fe.inter.gen.sys.session.I_ServerPOATie.sendCommand(I_ServerP= OATie.java:204) > at > xms.xserver.fe.inter.gen.sys.session.I_ServerPOA._invoke_sendCommand(I_Se= rverPOA.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.in= voke(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.jav= a:1601) > at > org.openorb.orb.net.ServerManagerImpl.thread_pool_main(ServerManagerImpl.= java:1526) > at > org.openorb.orb.net.ServerManagerImpl.access$9(ServerManagerImpl.java:138= 2) > at > org.openorb.orb.net.ServerManagerImpl$PoolThread.run(ServerManagerImpl > .java:2886) Caused by: error> > org.apache.openjpa.persistence.PersistenceException: The transaction=20 > has been rolled back. See the nested exceptions for details on the=20 > errors that occurred. > FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-22= 4 > at > org.apache.openjpa.kernel.BrokerImpl.newFlushException(BrokerImpl.java:23= 47) > 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:200= 0) > at > org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.= java:81) > at org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:152= 4) > at > org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:9= 33) > at > org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl= .java:570) > ... 22 more > Caused by: > org.apache.openjpa.persistence.PersistenceException: GDS Exception. > 335544466. violation of FOREIGN KEY constraint "INTEG_46" on table=20 > "SCHEDULE_ELEMENT" > Foreign key reference target does not exist {prepstmnt 8820448 UPDATE=20 > schedule_element > SET persistentPlanable =3D ?, plannedEndTriggerId =3D ?,=20 > plannedStartTriggerId =3D ? > WHERE id =3D ? > [params=3D(byte[]) [B@1b7faf, (long) 0, (long) 0, (long) 224]}=20 > [code=3D335544466, state=3DHY000] > FailedObject: xms.common.beans.bus.planning.schedule.B_ScheduleElement-22= 4 > at > org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4962) > at > org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.j= ava: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.flushAndUpdat= e(PreparedStatementManagerImpl.java:144) > at > org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flush= AndUpdate(BatchingPreparedStatementManagerImpl.java:79) > at > org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushInternal= (PreparedStatementManagerImpl.java:100) > at > org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flush(Prepare= dStatementManagerImpl.java:88) > at > org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUp= dateManager.java:550) > at > org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUp= dateManager.java:107) > at > org.apache.openjpa.jdbc.kernel.BatchingConstraintUpdateManager.flush(Batc= hingConstraintUpdateManager.java:59) > at > org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdate= Manager.java:105) > at > org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdate= Manager.java:78) > at > org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.ja= va:732) > at > org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreMan= ager.java:131) > ... 29 more > > When the sequence is OK, I have the following log: > > 68034 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 15313840 INSERT INTO=20 > schedule_trigger (id) > VALUES (?) > [params=3D(long) 604] > 68034 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68034 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 17226064 INSERT INTO=20 > schedule_trigger (id) > VALUES (?) > [params=3D(long) 603] > 68049 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [15 ms] spent > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 10822163 INSERT INTO=20 > schedule_trigger_date (id, triggerTime, triggerTimezone) > VALUES (?, ?, ?) > [params=3D(long) 604, (Timestamp) 2014-01-03 22:00:00.0, (null) null] > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 23077963 INSERT INTO=20 > schedule_trigger_duration (id, duration) > VALUES (?, ?) > [params=3D(long) 603, (long) 3600000] > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 15646409 UPDATE=20 > schedule_element > SET persistentPlanable =3D ?, plannedEndTriggerId =3D ?,=20 > plannedStartTriggerId =3D ? > WHERE id =3D ? > [params=3D(byte[]) [B@2f9009, (long) 603, (long) 604, (long) 224] > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 10056783 DELETE FROM=20 > schedule_trigger_duration > WHERE id =3D ? > [params=3D(long) 601] > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 10679288 DELETE FROM=20 > schedule_trigger_date > WHERE id =3D ? > [params=3D(long) 602] > 68065 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 4149336 DELETE FROM=20 > schedule_trigger > WHERE id =3D ? > [params=3D(long) 602] > 68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> [0 ms] spent > 68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 22442066, conn 12233946> executing prepstmnt 11794406 DELETE FROM=20 > schedule_trigger > WHERE id =3D ? > [params=3D(long) 601] > 68081 planning TRACE [Pool thread #3] openjpa.jdbc.SQL - 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=20 > B_ScheduleTrigger when I detect that it has changed in my=20 > 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=20 > trigger to force openJPA translating all the needed SQL statements ? > It seems thet OpenJPA forget that my B_ScheduleTrigger is a foreign=20 > key for b_ScheduleElement. > That's the reason why I have the following exception: > > Foreign key reference target does not exist {prepstmnt 8820448 UPDATE=20 > schedule_element > SET persistentPlanable =3D ?, plannedEndTriggerId =3D ?,=20 > plannedStartTriggerId =3D ? > WHERE id =3D ? > [params=3D(byte[]) [B@1b7faf, (long) 0, (long) 0, (long) 224]}=20 > [code=3D335544466, state=3DHY000] > > Is my configuration wrong ? > > Thanks for your help > Benoit DATIN > > > > > > > > > > > > >