eclipse-ee4j / glassfish

Eclipse GlassFish
https://eclipse-ee4j.github.io/glassfish/
386 stars 144 forks source link

ConcurrentModificationException in EJB #15477

Closed glassfishrobot closed 13 years ago

glassfishrobot commented 13 years ago

I have a stateless EJB method that updates a JPA Entity. (Many similar, in fact). When I call the update method for a CERTAIN entity with a CERTAIN id, I get an exception that seems to be the result of a bug somewhere deep down in Glassfish. It's reproducible for THAT entity type with THAT id, but no other.

Also, afterwards (but on WinXP only) normal JPA queries to that entity type (or perhaps a related entity - I can't figure it out) just hang forever. I have to redeploy and restart Glassfish for the problem to go away.

My web/ejb application works fine otherwise, with many entities implemented in exactly the same way. It seems to me that in some rare unfortunate circumstance, the bug is triggred.

I'll be happy to provide further information, as needed.

Here's a traceback of the event:

2011-01-07 13:59:11.441 WARN [http-thread-pool-8181-(1)] (error_jsp._jspService:191) - Server got unhandled exception: javax.ejb.EJBException: Transaction aborted AT com.sun.ejb.containers.BaseContainer.completeNewTx:5046 BaseContainer.postInvokeTx:4805 BaseContainer.postInvoke:2004 BaseContainer.postInvoke:1955 EJBLocalObjectInvocationHandler.invoke:198 EJBLocalObjectInvocationHandlerDelegate.invoke:84 $Proxy302.update AdminServlet.doPost:1196 HttpServlet.service:754 HttpServlet.service:847 StandardWrapper.service:1523 ApplicationFilterChain.internalDoFilter:343 ApplicationFilterChain.doFilter:215 RequestLogFilter.doFilter:62 ApplicationFilterChain.internalDoFilter:256 ApplicationFilterChain.doFilter:215 MainFilter.doFilter:41 ApplicationFilterChain.internalDoFilter:256 ApplicationFilterChain.doFilter:215 StandardWrapperValve.invoke:277 StandardContextValve.invoke:188 StandardPipeline.invoke:641 WebPipeline.invoke:97 PESessionLockingStandardPipeline.invoke:85 StandardHostValve.invoke:185 CoyoteAdapter.doService:325 CoyoteAdapter.service:226 ContainerMapper.service:165 ProcessorTask.invokeAdapter:791 ProcessorTask.doProcess:693 ProcessorTask.process:954 DefaultProtocolFilter.execute:170 DefaultProtocolChain.executeProtocolFilter:135 DefaultProtocolChain.execute:102 DefaultProtocolChain.execute:88 HttpProtocolChain.execute:76 ProtocolChainContextTask.doCall:53 SelectionKeyContextTask.call:57 ContextTask.run:69 AbstractThreadPool$Worker.doWork:330 AbstractThreadPool$Worker.run:309 Thread.run:662 CAUSED BY: javax.transaction.RollbackException: Transaction marked for rollback. AT com.sun.enterprise.transaction.JavaEETransactionImpl.commit:450 JavaEETransactionManagerSimplified.commit:837 BaseContainer.completeNewTx:5040 BaseContainer.postInvokeTx:4805 BaseContainer.postInvoke:2004 BaseContainer.postInvoke:1955 EJBLocalObjectInvocationHandler.invoke:198 EJBLocalObjectInvocationHandlerDelegate.invoke:84 $Proxy302.update AdminServlet.doPost:1196 HttpServlet.service:754 HttpServlet.service:847 StandardWrapper.service:1523 ApplicationFilterChain.internalDoFilter:343 ApplicationFilterChain.doFilter:215 RequestLogFilter.doFilter:62 ApplicationFilterChain.internalDoFilter:256 ApplicationFilterChain.doFilter:215 MainFilter.doFilter:41 ApplicationFilterChain.internalDoFilter:256 ApplicationFilterChain.doFilter:215 StandardWrapperValve.invoke:277 StandardContextValve.invoke:188 StandardPipeline.invoke:641 WebPipeline.invoke:97 PESessionLockingStandardPipeline.invoke:85 StandardHostValve.invoke:185 CoyoteAdapter.doService:325 CoyoteAdapter.service:226 ContainerMapper.service:165 ProcessorTask.invokeAdapter:791 ProcessorTask.doProcess:693 ProcessorTask.process:954 DefaultProtocolFilter.execute:170 DefaultProtocolChain.executeProtocolFilter:135 DefaultProtocolChain.execute:102 DefaultProtocolChain.execute:88 HttpProtocolChain.execute:76 ProtocolChainContextTask.doCall:53 SelectionKeyContextTask.call:57 ContextTask.run:69 AbstractThreadPool$Worker.doWork:330 AbstractThreadPool$Worker.run:309 Thread.run:662 CAUSED BY: java.util.ConcurrentModificationException AT java.util.AbstractList$Itr.checkForComodification:372 AbstractList$Itr.next:343 CollectionChangeRecord.mergeRecord:270 ObjectChangeSet.mergeObjectChanges:604 UnitOfWorkChangeSet.mergeObjectChanges:481 AttributeChangeTrackingPolicy.createObjectChangeSet:63 DeferredChangeDetectionPolicy.calculateChanges:89 AttributeChangeTrackingPolicy.calculateChangesForExistingObject:47 DatabaseQueryMechanism.updateObjectForWriteWithChangeSet:1091 UpdateObjectQuery.executeCommitWithChangeSet:84 DatabaseQueryMechanism.executeWriteWithChangeSet:286 WriteObjectQuery.executeDatabaseQuery:58 DatabaseQuery.execute:675 DatabaseQuery.executeInUnitOfWork:589 ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery:109 ObjectLevelModifyQuery.executeInUnitOfWork:86 UnitOfWorkImpl.internalExecuteQuery:2857 AbstractSession.executeQuery:1225 AbstractSession.executeQuery:1207 AbstractSession.executeQuery:1167 CommitManager.commitChangedObjectsForClassWithChangeSet:233 CommitManager.commitAllObjectsForClassWithChangeSet:163 CommitManager.commitAllObjectsWithChangeSet:116 AbstractSession.writeAllObjectsWithChangeSet:3260 UnitOfWorkImpl.commitToDatabase:1403 RepeatableWriteUnitOfWork.commitToDatabase:547 UnitOfWorkImpl.commitToDatabaseWithChangeSet:1508 UnitOfWorkImpl.issueSQLbeforeCompletion:3128 RepeatableWriteUnitOfWork.issueSQLbeforeCompletion:268 AbstractSynchronizationListener.beforeCompletion:157 JTASynchronizationListener.beforeCompletion:68 JavaEETransactionImpl.commit:412 JavaEETransactionManagerSimplified.commit:837 BaseContainer.completeNewTx:5040 BaseContainer.postInvokeTx:4805 BaseContainer.postInvoke:2004 BaseContainer.postInvoke:1955 EJBLocalObjectInvocationHandler.invoke:198 EJBLocalObjectInvocationHandlerDelegate.invoke:84 $Proxy302.update AdminServlet.doPost:1196 HttpServlet.service:754 HttpServlet.service:847 StandardWrapper.service:1523 ApplicationFilterChain.internalDoFilter:343 ApplicationFilterChain.doFilter:215 RequestLogFilter.doFilter:62 ApplicationFilterChain.internalDoFilter:256 ApplicationFilterChain.doFilter:215 MainFilter.doFilter:41 ApplicationFilterChain.internalDoFilter:256 ApplicationFilterChain.doFilter:215 StandardWrapperValve.invoke:277 StandardContextValve.invoke:188 StandardPipeline.invoke:641 WebPipeline.invoke:97 PESessionLockingStandardPipeline.invoke:85 StandardHostValve.invoke:185 CoyoteAdapter.doService:325 CoyoteAdapter.service:226 ContainerMapper.service:165 ProcessorTask.invokeAdapter:791 ProcessorTask.doProcess:693 ProcessorTask.process:954 DefaultProtocolFilter.execute:170 DefaultProtocolChain.executeProtocolFilter:135 DefaultProtocolChain.execute:102 DefaultProtocolChain.execute:88 HttpProtocolChain.execute:76 ProtocolChainContextTask.doCall:53 SelectionKeyContextTask.call:57 ContextTask.run:69 AbstractThreadPool$Worker.doWork:330 AbstractThreadPool$Worker.run:309 Thread.run:662

Environment

Unix & WinXP

Affected Versions

[v3.0.1]

glassfishrobot commented 6 years ago
glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said: By the way, the 'hang' problem that I saw on WinXP appears to exist on Unix as well.

I manually renamed the database record (no id:s were touched) using the MySQL client, and re-started Glassfish to flush the JPA cache. Then I could not get related etities using JPA. Restarting Glassfish did not help. Redeplying the EAR did not help. No particular exceptions were logged.

Undeploying, restarting Glassfish, and deplying helped. Strange.

glassfishrobot commented 13 years ago

@glassfishrobot Commented mvatkina said: CAUSED BY: java.util.ConcurrentModificationException AT java.util.AbstractList$Itr.checkForComodification:372 AbstractList$Itr.next:343 CollectionChangeRecord.mergeRecord:270 ObjectChangeSet.mergeObjectChanges:604UnitOfWorkChangeSet.mergeObjectChanges:481 AttributeChangeTrackingPolicy.createObjectChangeSet:63 DeferredChangeDetectionPolicy.calculateChanges:89 AttributeChangeTrackingPolicy.calculateChangesForExistingObject:47 DatabaseQueryMechanism.updateObjectForWriteWithChangeSet:1091 UpdateObjectQuery.executeCommitWithChangeSet:84 DatabaseQueryMechanism.executeWriteWithChangeSet:286 WriteObjectQuery.executeDatabaseQuery:58 DatabaseQuery.execute:675 DatabaseQuery.executeInUnitOfWork:589 ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery:109 ObjectLevelModifyQuery.executeInUnitOfWork:86 UnitOfWorkImpl.internalExecuteQuery:2857 AbstractSession.executeQuery:1225 AbstractSession.executeQuery:1207 AbstractSession.executeQuery:1167 CommitManager.commitChangedObjectsForClassWithChangeSet:233 CommitManager.commitAllObjectsForClassWithChangeSet:163 CommitManager.commitAllObjectsWithChangeSet:116 AbstractSession.writeAllObjectsWithChangeSet:3260 UnitOfWorkImpl.commitToDatabase:1403 RepeatableWriteUnitOfWork.commitToDatabase:547 UnitOfWorkImpl.commitToDatabaseWithChangeSet:1508 UnitOfWorkImpl.issueSQLbeforeCompletion:3128 RepeatableWriteUnitOfWork.issueSQLbeforeCompletion:268 AbstractSynchronizationListener.beforeCompletion:157 JTASynchronizationListener.beforeCompletion:68

glassfishrobot commented 13 years ago

@glassfishrobot Commented mm110999 said: -Is there a possibility that your EntityManager is some how reentered? That is are you using application managed EM? -The stack contains DeferredChangeDetectionPolicy which implies that you do not have weaving turned on. Did you turn it off explicitly?

-In any case, can you please try your scenario against nightly of GlassFish 3.1. That would help us isolate it against latest code base.

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said:

-Is there a possibility that your EntityManager is some how reentered? That is are you using application managed EM?

I'm not sure. I have a @Stateless EJB for each Entity that handles basic CRUD operations. Each of these EJBs is a subclass of a generic base class, see below.

public abstract class GenericEjb<T, ID extends Serializable> implements GenericLocal<T, ID> { private Class persistentClass = getPersistentClass(); private String persistentClassName = persistentClass.getSimpleName(); protected Logger log = LoggerFactory.getLogger(GenericEjb.class);

@PersistenceContext(unitName = "pu1") private EntityManager em;

@SuppressWarnings("unchecked") private Class getPersistentClass() { Class c = getClass(); Type t = c.getGenericSuperclass();

// Using EJB 3.1 generated interface results in a subclass... Try again! if (!(t instanceof ParameterizedType)) t = c.getSuperclass().getGenericSuperclass();

if (!(t instanceof ParameterizedType))

{ System.out.println("AARRGGHH!! superduper=" + t.toString()); return null; }

// This line caused a java.lang.ClassCastException with EJB 3.1: // java.lang.Class cannot be cast to java.lang.reflect.ParameterizedType ParameterizedType pt = (ParameterizedType) t; return (Class) pt.getActualTypeArguments()[0]; }

// Business method

public T find(ID id) { log.debug("find<{}>({})", persistentClassName, id); return em.find(persistentClass, id); }

// ... }

The update method in the CRUD EJB looks something like this:

@Stateless public class FooEjb extends GenericEjb<Foo, Integer> implements FooLocal { // ...

public void update(int id, String name) { log.debug("update({},{})", id, name); Foo foo = find(id); foo.setName(name); }

// ... }

I have plenty of these, and they all work fine. (Except in this rare case).

-The stack contains DeferredChangeDetectionPolicy which implies that you do not have weaving turned on. Did you turn it off explicitly?

Not that I know. (But there's no gurarantee that I have done something silly at some point). How can I check that?

-In any case, can you please try your scenario against nightly of GlassFish 3.1. That would help us isolate it against latest code base.

I can do that if necessary. But it appears to be a non-trivial task on WinXP, since there's no installer bundled with the zip file. And there appears to be some issues with it, see e.g. http://forums.java.net/node/706433 . But if you really need it, I'll give it a try. Just let me know.

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said: By the way, I just noticed that if I do fooLocal.update() WITH THE SAME NAME (i.e. without changing the name) on the problematic record, no exception is thrown.

And, as I said, the problem only happens for ONE specific record. Not the others in the same table.

Hope this is of help...

glassfishrobot commented 13 years ago

@glassfishrobot Commented mm110999 said: I do not spot any issue with the code. However, I do not get your last comment about fooLocal.update().

weaving Look for property "eclipselink.weaving" set to false in your persistence.xml

GlassFish 3.1 There is a zip install available. You can get it from http://dlc.sun.com.edgesuite.net/glassfish/3.1/nightly/latest-glassfish.zip. It would be nice to get it reproduced on a nightly to debug this better.

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said:

I do not get your last comment about fooLocal.update().

FooEjb has a local interface FooLocal. In my servlet I have @EJB FooLocal fooLocal; and call fooLocal.update(id, newName);

When newName is the same as the existing name for the Foo entity with the specified id, the problem does not occur, only when newName is different. And it (only occurs for a certain id). Isn't that strange?

Please ask again if this is not clarifying.

weaving; Look for property "eclipselink.weaving" set to false in your persistence.xml

Nope, there's no such property in my persistence.xml. (In fact I have an empty tag).

GlassFish 3.1

Ok, I will try the zip install. Thanks for the link!

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said: I may have found something that could help narrow the problem down a bit.

Contrary to my earlier experience, the problem does indeed occur for any instance, not just for a specific id. It just has to have some related data.

My application has several Entity classes. The problematic one (called Foo above, actually called CarModelGroup) has a many-to-many relationship with another (called CarModel):

@ManyToMany() @JoinTable(name="car_model_groups_car_models", joinColumns=@JoinColumn(name="car_model_group_id"), inverseJoinColumns=@JoinColumn(name="car_model_id")) public List getCarModels()

{ Collections.sort(carModels, CarModel.carModelOrder); // Suspect return carModels; }

The problem occurs iff the CarModelGroup has at least one CarModel, but not for an empty CarModelGroup. When I commented out the line with Collections.sort(...), the problem went away.

Here's the Comparator passed to Collections.sort:

public static final Comparator carModelOrder = new Comparator() { public int compare(CarModel c1, CarModel c2)

{ int x; x = c1.getCarMaker().getName().compareToIgnoreCase(c2.getCarMaker().getName()); if (x != 0) return x; x = c1.getName().compareToIgnoreCase(c2.getName()); if (x != 0) return x; return c1.getYear().compareToIgnoreCase(c2.getYear()); }

};

My apologies for not discovering this earlier. Hope this helps.

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said: Just checking: do you still need me to install Glassfish 3.1 beta and check if the bug is there, or did my latest comment give enough information for you to find it?

glassfishrobot commented 13 years ago

@glassfishrobot Commented mm110999 said: I do not think it is necessary to try this with 3.1. I think you have nailed the issue. It is not good idea to call sort() on a getter when you have PROPERTIES access. This is because the persistence provider also uses the getter to access the entity state and that may result in issue like the one you are running into. For a simpler ordering than the one you desire, it would be best to use @OrderBy. You might have to use another getter(that does not correspond to persistence property) that does sorting for you

The problem occurs iff the CarModelGroup has at least one CarModel, but not for an empty CarModelGroup. Can you please distill a reproducible test with data set you described. That would help a lot to get to bottom of this to issue faster.

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said:

For a simpler ordering than the one you desire, it would be best to use @OrderBy.

Indeed. I do just that in many other entities. And in this case, I would love to do something like @OrderBy("CarMaker.name, name, year"), but JPA does not appear to support @OrderBy on a related entity. So I have to settle for my less elegant solution with a hand-coded sorter.

You might have to use another getter(that does not correspond to persistence property) that does sorting for you.

I'm not sure how I could do that. The list is used in serveral places, accessed in JSPs with EL. (Very convenient!) And even if I write a @Transient getter method that does the sorting, it would have to access the list in the same way as the vanilla getter. And that would cause the same problem, I presume.

Is manual sorting in a entity getter method really illegal in JPA?

Can you please distill a reproducible test with data set you described. That would help a lot to get to bottom of this to issue faster.

I guess I could write a small webapp (with a database, entities, EJBs, servlet and JSP) that reproduces the problem, but that is a non-trivial task that would take serveral days.

glassfishrobot commented 13 years ago

@glassfishrobot Commented mm110999 said:

I'm not sure how I could do that. The list is used in serveral places, accessed in JSPs with EL. (Very convenient!) And even if I write a @Transient getter method >that does the sorting, it would have to access the list in the same way as the vanilla getter. And that would cause the same problem, I presume. It should not. The @Transient method will not be used by the persistence provider to access state of your entity.

Is manual sorting in a entity getter method really illegal in JPA? The spec does not say either way. However it is not good practice to do it. The persistence provider will call into your method when ever it wants to access state of your entity. This will result in the sort being performed. Not optimal.

I guess I could write a small webapp (with a database, entities, EJBs, servlet and JSP) that reproduces the problem We do not need a fancy front end for the reproduction. All we need is some sql scripts that populate the data that you think recreates the issue and a call into EJB that accesses and updates the data.

glassfishrobot commented 13 years ago

@glassfishrobot Commented tmpsa said:

The @Transient method will not be used by the persistence provider to access state of your entity.

I just tried to use such a @Transient access method that does the sorting, and it seems to be a successful workaround.

By the way, I have a strong hunch that my previously reported bug was also caused by manual sorting inside an entity getter (of a List), see http://java.net/jira/browse/GLASSFISH-14972

Hope this helps in further narrowing down the problem.

(It would still be a significant task to create a full-fledged bug-reproducing EJB application that accesses and updates some data. I could mail you directly with the source of the related EJBs and Entities, if you wish).

glassfishrobot commented 13 years ago

@glassfishrobot Commented mm110999 said: The usage pattern of calling sort() in properties based getter is not recommended

glassfishrobot commented 13 years ago

@glassfishrobot Commented Was assigned to mm110999

glassfishrobot commented 7 years ago

@glassfishrobot Commented This issue was imported from java.net JIRA GLASSFISH-15477

glassfishrobot commented 13 years ago

@glassfishrobot Commented Reported by tmpsa

glassfishrobot commented 13 years ago

@glassfishrobot Commented Marked as won't fix on Thursday, May 19th 2011, 7:13:07 am