Dhis2 module connection leak

sam.rab...@vaxtrac.com

unread,

Aug 19, 2016, 10:52:31 AM8/19/16

to MOTECH Developer

Hello,

I am using Motech v0.27.6, dhis2 v0.20, and a customized dhis2 module v0.27.6.

I have been load testing the dhis2 module by triggering a few thousands of entity creations and stage updates per second. I noticed http requests made by the dhis2 module to a dhis2 server are blocking. If a request fails, the client waits for a response indefinitely, which prevents events in the tomcat queue from being dequeued. I would then have to restart the Motech server to empty the queue, and thousands of events would be lost.

To prevent this from happening, I set up connection time-outs for the http client. After a few minutes, a connection exception would be raised, and no further requests could be made:

2016-08-12 16:54:58,814 ERROR [org.motechproject.event.listener.impl.ServerEventRelay] Handling error for event with subject create_and_enroll

org.motechproject.dhis2.rest.service.DhisWebException: Timeout waiting for responce for request: POST https://127.0.0.0/dhis2/api/trackedEntityInstances HTTP/1.1

at org.motechproject.dhis2.rest.service.impl.DhisWebServiceImpl.getResponseForRequest(DhisWebServiceImpl.java:373)

...

Caused by: org.apache.http.conn.ConnectionPoolTimeoutException: Timeout waiting for connection from pool

at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:286)

at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:263)

at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)

at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)

at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)

at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)

at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)

at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)

at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)

at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)

at org.motechproject.dhis2.rest.service.impl.DhisWebServiceImpl.getResponseForRequest(DhisWebServiceImpl.java:368)

Running the command line netstat -a | grep CLOSE_WAIT, I noticed that connections to the dhis2 server were not closed properly. The connection pool allows 2 connections per route by default, and both connections were be in the CLOSE_WAIT state.

To fix it, I followed the guidelines from https://hc.apache.org/httpcomponents-client-ga/quickstart.html that recommend consuming responses and closing requests. After this, there were no more CLOSE_WAIT connections. I have also increased the pool size. There must be additional steps to follow to manage connections properly.

A copy of my DhisWebServiceImpl.java file is attached.

Regards,

Samantha.

DhisWebServiceImpl.java

Craig A

unread,

Aug 21, 2016, 1:01:18 AM8/21/16

to Motech-dev

Thanks Sam,

I'll create a ticket in Jira to address this and we'll discuss on Tuesday's dev call.

Craig

--
You received this message because you are subscribed to the Google Groups "MOTECH Developer" group.
To unsubscribe from this group and stop receiving emails from it, send an email to motech-dev+unsubscribe@googlegroups.com.
To post to this group, send email to motec...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/motech-dev/4b75b95b-b664-45d8-bf79-07ef9d92a17f%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Craig Appl

Lead Technical Program Manager, Mobile Health Innovations

Grameen Foundation

2101 4th Ave | Suite 1550 | Seattle, WA 98121

Skype:craigappl

Facebook│Twitter│YouTube | www.motechsuite.org

Connecting the World's Poor to Their Potential

fgomul...@soldevelo.com

unread,

Aug 25, 2016, 7:59:18 AM8/25/16

to MOTECH Developer

Hi Samantha,

I am using Motech v0.27.6, dhis2 module v0.27.6 and dhis2 v2.20 (because I think that is what you meant by "dhis2 v0.20").

I tried to reproduce the exception. To do this I created a new task with action creating Tracked Entity Instance [Person] with values:

External ID: 1

Organisation Unit Id: Rp268JB6Ne4 (which was Adonkia CHP)

I also modified the code so that the event triggering my task would be raised 4000+ times.

Unfortunately, I was able to get blocking requests only once.

After that, no matter how many times the action would be executed, I was not able to get this problem second time.

I also think that my way of testing is not "fast" enough.

So I am asking if you could write down the reproduction steps for this problem.

Best regards

Filip

Paweł Gesek

unread,

Aug 25, 2016, 8:11:32 AM8/25/16

to motec...@googlegroups.com

From my understanding the problem is on the Dhis side not closing connections and Motech getting stuck in the wait phase, since we reuse the same http client.

My suggestion on reproducing this would be to use a mock http server as the dhis server, that just goes into a endless loop without closing the connection, that way you only would need to trigger the task a few times to repro this.

Regards,

Paweł

--

You received this message because you are subscribed to the Google Groups "MOTECH Developer" group.

To unsubscribe from this group and stop receiving emails from it, send an email to motech-dev+...@googlegroups.com.

To post to this group, send email to motec...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/motech-dev/ffdd4a65-8ff2-4d22-b741-65f2365dfd0c%40googlegroups.com.

Samantha Rabenjamina

unread,

Aug 25, 2016, 10:51:50 AM8/25/16

to MOTECH Developer

Hi Filip,

Yes, I am using DHIS2 v2.20.

As Pawel said, making failing requests to DHIS2 should help. For example, if you try to create a stage event without creating or enrolling a tracked entity in the DHIS2 server first, the DHIS2 module should be waiting for a response indefinitely. You could try adding your entity's external id in the trackedEntityInstanceMapping table manually before triggering an update stage event for an entity with that external id.

Regards,
Samantha.

To unsubscribe from this group and stop receiving emails from it, send an email to motech-dev+unsubscribe@googlegroups.com.

To post to this group, send email to motec...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/motech-dev/ffdd4a65-8ff2-4d22-b741-65f2365dfd0c%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to a topic in the Google Groups "MOTECH Developer" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/motech-dev/egp1KWfvyM0/unsubscribe.
To unsubscribe from this group and all its topics, send an email to motech-dev+unsubscribe@googlegroups.com.

To post to this group, send email to motec...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/motech-dev/e05ac608-cc91-8c86-44a9-a67987ee061b%40soldevelo.com.

sam.rab...@vaxtrac.com

unread,

Aug 25, 2016, 2:49:22 PM8/25/16

to MOTECH Developer

Hello,

The way I handled connections in the previously attached file allowed me to create tracked entities and events without problem, but it makes syncing faulty. When I click on the sync button in the dhis2 module settings, syncing fails because of closed sockets:

2016-08-25 19:31:39,621 ERROR [org.motechproject.dhis2.rest.service.impl.DhisWebServiceImpl] Error parsing dataElements resources, exception: java.net.SocketException: Socket is closed

java.net.SocketException: Socket is closed

at sun.security.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1532)

at sun.security.ssl.AppInputStream.read(AppInputStream.java:95)

at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139)

at org.apache.http.impl.io.SessionInputBufferImpl.read(SessionInputBufferImpl.java:200)

at org.apache.http.impl.io.ContentLengthInputStream.read(ContentLengthInputStream.java:178)

at org.apache.http.conn.EofSensorInputStream.read(EofSensorInputStream.java:137)

at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.loadMore(UTF8StreamJsonParser.java:174)

at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.slowParseFieldName(UTF8StreamJsonParser.java:1402)

at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._parseFieldName(UTF8StreamJsonParser.java:1237)

at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:501)

at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserializeFromObject(BeanDeserializer.java:283)

at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:112)

at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:226)

at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:203)

at com.fasterxml.jackson.databind.deser.std.CollectionDeserializer.deserialize(CollectionDeserializer.java:23)

at com.fasterxml.jackson.databind.deser.SettableAnyProperty.deserialize(SettableAnyProperty.java:98)

at com.fasterxml.jackson.databind.deser.SettableAnyProperty.deserializeAndSet(SettableAnyProperty.java:88)

at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserializeFromObject(BeanDeserializer.java:303)

at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:112)

at com.fasterxml.jackson.databind.ObjectReader._bindAndClose(ObjectReader.java:937)

at com.fasterxml.jackson.databind.ObjectReader.readValue(ObjectReader.java:601)

at org.motechproject.dhis2.rest.service.impl.DhisWebServiceImpl.getResources(DhisWebServiceImpl.java:285)

at org.motechproject.dhis2.rest.service.impl.DhisWebServiceImpl.getDataElements(DhisWebServiceImpl.java:143)

at org.motechproject.dhis2.service.impl.SyncServiceImpl.addDataElements(SyncServiceImpl.java:97)

at org.motechproject.dhis2.service.impl.SyncServiceImpl.sync(SyncServiceImpl.java:74)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:497)

at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)

at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)

at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)

at com.sun.proxy.$Proxy421.sync(Unknown Source)

at org.motechproject.dhis2.web.DhisSettingsController.sync(DhisSettingsController.java:70)

at org.motechproject.dhis2.web.DhisSettingsController$$FastClassByCGLIB$$bea31008.invoke(<generated>)

at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)

at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)

at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:61)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)

at org.motechproject.dhis2.web.DhisSettingsController$$EnhancerByCGLIB$$3822e7cc.sync(<generated>)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:497)

at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:212)

at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126)

at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96)

at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617)

at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578)

at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)

at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:900)

at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:827)

at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)

at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:620)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)

at org.apache.felix.http.base.internal.handler.ServletHandler.doHandle(ServletHandler.java:96)

at org.apache.felix.http.base.internal.handler.ServletHandler.handle(ServletHandler.java:79)

at org.apache.felix.http.base.internal.dispatch.ServletPipeline.handle(ServletPipeline.java:42)

at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:49)

at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:33)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:311)

at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:116)

at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)