Skip to Content
0
Former Member
May 24, 2018 at 04:24 PM

Under moderate load getting a.lang.IllegalStateException: could not switch tenant to <>

210 Views

Hi,

We are doing a performance testing with moderate load of around 2500 users that does everything from login to checkout and have observed the following exception frequently.

 NFO   | jvm 1    | main    | 2018/03/26 16:53:37.825 | [2018-03-26T16:53:37,450]ERROR157138[hybrisHTTP5970][](RestHandlerExceptionResolver.java:85) [] [000000020039] - de.hybris.platform.servicelayer.exceptions.ModelRemovalException: could not remove partOf attribute items in [alldocuments, paymenttransactions, allpromotionresults, entries] for 01334737(8839469203499) due to could not switch tenant to <<master>>
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.825 |         at de.hybris.platform.servicelayer.internal.converter.impl.ItemModelConverter.remove(ItemModelConverter.java:760)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.825 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.removeViaJalo(DefaultModelService.java:819)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.doJaloPersistence(DefaultModelService.java:740)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.persistWrappers(DefaultModelService.java:1121)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.performPersistenceOperations(DefaultModelService.java:717)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.removeAllInternal(DefaultModelService.java:593)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.removeAll(DefaultModelService.java:582)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.removeAll(DefaultModelService.java:536)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.remove(DefaultModelService.java:516)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at com.ril.commerceservices.cart.strategies.impl.DefaultRILGroceryCommerceCartMergingStrategy.mergeCarts(DefaultRILGroceryCommerceCartMergingStrategy.java:105)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.commerceservices.order.impl.DefaultCommerceCartService.mergeCarts(DefaultCommerceCartService.java:331)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at de.hybris.platform.commercefacades.order.impl.DefaultCartFacade.restoreAnonymousCartAndMerge(DefaultCartFacade.java:332)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at com.ril.v2.controller.CartsController.createCart(CartsController.java:445)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at com.ril.v2.controller.CartsController$$FastClassBySpringCGLIB$$150a4149.invoke(<generated>)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:669)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at com.ril.v2.controller.CartsController$$EnhancerBySpringCGLIB$$7a829834.createCart(<generated>)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at sun.reflect.GeneratedMethodAccessor1330.invoke(Unknown Source)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at java.lang.reflect.Method.invoke(Method.java:498)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.826 |         at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
 
 
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 | Caused by: de.hybris.platform.jalo.ConsistencyCheckException: could not remove partOf attribute items in [alldocuments, paymenttransactions, allpromotionresults, entries] for 01334737(8839469203499) due to could not switch tenant to <<master>>[HY-0]
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.Item.removePartOfItems(Item.java:3290)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.Item.removePartOfItems(Item.java:3272)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.Item.removeDependentItems(Item.java:3227)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.Item.doRemove(Item.java:3133)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.Item.remove(Item.java:3087)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.order.AbstractOrder.remove(AbstractOrder.java:2996)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.Item.remove(Item.java:3048)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.servicelayer.internal.converter.impl.ItemModelConverter.remove(ItemModelConverter.java:747)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         ... 131 more
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 | Caused by: de.hybris.platform.jalo.flexiblesearch.FlexibleSearchException: could not switch tenant to <<master>>[HY-0]
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.flexiblesearch.FlexibleSearch.search(FlexibleSearch.java:1452)
 
 
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 | Caused by: java.lang.IllegalStateException: could not switch tenant to <<master>>
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.core.Registry.activateTenant(Registry.java:710)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.core.Registry.setCurrentTenant(Registry.java:552)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jdbcwrapper.DataSourceImpl.getConnection(DataSourceImpl.java:432)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jdbcwrapper.DataSourceImpl.getConnection(DataSourceImpl.java:393)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.flexiblesearch.internal.FlexibleSearchExecutor.execute(FlexibleSearchExecutor.java:94)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.flexiblesearch.FlexibleSearch.executeSearch(FlexibleSearch.java:1772)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.flexiblesearch.FlexibleSearchCacheUnit.compute(FlexibleSearchCacheUnit.java:56)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.cache.AbstractCacheUnit.privateGetNoLock(AbstractCacheUnit.java:305)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.cache.AbstractCacheUnit.privateGet(AbstractCacheUnit.java:278)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.cache.AbstractCacheUnit.get(AbstractCacheUnit.java:180)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.flexiblesearch.FlexibleSearchCacheUnit.myGet(FlexibleSearchCacheUnit.java:95)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         at de.hybris.platform.jalo.flexiblesearch.FlexibleSearch.search(FlexibleSearch.java:1443)
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |         ... 157 more
 INFO   | jvm 1    | main    | 2018/03/26 16:53:37.827 |
 

We have total 8 nodes on production with 200*4+90*4= 1160 connections in the pool and oracle database has around 6500 sessions available.

So ideally the connection pool should not get exhausted with such moderate load. Any thoughts on why we are facing this issue and any optimization we can do ?

Thanks. Saurabh