[ http://jira.jboss.com/jira/browse/JBPORTAL-1211?page=all ] Prabhat Jha updated JBPORTAL-1211: ---------------------------------- Summary: portal load test: optimize use of Interceptors and DB query (was: portal load test: optimize DB query) Description: During portal load test, we found some bottlenecks related to call to DB. At 500 simultaneous user thread, we start seeing org.jboss.util.NestedSQLException: No ManagedConnections available within configured blocking timeout with min pool size of 20 and max pool size of 40. I am not sure but the following query which does join of 6 tables probably also needs to be optimized select portalobje0_.PK as PK20_0_, portalobje0_.LISTENER as LISTENER20_0_, portalobje0_4_.INSTANCE_REF as INSTANCE2_27_0_, case when portalobje0_1_.PK is not null then 1 when portalobje0_2_.PK is not null then 2 when portalobje0_3_.PK is not null then 3 when portalobje0_4_.PK is not null then 4 when portalobje0_.PK is not null then 0 end as clazz_0_, declaredpr1_.OBJECT_KEY as OBJECT1_2_, declaredpr1_.jbp_VALUE as jbp2_2_, declaredpr1_.NAME as NAME2_, modes2_.PK as PK3_, modes2_.name as name3_, windowstat3_.PK as PK4_, windowstat3_.name as name4_ from JBP_PORTAL_OBJECT portalobje0_ left outer join JBP_CONTEXT portalobje0_1_ on portalobje0_.PK=portalobje0_1_.PK left outer join JBP_PORTAL portalobje0_2_ on portalobje0_.PK=portalobje0_2_.PK left outer join JBP_PAGE portalobje0_3_ on portalobje0_.PK=portalobje0_3_.PK left outer join JBP_WINDOW portalobje0_4_ on portalobje0_.PK=portalobje0_4_.PK left outer join JBP_PORTAL_OBJECT_PROPS declaredpr1_ on portalobje0_.PK=declaredpr1_.OBJECT_KEY left outer join JBP_PORTAL_MODE modes2_ on portalobje0_.PK=modes2_.PK left outer join JBP_PORTAL_WINDOW_STATE windowstat3_ on portalobje0_.PK=windowstat3_.PK where portalobje0_.PK=? Complete Stack trace; org.jboss.util.NestedSQLException: No ManagedConnections available within configured blocking timeout ( 30000 [ms] ); - nested throwable: (javax.resource.Re\ sourceException: No ManagedConnections available within configured blocking timeout ( 30000 [ms] )) at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94) at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:69) at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417) at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144) at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139) at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1561) at org.hibernate.loader.Loader.doQuery(Loader.java:661) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224) at org.hibernate.loader.Loader.loadEntity(Loader.java:1785) at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48) at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42) at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2821) at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:370) at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:351) at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:122) at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:178) at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:86) at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:871) at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808) at org.hibernate.impl.SessionImpl.get(SessionImpl.java:801) at org.jboss.portal.core.impl.model.portal.PersistentPortalObjectContainer.lookup(PersistentPortalObjectContainer.java:475) at org.jboss.portal.core.impl.model.portal.PersistentPortalObjectContainer.getObject(PersistentPortalObjectContainer.java:242) at org.jboss.portal.core.impl.model.portal.PersistentPortalObjectContainer.getContext(PersistentPortalObjectContainer.java:255) at sun.reflect.GeneratedMethodAccessor262.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.AttributeDispatcher.invoke(AttributeDispatcher.java:99) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94) at org.jboss.mx.server.Invocation.invoke(Invocation.java:86) at org.jboss.mx.interceptor.ModelMBeanAttributeInterceptor.invoke(ModelMBeanAttributeInterceptor.java:197) at org.jboss.mx.interceptor.PersistenceInterceptor.invoke(PersistenceInterceptor.java:76) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.server.AbstractMBeanInvoker.getAttribute(AbstractMBeanInvoker.java:362) at org.jboss.mx.server.MBeanServerImpl.getAttribute(MBeanServerImpl.java:556) at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:140) at $Proxy55.getContext(Unknown Source) at org.jboss.portal.core.model.portal.PortalObjectCommandFactory$1.getRoot(PortalObjectCommandFactory.java:73) at org.jboss.portal.server.servlet.PathParser.map(PathParser.java:46) at org.jboss.portal.core.model.portal.PortalObjectCommandFactory.doMapping(PortalObjectCommandFactory.java:109) at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94) at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142) 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:659) at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210) at $Proxy57.doMapping(Unknown Source) at org.jboss.portal.core.command.mapper.CommandFactoryDelegate.doMapping(CommandFactoryDelegate.java:86) at org.jboss.portal.core.command.mapper.DelegatingCommandFactoryService.doMapping(DelegatingCommandFactoryService.java:139) at sun.reflect.GeneratedMethodAccessor265.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94) at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659) at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210) at $Proxy57.doMapping(Unknown Source) at org.jboss.portal.core.command.mapper.CommandFactoryDelegate.doMapping(CommandFactoryDelegate.java:86) at org.jboss.portal.core.command.mapper.DelegatingCommandFactoryService.doMapping(DelegatingCommandFactoryService.java:139) at sun.reflect.GeneratedMethodAccessor265.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94) at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142) 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:659) at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210) at $Proxy53.doMapping(Unknown Source) at org.jboss.portal.core.model.portal.DefaultPortalCommandFactory.doMapping(DefaultPortalCommandFactory.java:65) at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94) at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133) at org.jboss.mx.server.Invocation.invoke(Invocation.java:88) at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142) 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:659) at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210) at $Proxy68.doMapping(Unknown Source) at org.jboss.portal.core.CoreController.handle(CoreController.java:129) at sun.reflect.GeneratedMethodAccessor258.invoke(Unknown Source) ...... at org.jboss.portal.core.aspects.server.UserInterceptor.invoke(UserInterceptor.java:175) at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38) at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131) at org.jboss.portal.server.aspects.server.SessionInvalidatorInterceptor.invoke(SessionInvalidatorInterceptor.java:84) at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38) at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131) at org.jboss.portal.core.aspects.server.TransactionInterceptor.org$jboss$portal$core$aspects$server$TransactionInterceptor$invoke$aop(TransactionInt\ erceptor.java:49) at org.jboss.portal.core.aspects.server.TransactionInterceptor$invoke_N5143606530999904530.invokeNext(TransactionInterceptor$invoke_N514360653099990\ 4530.java) at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79) at org.jboss.aspects.tx.TxInterceptor$RequiresNew.invoke(TxInterceptor.java:275) at org.jboss.portal.core.aspects.server.TransactionInterceptor$invoke_N5143606530999904530.invokeNext(TransactionInterceptor$invoke_N514360653099990\ 4530.java) at org.jboss.portal.core.aspects.server.TransactionInterceptor.invoke(TransactionInterceptor.java) at org.jboss.portal.server.ServerInterceptor.invoke(ServerInterceptor.java:38) at org.jboss.portal.common.invocation.Invocation.invokeNext(Invocation.java:131) at org.jboss.portal.common.invocation.Invocation.invoke(Invocation.java:171) at org.jboss.portal.server.servlet.PortalServlet.process(PortalServlet.java:295) at org.jboss.portal.server.servlet.PortalServlet.doGet(PortalServlet.java:173) at javax.servlet.http.HttpServlet.service(HttpServlet.java:697) at javax.servlet.http.HttpServlet.service(HttpServlet.java:810) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252) was: During portal load test, we found some bottlenecks related to call to DB. At 500 simultaneous user thread, we start seeing org.jboss.util.NestedSQLException: No ManagedConnections available within configured blocking timeout with min pool size of 20 and max pool size of 40. I am not sure but the following query which does join of 6 tables probably also needs to be optimized select portalobje0_.PK as PK20_0_, portalobje0_.LISTENER as LISTENER20_0_, portalobje0_4_.INSTANCE_REF as INSTANCE2_27_0_, case when portalobje0_1_.PK is not null then 1 when portalobje0_2_.PK is not null then 2 when portalobje0_3_.PK is not null then 3 when portalobje0_4_.PK is not null then 4 when portalobje0_.PK is not null then 0 end as clazz_0_, declaredpr1_.OBJECT_KEY as OBJECT1_2_, declaredpr1_.jbp_VALUE as jbp2_2_, declaredpr1_.NAME as NAME2_, modes2_.PK as PK3_, modes2_.name as name3_, windowstat3_.PK as PK4_, windowstat3_.name as name4_ from JBP_PORTAL_OBJECT portalobje0_ left outer join JBP_CONTEXT portalobje0_1_ on portalobje0_.PK=portalobje0_1_.PK left outer join JBP_PORTAL portalobje0_2_ on portalobje0_.PK=portalobje0_2_.PK left outer join JBP_PAGE portalobje0_3_ on portalobje0_.PK=portalobje0_3_.PK left outer join JBP_WINDOW portalobje0_4_ on portalobje0_.PK=portalobje0_4_.PK left outer join JBP_PORTAL_OBJECT_PROPS declaredpr1_ on portalobje0_.PK=declaredpr1_.OBJECT_KEY left outer join JBP_PORTAL_MODE modes2_ on portalobje0_.PK=modes2_.PK left outer join JBP_PORTAL_WINDOW_STATE windowstat3_ on portalobje0_.PK=windowstat3_.PK where portalobje0_.PK=? -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.jboss.com/jira/browse/JBPORTAL-1211?page=comments#action_1235... ] Prabhat Jha commented on JBPORTAL-1211: --------------------------------------- Sure I can use trunk. I thought it would be good to see the problems with a stable codebase. I defintely see the above query getting printed in log more than once but I do not know the frequency. Once I run the tests using profiler, I would be able to answer your question. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.jboss.com/jira/browse/JBPORTAL-1211?page=comments#action_1235... ] Julien Viet commented on JBPORTAL-1211: --------------------------------------- I have checked in trunk at least accessing with an authenticated user makes an hit to the DB (which is normal) : Hibernate: select hibernateu0_.jbp_uid as jbp1_0_, hibernateu0_.jbp_uname as jbp2_0_, hibernateu0_.jbp_givenname as jbp3_0_, hibernateu0_.jbp_familyname as jbp4_0_, hibernateu0_.jbp_password as jbp5_0_, hibernateu0_.jbp_realemail as jbp6_0_, hibernateu0_.jbp_fakeemail as jbp7_0_, hibernateu0_.jbp_regdate as jbp8_0_, hibernateu0_.jbp_viewrealemail as jbp9_0_, hibernateu0_.jbp_enabled as jbp10_0_ from jbp_users hibernateu0_ where hibernateu0_.jbp_uname=? Hibernate: select roles0_.jbp_uid as jbp1_1_, roles0_.jbp_rid as jbp2_1_, hibernater1_.jbp_rid as jbp1_3_0_, hibernater1_.jbp_name as jbp2_3_0_, hibernater1_.jbp_displayname as jbp3_3_0_ from jbp_role_membership roles0_ left outer join jbp_roles hibernater1_ on roles0_.jbp_rid=hibernater1_.jbp_rid where roles0_.jbp_uid=? Hibernate: select dynamic0_.jbp_uid as jbp1_0_, dynamic0_.jbp_value as jbp2_0_, dynamic0_.jbp_name as jbp3_0_ from jbp_user_prop dynamic0_ where dynamic0_.jbp_uid=? when the uses the portal then, the hibernate layer caches the user and no DB access is done anymore. Please run a test with the latest trunk. If you still see database issues then we will fine tune the cache settings in order to keep more data and for a longer time in the cache. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.jboss.com/jira/browse/JBPORTAL-1211?page=comments#action_1236... ] Prabhat Jha commented on JBPORTAL-1211: --------------------------------------- I think this issue has been resolved. No?? -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira