[JBoss JIRA] (WFLY-9408) Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
by Scott Marlow (JIRA)
[ https://issues.jboss.org/browse/WFLY-9408?page=com.atlassian.jira.plugin.... ]
Scott Marlow commented on WFLY-9408:
------------------------------------
Thanks Brian!
[~nuno.godinhomatos] can you verify that Brian's change addresses the performance issue that you observed?
You should be able to retrieve it via:
{quote}
git fetch https://github.com/bstansberry/wildfly.git WFLY-9408:WFLY-9408
{quote}
> Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
> --------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9408
> URL: https://issues.jboss.org/browse/WFLY-9408
> Project: WildFly
> Issue Type: Bug
> Components: JPA / Hibernate
> Affects Versions: 10.1.0.Final
> Reporter: Nuno Godinho de Matos
> Assignee: Scott Marlow
> Fix For: 11.0.0.Final
>
>
> I have been trying to reduce the deployment of a WAR application.
> One of the greate bottlenecks on the deployment is the cost of getting the first EntityManager instance of eclipselink.
> To try to reduce cost of startup I found myself forced to during @Startup fire a CDI event observed by an @Asynchronous ejb whose only task is to do a dummy entityManager.flush().
> The results I had for the execution time of this observer could go as high as 13 seconds.
> On top of that, I had already noticed while writting an arquillian system test for eclipselink on:
> https://issues.jboss.org/browse/WFLY-8954
> that the cost of starting up elcipselink under wildfly was much much higher than that of Hibernate and OpenJPA.
> With this introduction done let us go to the facts, and they are quite ridiculous.
> I have sampled the deployment of an application from begging to end with a sampling script that took a thread dump every second to analyse where the app is spending deployment time generically.
> Eventually, I reached the eclipselink deployment.
> And I had entries on the log such as:
> DatabaseEntityManagerStarter] - <- StartupDatabaseEntityManagerStarter.observeApplicationReadyLoadEntityManagerEvent {5948 ms} <EJB aync-ejb-thread-pool - 1>
> While sampling why this was happening I got more than 7 straight thread dump samples (more than 7 seconds) where the following stack trace was present:
> {panel}
> at java.security.AccessController.getContext(Unknown Source)
> at org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:47)
> at org.jboss.as.controller.AbstractOperationContext.getCaller(AbstractOperationContext.java:1138)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:1306)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:128)
> at org.jboss.as.controller.operations.global.ReadResourceDescriptionHandler$CheckResourceAccessHandler.execute(ReadResourceDescriptionHandler.java:429)
> at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:890)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:659)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1329)
> at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:400)
> at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:208)
> at org.jboss.as.jmx.model.ResourceAccessControlUtil.getResourceAccess(ResourceAccessControlUtil.java:85)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:51)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.iterate(RootResourceIterator.java:43)
> at org.jboss.as.jmx.model.ModelControllerMBeanHelper.getMBeanCount(ModelControllerMBeanHelper.java:125)
> at org.jboss.as.jmx.model.ModelControllerMBeanServerPlugin.getMBeanCount(ModelControllerMBeanServerPlugin.java:161)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.getMBeanCount(PluggableMBeanServerImpl.java:545)
> ----- Because of the mBeanServer.getMBeanCount():
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
>
>
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.serverSpecificRegisterMBean(JMXServerPlatformBase.java:297)
> ---- Will register Managed beans under the prefix: TopLink:Name="
> at org.eclipse.persistence.platform.server.jboss.JBossPlatform.serverSpecificRegisterMBean(JBossPlatform.java:147)
> at org.eclipse.persistence.platform.server.ServerPlatformBase.registerMBean(ServerPlatformBase.java:581)
> ------- this.serverSpecificRegisterMBean();
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.postConnectDatasource(DatabaseSessionImpl.java:857)
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.loginAndDetectDatasource(DatabaseSessionImpl.java:762)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.login(EntityManagerFactoryProvider.java:265)
> at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:731)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getAbstractSession(EntityManagerFactoryDelegate.java:205)
> - locked [0x00000000a90d1210] (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:305)
> {panel}
> After chekcing the eclipselink source code associated to line:
> {panel}
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> {panel}
> I found the following source code - which I could hardly believe would explain this deployment bottleneck:
> {panel}
> } else {
> // Only a single MBeanServer instance was found
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
> }
> {panel}
> In short, the first eclipselink entity manager cost of creation is a never ending task under wildfly because of how expensive the above log statement is:
> {panel}
> mBeanServer.getMBeanCount()
> {panel}
> I do not know how to interpret this.
> Is the problem that the API should cost ms and it literally takes several seconds to calculate - and the problem is the cost of the API under wildfly.
> Or is it that eclipselink should never have written such a log statement on the first place?
> To address the issue, I have hacked up my local:
> org.jipijapa.eclipselink.WildFlyServerPlatform
> In this class, I have override the getMeabServer API from the base class.
> I Have created a hacked constant:
> {panel}
> /**
> * During deployment, when the first entity manager is created, the
> * application deployment becomes extremelty slow due to the
> * MbeanServer.getbeanCount() access done by eclipselink. This access is on
> * top of all things done only for logging purposes. We completely kill the
> * call to the api.
> */
> private static final int MBEAN_SERVER_COUNT_DUMMY_VALUE = -999;
> {panel}
> And finally I added an overriden method:
> {panel}
> @Override
> public MBeanServer getMBeanServer() {
> /**
> * This function will attempt to get the MBeanServer via the
> * findMBeanServer spec call. 1) If the return list is null we attempt
> * to retrieve the PlatformMBeanServer (if it exists or is enabled in
> * this security context). 2) If the list of MBeanServers returned is
> * more than one we get the lowest indexed MBeanServer that does not on
> * a null default domain. 3) 333336: we need to wrap JMX calls in
> * doPrivileged blocks 4) fail-fast: if there are any issues with JMX -
> * continue - don't block the deploy()
> */
> // lazy initialize the MBeanServer reference
> if (null == mBeanServer) {
> List<MBeanServer> mBeanServerList = null;
> try {
> if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> try {
> mBeanServerList = (List<MBeanServer>) AccessController
> .doPrivileged(new PrivilegedExceptionAction() {
> @Override
> public List<MBeanServer> run() {
> return MBeanServerFactory.findMBeanServer(null);
> }
> });
> } catch (PrivilegedActionException pae) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from privileged MBeanServerFactory.findMBeanServer(null)");
> Context initialContext = null;
> try {
> initialContext = new InitialContext(); // the
> // context
> // should be
> // cached
> mBeanServer = (MBeanServer) initialContext.lookup(JMX_JNDI_RUNTIME_REGISTER);
> } catch (NamingException ne) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server", ne);
> }
> }
> } else {
> mBeanServerList = MBeanServerFactory.findMBeanServer(null);
> }
> // Attempt to get the first MBeanServer we find - usually there
> // is only one - when agentId == null we return a List of them
> if (null == mBeanServer && (null == mBeanServerList || mBeanServerList.isEmpty())) {
> // Unable to acquire a JMX specification List of MBeanServer
> // instances
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from MBeanServerFactory.findMBeanServer(null)");
> // Try alternate static method
> if (!PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> mBeanServer = ManagementFactory.getPlatformMBeanServer();
> if (null == mBeanServer) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server",
> "null returned from ManagementFactory.getPlatformMBeanServer()");
> } else {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { mBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } else {
> // Use the first MBeanServer by default - there may be
> // multiple domains each with their own MBeanServer
> mBeanServer = mBeanServerList.get(JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS);
> if (mBeanServerList.size() > 1) {
> // There are multiple MBeanServerInstances (usually only
> // JBoss)
> // 328006: WebLogic may also return multiple instances
> // (we need to register the one containing the com.bea
> // tree)
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_encountered_multiple_mbeanserver_instances",
> mBeanServerList.size(), JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS,
> mBeanServer);
> // IE: for JBoss we need to verify we are using the
> // correct MBean server of the two (default, null)
> // Check the domain if it is non-null - avoid using this
> // server
> int index = 0;
> for (MBeanServer anMBeanServer : mBeanServerList) {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { anMBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> anMBeanServer.getDefaultDomain(), index });
> if (null != anMBeanServer.getDefaultDomain()) {
> mBeanServer = anMBeanServer;
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_switching_to_alternate_mbeanserver", mBeanServer,
> index);
> }
> index++;
> }
> } else {
> // Only a single MBeanServer instance was found
> // mBeanServer.getMBeanCount() - This is very slow on
> // wildfly
> // we are disabling this statemnt
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print", new Object[] { mBeanServer,
> MBEAN_SERVER_COUNT_DUMMY_VALUE, mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } catch (Exception e) {
> // TODO: Warning required
> e.printStackTrace();
> }
> }
> return mBeanServer;
> }
> {panel}
> The above code looks extremelly complex to me just to get a MBeanserver in an application server.
> I find it hard to believe that this operation should ever have a code with this many lines of code behind it, but ok.
> As you can see in the code I am pasting the only trick I am putting in place to address the deployment time on my machine is to replace every single mebanserver.getMbeanCoundt() by a "dumb" reference to the constant: MBEAN_SERVER_COUNT_DUMMY_VALUE.
> Would it possible that the wildflt server platform be tuned to address this issue?
> I think it would be a good Idea if you revise the getMbeanServer api to be as simple as possible for JBOSS/Wildfly - the base eclipselink code make slittle since in my oppinion.
> But you will know best.
> It is also interesting that now when i run the test suite project from wildfly eclipselink actualy manages to be few ms faster than hibernate:
> {panel}
> Running org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.662 sec - in org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> This eclipselink test is actually now faster than
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.685 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Running org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.714 sec - in
> The hibernate test here loses to the eclipselink test above.
> org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Running org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.218 sec - in org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> {panel}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (LOGMGR-142) Default app-name value of Syslog handler in Audit Logging violates specification
by James Perkins (JIRA)
[ https://issues.jboss.org/browse/LOGMGR-142?page=com.atlassian.jira.plugin... ]
James Perkins updated LOGMGR-142:
---------------------------------
Fix Version/s: 2.1.0.Alpha5
> Default app-name value of Syslog handler in Audit Logging violates specification
> --------------------------------------------------------------------------------
>
> Key: LOGMGR-142
> URL: https://issues.jboss.org/browse/LOGMGR-142
> Project: JBoss Log Manager
> Issue Type: Bug
> Reporter: Jan Tymel
> Assignee: James Perkins
> Fix For: 2.1.0.Alpha5
>
>
> According to syslog specification[1] {{app-name}} cannot contain space character (" "). However, the default value in WildFly Core 3.0.0.Alpha3 is {{WildFly Core}}. This results in the syslog server is not able to capture Process ID from which the message was sent.
> E.g. following piece of information is captured {{WildFly[Core] (...)}} instead of {{WildFlyCore[795]}}
> Suggestions for improvement:
> Change default value {{WildFly Core}} to one without space character.
> Also please consider addition of check whether {{app-name}} contains space character.
> [1] https://tools.ietf.org/html/rfc5424#page-8
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (WFLY-9408) Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
by Brian Stansberry (JIRA)
[ https://issues.jboss.org/browse/WFLY-9408?page=com.atlassian.jira.plugin.... ]
Brian Stansberry commented on WFLY-9408:
----------------------------------------
I pushed a second commit that drops those log calls, in case you want to go that route.
> Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
> --------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9408
> URL: https://issues.jboss.org/browse/WFLY-9408
> Project: WildFly
> Issue Type: Bug
> Components: JPA / Hibernate
> Affects Versions: 10.1.0.Final
> Reporter: Nuno Godinho de Matos
> Assignee: Scott Marlow
> Fix For: 11.0.0.Final
>
>
> I have been trying to reduce the deployment of a WAR application.
> One of the greate bottlenecks on the deployment is the cost of getting the first EntityManager instance of eclipselink.
> To try to reduce cost of startup I found myself forced to during @Startup fire a CDI event observed by an @Asynchronous ejb whose only task is to do a dummy entityManager.flush().
> The results I had for the execution time of this observer could go as high as 13 seconds.
> On top of that, I had already noticed while writting an arquillian system test for eclipselink on:
> https://issues.jboss.org/browse/WFLY-8954
> that the cost of starting up elcipselink under wildfly was much much higher than that of Hibernate and OpenJPA.
> With this introduction done let us go to the facts, and they are quite ridiculous.
> I have sampled the deployment of an application from begging to end with a sampling script that took a thread dump every second to analyse where the app is spending deployment time generically.
> Eventually, I reached the eclipselink deployment.
> And I had entries on the log such as:
> DatabaseEntityManagerStarter] - <- StartupDatabaseEntityManagerStarter.observeApplicationReadyLoadEntityManagerEvent {5948 ms} <EJB aync-ejb-thread-pool - 1>
> While sampling why this was happening I got more than 7 straight thread dump samples (more than 7 seconds) where the following stack trace was present:
> {panel}
> at java.security.AccessController.getContext(Unknown Source)
> at org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:47)
> at org.jboss.as.controller.AbstractOperationContext.getCaller(AbstractOperationContext.java:1138)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:1306)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:128)
> at org.jboss.as.controller.operations.global.ReadResourceDescriptionHandler$CheckResourceAccessHandler.execute(ReadResourceDescriptionHandler.java:429)
> at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:890)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:659)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1329)
> at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:400)
> at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:208)
> at org.jboss.as.jmx.model.ResourceAccessControlUtil.getResourceAccess(ResourceAccessControlUtil.java:85)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:51)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.iterate(RootResourceIterator.java:43)
> at org.jboss.as.jmx.model.ModelControllerMBeanHelper.getMBeanCount(ModelControllerMBeanHelper.java:125)
> at org.jboss.as.jmx.model.ModelControllerMBeanServerPlugin.getMBeanCount(ModelControllerMBeanServerPlugin.java:161)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.getMBeanCount(PluggableMBeanServerImpl.java:545)
> ----- Because of the mBeanServer.getMBeanCount():
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
>
>
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.serverSpecificRegisterMBean(JMXServerPlatformBase.java:297)
> ---- Will register Managed beans under the prefix: TopLink:Name="
> at org.eclipse.persistence.platform.server.jboss.JBossPlatform.serverSpecificRegisterMBean(JBossPlatform.java:147)
> at org.eclipse.persistence.platform.server.ServerPlatformBase.registerMBean(ServerPlatformBase.java:581)
> ------- this.serverSpecificRegisterMBean();
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.postConnectDatasource(DatabaseSessionImpl.java:857)
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.loginAndDetectDatasource(DatabaseSessionImpl.java:762)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.login(EntityManagerFactoryProvider.java:265)
> at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:731)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getAbstractSession(EntityManagerFactoryDelegate.java:205)
> - locked [0x00000000a90d1210] (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:305)
> {panel}
> After chekcing the eclipselink source code associated to line:
> {panel}
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> {panel}
> I found the following source code - which I could hardly believe would explain this deployment bottleneck:
> {panel}
> } else {
> // Only a single MBeanServer instance was found
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
> }
> {panel}
> In short, the first eclipselink entity manager cost of creation is a never ending task under wildfly because of how expensive the above log statement is:
> {panel}
> mBeanServer.getMBeanCount()
> {panel}
> I do not know how to interpret this.
> Is the problem that the API should cost ms and it literally takes several seconds to calculate - and the problem is the cost of the API under wildfly.
> Or is it that eclipselink should never have written such a log statement on the first place?
> To address the issue, I have hacked up my local:
> org.jipijapa.eclipselink.WildFlyServerPlatform
> In this class, I have override the getMeabServer API from the base class.
> I Have created a hacked constant:
> {panel}
> /**
> * During deployment, when the first entity manager is created, the
> * application deployment becomes extremelty slow due to the
> * MbeanServer.getbeanCount() access done by eclipselink. This access is on
> * top of all things done only for logging purposes. We completely kill the
> * call to the api.
> */
> private static final int MBEAN_SERVER_COUNT_DUMMY_VALUE = -999;
> {panel}
> And finally I added an overriden method:
> {panel}
> @Override
> public MBeanServer getMBeanServer() {
> /**
> * This function will attempt to get the MBeanServer via the
> * findMBeanServer spec call. 1) If the return list is null we attempt
> * to retrieve the PlatformMBeanServer (if it exists or is enabled in
> * this security context). 2) If the list of MBeanServers returned is
> * more than one we get the lowest indexed MBeanServer that does not on
> * a null default domain. 3) 333336: we need to wrap JMX calls in
> * doPrivileged blocks 4) fail-fast: if there are any issues with JMX -
> * continue - don't block the deploy()
> */
> // lazy initialize the MBeanServer reference
> if (null == mBeanServer) {
> List<MBeanServer> mBeanServerList = null;
> try {
> if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> try {
> mBeanServerList = (List<MBeanServer>) AccessController
> .doPrivileged(new PrivilegedExceptionAction() {
> @Override
> public List<MBeanServer> run() {
> return MBeanServerFactory.findMBeanServer(null);
> }
> });
> } catch (PrivilegedActionException pae) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from privileged MBeanServerFactory.findMBeanServer(null)");
> Context initialContext = null;
> try {
> initialContext = new InitialContext(); // the
> // context
> // should be
> // cached
> mBeanServer = (MBeanServer) initialContext.lookup(JMX_JNDI_RUNTIME_REGISTER);
> } catch (NamingException ne) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server", ne);
> }
> }
> } else {
> mBeanServerList = MBeanServerFactory.findMBeanServer(null);
> }
> // Attempt to get the first MBeanServer we find - usually there
> // is only one - when agentId == null we return a List of them
> if (null == mBeanServer && (null == mBeanServerList || mBeanServerList.isEmpty())) {
> // Unable to acquire a JMX specification List of MBeanServer
> // instances
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from MBeanServerFactory.findMBeanServer(null)");
> // Try alternate static method
> if (!PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> mBeanServer = ManagementFactory.getPlatformMBeanServer();
> if (null == mBeanServer) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server",
> "null returned from ManagementFactory.getPlatformMBeanServer()");
> } else {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { mBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } else {
> // Use the first MBeanServer by default - there may be
> // multiple domains each with their own MBeanServer
> mBeanServer = mBeanServerList.get(JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS);
> if (mBeanServerList.size() > 1) {
> // There are multiple MBeanServerInstances (usually only
> // JBoss)
> // 328006: WebLogic may also return multiple instances
> // (we need to register the one containing the com.bea
> // tree)
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_encountered_multiple_mbeanserver_instances",
> mBeanServerList.size(), JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS,
> mBeanServer);
> // IE: for JBoss we need to verify we are using the
> // correct MBean server of the two (default, null)
> // Check the domain if it is non-null - avoid using this
> // server
> int index = 0;
> for (MBeanServer anMBeanServer : mBeanServerList) {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { anMBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> anMBeanServer.getDefaultDomain(), index });
> if (null != anMBeanServer.getDefaultDomain()) {
> mBeanServer = anMBeanServer;
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_switching_to_alternate_mbeanserver", mBeanServer,
> index);
> }
> index++;
> }
> } else {
> // Only a single MBeanServer instance was found
> // mBeanServer.getMBeanCount() - This is very slow on
> // wildfly
> // we are disabling this statemnt
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print", new Object[] { mBeanServer,
> MBEAN_SERVER_COUNT_DUMMY_VALUE, mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } catch (Exception e) {
> // TODO: Warning required
> e.printStackTrace();
> }
> }
> return mBeanServer;
> }
> {panel}
> The above code looks extremelly complex to me just to get a MBeanserver in an application server.
> I find it hard to believe that this operation should ever have a code with this many lines of code behind it, but ok.
> As you can see in the code I am pasting the only trick I am putting in place to address the deployment time on my machine is to replace every single mebanserver.getMbeanCoundt() by a "dumb" reference to the constant: MBEAN_SERVER_COUNT_DUMMY_VALUE.
> Would it possible that the wildflt server platform be tuned to address this issue?
> I think it would be a good Idea if you revise the getMbeanServer api to be as simple as possible for JBOSS/Wildfly - the base eclipselink code make slittle since in my oppinion.
> But you will know best.
> It is also interesting that now when i run the test suite project from wildfly eclipselink actualy manages to be few ms faster than hibernate:
> {panel}
> Running org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.662 sec - in org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> This eclipselink test is actually now faster than
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.685 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Running org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.714 sec - in
> The hibernate test here loses to the eclipselink test above.
> org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Running org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.218 sec - in org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> {panel}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (WFLY-9408) Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
by Brian Stansberry (JIRA)
[ https://issues.jboss.org/browse/WFLY-9408?page=com.atlassian.jira.plugin.... ]
Brian Stansberry commented on WFLY-9408:
----------------------------------------
[~smarlow] My branch linked above isn't quite right either, as it is still using logging calls from the superclass. Those need to go since every time we upgrade eclipse link we have no idea whether those message codes / related params are correct.
So either the logging should be dropped altogether or the JPA subsystem will need to provide log messages.
> Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
> --------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9408
> URL: https://issues.jboss.org/browse/WFLY-9408
> Project: WildFly
> Issue Type: Bug
> Components: JPA / Hibernate
> Affects Versions: 10.1.0.Final
> Reporter: Nuno Godinho de Matos
> Assignee: Scott Marlow
> Fix For: 11.0.0.Final
>
>
> I have been trying to reduce the deployment of a WAR application.
> One of the greate bottlenecks on the deployment is the cost of getting the first EntityManager instance of eclipselink.
> To try to reduce cost of startup I found myself forced to during @Startup fire a CDI event observed by an @Asynchronous ejb whose only task is to do a dummy entityManager.flush().
> The results I had for the execution time of this observer could go as high as 13 seconds.
> On top of that, I had already noticed while writting an arquillian system test for eclipselink on:
> https://issues.jboss.org/browse/WFLY-8954
> that the cost of starting up elcipselink under wildfly was much much higher than that of Hibernate and OpenJPA.
> With this introduction done let us go to the facts, and they are quite ridiculous.
> I have sampled the deployment of an application from begging to end with a sampling script that took a thread dump every second to analyse where the app is spending deployment time generically.
> Eventually, I reached the eclipselink deployment.
> And I had entries on the log such as:
> DatabaseEntityManagerStarter] - <- StartupDatabaseEntityManagerStarter.observeApplicationReadyLoadEntityManagerEvent {5948 ms} <EJB aync-ejb-thread-pool - 1>
> While sampling why this was happening I got more than 7 straight thread dump samples (more than 7 seconds) where the following stack trace was present:
> {panel}
> at java.security.AccessController.getContext(Unknown Source)
> at org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:47)
> at org.jboss.as.controller.AbstractOperationContext.getCaller(AbstractOperationContext.java:1138)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:1306)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:128)
> at org.jboss.as.controller.operations.global.ReadResourceDescriptionHandler$CheckResourceAccessHandler.execute(ReadResourceDescriptionHandler.java:429)
> at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:890)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:659)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1329)
> at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:400)
> at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:208)
> at org.jboss.as.jmx.model.ResourceAccessControlUtil.getResourceAccess(ResourceAccessControlUtil.java:85)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:51)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.iterate(RootResourceIterator.java:43)
> at org.jboss.as.jmx.model.ModelControllerMBeanHelper.getMBeanCount(ModelControllerMBeanHelper.java:125)
> at org.jboss.as.jmx.model.ModelControllerMBeanServerPlugin.getMBeanCount(ModelControllerMBeanServerPlugin.java:161)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.getMBeanCount(PluggableMBeanServerImpl.java:545)
> ----- Because of the mBeanServer.getMBeanCount():
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
>
>
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.serverSpecificRegisterMBean(JMXServerPlatformBase.java:297)
> ---- Will register Managed beans under the prefix: TopLink:Name="
> at org.eclipse.persistence.platform.server.jboss.JBossPlatform.serverSpecificRegisterMBean(JBossPlatform.java:147)
> at org.eclipse.persistence.platform.server.ServerPlatformBase.registerMBean(ServerPlatformBase.java:581)
> ------- this.serverSpecificRegisterMBean();
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.postConnectDatasource(DatabaseSessionImpl.java:857)
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.loginAndDetectDatasource(DatabaseSessionImpl.java:762)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.login(EntityManagerFactoryProvider.java:265)
> at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:731)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getAbstractSession(EntityManagerFactoryDelegate.java:205)
> - locked [0x00000000a90d1210] (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:305)
> {panel}
> After chekcing the eclipselink source code associated to line:
> {panel}
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> {panel}
> I found the following source code - which I could hardly believe would explain this deployment bottleneck:
> {panel}
> } else {
> // Only a single MBeanServer instance was found
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
> }
> {panel}
> In short, the first eclipselink entity manager cost of creation is a never ending task under wildfly because of how expensive the above log statement is:
> {panel}
> mBeanServer.getMBeanCount()
> {panel}
> I do not know how to interpret this.
> Is the problem that the API should cost ms and it literally takes several seconds to calculate - and the problem is the cost of the API under wildfly.
> Or is it that eclipselink should never have written such a log statement on the first place?
> To address the issue, I have hacked up my local:
> org.jipijapa.eclipselink.WildFlyServerPlatform
> In this class, I have override the getMeabServer API from the base class.
> I Have created a hacked constant:
> {panel}
> /**
> * During deployment, when the first entity manager is created, the
> * application deployment becomes extremelty slow due to the
> * MbeanServer.getbeanCount() access done by eclipselink. This access is on
> * top of all things done only for logging purposes. We completely kill the
> * call to the api.
> */
> private static final int MBEAN_SERVER_COUNT_DUMMY_VALUE = -999;
> {panel}
> And finally I added an overriden method:
> {panel}
> @Override
> public MBeanServer getMBeanServer() {
> /**
> * This function will attempt to get the MBeanServer via the
> * findMBeanServer spec call. 1) If the return list is null we attempt
> * to retrieve the PlatformMBeanServer (if it exists or is enabled in
> * this security context). 2) If the list of MBeanServers returned is
> * more than one we get the lowest indexed MBeanServer that does not on
> * a null default domain. 3) 333336: we need to wrap JMX calls in
> * doPrivileged blocks 4) fail-fast: if there are any issues with JMX -
> * continue - don't block the deploy()
> */
> // lazy initialize the MBeanServer reference
> if (null == mBeanServer) {
> List<MBeanServer> mBeanServerList = null;
> try {
> if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> try {
> mBeanServerList = (List<MBeanServer>) AccessController
> .doPrivileged(new PrivilegedExceptionAction() {
> @Override
> public List<MBeanServer> run() {
> return MBeanServerFactory.findMBeanServer(null);
> }
> });
> } catch (PrivilegedActionException pae) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from privileged MBeanServerFactory.findMBeanServer(null)");
> Context initialContext = null;
> try {
> initialContext = new InitialContext(); // the
> // context
> // should be
> // cached
> mBeanServer = (MBeanServer) initialContext.lookup(JMX_JNDI_RUNTIME_REGISTER);
> } catch (NamingException ne) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server", ne);
> }
> }
> } else {
> mBeanServerList = MBeanServerFactory.findMBeanServer(null);
> }
> // Attempt to get the first MBeanServer we find - usually there
> // is only one - when agentId == null we return a List of them
> if (null == mBeanServer && (null == mBeanServerList || mBeanServerList.isEmpty())) {
> // Unable to acquire a JMX specification List of MBeanServer
> // instances
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from MBeanServerFactory.findMBeanServer(null)");
> // Try alternate static method
> if (!PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> mBeanServer = ManagementFactory.getPlatformMBeanServer();
> if (null == mBeanServer) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server",
> "null returned from ManagementFactory.getPlatformMBeanServer()");
> } else {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { mBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } else {
> // Use the first MBeanServer by default - there may be
> // multiple domains each with their own MBeanServer
> mBeanServer = mBeanServerList.get(JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS);
> if (mBeanServerList.size() > 1) {
> // There are multiple MBeanServerInstances (usually only
> // JBoss)
> // 328006: WebLogic may also return multiple instances
> // (we need to register the one containing the com.bea
> // tree)
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_encountered_multiple_mbeanserver_instances",
> mBeanServerList.size(), JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS,
> mBeanServer);
> // IE: for JBoss we need to verify we are using the
> // correct MBean server of the two (default, null)
> // Check the domain if it is non-null - avoid using this
> // server
> int index = 0;
> for (MBeanServer anMBeanServer : mBeanServerList) {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { anMBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> anMBeanServer.getDefaultDomain(), index });
> if (null != anMBeanServer.getDefaultDomain()) {
> mBeanServer = anMBeanServer;
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_switching_to_alternate_mbeanserver", mBeanServer,
> index);
> }
> index++;
> }
> } else {
> // Only a single MBeanServer instance was found
> // mBeanServer.getMBeanCount() - This is very slow on
> // wildfly
> // we are disabling this statemnt
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print", new Object[] { mBeanServer,
> MBEAN_SERVER_COUNT_DUMMY_VALUE, mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } catch (Exception e) {
> // TODO: Warning required
> e.printStackTrace();
> }
> }
> return mBeanServer;
> }
> {panel}
> The above code looks extremelly complex to me just to get a MBeanserver in an application server.
> I find it hard to believe that this operation should ever have a code with this many lines of code behind it, but ok.
> As you can see in the code I am pasting the only trick I am putting in place to address the deployment time on my machine is to replace every single mebanserver.getMbeanCoundt() by a "dumb" reference to the constant: MBEAN_SERVER_COUNT_DUMMY_VALUE.
> Would it possible that the wildflt server platform be tuned to address this issue?
> I think it would be a good Idea if you revise the getMbeanServer api to be as simple as possible for JBOSS/Wildfly - the base eclipselink code make slittle since in my oppinion.
> But you will know best.
> It is also interesting that now when i run the test suite project from wildfly eclipselink actualy manages to be few ms faster than hibernate:
> {panel}
> Running org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.662 sec - in org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> This eclipselink test is actually now faster than
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.685 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Running org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.714 sec - in
> The hibernate test here loses to the eclipselink test above.
> org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Running org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.218 sec - in org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> {panel}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (WFLY-9408) Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
by Brian Stansberry (JIRA)
[ https://issues.jboss.org/browse/WFLY-9408?page=com.atlassian.jira.plugin.... ]
Brian Stansberry updated WFLY-9408:
-----------------------------------
Workaround Description:
Remove the expose-expression-model and expose-resolved-model settings from the JMX subsystem config.
{code}
<subsystem xmlns="urn:jboss:domain:jmx:1.3">
<expose-resolved-model/>
<expose-expression-model/>
<remoting-connector/>
</subsystem>
{code}
Workaround: Workaround Exists
> Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
> --------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9408
> URL: https://issues.jboss.org/browse/WFLY-9408
> Project: WildFly
> Issue Type: Bug
> Components: JPA / Hibernate
> Affects Versions: 10.1.0.Final
> Reporter: Nuno Godinho de Matos
> Assignee: Scott Marlow
> Fix For: 11.0.0.Final
>
>
> I have been trying to reduce the deployment of a WAR application.
> One of the greate bottlenecks on the deployment is the cost of getting the first EntityManager instance of eclipselink.
> To try to reduce cost of startup I found myself forced to during @Startup fire a CDI event observed by an @Asynchronous ejb whose only task is to do a dummy entityManager.flush().
> The results I had for the execution time of this observer could go as high as 13 seconds.
> On top of that, I had already noticed while writting an arquillian system test for eclipselink on:
> https://issues.jboss.org/browse/WFLY-8954
> that the cost of starting up elcipselink under wildfly was much much higher than that of Hibernate and OpenJPA.
> With this introduction done let us go to the facts, and they are quite ridiculous.
> I have sampled the deployment of an application from begging to end with a sampling script that took a thread dump every second to analyse where the app is spending deployment time generically.
> Eventually, I reached the eclipselink deployment.
> And I had entries on the log such as:
> DatabaseEntityManagerStarter] - <- StartupDatabaseEntityManagerStarter.observeApplicationReadyLoadEntityManagerEvent {5948 ms} <EJB aync-ejb-thread-pool - 1>
> While sampling why this was happening I got more than 7 straight thread dump samples (more than 7 seconds) where the following stack trace was present:
> {panel}
> at java.security.AccessController.getContext(Unknown Source)
> at org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:47)
> at org.jboss.as.controller.AbstractOperationContext.getCaller(AbstractOperationContext.java:1138)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:1306)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:128)
> at org.jboss.as.controller.operations.global.ReadResourceDescriptionHandler$CheckResourceAccessHandler.execute(ReadResourceDescriptionHandler.java:429)
> at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:890)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:659)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1329)
> at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:400)
> at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:208)
> at org.jboss.as.jmx.model.ResourceAccessControlUtil.getResourceAccess(ResourceAccessControlUtil.java:85)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:51)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.iterate(RootResourceIterator.java:43)
> at org.jboss.as.jmx.model.ModelControllerMBeanHelper.getMBeanCount(ModelControllerMBeanHelper.java:125)
> at org.jboss.as.jmx.model.ModelControllerMBeanServerPlugin.getMBeanCount(ModelControllerMBeanServerPlugin.java:161)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.getMBeanCount(PluggableMBeanServerImpl.java:545)
> ----- Because of the mBeanServer.getMBeanCount():
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
>
>
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.serverSpecificRegisterMBean(JMXServerPlatformBase.java:297)
> ---- Will register Managed beans under the prefix: TopLink:Name="
> at org.eclipse.persistence.platform.server.jboss.JBossPlatform.serverSpecificRegisterMBean(JBossPlatform.java:147)
> at org.eclipse.persistence.platform.server.ServerPlatformBase.registerMBean(ServerPlatformBase.java:581)
> ------- this.serverSpecificRegisterMBean();
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.postConnectDatasource(DatabaseSessionImpl.java:857)
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.loginAndDetectDatasource(DatabaseSessionImpl.java:762)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.login(EntityManagerFactoryProvider.java:265)
> at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:731)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getAbstractSession(EntityManagerFactoryDelegate.java:205)
> - locked [0x00000000a90d1210] (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:305)
> {panel}
> After chekcing the eclipselink source code associated to line:
> {panel}
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> {panel}
> I found the following source code - which I could hardly believe would explain this deployment bottleneck:
> {panel}
> } else {
> // Only a single MBeanServer instance was found
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
> }
> {panel}
> In short, the first eclipselink entity manager cost of creation is a never ending task under wildfly because of how expensive the above log statement is:
> {panel}
> mBeanServer.getMBeanCount()
> {panel}
> I do not know how to interpret this.
> Is the problem that the API should cost ms and it literally takes several seconds to calculate - and the problem is the cost of the API under wildfly.
> Or is it that eclipselink should never have written such a log statement on the first place?
> To address the issue, I have hacked up my local:
> org.jipijapa.eclipselink.WildFlyServerPlatform
> In this class, I have override the getMeabServer API from the base class.
> I Have created a hacked constant:
> {panel}
> /**
> * During deployment, when the first entity manager is created, the
> * application deployment becomes extremelty slow due to the
> * MbeanServer.getbeanCount() access done by eclipselink. This access is on
> * top of all things done only for logging purposes. We completely kill the
> * call to the api.
> */
> private static final int MBEAN_SERVER_COUNT_DUMMY_VALUE = -999;
> {panel}
> And finally I added an overriden method:
> {panel}
> @Override
> public MBeanServer getMBeanServer() {
> /**
> * This function will attempt to get the MBeanServer via the
> * findMBeanServer spec call. 1) If the return list is null we attempt
> * to retrieve the PlatformMBeanServer (if it exists or is enabled in
> * this security context). 2) If the list of MBeanServers returned is
> * more than one we get the lowest indexed MBeanServer that does not on
> * a null default domain. 3) 333336: we need to wrap JMX calls in
> * doPrivileged blocks 4) fail-fast: if there are any issues with JMX -
> * continue - don't block the deploy()
> */
> // lazy initialize the MBeanServer reference
> if (null == mBeanServer) {
> List<MBeanServer> mBeanServerList = null;
> try {
> if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> try {
> mBeanServerList = (List<MBeanServer>) AccessController
> .doPrivileged(new PrivilegedExceptionAction() {
> @Override
> public List<MBeanServer> run() {
> return MBeanServerFactory.findMBeanServer(null);
> }
> });
> } catch (PrivilegedActionException pae) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from privileged MBeanServerFactory.findMBeanServer(null)");
> Context initialContext = null;
> try {
> initialContext = new InitialContext(); // the
> // context
> // should be
> // cached
> mBeanServer = (MBeanServer) initialContext.lookup(JMX_JNDI_RUNTIME_REGISTER);
> } catch (NamingException ne) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server", ne);
> }
> }
> } else {
> mBeanServerList = MBeanServerFactory.findMBeanServer(null);
> }
> // Attempt to get the first MBeanServer we find - usually there
> // is only one - when agentId == null we return a List of them
> if (null == mBeanServer && (null == mBeanServerList || mBeanServerList.isEmpty())) {
> // Unable to acquire a JMX specification List of MBeanServer
> // instances
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from MBeanServerFactory.findMBeanServer(null)");
> // Try alternate static method
> if (!PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> mBeanServer = ManagementFactory.getPlatformMBeanServer();
> if (null == mBeanServer) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server",
> "null returned from ManagementFactory.getPlatformMBeanServer()");
> } else {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { mBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } else {
> // Use the first MBeanServer by default - there may be
> // multiple domains each with their own MBeanServer
> mBeanServer = mBeanServerList.get(JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS);
> if (mBeanServerList.size() > 1) {
> // There are multiple MBeanServerInstances (usually only
> // JBoss)
> // 328006: WebLogic may also return multiple instances
> // (we need to register the one containing the com.bea
> // tree)
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_encountered_multiple_mbeanserver_instances",
> mBeanServerList.size(), JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS,
> mBeanServer);
> // IE: for JBoss we need to verify we are using the
> // correct MBean server of the two (default, null)
> // Check the domain if it is non-null - avoid using this
> // server
> int index = 0;
> for (MBeanServer anMBeanServer : mBeanServerList) {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { anMBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> anMBeanServer.getDefaultDomain(), index });
> if (null != anMBeanServer.getDefaultDomain()) {
> mBeanServer = anMBeanServer;
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_switching_to_alternate_mbeanserver", mBeanServer,
> index);
> }
> index++;
> }
> } else {
> // Only a single MBeanServer instance was found
> // mBeanServer.getMBeanCount() - This is very slow on
> // wildfly
> // we are disabling this statemnt
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print", new Object[] { mBeanServer,
> MBEAN_SERVER_COUNT_DUMMY_VALUE, mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } catch (Exception e) {
> // TODO: Warning required
> e.printStackTrace();
> }
> }
> return mBeanServer;
> }
> {panel}
> The above code looks extremelly complex to me just to get a MBeanserver in an application server.
> I find it hard to believe that this operation should ever have a code with this many lines of code behind it, but ok.
> As you can see in the code I am pasting the only trick I am putting in place to address the deployment time on my machine is to replace every single mebanserver.getMbeanCoundt() by a "dumb" reference to the constant: MBEAN_SERVER_COUNT_DUMMY_VALUE.
> Would it possible that the wildflt server platform be tuned to address this issue?
> I think it would be a good Idea if you revise the getMbeanServer api to be as simple as possible for JBOSS/Wildfly - the base eclipselink code make slittle since in my oppinion.
> But you will know best.
> It is also interesting that now when i run the test suite project from wildfly eclipselink actualy manages to be few ms faster than hibernate:
> {panel}
> Running org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.662 sec - in org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> This eclipselink test is actually now faster than
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.685 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Running org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.714 sec - in
> The hibernate test here loses to the eclipselink test above.
> org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Running org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.218 sec - in org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> {panel}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (WFLY-9408) Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
by Brian Stansberry (JIRA)
[ https://issues.jboss.org/browse/WFLY-9408?page=com.atlassian.jira.plugin.... ]
Brian Stansberry commented on WFLY-9408:
----------------------------------------
[~smarlow] Overriding eclipse link's JMXServerPlatformBase.getMBeanServer() is the right thing to do here. I don't believe the jsr77 module is involved.
The getMBeanCount() call may be more performant in WF 11, but regardless calling that just to do some trace logging is silly.
A similar thing to https://github.com/wildfly/wildfly/pull/10558 is at
https://github.com/wildfly/wildfly/compare/master...bstansberry:WFLY-9408
ManagementFactory.getPlatformMBeanServer() would get you the mbean server. But since the Eclipse link code we're replacing tried a call to MBeanServerFactory.findMBeanServer(null) first and since in a security manager environment those two call can require different permissions, to avoid breaking apps by needing different permissions I use MBeanServerFactory.findMBeanServer(null) as well. That returns a list so we have to iterate over the list to find the right mbean server. The Eclipse link code for that was written against old JBoss AS < 7 code, so it was looking for an mbean server whose getDefaultDomain() != null. That's wrong with AS 7 or later, so instead I look for getDefaultDomain() == null.
I just dropped the trace logging involving the mbean count.
I'll post a workaround in a second.
> Wildfly 10 - The cost of creating the first eclipselink EntityManager during deployment is extremelly high due to MBeanServer.getMbeanCount() cost
> --------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9408
> URL: https://issues.jboss.org/browse/WFLY-9408
> Project: WildFly
> Issue Type: Bug
> Components: JPA / Hibernate
> Affects Versions: 10.1.0.Final
> Reporter: Nuno Godinho de Matos
> Assignee: Scott Marlow
> Fix For: 11.0.0.Final
>
>
> I have been trying to reduce the deployment of a WAR application.
> One of the greate bottlenecks on the deployment is the cost of getting the first EntityManager instance of eclipselink.
> To try to reduce cost of startup I found myself forced to during @Startup fire a CDI event observed by an @Asynchronous ejb whose only task is to do a dummy entityManager.flush().
> The results I had for the execution time of this observer could go as high as 13 seconds.
> On top of that, I had already noticed while writting an arquillian system test for eclipselink on:
> https://issues.jboss.org/browse/WFLY-8954
> that the cost of starting up elcipselink under wildfly was much much higher than that of Hibernate and OpenJPA.
> With this introduction done let us go to the facts, and they are quite ridiculous.
> I have sampled the deployment of an application from begging to end with a sampling script that took a thread dump every second to analyse where the app is spending deployment time generically.
> Eventually, I reached the eclipselink deployment.
> And I had entries on the log such as:
> DatabaseEntityManagerStarter] - <- StartupDatabaseEntityManagerStarter.observeApplicationReadyLoadEntityManagerEvent {5948 ms} <EJB aync-ejb-thread-pool - 1>
> While sampling why this was happening I got more than 7 straight thread dump samples (more than 7 seconds) where the following stack trace was present:
> {panel}
> at java.security.AccessController.getContext(Unknown Source)
> at org.jboss.as.controller.SecurityActions.getCaller(SecurityActions.java:47)
> at org.jboss.as.controller.AbstractOperationContext.getCaller(AbstractOperationContext.java:1138)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:1306)
> at org.jboss.as.controller.OperationContextImpl.authorizeResource(OperationContextImpl.java:128)
> at org.jboss.as.controller.operations.global.ReadResourceDescriptionHandler$CheckResourceAccessHandler.execute(ReadResourceDescriptionHandler.java:429)
> at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:890)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:659)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1329)
> at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:400)
> at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:208)
> at org.jboss.as.jmx.model.ResourceAccessControlUtil.getResourceAccess(ResourceAccessControlUtil.java:85)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:51)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.doIterate(RootResourceIterator.java:61)
> at org.jboss.as.jmx.model.RootResourceIterator.iterate(RootResourceIterator.java:43)
> at org.jboss.as.jmx.model.ModelControllerMBeanHelper.getMBeanCount(ModelControllerMBeanHelper.java:125)
> at org.jboss.as.jmx.model.ModelControllerMBeanServerPlugin.getMBeanCount(ModelControllerMBeanServerPlugin.java:161)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.getMBeanCount(PluggableMBeanServerImpl.java:545)
> ----- Because of the mBeanServer.getMBeanCount():
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
>
>
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.serverSpecificRegisterMBean(JMXServerPlatformBase.java:297)
> ---- Will register Managed beans under the prefix: TopLink:Name="
> at org.eclipse.persistence.platform.server.jboss.JBossPlatform.serverSpecificRegisterMBean(JBossPlatform.java:147)
> at org.eclipse.persistence.platform.server.ServerPlatformBase.registerMBean(ServerPlatformBase.java:581)
> ------- this.serverSpecificRegisterMBean();
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.postConnectDatasource(DatabaseSessionImpl.java:857)
> at org.eclipse.persistence.internal.sessions.DatabaseSessionImpl.loginAndDetectDatasource(DatabaseSessionImpl.java:762)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryProvider.login(EntityManagerFactoryProvider.java:265)
> at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:731)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.getAbstractSession(EntityManagerFactoryDelegate.java:205)
> - locked [0x00000000a90d1210] (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate)
> at org.eclipse.persistence.internal.jpa.EntityManagerFactoryDelegate.createEntityManagerImpl(EntityManagerFactoryDelegate.java:305)
> {panel}
> After chekcing the eclipselink source code associated to line:
> {panel}
> at org.eclipse.persistence.platform.server.JMXServerPlatformBase.getMBeanServer(JMXServerPlatformBase.java:271)
> {panel}
> I found the following source code - which I could hardly believe would explain this deployment bottleneck:
> {panel}
> } else {
> // Only a single MBeanServer instance was found
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[]{mBeanServer, mBeanServer.getMBeanCount(), mBeanServer.getDefaultDomain(), 0});
> }
> {panel}
> In short, the first eclipselink entity manager cost of creation is a never ending task under wildfly because of how expensive the above log statement is:
> {panel}
> mBeanServer.getMBeanCount()
> {panel}
> I do not know how to interpret this.
> Is the problem that the API should cost ms and it literally takes several seconds to calculate - and the problem is the cost of the API under wildfly.
> Or is it that eclipselink should never have written such a log statement on the first place?
> To address the issue, I have hacked up my local:
> org.jipijapa.eclipselink.WildFlyServerPlatform
> In this class, I have override the getMeabServer API from the base class.
> I Have created a hacked constant:
> {panel}
> /**
> * During deployment, when the first entity manager is created, the
> * application deployment becomes extremelty slow due to the
> * MbeanServer.getbeanCount() access done by eclipselink. This access is on
> * top of all things done only for logging purposes. We completely kill the
> * call to the api.
> */
> private static final int MBEAN_SERVER_COUNT_DUMMY_VALUE = -999;
> {panel}
> And finally I added an overriden method:
> {panel}
> @Override
> public MBeanServer getMBeanServer() {
> /**
> * This function will attempt to get the MBeanServer via the
> * findMBeanServer spec call. 1) If the return list is null we attempt
> * to retrieve the PlatformMBeanServer (if it exists or is enabled in
> * this security context). 2) If the list of MBeanServers returned is
> * more than one we get the lowest indexed MBeanServer that does not on
> * a null default domain. 3) 333336: we need to wrap JMX calls in
> * doPrivileged blocks 4) fail-fast: if there are any issues with JMX -
> * continue - don't block the deploy()
> */
> // lazy initialize the MBeanServer reference
> if (null == mBeanServer) {
> List<MBeanServer> mBeanServerList = null;
> try {
> if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> try {
> mBeanServerList = (List<MBeanServer>) AccessController
> .doPrivileged(new PrivilegedExceptionAction() {
> @Override
> public List<MBeanServer> run() {
> return MBeanServerFactory.findMBeanServer(null);
> }
> });
> } catch (PrivilegedActionException pae) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from privileged MBeanServerFactory.findMBeanServer(null)");
> Context initialContext = null;
> try {
> initialContext = new InitialContext(); // the
> // context
> // should be
> // cached
> mBeanServer = (MBeanServer) initialContext.lookup(JMX_JNDI_RUNTIME_REGISTER);
> } catch (NamingException ne) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server", ne);
> }
> }
> } else {
> mBeanServerList = MBeanServerFactory.findMBeanServer(null);
> }
> // Attempt to get the first MBeanServer we find - usually there
> // is only one - when agentId == null we return a List of them
> if (null == mBeanServer && (null == mBeanServerList || mBeanServerList.isEmpty())) {
> // Unable to acquire a JMX specification List of MBeanServer
> // instances
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER, "failed_to_find_mbean_server",
> "null or empty List returned from MBeanServerFactory.findMBeanServer(null)");
> // Try alternate static method
> if (!PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
> mBeanServer = ManagementFactory.getPlatformMBeanServer();
> if (null == mBeanServer) {
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "failed_to_find_mbean_server",
> "null returned from ManagementFactory.getPlatformMBeanServer()");
> } else {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { mBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } else {
> // Use the first MBeanServer by default - there may be
> // multiple domains each with their own MBeanServer
> mBeanServer = mBeanServerList.get(JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS);
> if (mBeanServerList.size() > 1) {
> // There are multiple MBeanServerInstances (usually only
> // JBoss)
> // 328006: WebLogic may also return multiple instances
> // (we need to register the one containing the com.bea
> // tree)
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_encountered_multiple_mbeanserver_instances",
> mBeanServerList.size(), JMX_MBEANSERVER_INDEX_DEFAULT_FOR_MULTIPLE_SERVERS,
> mBeanServer);
> // IE: for JBoss we need to verify we are using the
> // correct MBean server of the two (default, null)
> // Check the domain if it is non-null - avoid using this
> // server
> int index = 0;
> for (MBeanServer anMBeanServer : mBeanServerList) {
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print",
> new Object[] { anMBeanServer, MBEAN_SERVER_COUNT_DUMMY_VALUE,
> anMBeanServer.getDefaultDomain(), index });
> if (null != anMBeanServer.getDefaultDomain()) {
> mBeanServer = anMBeanServer;
> getAbstractSession().log(SessionLog.WARNING, SessionLog.SERVER,
> "jmx_mbean_runtime_services_switching_to_alternate_mbeanserver", mBeanServer,
> index);
> }
> index++;
> }
> } else {
> // Only a single MBeanServer instance was found
> // mBeanServer.getMBeanCount() - This is very slow on
> // wildfly
> // we are disabling this statemnt
> getAbstractSession().log(SessionLog.FINER, SessionLog.SERVER,
> "jmx_mbean_runtime_services_registration_mbeanserver_print", new Object[] { mBeanServer,
> MBEAN_SERVER_COUNT_DUMMY_VALUE, mBeanServer.getDefaultDomain(), 0 });
> }
> }
> } catch (Exception e) {
> // TODO: Warning required
> e.printStackTrace();
> }
> }
> return mBeanServer;
> }
> {panel}
> The above code looks extremelly complex to me just to get a MBeanserver in an application server.
> I find it hard to believe that this operation should ever have a code with this many lines of code behind it, but ok.
> As you can see in the code I am pasting the only trick I am putting in place to address the deployment time on my machine is to replace every single mebanserver.getMbeanCoundt() by a "dumb" reference to the constant: MBEAN_SERVER_COUNT_DUMMY_VALUE.
> Would it possible that the wildflt server platform be tuned to address this issue?
> I think it would be a good Idea if you revise the getMbeanServer api to be as simple as possible for JBOSS/Wildfly - the base eclipselink code make slittle since in my oppinion.
> But you will know best.
> It is also interesting that now when i run the test suite project from wildfly eclipselink actualy manages to be few ms faster than hibernate:
> {panel}
> Running org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.662 sec - in org.jboss.as.test.compat.jpa.eclipselink.EclipseLinkSharedModuleProviderTestCase
> This eclipselink test is actually now faster than
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.354 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.PersistenceXmlHelperTest
> Running org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.685 sec - in org.jboss.as.test.compat.jpa.eclipselink.wildfly8954.WFLY8954BaseTest
> Running org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.714 sec - in
> The hibernate test here loses to the eclipselink test above.
> org.jboss.as.test.compat.jpa.hibernate.HibernateJarsInDeploymentTestCase
> Running org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.218 sec - in org.jboss.as.test.compat.jpa.openjpa.OpenJPASharedModuleProviderTestCase
> {panel}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (DROOLS-1749) Allow Build & Deploy to execute regardless of KieContainer currently executing
by Chad Poe (JIRA)
[ https://issues.jboss.org/browse/DROOLS-1749?page=com.atlassian.jira.plugi... ]
Chad Poe updated DROOLS-1749:
-----------------------------
Issue Type: Enhancement (was: Bug)
> Allow Build & Deploy to execute regardless of KieContainer currently executing
> ------------------------------------------------------------------------------
>
> Key: DROOLS-1749
> URL: https://issues.jboss.org/browse/DROOLS-1749
> Project: Drools
> Issue Type: Enhancement
> Reporter: Chad Poe
> Assignee: Edson Tirelli
>
> Currently, when clicking Build & Deploy the first time, an artifact is created and put in the maven repository, and a KieContainer (with the artifact GAV) is created and started on Kie Server. When doing active development on a SNAPSHOT of that GAV it would be nice if Build & Deploy could be used to create a new SNAPSHOT version in the repository which would allow for the KieScanner to pick up those changes if the container was configured to do so.
> Currently, when clicking Build & Deploy a second time, an error is returned indicating that a Container already exists with container id matching the GAV of the artifact.
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (DROOLS-1749) Allow Build & Deploy to execute regardless of KieContainer currently executing
by Chad Poe (JIRA)
[ https://issues.jboss.org/browse/DROOLS-1749?page=com.atlassian.jira.plugi... ]
Chad Poe updated DROOLS-1749:
-----------------------------
Description:
Currently, when clicking Build & Deploy the first time, an artifact is created and put in the maven repository, and a KieContainer (with the artifact GAV) is created and started on Kie Server. When doing active development on a SNAPSHOT of that GAV it would be nice if Build & Deploy could be used to create a new SNAPSHOT version in the repository which would allow for the KieScanner to pick up those changes if the container was configured to do so.
Currently, when clicking Build & Deploy a second time, an error is returned indicating that a Container already exists with container id matching the GAV of the artifact.
was:Currently, when clicking Build & Deploy the first time, an artifact is created and put in the maven repository, and a KieContainer (with the artifact GAV) is created and started on Kie Server. When doing active development on a SNAPSHOT of that GAV it would be nice if Build & Deploy could be used to create a new SNAPSHOT version in the repository which would allow for the KieScanner to pick up those changes if the container was configured to do so.
> Allow Build & Deploy to execute regardless of KieContainer currently executing
> ------------------------------------------------------------------------------
>
> Key: DROOLS-1749
> URL: https://issues.jboss.org/browse/DROOLS-1749
> Project: Drools
> Issue Type: Bug
> Reporter: Chad Poe
> Assignee: Edson Tirelli
>
> Currently, when clicking Build & Deploy the first time, an artifact is created and put in the maven repository, and a KieContainer (with the artifact GAV) is created and started on Kie Server. When doing active development on a SNAPSHOT of that GAV it would be nice if Build & Deploy could be used to create a new SNAPSHOT version in the repository which would allow for the KieScanner to pick up those changes if the container was configured to do so.
> Currently, when clicking Build & Deploy a second time, an error is returned indicating that a Container already exists with container id matching the GAV of the artifact.
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (DROOLS-1749) Allow Build & Deploy to execute regardless of KieContainer currently executing
by Chad Poe (JIRA)
Chad Poe created DROOLS-1749:
--------------------------------
Summary: Allow Build & Deploy to execute regardless of KieContainer currently executing
Key: DROOLS-1749
URL: https://issues.jboss.org/browse/DROOLS-1749
Project: Drools
Issue Type: Bug
Reporter: Chad Poe
Assignee: Edson Tirelli
Currently, when clicking Build & Deploy the first time, an artifact is created and put in the maven repository, and a KieContainer (with the artifact GAV) is created and started on Kie Server. When doing active development on a SNAPSHOT of that GAV it would be nice if Build & Deploy could be used to create a new SNAPSHOT version in the repository which would allow for the KieScanner to pick up those changes if the container was configured to do so.
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0
[JBoss JIRA] (LOGMGR-115) Writing the configuration file should handle properties with null values
by James Perkins (JIRA)
[ https://issues.jboss.org/browse/LOGMGR-115?page=com.atlassian.jira.plugin... ]
James Perkins closed LOGMGR-115.
--------------------------------
Resolution: Out of Date
This should be mostly addressed in LOGMGR-178
> Writing the configuration file should handle properties with null values
> ------------------------------------------------------------------------
>
> Key: LOGMGR-115
> URL: https://issues.jboss.org/browse/LOGMGR-115
> Project: JBoss Log Manager
> Issue Type: Enhancement
> Reporter: James Perkins
> Assignee: James Perkins
> Priority: Minor
> Fix For: 2.1.0.Alpha5
>
>
> Currently in the configuration API if a property is set to {{null}} an NPE occurs during the write and is swallowed. The idea was the {{removeProperty()}} should be used in the API. We should though check for {{null}} values and either not write the value or leave the value blank and have the reader for the configuration assume a value of 0 length is {{null}}.
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
8 years, 9 months
- 1
- 0