Sunday, June 7, 2015

NullPointerException on Weblogic server startup logs when deploying the applications which use log4j jar while calling (Category.removeAllAppenders())

Introduction:


While deploying an application which uses log4j jar, managed server startup logs display the exception as follows.

Exception:

java.lang.NullPointerException
at org.apache.log4j.Category.removeAllAppenders(Category.java:888)

Below is complete error stack trace.


log4j:ERROR Could not parse url [file:/opt/app/domains/domain_name/log4j.xml].
java.lang.NullPointerException
at org.apache.log4j.Category.removeAllAppenders(Category.java:888)
        at org.apache.log4j.xml.DOMConfigurator.parseChildrenOfLoggerElement(DOMConfigurator.java:487)
        at org.apache.log4j.xml.DOMConfigurator.parseCategory(DOMConfigurator.java:415)
        at org.apache.log4j.xml.DOMConfigurator.parse(DOMConfigurator.java:919)
        at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:790)
        at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:682)
        at org.apache.log4j.xml.XMLWatchdog.doOnChange(DOMConfigurator.java:1033)
        at org.apache.log4j.helpers.FileWatchdog.checkAndConfigure(FileWatchdog.java:89)
        at org.apache.log4j.helpers.FileWatchdog.<init>(FileWatchdog.java:58)
        at org.apache.log4j.xml.XMLWatchdog.<init>(DOMConfigurator.java:1025)
        at org.apache.log4j.xml.DOMConfigurator.configureAndWatch(DOMConfigurator.java:662)
        at org.apache.log4j.xml.DOMConfigurator.configureAndWatch(DOMConfigurator.java:645)
        at com.test.utility.Logger.<clinit>(Logger.java:35)
        at com.test.integration.mdbs.StartUp.<init>(StartUp.java:44)
        at com.test.integration.mdbs.StartUp_bco80w_Impl.<init>(StartUp_bco80w_Impl.java:45)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at java.lang.Class.newInstance0(Class.java:357)
        at java.lang.Class.newInstance(Class.java:310)
        at weblogic.ejb.container.manager.BaseEJBManager.createNewBeanInstance(BaseEJBManager.java:222)
        at weblogic.ejb.container.manager.BaseEJBManager.allocateBean(BaseEJBManager.java:233)
        at weblogic.ejb.container.manager.StatelessManager.createBean(StatelessManager.java:303)
        at weblogic.ejb.container.pool.StatelessSessionPool.createBean(StatelessSessionPool.java:190)
        at weblogic.ejb.container.pool.Pool.createInitialBeans(Pool.java:300)
        at weblogic.ejb.container.manager.StatelessManager.initializePool(StatelessManager.java:444)
        at weblogic.ejb.container.deployer.EJBDeployer.initializePools(EJBDeployer.java:1546)
        at weblogic.ejb.container.deployer.EJBDeployer.start(EJBDeployer.java:1377)
        at weblogic.ejb.container.deployer.EJBModule.start(EJBModule.java:589)
        at weblogic.application.internal.flow.ModuleListenerInvoker.start(ModuleListenerInvoker.java:117)
        at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleStateDriver.java:204)
        at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
        at weblogic.application.internal.flow.ModuleStateDriver.start(ModuleStateDriver.java:60)
        at weblogic.application.internal.flow.StartModulesFlow.activate(StartModulesFlow.java:27)
        at weblogic.application.internal.BaseDeployment$2.next(BaseDeployment.java:635)
        at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
        at weblogic.application.internal.BaseDeployment.activate(BaseDeployment.java:212)
        at weblogic.application.internal.EarDeployment.activate(EarDeployment.java:16)
        at weblogic.application.internal.DeploymentStateChecker.activate(DeploymentStateChecker.java:162)
        at weblogic.deploy.internal.targetserver.AppContainerInvoker.activate(AppContainerInvoker.java:79)
        at weblogic.deploy.internal.targetserver.BasicDeployment.activate(BasicDeployment.java:184)
        at weblogic.deploy.internal.targetserver.BasicDeployment.activateFromServerLifecycle(BasicDeployment.java:361)
        at weblogic.management.deploy.internal.DeploymentAdapter$1.doActivate(DeploymentAdapter.java:51)
        at weblogic.management.deploy.internal.DeploymentAdapter.activate(DeploymentAdapter.java:196)
        at weblogic.management.deploy.internal.AppTransition$2.transitionApp(AppTransition.java:30)
        at weblogic.management.deploy.internal.ConfiguredDeployments.transitionApps(ConfiguredDeployments.java:233)
        at weblogic.management.deploy.internal.ConfiguredDeployments.activate(ConfiguredDeployments.java:169)
        at weblogic.management.deploy.internal.ConfiguredDeployments.deploy(ConfiguredDeployments.java:123)
        at weblogic.management.deploy.internal.DeploymentServerService.resume(DeploymentServerService.java:173)
        at weblogic.management.deploy.internal.DeploymentServerService.start(DeploymentServerService.java:89)
        at weblogic.t3.srvr.SubsystemRequest.run(SubsystemRequest.java:64)
        at weblogic.work.ExecuteThread.execute(ExecuteThread.java:201)
        at weblogic.work.ExecuteThread.run(ExecuteThread.java:173)



Cause:


Code issue with the version of the log4j jar used. The method removeAllAppenders() does not have proper checks for NullPointerException. Please see more details in analysis section.



Analysis:


To analyze it have a look at log4j.jar placed at app server/lib and in my case I noticed that log4j-1.2.15.jar is at the path and tried to look to Category.java:888.

Below is screenshot of Category.java:888 in log4j-1.2.15.jar




The null pointer is coming at iter.hasMoreElements() at line 888 which indicates iter is null that means aai.getAllAppenders()is returning null value. In such case the null pointer can be avoided
by adding one more condition(highlighted below) to loop.

for (Enumeration iter = aai.getAllAppenders(); iter != null &&
iter.hasMoreElements();) {
appenders.add(iter.nextElement());
}



Solution:


I downloaded log4j-1.2.16.jar and extracted and verified the same Category.java and found that code is modified.

Below is screenshot of Category.java:888 in log4j-1.2.16.jar


By putting the newer version of log4j_1.2.16.jar in appserver/lib fixed the issue.

Hope above helps in fixing the above exception for your application, please leave your feedback or query.

Tuesday, June 2, 2015

Weblogic rmi connection.prepareCall throwing NullPointerException

Introduction:

In a standalone java application which creates DB connection through datasource lookup using initial context. The connection is not null but when it calls prepareCall() It throws NullPointerException.

Here is the source code which is responsible for the error.

public static boolean callProc(Connection connection)
  {
    logger.info("Calling the procedure");
    CallableStatement localCallableStatement = null;
    try
    {
      logger.warn("Calling Procedure");
      localCallableStatement = connection.prepareCall("CALL db_proc_name()");
      localCallableStatement.execute();
      logger.warn("Procedure Execution Complete");
    }


Error: 

java.lang.NullPointerException at weblogic.utils.wrapper.WrapperFactory.getCachedWrapperClass(WrapperFactory.java:49)

Below is the complete error stacktrace.

java.lang.NullPointerException
        at weblogic.utils.wrapper.WrapperFactory.getCachedWrapperClass(WrapperFactory.java:49)
        at weblogic.utils.wrapper.WrapperFactory.getWrapperClass(WrapperFactory.java:212)
        at weblogic.utils.wrapper.WrapperFactory.getWrapperClass(WrapperFactory.java:200)
        at weblogic.utils.wrapper.WrapperFactory.createWrapper(WrapperFactory.java:189)
        at weblogic.jdbc.wrapper.JDBCWrapperFactory.getWrapper(JDBCWrapperFactory.java:182)
        at weblogic.jdbc.rmi.internal.CallableStatementStub.readResolve(CallableStatementStub.java:49)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at java.io.ObjectStreamClass.invokeReadResolve(ObjectStreamClass.java:1056)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1784)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1327)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:349)
        at weblogic.common.internal.ChunkedObjectInputStream.readObject(ChunkedObjectInputStream.java:120)
        at weblogic.rjvm.MsgAbbrevInputStream.readObject(MsgAbbrevInputStream.java:121)
        at weblogic.rmi.internal.ObjectIO.readObject(ObjectIO.java:56)
        at weblogic.rjvm.ResponseImpl.unmarshalReturn(ResponseImpl.java:164)
        at weblogic.rmi.internal.BasicRemoteRef.invoke(BasicRemoteRef.java:165)
        at weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_PoolConnection_oracle_jdbc_driver_T4CConnection_1030_WLStub.prepareCall(Unknown Source)
        at weblogic.jdbc.rmi.SerialConnection.prepareCall(SerialConnection.java:238)

Screenshot is as below.



Cause: 


Client JVM has different version of weblogic classes in the classpath than the weblogic server it is communicating. It may be possible that the client is trying to connect to weblogic 10.3 but the weblogic jar used in the client code is of version 8.1.

Analysis:


I followed the below steps in order to fix the problem.

1. Adding the right version of weblogic.jar further gave me below error. In my case I moved from weblogic 8.1 version to weblogic 10.3 version so I added weblogic.jar from 10.3 version.

Error: 

Exception in thread "main" java.lang.NoClassDefFoundError: weblogic/security/subject/AbstractSubject

Below is the complete error stacktrace.


Exception in thread "main" java.lang.NoClassDefFoundError: weblogic/security/subject/AbstractSubject
        at weblogic.jndi.WLInitialContextFactory.getInitialContext(WLInitialContextFactory.java:117)
        at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:667)
        at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:288)
        at javax.naming.InitialContext.init(InitialContext.java:223)
        at javax.naming.InitialContext.<init>(InitialContext.java:197)
        at com.frp.dataAccess.M6DataSource.getConnection(Unknown Source)
        at com.frp.core.SAFileWriteController.main(Unknown Source)
Caused by: java.lang.ClassNotFoundException: weblogic.security.subject.AbstractSubject
        at java.net.URLClassLoader$1.run(URLClassLoader.java:202)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
        ... 7 more

Screenshot is as below.




2.  After encountering the above exception I added wlclient.jar to the classpath but that also resulted in a different error

Error:

 Exception in thread "main" java.lang.NoClassDefFoundError: weblogic/security/acl/UserInfo

Below is the complete error stacktrace.

Exception in thread "main" java.lang.NoClassDefFoundError: weblogic/security/acl/UserInfo
        at weblogic.jndi.WLInitialContextFactory.getInitialContext(WLInitialContextFactory.java:117)
        at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:667)
        at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:288)
        at javax.naming.InitialContext.init(InitialContext.java:223)
        at javax.naming.InitialContext.<init>(InitialContext.java:197)
        at com.frp.dataAccess.M6DataSource.getConnection(Unknown Source)
        at com.frp.core.SAFileWriteController.main(Unknown Source)
Caused by: java.lang.ClassNotFoundException: weblogic.security.acl.UserInfo
        at java.net.URLClassLoader$1.run(URLClassLoader.java:202)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
        ... 7 more

Screenshot is as below:


after performing above two steps it did not help in fixing the issue rather resulted in different errors. So I reverted both the steps and used below as a solution for all 3 of above errors.

Solution:


I was able to resolve this issue by creating and adding wlfullclient.jar in the standalone client classpath. Also weblogic.jar and wlclient.jar is no more required in classpath as mentioned in analysis section.

It seems it is not recommended since release 10 to use weblogic.jar in the client so instead of that wlfullclient.jar is used. Using jdk1.6 it can be created with following three steps

1. Change directories to the server/lib directory.
cd WL_HOME/server/lib

2. Use the following command to create wlfullclient.jar in the server/lib directory:
java -jar wljarbuilder.jar

3. You can now copy and bundle the wlfullclient.jar with client applications and modify the classpath.


Hope above helps in fixing the above exception for your application, please leave your feedback or query.