Seam Faces 3.0.0.Alpha3 - Weird but serious performance issue
Hi guys
We recently split up our application into two separate webapps: one for the frontend (JSF2/Primefaces) and one for the backend (EJB3, JPA2, Hibernate). The frontend uses ejb remote interfaces to the backend. Both are running on Glassfish 3.0.1.
After this process the performance was horrible. Using remote interfaces instead of local interfaces is indeed more costly, but when summing up the time spent in remote calls, there was still a huge gap. Rendering an empty.xhtml with no logic took about 3 seconds. Static resources (css, js) also took a lot of time.
After pulling out every class in the application we finally found the culprit: We had 3 webservices in the frontend (plain classes annotated with @WebService). If we removed these, rendering time of empty.xhtml went down to 50ms. Each of them had an equal 1 second impact of the rendering time.
I added the webservices and tried to shut down the backend server and reload empty.xhtml, and now I got an exception:
[#|2010-10-14T08:25:42.927+0200|WARNING|glassfish3.0.1|javax.enterprise.system.container.web.com.sun.enterprise.web|_ThreadID=29;_ThreadName=Thread-1;|StandardWrapperValve[Faces Servlet]: PWC1406: Servlet.service() for servlet Faces Servlet threw exception java.lang.IllegalStateException: Could not wrap ExternalContext at org.jboss.seam.faces.environment.SeamExternalContextFactory.getExternalContext(SeamExternalContextFactory.java:35) at com.sun.faces.context.InjectionExternalContextFactory.getExternalContext(InjectionExternalContextFactory.java:109) at com.sun.faces.context.FacesContextFactoryImpl.getFacesContext(FacesContextFactoryImpl.java:93) at javax.faces.webapp.FacesServlet.service(FacesServlet.java:302) at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1523) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) at org.primefaces.webapp.filter.FileUploadFilter.doFilter(FileUploadFilter.java:79) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) at no.evote.service.security.CookieFilter.doFilter(CookieFilter.java:49) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:277) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:188) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:641) at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97) at com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185) at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:325) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226) at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:239) at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791) at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693) at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954) at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170) at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135) at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102) at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88) at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76) at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53) at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57) at com.sun.grizzly.ContextTask.run(ContextTask.java:69) at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330) at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309) at java.lang.Thread.run(Thread.java:619) Caused by: java.lang.IllegalStateException: Exception attempting to inject Remote ejb-ref name=MvAreaService,Remote 3.x interface =no.evote.service.MvAreaService,ejb-link=null,lookup=null,mappedName=,jndi-name=corbaname:iiop:admin-backend:3700#no.evote.service.MvAreaService,refType=Session into class org.jboss.seam.faces.environment.SeamExternalContext at org.glassfish.weld.services.InjectionServicesImpl.aroundInject(InjectionServicesImpl.java:133) at org.jboss.weld.injection.InjectionContextImpl.run(InjectionContextImpl.java:47) at org.jboss.weld.bean.ManagedBean$ManagedBeanInjectionTarget$1.work(ManagedBean.java:171) at org.jboss.weld.bean.ManagedBean$FixInjectionPoint.run(ManagedBean.java:142) at org.jboss.weld.bean.ManagedBean$ManagedBeanInjectionTarget.inject(ManagedBean.java:165) at org.jboss.weld.bean.ManagedBean.create(ManagedBean.java:332) at org.jboss.weld.context.AbstractMapContext.get(AbstractMapContext.java:112) at org.jboss.weld.bean.proxy.ClientProxyMethodHandler.getProxiedInstance(ClientProxyMethodHandler.java:143) at org.jboss.weld.bean.proxy.ClientProxyMethodHandler.invoke(ClientProxyMethodHandler.java:100) at org.jboss.weld.util.CleanableMethodHandler.invoke(CleanableMethodHandler.java:43) at org.jboss.seam.faces.environment.SeamExternalContext_$$_javassist_48.setWrapped(SeamExternalContext_$$_javassist_48.java) at org.jboss.seam.faces.environment.SeamExternalContextFactory.getExternalContext(SeamExternalContextFactory.java:29) ... 35 more Caused by: com.sun.enterprise.container.common.spi.util.InjectionException: Exception attempting to inject Remote ejb-ref name=MvAreaService,Remote 3.x interface =no.evote.service.MvAreaService,ejb-link=null,lookup=null,mappedName=,jndi-name=corbaname:iiop:admin-backend:3700#no.evote.service.MvAreaService,refType=Session into class org.jboss.seam.faces.environment.SeamExternalContext at com.sun.enterprise.container.common.impl.util.InjectionManagerImpl._inject(InjectionManagerImpl.java:614) at com.sun.enterprise.container.common.impl.util.InjectionManagerImpl.inject(InjectionManagerImpl.java:384) at com.sun.enterprise.container.common.impl.util.InjectionManagerImpl.injectInstance(InjectionManagerImpl.java:168) at org.glassfish.weld.services.InjectionServicesImpl.aroundInject(InjectionServicesImpl.java:126) ... 46 more Caused by: javax.naming.NamingException: Lookup failed for 'java:comp/env/MvAreaService' in SerialContext [Root exception is javax.naming.NamingException: Exception resolving Ejb for 'Remote ejb-ref name=MvAreaService,Remote 3.x interface =no.evote.service.MvAreaService,ejb-link=null,lookup=null,mappedName=,jndi-name=corbaname:iiop:admin-backend:3700#no.evote.service.MvAreaService,refType=Session' . Actual (possibly internal) Remote JNDI name used for lookup is 'corbaname:iiop:admin-backend:3700#no.evote.service.MvAreaService__3_x_Internal_RemoteBusinessHome__' [Root exception is org.omg.CORBA.BAD_PARAM: vmcid: OMG minor code: 9 completed: No]] at com.sun.enterprise.naming.impl.SerialContext.lookup(SerialContext.java:442) at javax.naming.InitialContext.lookup(InitialContext.java:392) at com.sun.enterprise.container.common.impl.util.InjectionManagerImpl._inject(InjectionManagerImpl.java:513) ... 49 more Caused by: javax.naming.NamingException: Exception resolving Ejb for 'Remote ejb-ref name=MvAreaService,Remote 3.x interface =no.evote.service.MvAreaService,ejb-link=null,lookup=null,mappedName=,jndi-name=corbaname:iiop:admin-backend:3700#no.evote.service.MvAreaService,refType=Session' . Actual (possibly internal) Remote JNDI name used for lookup is 'corbaname:iiop:admin-backend:3700#no.evote.service.MvAreaService__3_x_Internal_RemoteBusinessHome__' [Root exception is org.omg.CORBA.BAD_PARAM: vmcid: OMG minor code: 9 completed: No] at com.sun.ejb.EjbNamingReferenceManagerImpl.resolveEjbReference(EjbNamingReferenceManagerImpl.java:174) at com.sun.enterprise.container.common.impl.ComponentEnvManagerImpl$EjbReferenceProxy.create(ComponentEnvManagerImpl.java:1040) at com.sun.enterprise.naming.impl.GlassfishNamingManagerImpl.lookup(GlassfishNamingManagerImpl.java:688) at com.sun.enterprise.naming.impl.GlassfishNamingManagerImpl.lookup(GlassfishNamingManagerImpl.java:657) at com.sun.enterprise.naming.impl.JavaURLContext.lookup(JavaURLContext.java:148) at com.sun.enterprise.naming.impl.SerialContext.lookup(SerialContext.java:428) ... 51 more Caused by: org.omg.CORBA.BAD_PARAM: vmcid: OMG minor code: 9 completed: No at com.sun.corba.ee.impl.logging.OMGSystemException.soBadSchemaSpecific(OMGSystemException.java:1075) at com.sun.corba.ee.impl.logging.OMGSystemException.soBadSchemaSpecific(OMGSystemException.java:1093) at com.sun.corb at com.sun.corba.ee.impl.resolver.INSURLOperationImpl.resolveCorbaname(INSURLOperationImpl.java:228) at com.sun.corba.ee.impl.resolver.INSURLOperationImpl.resolveINSURL(INSURLOperationImpl.java:154) at com.sun.corba.ee.impl.resolver.INSURLOperationImpl.operate(INSURLOperationImpl.java:144) at com.sun.corba.ee.impl.orb.ORBImpl.string_to_object(ORBImpl.java:954) at com.sun.ejb.EjbNamingReferenceManagerImpl.resolveEjbReference(EjbNamingReferenceManagerImpl.java:167) ... 56 more Caused by: org.omg.CORBA.COMM_FAILURE: vmcid: SUN minor code: 201 completed: No at com.sun.corba.ee.impl.logging.ORBUtilSystemException.connectFailure(ORBUtilSystemException.java:3431) at com.sun.corba.ee.impl.logging.ORBUtilSystemException.connectFailure(ORBUtilSystemException.java:3452) at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.<init>(SocketOrChannelConnectionImpl.java:256) at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.<init>(SocketOrChannelConnectionImpl.java:269) at com.sun.corba.ee.impl.transport.SocketOrChannelContactInfoImpl.createConnection(SocketOrChannelContactInfoImpl.java:125) at com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.beginRequest(CorbaClientRequestDispatcherImpl.java:188) at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.request(CorbaClientDelegateImpl.java:186) at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.is_a(CorbaClientDelegateImpl.java:352) at org.omg.CORBA.portable.ObjectImpl._is_a(ObjectImpl.java:112) at org.omg.CosNaming.NamingContextExtHelper.narrow(NamingContextExtHelper.java:73) at com.sun.corba.ee.impl.resolver.INSURLOperationImpl.resolveCorbaname(INSURLOperationImpl.java:212) ... 60 more Caused by: java.lang.RuntimeException: java.net.ConnectException: Connection refused: connect at org.glassfish.enterprise.iiop.impl.IIOPSSLSocketFactory.createSocket(IIOPSSLSocketFactory.java:340) at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.<init>(SocketOrChannelConnectionImpl.java:239) ... 68 more Caused by: java.net.ConnectException: Connection refused: connect at sun.nio.ch.Net.connect(Native Method) at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:507) at com.sun.corba.ee.impl.orbutil.ORBUtility.openSocketChannel(ORBUtility.java:106) at org.glassfish.enterprise.iiop.impl.IIOPSSLSocketFactory.createSocket(IIOPSSLSocketFactory.java:325) ... 69 more |#]
So for some reason, the EJB's in our webservice are looked up on each request, not only to jsf pages but also resources. I tried adding a @PostConstruct method to see whether the classes were instantiated, but it doesn't look like they are.
If we add @Stateless to the classes (making them EJB's), the problem goes away. And it also does if we remove seam-faces-3.0.0.Alpha3.
So, we have a workaround for this problem. But, what the heck is going on here??
Regards,
Anders
