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

[Former Member]

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

[Former Member]

Hi,

Please make sure same customer ID is not being used concurrently from single/multiple load generator agents.

Thanks