search

servicecatalog / development

An Enterprise-ready Cloud Services Management Software
http://openservicecatalogmanager.org
Apache License 2.0
39 stars 27 forks source link

Connection exhausted by technical service deletion #262

Open StavrevaS opened 8 years ago

StavrevaS commented 8 years ago

[version] V16.0 GA1

[Frequency] Always

[How to reproduce]

  1. Create VMware services
  2. Subscribe VMware services
  3. Unsubscribe VMware services
  4. Delete VMware services
  5. Delete Technical service for VMware

[Expected result]

[Observed result]

StavrevaS commented 8 years ago

OSCM domain server.log

Caused by: org.oscm.internal.types.exception.SaaSSystemException: EXCEPTIONID 1469797748056: Exception notifying indexer queue for Parameter at org.oscm.dataservice.bean.IndexMQSender.notifyIndexer(IndexMQSender.java:129) at org.oscm.dataservice.bean.HibernateEventListener.onPostDelete(HibernateEventListener.java:86) at org.hibernate.action.internal.EntityDeleteAction.postDelete(EntityDeleteAction.java:156) at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:123) at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:362) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:354) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:280) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:326) at org.hibernate.event.internal.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:62) at org.hibernate.internal.SessionImpl.autoFlushIfRequired(SessionImpl.java:1185) at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1240) at org.hibernate.internal.QueryImpl.list(QueryImpl.java:101) at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:257) at org.oscm.accountservice.bean.MarketingPermissionServiceBean.removeObsoleteOrgRefs(MarketingPermissionServiceBean.java:138) at org.oscm.accountservice.bean.MarketingPermissionServiceBean.removeMarketingPermissions(MarketingPermissionServiceBean.java:437) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1052) at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1124) at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:5388) at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:619) at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800) at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:571) at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:42) at sun.reflect.GeneratedMethodAccessor195.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:861) at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800) at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:571) at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doAround(SystemInterceptorProxy.java:162) at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:144) at sun.reflect.GeneratedMethodAccessor150.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:861) at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800) at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:370) at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:5360) at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:5348) at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:214) ... 149 more Caused by: com.sun.messaging.jms.JMSException: MQRA:DCF:allocation failure:createConnection:Error in allocating a connection. Cause: In-use connections equal max-pool-size and expired max-wait-time. Cannot allocate more connections. at com.sun.messaging.jms.ra.DirectConnectionFactory._allocateConnection(DirectConnectionFactory.java:548) at com.sun.messaging.jms.ra.DirectConnectionFactory.createConnection(DirectConnectionFactory.java:265) at com.sun.messaging.jms.ra.DirectConnectionFactory.createConnection(DirectConnectionFactory.java:244) at org.oscm.dataservice.bean.IndexMQSender.sendMessage(IndexMQSender.java:88) at org.oscm.dataservice.bean.IndexMQSender.notifyIndexer(IndexMQSender.java:127) ... 191 more Caused by: javax.resource.spi.ResourceAllocationException: Error in allocating a connection. Cause: In-use connections equal max-pool-size and expired max-wait-time. Cannot allocate more connections. at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:307) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:190) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:165) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:160) at com.sun.messaging.jms.ra.DirectConnectionFactory._allocateConnection(DirectConnectionFactory.java:543) ... 195 more Caused by: com.sun.appserv.connectors.internal.api.PoolingException: In-use connections equal max-pool-size and expired max-wait-time. Cannot allocate more connections. at com.sun.enterprise.resource.pool.ConnectionPool.getResource(ConnectionPool.java:418) at com.sun.enterprise.resource.pool.PoolManagerImpl.getResourceFromPool(PoolManagerImpl.java:245) at com.sun.enterprise.resource.pool.PoolManagerImpl.getResource(PoolManagerImpl.java:170) at com.sun.enterprise.connectors.ConnectionManagerImpl.getResource(ConnectionManagerImpl.java:332) at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:301) ... 199 more

StavrevaS commented 8 years ago

The error can be reproduced using the sample VMWare technical service with creating and then terminating 5-6 subscriptions. Deleting the technical service afterwards ends with OperationFailed error.

StavrevaS commented 8 years ago

The user impact of this bug in not critical.

The technical service cannot be deleted, because there is a problem with deleting deactivated subscriptions.

The provisioned instances are deleted with the termination of the subscriptions, which means there is no cost impact for the technology provider.

The end effect is keeping stale data in the system.

Set the severity to minor.

StavrevaS commented 8 years ago

The error can be reproduced with creating and deleting more subscriptions from the same technical service.

It is the VMWare technical service, but the behavior is independent of VMWare controller. The number of parameter of this service is very big - 62 in the sample technical service.

The error is caused from Hibernate flushing in a big transaction of deleting a technical service.

The transaction is big (a lot of entities are deleted), due to the OSCM logic to clean-up all resources connected to the technical service, except the history data needed for billing purposes. The number of entities is big, because subscription records are not deleted, but subscriptions are marked as deactivated in the database in case of termination.

Furthermore, subscription records (e.g subscription, parameter) are now indexed for the subscription full-text search feature. Each write operation on these records triggers JMS message in direction master indexer.

By executing one of the queries, Hibernate needs to flush (sync with database), so there are a lot of deleted entities, especially parameters at that moment. The OSCM tries to send JMS message for each deleted entity which causes connection pool between application and JMS broker to be exhausted (currently set to max. 250 connections - ms/bss/indexerQueueFactory). As a result, there is an exception thrown which causes transaction rollback. The rollback needs additional connections and cannot be done. The result is operation failed runtime exception.

The solution could be splitting the big transaction in more smaller transactions (e.g delete each subscription in a separate transaction).

StavrevaS commented 8 years ago

Unfortunately a quick solution of this bug cannot be found. The deleting of technical services must be completely refactored in order not to block the server resources. It works fine when the technical service has not so many depended entities like services and subscriptions, but blocks otherwise.

It should be asynchronous task, which runs in the background and deletes the orphan entities of the technical service in a smaller transactions. The technical service should be marked first as deleted, since the database constraints do not allow deleting it first. The logic of deleting the provisioned resources should be revised again. For the deleted subscriptions, the provisioned resources are already deleted by its termination, so there no need to make external calls to the provisioning systems. The expired subscriptions must be checked.

misako0927 commented 8 years ago

You said the parameters are big and this error occurred. How many parameters can be used without this error?

StavrevaS commented 7 years ago

The behavior should be tested with Glassfish4.