-
15. Re: JBAS-6104; slow Seam deployments
"pete.muir@jboss.org" wrote:
It does get called a lot from javax.faces.application.ViewHandler.renderView() - there are 524 invocations of org.jboss.virtual.plugins.vfs.VirtualFileURLConnection.getInputStream().
Shane is talking about runtime performance (when rendering a view) NOT about deployment :-)
AFAIK ViewHandler can be replaced/configured, right?
Should I/we implement one that would work on VFS directly? -
16. Re: JBAS-6104; slow Seam deployments
AFAIK ViewHandler can be replaced/configured, right?
Should I/we implement one that would work on VFS directly?
I did some poking, and ViewHandler isn't actually responsible for loading any files, but rather other classes which load files.
Shane, I guess the calls getInputStream come from Class::getResourceAsStream or ClassLoader::getResourceAsStream? And if so, do we have a particular place that loads a lot of these? -
17. Re: JBAS-6104; slow Seam deployments
Deployment seems to be fine now, as Pete said. The issue is when you hit a Seam application for the first time, a whole bunch of stuff needs to be initialised. I did some deeper profiling, and here's a sample of some of the places where the most calls are being made to VirtualFileURLConnection.getInputStream:
25.2% - 90,069ms - 335 inv. com.sun.facelets.util.Classpath.searchFromURL
10.0% - 35,665ms - 11 inv. com.sun.facelets.compiler.TagLibraryConfig.create
1.0% - 3,461ms - 1 inv. org.ajax4jsf.resource.JarResource.getResourceAsStream (called from TemplateCSSRendered.getTemplate)
13.1% - 46,692ms - 11 inv. org.jboss.seam.deployment.SeamDeploymentProperties.addPropertiesFromResourceBundle (called indirectly from HotDeploymentStrategy.getDeploymentHandlers)
12.9% - 46,115ms - 11 inv. org.jboss.seam.deployment.SeamDeploymentProperties.addPropertiesFromResourceBundle (called indirectly from DeploymentStrategy.getDeploymentHandlers - initialized by WarRootDeploymentStrategy)
12.7% - 45,284ms - 11 inv. org.jboss.seam.deployment.SeamDeploymentProperties.addPropertiesFromResourceBundle (called indirectly from DeploymentStrategy.getScanner)
12.6% - 45,042ms - 11 inv. org.jboss.seam.deployment.SeamDeploymentProperties.addPropertiesFromResourceBundle (called indirectly from DeploymentStrategy.getScanner, initialized by WarRootDeploymentStrategy.scan)
The percentages are the fraction of total CPU time taken during application initialization for the first request hitting a Seam application, in this case seam-booking. Looking at where most of the calls are being made from, we can possibly do some optimization in SeamDeploymentProperties (I'll start investigating this next) however even with some optimizations here the fact remains that vfs still seems very under-performant. -
18. Re: JBAS-6104; slow Seam deployments
The question here is what can we move directly on VFS?
Since if we can get a hold of existing VFS deployment root, things are gonna be fast.
e.g. ServletContext --> VFSDeploymentUnit --> VFS root
But like I already said, if VFS always goes via URL --> URLConnection --> VFS, then it's gonna be slow as it has no memory of previously exploded jars/entries.
Keeping this info around is a potential memory leak, as you have no handle/mechanism to remove it, except some SoftRef handling. -
19. Re: JBAS-6104; slow Seam deployments
I think it would also be an idea to get an idea of how long getting a URL in JBoss 4 takes for comparison - Shane, could you run those numbers :-)
-
20. Re: JBAS-6104; slow Seam deployments
"pete.muir@jboss.org" wrote:
I think Shane and you/Marko got your wires crossed, and his latter comments are regarding runtime not deployment performance.
From:It does get called a lot from javax.faces.application.ViewHandler.renderView() - there are 524 invocations of org.jboss.virtual.plugins.vfs.VirtualFileURLConnection.getInputStream().
Shane is talking about runtime performance (when rendering a view) NOT about deployment :-)
Yeah, but no harm done - we need to fix both cases anyway. And I'm glad to see the culprit is integration, and not VFS code itself :)
- marko -
21. Re: JBAS-6104; slow Seam deployments
"pete.muir@jboss.org" wrote:
I think it would also be an idea to get an idea of how long getting a URL in JBoss 4 takes for comparison
This doesn't make sense, as it's completely different resources handling strategy.
JBoss4 (more of a guess, since I didn't do it and never really looked how it's done):
It copies every jar into temp. Same with nested.
But when it references those jars, it returns URLs with the temp paths.
JBoss5:
Impl details are VFS based:
- deployment
- metadata
- classloading
- ...
All these pieces work on the same VFS roots.
Once something is unpacked/read-in-memory, the references are kept internally,
hence the same instances will work on the same (temp) files / memory.
But the returned URLs are not exposing impl details == no pointing to temp files.
I'll open a MC dev discussion on this URL+VFS issue. -
22. Re: JBAS-6104; slow Seam deployments
This doesn't make sense, as it's completely different resources handling strategy.
Sure, it doesn't make sense to *you*, but this is exactly the way any end user will see it - "Why does JBoss 5 take ~4s to open an inputstream!!!!????" ;-) It would be naive to assume that applications don't open files (let alone third party frameworks), and it's not viable to tell them "use VFS", not least because it's not a standard... Do I make sense? Or am I missing an important piece of the puzzle? -
23. Re: JBAS-6104; slow Seam deployments
No problem, here's a comparison (running in JBossAS 4.2.3):
11.7% - 2,649ms - 44 inv. org.jboss.seam.deployment.SeamDeploymentProperties.addPropertiesFromResourceBundle
Averaging out the CPU time per call we get about 60.2ms. Compare this to JBossAS 5 which is > 4000ms, and it's a significant difference. -
24. Re: JBAS-6104; slow Seam deployments
"pete.muir@jboss.org" wrote:
Sure, it doesn't make sense to *you*, but this is exactly the way any end user will see it - "Why does JBoss 5 take ~4s to open an inputstream!!!!????" ;-) It would be naive to assume that applications don't open files (let alone third party frameworks), and it's not viable to tell them "use VFS", not least because it's not a standard... Do I make sense? Or am I missing an important piece of the puzzle?
Missing a puzzle --> This is dev forum == no users. ;-)
Shane's results won't surprise me, since we know what they'll show:
- direct temp URL vs. URL->URLConnection->VFS
We're here to find a solution, not performance numbers. ;-)
I've started a MC dev post here:
- http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4184788#4184788
As the problem is more general than Seam's usage.
Please post any suggestions there, and we'll come back here to try them. :-) -
25. Re: JBAS-6104; slow Seam deployments
So I'm still seeing a problem using AS trunk and Seam trunk (both as of yesterday).
Steps to reproduce:
1) Run seam-booking and book a hotel.
2) Undeploy seam-booking. You will see this stack trace:08:25:16,795 WARN [Component] Exception calling stateful session bean default @ Remove method: hotelSearch org.jboss.ejb3.common.registrar.spi.NotBoundException: Requested value bound at name "jboss.j2ee:ear=jboss-seam-booking.ear,jar=jboss-seam-booking.jar,name=Hote lSearchingAction,service=EJB3" is not bound. at org.jboss.ejb3.common.registrar.plugin.mc.Ejb3McRegistrar.lookup(Ejb3 McRegistrar.java:157) at org.jboss.ejb3.common.registrar.plugin.mc.Ejb3McRegistrar.lookup(Ejb3 McRegistrar.java:133) at org.jboss.ejb3.proxy.handler.session.SessionProxyInvocationHandlerBas e.getContainerLocally(SessionProxyInvocationHandlerBase.java:80) at org.jboss.ejb3.proxy.handler.session.stateful.StatefulLocalProxyInvoc ationHandler.getContainer(StatefulLocalProxyInvocationHandler.java:87) at org.jboss.ejb3.proxy.handler.session.SessionSpecProxyInvocationHandle rBase.invoke(SessionSpecProxyInvocationHandlerBase.java:111) at $Proxy247.destroy(Unknown Source) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.seam.util.Reflections.invoke(Reflections.java:22) at org.jboss.seam.intercept.RootInvocationContext.proceed(RootInvocation Context.java:31) at org.jboss.seam.intercept.ClientSideInterceptor$1.proceed(ClientSideIn terceptor.java:76) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:56) at org.jboss.seam.security.SecurityInterceptor.aroundInvoke(SecurityInte rceptor.java:157) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:68) at org.jboss.seam.ejb.RemoveInterceptor.aroundInvoke(RemoveInterceptor.j ava:43) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:68) at org.jboss.seam.core.SynchronizationInterceptor.aroundInvoke(Synchroni zationInterceptor.java:32) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:68) at org.jboss.seam.intercept.RootInterceptor.invoke(RootInterceptor.java: 107) at org.jboss.seam.intercept.ClientSideInterceptor.invoke(ClientSideInter ceptor.java:54) at org.javassist.tmp.java.lang.Object_$$_javassist_4.destroy(Object_$$_j avassist_4.java) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.seam.util.Reflections.invoke(Reflections.java:22) at org.jboss.seam.util.Reflections.invokeAndWrap(Reflections.java:138) at org.jboss.seam.Component.callComponentMethod(Component.java:2210) at org.jboss.seam.Component.callDefaultRemoveMethod(Component.java:2115) at org.jboss.seam.Component.destroy(Component.java:1445) at org.jboss.seam.contexts.Contexts.destroy(Contexts.java:251) at org.jboss.seam.contexts.Lifecycle.endSession(Lifecycle.java:249) at org.jboss.seam.contexts.ServletLifecycle.endSession(ServletLifecycle. java:146) at org.jboss.seam.servlet.SeamListener.sessionDestroyed(SeamListener.jav a:49) at org.apache.catalina.session.StandardSession.expire(StandardSession.ja va:702) at org.apache.catalina.session.StandardSession.expire(StandardSession.ja va:660) at org.apache.catalina.session.StandardManager.stop(StandardManager.java :675) at org.apache.catalina.core.StandardContext.stop(StandardContext.java:45 88) at org.apache.catalina.core.ContainerBase.destroy(ContainerBase.java:117 5) at org.apache.catalina.core.StandardContext.destroy(StandardContext.java :4682) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.j ava:297) at org.jboss.mx.server.RawDynamicInvoker.invoke(RawDynamicInvoker.java:1 64) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:668) at org.jboss.web.tomcat.service.deployers.TomcatDeployment.performUndepl oyInternal(TomcatDeployment.java:677) at org.jboss.web.tomcat.service.deployers.TomcatDeployment.performUndepl oy(TomcatDeployment.java:650) at org.jboss.web.deployers.AbstractWarDeployment.stop(AbstractWarDeploym ent.java:480) at org.jboss.web.deployers.WebModule.stopModule(WebModule.java:134) at org.jboss.web.deployers.WebModule.stop(WebModule.java:101) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatch er.java:157) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:96) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker. java:264) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:668) at org.jboss.system.microcontainer.ServiceProxy.invoke(ServiceProxy.java :206) at $Proxy35.stop(Unknown Source) at org.jboss.system.microcontainer.StartStopLifecycleAction.uninstallAct ion(StartStopLifecycleAction.java:56) at org.jboss.system.microcontainer.StartStopLifecycleAction.uninstallAct ion(StartStopLifecycleAction.java:37) at org.jboss.dependency.plugins.action.SimpleControllerContextAction.sim pleUninstallAction(SimpleControllerContextAction.java:79) at org.jboss.dependency.plugins.action.AccessControllerContextAction.uni nstall(AccessControllerContextAction.java:131) at org.jboss.dependency.plugins.AbstractControllerContextActions.uninsta ll(AbstractControllerContextActions.java:58) at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(Abst ractControllerContext.java:354) at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractCon troller.java:1631) at org.jboss.dependency.plugins.AbstractController.uninstallContext(Abst ractController.java:1242) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:827) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:553) at org.jboss.system.ServiceController.doChange(ServiceController.java:67 2) at org.jboss.system.ServiceController.stop(ServiceController.java:494) at org.jboss.system.deployers.ServiceDeployer.stop(ServiceDeployer.java: 153) at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.j ava:133) at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.j ava:45) at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.i nternalUndeploy(AbstractSimpleRealDeployer.java:69) at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.undeplo y(AbstractRealDeployer.java:112) at org.jboss.deployers.plugins.deployers.DeployerWrapper.undeploy(Deploy erWrapper.java:196) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUndeploy(Deploy ersImpl.java:1440) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParent Last(DeployersImpl.java:1347) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParent Last(DeployersImpl.java:1340) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParent Last(DeployersImpl.java:1327) at org.jboss.deployers.plugins.deployers.DeployersImpl.uninstall(Deploye rsImpl.java:1302) at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(Abst ractControllerContext.java:354) at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractCon troller.java:1631) at org.jboss.dependency.plugins.AbstractController.uninstallContext(Abst ractController.java:1242) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:827) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:553) at org.jboss.deployers.plugins.deployers.DeployersImpl.process(Deployers Impl.java:665) at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeploye rImpl.java:541) at org.jboss.system.server.profileservice.hotdeploy.HDScanner.scan(HDSca nner.java:290) at org.jboss.system.server.profileservice.hotdeploy.HDScanner.run(HDScan ner.java:221) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:41 7) at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java :280) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. access$101(ScheduledThreadPoolExecutor.java:65) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. runPeriodic(ScheduledThreadPoolExecutor.java:142) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. run(ScheduledThreadPoolExecutor.java:166) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec utor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor .java:675) at java.lang.Thread.run(Thread.java:595) 08:25:16,874 WARN [Component] Exception calling stateful session bean default @ Remove method: bookingList org.jboss.ejb3.common.registrar.spi.NotBoundException: Requested value bound at name "jboss.j2ee:ear=jboss-seam-booking.ear,jar=jboss-seam-booking.jar,name=Book ingListAction,service=EJB3" is not bound. at org.jboss.ejb3.common.registrar.plugin.mc.Ejb3McRegistrar.lookup(Ejb3 McRegistrar.java:157) at org.jboss.ejb3.common.registrar.plugin.mc.Ejb3McRegistrar.lookup(Ejb3 McRegistrar.java:133) at org.jboss.ejb3.proxy.handler.session.SessionProxyInvocationHandlerBas e.getContainerLocally(SessionProxyInvocationHandlerBase.java:80) at org.jboss.ejb3.proxy.handler.session.stateful.StatefulLocalProxyInvoc ationHandler.getContainer(StatefulLocalProxyInvocationHandler.java:87) at org.jboss.ejb3.proxy.handler.session.SessionSpecProxyInvocationHandle rBase.invoke(SessionSpecProxyInvocationHandlerBase.java:111) at $Proxy248.destroy(Unknown Source) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.seam.util.Reflections.invoke(Reflections.java:22) at org.jboss.seam.intercept.RootInvocationContext.proceed(RootInvocation Context.java:31) at org.jboss.seam.intercept.ClientSideInterceptor$1.proceed(ClientSideIn terceptor.java:76) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:56) at org.jboss.seam.security.SecurityInterceptor.aroundInvoke(SecurityInte rceptor.java:157) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:68) at org.jboss.seam.ejb.RemoveInterceptor.aroundInvoke(RemoveInterceptor.j ava:43) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:68) at org.jboss.seam.core.SynchronizationInterceptor.aroundInvoke(Synchroni zationInterceptor.java:32) at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocation Context.java:68) at org.jboss.seam.intercept.RootInterceptor.invoke(RootInterceptor.java: 107) at org.jboss.seam.intercept.ClientSideInterceptor.invoke(ClientSideInter ceptor.java:54) at org.javassist.tmp.java.lang.Object_$$_javassist_5.destroy(Object_$$_j avassist_5.java) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.seam.util.Reflections.invoke(Reflections.java:22) at org.jboss.seam.util.Reflections.invokeAndWrap(Reflections.java:138) at org.jboss.seam.Component.callComponentMethod(Component.java:2210) at org.jboss.seam.Component.callDefaultRemoveMethod(Component.java:2115) at org.jboss.seam.Component.destroy(Component.java:1445) at org.jboss.seam.contexts.Contexts.destroy(Contexts.java:251) at org.jboss.seam.contexts.Lifecycle.endSession(Lifecycle.java:249) at org.jboss.seam.contexts.ServletLifecycle.endSession(ServletLifecycle. java:146) at org.jboss.seam.servlet.SeamListener.sessionDestroyed(SeamListener.jav a:49) at org.apache.catalina.session.StandardSession.expire(StandardSession.ja va:702) at org.apache.catalina.session.StandardSession.expire(StandardSession.ja va:660) at org.apache.catalina.session.StandardManager.stop(StandardManager.java :675) at org.apache.catalina.core.StandardContext.stop(StandardContext.java:45 88) at org.apache.catalina.core.ContainerBase.destroy(ContainerBase.java:117 5) at org.apache.catalina.core.StandardContext.destroy(StandardContext.java :4682) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.j ava:297) at org.jboss.mx.server.RawDynamicInvoker.invoke(RawDynamicInvoker.java:1 64) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:668) at org.jboss.web.tomcat.service.deployers.TomcatDeployment.performUndepl oyInternal(TomcatDeployment.java:677) at org.jboss.web.tomcat.service.deployers.TomcatDeployment.performUndepl oy(TomcatDeployment.java:650) at org.jboss.web.deployers.AbstractWarDeployment.stop(AbstractWarDeploym ent.java:480) at org.jboss.web.deployers.WebModule.stopModule(WebModule.java:134) at org.jboss.web.deployers.WebModule.stop(WebModule.java:101) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl. java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces sorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:585) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatch er.java:157) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:96) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker. java:264) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:668) at org.jboss.system.microcontainer.ServiceProxy.invoke(ServiceProxy.java :206) at $Proxy35.stop(Unknown Source) at org.jboss.system.microcontainer.StartStopLifecycleAction.uninstallAct ion(StartStopLifecycleAction.java:56) at org.jboss.system.microcontainer.StartStopLifecycleAction.uninstallAct ion(StartStopLifecycleAction.java:37) at org.jboss.dependency.plugins.action.SimpleControllerContextAction.sim pleUninstallAction(SimpleControllerContextAction.java:79) at org.jboss.dependency.plugins.action.AccessControllerContextAction.uni nstall(AccessControllerContextAction.java:131) at org.jboss.dependency.plugins.AbstractControllerContextActions.uninsta ll(AbstractControllerContextActions.java:58) at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(Abst ractControllerContext.java:354) at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractCon troller.java:1631) at org.jboss.dependency.plugins.AbstractController.uninstallContext(Abst ractController.java:1242) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:827) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:553) at org.jboss.system.ServiceController.doChange(ServiceController.java:67 2) at org.jboss.system.ServiceController.stop(ServiceController.java:494) at org.jboss.system.deployers.ServiceDeployer.stop(ServiceDeployer.java: 153) at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.j ava:133) at org.jboss.system.deployers.ServiceDeployer.undeploy(ServiceDeployer.j ava:45) at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.i nternalUndeploy(AbstractSimpleRealDeployer.java:69) at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.undeplo y(AbstractRealDeployer.java:112) at org.jboss.deployers.plugins.deployers.DeployerWrapper.undeploy(Deploy erWrapper.java:196) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUndeploy(Deploy ersImpl.java:1440) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParent Last(DeployersImpl.java:1347) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParent Last(DeployersImpl.java:1340) at org.jboss.deployers.plugins.deployers.DeployersImpl.doUninstallParent Last(DeployersImpl.java:1327) at org.jboss.deployers.plugins.deployers.DeployersImpl.uninstall(Deploye rsImpl.java:1302) at org.jboss.dependency.plugins.AbstractControllerContext.uninstall(Abst ractControllerContext.java:354) at org.jboss.dependency.plugins.AbstractController.uninstall(AbstractCon troller.java:1631) at org.jboss.dependency.plugins.AbstractController.uninstallContext(Abst ractController.java:1242) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:827) at org.jboss.dependency.plugins.AbstractController.change(AbstractContro ller.java:553) at org.jboss.deployers.plugins.deployers.DeployersImpl.process(Deployers Impl.java:665) at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeploye rImpl.java:541) at org.jboss.system.server.profileservice.hotdeploy.HDScanner.scan(HDSca nner.java:290) at org.jboss.system.server.profileservice.hotdeploy.HDScanner.run(HDScan ner.java:221) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:41 7) at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java :280) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. access$101(ScheduledThreadPoolExecutor.java:65) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. runPeriodic(ScheduledThreadPoolExecutor.java:142) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. run(ScheduledThreadPoolExecutor.java:166) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec utor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor .java:675) at java.lang.Thread.run(Thread.java:595) 08:25:16,998 INFO [SessionSpecContainer] Stopping jboss.j2ee:ear=jboss-seam-boo king.ear,jar=jboss-seam.jar,name=EjbSynchronizations,service=EJB3 08:25:16,999 INFO [EJBContainer] STOPPED EJB: org.jboss.seam.transaction.EjbSyn chronizations ejbName: EjbSynchronizations 08:25:17,045 INFO [SessionSpecContainer] Stopping jboss.j2ee:ear=jboss-seam-boo king.ear,jar=jboss-seam.jar,name=TimerServiceDispatcher,service=EJB3 08:25:17,047 INFO [EJBContainer] STOPPED EJB: org.jboss.seam.async.TimerService Dispatcher ejbName: TimerServiceDispatcher
3) Deploy seam-numberguess
It takes about 30 seconds before you start to see any message in the console, but if you look at the server.log you can see pauses of about 10-14 seconds between debug messages:2008-10-28 08:29:04,545 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] (Thread-12) [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass 2008-10-28 08:29:14,545 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] (Thread-12) Periodic recovery - second pass <Tue, 28 Oct 2008 08:29:14>
2008-10-28 08:29:14,545 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] (Thread-12) [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass 2008-10-28 08:29:28,578 DEBUG [org.jboss.metadata.process.chain.ejb.jboss.JBossMetaDataProcessorChain] (HDScanner) Added Processor
You finally see that the TomcatDeployment says the ctxPath is ready, but the deployment is not done. If you try to hit the page at 8:29:30, you will get a 404. It actually takes another 1 minute and 19 seconds before it finishes the deployment.08:29:30,017 INFO [TomcatDeployment] deploy, ctxPath=/seam-numberguess, vfsUrl= jboss-seam-numberguess.ear/jboss-seam-numberguess.war 08:29:30,339 INFO [ServletContextListener] Welcome to Seam 2.1.1-SNAPSHOT 08:30:49,756 INFO [Initialization] Namespace: http://jboss.com/products/seam/in ternational, package: org.jboss.seam.international, prefix: org.jboss.seam.inter national
Altogether, deployment of seam-numberguess took about 2 minutes with several pauses.
Shane, can you reproduce this?
Stan -
26. Re: JBAS-6104; slow Seam deployments
This stack trace provided by Marko shows the problem:
at org.jboss.virtual.VFS.findChild(VFS.java:209) at org.jboss.virtual.plugins.vfs.VirtualFileURLConnection.resolveVirtualFile(VirtualFileURLConnection.java:129) at org.jboss.virtual.plugins.vfs.VirtualFileURLConnection.getVirtualFile(VirtualFileURLConnection.java:148) - locked <0x32416218> (a org.jboss.virtual.plugins.vfs.VirtualFileURLConnection) at org.jboss.virtual.plugins.vfs.VirtualFileURLConnection.getInputStream(VirtualFileURLConnection.java:99) at java.net.URL.openStream(URL.java:1009) at java.lang.ClassLoader.getResourceAsStream(ClassLoader.java:1161) at javassist.LoaderClassPath.openClassfile(LoaderClassPath.java:70) at javassist.ClassPoolTail.openClassfile(ClassPoolTail.java:335) at javassist.ClassPool.openClassfile(ClassPool.java:594) at javassist.CtClassType.getClassFile2(CtClassType.java:185) at javassist.CtClassType.getAnnotations(CtClassType.java:453) at javassist.CtClassType.getAvailableAnnotations(CtClassType.java:443) at org.jboss.deployers.plugins.annotations.GenericAnnotationResourceVisitor.handleCtClass(GenericAnnotationResourceVisitor.java:173) at org.jboss.deployers.plugins.annotations.GenericAnnotationResourceVisitor.handleCtClass(GenericAnnotationResourceVisitor.java:192)
It's javassist that hits VFSURLConnection a lot,
when trying to load annotations.
I'll see if I can re-write this to use VFS directly. -
27. Re: JBAS-6104; slow Seam deployments
"alesj" wrote:
I'll see if I can re-write this to use VFS directly.
I've implemented DU based Javassist ClassPath,
which does the trick by doing lookup directly on VFS.public class DeploymentUnitClassPath implements ClassPath { private VFSDeploymentUnit unit; private Map<String, VirtualFile> cache; public DeploymentUnitClassPath(VFSDeploymentUnit unit) { if (unit == null) throw new IllegalArgumentException("Null deployment unit."); this.unit = unit; this.cache = new HashMap<String, VirtualFile>(); } /** * Find file. * * @param className the classname we're looking for * @return virtual file or null if not found * @throws IOException for any exception */ protected VirtualFile findFile(String className) throws IOException { // ignore jdk classes if (ClassFilter.JAVA_ONLY.matchesClassName(className)) return null; VirtualFile file = cache.get(className); if (file != null) return file; List<VirtualFile> classPath = unit.getClassPath(); if (classPath != null && classPath.isEmpty() == false) { String path = ClassLoaderUtils.classNameToPath(className); for (VirtualFile cp : classPath) { file = cp.getChild(path); if (file != null) { cache.put(className, file); return file; } } } return null; } public InputStream openClassfile(String className) throws NotFoundException { try { VirtualFile file = findFile(className); if (file != null) return file.openStream(); } catch (IOException e) { throw new NotFoundException("Exception finding file: " + className, e); } throw new NotFoundException("ClassName '" + className + "' not found in deployment unit: " + unit); } public URL find(String className) { try { VirtualFile file = findFile(className); if (file != null) return file.toURL(); } catch (Exception ignored) { } return null; } public void close() { cache.clear(); } }
It's in the deployers trunk.
Can either Stan or Shane test this? -
-