-
1. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
alesj Mar 18, 2009 5:50 AM (in response to chawax)Are you deploying outside deploy/ dir?
As 7min is just strangely too much, our Seam examples deploy pretty fast,
and they use all of the stuff you mentioned - JPA, EJB, ... -
2. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
jaikiran Mar 18, 2009 5:59 AM (in response to chawax)In addition to what Ales asked - how many EJBs does your application have? From the logs or some profiler are you able to find out where the time is being spent?
-
3. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
chawax Mar 18, 2009 6:06 AM (in response to chawax)Thanks for your response.
To deploy, I just copy my EAR file to deploy directory. Then I start JBoss from Eclipse via JBoss Tools, but I don't think it should be different.
I add these VM arguments (most of them added by JBoss Tools) on server startup :-Dprogram.name="JBossTools JBoss 5.0.1 Runtime" -Xms256m -Xmx512m -XX:MaxPermSize=256m -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Djava.endorsed.dirs="C:/t4-dev/jboss/jboss-5.0.1.GA/lib/endorsed" -Dhibernate.dialect=org.hibernate.dialect.HSQLDialect -Dhibernate.hbm2ddl.auto=update
Here are JBoss AS startup logs :10:51:11,431 INFO [ServerImpl] Starting JBoss (Microcontainer)... 10:51:11,446 INFO [ServerImpl] Release ID: JBoss [Morpheus] 5.0.1.GA (build: SVNTag=JBoss_5_0_1_GA date=200902232048) 10:51:11,446 INFO [ServerImpl] Bootstrap URL: null 10:51:11,446 INFO [ServerImpl] Home Dir: C:\t4-dev\jboss\jboss-5.0.1.GA 10:51:11,446 INFO [ServerImpl] Home URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/ 10:51:11,446 INFO [ServerImpl] Library URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/lib/ 10:51:11,446 INFO [ServerImpl] Patch URL: null 10:51:11,446 INFO [ServerImpl] Common Base URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/common/ 10:51:11,446 INFO [ServerImpl] Common Library URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/common/lib/ 10:51:11,446 INFO [ServerImpl] Server Name: default 10:51:11,446 INFO [ServerImpl] Server Base Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server 10:51:11,446 INFO [ServerImpl] Server Base URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/ 10:51:11,446 INFO [ServerImpl] Server Config URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/conf/ 10:51:11,446 INFO [ServerImpl] Server Home Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default 10:51:11,446 INFO [ServerImpl] Server Home URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/ 10:51:11,446 INFO [ServerImpl] Server Data Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default\data 10:51:11,446 INFO [ServerImpl] Server Library URL: file:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/lib/ 10:51:11,446 INFO [ServerImpl] Server Log Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default\log 10:51:11,446 INFO [ServerImpl] Server Native Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default\tmp\native 10:51:11,446 INFO [ServerImpl] Server Temp Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default\tmp 10:51:11,446 INFO [ServerImpl] Server Temp Deploy Dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default\tmp\deploy 10:51:12,506 INFO [ServerImpl] Starting Microcontainer, bootstrapURL=file:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/conf/bootstrap.xml 10:51:13,394 INFO [VFSCacheFactory] Initializing VFSCache [org.jboss.virtual.plugins.cache.CombinedVFSCache] 10:51:13,394 INFO [VFSCacheFactory] Using VFSCache [CombinedVFSCache[real-cache: null]] 10:51:13,846 INFO [CopyMechanism] VFS temp dir: C:\t4-dev\jboss\jboss-5.0.1.GA\server\default\tmp 10:51:13,846 INFO [ZipEntryContext] VFS force nested jars copy-mode is enabled. 10:51:15,873 INFO [ServerInfo] Java version: 1.6.0_12,Sun Microsystems Inc. 10:51:15,873 INFO [ServerInfo] Java Runtime: Java(TM) SE Runtime Environment (build 1.6.0_12-b04) 10:51:15,873 INFO [ServerInfo] Java VM: Java HotSpot(TM) Client VM 11.2-b01,Sun Microsystems Inc. 10:51:15,873 INFO [ServerInfo] OS-System: Windows XP 5.1,x86 10:51:15,966 INFO [JMXKernel] Legacy JMX core initialized 10:51:19,161 INFO [ProfileServiceImpl] Loading profile: default from: org.jboss.system.server.profileservice.repository.SerializableDeploymentRepository@a083f2(root=C:\t4-dev\jboss\jboss-5.0.1.GA\server, key=org.jboss.profileservice.spi.ProfileKey@143b82c3[domain=default,server=default,name=default]) 10:51:19,161 INFO [ProfileImpl] Using repository:org.jboss.system.server.profileservice.repository.SerializableDeploymentRepository@a083f2(root=C:\t4-dev\jboss\jboss-5.0.1.GA\server, key=org.jboss.profileservice.spi.ProfileKey@143b82c3[domain=default,server=default,name=default]) 10:51:19,161 INFO [ProfileServiceImpl] Loaded profile: ProfileImpl@c22978{key=org.jboss.profileservice.spi.ProfileKey@143b82c3[domain=default,server=default,name=default]} 10:51:22,263 INFO [WebService] Using RMI server codebase: http://ws-r1-be03:8083/ 10:51:34,311 INFO [NativeServerConfig] JBoss Web Services - Stack Native Core 10:51:34,311 INFO [NativeServerConfig] 3.0.5.GA
And here are the first logs I have when starting the application :10:52:00,121 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@9796844{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/jboss-seam-2.1.1.GA.jar/} 10:52:00,121 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@9796844{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/jboss-seam-2.1.1.GA.jar/} 10:52:00,121 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@19724733{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-core-all-1.0-SNAPSHOT.jar/} 10:52:00,121 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@19724733{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-core-all-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@19724733{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-core-all-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@19724733{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-core-all-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@29364986{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-ihm-self-ejb-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@29364986{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-ihm-self-ejb-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@29364986{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-ihm-self-ejb-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@29364986{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-ihm-self-ejb-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@18750094{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-commons-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@18750094{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-commons-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@18750094{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-commons-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@18750094{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-commons-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@23175637{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-gt-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@23175637{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-gt-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@23175637{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-gt-core-1.0-SNAPSHOT.jar/} 10:52:00,137 INFO [Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@23175637{vfszip:/C:/t4-dev/jboss/jboss-5.0.1.GA/server/default/deploy/t4-ihm-self-ear-1.0-SNAPSHOT.ear/t4-module-gt-core-1.0-SNAPSHOT.jar/}
I don't know how I could find what causes these low performance :( -
4. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
chawax Mar 18, 2009 6:29 AM (in response to chawax)"jaikiran" wrote:
In addition to what Ales asked - how many EJBs does your application have?
For the moment we have 365 EJB3 components, but we will have a lot more in the future."jaikiran" wrote:
From the logs or some profiler are you able to find out where the time is being spent?
From the logs, I can see these phases in server / application startup :
1 - AS startup : about 45 seconds
2 - Application deployment : about 3 minutes
I mean messages like this one :10:55:15,991 INFO [JBossASKernel] installing bean: jboss.j2ee:ear=t4-ihm-self-ear-1.0-SNAPSHOT.ear,jar=t4-module-gt-core-1.0-SNAPSHOT.jar,name=EmployeeServiceBean,service=EJB3 10:55:15,991 INFO [JBossASKernel] with dependencies: 10:55:15,991 INFO [JBossASKernel] and demands: 10:55:16,006 INFO [JBossASKernel] jboss.ejb:service=EJBTimerService 10:55:16,006 INFO [JBossASKernel] and supplies: 10:55:16,006 INFO [JBossASKernel] Class:t4.module.commons.employee.EmployeeServiceLocal 10:55:16,006 INFO [JBossASKernel] Added bean(jboss.j2ee:ear=t4-ihm-self-ear-1.0-SNAPSHOT.ear,jar=t4-module-gt-core-1.0-SNAPSHOT.jar,name=EmployeeServiceBean,service=EJB3) to KernelDeployment of: t4-module-gt-core-1.0-SNAPSHOT.jar
3 - Hibernate / JPA startup and schema update : about 10 seconds
4 - EJB3 startup : about 1 minute and 30 seconds10:56:13,441 INFO [SessionSpecContainer] Starting jboss.j2ee:ear=t4-ihm-self-ear-1.0-SNAPSHOT.ear,jar=t4-ihm-self-ejb-1.0-SNAPSHOT.jar,name=DictionaryFacadeServiceBean,service=EJB3 10:56:13,441 INFO [EJBContainer] STARTED EJB: t4.core.utils.dictionary.facade.DictionaryFacadeServiceBean ejbName: DictionaryFacadeServiceBean 10:56:13,441 INFO [JndiSessionRegistrarBase] Binding the following Entries in Global JNDI:
5 - Seam startup : about 30 seconds
So I think most of the time is consumed with application deployment. -
5. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
jaikiran Mar 18, 2009 6:51 AM (in response to chawax)"chawax" wrote:
For the moment we have 365 EJB3 components, but we will have a lot more in the future.
I have seen some more users mentioning that the startup time isn't good (as compared to 4.x) when the number of EJBs in their application is many.
Thank you for breaking down the timings to explain what's happening. Any chance of making this application available to test out what's going on? If not, i'll try and come up with a sample application which tries to reproduce this. -
6. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
chawax Mar 18, 2009 7:12 AM (in response to chawax)I am sorry I can't make the application available since it is confidential code :(
By the way, are there recommandations about memory configuration for JBoss ? If I don't affect enough memory to JBoss, is there a risk that garbage collector never stops working, causing performance problems ? -
7. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
dimitris Mar 18, 2009 9:17 AM (in response to chawax)Try doubling the heap size to see if it makes any difference:
-Xmx1024m -
8. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
chawax Mar 18, 2009 9:49 AM (in response to chawax)I just tried and it changed nothing, still about 7 minutes to startup.
-
9. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
peterj Mar 18, 2009 1:05 PM (in response to chawax)Regarding the garbage collection, which collector are you using? If you do not specify a collector, your application (JBoss AS + all deployed apps) stops while collection happens - so it will complete, it has to before the app can continue. If you use the CMS collector, the collection thread runs along with your app, so with CMS you could find yourself in continuous collection mode.
See my presentation for details: http://www.cecmg.de/doc/tagung_2007/agenda07/24-mai/2b3-peter-johnson/index.html -
10. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
chawax Mar 20, 2009 11:56 AM (in response to chawax)I improved a lot startup performance. My JBOSS_HOME pointed to my old JBoss 4.2.3 installation. I changed it to point to JBoss 5.0.1 directory, it now takes 4 minutes and 45 seconds to startup compared to 7 minutes before I changed this. Anyway I think it's still too long, I really worry about how long it will be when my application will be complete with thousands of EJB3 session beans :(
-
11. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
jaikiran Mar 20, 2009 12:26 PM (in response to chawax)"chawax" wrote:
I improved a lot startup performance. My JBOSS_HOME pointed to my old JBoss 4.2.3 installation. I changed it to point to JBoss 5.0.1 directory, it now takes 4 minutes and 45 seconds to startup compared to 7 minutes before I changed this.
I am not sure what the problem was. But you earlier logs did show that you were using 5.0.1 GA,/C:/t4-dev/jboss/jboss-5.0.1.GA/
so i don't think the JBOSS_HOME was messing the startup time. -
12. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
chawax Mar 20, 2009 12:49 PM (in response to chawax)I agree it is very strange, but this is what I noted ;) And that's the only thing I changed from wednesday, I changed nothing in the EAR !
-
13. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
tonylmai Mar 22, 2009 10:27 PM (in response to chawax)I too have experienced severe performance with JBoss 5.1.0Beta1. Our application also has several hundred EJB beans.
A simple login page using Seam 2.1.1 used to take a few seconds (in 4.2.1GA) now takes minutes. I have not collected sufficient statistics like chawax but it was quite obvious that the AS takes a long time to load EJB related beans (session/entity).
The performance will definitely hinder our upgrade as QA will not even entertain testing the ported app.
As soon as the porting is relatively stable, I will put the app under a profiler. Will post if find anything relevant.
Thanks
-tony -
14. Re: Low performance with JBoss AS 5.0.1 compared with 4.2.3
jaikiran Mar 23, 2009 3:28 AM (in response to chawax)"tonylmai" wrote:
A simple login page using Seam 2.1.1 used to take a few seconds (in 4.2.1GA) now takes minutes.
Hmmm, so its not pure EJB3. I remember there was extensive testing/discussion in the forums about Seam related web application performance in AS 5.x and from what i know they had been fixed.
"tonylmai" wrote:
As soon as the porting is relatively stable, I will put the app under a profiler. Will post if find anything relevant.
Thanks, we would like to have that info. I'm also trying to get it reproduced locally, but do post your findings too. And please create a separate thread when you post those findings so that the discussions are not mixed up :)