search

eclipse-ee4j / glassfish

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

NPE while starting JPA #18513

Closed glassfishrobot closed 4 years ago

glassfishrobot commented 12 years ago

JPA is started from a OSGi bundle using the context classloader work around.

This NPE seems to be random, it does not always happen.

In this example two bundles are loading two different persistence units are the same time, not sure if that contributes to the NPE or not.

[#|2012-03-15T17:39:24.506-0400|INFO|glassfish3.1.2|org.eclipse.persistence.session.bundle://300.1:1/_proview|_ThreadID=112;_ThreadName=Thread-2;|EclipseLink, version: Eclipse Persistence Services - 2.3.2.v20111125-r10461|#] 
[#|2012-03-15T17:39:24.506-0400|INFO|glassfish3.1.2|org.eclipse.persistence.session.bundle://304.0:1/_subscription|_ThreadID=113;_ThreadName=Thread-2;|EclipseLink, version: Eclipse Persistence Services - 2.3.2.v20111125-r10461|#] 
[#|2012-03-15T17:39:24.680-0400|SEVERE|glassfish3.1.2|javax.enterprise.system.tools.deployment.org.glassfish.deployment.common|_ThreadID=117;_ThreadName=Thread-2;|Exception while visiting com/sun/gjc/common/DataSourceSpec.class of size 3267
java.lang.NullPointerException
        at org.glassfish.hk2.classmodel.reflect.impl.TypesImpl.getType(TypesImpl.java:78)
        at org.glassfish.hk2.classmodel.reflect.impl.ModelClassVisitor.visit(ModelClassVisitor.java:119)
        at org.objectweb.asm.ClassReader.accept(Unknown Source)
        at org.objectweb.asm.ClassReader.accept(Unknown Source)
        at org.glassfish.hk2.classmodel.reflect.Parser$5.on(Parser.java:363)
        at org.glassfish.hk2.classmodel.reflect.util.JarArchive.onSelectedEntries(JarArchive.java:125)
        at org.glassfish.hk2.classmodel.reflect.Parser.doJob(Parser.java:348)
        at org.glassfish.hk2.classmodel.reflect.Parser.access$300(Parser.java:70)
        at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:307)
        at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:296)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
|#]

Affected Versions

[3.1.2]

glassfishrobot commented 6 years ago
glassfishrobot commented 12 years ago

@glassfishrobot Commented mm110999 said: Here is comment from Sahoo in an offline mail discussion. / This is neither a jpa nor an osgi bug. It's a bug in deployment/classmodel code. It's harmeless AFAIK. Marina has also seen this behavior before. Jerome wanted a reproducible test case to get to the bottom of it. So, assign to deployment team with all thses information / Assigning it to deployment for initial evaluation.

glassfishrobot commented 12 years ago

@glassfishrobot Commented @honghzzhang said: The NPE came from the HK2 classmodel code, I am not sure who owns this part of the HK2 code now. I am assigning to Tom and he could assign accordingly.

glassfishrobot commented 12 years ago

@glassfishrobot Commented rusty_turkey said: I got the exact stacktrace that is in the description of the issue, then on the next project build I got a very similar stacktrace from Glassfish 3.1.2

18/04/2012 10:26:20 AM org.glassfish.hk2.classmodel.reflect.Parser$5 on SEVERE: Exception while visiting com/sun/gjc/util/SQLTraceCache.class of size 4662 java.lang.NullPointerException at org.glassfish.hk2.classmodel.reflect.impl.TypesImpl.getType(TypesImpl.java:78) at org.glassfish.hk2.classmodel.reflect.impl.ModelClassVisitor.visit(ModelClassVisitor.java:119) at org.objectweb.asm.ClassReader.accept(Unknown Source) at org.objectweb.asm.ClassReader.accept(Unknown Source) at org.glassfish.hk2.classmodel.reflect.Parser$5.on(Parser.java:363) at org.glassfish.hk2.classmodel.reflect.util.JarArchive.onSelectedEntries(JarArchive.java:125) at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.parse(DirectoryArchive.java:111) at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.onSelectedEntries(DirectoryArchive.java:92) at org.glassfish.hk2.classmodel.reflect.Parser.doJob(Parser.java:348) at org.glassfish.hk2.classmodel.reflect.Parser.access$300(Parser.java:70) at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:307) at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:296) 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:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662)

glassfishrobot commented 12 years ago

@glassfishrobot Commented tbeerbower said: Is it possible to provide a test case that reproduces the issue?

glassfishrobot commented 12 years ago

@glassfishrobot Commented tacoss said: Testbean

deploy this bean and start the Glassfish-Server

package ejb;

import java.util.HashMap; import java.util.logging.Level; import java.util.logging.Logger; import javax.annotation.PostConstruct; import javax.annotation.Resource; import javax.ejb.*; import javax.persistence.EntityManager; import javax.persistence.PersistenceContext;

/*

@Startup @Stateless @LocalBean

public class NewSessionBean {

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

@Schedule(second="0", minute="", hour="") public void importAuto()

{ Logger.getLogger( NewSessionBean.class.getName() ).log( Level.INFO, "importiereAuto" ); }

@PostConstruct public void post()

{ Logger.getLogger( NewSessionBean.class.getName() ).log( Level.INFO, "post" ); }

}

glassfishrobot commented 12 years ago

@glassfishrobot Commented grunt2000 said: The function getType() that is giving NullPointerException to many callers, not only in the case of this issue.

This function has been quickly written: it has no comments, no assertions, no checkings inside.

public TypeImpl getType(int access, String name, TypeProxy parent) { Class<? extends Type> requestedType = getType(access);

TypeProxy typeProxy = types.getHolder(name, requestedType); synchronized(typeProxy) { final Type type = typeProxy.get(); TypeImpl result; if (null == type) { if ((access & Opcodes.ACC_ANNOTATION)==Opcodes.ACC_ANNOTATION)

{ result = new AnnotationTypeImpl(name, typeProxy); } else if ((access & Opcodes.ACC_INTERFACE)==Opcodes.ACC_INTERFACE) { result = new InterfaceModelImpl(name, typeProxy, parent); } else { result = new ClassModelImpl(name, typeProxy, parent); } typeProxy.set(result); return result; } else { TypeImpl impl = (TypeImpl)type; if (ExtensibleTypeImpl.class.isInstance(impl)) { // ensure we have the parent right ((ExtensibleTypeImpl<?>)impl).setParent(parent); } return impl; } } }

The method should at least do the minimal checkings to avoid throwing a clueless NullPointerException to callers.

/**

// If the access has no requested type associated, throw an exception. if (requestedType == null) throw(new IllegalArgumentException(MessageFormat.format("Cannot find the requested type for the access {0}.", access)));

TypeProxy typeProxy = types.getHolder(name, requestedType);

// If the proxy has not been found, throw an exception. // For our issue, it is the cause of the NullPointerException that is thrown (a synchronized(null) may occurs). if (typeProxy == null) throw(new NoSuchElementException(MessageFormat.format("Cannot find the proxy holder for the requested type {0}.", requestedType))); // if requestType.toString() has a useful implementation, else select one of its members for displaying.

synchronized(typeProxy) { final Type type = typeProxy.get(); TypeImpl result; if (null == type) { if ((access & Opcodes.ACC_ANNOTATION)==Opcodes.ACC_ANNOTATION) { result = new AnnotationTypeImpl(name, typeProxy); }

else if ((access & Opcodes.ACC_INTERFACE)==Opcodes.ACC_INTERFACE)

{ result = new InterfaceModelImpl(name, typeProxy, parent); }

else

{ result = new ClassModelImpl(name, typeProxy, parent); }

typeProxy.set(result); return result; } else { TypeImpl impl = (TypeImpl)type; if (ExtensibleTypeImpl.class.isInstance(impl))

{ // ensure we have the parent right ((ExtensibleTypeImpl<?>)impl).setParent(parent); }

return impl; } } }

Regards,

Grunt.

glassfishrobot commented 12 years ago

@glassfishrobot Commented @ljnelson said: FWIW I see this using embedded GlassFish 3.1.2 as well; perhaps that will make it easier to roll a test case.

glassfishrobot commented 12 years ago

@glassfishrobot Commented gfuser9999 said: Possibly HK2 org.glassfish.hk2.classmodel.reflect.impl.TypesCtr.getHolder(name,...) return null is the following concurrency issue:

— TypesCtr-orig.java Sat Sep 15 21:36:00 2012 +++ TypesCtr.java Sat Sep 15 21:40:02 2012 @@ -111,9 +111,13 @@ TypeProxy typeProxy = typeStorage.get(name); if (typeProxy ==null) { // in our unknown type pool ?

glassfishrobot commented 12 years ago

@glassfishrobot Commented @jwells131313 said: classmodel is only used by the config subsystem, so assigning to Mahesh

glassfishrobot commented 11 years ago

@glassfishrobot Commented chejavara said: For those who tried to debug this, this is what I found.

The class is actually in auto-depends.jar, but public sources for it do not include org.glassfish... I found them in class-model-1.1.14.jar sources for Glassfish 3.1.2

There's a NullPointer because because somebody asks TypesImpl to get a TypeProxy by invoking getHolder on org.glassfish.hk2.classmodel.reflect.impl.TypesCtr

This thing then consults some gigantic ConcurrentHashMap called storage for another ConcurrentHashMap to look for the class by fully qualified name.

If not found, then it consults some unknownTypesStorage ConcurrenthashMap to see if its there. If yes it removes and returns from there.

If not in unknownTypesStorage, then it creates a new Proxy and returns it.

So it should never return null, which is what causes the NullPointerException.

I can only see one path though which it can return null, thats when unknownTypesStorage contains it, but due to concurrency by the time we call unknownTypesStorage.remove it is already gone from the hashmap. Then we go ahead and return NULL.

Here is the related code:

public TypeProxy getHolder(String name, Class type) { if (name.equals("java.lang.Object")) return null; ConcurrentMap<String, TypeProxy> typeStorage = storage.get(type); if (typeStorage==null) { typeStorage = new ConcurrentHashMap<String, TypeProxy>(); ConcurrentMap<String, TypeProxy> old = storage.putIfAbsent(type, typeStorage); if (old!=null)

{ // some other thread got to set that type storage before us, let's use it typeStorage=old; }

} TypeProxy typeProxy = typeStorage.get(name); if (typeProxy ==null) { // in our unknown type pool ? if (unknownTypesStorage.containsKey(name)) { synchronized (unknownTypesStorage)

{ typeProxy = unknownTypesStorage.remove(name); }

=====> WHAT IF typeProxy is NULL HERE ? <======== if (typeProxy!=null) { TypeProxy old = typeStorage.putIfAbsent(name, typeProxy); if (old!=null)

{ typeProxy = old; }

} } else { typeProxy = new TypeProxy(null, name); TypeProxy old = typeStorage.putIfAbsent(name, typeProxy); if (old==null)

{ nonVisited.push(typeProxy); }

else

{ typeProxy=old; }

} } return typeProxy; }

Im thinking gfuser9999 had the same idea.

The bad code would be synchronizng after checking contains. Hope this helps whoever is trying to reproduce this.

glassfishrobot commented 11 years ago

@glassfishrobot Commented kloeber said: I got the same issue here, but with only one PU loading: [code] Launching GlassFish on Felix platform INFO: Running GlassFish Version: GlassFish Server Open Source Edition 3.1.2.2 (build 5) INFO: Registered org.glassfish.ha.store.adapter.cache.ShoalBackingStoreProxy for persistence-type = replicated in BackingStoreFactoryRegistry INFO: Grizzly Framework 1.9.50 started in: 13ms - bound to [0.0.0.0:8181] INFO: Grizzly Framework 1.9.50 started in: 36ms - bound to [0.0.0.0:8080] INFO: Grizzly Framework 1.9.50 started in: 5ms - bound to [0.0.0.0:4848] INFO: Grizzly Framework 1.9.50 started in: 9ms - bound to [0.0.0.0:3700] INFO: Grizzly Framework 1.9.50 started in: 6ms - bound to [0.0.0.0:7676] INFO: The Admin Console is already installed, but not yet loaded. INFO: Created EjbThreadPoolExecutor with thread-core-pool-size 16 thread-max-pool-size 32 thread-keep-alive-seconds 60 thread-queue-capacity 2147483647 allow-core-thread-timeout false INFO: SEC1002: Security Manager is OFF. INFO: SEC1010: Entering Security Startup Service INFO: SEC1143: Loading policy provider com.sun.enterprise.security.provider.PolicyWrapper. INFO: SEC1115: Realm [admin-realm] of classtype [com.sun.enterprise.security.auth.realm.file.FileRealm] successfully created. INFO: SEC1115: Realm [file] of classtype [com.sun.enterprise.security.auth.realm.file.FileRealm] successfully created. INFO: SEC1115: Realm [certificate] of classtype [com.sun.enterprise.security.auth.realm.certificate.CertificateRealm] successfully created. INFO: SEC1011: Security Service(s) Started Successfully INFO: WEB0169: Created HTTP listener [http-listener-1] on host/port [0.0.0.0:8080] INFO: WEB0169: Created HTTP listener [http-listener-2] on host/port [0.0.0.0:8181] INFO: WEB0169: Created HTTP listener [admin-listener] on host/port [0.0.0.0:4848] INFO: WEB0171: Created virtual server [server] INFO: WEB0171: Created virtual server [__asadmin] INFO: WEB0172: Virtual server [server] loaded default web module [] SEVERE: Exception while visiting com/sun/gjc/common/DataSourceSpec.class of size 3267 java.lang.NullPointerException at org.glassfish.hk2.classmodel.reflect.impl.TypesImpl.getType(TypesImpl.java:78) at org.glassfish.hk2.classmodel.reflect.impl.ModelClassVisitor.visit(ModelClassVisitor.java:119) at org.objectweb.asm.ClassReader.accept(Unknown Source) at org.objectweb.asm.ClassReader.accept(Unknown Source) at org.glassfish.hk2.classmodel.reflect.Parser$5.on(Parser.java:363) at org.glassfish.hk2.classmodel.reflect.util.JarArchive.onSelectedEntries(JarArchive.java:125) at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.parse(DirectoryArchive.java:111) at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.onSelectedEntries(DirectoryArchive.java:92) at org.glassfish.hk2.classmodel.reflect.Parser.doJob(Parser.java:348) at org.glassfish.hk2.classmodel.reflect.Parser.access$300(Parser.java:70) at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:307) at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:296) 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:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) [/code]

glassfishrobot commented 11 years ago

@glassfishrobot Commented kithouna said: I've got the exact same exception using GlassFish 3.1.2.2 and an h2 database version 1.3.170.

glassfishrobot commented 11 years ago

@glassfishrobot Commented kithouna said: If it helps anyone, this is in my log:

SEVERE: Exception while visiting com/sun/gjc/common/DataSourceSpec.class of size 3267
java.lang.NullPointerException
    at org.glassfish.hk2.classmodel.reflect.impl.TypesImpl.getType(TypesImpl.java:78)
    at org.glassfish.hk2.classmodel.reflect.impl.ModelClassVisitor.visit(ModelClassVisitor.java:119)
    at org.objectweb.asm.ClassReader.accept(Unknown Source)
    at org.objectweb.asm.ClassReader.accept(Unknown Source)
    at org.glassfish.hk2.classmodel.reflect.Parser$5.on(Parser.java:363)
    at org.glassfish.hk2.classmodel.reflect.util.JarArchive.onSelectedEntries(JarArchive.java:125)
    at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.parse(DirectoryArchive.java:111)
    at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.onSelectedEntries(DirectoryArchive.java:92)
    at org.glassfish.hk2.classmodel.reflect.Parser.doJob(Parser.java:348)
    at org.glassfish.hk2.classmodel.reflect.Parser.access$300(Parser.java:70)
    at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:307)
    at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:296)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
    at java.util.concurrent.FutureTask.run(FutureTask.java:166)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:722)

WARNING: RAR8705: Invalid value for property dynamic-reconfiguration-wait-timeout-in-seconds : null
SEVERE: Exception while visiting com/sun/gjc/spi/JdbcObjectsFactory.class of size 3630
java.lang.NullPointerException
    at org.glassfish.hk2.classmodel.reflect.impl.TypesImpl.getType(TypesImpl.java:78)
    at org.glassfish.hk2.classmodel.reflect.impl.ModelClassVisitor.visit(ModelClassVisitor.java:119)
    at org.objectweb.asm.ClassReader.accept(Unknown Source)
    at org.objectweb.asm.ClassReader.accept(Unknown Source)
    at org.glassfish.hk2.classmodel.reflect.Parser$5.on(Parser.java:363)
    at org.glassfish.hk2.classmodel.reflect.util.JarArchive.onSelectedEntries(JarArchive.java:125)
    at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.parse(DirectoryArchive.java:111)
    at org.glassfish.hk2.classmodel.reflect.util.DirectoryArchive.onSelectedEntries(DirectoryArchive.java:92)
    at org.glassfish.hk2.classmodel.reflect.Parser.doJob(Parser.java:348)
    at org.glassfish.hk2.classmodel.reflect.Parser.access$300(Parser.java:70)
    at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:307)
    at org.glassfish.hk2.classmodel.reflect.Parser$3.call(Parser.java:296)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
    at java.util.concurrent.FutureTask.run(FutureTask.java:166)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:722)
glassfishrobot commented 11 years ago

@glassfishrobot Commented codeprince said: Mahesh, kithouna,

Firstly, the test bean needs to be modified as following,

@Schedule(second="0", minute="", hour="") public void importAuto()

{ Logger.getLogger( NewSessionBean.class.getName() ).log( Level.INFO, "importiereAuto" ); } ↓

@Schedule(second="0", minute="0", hour="0") public void importAuto() { Logger.getLogger( NewSessionBean.class.getName() ).log( Level.INFO, "importiereAuto" ); }

Otherwise, the following exception will happen while deploying

[2013-04-08T19:34:18.296+0900] [glassfish 4.0] [SEVERE] [] [javax.enterprise.system.core] [tid: _ThreadID=34 _ThreadName=admin-listener(3)] [timeMillis: 1365417258296] [levelValue: 1000] [[ Exception while deploying the app [TestCDIInterterceptorInEar-ejb-1.0-SNAPSHOT] : Error processing EjbDescriptor java.lang.RuntimeException: StartupBean: Invalid schedule defined on method importAuto(): Field minute cannot be an empty String at org.glassfish.ejb.deployment.util.EjbBundleValidator.accept(EjbBundleValidator.java:351) ...

Secondly,

I have confirmed the issue on gf 3.1.2.2 and current v4,

1) on 3.1.2.2 , the issue can be re-produced

2) on v4, anything is OK while deploying

So, pl. Mahesh closed the issue.

Thanks --Tang

glassfishrobot commented 11 years ago

@glassfishrobot Commented juliohm said: Grettings.

I am having the same exception on a system I am working on. The Exception stack trace is exactly the same, but I can't seem to find a relation to the test bean provided here. We are not using @Schedule anywhere.

Does anyone have any updates on this? Any ideas on how to debug and get clues to which beans in my application might be causing it?

Most importantly, a workaround would be greatly appreciated.

glassfishrobot commented 11 years ago

@glassfishrobot Commented zhouronghui said: Hi, Mahesh Kannan

I found that TypesCtr had been modified in Revision:4175. It seems the the revision:4175 modified this ISSUE.

https://svn.java.net/svn/hk2~svn/trunk/hk2/class-model/src/main/java/org/glassfish/hk2/classmodel/reflect/impl/TypesCtr.java

Revision: 4175 Author: mtaube Date: 4:43:16, 2012/12/14 Message: forward port of change 4107

Could you please check it? If it is YES, I think that the Revision:4175 should feed-back to the GF V3.1.2. Right?

Thanks.

glassfishrobot commented 11 years ago

@glassfishrobot Commented codeprince said: +1 agree with Zhou!

glassfishrobot commented 11 years ago

@glassfishrobot Commented flotho said: Hy folks,

If it could help, I also explained How I hav the same issue. Whatt is tsrange is that the problem is coming only on GF reboot. I installed archiva.apache.org with success and all the stuff.... When I reboot I have the same problem.

So I vote +1 for having a solution to this

glassfishrobot commented 11 years ago

@glassfishrobot Commented gfuser9999 said: I thought the fix made to 3.1.2.4 (available from Oracle) since many months now. See https://blogs.oracle.com/GlassFishForBusiness/entry/oracle_glassfish_server_ogfs_v3 15884192 INTEGRATE NEW HK2 14512884 EXCEPTION WHILE VISITING COM/SUN/GJC/COMMON/DATASOURCESPEC.CLASS OF SIZE 3267

glassfishrobot commented 11 years ago

@glassfishrobot Commented flotho said: Hy,

And do you know ho to integrate this in the community release?

Regards

glassfishrobot commented 12 years ago

@glassfishrobot Commented Was assigned to mk111283

glassfishrobot commented 7 years ago

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

glassfishrobot commented 12 years ago

@glassfishrobot Commented Reported by aaronjwhiteside

github-actions[bot] commented 4 years ago

This issue has been marked as inactive and old and will be closed in 7 days if there is no further activity. If you want the issue to remain open please add a comment