Latest revision as of 10:55, 28 April 2010

Bug Analysis Document: 256277: Endless loop on @PrePersist using a nested Persist

• Bugzilla Bug 256277
• EclipseLink Users Newsgroup posting

Document History

Overview

This bug describes the behavior and fix for the issue of nested flush() calls when using the @PrePersist annotation callback method on an unmanaged entity containing a read query method that causes a flush() when the entity is the target of a relationship from a managed entity that has pending changes.

This bug is also encountered when a secondary persist is executed inside of a @PrePersist callback method on the Entity being itself persisted. Soo there are two use cases here - we will concentrate on the read query causing a secondary flush to sync changes before the read - causing an infinite loop or double persist which causes a PK conflict.

Concepts

See p.139 of Pro EJB 3.0 "Some providers will flush the persistence context to ensure that the query incorporates all pending changes" - EclipseLink is one of these providers.

JPA Specification Notes

Here is what the JPA specification says about performing persists inside the @PrePersist method. Essentially it states that we should not be performing persists inside a @PrePersist callback - however it may be the responsibility of the container to handle any that may be done depending on the nature of the persistence.

JPA 1.0 Specification

• P58 Section 3.5
  • "In general, portable applications should not invoke EntityManager or Query operations, access other entity instances, or modify relationships in a lifecycle callback method.[19]"
  • "[19] The semantics of such operations may be standardized in a future release of this specification."

JPA 2.0 Specification

• P82 Section 3.5.1
  • "In general, portable applications should not invoke EntityManager or Query operations, access other entity instances, or modify relationships within the same persistence context.[34] A lifecycle callback method may modify the non-relationship state of the entity on which it is invoked."
  • "[34] The semantics of such operations may be standardized in a future release of this specification."

Reproduction

Prerequisites

• Run tests out of container on an SE persistence unit (EE can also be used)
• At least two entities must be persisted to avoid performance optimization code for a single entity
• Two different entity classes are required
  • One must be managed, the other one containing the @PrePersist must be unmanaged/detached but referenced by the first
• Test must commit more than one object so that the non-performance else clause in CommitManager.commitAllObjectsWithChangeSet() is used
• Test must perform a change on an existing object that is already persisted
• cascade must be set to CascadeType.ALL
• fetch must be set to FetchType.EAGER
• Set FlushMode to AUTO
  • entityManager.setFlushMode(FlushModeType.AUTO);

Data Model

This matches the data model used in Chapter 5 of Pro EJB 3.0.

@Entity
public class Employee implements Serializable {
    @Id
    private BigInteger id;
 
    @OneToOne(fetch=FetchType.EAGER, cascade=CascadeType.ALL)
    ParkingSpace parkingSpace;
 
    @OneToMany(fetch=FetchType.EAGER, mappedBy="employee", cascade=CascadeType.ALL)
    Collection<Phone> phones;
 
    @ManyToOne(fetch=FetchType.EAGER, cascade=CascadeType.ALL)
    Address address;
}
 
@Entity
public class Address implements Serializable {
 
    @Id
    private BigInteger id;
 
    @OneToMany(fetch=FetchType.EAGER, mappedBy="address",cascade=CascadeType.ALL)
    Collection<Employee> employees;
 
    @PrePersist
    // 256277: test prePersist with a nested persist
    public void prePersist() {
        name = "name"; 
        // get a reference to the entityManager and perform a persist inside this prePersist
        EntityManager entityManager = TestClient.staticEntityManager;
        processQuery(entityManager);
    }
 
    private void processQuery(EntityManager entityManager) {
        Query aQuery = null;
        List<Employee> rowsList = null;
        try {
            aQuery = entityManager.createQuery("select object(e) from Employee e");
/** we don't need the results from the query
    we just require the query action to pre flush() uncommitted changes
*/
            rowsList = aQuery.getResultList();
         } catch (Exception e) {
            e.printStackTrace();
        }
    }
 
}
 
@Entity
public class ParkingSpace implements Serializable {
    @Id
    private BigInteger id;
}
 
@Entity
public class Phone implements Serializable {
    @Id
    private BigInteger id;
 
    @ManyToOne
    Employee employee;
}

Use Case 1: Persist unmanaged entity (with @PrePersist query) referenced by managed entity

Reproduction Source

• Here there is a managed source entity that has some uncommitted changes
• There is an unmanaged target entity that has a @PrePersist callback method that contains a query on the source
• We do a final flush() or commit()
• The result is that the @PrePersist method causes it's own flush() within a flush() - we need to disallow this.

Use Case 2: Persist other Entity (with its own @PrePersist and persist) inside @PrePersist callback

Source

This use case currently causes an infinite loop on the following line up to build 20090105.

    EntityClassListener(EntityListener).prePersist(DescriptorEvent) line: 412

StackTrace

TestClient [Java Application]	
	org.eclipse.persistence.example.TestClient at localhost:2561	
		Thread [main] (Suspended (breakpoint at line 112 in Cell))	
			Cell.processInsert(EntityManager) line: 112	
			Cell.prePersist() line: 69	
			NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
			NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39	
			DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25	
			Method.invoke(Object, Object...) line: 597	
			PrivilegedAccessHelper.invokeMethod(Method, Object, Object[]) line: 344	
			EntityClassListener(EntityListener).invokeMethod(Method, Object, Object[], DescriptorEvent) line: 297	
			EntityClassListener.invokeMethod(String, DescriptorEvent) line: 64	
			EntityClassListener(EntityListener).prePersist(DescriptorEvent) line: 412	
			DescriptorEventManager.notifyListener(DescriptorEventListener, DescriptorEvent) line: 650	
			DescriptorEventManager.notifyEJB30Listeners(DescriptorEvent) line: 593	
			DescriptorEventManager.executeEvent(DescriptorEvent) line: 187	
			RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectClone(Object, Object, ClassDescriptor) line: 3980	
			RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 3959	
			RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 336	
			RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectForPersist(Object, Map) line: 3903	
			EntityManagerImpl.persist(Object) line: 254	
			Cell.processInsert(EntityManager) line: 121	
			Cell.prePersist() line: 69	
...
			Cell.prePersist() line: 69	
			NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
			NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39	
			DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25	
			Method.invoke(Object, Object...) line: 597	
			PrivilegedAccessHelper.invokeMethod(Method, Object, Object[]) line: 344	
			EntityClassListener(EntityListener).invokeMethod(Method, Object, Object[], DescriptorEvent) line: 297	
			EntityClassListener.invokeMethod(String, DescriptorEvent) line: 64	
			EntityClassListener(EntityListener).prePersist(DescriptorEvent) line: 412	
			DescriptorEventManager.notifyListener(DescriptorEventListener, DescriptorEvent) line: 650	
			DescriptorEventManager.notifyEJB30Listeners(DescriptorEvent) line: 593	
			DescriptorEventManager.executeEvent(DescriptorEvent) line: 187	
			RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectClone(Object, Object, ClassDescriptor) line: 3980	
			RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 3959	
			RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 336	
			RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectForPersist(Object, Map) line: 3903	
			EntityManagerImpl.persist(Object) line: 254	
			TestClient.processInsert() line: 176	
			TestClient.doQuery() line: 254	
			TestClient.main(String[]) line: 247	
	C:\jdk1.6.0\bin\javaw.exe (Jan 5, 2009 1:10:19 PM)	

Logs

[EL Finest]: 2009.01.05 13:09:22.915--UnitOfWork(2804823)--Thread(Thread[main,5,main])--assign sequence to the object (1,210 -> org.eclipse.persistence.example.business.Cell@11024915( id: null state: null left: null right: null))
[EL Finest]: 2009.01.05 13:09:22.915--UnitOfWork(2804823)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.Cell@8180602( id: null state: null left: null right: null).
[EL Finest]: 2009.01.05 13:09:22.930--UnitOfWork(2804823)--Thread(Thread[main,5,main])--assign sequence to the object (1,211 -> org.eclipse.persistence.example.business.Cell@8180602( id: null state: null left: null right: null))
Exception in thread "main" java.lang.StackOverflowError
	at java.text.DecimalFormat.setMinimumIntegerDigits(DecimalFormat.java:2677)
	at java.text.SimpleDateFormat.zeroPaddingNumber(SimpleDateFormat.java:1184)
	at java.text.SimpleDateFormat.subFormat(SimpleDateFormat.java:1125)
	at java.text.SimpleDateFormat.format(SimpleDateFormat.java:882)
	at java.text.SimpleDateFormat.format(SimpleDateFormat.java:852)
	at java.text.DateFormat.format(DateFormat.java:316)
	at org.eclipse.persistence.logging.AbstractSessionLog.getDateString(AbstractSessionLog.java:644)
	at org.eclipse.persistence.logging.AbstractSessionLog.getSupplementDetailString(AbstractSessionLog.java:654)
	at org.eclipse.persistence.logging.DefaultSessionLog.log(DefaultSessionLog.java:130)
	at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:2492)
	at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3579)
	at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3551)
	at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3527)
	at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3449)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.logDebugMessage(UnitOfWorkImpl.java:5106)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNotRegisteredNewObjectForPersist(UnitOfWorkImpl.java:3945)
	at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(RepeatableWriteUnitOfWork.java:336)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNewObjectForPersist(UnitOfWorkImpl.java:3903)
	at org.eclipse.persistence.internal.jpa.EntityManagerImpl.persist(EntityManagerImpl.java:254)
	at org.eclipse.persistence.example.business.Cell.processInsert(Cell.java:121)
	at org.eclipse.persistence.example.business.Cell.prePersist(Cell.java:69)
	at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.eclipse.persistence.internal.security.PrivilegedAccessHelper.invokeMethod(PrivilegedAccessHelper.java:344)
	at org.eclipse.persistence.internal.jpa.metadata.listeners.EntityListener.invokeMethod(EntityListener.java:297)
	at org.eclipse.persistence.internal.jpa.metadata.listeners.EntityClassListener.invokeMethod(EntityClassListener.java:64)
	at org.eclipse.persistence.internal.jpa.metadata.listeners.EntityListener.prePersist(EntityListener.java:412)
	at org.eclipse.persistence.descriptors.DescriptorEventManager.notifyListener(DescriptorEventManager.java:650)
	at org.eclipse.persistence.descriptors.DescriptorEventManager.notifyEJB30Listeners(DescriptorEventManager.java:593)
	at org.eclipse.persistence.descriptors.DescriptorEventManager.executeEvent(DescriptorEventManager.java:187)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNewObjectClone(UnitOfWorkImpl.java:3980)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNotRegisteredNewObjectForPersist(UnitOfWorkImpl.java:3959)
	at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(RepeatableWriteUnitOfWork.java:336)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNewObjectForPersist(UnitOfWorkImpl.java:3903)
	at org.eclipse.persistence.internal.jpa.EntityManagerImpl.persist(EntityManagerImpl.java:254)
	at org.eclipse.persistence.example.business.Cell.processInsert(Cell.java:121)
	at org.eclipse.persistence.example.business.Cell.prePersist(Cell.java:69)
	at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.eclipse.persistence.internal.security.PrivilegedAccessHelper.invokeMethod(PrivilegedAccessHelper.java:344)
	at org.eclipse.persistence.internal.jpa.metadata.listeners.EntityListener.invokeMethod(EntityListener.java:297)
	at org.eclipse.persistence.internal.jpa.metadata.listeners.EntityClassListener.invokeMethod(EntityClassListener.java:64)
	at org.eclipse.persistence.internal.jpa.metadata.listeners.EntityListener.prePersist(EntityListener.java:412)
	at org.eclipse.persistence.descriptors.DescriptorEventManager.notifyListener(DescriptorEventManager.java:650)
	at org.eclipse.persistence.descriptors.DescriptorEventManager.notifyEJB30Listeners(DescriptorEventManager.java:593)
	at org.eclipse.persistence.descriptors.DescriptorEventManager.executeEvent(DescriptorEventManager.java:187)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNewObjectClone(UnitOfWorkImpl.java:3980)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNotRegisteredNewObjectForPersist(UnitOfWorkImpl.java:3959)
	at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(RepeatableWriteUnitOfWork.java:336)
	at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerNewObjectForPersist(UnitOfWorkImpl.java:3903)
	at org.eclipse.persistence.internal.jpa.EntityManagerImpl.persist(EntityManagerImpl.java:254)
	at org.eclipse.persistence.example.business.Cell.processInsert(Cell.java:121)
	at org.eclipse.persistence.example.business.Cell.prePersist(Cell.java:69)
	at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)

Use Case 3: Persist other Entity (with a @PrePersist without a persist) inside @PrePersist callback

Source

The @PrePersist of the first entity will cause a persist of the second entity that also has it's own @PrePersist (but without another persist).

Normal functionality with no infinite loop.

Use Case 4: Persist other Entity (without its own @PrePersist) inside @PrePersist

Normal functionality with no infinite loop.

Use Case 5: @PrePersist calls another @PrePersist on a referenced entity

Analysis Constraints

Concurrency and Thread Safety

The entityManagerFactory is thread-safe, the entityManager is not. However, the boolean flag withinFlush is a non-static field on each instance of EntityManager so as long as the lifecyle of the entityManager is thread-safe then the addition of this flag will have no issues.

Design / Functionality

Alternative 1: No flush() within a flush()

We will not perform nested flush() calls, a break will be required and a warning will printed if the entityManager is in FlushModeType.AUTO.

We will accomplish this by adding a boolean flag withinFlush to the EntityManagerImpl class that will be true for the lifetime of any flush() call. We will check this flag before issuing a flush in the preparation within EJBQueryImpl.executeReadQuery() - which occurs in the case that a query requires pending uncommitted changes written before running it's query. This would happen if a query or persist were done inside of a @PrePersist callback method.

- deprecated in favor of alternative 2:

Alternative 2: No nested flush in RepeatableWriteUnitOfWork

The call to calculateChanges() can be recursive before we even get to commitToDatabaseWithPreBuiltChangeSet(). In this case we will commit in a PrePersist and then later fail on a second commit. We therefore need to move the flag set before the try/catch block.

we now set the flag before calculateChanges and clear it in two places

• - when we dont commit anything on an early return - just before the return
• - when we commit changes - in the finally block

Thread [main] (Suspended (breakpoint at line 293 in RepeatableWriteUnitOfWork))	
	RepeatableWriteUnitOfWork.writeChanges() line: 293	

	EntityManagerImpl.flush() line: 534
	EJBQueryImpl.performPreQueryFlush() line: 1038	
	EJBQueryImpl.executeReadQuery() line: 347	
	EJBQueryImpl.getResultList() line: 592	
	Address.processQuery(EntityManager) line: 83	
	Address.prePersist() line: 73	
	NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
	NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39	
	DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25	
	Method.invoke(Object, Object...) line: 597	
	PrivilegedAccessHelper.invokeMethod(Method, Object, Object[]) line: 344	
	EntityClassListener(EntityListener).invokeMethod(Method, Object, Object[], DescriptorEvent) line: 297	
	EntityClassListener.invokeMethod(String, DescriptorEvent) line: 64	
	EntityClassListener(EntityListener).prePersist(DescriptorEvent) line: 412	
	DescriptorEventManager.notifyListener(DescriptorEventListener, DescriptorEvent) line: 650	
	DescriptorEventManager.notifyEJB30Listeners(DescriptorEvent) line: 593	
	DescriptorEventManager.executeEvent(DescriptorEvent) line: 187	
	RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectClone(Object, Object, ClassDescriptor) line: 3976	
	RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 3955	
	RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 356	
	RepeatableWriteUnitOfWork(UnitOfWorkImpl).discoverAndPersistUnregisteredNewObjects(Object, boolean, Map, Map, Map) line: 3857	
	OneToOneMapping(ObjectReferenceMapping).cascadeDiscoverAndPersistUnregisteredNewObjects(Object, Map, Map, Map, UnitOfWorkImpl) line: 713	
	ObjectBuilder.cascadeDiscoverAndPersistUnregisteredNewObjects(Object, Map, Map, Map, UnitOfWorkImpl) line: 1493	
	RepeatableWriteUnitOfWork(UnitOfWorkImpl).discoverAndPersistUnregisteredNewObjects(Object, boolean, Map, Map, Map) line: 3871	
	RepeatableWriteUnitOfWork.discoverUnregisteredNewObjects(Map, Map, Map, Map) line: 182	
	RepeatableWriteUnitOfWork(UnitOfWorkImpl).calculateChanges(Map, UnitOfWorkChangeSet, boolean) line: 613	
	RepeatableWriteUnitOfWork.writeChanges() line: 304	

	EntityManagerImpl.flush() line: 534	
	TestClient.prePersistQuery() line: 105	
	TestClient.main(String[]) line: 128	

Sequence: flush() calls flush() because of uncommitted changes

• - flush
• - flag is set
• - calculateChanges called
• - flush 2 has no effect
• - changes committed
• - flag cleared in finally block

Sequence: flush() calls flush() but no changes were uncommitted

• - flush
• - flag is set
• - calculateChanges called
• - flush 2 has no effect
• - changes not done
• - flag cleared before return
• - we return early before the commit

Sequence: single flush() call with changes

• - flush
• - flag is set
• - calculateChanges called
• - changes committed
• - flag cleared in finally block

Sequence: single flush() call with no changes

• - flush
• - flag is set
• - calculateChanges called
• - changes not done
• - flag cleared before return
• - we return early before the commit

Implementation

• A new boolean field will be introduced on EntityManagerImpl.java

    /** Track whether we are already in a flush() */
    protected boolean withinFlush;

that will be set inside flush() just before writeChanges() to true and then reset to false on the finaly block. The use of this flag will be thread safe as far as the entityManager instance is used in a thread safe manner.

EJBQueryImpl when executing a read (possibly from a @PrePersist callback) will check that it is not already in a flush() before doing a pre-flush() - normally done so that any outstanding (uncommitted) changes are included in this query.

public class EJBQueryImpl implements org.eclipse.persistence.jpa.JpaQuery {
    protected Object executeReadQuery() {
...
        if (isFlushModeAUTO()) {
            // 256277: we do not allow nested flush() calls             
            if(!this.entityManager.withinFlush) {
                performPreQueryFlush();
            } else {
                AbstractSessionLog.getLog().log(SessionLog.WARNING,
                        "nested_entity_manager_flush_not_executed_pre_query_changes_may_be_pending", entityManager);
            }

Logging

The following log will not be used.

 this.entityManager.getServerSession().log(SessionLog.WARNING, 
     SessionLog.QUERY, "nested_entity_manager_flush_not_executed_pre_query_changes_may_be_pending");

The following log will be used.

 AbstractSessionLog.getLog().log(SessionLog.WARNING,
     "nested_entity_manager_flush_not_executed_pre_query_changes_may_be_pending", entityManager);

The output will be the following

[EL Warning]: 2009.01.11 21:36:21.786--Thread(Thread[main,5,main])--The em: org.eclipse.persistence.internal.jpa.EntityManagerImpl@1777b1 is already flushing. The query will be executed without further changes being written to the database. If the query is conditional upon changed data the changes may not be reflected in the results. Users should issue a flush() call upon completion of the dependent changes and prior to this flush() to ensure correct results.

Testing

JPA LRG passes

Core LRG passes

Static Weaved reproduction passes

Use Case 1: Output of nested flush()

The following logs and stacktrace illustrate the current nested flush() behavior when performing a @PrePersist containing a query that requires a flush() on uncommitted managed entity changes.

Client Code

Client code is persisting 2 Cell entities that themselves persist new Cell entities in their @PrePersist method.

    private void prePersistQuery() {
        EntityManagerFactory entityManagerFactory = Persistence.createEntityManagerFactory(PU_NAME_IN_USE);
        EntityManager em = entityManagerFactory.createEntityManager();
        staticEntityManager = em;
        try {
            // create 2 cells (to avoid performance optimization for 1 entity)  and link them
                em.getTransaction().begin();
 
                Employee left = new Employee();
                Employee right = new Employee();
 
                // Relationship: Employee --> 1-1 ParkingSpace
                ParkingSpace parkingSpace = new ParkingSpace();
 
                // Relationship: Employee <--> 1-n Phone
                List<Phone> phones = new ArrayList<Phone>();
                Phone phone1 = new Phone();
                Phone phone2 = new Phone();
                // Reverse relationship
                List<Employee> phoneEmployees = new ArrayList<Employee>();
                phoneEmployees.add(right);
 
                // Relationship: Employee <--> 1-1 Address                
                Address address = new Address();
                // Reverse relationship
                List<Employee> addressEmployees = new ArrayList<Employee>();
                addressEmployees.add(right);
 
                // Before merging objects, set any relationships
                right.setParkingSpace(parkingSpace);
 
                // persist the managed source
                em.persist(left);
                em.persist(right);            
 
                // modify the managed entity
                right.setName("unnamed");
                right.setParkingSpace(null);//parkingSpace);
                right.setAddress(address);
                // set reverse
                address.setEmployees(addressEmployees);
 
                phones.add(phone1);
                phones.add(phone2);
                right.setPhones(phones);
                // set reverse
                phone1.setEmployee(right);
                phone2.setEmployee(right);
                // Store objects
                // Note: a flush here will invoke a nested flush during the PrePersist without the changes for bug# 256277
                em.flush();
                em.getTransaction().commit();
        } catch (Exception e) {
            System.out.println("Exception " + e.getMessage());
            e.printStackTrace();
        } finally {
            em.close();
            entityManagerFactory.close();
        }
    }

Logs

[EL Finest]: 2009.01.11 21:36:21.483--UnitOfWork(7634850)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.Employee@18433730( id: null).
[EL Finest]: 2009.01.11 21:36:21.484--ClientSession(28524838)--Thread(Thread[main,5,main])--Execute query ValueReadQuery(sql="SELECT EL_EMPLOYEE_SEQ.NEXTVAL FROM DUAL")
[EL Fine]: 2009.01.11 21:36:21.484--ServerSession(12097592)--Connection(29752800)--Thread(Thread[main,5,main])--SELECT EL_EMPLOYEE_SEQ.NEXTVAL FROM DUAL
[EL Finest]: 2009.01.11 21:36:21.491--ServerSession(12097592)--Thread(Thread[main,5,main])--sequencing preallocation for EL_EMPLOYEE_SEQ: objects: 25 , first: 1, last: 25
[EL Finest]: 2009.01.11 21:36:21.491--UnitOfWork(7634850)--Thread(Thread[main,5,main])--assign sequence to the object (1 -> org.eclipse.persistence.example.business.Employee@18433730( id: null))
[EL Finest]: 2009.01.11 21:36:21.495--UnitOfWork(7634850)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.Employee@21684929( id: null).
[EL Finest]: 2009.01.11 21:36:21.495--UnitOfWork(7634850)--Thread(Thread[main,5,main])--assign sequence to the object (2 -> org.eclipse.persistence.example.business.Employee@21684929( id: null))
[EL Finest]: 2009.01.11 21:36:21.495--UnitOfWork(7634850)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.ParkingSpace@23930626( id: null).
[EL Finest]: 2009.01.11 21:36:21.495--ClientSession(28524838)--Thread(Thread[main,5,main])--Execute query ValueReadQuery(sql="SELECT EL_PARKINGSPACE_SEQ.NEXTVAL FROM DUAL")
[EL Fine]: 2009.01.11 21:36:21.496--ServerSession(12097592)--Connection(5324129)--Thread(Thread[main,5,main])--SELECT EL_PARKINGSPACE_SEQ.NEXTVAL FROM DUAL
[EL Finest]: 2009.01.11 21:36:21.498--ServerSession(12097592)--Thread(Thread[main,5,main])--sequencing preallocation for EL_PARKINGSPACE_SEQ: objects: 25 , first: 1, last: 25
[EL Finest]: 2009.01.11 21:36:21.499--UnitOfWork(7634850)--Thread(Thread[main,5,main])--assign sequence to the object (1 -> org.eclipse.persistence.example.business.ParkingSpace@23930626( id: null))
[EL Finest]: 2009.01.11 21:36:21.501--UnitOfWork(7634850)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.Address@15594377( id: null).
[EL Finest]: 2009.01.11 21:36:21.502--ClientSession(28524838)--Thread(Thread[main,5,main])--Execute query ValueReadQuery(sql="SELECT EL_ADDRESS_SEQ.NEXTVAL FROM DUAL")
[EL Fine]: 2009.01.11 21:36:21.502--ServerSession(12097592)--Connection(29752800)--Thread(Thread[main,5,main])--SELECT EL_ADDRESS_SEQ.NEXTVAL FROM DUAL
[EL Finest]: 2009.01.11 21:36:21.504--ServerSession(12097592)--Thread(Thread[main,5,main])--sequencing preallocation for EL_ADDRESS_SEQ: objects: 25 , first: 1, last: 25
[EL Finest]: 2009.01.11 21:36:21.504--UnitOfWork(7634850)--Thread(Thread[main,5,main])--assign sequence to the object (1 -> org.eclipse.persistence.example.business.Address@15594377( id: null))
[EL Warning]: 2009.01.11 21:36:21.786--Thread(Thread[main,5,main])--The em: org.eclipse.persistence.internal.jpa.EntityManagerImpl@1777b1 is already flushing. The query will be executed without further changes being written to the database.  If the query is conditional upon changed data the changes may not be reflected in the results.  Users should issue a flush() call upon completion of the dependent changes and prior to this flush() to ensure correct results.
[EL Finest]: 2009.01.11 21:36:21.787--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query ReadAllQuery(referenceClass=Employee sql="SELECT ID, NAME, ADDRESS_ID, PARKINGSPACE_ID FROM EL_EMPLOYEE")
[EL Fine]: 2009.01.11 21:36:21.789--ServerSession(12097592)--Connection(5324129)--Thread(Thread[main,5,main])--SELECT ID, NAME, ADDRESS_ID, PARKINGSPACE_ID FROM EL_EMPLOYEE
_Address.prePersist() complete: org.eclipse.persistence.example.business.Address@15594377( id: 1)
[EL Finest]: 2009.01.11 21:36:21.802--UnitOfWork(7634850)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.Phone@30008954( id: null).
[EL Finest]: 2009.01.11 21:36:21.802--ClientSession(28524838)--Thread(Thread[main,5,main])--Execute query ValueReadQuery(sql="SELECT EL_PHONE_SEQ.NEXTVAL FROM DUAL")
[EL Fine]: 2009.01.11 21:36:21.802--ServerSession(12097592)--Connection(29752800)--Thread(Thread[main,5,main])--SELECT EL_PHONE_SEQ.NEXTVAL FROM DUAL
[EL Finest]: 2009.01.11 21:36:21.805--ServerSession(12097592)--Thread(Thread[main,5,main])--sequencing preallocation for EL_PHONE_SEQ: objects: 25 , first: 1, last: 25
[EL Finest]: 2009.01.11 21:36:21.805--UnitOfWork(7634850)--Thread(Thread[main,5,main])--assign sequence to the object (1 -> org.eclipse.persistence.example.business.Phone@30008954( id: null))
_Phone.prePersist() complete: org.eclipse.persistence.example.business.Phone@30008954( id: 1)
[EL Finest]: 2009.01.11 21:36:21.806--UnitOfWork(7634850)--Thread(Thread[main,5,main])--PERSIST operation called on: org.eclipse.persistence.example.business.Phone@3823508( id: null).
[EL Finest]: 2009.01.11 21:36:21.806--UnitOfWork(7634850)--Thread(Thread[main,5,main])--assign sequence to the object (2 -> org.eclipse.persistence.example.business.Phone@3823508( id: null))
_Phone.prePersist() complete: org.eclipse.persistence.example.business.Phone@3823508( id: 2)
[EL Finer]: 2009.01.11 21:36:21.807--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--begin transaction
[EL Finest]: 2009.01.11 21:36:21.808--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(org.eclipse.persistence.example.business.Address@15594377( id: 1))
[EL Fine]: 2009.01.11 21:36:21.808--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--INSERT INTO EL_ADDRESS (ID, NAME) VALUES (?, ?)
	bind => [1, name]
[EL Finest]: 2009.01.11 21:36:21.862--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(org.eclipse.persistence.example.business.ParkingSpace@23930626( id: 1))
[EL Fine]: 2009.01.11 21:36:21.863--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--INSERT INTO EL_PARKINGSPACE (ID, PARKINGNUMBER) VALUES (?, ?)
	bind => [1, null]
[EL Finest]: 2009.01.11 21:36:21.866--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(org.eclipse.persistence.example.business.Employee@18433730( id: 1))
[EL Fine]: 2009.01.11 21:36:21.866--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--INSERT INTO EL_EMPLOYEE (ID, NAME, ADDRESS_ID, PARKINGSPACE_ID) VALUES (?, ?, ?, ?)
	bind => [1, null, null, null]
[EL Finest]: 2009.01.11 21:36:21.919--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(org.eclipse.persistence.example.business.Employee@21684929( id: 2))
[EL Finest]: 2009.01.11 21:36:21.919--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query WriteObjectQuery(org.eclipse.persistence.example.business.Address@15594377( id: 1))
[EL Fine]: 2009.01.11 21:36:21.919--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--INSERT INTO EL_EMPLOYEE (ID, NAME, ADDRESS_ID, PARKINGSPACE_ID) VALUES (?, ?, ?, ?)
	bind => [2, xxxx, 1, null]
[EL Finest]: 2009.01.11 21:36:21.924--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(org.eclipse.persistence.example.business.Phone@30008954( id: 1))
[EL Finest]: 2009.01.11 21:36:21.924--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query WriteObjectQuery(org.eclipse.persistence.example.business.Employee@21684929( id: 2))
[EL Fine]: 2009.01.11 21:36:21.925--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--INSERT INTO EL_PHONE (ID, PHONENUMBER, EMPLOYEE_ID) VALUES (?, ?, ?)
	bind => [1, 0000000, 2]
[EL Finest]: 2009.01.11 21:36:21.949--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query InsertObjectQuery(org.eclipse.persistence.example.business.Phone@3823508( id: 2))
[EL Finest]: 2009.01.11 21:36:21.950--UnitOfWork(7634850)--Thread(Thread[main,5,main])--Execute query WriteObjectQuery(org.eclipse.persistence.example.business.Employee@21684929( id: 2))
[EL Fine]: 2009.01.11 21:36:21.950--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--INSERT INTO EL_PHONE (ID, PHONENUMBER, EMPLOYEE_ID) VALUES (?, ?, ?)
	bind => [2, 0000000, 2]
[EL Finer]: 2009.01.11 21:36:21.952--UnitOfWork(7634850)--Thread(Thread[main,5,main])--begin unit of work commit
[EL Finer]: 2009.01.11 21:36:21.961--ClientSession(28524838)--Connection(19432672)--Thread(Thread[main,5,main])--commit transaction

StackTrace before change

This stacktrace is before changes were done to disallow nested flush() calls - notice the second flush()

org.eclipse.persistence.example.TestClient at localhost:64236	
	Thread [main] (Suspended)	
		CommitManager.commitChangedObjectsForClassWithChangeSet(UnitOfWorkChangeSet, String) line: 236	
		CommitManager.commitAllObjectsForClassWithChangeSet(UnitOfWorkChangeSet, Class) line: 163	
		CommitManager.commitAllObjectsWithChangeSet(UnitOfWorkChangeSet) line: 116	
		RepeatableWriteUnitOfWork(AbstractSession).writeAllObjectsWithChangeSet(UnitOfWorkChangeSet) line: 3175	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).commitToDatabase(boolean) line: 1271	
		RepeatableWriteUnitOfWork.commitToDatabase(boolean) line: 445	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkChangeSet, boolean) line: 1407	
		RepeatableWriteUnitOfWork.writeChanges() line: 295	
		EntityManagerImpl.flush() line: 543	
		EJBQueryImpl.performPreQueryFlush() line: 1046	
		EJBQueryImpl.executeReadQuery() line: 351	
		EJBQueryImpl.getResultList() line: 600	
		Address.processQuery(EntityManager) line: 83	
		Address.prePersist() line: 73	
		NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
		NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39	
		DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25	
		Method.invoke(Object, Object...) line: 597	
		PrivilegedAccessHelper.invokeMethod(Method, Object, Object[]) line: 344	
		EntityClassListener(EntityListener).invokeMethod(Method, Object, Object[], DescriptorEvent) line: 297	
		EntityClassListener.invokeMethod(String, DescriptorEvent) line: 64	
		EntityClassListener(EntityListener).prePersist(DescriptorEvent) line: 412	
		DescriptorEventManager.notifyListener(DescriptorEventListener, DescriptorEvent) line: 650	
		DescriptorEventManager.notifyEJB30Listeners(DescriptorEvent) line: 593	
		DescriptorEventManager.executeEvent(DescriptorEvent) line: 187	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectClone(Object, Object, ClassDescriptor) line: 3976	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 3955	
		RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 336	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).discoverAndPersistUnregisteredNewObjects(Object, boolean, Map, Map, Map) line: 3857	
		OneToOneMapping(ObjectReferenceMapping).cascadeDiscoverAndPersistUnregisteredNewObjects(Object, Map, Map, Map, UnitOfWorkImpl) line: 713	
		ObjectBuilder.cascadeDiscoverAndPersistUnregisteredNewObjects(Object, Map, Map, Map, UnitOfWorkImpl) line: 1493	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).discoverAndPersistUnregisteredNewObjects(Object, boolean, Map, Map, Map) line: 3871	
		RepeatableWriteUnitOfWork.discoverUnregisteredNewObjects(Map, Map, Map, Map) line: 174	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).calculateChanges(Map, UnitOfWorkChangeSet, boolean) line: 613	
		RepeatableWriteUnitOfWork.writeChanges() line: 289	
		EntityManagerImpl.flush() line: 543	
		TestClient.prePersistQuery() line: 105	
		TestClient.main(String[]) line: 128	
	

StackTrace after changes

Notice that there is no second flush.

org.eclipse.persistence.example.TestClient at localhost:3173	
	Thread [main] (Suspended (breakpoint at line 353 in EJBQueryImpl))	
		EJBQueryImpl.executeReadQuery() line: 353	
		EJBQueryImpl.getResultList() line: 600	
		Address.processQuery(EntityManager) line: 83	
		Address.prePersist() line: 73	
		NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
		NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39	
		DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25	
		Method.invoke(Object, Object...) line: 597	
		PrivilegedAccessHelper.invokeMethod(Method, Object, Object[]) line: 344	
		EntityClassListener(EntityListener).invokeMethod(Method, Object, Object[], DescriptorEvent) line: 297	
		EntityClassListener.invokeMethod(String, DescriptorEvent) line: 64	
		EntityClassListener(EntityListener).prePersist(DescriptorEvent) line: 412	
		DescriptorEventManager.notifyListener(DescriptorEventListener, DescriptorEvent) line: 650	
		DescriptorEventManager.notifyEJB30Listeners(DescriptorEvent) line: 593	
		DescriptorEventManager.executeEvent(DescriptorEvent) line: 187	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNewObjectClone(Object, Object, ClassDescriptor) line: 3976	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 3955	
		RepeatableWriteUnitOfWork.registerNotRegisteredNewObjectForPersist(Object, ClassDescriptor) line: 336	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).discoverAndPersistUnregisteredNewObjects(Object, boolean, Map, Map, Map) line: 3857	
		OneToOneMapping(ObjectReferenceMapping).cascadeDiscoverAndPersistUnregisteredNewObjects(Object, Map, Map, Map, UnitOfWorkImpl) line: 713	
		ObjectBuilder.cascadeDiscoverAndPersistUnregisteredNewObjects(Object, Map, Map, Map, UnitOfWorkImpl) line: 1493	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).discoverAndPersistUnregisteredNewObjects(Object, boolean, Map, Map, Map) line: 3871	
		RepeatableWriteUnitOfWork.discoverUnregisteredNewObjects(Map, Map, Map, Map) line: 174	
		RepeatableWriteUnitOfWork(UnitOfWorkImpl).calculateChanges(Map, UnitOfWorkChangeSet, boolean) line: 613	
		RepeatableWriteUnitOfWork.writeChanges() line: 289	
		EntityManagerImpl.flush() line: 543	
		TestClient.prePersistQuery() line: 105	
		TestClient.main(String[]) line: 128	

API

GUI

Config files

Testing Java SE JPA applications with Weaving on

Statically weave entities using an ant task

    <target name="run-weaver">
        <!-- define weaving ant task-->
        <taskdef name="weave" classname="org.eclipse.persistence.tools.weaving.jpa.StaticWeaveAntTask">
            <classpath>
                <pathelement path="persistence.jar"/>
		<pathelement path="eclipselink.jar"/>
		<pathelement path="persistence_1_0.xsd"/>
            </classpath>
        </taskdef>
        <!-- process the weaving function, persistenceInfo references persistence.xml -->
        <weave source="c:/wse/staticweave/build/classes_unweaved"
               target="c:/wse/staticweave/build/classes"
               persistenceinfo="c:/wse/staticweave/build/jars/app_unweaved.jar"
	       loglevel="FINEST">
        </weave>
	</target>

Run static weaver

ant -lib "c:\wse\staticweave" -f build.xml run-weaver

Add the javaagent instrumentation flag to run target

-javaagent:C:\view_w34r1d\eclipselink.jar

Increase the Native Stack Size using the -Xss JVM parameter

• You will decrease the chance of getting a StackOverflowError for highly connected Entity models like rings or bidirectional trees or arrays by increasing the native stack size.
  • I have found that increasing the stack to the value below pushed the StackOverflowError experienced in a bidirectionally linked 6 dimensional Hypercube model (64 entities) to a 13 dimensional Hypercube (8192 entities) in bug# 310662.
    • -Xss42m (Native cache size)
    • -Xoss42m had no effect (Java cache size)

Documentation

Open Issues

Decisions

Future Considerations

During the research for this bug, the following items were identified as out of scope but are captured here as potential future enhancements. If agreed upon during the review process these should be logged in the bug system.

References

• EclipseLink Fisheye Revision 3202