Thursday, October 29, 2009

No singletons allowed in a WebLogic EAR!

The context


There is a big EJB3 application (835 Entities, 88 stateless, 1 MDB) that works on JBoss (Server and Embedded) in production with no problem.
We now want to support WebLogic 10.3 and WebSphere 7.0!

The problem


The application contains "of course" some framework jars to manage cross cutting services (logger, metadata, XML marshalling, ...) using immutable static maps that are initialized at bootstrap time. Nothing extraordinary in my point of view!
Still, we found out that under WebLogic 10.3 the final static maps are created multiple times!

No way!


I did not believe it!
I'm working with WebLogic since it was a company (not under BEA), and I always managed and enjoyed creating big enterprise application with it.
Putting JBoss aside (this thread is about WebLogic), in 1999-2002, every presale competition against IBM WebSphere if no politics were involved, WebLogic always won.
From my experience, I always managed to understand the logical behavior of WebLogic, and found a way to deliver the applications to my customers.
Is this crazy behavior due to the influence of Oracle buying BEA almost 2 years ago?

The small test case


To prove the point, we created a small ejb3 application that can be easily build with Maven 2. Side note: this simple app can be useful to others that wish to test their EJB3 container.
The source code is under subversion here.

The modules


This Enterprise Application has the simplest but complete set of features we need from an EJB3 container. It is made of the following modules (by order of dependency):
  1. simple-framework
    A simple framework jar that will be part of the EAR and used by the WEB and EJB classes. This module uses only 2 external jars: log4j and slf4j.
  2. another-ejb-sample
    A pure Stateless session bean used from different layer of the other modules to test EJB injection.
  3. ejb-sample
    A simple EJB3 jar with different kind of beans: a Stateful, a Stateless and an Entity. This module contains the persistence.xml that defined the connection to the DB. By default the persistence.xml is configured for a MySQL (the line for Oracle is commented) DB data source with JNDI Name "jdbc/ejb3_ds" which contain one table "customer"
  4. web-sample
    A webapp http://localhost:7001/web-sample with a servlet that can activate the different tests.
  5. ear
    A maven module that will create "sample-ejb3-ear.ear" file that can be deployed in WebLogic Server 10.3.


How to build


Use standard maven 2.0.9 or above and run "mvn install" under the root folder of the project. All needed dependencies are coming from this repository.

After a successful build the "ear/target/sample-ejb3-ear.ear" can be deployed on a correctly configured WebLogic 10.3 Server.

WebLogic and DB configuration


  • For MySQL:
    create table customer (
    id int(10) unsigned not null auto_increment,
    name varchar(255) default null,
    primary key (id));
  • For Oracle:
    create table customer (
    ID NUMBER(12,0) NOT NULL ENABLE,
    NAME VARCHAR2(200),
    CONSTRAINT CUSTOMER PRIMARY KEY (ID) USING INDEX COMPUTE STATISTICS);

    create sequence CORE.hibernate_sequence
    start with 1 increment by 1 nomaxvalue;
  • Need to create a data source with JNDI Name "jdbc/ejb3_ds" for the DB.
  • Deploy the "sample-ejb3-ear.ear" application in WLS 10.3.


The Results


You will see in the log that a pure and simple singleton LogServiceImpl available in the "simple-framework" module is initialized 3 times (which is 2 times too much for a singleton :). The 3 times match the 3 beans (2 stateless, 1 entity) where the standard log variables appears
private static final Log log = LogService.getLog(...);

Any solution to solve this problem will be extremely painful, since basically ALL our static members are not static anymore. Any solution will have to be based on a ThreadLocal entry hoping that one single thread is doing the code analysis :).
What's even more worrying for us, is that these classes loaded with different class loader (static stack), are not discarded after code analysis, but assembled together!

Possible Solutions?


  1. We added a <classloader-structure> in the weblogic-application.xml file to enforce a single class loader for the whole EAR, it still in the code and did not work.
  2. We tested with Sun JVM 1.6 and JRockit. Both gave the same results

Are we missing a flag "unified class loader for EAR"?

Who is doing what?


Here is the full stack of 3 different creations of the same singleton. It's hard to write something like this after 12 years of Java development :( :

[04-11-09 14:52:18.867] INFO SessionFactoryImpl - building session factory
java.lang.Exception: THIS SHOULD HAPPEN ONLY ONCE
at greenhouse.ejb3.sample.framework.LogServiceImpl.<init>(LogServiceImpl.java:54)
at greenhouse.ejb3.sample.framework.LogServiceImpl.<clinit>(LogServiceImpl.java:51)
at greenhouse.ejb3.sample.framework.LogService.getLog(LogService.java:23)
at greenhouse.ejb3.sample.Customer.<clinit>(Customer.java:35)
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 org.hibernate.engine.UnsavedValueFactory.instantiate(UnsavedValueFactory.java:22)
at org.hibernate.engine.UnsavedValueFactory.getUnsavedIdentifierValue(UnsavedValueFactory.java:44)
at org.hibernate.tuple.PropertyFactory.buildIdentifierProperty(PropertyFactory.java:44)
at org.hibernate.tuple.entity.EntityMetamodel.<init>(EntityMetamodel.java:124)
at org.hibernate.persister.entity.AbstractEntityPersister.<init>(AbstractEntityPersister.java:434)
at org.hibernate.persister.entity.SingleTableEntityPersister.<init>(SingleTableEntityPersister.java:109)
at org.hibernate.persister.PersisterFactory.createClassPersister(PersisterFactory.java:55)
at org.hibernate.impl.SessionFactoryImpl.<init>(SessionFactoryImpl.java:226)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1300)
at org.hibernate.cfg.AnnotationConfiguration.buildSessionFactory(AnnotationConfiguration.java:859)
at org.hibernate.ejb.Ejb3Configuration.buildEntityManagerFactory(Ejb3Configuration.java:669)
at org.hibernate.ejb.HibernatePersistence.createContainerEntityManagerFactory(HibernatePersistence.java:132)
at weblogic.deployment.PersistenceUnitInfoImpl.createEntityManagerFactory(PersistenceUnitInfoImpl.java:330)
at weblogic.deployment.PersistenceUnitInfoImpl.<init>(PersistenceUnitInfoImpl.java:123)
at weblogic.deployment.AbstractPersistenceUnitRegistry.storeDescriptors(AbstractPersistenceUnitRegistry.java:331)
at weblogic.deployment.AbstractPersistenceUnitRegistry.loadPersistenceDescriptor(AbstractPersistenceUnitRegistry.java:245)
at weblogic.deployment.ModulePersistenceUnitRegistry.<init>(ModulePersistenceUnitRegistry.java:63)
at weblogic.ejb.container.deployer.EJBModule.setupPersistenceUnitRegistry(EJBModule.java:209)
at weblogic.ejb.container.deployer.EJBModule$1.execute(EJBModule.java:310)
at weblogic.deployment.PersistenceUnitRegistryInitializer.setupPersistenceUnitRegistries(PersistenceUnitRegistryInitializer.java:62)
at weblogic.ejb.container.deployer.EJBModule.prepare(EJBModule.java:376)
at weblogic.application.internal.flow.ModuleListenerInvoker.prepare(ModuleListenerInvoker.java:93)
at weblogic.application.internal.flow.DeploymentCallbackFlow$1.next(DeploymentCallbackFlow.java:387)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
at weblogic.application.internal.flow.DeploymentCallbackFlow.prepare(DeploymentCallbackFlow.java:58)
at weblogic.application.internal.flow.DeploymentCallbackFlow.prepare(DeploymentCallbackFlow.java:42)
at weblogic.application.internal.BaseDeployment$1.next(BaseDeployment.java:615)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
at weblogic.application.internal.BaseDeployment.prepare(BaseDeployment.java:191)
at weblogic.application.internal.EarDeployment.prepare(EarDeployment.java:16)
at weblogic.application.internal.DeploymentStateChecker.prepare(DeploymentStateChecker.java:155)
at weblogic.deploy.internal.targetserver.AppContainerInvoker.prepare(AppContainerInvoker.java:60)
at weblogic.deploy.internal.targetserver.AppDeployment.prepare(AppDeployment.java:141)
at weblogic.management.deploy.internal.DeploymentAdapter$1.doPrepare(DeploymentAdapter.java:39)
at weblogic.management.deploy.internal.DeploymentAdapter.prepare(DeploymentAdapter.java:187)
at weblogic.management.deploy.internal.AppTransition$1.transitionApp(AppTransition.java:21)
at weblogic.management.deploy.internal.ConfiguredDeployments.transitionApps(ConfiguredDeployments.java:233)
at weblogic.management.deploy.internal.ConfiguredDeployments.prepare(ConfiguredDeployments.java:165)
at weblogic.management.deploy.internal.ConfiguredDeployments.deploy(ConfiguredDeployments.java:122)
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)
[04-11-09 14:52:19.117] INFO Customer - A new customer is created
[04-11-09 14:52:19.492] INFO SessionFactoryObjectFactory - Not binding factory to JNDI, no JNDI name configured
[04-11-09 14:52:19.495] INFO NamingHelper - JNDI InitialContext properties:{}
java.lang.Exception: THIS SHOULD HAPPEN ONLY ONCE
at greenhouse.ejb3.sample.framework.LogServiceImpl.<init>(LogServiceImpl.java:54)
at greenhouse.ejb3.sample.framework.LogServiceImpl.<clinit>(LogServiceImpl.java:51)
at greenhouse.ejb3.sample.framework.LogService.getLog(LogService.java:23)
at greenhouse.ejb3.sample.CustomerDAOBean.<clinit>(CustomerDAOBean.java:26)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:247)
at weblogic.j2ee.dd.xml.validator.AnnotationValidatorHelper.getClass(AnnotationValidatorHelper.java:14)
at weblogic.j2ee.dd.xml.validator.injectiontarget.BaseValidator.getClass(BaseValidator.java:38)
at weblogic.j2ee.dd.xml.validator.AbstractAnnotationValidator.validate(AbstractAnnotationValidator.java:22)
at weblogic.j2ee.dd.xml.validator.AnnotationValidatorVisitor.visitInjectionTargetBean(AnnotationValidatorVisitor.java:48)
at weblogic.j2ee.dd.xml.validator.AnnotationValidatorVisitor.visit(AnnotationValidatorVisitor.java:25)
at weblogic.descriptor.internal.AbstractDescriptorBean.accept(AbstractDescriptorBean.java:1124)
at weblogic.descriptor.internal.AbstractDescriptorBean.accept(AbstractDescriptorBean.java:1128)
at weblogic.descriptor.internal.AbstractDescriptorBean.accept(AbstractDescriptorBean.java:1128)
at weblogic.descriptor.internal.AbstractDescriptorBean.accept(AbstractDescriptorBean.java:1128)
at weblogic.descriptor.internal.AbstractDescriptorBean.accept(AbstractDescriptorBean.java:1128)
at weblogic.j2ee.dd.xml.BaseJ2eeAnnotationProcessor.validate(BaseJ2eeAnnotationProcessor.java:143)
at weblogic.j2ee.dd.xml.BaseJ2eeAnnotationProcessor.validate(BaseJ2eeAnnotationProcessor.java:131)
at weblogic.ejb.container.dd.xml.EjbAnnotationProcessor.processAnnotations(EjbAnnotationProcessor.java:205)
at weblogic.ejb.container.dd.xml.EjbDescriptorReaderImpl.processStandardAnnotations(EjbDescriptorReaderImpl.java:324)
at weblogic.ejb.container.dd.xml.EjbDescriptorReaderImpl.createReadOnlyDescriptorFromJarFile(EjbDescriptorReaderImpl.java:190)
at weblogic.ejb.spi.EjbDescriptorFactory.createReadOnlyDescriptorFromJarFile(EjbDescriptorFactory.java:93)
at weblogic.ejb.container.deployer.EJBModule.loadEJBDescriptor(EJBModule.java:1198)
at weblogic.ejb.container.deployer.EJBModule.prepare(EJBModule.java:380)
at weblogic.application.internal.flow.ModuleListenerInvoker.prepare(ModuleListenerInvoker.java:93)
at weblogic.application.internal.flow.DeploymentCallbackFlow$1.next(DeploymentCallbackFlow.java:387)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
at weblogic.application.internal.flow.DeploymentCallbackFlow.prepare(DeploymentCallbackFlow.java:58)
at weblogic.application.internal.flow.DeploymentCallbackFlow.prepare(DeploymentCallbackFlow.java:42)
at weblogic.application.internal.BaseDeployment$1.next(BaseDeployment.java:615)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
at weblogic.application.internal.BaseDeployment.prepare(BaseDeployment.java:191)
at weblogic.application.internal.EarDeployment.prepare(EarDeployment.java:16)
at weblogic.application.internal.DeploymentStateChecker.prepare(DeploymentStateChecker.java:155)
at weblogic.deploy.internal.targetserver.AppContainerInvoker.prepare(AppContainerInvoker.java:60)
at weblogic.deploy.internal.targetserver.AppDeployment.prepare(AppDeployment.java:141)
at weblogic.management.deploy.internal.DeploymentAdapter$1.doPrepare(DeploymentAdapter.java:39)
at weblogic.management.deploy.internal.DeploymentAdapter.prepare(DeploymentAdapter.java:187)
at weblogic.management.deploy.internal.AppTransition$1.transitionApp(AppTransition.java:21)
at weblogic.management.deploy.internal.ConfiguredDeployments.transitionApps(ConfiguredDeployments.java:233)
at weblogic.management.deploy.internal.ConfiguredDeployments.prepare(ConfiguredDeployments.java:165)
at weblogic.management.deploy.internal.ConfiguredDeployments.deploy(ConfiguredDeployments.java:122)
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)
java.lang.Exception: THIS SHOULD HAPPEN ONLY ONCE
at greenhouse.ejb3.sample.framework.LogServiceImpl.<init>(LogServiceImpl.java:54)
at greenhouse.ejb3.sample.framework.LogServiceImpl.<clinit>(LogServiceImpl.java:51)
at greenhouse.ejb3.sample.framework.LogService.getLog(LogService.java:23)
at greenhouse.ejb3.sample.RandomNumberGeneratorBean.<clinit>(RandomNumberGeneratorBean.java:16)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:247)
at weblogic.ejb.container.dd.xml.EjbAnnotationProcessor.processWLSAnnotations(EjbAnnotationProcessor.java:1699)
at weblogic.ejb.container.dd.xml.EjbDescriptorReaderImpl.processWLSAnnotations(EjbDescriptorReaderImpl.java:346)
at weblogic.ejb.container.dd.xml.EjbDescriptorReaderImpl.createReadOnlyDescriptorFromJarFile(EjbDescriptorReaderImpl.java:192)
at weblogic.ejb.spi.EjbDescriptorFactory.createReadOnlyDescriptorFromJarFile(EjbDescriptorFactory.java:93)
at weblogic.ejb.container.deployer.EJBModule.loadEJBDescriptor(EJBModule.java:1198)
at weblogic.ejb.container.deployer.EJBModule.prepare(EJBModule.java:380)
at weblogic.application.internal.flow.ModuleListenerInvoker.prepare(ModuleListenerInvoker.java:93)
at weblogic.application.internal.flow.DeploymentCallbackFlow$1.next(DeploymentCallbackFlow.java:387)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
at weblogic.application.internal.flow.DeploymentCallbackFlow.prepare(DeploymentCallbackFlow.java:58)
at weblogic.application.internal.flow.DeploymentCallbackFlow.prepare(DeploymentCallbackFlow.java:42)
at weblogic.application.internal.BaseDeployment$1.next(BaseDeployment.java:615)
at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:37)
at weblogic.application.internal.BaseDeployment.prepare(BaseDeployment.java:191)
at weblogic.application.internal.EarDeployment.prepare(EarDeployment.java:16)
at weblogic.application.internal.DeploymentStateChecker.prepare(DeploymentStateChecker.java:155)
at weblogic.deploy.internal.targetserver.AppContainerInvoker.prepare(AppContainerInvoker.java:60)
at weblogic.deploy.internal.targetserver.AppDeployment.prepare(AppDeployment.java:141)
at weblogic.management.deploy.internal.DeploymentAdapter$1.doPrepare(DeploymentAdapter.java:39)
at weblogic.management.deploy.internal.DeploymentAdapter.prepare(DeploymentAdapter.java:187)
at weblogic.management.deploy.internal.AppTransition$1.transitionApp(AppTransition.java:21)
at weblogic.management.deploy.internal.ConfiguredDeployments.transitionApps(ConfiguredDeployments.java:233)
at weblogic.management.deploy.internal.ConfiguredDeployments.prepare(ConfiguredDeployments.java:165)
at weblogic.management.deploy.internal.ConfiguredDeployments.deploy(ConfiguredDeployments.java:122)
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)


Update on Nov 10th 2009


Thanks to Dror Bereznetsky for the heads up on the code analysis of "EjbDescriptorReaderImpl.createReadOnlyDescriptorFromJarFile(EjbDescriptorReaderImpl.java:192)" I managed to create a small patch to weblogic.jar that solved the problem.

The "stupid" issue is that the new class loader created for bean analysis was using the parent class loader of the EAR classloader, basically ignoring all the classes of my application that where reloaded on each analysis...

I went very strong on my patch making the parent of the bean analyzer class loader the current thread class loader, and it works. More tests coming, and a small hope that "Oracle" will solve the bug soon :(