Skip to content

[2.2.x] OPENJPA-2817: OpenJPA enhancer needs improved reentrancy #64

New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Merged
merged 1 commit into from
Jul 13, 2020

Conversation

jgrassel
Copy link
Contributor

@jgrassel jgrassel commented Jul 13, 2020

OpenJPA's class transformer was designed in a time when ClassLoader access was synchronized. Because it was assumed that if the ClassLoader caused another class to load while it was already enhancing a class, causing another triggering of the class transformer, it was assumed that that could only happen if OpenJPA was bundled as part of the application (loaded by the app classloader in an EE environment), and was safe to assume that this reentrant invocation would not be a request to enhance a persistent type, and thus return null (no enhancement needed).

With Java 7+, ClassLoader locking has been changed (https://docs.oracle.com/javase/7/docs/technotes/guides/lang/cl-mt.html).

Now, because the same ClassLoader (and thus same transformer), can be invoked concurrently by different threads, this assumption was no longer valid.

OpenJPA needs to be updated to be mindful of reentrancy on a thread scope, instead of just simply reacting to reentrancy whenever it happens.

JIRA: https://issues.apache.org/jira/browse/OPENJPA-2817

@jgrassel jgrassel self-assigned this Jul 13, 2020
@jgrassel
Copy link
Contributor Author

Will create a trunk PR after this has been reviewed.

@rmannibucau
Copy link
Contributor

@jgrassel , for now I'm trying to see in which case we need that. Say me if I'm wrong but the scope is only about the javaagent (other cases - ie container deployment enhancement and build time enhancement - must be single threaded by construction today). Since all entities are loaded when the EMF is created it should also be single threaded until the EMF is lazily created and concurrently at runtime - which must be handled by the EMF then IMO. The comment is surprising though cause it means it only happens when loading openjpa itself - which kind of implies the temp loader should filter openjpa "runtime" instead of adding this boolean. So wonder if you are able to replicate the issue in a test (even abusing of countdownlatch or "sleep" in loadClass) to ensure we fix an issue instead of propagating dead code. Hope it makes sense.

@jgrassel
Copy link
Contributor Author

@rmannibucau This issue was brought to my awareness after Open Liberty's application classloader was updated to allow multi-threaded concurrency (even though concurrency was allowed after JDK 7, OpenLiberty only very recently updated its own application classloader to allow this). Presumably, this would also affect other application servers which are also updated to take advantage of that particular approach for performance improvement.

I was not able to replicate this in a test environment, but my customer has confirmed that this resolved the symptoms caused by the old design approach (in the form of entity types not being class transformed).

@rmannibucau
Copy link
Contributor

@jgrassel can you thread dump (even with a monkey patch) when the issue occurs? OpenLiberty is supposed to have the EMF ready during CDI boot (I know there is a chicken egg issue between cdi and jpa in the spec so can be a toggle thing in OpenLiberty) and this part is monothreaded so classes are either concurrently loaded before (which can be but would be weird and wouldn't use enhancement at deploy time properly) or it is when bypassing this part (not EE case?).
I'm just trying to refine the exact use case cause today I would be more keen to remove the boolean but I'm sure I miss a case if you hit it hard, we just need to ensure we fully get why ;). Also happy to run it locally if you can share a mvn project on github.

@jgrassel
Copy link
Contributor Author

True, OpenLiberty creates the EMF during application start (it has to, in order to register the Class Transformer [with the application classloader] before any of the persistent capable classes are loaded), but the transformation is invoked when the class is first loaded, which can happen at any time after the transformer has been registered. In the customer scenario, two concurrent threads triggered a classload on the same application classloader. Before the classloader perf-update, one thread would secure a lock on the classloader, while the second thread would get blocked, the class that it requested would be enhanced, and then it would unlock the classloader, which then the other thread would get its lock.

Now, both threads can concurrently request a class load without one being blocked, so both can enter the transformer (enhancer) and the same time. One thread sets the _transforming boolean, and while that thread is doing its transforming work, the other thread sees that _transforming has been set, assumes that this is a reentrant call(x), and returns null -- meaning don't transform the class. So the second thread's transform request does not happen, and the class is loaded untransformed, and thus cannot be used by openjpa.

(x) - The _transforming field was to prevent reentrancy which, in the days of single-threaded access, was assumed to be only possible by the thread that had the lock on the classloader, and during the transform, a classload occurred while in the transform method body and that classload (an openjpa library class is the only possibility at this point, it wouldn't be a PC-type) is being performed by the classloader that has the enhancer registered to it. Since it was safe to assume that a reentrant call to the enhancer could only be an openjpa library type, that would never be enhanced, so just return null instead of going through the effort spent to check the type against the persistence unit's PC-type membership list.

@jgrassel
Copy link
Contributor Author

Now, I can try to come up with an example to demonstrate it, but I am on a very tight deadline, so I can agree to delay committing the update to trunk, but I'm going to insist on the example not being a gating requirement for integrating into 2.2.x.

Signed-off-by: Joe Grassel <jgrassel@apache.org>
@jgrassel
Copy link
Contributor Author

(updated the commit to rename _tl to _isTransformingInLocalThread based on a review comment by Albert. Thanks!)

@jgrassel jgrassel merged commit 172c084 into apache:2.2.x Jul 13, 2020
@rmannibucau
Copy link
Contributor

@jgrassel Hmm, a few things which makes this fix looking very weird to me:

  1. fact is it is already synchronized by metadatarepository until Preload=true (see org.apache.openjpa.meta.MetaDataRepository#preload) so concurrency here is very unlikely so removing the threadlocal (and boolean) sounds better to me - I guess only Geronimo (and maybe WAS?) was using it out there due to a not conrrectly configured temp loader.
  2. that _transforming boolean was not here for exactly what you describe but for the case you load a transformed class and - using the javaagent, not a deploy time or build time enhancement - you load openjpa (org.apache.openjpa.enhance.PCEnhancer typically but a few other classes as well).
  3. a correct concurrent classloader locks around transform so the case you describe does not really happen and the boolean protection is not needed even with the javaagent (classloader#loadclass > findClass > transform for custom classloaders or loadclass > findclass > defineClass > transform for the jvm classloader)

So at the end it sounds like a bug in the classloader you use in openliberty so I would fix it there.

BTW where is Albert's review? I can't see it it seems.

@jgrassel
Copy link
Contributor Author

jgrassel commented Jul 13, 2020

I asked Albert via company internal slack to review my changes, he's not set up a link between github and apache yet.

Joe Grassel  11:07 AM
Hey, Albert.  Hope things are going well!  I was going to ask if you could do an OpenJPA code review, as Will is out until tomorrow and I've got a customer pressuring for an ifix asap.  https://issues.apache.org/jira/browse/OPENJPA-2817

Albert Lee  12:31 PM
Jody,  I have reviewed the PR.  I don't have access to approve the PR.
Once one comment:
private static final ThreadLocal<Boolean> tl = new ThreadLocal();
12:33
you may want to add a comment for that this variable is for.   tl does not means anything to me.  The value in this ThreadLocal is irrelevant since you are just checking for not null. Change it to isTransformingInLocalThread ?

Joe Grassel  12:33 PM
Oh, sure, that's a good idea.

@jgrassel
Copy link
Contributor Author

@rmannibucau

  1. preload=true is not enabled by default (at least it is not in the 2.2.x branch.) Therefore the MDR will lazily initialize itself in incrementals that it finds necessary. Also, processing reaches the _transforming check before touching the MDR (which yes, has synchronized access, but it is invoked only after _transforming is checked and set)

  2. The _transforming field is there because it is possible for a classloader load to occur while the transform() is being executed, where the second load is an OpenJPA library type (for the scenario where OpenJPA is bundled in the application and thus is being loaded by the application classloader that will call on the enhancer to transform a class before loading it), which when classloader access is synchronized across threads, a reentrant call could be assumed to be this situation. See Marc's commit from 14 years ago:

commit f74ac8b6b9f8d6f5c4fdae6798018458687741fc
Author: Marc Prud'hommeaux <mprudhom@apache.org> 2006-09-29 21:00:40
Committer: Marc Prud'hommeaux <mprudhom@apache.org> 2006-09-29 21:00:40
Parent: 1236605135400dd42e4942d25cff310ac304dac0 (removed unneeded imports)
Child: e30632b60b26430fe4f95dd3f5a3bd79c4a36f9f (Trying a new approach to automatic enhancement in a container.  Might have to revert.)
Branches: 2.2.x_debug, 2.2.x_OJ2287, 2.2.x_OJ2790, 2.2.x_TS003776060_PH26967, 2.4.x_OJ2790, currentaccessdiag, DIAG_TS003449484, master, master_OJ2790, OJ2603, OPENJPA_2817_22X, pmr42014_211_788, QueryDebugForCase, trunk, TS000798754, TS001107772, TS001228829_DIAG01, TS001491495, TS002193952_detach_issue, TS002637050_testfix_2.2.x, ibmgit/1.2.x, ibmgit/2.2.x_debug and 71 more branches

Prevent reentrant calls to transform() in order to prevent attempts to enhance OpenJPA libraries (for cases where OpenJPA falls under the control of the enhancing class loader).

git-svn-id: https://svn.apache.org/repos/asf/incubator/openjpa/trunk@451517 13f79535-47bb-0310-9956-ffa450edef68

However, because now the classloader isn't going to synchronize between threads, we can't make that assumption anymore, hence we need to rely on a marker that is independent of the thread -- a ThreadLocal instead of a boolean.

  1. This is an issue within the transformer/enhancer, I do not think shifting the burden of single-transformer entrancy to the application server is the correct solution.

@rmannibucau
Copy link
Contributor

rmannibucau commented Jul 13, 2020

@jgrassel

  1. hmm, depends once again the env, with a javaagent it will be triggered on a new MyEntity() but on other cases it will not. And for javaagent this is not an issue since the context is protected properly by the classloader normally.
  2. this is a setup bug we shouldn't have. Correct fix is probably to prevent openjpa to be loaded from the temp loader (likely container integration) and/or to skip openjpa stack in transform (we can skip more actually, see https://github.com/apache/tomee/blob/master/container/openejb-core/src/main/java/org/apache/openejb/util/classloader/URLClassLoaderFirst.java#L207 for a list example). A toggle is a quick and dirty fix but does not solve the cause of this issue IMHO. The threadlocal generalizes this workaround but still does not tackle the source of the issue. I'd like to fix it right on master at least.
  3. The transformer is executed in a secured context by design/contract so this must be an issue with the env so part of 2 (the exclusion list in transform) and potentially server classloader enhancement support.

What the boolean - with a threadlocal or not - enables is to not enhance some classes - this is why sometimes we can have "missing metadata" error in some setup because if an enhancement triggers the load of another entity, this last one is not enhanced - depends the tmploader which can be the same as app loader when using an agent to speed up the execution/boot.

FYI: dropping the boolean the build still works fine so guess we should work forward the exclusion list.

What about something like that:

diff --git a/openjpa-kernel/src/main/java/org/apache/openjpa/enhance/PCClassFileTransformer.java b/openjpa-kernel/src/main/java/org/apache/openjpa/enhance/PCClassFileTransformer.java
index 872d413a4..1126762ef 100644
--- a/openjpa-kernel/src/main/java/org/apache/openjpa/enhance/PCClassFileTransformer.java
+++ b/openjpa-kernel/src/main/java/org/apache/openjpa/enhance/PCClassFileTransformer.java
@@ -55,7 +55,6 @@ public class PCClassFileTransformer
     private final ClassLoader _tmpLoader;
     private final Log _log;
     private final Set _names;
-    private boolean _transforming = false;
 
     /**
      * Constructor.
@@ -107,6 +106,9 @@ public class PCClassFileTransformer
	     _log.info(_loc.get("runtime-enhance-pcclasses"));
     }
 
+    // this must be called under a proper locking, this is guaranteed by either
+    // a correct concurrent classloader with transformation support OR
+    // a mono-threaded access guarantee (build, deploy time enhancements).
     @Override
     public byte[] transform(ClassLoader loader, String className,
	 Class redef, ProtectionDomain domain, byte[] bytes)
@@ -115,16 +117,13 @@ public class PCClassFileTransformer
	     return null;
 
	 // JDK bug -- OPENJPA-1676
-        if (className == null) {
+        if (className == null ||
+                className.startsWith("org/apache/openjpa/") ||
+                className.startsWith("java/") ||
+                className.startsWith("javax/") ||
+                className.startsWith("jakarta/")) {
	     return null;
	 }
-        // prevent re-entrant calls, which can occur if the enhancing
-        // loader is used to also load OpenJPA libraries; this is to prevent
-        // recursive enhancement attempts for internal openjpa libraries
-        if (_transforming)
-            return null;
-
-        _transforming = true;
 
	 return transform0(className, redef, bytes);
     }
@@ -151,7 +150,7 @@ public class PCClassFileTransformer
	     try {
	         PCEnhancer enhancer = new PCEnhancer(_repos.getConfiguration(),
	                 new Project().loadClass(new ByteArrayInputStream(bytes),
-                                _tmpLoader), _repos);
+                                _tmpLoader), _repos, _tmpLoader);
	         enhancer.setAddDefaultConstructor(_flags.addDefaultConstructor);
	         enhancer.setEnforcePropertyRestrictions
	                 (_flags.enforcePropertyRestrictions);
@@ -172,7 +171,6 @@ public class PCClassFileTransformer
	         throw (IllegalClassFormatException) t;
	     throw new GeneralException(t);
	 } finally {
-            _transforming = false;
	     if (returnBytes != null && _log.isTraceEnabled())
	         _log.trace(_loc.get("runtime-enhance-complete", className,
	             bytes.length, returnBytes.length));
@@ -186,9 +184,9 @@ public class PCClassFileTransformer
	 if (redef != null) {
	     Class[] intfs = redef.getInterfaces();
	     for (int i = 0; i < intfs.length; i++)
-                if (PersistenceCapable.class.getName().
-                    equals(intfs[i].getName()))
-                    return Boolean.valueOf(!isEnhanced(bytes));
+                if (PersistenceCapable.class.getName()
+                    .equals(intfs[i].getName()))
+                    return false;
	     return null;
	 }
 
@@ -198,8 +196,6 @@ public class PCClassFileTransformer
	     return null;
	 }
 
-        if (clsName.startsWith("java/") || clsName.startsWith("javax/"))
-            return null;
	 if (isEnhanced(bytes))
	     return Boolean.FALSE;

@jgrassel
Copy link
Contributor Author

This has nothing to do with the temp classloader. The temp classloader itself doesn't have an enhancer registered to it, it only exists as a means for the persistence provider impl to load a class (in order to inspect it via reflection, though OpenJPA uses SERP for that business, I don't believe OpenJPA does much with the temp classloader that PersistenceUnitInfo can provide) without using the real application classloader (because once a class is loaded, that's it, the opportunity to enhance it has been missed.)

@jgrassel
Copy link
Contributor Author

Personally, I'm not a fan of the "exclude list", because that adds a lot of unnecessary processing time, as String comparing a jar with hundreds and even thousands of classes against a group of patterns is not going to come cheap. In an application server environment, as long as the jpa provider impl is not bundled with the application (that is, loaded by the same classloader that we register a class transformer with), then the reentrancy that the _transforming boolean was put in to guard against is not going to happen. But it can if openjpa is bundled as part of the application and is loaded by the classloader which has the transformer registered to it. That's what Marc's original method was to guard against.

But like I've said many times now, with ClassLoaders that permit concurrent classloading (and thus concurrent enhancing), the boolean method falls short because it doesn't detect thread-scoped reentrancy.

@jgrassel
Copy link
Contributor Author

jgrassel commented Jul 13, 2020

Okay, here is a maven project that will demonstrate the problem with an application server using openjpa.

Couple of notes:

  1. Yes, you can use the mvn liberty:start goal in the ear sub-project (after building the entire project) to download Open Liberty and start the server, but it will use Eclipselink. URL to hit the test servlet is http://localhost:9080/jpatest/SimpleTestServlet .
  2. Open Liberty does not ship with OpenJPA, only Eclipselink. It's Commercial Liberty that ships with OpenJPA in the form of the jpa-2.0 feature. The maven tools will thus not be able to download the jpa-2.0 feature because it is not available to the open public.

However, you can build and extract the ear application generated, and run it on an application server that will run with OpenJPA. The problem will only manifest itself if the application classloader allows for concurrent classloading and enhancement.

Example output using Commercial Liberty with the ear generated by this application:

OPENJPA-2817 Test Case

Starting Worker thread 1...
Starting Worker thread 2...
Worker Threads Complete.
Worker thread Thread-30 started.

Now to verify enhancement. Look at the interfaces associated with EntityA and EntityC:
Class: model.EntityA
Worker thread Thread-30 finished.
Interfaces:
org.apache.openjpa.enhance.PersistenceCapable


Class: model.EntityC
No Interfaces Found
Worker thread Thread-31 started.
Worker thread Thread-31 finished.

Note that with Eclipselink, which has a bytecode weaver that properly manages reentrancy, doesn't suffer from this problem:

OPENJPA-2817 Test Case

Starting Worker thread 1...
Starting Worker thread 2...
Worker thread Thread-16 started.
Worker thread Thread-17 started.
Worker thread Thread-17 finished.
Worker thread Thread-16 finished.
Worker Threads Complete.

Now to verify enhancement. Look at the interfaces associated with EntityA and EntityC:
Class: model.EntityA
Interfaces:
java.lang.Cloneable
org.eclipse.persistence.internal.weaving.PersistenceWeaved
org.eclipse.persistence.internal.descriptors.PersistenceEntity
org.eclipse.persistence.internal.descriptors.PersistenceObject
org.eclipse.persistence.queries.FetchGroupTracker
org.eclipse.persistence.internal.weaving.PersistenceWeavedFetchGroups
org.eclipse.persistence.descriptors.changetracking.ChangeTracker
org.eclipse.persistence.internal.weaving.PersistenceWeavedChangeTracking
org.eclipse.persistence.internal.weaving.PersistenceWeavedRest


Class: model.EntityC
Interfaces:
java.lang.Cloneable
org.eclipse.persistence.internal.weaving.PersistenceWeaved
org.eclipse.persistence.internal.descriptors.PersistenceEntity
org.eclipse.persistence.internal.descriptors.PersistenceObject
org.eclipse.persistence.queries.FetchGroupTracker
org.eclipse.persistence.internal.weaving.PersistenceWeavedFetchGroups
org.eclipse.persistence.descriptors.changetracking.ChangeTracker
org.eclipse.persistence.internal.weaving.PersistenceWeavedChangeTracking
org.eclipse.persistence.internal.weaving.PersistenceWeavedRest

openjpa_2817-project.zip

@jgrassel
Copy link
Contributor Author

And in the OpenJPA case above, here is a cut of the trace log file showing EntityA (thread 000000a2) being enhanced, but EntityC (thread 000000a3) is not:

[7/13/20 17:44:15:317 CDT] 0000008f JPAPUnitInfo_ >  transformClass: PUID = PuId=jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear#webapp.war#TestPU, class name = web.SimpleTestServlet$Worker, classBytes.length = 1907 Entry  
                                 (file:/Users/jgrassel/Dev/Liberty/WS-CD-Open/dev/build.image/wlp/usr/servers/defaultServer/apps/jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear <no signer certificates>)
                                 com.ibm.ws.classloading.internal.AppClassLoader@369bc432
[7/13/20 17:44:15:317 CDT] 0000008f JPAPUnitInfo  >  classNeedsTransform : PUID = PuId=jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear#webapp.war#TestPU, class name = web.SimpleTestServlet$Worker Entry 
[7/13/20 17:44:15:317 CDT] 0000008f JPAPUnitInfo  <  classNeedsTransform : web.SimpleTestServlet$Worker needs transform. Exit 
[7/13/20 17:44:15:317 CDT] 0000008f JPAPUnitInfo_ 3   transformer: org.apache.openjpa.persistence.PersistenceProviderImpl$ClassTransformerImpl@4192b75d , className: web.SimpleTestServlet$Worker
[7/13/20 17:44:15:317 CDT] 0000008f JPAPUnitInfo_ 3   transformer:org.apache.openjpa.persistence.PersistenceProviderImpl$ClassTransformerImpl@4192b75d, web.SimpleTestServlet$Worker is NOT transformed. Byte length(old/new)=1907/1907
[7/13/20 17:44:15:317 CDT] 0000008f JPAPUnitInfo_ <  transformClass: 0/1 Exit 
[7/13/20 17:44:15:321 CDT] 000000a3 JPAPUnitInfo_ >  transformClass: PUID = PuId=jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear#webapp.war#TestPU, class name = model.EntityC, classBytes.length = 1219 Entry  
                                 (file:/Users/jgrassel/Dev/Liberty/WS-CD-Open/dev/build.image/wlp/usr/servers/defaultServer/apps/jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear <no signer certificates>)
                                 com.ibm.ws.classloading.internal.AppClassLoader@369bc432
[7/13/20 17:44:15:321 CDT] 000000a2 JPAPUnitInfo_ >  transformClass: PUID = PuId=jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear#webapp.war#TestPU, class name = model.EntityA, classBytes.length = 2258 Entry  
                                 (file:/Users/jgrassel/Dev/Liberty/WS-CD-Open/dev/build.image/wlp/usr/servers/defaultServer/apps/jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear <no signer certificates>)
                                 com.ibm.ws.classloading.internal.AppClassLoader@369bc432
[7/13/20 17:44:15:322 CDT] 000000a2 JPAPUnitInfo  >  classNeedsTransform : PUID = PuId=jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear#webapp.war#TestPU, class name = model.EntityA Entry 
[7/13/20 17:44:15:322 CDT] 000000a3 JPAPUnitInfo  >  classNeedsTransform : PUID = PuId=jpasandbox_simple_web.ear-1.0-SNAPSHOT.ear#webapp.war#TestPU, class name = model.EntityC Entry 
[7/13/20 17:44:15:322 CDT] 000000a2 JPAPUnitInfo  <  classNeedsTransform : model.EntityA needs transform. Exit 
[7/13/20 17:44:15:322 CDT] 000000a2 JPAPUnitInfo_ 3   transformer: org.apache.openjpa.persistence.PersistenceProviderImpl$ClassTransformerImpl@4192b75d , className: model.EntityA
[7/13/20 17:44:15:322 CDT] 000000a3 JPAPUnitInfo  <  classNeedsTransform : model.EntityC needs transform. Exit 
[7/13/20 17:44:15:322 CDT] 000000a3 JPAPUnitInfo_ 3   transformer: org.apache.openjpa.persistence.PersistenceProviderImpl$ClassTransformerImpl@4192b75d , className: model.EntityC
[7/13/20 17:44:15:322 CDT] 000000a3 JPAPUnitInfo_ 3   transformer:org.apache.openjpa.persistence.PersistenceProviderImpl$ClassTransformerImpl@4192b75d, model.EntityC is NOT transformed. Byte length(old/new)=1219/1219
[7/13/20 17:44:15:322 CDT] 000000a3 JPAPUnitInfo_ <  transformClass: 0/1 Exit 
[7/13/20 17:44:15:325 CDT] 000000a2 Enhance       3   openjpa.Enhance: Trace: "model.EntityA" requires runtime enhancement: true
[7/13/20 17:44:15:366 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Loading metadata for "class model.EntityA" under mode "[META][QUERY]".
[7/13/20 17:44:15:387 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Parsing class "model.EntityA".
[7/13/20 17:44:15:387 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Parsing package "model.EntityA".
[7/13/20 17:44:15:408 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Generating default metadata for type "model.EntityA".
[7/13/20 17:44:15:408 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Using reflection for metadata generation.
[7/13/20 17:44:15:420 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Set persistence-capable superclass of "model.EntityA" to "null".
[7/13/20 17:44:15:422 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Resolving metadata for "model.EntityA@5732165".
[7/13/20 17:44:15:422 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityA@5732165.entityB".
[7/13/20 17:44:15:422 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Loading metadata for "class model.EntityB" under mode "[META][QUERY]".
[7/13/20 17:44:15:422 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Parsing class "model.EntityB".
[7/13/20 17:44:15:422 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Generating default metadata for type "model.EntityB".
[7/13/20 17:44:15:422 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Using reflection for metadata generation.
[7/13/20 17:44:15:423 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Set persistence-capable superclass of "model.EntityB" to "null".
[7/13/20 17:44:15:430 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityA@5732165.id".
[7/13/20 17:44:15:430 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityA@5732165.lazyStringData".
[7/13/20 17:44:15:430 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityA@5732165.strData".
[7/13/20 17:44:15:430 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityA@5732165.version".
[7/13/20 17:44:15:431 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: Resolving metadata for "model.EntityB@55778804".
[7/13/20 17:44:15:431 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityB@55778804.id".
[7/13/20 17:44:15:431 CDT] 000000a2 MetaData      3   openjpa.MetaData: Trace: 	Resolving field "model.EntityB@55778804.strData".
[7/13/20 17:44:15:432 CDT] 000000a2 Enhance       3   openjpa.Enhance: Trace: Enhancing type "class model.EntityA" loaded by com.ibm.ws.classloading.internal.ShadowClassLoader@79eae7e4.
[7/13/20 17:44:15:459 CDT] 000000a2 Enhance       3   openjpa.Enhance: Trace: Enhancement for "model.EntityA" completed. Class size: [2,258/10,803]
[7/13/20 17:44:15:459 CDT] 000000a2 JPAPUnitInfo_ 3   transformer:org.apache.openjpa.persistence.PersistenceProviderImpl$ClassTransformerImpl@4192b75d, model.EntityA is transformed. Byte length(old/new)=2258/10803
[7/13/20 17:44:15:459 CDT] 000000a2 JPAPUnitInfo_ <  transformClass: 1/1 Exit 

Notice we only see: openjpa.Enhance: Trace: "model.EntityA" requires runtime enhancement: true, but not for EntityC, because the boolean short circuits hitting the MDR.

@struberg
Copy link
Member

I've now read the SE7 documentation about a few times and I think the ThreadLocal is not enough for this specific case. From the ClassLoader doc it appears that the lock now got moved from a full exclusive Semaphore to a Lock by ClassLoader+Classname.
So - without digging into all the details - it seems logical to also move from a Boolean to a Map<String, Boolean> were the key is the CL id + Classname ?

@rmannibucau
Copy link
Contributor

rmannibucau commented Jul 14, 2020

@struberg point is that the classloader does it and the transformer is called under that lock already
@jgrassel will test your sample but today I'm off but I will come back to you likely tomorrow, thanks a lot for setting up a project!

edit: tested on tomee adding:

        <plugin>
            <groupId>org.apache.tomee.maven</groupId>
            <artifactId>tomee-maven-plugin</artifactId>
            <version>8.0.3</version>
        </plugin>

It works as expected:

Starting Worker thread 1...
Starting Worker thread 2...
Worker thread Thread-63 started.
Worker Threads Complete.

Now to verify enhancement. Look at the interfaces associated with EntityA and EntityC:
Worker thread Thread-64 started.
Worker thread Thread-63 finished.
Worker thread Thread-64 finished.
Class: model.EntityA
Interfaces:
org.apache.openjpa.enhance.PersistenceCapable


Class: model.EntityC
Interfaces:
org.apache.openjpa.enhance.PersistenceCapable he.openjpa.enhance.PersistenceCapable
Worker Threads Complete.

Now to verify enhancement. Look at the interfaces associated with EntityA and EntityC:
Worker thread Thread-66 finished.
Class: model.EntityA
Interfaces:
org.apache.openjpa.enhance.PersistenceCapable


Class: model.EntityC
Interfaces:
org.apache.openjpa.enhance.PersistenceCapable

In particular with the proposed patch ^^. Any way to patch liberty locally to run openjpa (creating my liberty.openjpa.jar with blueprint registration maybe?).

edit 2: just checked openliberty sources (https://github.com/OpenLiberty/open-liberty/ right?), seems all classloaders are marked as concurrent but wrongly get the lock, in particular when there is a transformer so this is not an openjpa issue but an openliberty issue, no? Look https://github.com/OpenLiberty/open-liberty/blob/integration/dev/com.ibm.ws.classloading/src/com/ibm/ws/classloading/internal/AppClassLoader.java#L272 for ex, if no transformer is it correctly impl, if there is a transfomer it bypasses the lock :s.

@rmannibucau
Copy link
Contributor

Created #65 as a proposed fix on master if you want to give it a try.

@jgrassel
Copy link
Contributor Author

Here's a version of the test bucket that will run with the jpa-2.2 complaint version of OpenJPA

You'll need to edit the pom.xml file at the project root, and put in the full classname for the ProviderImpl class, as well as the directory where all of the jpa impl jar and its dependent libraries are (be sure to remove the jars containing javax.* packages) -- I moved the openjpa impl jar into lib so that all of the jars were in one dir:

        <!-- Third Party JPA Persistence Provider Configuration 
             Persistence Provider Class - fully qualified classname of the provider's implementation of javax.persistence.spi.PersistenceProvider -->
        
        <thirdPartyJPAProviderClass>org.apache.openjpa.persistence.PersistenceProviderImpl</thirdPartyJPAProviderClass>
        
        
        <!-- Path to Third Party JPA Persistence Privider jars -->
        
        <!-- For openjpa, removed the jars containing javax. packages, and moved the openjpa impl into lib -->        
        <thirdPartyJPAProviderPath>/Users/jgrassel/dev/Apache/drivers/apache-openjpa-3.1.0/lib</thirdPartyJPAProviderPath>

simple-webWithThirdPartyJPAProvider-project.zip

@jgrassel
Copy link
Contributor Author

I was able to reproduce the enhancement failure issue with OpenJPA 3.1.0 this way on Open Liberty.

@rmannibucau
Copy link
Contributor

@jgrassel thanks a lot, I was able to test it on 3.1.2 too and also checked the proposed patch in my PR fixes that issue.

@jgrassel
Copy link
Contributor Author

jgrassel commented Jul 14, 2020

Ok, glad to hear that it worked with 3.1.2 (the patch that is)!

@rmannibucau
Copy link
Contributor

rmannibucau commented Jul 14, 2020

@jgrassel not with 3.1.2 (:() but with a patched 3.1.3-SNAPSHOT (still trying to find a good solution we both agree on before merging/pushing). Just meant I can reproduce the issue too with 3.1.2.

# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants