Error pulling back records with FetchType=LAZY

[Kevin Lester]

We're testing EclipseLink 1.1, and we're getting an error while retrieving child records that are marked as lazy.  Specifically we receive the following error:
ECLIPSELINK-02004: A signal was attempted before wait() on ConcurrencyManager. This normally means that an attempt was made to {0}commit or rollback a transaction before it was started, or to rollback a transaction twice.

The error gets thrown from a line of code like the following: parent.getChildren().size();
The getChildren() method returns a Set of Child objects that have a fetchType of LAZY.  This code used to work with EclipseLink 1.0.2.

To debug the issue, I created a small test project that recreates the situation in which we see the error.  The code for the test project is below.  An error gets thrown on the expected line of code in my test project - but interestingly it is a different error than we get in our application.  I was not able to reproduce the exact error in my test project for some reason.  Test project code below:


----------------------------EclipseLinkLazyTester class ----------------------------------------
public class EclipseLinkLazyTester {
  protected static EntityManagerFactory emf;
  private static Logger logger = Logger.getLogger(EclipseLinkLazyTester.class);
  private static final String PERSISTENCE_UNIT = "testPersistenceUnit";
  private static final int NUM_EMPLOYEES=59999;
 
  private Manager manager1 = null;
  private Manager manager2 = null;
 
  @BeforeClass
  public static void initialize(){
    System.setProperty("LOG_DIR", System.getProperty("user.dir"));
   
    //set up the DB datasource
    setupInitialContext();
   
    //Set up the entity manager factory
    logger.info("persistanceUnitName: " + PERSISTENCE_UNIT);
    emf = Persistence.createEntityManagerFactory(PERSISTENCE_UNIT);
  }  
 
  private void insertDBRecords(){
    manager1 = new Manager();
    manager1.setName("Homer");
    manager1.setDept("Sector 7-G");
   
    manager2 = new Manager();
    manager2.setName("Carl");
    manager2.setDept("Sector 7-G");
   
    //Fill the employees
    try{
      ExecutorService execService=Executors.newFixedThreadPool(2);
      CompletionService<Manager> fillManagerSvc = new ExecutorCompletionService<Manager>(execService);
           
      fillManagerSvc.submit(new EmpCreator(manager1, NUM_EMPLOYEES));
      fillManagerSvc.submit(new EmpCreator(manager2, NUM_EMPLOYEES));
      for (int counter = 0; counter < 2; counter ++){
        fillManagerSvc.take().get();
      }
    } catch (Exception e){
      logger.error("Error occurred filling the manager with Employees");
      System.exit(1);
    }
   
    try{
      ExecutorService execService2=Executors.newFixedThreadPool(2);
      CompletionService<Manager> updateManagerSvc = new ExecutorCompletionService<Manager>(execService2);
 
      updateManagerSvc.submit(new ManagerUpdater(manager1));
      updateManagerSvc.submit(new ManagerUpdater(manager2));
      for (int counter = 0; counter < 2; counter++){
        Manager manager = updateManagerSvc.take().get();
        System.out.println("Manager " + manager.getName() + " filled");
       }
    } catch (Exception e){
      logger.error("Error occurred updating the manager", e);
      System.exit(1);      
    }
  }
   
  public static void main(String[] args){
    EclipseLinkLazyTester lazyTester = new EclipseLinkLazyTester();
    EclipseLinkLazyTester.initialize();
    lazyTester.insertDBRecords();
  }
 
  @Before
  public void beforeTest(){
    try {
      manager1 = this.findManagerByName("Homer", "Sector 7-G");
      manager2 = this.findManagerByName("Carl", "Sector 7-G");
      System.out.println(manager1.getName() + "'s id = " + manager1.getManagerId());
      System.out.println(manager2.getName() + "'s id = " + manager2.getManagerId());
    } catch (Exception e) {
      e.printStackTrace();
      System.exit(1);
    }
  }
 
  @Test
  public void testGetEmployeesLazy(){
    try{
      Department dept1 = new Department(manager1);
      Department dept2 = new Department(manager2);
     
      updateDept(dept1);
      updateDept(dept2);
     
      ExecutorService updateManagerService=Executors.newFixedThreadPool(2);
      CompletionService<Manager> updateMgrSvc = new ExecutorCompletionService<Manager>(updateManagerService);
     
      ExecutorService execService=Executors.newFixedThreadPool(2);
      CompletionService<Manager> ecs = new ExecutorCompletionService<Manager>(execService);
      ecs.submit(new EmpRetriever(manager1, 0));
      ecs.submit(new EmpRetriever(manager2, 0));
      for (int counter = 0; counter < 2; counter++){
        Manager mgr = ecs.take().get();
        logger.info("Got employees for " + mgr.getName());
        updateMgrSvc.submit(new ManagerUpdater(mgr));
      }
      for (int counter = 0; counter < 2; counter++){
        Manager updatedManager = updateMgrSvc.take().get();
        logger.info("Manager " + updatedManager.getName() + " updated.");
      }
    }catch (Exception e){
      logger.error("Error occurred",e);
    }
  }
 
  private Employee createEmployee(Manager manager, String name, long now){
    Employee emp = new Employee();
    emp.setManager(manager);
    emp.setName(name);
    emp.setRank("peon");
    emp.setLastModified(now);
    return emp;
  }
   
  @SuppressWarnings("unchecked")
  private Manager findManagerByName(String name, String dept) throws Exception{
    EntityManager em = getNewEntityManager();
    try {
      Query q = em.createNamedQuery("GetManagerByNameDept");
      q.setParameter("name", name);
      q.setParameter("dept", dept);
      List<Manager> results = q.getResultList();
      if (results == null || results.size() == 0){
        return null;
      }
      if (results.size() != 1){
        //We have duplicate Build records in the DB, this is illegal
        String errorMsg = "Duplicate Manager records were found with name = " + name + " and department " + dept;
        logger.error(errorMsg);
        throw new Exception(errorMsg);
      }
      return (Manager) results.get(0);
    } finally {
      em.close();
    }
  }

  private Manager updateManager(Manager manager){
    EntityManager em = getNewEntityManager();
    try {
      em.getTransaction().begin();
      manager = em.merge(manager);
      em.getTransaction().commit();
      //Build newBuild=em.find(Build.class, inBuild.getBuildId());
      System.out.println("#Build files from manager in same session = " + manager.getEmployees().size());
    } finally {
      em.close();
    }
    //The manger will be the original object passed in but with the ids set properly (which could potentially modify the hashCode, depending on how it is implemented)
    //Since child objects were added prior to the ID being set, there is a chance that the child objects will not be
    //retrievable is they were stored in any Collections (because their hashcode affects their "bucket" in the collection).
    //So we need to return a new object back from scratch which has everything set correctly.
     return this.getManager(manager.getManagerId());
  }
 
  private Manager getManager(Integer managerId){
    EntityManager em = getNewEntityManager();
    try {
      return em.find(Manager.class, managerId);
    } finally {
      em.close();
    }
  }
 
  private Department updateDept(Department dept){
    EntityManager em = getNewEntityManager();
    try {
      em.getTransaction().begin();
      dept = em.merge(dept);
      em.getTransaction().commit();
    } finally {
      em.close();
    }
    //The dept will be the original object passed in but with the ids set properly (which could potentially modify the hashCode, depending on how it is implemented)
    //Since child objects were added prior to the ID being set, there is a chance that the child objects will not be
    //retrievable is they were stored in any Collections (because their hashcode affects their "bucket" in the collection).
    //So we need to return a new object back from scratch which has everything set correctly.
     return this.getDepartment(dept.getDeptId());
  }
 
  private Department getDepartment(Integer deptId){
    EntityManager em = getNewEntityManager();
    try {
      return em.find(Department.class, deptId);
    } finally {
      em.close();
    }
  }  
 
  public EntityManager getNewEntityManager() {
    EntityManager ret=emf.createEntityManager();
    /**
     * bug: http://forums.oracle.com/forums/thread.jspa?messageID=2284069
     * https://glassfish.dev.java.net/issues/show_bug.cgi?id=3937
     */
    return ret;
  }

  private static void setupInitialContext(){
    try {
      // Create initial context
      System.setProperty(Context.INITIAL_CONTEXT_FACTORY, "org.apache.naming.java.javaURLContextFactory");
      System.setProperty(Context.URL_PKG_PREFIXES, "org.apache.naming");
      InitialContext ic = new InitialContext();

      ic.createSubcontext("java:");
      ic.createSubcontext("java:/comp");
      ic.createSubcontext("java:/comp/env");
      ic.createSubcontext("java:/comp/env/jdbc");
     
      // Construct DataSource
      MysqlDataSource dataSource = new MysqlConnectionPoolDataSource();
      String dbURL=<dburl>;
      dataSource.setURL(dbURL);
      logger.info("Running test against db "+dbURL);
      dataSource.setUser(<user>);
      dataSource.setPassword(<password>);
      ic.bind("java:/comp/env/jdbc/testDs", dataSource);
    } catch (NamingException ex) {
      ex.printStackTrace();
      logger.error("Error occurred setting the datasource", ex);
    }
  }
 
  class EmpRetriever implements Callable<Manager>{
    private Manager manager;    
    private long delay;
   
    public EmpRetriever(Manager manager, long delay) {
      super();
      this.manager = manager;
      this.delay = delay;
    }

    public Manager call() {
      try {Thread.sleep(delay);} catch (InterruptedException e) {}
      logger.info("Thread for getting Employees for manager " + manager.getName() + " starting");
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
      return manager;
    }    
  }
   
  class ManagerUpdater implements Callable<Manager>{
    private Manager manager;    
    private long delay;
   
    public ManagerUpdater(Manager manager, long delay) {
      this.manager = manager;
      this.delay = delay;
    }

    public ManagerUpdater(Manager manager) {
      this(manager, 0);
    }

    public Manager call() {
      try {Thread.sleep(delay);} catch (InterruptedException e) {}
      logger.info("Thread for updating manager " + manager.getName() + " starting");
      manager = updateManager(manager);
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
      return manager;
    }
  }
 
  class EmpCreator implements Callable<Manager>{
    private Manager manager;
    private long numEmployees;
   
    public EmpCreator(Manager manager, long numEmployees) {
      this.manager = manager;
      this.numEmployees = numEmployees;
    }
   
    public Manager call(){
      for (int counter = 0; counter < numEmployees; counter++){
        manager.getEmployees().add(createEmployee(manager, "Emp_" + manager.getName() + "-" + counter, System.currentTimeMillis()));
      }
      return manager;
    }
  }
}

----------------------------Manager class ----------------------------------------
@Entity
@Table(name = "Manager")
@NamedQuery(name = "GetManagerByNameDept", query = "SELECT obj FROM Manager obj WHERE obj.name = :name and obj.dept = :dept")
public class Manager {
 
  @Id
  @Column(name = "managerId")
    @TableGenerator(
        name="MGR_ID_SEQ",
        table="SEQUENCE",
        allocationSize=1)
  @GeneratedValue(strategy = GenerationType.AUTO, generator = "MGR_ID_SEQ")
  private Integer managerId;
 
  private String name = null;
 
  private String dept = null;
 
  //Changing the FetchType to EAGER avoids the issue.
  @OneToMany (cascade=CascadeType.ALL, mappedBy="manager", fetch=FetchType.LAZY)
  @PrivateOwned
  private Set<Employee> employees = new HashSet<Employee>();

  public Integer getManagerId() {
    return managerId;
  }

  public void setManagerId(Integer managerId) {
    this.managerId = managerId;
  }

  public String getName() {
    return name;
  }

  public void setName(String name) {
    this.name = name;
  }

  public String getDept() {
    return dept;
  }

  public void setDept(String dept) {
    this.dept = dept;
  }

  public Set<Employee> getEmployees() {
    return employees;
  }

  public void setEmployees(Set<Employee> employees) {
    this.employees = employees;
  }  
}

----------------------------Employee class ----------------------------------------
@Entity
@Table(name = "Employee")
public class Employee {
 
  @Id
  @Column(name = "empId")
  @TableGenerator(
        name="EMP_ID_SEQ",
        table="SEQUENCE",
        allocationSize=100)
  @GeneratedValue(strategy = GenerationType.AUTO, generator = "EMP_ID_SEQ")
  private Integer empId;
 
  private String name = null;
 
  private String rank = null;
 
  @ManyToOne (cascade=CascadeType.REFRESH)
  @JoinColumn(name="managerId")
  private Manager manager = null;

  private long lastModified = 0L;
 
  public String getName() {
    return name;
  }

  public void setName(String name) {
    this.name = name;
  }

  public String getRank() {
    return rank;
  }

  public void setRank(String rank) {
    this.rank = rank;
  }

  public Manager getManager() {
    return manager;
  }

  public void setManager(Manager manager) {
    this.manager = manager;
  }

  public Integer getEmpId() {
    return empId;
  }

  public void setEmpId(Integer empId) {
    this.empId = empId;
  }

  public long getLastModified() {
    return lastModified;
  }

  public void setLastModified(long lastModified) {
    this.lastModified = lastModified;
  }

  @Override
  public String toString() {
    return name;
  }  
}

----------------------------Persistence.xml class ----------------------------------------
<?xml version="1.0" encoding="UTF-8"?>
<persistence xmlns="http://java.sun.com/xml/ns/persistence"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://java.sun.com/xml/ns/persistence
    persistence_1_0.xsd" version="1.0">
   
    <persistence-unit name="testPersistenceUnit" >
    <provider>org.eclipse.persistence.jpa.PersistenceProvider</provider>
     
      <jta-data-source>java:/comp/env/jdbc/testDs</jta-data-source>
      <non-jta-data-source>java:/comp/env/jdbc/testDs</non-jta-data-source>
     
      <class>Employee</class>
      <class>Manager</class>
      <class>Department</class>

          <!-- Provider-specific settings -->
          <properties>
                  <property name="eclipselink.ddl-generation" value="drop-and-create-tables"/> <!-- other values are: create-tables|drop-and-create-tables|none -->
                 
                  <property name="eclipselink.logging.logger" value="Log4JEclipseLinkLogger"/>
                  <property name="eclipselink.logging.level" value="FINEST" /><!-- http://www.oracle.com/technology/products/ias/toplink/jpa/howto/configure-logging.html -->
                  <property name="eclipselink.logging.thread" value="true"/>
                  <property name="eclipselink.logging.session" value="true"/>
                  <property name="eclipselink.logging.timestamp" value="true"/>
                  <property name="eclipselink.logging.exceptions" value="true"/>
                 
                  <property name="eclipselink.create-ddl-jdbc-file-name" value="create-tables.sql"/>
                  <property name="eclipselink.drop-ddl-jdbc-file-name" value="drop-tables.sql"/>
                  <property name="eclipselink.target-database" value="MySQL4"/>
                  <property name="eclipselink.cache.type.default" value="SoftWeak" /> <!-- Full | HeadWeak | NONE | SoftWeak|Weak http://www.oracle.com/technology/products/ias/toplink/JPA/essentials/toplink-jpa-extensions.html#TopLinkCaching -->
                  <property name="eclipselink.jdbc.batch-writing" value="JDBC"/>
                  <property name="eclipselink.jdbc.cache-statements" value="true"/>
                  <property name="eclipselink.jdbc.cache-statements.size" value="100"/>
                  <property name="eclipselink.cache.size.Employee" value="250000" />
          </properties>  
        </persistence-unit>
</persistence>


To get the error I simply run the project (NOT as a junit test - the project never gets that far).  Running it as an application invokes the main, which tries to insert the DB records (which it does successfully), but I get an error when it returns the count of the Employee records for a manager on the following line:
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
The error we get is below:
     Caused by: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634):  
     org.eclipse.persistence.exceptions.ConcurrencyException
     Exception Description: Max number of attempts to lock object: Emp_Homer-55086 exceded.  Failed to clone the object.

After playing with the test project, I have the following findings:
1). This issue can only be reproduced if the employees have a FetchType of LAZY.  Changing them to EAGER makes the test project work.
2). Reducing the size of NUM_EMPLOYEES can also make the test project work.  Through trial and error I found that if I set the NUM_EMPLOYEES to 59,999 the test project works.  If I set it to 60,000 it fails.  Not sure if this is significant, but I found it interesting if nothing else.

Any ideas as to what might be causing this?  Thanks in advance.
Kevin

[James Sutherland]

Could you include the full exception for the stack trace.  Also include what is occurring when the error occurs, you seem to have multiple threads inserting objects, is that correct, how many threads, do they each use a different EntityManager?  Also the code for EmpCreator, or ExecutorService, ExecutorCompletionService.

Kevin Lester wrote:

We're testing EclipseLink 1.1, and we're getting an error while retrieving child records that are marked as lazy.  Specifically we receive the following error:
ECLIPSELINK-02004: A signal was attempted before wait() on ConcurrencyManager. This normally means that an attempt was made to {0}commit or rollback a transaction before it was started, or to rollback a transaction twice.

The error gets thrown from a line of code like the following: parent.getChildren().size();
The getChildren() method returns a Set of Child objects that have a fetchType of LAZY.  This code used to work with EclipseLink 1.0.2.

To debug the issue, I created a small test project that recreates the situation in which we see the error.  The code for the test project is below.  An error gets thrown on the expected line of code in my test project - but interestingly it is a different error than we get in our application.  I was not able to reproduce the exact error in my test project for some reason.  Test project code below:


----------------------------EclipseLinkLazyTester class ----------------------------------------
public class EclipseLinkLazyTester {
  protected static EntityManagerFactory emf;
  private static Logger logger = Logger.getLogger(EclipseLinkLazyTester.class);
  private static final String PERSISTENCE_UNIT = "testPersistenceUnit";
  private static final int NUM_EMPLOYEES=59999;
 
  private Manager manager1 = null;
  private Manager manager2 = null;
 
  @BeforeClass
  public static void initialize(){
    System.setProperty("LOG_DIR", System.getProperty("user.dir"));
   
    //set up the DB datasource
    setupInitialContext();
   
    //Set up the entity manager factory
    logger.info("persistanceUnitName: " + PERSISTENCE_UNIT);
    emf = Persistence.createEntityManagerFactory(PERSISTENCE_UNIT);
  }  
 
  private void insertDBRecords(){
    manager1 = new Manager();
    manager1.setName("Homer");
    manager1.setDept("Sector 7-G");
   
    manager2 = new Manager();
    manager2.setName("Carl");
    manager2.setDept("Sector 7-G");
   
    //Fill the employees
    try{
      ExecutorService execService=Executors.newFixedThreadPool(2);
      CompletionService<Manager> fillManagerSvc = new ExecutorCompletionService<Manager>(execService);
           
      fillManagerSvc.submit(new EmpCreator(manager1, NUM_EMPLOYEES));
      fillManagerSvc.submit(new EmpCreator(manager2, NUM_EMPLOYEES));
      for (int counter = 0; counter < 2; counter ++){
        fillManagerSvc.take().get();
      }
    } catch (Exception e){
      logger.error("Error occurred filling the manager with Employees");
      System.exit(1);
    }
   
    try{
      ExecutorService execService2=Executors.newFixedThreadPool(2);
      CompletionService<Manager> updateManagerSvc = new ExecutorCompletionService<Manager>(execService2);
 
      updateManagerSvc.submit(new ManagerUpdater(manager1));
      updateManagerSvc.submit(new ManagerUpdater(manager2));
      for (int counter = 0; counter < 2; counter++){
        Manager manager = updateManagerSvc.take().get();
        System.out.println("Manager " + manager.getName() + " filled");
       }
    } catch (Exception e){
      logger.error("Error occurred updating the manager", e);
      System.exit(1);      
    }
  }
   
  public static void main(String[] args){
    EclipseLinkLazyTester lazyTester = new EclipseLinkLazyTester();
    EclipseLinkLazyTester.initialize();
    lazyTester.insertDBRecords();
  }
 
  @Before
  public void beforeTest(){
    try {
      manager1 = this.findManagerByName("Homer", "Sector 7-G");
      manager2 = this.findManagerByName("Carl", "Sector 7-G");
      System.out.println(manager1.getName() + "'s id = " + manager1.getManagerId());
      System.out.println(manager2.getName() + "'s id = " + manager2.getManagerId());
    } catch (Exception e) {
      e.printStackTrace();
      System.exit(1);
    }
  }
 
  @Test
  public void testGetEmployeesLazy(){
    try{
      Department dept1 = new Department(manager1);
      Department dept2 = new Department(manager2);
     
      updateDept(dept1);
      updateDept(dept2);
     
      ExecutorService updateManagerService=Executors.newFixedThreadPool(2);
      CompletionService<Manager> updateMgrSvc = new ExecutorCompletionService<Manager>(updateManagerService);
     
      ExecutorService execService=Executors.newFixedThreadPool(2);
      CompletionService<Manager> ecs = new ExecutorCompletionService<Manager>(execService);
      ecs.submit(new EmpRetriever(manager1, 0));
      ecs.submit(new EmpRetriever(manager2, 0));
      for (int counter = 0; counter < 2; counter++){
        Manager mgr = ecs.take().get();
        logger.info("Got employees for " + mgr.getName());
        updateMgrSvc.submit(new ManagerUpdater(mgr));
      }
      for (int counter = 0; counter < 2; counter++){
        Manager updatedManager = updateMgrSvc.take().get();
        logger.info("Manager " + updatedManager.getName() + " updated.");
      }
    }catch (Exception e){
      logger.error("Error occurred",e);
    }
  }
 
  private Employee createEmployee(Manager manager, String name, long now){
    Employee emp = new Employee();
    emp.setManager(manager);
    emp.setName(name);
    emp.setRank("peon");
    emp.setLastModified(now);
    return emp;
  }
   
  @SuppressWarnings("unchecked")
  private Manager findManagerByName(String name, String dept) throws Exception{
    EntityManager em = getNewEntityManager();
    try {
      Query q = em.createNamedQuery("GetManagerByNameDept");
      q.setParameter("name", name);
      q.setParameter("dept", dept);
      List<Manager> results = q.getResultList();
      if (results == null || results.size() == 0){
        return null;
      }
      if (results.size() != 1){
        //We have duplicate Build records in the DB, this is illegal
        String errorMsg = "Duplicate Manager records were found with name = " + name + " and department " + dept;
        logger.error(errorMsg);
        throw new Exception(errorMsg);
      }
      return (Manager) results.get(0);
    } finally {
      em.close();
    }
  }

  private Manager updateManager(Manager manager){
    EntityManager em = getNewEntityManager();
    try {
      em.getTransaction().begin();
      manager = em.merge(manager);
      em.getTransaction().commit();
      //Build newBuild=em.find(Build.class, inBuild.getBuildId());
      System.out.println("#Build files from manager in same session = " + manager.getEmployees().size());
    } finally {
      em.close();
    }
    //The manger will be the original object passed in but with the ids set properly (which could potentially modify the hashCode, depending on how it is implemented)
    //Since child objects were added prior to the ID being set, there is a chance that the child objects will not be
    //retrievable is they were stored in any Collections (because their hashcode affects their "bucket" in the collection).
    //So we need to return a new object back from scratch which has everything set correctly.
     return this.getManager(manager.getManagerId());
  }
 
  private Manager getManager(Integer managerId){
    EntityManager em = getNewEntityManager();
    try {
      return em.find(Manager.class, managerId);
    } finally {
      em.close();
    }
  }
 
  private Department updateDept(Department dept){
    EntityManager em = getNewEntityManager();
    try {
      em.getTransaction().begin();
      dept = em.merge(dept);
      em.getTransaction().commit();
    } finally {
      em.close();
    }
    //The dept will be the original object passed in but with the ids set properly (which could potentially modify the hashCode, depending on how it is implemented)
    //Since child objects were added prior to the ID being set, there is a chance that the child objects will not be
    //retrievable is they were stored in any Collections (because their hashcode affects their "bucket" in the collection).
    //So we need to return a new object back from scratch which has everything set correctly.
     return this.getDepartment(dept.getDeptId());
  }
 
  private Department getDepartment(Integer deptId){
    EntityManager em = getNewEntityManager();
    try {
      return em.find(Department.class, deptId);
    } finally {
      em.close();
    }
  }  
 
  public EntityManager getNewEntityManager() {
    EntityManager ret=emf.createEntityManager();
    /**
     * bug: http://forums.oracle.com/forums/thread.jspa?messageID=2284069
     * https://glassfish.dev.java.net/issues/show_bug.cgi?id=3937
     */
    return ret;
  }

  private static void setupInitialContext(){
    try {
      // Create initial context
      System.setProperty(Context.INITIAL_CONTEXT_FACTORY, "org.apache.naming.java.javaURLContextFactory");
      System.setProperty(Context.URL_PKG_PREFIXES, "org.apache.naming");
      InitialContext ic = new InitialContext();

      ic.createSubcontext("java:");
      ic.createSubcontext("java:/comp");
      ic.createSubcontext("java:/comp/env");
      ic.createSubcontext("java:/comp/env/jdbc");
     
      // Construct DataSource
      MysqlDataSource dataSource = new MysqlConnectionPoolDataSource();
      String dbURL=<dburl>;
      dataSource.setURL(dbURL);
      logger.info("Running test against db "+dbURL);
      dataSource.setUser(<user>);
      dataSource.setPassword(<password>);
      ic.bind("java:/comp/env/jdbc/testDs", dataSource);
    } catch (NamingException ex) {
      ex.printStackTrace();
      logger.error("Error occurred setting the datasource", ex);
    }
  }
 
  class EmpRetriever implements Callable<Manager>{
    private Manager manager;    
    private long delay;
   
    public EmpRetriever(Manager manager, long delay) {
      super();
      this.manager = manager;
      this.delay = delay;
    }

    public Manager call() {
      try {Thread.sleep(delay);} catch (InterruptedException e) {}
      logger.info("Thread for getting Employees for manager " + manager.getName() + " starting");
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
      return manager;
    }    
  }
   
  class ManagerUpdater implements Callable<Manager>{
    private Manager manager;    
    private long delay;
   
    public ManagerUpdater(Manager manager, long delay) {
      this.manager = manager;
      this.delay = delay;
    }

    public ManagerUpdater(Manager manager) {
      this(manager, 0);
    }

    public Manager call() {
      try {Thread.sleep(delay);} catch (InterruptedException e) {}
      logger.info("Thread for updating manager " + manager.getName() + " starting");
      manager = updateManager(manager);
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
      return manager;
    }
  }
 
  class EmpCreator implements Callable<Manager>{
    private Manager manager;
    private long numEmployees;
   
    public EmpCreator(Manager manager, long numEmployees) {
      this.manager = manager;
      this.numEmployees = numEmployees;
    }
   
    public Manager call(){
      for (int counter = 0; counter < numEmployees; counter++){
        manager.getEmployees().add(createEmployee(manager, "Emp_" + manager.getName() + "-" + counter, System.currentTimeMillis()));
      }
      return manager;
    }
  }
}

----------------------------Manager class ----------------------------------------
@Entity
@Table(name = "Manager")
@NamedQuery(name = "GetManagerByNameDept", query = "SELECT obj FROM Manager obj WHERE obj.name = :name and obj.dept = :dept")
public class Manager {
 
  @Id
  @Column(name = "managerId")
    @TableGenerator(
        name="MGR_ID_SEQ",
        table="SEQUENCE",
        allocationSize=1)
  @GeneratedValue(strategy = GenerationType.AUTO, generator = "MGR_ID_SEQ")
  private Integer managerId;
 
  private String name = null;
 
  private String dept = null;
 
  //Changing the FetchType to EAGER avoids the issue.
  @OneToMany (cascade=CascadeType.ALL, mappedBy="manager", fetch=FetchType.LAZY)
  @PrivateOwned
  private Set<Employee> employees = new HashSet<Employee>();

  public Integer getManagerId() {
    return managerId;
  }

  public void setManagerId(Integer managerId) {
    this.managerId = managerId;
  }

  public String getName() {
    return name;
  }

  public void setName(String name) {
    this.name = name;
  }

  public String getDept() {
    return dept;
  }

  public void setDept(String dept) {
    this.dept = dept;
  }

  public Set<Employee> getEmployees() {
    return employees;
  }

  public void setEmployees(Set<Employee> employees) {
    this.employees = employees;
  }  
}

----------------------------Employee class ----------------------------------------
@Entity
@Table(name = "Employee")
public class Employee {
 
  @Id
  @Column(name = "empId")
  @TableGenerator(
        name="EMP_ID_SEQ",
        table="SEQUENCE",
        allocationSize=100)
  @GeneratedValue(strategy = GenerationType.AUTO, generator = "EMP_ID_SEQ")
  private Integer empId;
 
  private String name = null;
 
  private String rank = null;
 
  @ManyToOne (cascade=CascadeType.REFRESH)
  @JoinColumn(name="managerId")
  private Manager manager = null;

  private long lastModified = 0L;
 
  public String getName() {
    return name;
  }

  public void setName(String name) {
    this.name = name;
  }

  public String getRank() {
    return rank;
  }

  public void setRank(String rank) {
    this.rank = rank;
  }

  public Manager getManager() {
    return manager;
  }

  public void setManager(Manager manager) {
    this.manager = manager;
  }

  public Integer getEmpId() {
    return empId;
  }

  public void setEmpId(Integer empId) {
    this.empId = empId;
  }

  public long getLastModified() {
    return lastModified;
  }

  public void setLastModified(long lastModified) {
    this.lastModified = lastModified;
  }

  @Override
  public String toString() {
    return name;
  }  
}

----------------------------Persistence.xml class ----------------------------------------
<?xml version="1.0" encoding="UTF-8"?>
<persistence xmlns="http://java.sun.com/xml/ns/persistence"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://java.sun.com/xml/ns/persistence
    persistence_1_0.xsd" version="1.0">
   
    <persistence-unit name="testPersistenceUnit" >
    <provider>org.eclipse.persistence.jpa.PersistenceProvider</provider>
     
      <jta-data-source>java:/comp/env/jdbc/testDs</jta-data-source>
      <non-jta-data-source>java:/comp/env/jdbc/testDs</non-jta-data-source>
     
      <class>Employee</class>
      <class>Manager</class>
      <class>Department</class>

          <!-- Provider-specific settings -->
          <properties>
                  <property name="eclipselink.ddl-generation" value="drop-and-create-tables"/> <!-- other values are: create-tables|drop-and-create-tables|none -->
                 
                  <property name="eclipselink.logging.logger" value="Log4JEclipseLinkLogger"/>
                  <property name="eclipselink.logging.level" value="FINEST" /><!-- http://www.oracle.com/technology/products/ias/toplink/jpa/howto/configure-logging.html -->
                  <property name="eclipselink.logging.thread" value="true"/>
                  <property name="eclipselink.logging.session" value="true"/>
                  <property name="eclipselink.logging.timestamp" value="true"/>
                  <property name="eclipselink.logging.exceptions" value="true"/>
                 
                  <property name="eclipselink.create-ddl-jdbc-file-name" value="create-tables.sql"/>
                  <property name="eclipselink.drop-ddl-jdbc-file-name" value="drop-tables.sql"/>
                  <property name="eclipselink.target-database" value="MySQL4"/>
                  <property name="eclipselink.cache.type.default" value="SoftWeak" /> <!-- Full | HeadWeak | NONE | SoftWeak|Weak http://www.oracle.com/technology/products/ias/toplink/JPA/essentials/toplink-jpa-extensions.html#TopLinkCaching -->
                  <property name="eclipselink.jdbc.batch-writing" value="JDBC"/>
                  <property name="eclipselink.jdbc.cache-statements" value="true"/>
                  <property name="eclipselink.jdbc.cache-statements.size" value="100"/>
                  <property name="eclipselink.cache.size.Employee" value="250000" />
          </properties>  
        </persistence-unit>
</persistence>


To get the error I simply run the project (NOT as a junit test - the project never gets that far).  Running it as an application invokes the main, which tries to insert the DB records (which it does successfully), but I get an error when it returns the count of the Employee records for a manager on the following line:
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
The error we get is below:
     Caused by: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634):  
     org.eclipse.persistence.exceptions.ConcurrencyException
     Exception Description: Max number of attempts to lock object: Emp_Homer-55086 exceded.  Failed to clone the object.

After playing with the test project, I have the following findings:
1). This issue can only be reproduced if the employees have a FetchType of LAZY.  Changing them to EAGER makes the test project work.
2). Reducing the size of NUM_EMPLOYEES can also make the test project work.  Through trial and error I found that if I set the NUM_EMPLOYEES to 59,999 the test project works.  If I set it to 60,000 it fails.  Not sure if this is significant, but I found it interesting if nothing else.

Any ideas as to what might be causing this?  Thanks in advance.
Kevin

[Kevin Lester]

James, thanks for the response.  Answers to your questions below:

Also include what is occurring when the error occurs, you seem to have multiple threads inserting objects, is that correct, how many threads, do they each use a different EntityManager?

I start two threads that each populate the Manager with NUM_EMPLOYEES Employees (this set to 59,999 in the test code, but will be over 100,000 in our app).  Once both threads complete, I start two ManagerUpdater threads that each persist the new manager objects.  The ManagerUpdater does the following (full code can be found at the end of the EclipseLinkLazyTester class):
      manager = updateManager(manager);
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
The updateManager method saves the manager, and then returns a fresh copy of the manager.  The logger.info method prints out the number of employees that were persisted for the manager, and this is where the error occurs.  The employees are LAZY loaded from the manager, so when we call getEmployees().size(), the employees are loaded, and this is where we get the error for some reason.  The actual persistence of the Manager and Employee objects succeeds, and I see the proper values in the DB; it just errors out when the employees are lazy loaded from the fresh manager object for some reason.

Each ManagerUpdater thread uses its own EntityManager.

James Sutherland wrote:

Could you include the full exception for the stack trace

Full stack trace below:
10:15:14,137 INFO  [EclipseLinkLazyTester] persistanceUnitName: testPersistenceUnit
10:15:15,485 INFO  [EclipseLinkLazyTester] Thread for updating manager Homer starting
10:15:15,486 INFO  [EclipseLinkLazyTester] Thread for updating manager Carl starting
#Build files from manager in same session = 59999
10:16:36,264 ERROR [EclipseLinkLazyTester] Error occurred updating the manager
java.util.concurrent.ExecutionException: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
Exception Description: Max number of attempts to lock object: Emp_Carl-27839 exceded.  Failed to clone the object.
        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
        at java.util.concurrent.FutureTask.get(FutureTask.java:83)
        at EclipseLinkLazyTester.insertDBRecords(EclipseLinkLazyTester.java:79)
        at EclipseLinkLazyTester.main(EclipseLinkLazyTester.java:92)
Caused by: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
Exception Description: Max number of attempts to lock object: Emp_Carl-27839 exceded.  Failed to clone the object.
        at org.eclipse.persistence.exceptions.ConcurrencyException.maxTriesLockOnCloneExceded(ConcurrencyException.java:60)
        at org.eclipse.persistence.internal.helper.WriteLockManager.acquireLocksForClone(WriteLockManager.java:97)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:873)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:811)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getAndCloneCacheKeyFromParent(UnitOfWorkIdentityMapAccessor.java:171)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getFromIdentityMap(UnitOfWorkIdentityMapAccessor.java:110)
        at org.eclipse.persistence.internal.sessions.IdentityMapAccessor.getFromIdentityMap(IdentityMapAccessor.java:327)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3708)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3668)
        at org.eclipse.persistence.mappings.CollectionMapping.buildElementClone(CollectionMapping.java:207)
        at org.eclipse.persistence.mappings.CollectionMapping.buildCloneForPartObject(CollectionMapping.java:164)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkQueryValueHolder.buildCloneFor(UnitOfWorkQueryValueHolder.java:51)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiateImpl(UnitOfWorkValueHolder.java:162)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiate(UnitOfWorkValueHolder.java:230)
        at org.eclipse.persistence.internal.indirection.DatabaseValueHolder.getValue(DatabaseValueHolder.java:83)
        at org.eclipse.persistence.indirection.IndirectSet.buildDelegate(IndirectSet.java:192)
        at org.eclipse.persistence.indirection.IndirectSet.getDelegate(IndirectSet.java:343)
        at org.eclipse.persistence.indirection.IndirectSet.size(IndirectSet.java:500)
        at EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:304)
        at EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:1)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:619)

Also the code for EmpCreator, or ExecutorService, ExecutorCompletionService.

The code for the EmpCreator is at the end of the EclipseLinkLazyTester class. The ExecutorService and the ExecutorCompletionService are built-in Java classes that are part of the java.util.concurrent package.

Just to reiterate my findings they are as follows:
1). This issue can only be reproduced if the employees have a FetchType of LAZY.  Changing them to EAGER makes the test project work.
2). Reducing the size of NUM_EMPLOYEES can also make the test project work.  Through trial and error I found that if I set the NUM_EMPLOYEES to < 50,000 or so, everything works.  If I set it above 50,000 it fails.  The actual threshold of records that cause it to fail is not constant, but it seems to always work if set the number beneath 50,000 or so. Not sure if this is significant, but I found it interesting if nothing else.

Is this simply a configuration issue where I need to increase some value to allow for lazy loading of my large data set without causing errors?  The fact that it works with ~< 50,000 employee records per manager implies that this might just be a configuration issue but I'm not sure what to tweak.

Thanks
Kevin

[James Sutherland]

The error does not make sense in this situation.  In EclipseLink when cloning object from the shared cache, cache locks are first obtained on the objects (and any EAGER relationships).  If you had many threads trying to access the same set of objects and the same time and starting with different objects in the cycle, then you could potentially get this error.  But you have only a single thread accessing these objects, so this makes little sense.

In your first post you mentioned a different error than this one.  Do any errors occurs before you get this error?  They could be the root cause.

>> ECLIPSELINK-02004: A signal was attempted before wait() on ConcurrencyManager. This normally means that an attempt was made to {0}commit or rollback a transaction before it was started, or to rollback a transaction twice.

Could you also try making the manager relationship from Employee LAZY, does this fix the issue?

A workaround may also to be to set,
session.getLogin().setCacheTransactionIsolation(DatabaseLogin.CONCURRENT_READ_WRITE);

using a SessionCustomizer.

Also in general it is normally not a good idea to map a 1-m for a collections that has 60,000 objects.  Normally it is better to query for such a result when required.
 

Kevin Lester wrote:

James, thanks for the response.  Answers to your questions below:

Also include what is occurring when the error occurs, you seem to have multiple threads inserting objects, is that correct, how many threads, do they each use a different EntityManager?

I start two threads that each populate the Manager with NUM_EMPLOYEES Employees (this set to 59,999 in the test code, but will be over 100,000 in our app).  Once both threads complete, I start two ManagerUpdater threads that each persist the new manager objects.  The ManagerUpdater does the following (full code can be found at the end of the EclipseLinkLazyTester class):
      manager = updateManager(manager);
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
The updateManager method saves the manager, and then returns a fresh copy of the manager.  The logger.info method prints out the number of employees that were persisted for the manager, and this is where the error occurs.  The employees are LAZY loaded from the manager, so when we call getEmployees().size(), the employees are loaded, and this is where we get the error for some reason.  The actual persistence of the Manager and Employee objects succeeds, and I see the proper values in the DB; it just errors out when the employees are lazy loaded from the fresh manager object for some reason.

Each ManagerUpdater thread uses its own EntityManager.

James Sutherland wrote:

Could you include the full exception for the stack trace

Full stack trace below:
10:15:14,137 INFO  [EclipseLinkLazyTester] persistanceUnitName: testPersistenceUnit
10:15:15,485 INFO  [EclipseLinkLazyTester] Thread for updating manager Homer starting
10:15:15,486 INFO  [EclipseLinkLazyTester] Thread for updating manager Carl starting
#Build files from manager in same session = 59999
10:16:36,264 ERROR [EclipseLinkLazyTester] Error occurred updating the manager
java.util.concurrent.ExecutionException: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
Exception Description: Max number of attempts to lock object: Emp_Carl-27839 exceded.  Failed to clone the object.
        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
        at java.util.concurrent.FutureTask.get(FutureTask.java:83)
        at EclipseLinkLazyTester.insertDBRecords(EclipseLinkLazyTester.java:79)
        at EclipseLinkLazyTester.main(EclipseLinkLazyTester.java:92)
Caused by: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
Exception Description: Max number of attempts to lock object: Emp_Carl-27839 exceded.  Failed to clone the object.
        at org.eclipse.persistence.exceptions.ConcurrencyException.maxTriesLockOnCloneExceded(ConcurrencyException.java:60)
        at org.eclipse.persistence.internal.helper.WriteLockManager.acquireLocksForClone(WriteLockManager.java:97)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:873)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:811)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getAndCloneCacheKeyFromParent(UnitOfWorkIdentityMapAccessor.java:171)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getFromIdentityMap(UnitOfWorkIdentityMapAccessor.java:110)
        at org.eclipse.persistence.internal.sessions.IdentityMapAccessor.getFromIdentityMap(IdentityMapAccessor.java:327)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3708)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3668)
        at org.eclipse.persistence.mappings.CollectionMapping.buildElementClone(CollectionMapping.java:207)
        at org.eclipse.persistence.mappings.CollectionMapping.buildCloneForPartObject(CollectionMapping.java:164)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkQueryValueHolder.buildCloneFor(UnitOfWorkQueryValueHolder.java:51)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiateImpl(UnitOfWorkValueHolder.java:162)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiate(UnitOfWorkValueHolder.java:230)
        at org.eclipse.persistence.internal.indirection.DatabaseValueHolder.getValue(DatabaseValueHolder.java:83)
        at org.eclipse.persistence.indirection.IndirectSet.buildDelegate(IndirectSet.java:192)
        at org.eclipse.persistence.indirection.IndirectSet.getDelegate(IndirectSet.java:343)
        at org.eclipse.persistence.indirection.IndirectSet.size(IndirectSet.java:500)
        at EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:304)
        at EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:1)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:619)

Also the code for EmpCreator, or ExecutorService, ExecutorCompletionService.

The code for the EmpCreator is at the end of the EclipseLinkLazyTester class. The ExecutorService and the ExecutorCompletionService are built-in Java classes that are part of the java.util.concurrent package.

Just to reiterate my findings they are as follows:
1). This issue can only be reproduced if the employees have a FetchType of LAZY.  Changing them to EAGER makes the test project work.
2). Reducing the size of NUM_EMPLOYEES can also make the test project work.  Through trial and error I found that if I set the NUM_EMPLOYEES to < 50,000 or so, everything works.  If I set it above 50,000 it fails.  The actual threshold of records that cause it to fail is not constant, but it seems to always work if set the number beneath 50,000 or so. Not sure if this is significant, but I found it interesting if nothing else.

Is this simply a configuration issue where I need to increase some value to allow for lazy loading of my large data set without causing errors?  The fact that it works with ~< 50,000 employee records per manager implies that this might just be a configuration issue but I'm not sure what to tweak.

Thanks
Kevin

[Kevin Lester]

The error does not make sense in this situation...

I agree.  I just re-ran the test with only 1 thread and I still get the same error ("Failed to clone object").

In your first post you mentioned a different error than this one.  Do any errors occurs before you get this error?  They could be the root cause.

The entire output of my test project is included in my previous post under the "Full stack trace below:".  As you can see I only get 1 error which is the "Failed to clone object" error, so there are no other errors which could be the root cause.  My persistence.xml file also does a drop-and-create-tables, so it's not a data issue.  The other error I referred to in my first post is the error we get in our actual application when we have a situation similar to the situation I created in my test project.  We should ignore that for now and just focus on the easily reproducible one via my test application, since understanding the test application's error will most likely help me understand the other error.

Could you also try making the manager relationship from Employee LAZY, does this fix the issue?

Unfortunately, I get the same error.

A workaround may also to be to set,
session.getLogin().setCacheTransactionIsolation(DatabaseLogin.CONCURRENT_READ_WRITE);
using a SessionCustomizer.

This does avoid the error in my test project, but reading the javadocs, this seems like it has some downsides.  It seems like there might potentially be some additional locking necessary with this setting since it allows reads and unit of work merges to be done concurrently.  I couldn't find any documentation on this setting except in the Javadocs.  Can you point me to a page where I can get a better description of the downsides of this setting?  

This setting was not needed with EclipselLink 1.0.2 and everything worked fine.  Why would this be needed now?

Also in general it is normally not a good idea to map a 1-m for a collections that has 60,000 objects.  Normally it is better to query for such a result when required.

Why would that be?  EclipseLink 1.0.2 worked just fine with well over 100,000 objects in a 1-m mapping, so I don't really see why we would need to handle these objects any differently with EclipseLink 1.1.  I'm sure it's a bit slower for EclipseLink to go through the large number of sub-objects looking for changes and merging them, but if performance is the only issue then we don't see it as being a significant downside.  This is because the performance in EclipseLink 1.0.2 is excellent for our needs even with the large amount of objects.  I'm sure we could manage these objects ourselves and it would be a little faster, but the bottleneck is our DB, not the code, so we don't see this as an issue.  Can you shed a little more light on why you wouldn't recommend this?  Are there other issues with this other than performance that we haven't seen yet?

My conclusion based on my tests is that there seems to be an issue with EclipseLink 1.1.  I hate to throw out the "it's a bug" statement without fully understanding EclipseLink since this could still be some easy issue, but at this point I'm running out of things to try.  I agree with your comments above that this error shouldn't happen since there is no sharing of data, so the thread should be able to get all the necessary locks when it lazy loads the sub-objects, but apparently it can't since it throws an error.  I've played around with my test project to see if it is a timing issue, but even with some sleep statements and getting fresh copies of the manager at certain points I still get the same error.  If I switch the EclipseLink jars back to version 1.0.2 everything works - which further leads me to think there is an issue with EclipseLink 1.1.  

Do you have enough info to reproduce this issue on your side if it comes to that?  I included all my code (expect for the import statements) and my persistence.xml file, so hopefully you should have everything you need if you want to try and run it.  Just let me know if there is any other info I can provide.

Kevin

[James Sutherland]

The only other thing I can think of is it could be some kind of invalidation issue, are you setting a cache invalidation timeout?

I would recommend you log a bug for the issue, and include all of the information you have gathered.  If you have an Oracle support contract please also contact Oracle technical support.

As a workaround, either disable the shared cache for the class (@Cache(shared=false)), or use the cache isolation setting that seems to be working, it should have no adverse side-effects.

The only issue with the large OneToMany was performance.



The error does not make sense in this situation.  In EclipseLink when cloning object from the shared cache, cache locks are first obtained on the objects (and any EAGER relationships).  If you had many threads trying to access the same set of objects and the same time and starting with different objects in the cycle, then you could potentially get this error.  But you have only a single thread accessing these objects, so this makes little sense.

In your first post you mentioned a different error than this one.  Do any errors occurs before you get this error?  They could be the root cause.

>> ECLIPSELINK-02004: A signal was attempted before wait() on ConcurrencyManager. This normally means that an attempt was made to {0}commit or rollback a transaction before it was started, or to rollback a transaction twice.

Could you also try making the manager relationship from Employee LAZY, does this fix the issue?

A workaround may also to be to set,
session.getLogin().setCacheTransactionIsolation(DatabaseLogin.CONCURRENT_READ_WRITE);

using a SessionCustomizer.

Also in general it is normally not a good idea to map a 1-m for a collections that has 60,000 objects.  Normally it is better to query for such a result when required.
 

Kevin Lester wrote:

James, thanks for the response.  Answers to your questions below:

Also include what is occurring when the error occurs, you seem to have multiple threads inserting objects, is that correct, how many threads, do they each use a different EntityManager?

I start two threads that each populate the Manager with NUM_EMPLOYEES Employees (this set to 59,999 in the test code, but will be over 100,000 in our app).  Once both threads complete, I start two ManagerUpdater threads that each persist the new manager objects.  The ManagerUpdater does the following (full code can be found at the end of the EclipseLinkLazyTester class):
      manager = updateManager(manager);
      logger.info("Manager " + manager.getName() + " has " + manager.getEmployees().size() + " employees");
The updateManager method saves the manager, and then returns a fresh copy of the manager.  The logger.info method prints out the number of employees that were persisted for the manager, and this is where the error occurs.  The employees are LAZY loaded from the manager, so when we call getEmployees().size(), the employees are loaded, and this is where we get the error for some reason.  The actual persistence of the Manager and Employee objects succeeds, and I see the proper values in the DB; it just errors out when the employees are lazy loaded from the fresh manager object for some reason.

Each ManagerUpdater thread uses its own EntityManager.

James Sutherland wrote:

Could you include the full exception for the stack trace

Full stack trace below:
10:15:14,137 INFO  [EclipseLinkLazyTester] persistanceUnitName: testPersistenceUnit
10:15:15,485 INFO  [EclipseLinkLazyTester] Thread for updating manager Homer starting
10:15:15,486 INFO  [EclipseLinkLazyTester] Thread for updating manager Carl starting
#Build files from manager in same session = 59999
10:16:36,264 ERROR [EclipseLinkLazyTester] Error occurred updating the manager
java.util.concurrent.ExecutionException: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
Exception Description: Max number of attempts to lock object: Emp_Carl-27839 exceded.  Failed to clone the object.
        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
        at java.util.concurrent.FutureTask.get(FutureTask.java:83)
        at EclipseLinkLazyTester.insertDBRecords(EclipseLinkLazyTester.java:79)
        at EclipseLinkLazyTester.main(EclipseLinkLazyTester.java:92)
Caused by: Exception [EclipseLink-2007] (Eclipse Persistence Services - 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
Exception Description: Max number of attempts to lock object: Emp_Carl-27839 exceded.  Failed to clone the object.
        at org.eclipse.persistence.exceptions.ConcurrencyException.maxTriesLockOnCloneExceded(ConcurrencyException.java:60)
        at org.eclipse.persistence.internal.helper.WriteLockManager.acquireLocksForClone(WriteLockManager.java:97)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:873)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:811)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getAndCloneCacheKeyFromParent(UnitOfWorkIdentityMapAccessor.java:171)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getFromIdentityMap(UnitOfWorkIdentityMapAccessor.java:110)
        at org.eclipse.persistence.internal.sessions.IdentityMapAccessor.getFromIdentityMap(IdentityMapAccessor.java:327)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3708)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3668)
        at org.eclipse.persistence.mappings.CollectionMapping.buildElementClone(CollectionMapping.java:207)
        at org.eclipse.persistence.mappings.CollectionMapping.buildCloneForPartObject(CollectionMapping.java:164)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkQueryValueHolder.buildCloneFor(UnitOfWorkQueryValueHolder.java:51)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiateImpl(UnitOfWorkValueHolder.java:162)
        at org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiate(UnitOfWorkValueHolder.java:230)
        at org.eclipse.persistence.internal.indirection.DatabaseValueHolder.getValue(DatabaseValueHolder.java:83)
        at org.eclipse.persistence.indirection.IndirectSet.buildDelegate(IndirectSet.java:192)
        at org.eclipse.persistence.indirection.IndirectSet.getDelegate(IndirectSet.java:343)
        at org.eclipse.persistence.indirection.IndirectSet.size(IndirectSet.java:500)
        at EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:304)
        at EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:1)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:619)

Also the code for EmpCreator, or ExecutorService, ExecutorCompletionService.

The code for the EmpCreator is at the end of the EclipseLinkLazyTester class. The ExecutorService and the ExecutorCompletionService are built-in Java classes that are part of the java.util.concurrent package.

Just to reiterate my findings they are as follows:
1). This issue can only be reproduced if the employees have a FetchType of LAZY.  Changing them to EAGER makes the test project work.
2). Reducing the size of NUM_EMPLOYEES can also make the test project work.  Through trial and error I found that if I set the NUM_EMPLOYEES to < 50,000 or so, everything works.  If I set it above 50,000 it fails.  The actual threshold of records that cause it to fail is not constant, but it seems to always work if set the number beneath 50,000 or so. Not sure if this is significant, but I found it interesting if nothing else.

Is this simply a configuration issue where I need to increase some value to allow for lazy loading of my large data set without causing errors?  The fact that it works with ~< 50,000 employee records per manager implies that this might just be a configuration issue but I'm not sure what to tweak.

Thanks
Kevin

[Magnus Heino]

Hi.

We have the same issue as described here now :-P Has anything new happened since this thread was last updated?

If we set session.getLogin().setCacheTransactionIsolation(DatabaseLogin.CONCURRENT_READ_WRITE), as described in this thread, what does that mean? Why do we see this behaviour in 1.1?

We dont have any big onetomany mappings. What we have though, is 2 concurrent jsm consumers. This error seems to happen when the entity is created in thread 1, and later deleted from thread 2. The delete fails with this "Max number of attempts to lock object exceded" error.

Thanks,

 /Magnus Heino

On Wed, Apr 15, 2009 at 4:01 PM, James Sutherland <jamesssss@...> wrote:

The only other thing I can think of is it could be some kind of invalidation
issue, are you setting a cache invalidation timeout?

I would recommend you log a bug for the issue, and include all of the
information you have gathered.  If you have an Oracle support contract
please also contact Oracle technical support.

As a workaround, either disable the shared cache for the class
(@Cache(shared=false)), or use the cache isolation setting that seems to be
working, it should have no adverse side-effects.

The only issue with the large OneToMany was performance.

James Sutherland wrote:
>
> The error does not make sense in this situation.  In EclipseLink when
> cloning object from the shared cache, cache locks are first obtained on
> the objects (and any EAGER relationships).  If you had many threads trying
> to access the same set of objects and the same time and starting with
> different objects in the cycle, then you could potentially get this error.
> But you have only a single thread accessing these objects, so this makes
> little sense.
>
> In your first post you mentioned a different error than this one.  Do any
> errors occurs before you get this error?  They could be the root cause.
>
>>> ECLIPSELINK-02004: A signal was attempted before wait() on
>>> ConcurrencyManager. This normally means that an attempt was made to
>>> {0}commit or rollback a transaction before it was started, or to
>>> rollback a transaction twice.
>
> Could you also try making the manager relationship from Employee LAZY,
> does this fix the issue?
>
> A workaround may also to be to set,
> session.getLogin().setCacheTransactionIsolation(DatabaseLogin.CONCURRENT_READ_WRITE);
>
> using a SessionCustomizer.
>
> Also in general it is normally not a good idea to map a 1-m for a
> collections that has 60,000 objects.  Normally it is better to query for
> such a result when required.
>
>
>
> Kevin Lester wrote:
>>
>> James, thanks for the response.  Answers to your questions below:
>>
>> Also include what is occurring when the error occurs, you seem to have
>> multiple threads inserting objects, is that correct, how many threads, do
>> they each use a different EntityManager?
>> I start two threads that each populate the Manager with NUM_EMPLOYEES
>> Employees (this set to 59,999 in the test code, but will be over 100,000
>> in our app).  Once both threads complete, I start two ManagerUpdater
>> threads that each persist the new manager objects.  The ManagerUpdater
>> does the following (full code can be found at the end of the
>> EclipseLinkLazyTester class):
>>       manager = updateManager(manager);
>>       logger.info("Manager " + manager.getName() + " has " +
>> manager.getEmployees().size() + " employees");
>> The updateManager method saves the manager, and then returns a fresh copy
>> of the manager.  The logger.info method prints out the number of
>> employees that were persisted for the manager, and this is where the
>> error occurs.  The employees are LAZY loaded from the manager, so when we
>> call getEmployees().size(), the employees are loaded, and this is where
>> we get the error for some reason.  The actual persistence of the Manager
>> and Employee objects succeeds, and I see the proper values in the DB; it
>> just errors out when the employees are lazy loaded from the fresh manager
>> object for some reason.
>>
>> Each ManagerUpdater thread uses its own EntityManager.
>>
>> James Sutherland wrote:
>>> Could you include the full exception for the stack trace
>> Full stack trace below:
>> 10:15:14,137 INFO  [EclipseLinkLazyTester] persistanceUnitName:
>> testPersistenceUnit
>> 10:15:15,485 INFO  [EclipseLinkLazyTester] Thread for updating manager
>> Homer starting
>> 10:15:15,486 INFO  [EclipseLinkLazyTester] Thread for updating manager
>> Carl starting
>> #Build files from manager in same session = 59999
>> 10:16:36,264 ERROR [EclipseLinkLazyTester] Error occurred updating the
>> manager
>> java.util.concurrent.ExecutionException: Exception [EclipseLink-2007]
>> (Eclipse Persistence Services - 1.1.0.r3634):
>> org.eclipse.persistence.exceptions.ConcurrencyException
>> Exception Description: Max number of attempts to lock object:
>> Emp_Carl-27839 exceded.  Failed to clone the object.
>>      at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
>>      at java.util.concurrent.FutureTask.get(FutureTask.java:83)
>>      at EclipseLinkLazyTester.insertDBRecords(EclipseLinkLazyTester.java:79)
>>      at EclipseLinkLazyTester.main(EclipseLinkLazyTester.java:92)
>> Caused by: Exception [EclipseLink-2007] (Eclipse Persistence Services -
>> 1.1.0.r3634): org.eclipse.persistence.exceptions.ConcurrencyException
>> Exception Description: Max number of attempts to lock object:
>> Emp_Carl-27839 exceded.  Failed to clone the object.
>>      at
>> org.eclipse.persistence.exceptions.ConcurrencyException.maxTriesLockOnCloneExceded(ConcurrencyException.java:60)
>>      at
>> org.eclipse.persistence.internal.helper.WriteLockManager.acquireLocksForClone(WriteLockManager.java:97)
>>      at
>> org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:873)
>>      at
>> org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.cloneAndRegisterObject(UnitOfWorkImpl.java:811)
>>      at
>> org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getAndCloneCacheKeyFromParent(UnitOfWorkIdentityMapAccessor.java:171)
>>      at
>> org.eclipse.persistence.internal.sessions.UnitOfWorkIdentityMapAccessor.getFromIdentityMap(UnitOfWorkIdentityMapAccessor.java:110)
>>      at
>> org.eclipse.persistence.internal.sessions.IdentityMapAccessor.getFromIdentityMap(IdentityMapAccessor.java:327)
>>      at
>> org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3708)
>>      at
>> org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.registerExistingObject(UnitOfWorkImpl.java:3668)
>>      at
>> org.eclipse.persistence.mappings.CollectionMapping.buildElementClone(CollectionMapping.java:207)
>>      at
>> org.eclipse.persistence.mappings.CollectionMapping.buildCloneForPartObject(CollectionMapping.java:164)
>>      at
>> org.eclipse.persistence.internal.indirection.UnitOfWorkQueryValueHolder.buildCloneFor(UnitOfWorkQueryValueHolder.java:51)
>>      at
>> org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiateImpl(UnitOfWorkValueHolder.java:162)
>>      at
>> org.eclipse.persistence.internal.indirection.UnitOfWorkValueHolder.instantiate(UnitOfWorkValueHolder.java:230)
>>      at
>> org.eclipse.persistence.internal.indirection.DatabaseValueHolder.getValue(DatabaseValueHolder.java:83)
>>      at
>> org.eclipse.persistence.indirection.IndirectSet.buildDelegate(IndirectSet.java:192)
>>      at
>> org.eclipse.persistence.indirection.IndirectSet.getDelegate(IndirectSet.java:343)
>>      at
>> org.eclipse.persistence.indirection.IndirectSet.size(IndirectSet.java:500)
>>      at
>> EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:304)
>>      at
>> EclipseLinkLazyTester$ManagerUpdater.call(EclipseLinkLazyTester.java:1)
>>      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>>      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>>      at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>>      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>>      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>>      at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
>>      at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
>>      at java.lang.Thread.run(Thread.java:619)
>>
>> Also the code for EmpCreator, or ExecutorService,
>> ExecutorCompletionService.
>> The code for the EmpCreator is at the end of the EclipseLinkLazyTester
>> class. The ExecutorService and the ExecutorCompletionService are built-in
>> Java classes that are part of the java.util.concurrent package.
>>
>> Just to reiterate my findings they are as follows:
>> 1). This issue can only be reproduced if the employees have a FetchType
>> of LAZY.  Changing them to EAGER makes the test project work.
>> 2). Reducing the size of NUM_EMPLOYEES can also make the test project
>> work.  Through trial and error I found that if I set the NUM_EMPLOYEES to
>> < 50,000 or so, everything works.  If I set it above 50,000 it fails.
>> The actual threshold of records that cause it to fail is not constant,
>> but it seems to always work if set the number beneath 50,000 or so. Not
>> sure if this is significant, but I found it interesting if nothing else.
>>
>> Is this simply a configuration issue where I need to increase some value
>> to allow for lazy loading of my large data set without causing errors?
>> The fact that it works with ~< 50,000 employee records per manager
>> implies that this might just be a configuration issue but I'm not sure
>> what to tweak.
>>
>> Thanks
>> Kevin
>>
>
>


-----
---
http://wiki.eclipse.org/User:James.sutherland.oracle.com James Sutherland
http://www.eclipse.org/eclipselink/
 EclipseLink ,  http://www.oracle.com/technology/products/ias/toplink/
TopLink
Wiki:  http://wiki.eclipse.org/EclipseLink EclipseLink ,
http://wiki.oracle.com/page/TopLink TopLink
Forums:  http://forums.oracle.com/forums/forum.jspa?forumID=48 TopLink ,
http://www.nabble.com/EclipseLink-f26430.html EclipseLink
Book:  http://en.wikibooks.org/wiki/Java_Persistence Java Persistence
--

View this message in context: http://www.nabble.com/Error-pulling-back-records-with-FetchType%3DLAZY-tp22957109p23059596.html

Sent from the EclipseLink - Users mailing list archive at Nabble.com.

_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users

_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users

[Kevin Lester]

Magnus,

This issue still exists with EclipseLink 1.1.1, and no work has been done on it.  I opened a bug for this issue, and you should vote for it if you would like it to be more visible:
https://bugs.eclipse.org/bugs/show_bug.cgi?id=275046

This issue has prevented us from upgrading from version 1.0.2, and since we don't know what exactly the DatabaseLogin.CONCURRENT_READ_WRITE does, we are uncomfortable using it in production.  Sadly there is also no documentation on it (at least there wasn't when we last checked).

Kevin

[Magnus Heino]

Could this possibly be related to https://bugs.eclipse.org/bugs/show_bug.cgi?id=272022 It affects concurrency, and has been checked in within the timeframe of this bug being introduced...?

 /Magnus Heino

On Thu, Jun 11, 2009 at 11:07 PM, Kevin Lester <kevin@...> wrote:

Magnus,

This issue still exists with EclipseLink 1.1.1, and no work has been done on
it.  I opened a bug for this issue, and you should vote for it if you would
like it to be more visible:
https://bugs.eclipse.org/bugs/show_bug.cgi?id=275046
https://bugs.eclipse.org/bugs/show_bug.cgi?id=275046

This issue has prevented us from upgrading from version 1.0.2, and since we
don't know what exactly the DatabaseLogin.CONCURRENT_READ_WRITE does, we are
uncomfortable using it in production.  Sadly there is also no documentation
on it (at least there wasn't when we last checked).

Kevin
--
View this message in context: http://www.nabble.com/Error-pulling-back-records-with-FetchType%3DLAZY-tp22957109p23945738.html

Sent from the EclipseLink - Users mailing list archive at Nabble.com.

_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users

_______________________________________________
eclipselink-users mailing list
eclipselink-users@...
https://dev.eclipse.org/mailman/listinfo/eclipselink-users