[
https://issues.apache.org/jira/browse/TOMEE-4293?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Nicolas Ternisien updated TOMEE-4293:
-------------------------------------
Description:
h3. High Memory Consumption / Load Time when using WAR file (as "Collapsed
EAR") vs EAR file
We're currently experimenting the migration of an EAR project from Oracle
Weblogic application server to TomEE.
While conducting this experiment, we also tried to see if we could rely on
"Collapsed EAR" approach, ie, simplifying the application by providing a single
WAR file with EJBs embedded into it, instead of multiple ejb and web modules
inside the EAR file.
The project is quite big with:
* 1992 EJBs in EJB Module (+ CDI beans)
* 1193 EJBs in Web Module (+ CDI beans for JAX RS resources)
* (and a total of 8569 injection points via @EJB annotation - you can keep
this info for later)
Still, with the EAR approach, total loading time is about 1min, with 3.1 GB JVM
memory usage, so this is quite good (way faster than Oracle Weblogic).
When trying the alternative approach via a WAR file (including the EJB module
as JAR), the startup takes huge time (30 to 40 minutes) and JVM memory
consumption goes up to 8.7 GB.
h3. How to Reproduce
We tried to investigate this difference and we have identified the bottleneck
(via TomEE startup debugging) at JndiEncInfoBuilder, more especially at
JndiEncInfoBuilder.buildEjbRefs() where each EJB has the *whole* list of
ejbLocalRef of all the EJBs of the entire application. We are not very sure if
this is an expected behavior, but each EJB referenced is linked to the 8569
injection points discovered.
Wed've setup a dedicated project (in attachment), with 2 different deployable
binaries:
* collapsedear-bug.war
* collapsedear-bug-ear.ear
So that we could compare the two processes at loading time.
Note the deployment is performed via the "tomee/apps" folder. Please note we
only deployed on archive at a time, to be able to properly compare the two
startups.
Both WAR and EAR contains an EJB module, named "collapsedear-bug-ejb", which
itself contains the following basic EJB NumberService.java:
{code:java}
package org.lastnico.collapsedear.bug.ejb;
import java.util.Random;
import javax.annotation.PostConstruct;
import javax.ejb.EJB;
import javax.ejb.Singleton;
import javax.ejb.Startup;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@Singleton
@Startup
public class NumberService {
private static Logger log = LoggerFactory.getLogger(NumberFinder.class);
@PostConstruct
public void start() {
log.info("Starting {}", this.getClass());
}
@EJB
private NumberFinder userFinder;
public long save() {
return new Random().nextLong();
}
}
{code}
Of course, this project is much more simple (less than 5 EJBs in total), so we
cannot notice it from memory consumption or loading time, but here are the
debugging output:
h4. collapsedear-bug.war
At startup, with a debugging breakpoint, watching for "NumberService" EJB
registration
at
{code}
org.apache.openejb.config.JndiEncInfoBuilder.build(final JndiConsumer
jndiConsumer, final String ejbName, final String moduleId, final URI moduleUri,
final JndiEncInfo moduleJndiEnc, final JndiEncInfo compJndiEnc) throws
OpenEJBException {
{code}
{code:java}
moduleId = collapsedear-bug-ejb
JndiConsumer.ejbClass = "org.lastnico.collapsedear.bug.ejb.NumberService"
JndiConsumer.ejbLocalRef =
{java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'},
java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/numberFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/numberFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'},
java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/calculatorFront=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/calculatorFront',
local=org.lastnico.collapsedear.bug.war.CalculatorFront, link='null',
mappedName='null', lookupName='null'},
java:comp/env/org.lastnico.collapsedear.bug.war.CalculatorFront/numberFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.CalculatorFront/numberFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'}}{code}
You can see that ejbLocalRef contains 8 different injection points, while
NumberService has only a single injection point (NumberFinder). Most of them
actually relates to *other* EJBs in the application. If we skip and go to the
next EJB JNDI registration, the exact same complete list of ejbLocalRef is
provided.
h4. collapsedear-bug-ear.ear
At the opposite, when debugging the startup of the equivalent EAR file
Here are the debugging info extracted:
{code}
moduleId = collapsedear-bug-ejb
JndiConsumer.ejbClass = "org.lastnico.collapsedear.bug.ejb.NumberService"
JndiConsumer.ejbLocalRef =
{java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'}}
{code}
This time, as expected, the NumberService EJB only has 1 single EJB local ref,
matching its single injection point.
h4. Suspicion
I suspect the reason for this is that MergeWebappJndiContext indistinctely
copies all possible EJB local refs, and hence each EJB receives the whole list
of injection points.
In the scenario of our application described earlier, we end up with (1992 +
1193) * 8569 declared EJB local refs, which slows down the whole startup and
waste huge quantity of memory.
You can find in attachments both the WAR and EAR file, as well as the log
output of both deployable artifacts, and the source code of the respective
Maven project. Please note this was tested against TomEE 8.0.16 because this is
our current target, but I assume this issue could also be valid on TomEE 9.1.2
Thanks!
was:
h3. High Memory Consumption / Load Time when using WAR file (as "Collapsed
EAR") vs EAR file
We're currently experimenting the migration of an EAR project from Oracle
Weblogic application server to TomEE.
While conducting this experiment, we also tried to see if we could rely on
"Collapsed EAR" approach, ie, simplifying the application by providing a single
WAR file with EJBs embedded into it, instead of multiple ejb and web modules
inside the EAR file.
The project is quite big with:
* 1992 EJBs in EJB Module (+ CDI beans)
* 1193 EJBs in Web Module (+ CDI beans for JAX RS resources)
* (and a total of 8569 injection points via @EJB annotation - you can keep
this info for later)
Still, with the EAR approach, total loading time is about 1min, with 3.1 GB JVM
memory usage, so this is quite good (way faster than Oracle Weblogic).
When trying the alternative approach via a WAR file (including the EJB module
as JAR), the startup takes huge time (30 to 40 minutes) and JVM memory
consumption goes up to 8.7 GB.
h3. How to Reproduce
We tried to investigate this difference and we have identified the bottleneck
(via TomEE startup debugging) at JndiEncInfoBuilder, more especially at
JndiEncInfoBuilder.buildEjbRefs() where each EJB has the *whole* list of
ejbLocalRef of all the EJBs of the entire application. We are not very sure if
this is an expected behavior, but each EJB referenced is linked to the 8569
injection points discovered.
Wed've setup a dedicated project (in attachment), with 2 different deployable
binaries:
* collapsedear-bug.war
* collapsedear-bug-ear.ear
So that we could compare the two processes at loading time.
Note the deployment is performed via the "tomee/apps" folder. Please note we
only deployed on archive at a time, to be able to properly compare the two
startups.
Both WAR and EAR contains an EJB module, named "collapsedear-bug-ejb", which
itself contains the following basic EJB NumberService.java:
{code:java}
package org.lastnico.collapsedear.bug.ejb;
import java.util.Random;
import javax.annotation.PostConstruct;
import javax.ejb.EJB;
import javax.ejb.Singleton;
import javax.ejb.Startup;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@Singleton
@Startup
public class NumberService {
private static Logger log = LoggerFactory.getLogger(NumberFinder.class);
@PostConstruct
public void start() {
log.info("Starting {}", this.getClass());
}
@EJB
private NumberFinder userFinder;
public long save() {
return new Random().nextLong();
}
}
{code}
Of course, this project is much more simple (less than 5 EJBs in total), so we
cannot notice it from memory consumption or loading time, but here are the
debugging output:
h4. collapsedear-bug.war
At startup, with a debugging breakpoint, watching for "NumberService" EJB
registration
at
{code}
org.apache.openejb.config.JndiEncInfoBuilder.build(final JndiConsumer
jndiConsumer, final String ejbName, final String moduleId, final URI moduleUri,
final JndiEncInfo moduleJndiEnc, final JndiEncInfo compJndiEnc) throws
OpenEJBException {
{code}
{code:java}
moduleId = collapsedear-bug-ejb
JndiConsumer.ejbClass = "org.lastnico.collapsedear.bug.ejb.NumberService"
JndiConsumer.ejbLocalRef =
{java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'},
java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/numberFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/numberFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'},
java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/calculatorFront=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/calculatorFront',
local=org.lastnico.collapsedear.bug.war.CalculatorFront, link='null',
mappedName='null', lookupName='null'},
java:comp/env/org.lastnico.collapsedear.bug.war.CalculatorFront/numberFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.CalculatorFront/numberFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'}}{code}
You can see that ejbLocalRef contains 8 different injection points, while
NumberService has only a single injection point (NumberFinder)
h4. collapsedear-bug-ear.ear
At the opposite, when debugging the startup of the equivalent EAR file
Here are the debugging info extracted:
{code}
moduleId = collapsedear-bug-ejb
JndiConsumer.ejbClass = "org.lastnico.collapsedear.bug.ejb.NumberService"
JndiConsumer.ejbLocalRef =
{java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder',
local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
mappedName='null', lookupName='null'}}
{code}
This time, as expected, the NumberService EJB only has 1 single EJB local ref,
matching its single injection point.
h4. Suspicion
I suspect the reason for this is that MergeWebappJndiContext indistinctely
copies all possible EJB local refs, and hence each EJB receives the whole list
of injection points.
In the scenario of our application described earlier, we end up with (1992 +
1193) * 8569 declared EJB local refs, which slows down the whole startup and
waste huge quantity of memory.
You can find in attachments both the WAR and EAR file, as well as the log
output of both deployable artifacts, and the source code of the respective
Maven project. Please note this was tested against TomEE 8.0.16 because this is
our current target, but I assume this issue could also be valid on TomEE 9.1.2
Thanks!
> WAR-wide EJB local refs inserted into each EJB at startup
> ---------------------------------------------------------
>
> Key: TOMEE-4293
> URL: https://issues.apache.org/jira/browse/TOMEE-4293
> Project: TomEE
> Issue Type: Bug
> Components: TomEE Core Server
> Affects Versions: 8.0.16
> Reporter: Nicolas Ternisien
> Priority: Major
> Attachments: collapsedear-bug-ear.catalina.out,
> collapsedear-bug-ear.ear, collapsedear-bug-project.tar.gz,
> collapsedear-bug.war, collapsedear-bug.war.catalina.out
>
>
> h3. High Memory Consumption / Load Time when using WAR file (as "Collapsed
> EAR") vs EAR file
> We're currently experimenting the migration of an EAR project from Oracle
> Weblogic application server to TomEE.
> While conducting this experiment, we also tried to see if we could rely on
> "Collapsed EAR" approach, ie, simplifying the application by providing a
> single WAR file with EJBs embedded into it, instead of multiple ejb and web
> modules inside the EAR file.
> The project is quite big with:
> * 1992 EJBs in EJB Module (+ CDI beans)
> * 1193 EJBs in Web Module (+ CDI beans for JAX RS resources)
> * (and a total of 8569 injection points via @EJB annotation - you can keep
> this info for later)
> Still, with the EAR approach, total loading time is about 1min, with 3.1 GB
> JVM memory usage, so this is quite good (way faster than Oracle Weblogic).
> When trying the alternative approach via a WAR file (including the EJB module
> as JAR), the startup takes huge time (30 to 40 minutes) and JVM memory
> consumption goes up to 8.7 GB.
>
> h3. How to Reproduce
> We tried to investigate this difference and we have identified the bottleneck
> (via TomEE startup debugging) at JndiEncInfoBuilder, more especially at
> JndiEncInfoBuilder.buildEjbRefs() where each EJB has the *whole* list of
> ejbLocalRef of all the EJBs of the entire application. We are not very sure
> if this is an expected behavior, but each EJB referenced is linked to the
> 8569 injection points discovered.
> Wed've setup a dedicated project (in attachment), with 2 different deployable
> binaries:
> * collapsedear-bug.war
> * collapsedear-bug-ear.ear
> So that we could compare the two processes at loading time.
> Note the deployment is performed via the "tomee/apps" folder. Please note we
> only deployed on archive at a time, to be able to properly compare the two
> startups.
> Both WAR and EAR contains an EJB module, named "collapsedear-bug-ejb", which
> itself contains the following basic EJB NumberService.java:
> {code:java}
> package org.lastnico.collapsedear.bug.ejb;
> import java.util.Random;
> import javax.annotation.PostConstruct;
> import javax.ejb.EJB;
> import javax.ejb.Singleton;
> import javax.ejb.Startup;
> import org.slf4j.Logger;
> import org.slf4j.LoggerFactory;
> @Singleton
> @Startup
> public class NumberService {
> private static Logger log = LoggerFactory.getLogger(NumberFinder.class);
> @PostConstruct
> public void start() {
> log.info("Starting {}", this.getClass());
> }
> @EJB
> private NumberFinder userFinder;
> public long save() {
> return new Random().nextLong();
> }
> }
> {code}
>
> Of course, this project is much more simple (less than 5 EJBs in total), so
> we cannot notice it from memory consumption or loading time, but here are the
> debugging output:
>
> h4. collapsedear-bug.war
> At startup, with a debugging breakpoint, watching for "NumberService" EJB
> registration
> at
> {code}
> org.apache.openejb.config.JndiEncInfoBuilder.build(final JndiConsumer
> jndiConsumer, final String ejbName, final String moduleId, final URI
> moduleUri, final JndiEncInfo moduleJndiEnc, final JndiEncInfo compJndiEnc)
> throws OpenEJBException {
> {code}
> {code:java}
> moduleId = collapsedear-bug-ejb
> JndiConsumer.ejbClass = "org.lastnico.collapsedear.bug.ejb.NumberService"
> JndiConsumer.ejbLocalRef =
> {java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder',
> local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
> mappedName='null', lookupName='null'},
> java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/numberFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/numberFinder',
> local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
> mappedName='null', lookupName='null'},
> java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/calculatorFront=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.GreetingResource/calculatorFront',
> local=org.lastnico.collapsedear.bug.war.CalculatorFront, link='null',
> mappedName='null', lookupName='null'},
> java:comp/env/org.lastnico.collapsedear.bug.war.CalculatorFront/numberFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.war.CalculatorFront/numberFinder',
> local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
> mappedName='null', lookupName='null'}}{code}
>
> You can see that ejbLocalRef contains 8 different injection points, while
> NumberService has only a single injection point (NumberFinder). Most of them
> actually relates to *other* EJBs in the application. If we skip and go to the
> next EJB JNDI registration, the exact same complete list of ejbLocalRef is
> provided.
> h4. collapsedear-bug-ear.ear
> At the opposite, when debugging the startup of the equivalent EAR file
> Here are the debugging info extracted:
> {code}
> moduleId = collapsedear-bug-ejb
> JndiConsumer.ejbClass = "org.lastnico.collapsedear.bug.ejb.NumberService"
> JndiConsumer.ejbLocalRef =
> {java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder=EjbLocalRef{name='java:comp/env/org.lastnico.collapsedear.bug.ejb.NumberService/userFinder',
> local=org.lastnico.collapsedear.bug.ejb.NumberFinder, link='null',
> mappedName='null', lookupName='null'}}
> {code}
> This time, as expected, the NumberService EJB only has 1 single EJB local
> ref, matching its single injection point.
> h4. Suspicion
> I suspect the reason for this is that MergeWebappJndiContext indistinctely
> copies all possible EJB local refs, and hence each EJB receives the whole
> list of injection points.
> In the scenario of our application described earlier, we end up with (1992 +
> 1193) * 8569 declared EJB local refs, which slows down the whole startup and
> waste huge quantity of memory.
> You can find in attachments both the WAR and EAR file, as well as the log
> output of both deployable artifacts, and the source code of the respective
> Maven project. Please note this was tested against TomEE 8.0.16 because this
> is our current target, but I assume this issue could also be valid on TomEE
> 9.1.2
> Thanks!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
