Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.1

classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.1

johnhd_at_zen
This post was updated on .
Hi All,

I'm using an instance of CONNECT 4.4.1. We have cases with our underlying CDR responding quite slowly to generate a CCD in response to a DocRequest and we're getting a read timeout while CONNECT waits to hear back (via its adapter).

The timeout occurs at exactly 60 seconds after we receive the DocRequest. The gateway throws this:

[#|2017-06-15T10:12:56.816-0700|WARNING|glassfish3.1.2|org.apache.cxf.phase.PhaseInterceptorChain|_ThreadID=253;_ThreadName=Thread-2;|Interceptor for {http://ejb.our.vendor.com/}NhinInterfaceWSService#{http://ejb.our.vendor.com/}docQuery has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: Could not send Message.
	at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:64)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:272)
	at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:570)
	at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:479)
	at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:382)
	at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:335)
	at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
	at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:136)
	at com.sun.proxy.$Proxy372.docQuery(Unknown Source)
	at com.mirth.results.nhinc.MirthResultsStrategy.docQuery(MirthResultsStrategy.java:43)
	at com.mirth.results.nhinc.LocalSystemClient.docQuery(LocalSystemClient.java:45)
	at com.mirth.results.nhinc.MirthDocumentQueryHandler.docQuery(MirthDocumentQueryHandler.java:14)
	at com.mirth.nhin.adapter.repository.service.DocumentService.documentQuery(DocumentService.java:51)
	at com.mirth.nhin.adapter.document.DocumentRegistryHelper.documentRegistryRegistryStoredQuery(DocumentRegistryHelper.java:207)
	at com.mirth.nhin.adapterutils.DocumentQuery.execute(DocumentQuery.java:22)
	at gov.hhs.fha.nhinc.docquery.adapter.AdapterDocQuerySecured.respondingGatewayCrossGatewayQuery(AdapterDocQuerySecured.java:38)
	at sun.reflect.GeneratedMethodAccessor849.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:188)
	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:104)
	at org.apache.cxf.jaxws.AbstractJAXWSMethodInvoker.invoke(AbstractJAXWSMethodInvoker.java:237)
	at org.apache.cxf.jaxws.JAXWSMethodInvoker.invoke(JAXWSMethodInvoker.java:69)
	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:75)
	at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37)
	at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:107)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:272)
	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121)
	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:241)
	at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:248)
	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:222)
	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:153)
	at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171)
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:286)
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:206)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:262)
	at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
	at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161)
	at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:331)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
	at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317)
	at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
	at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:860)
	at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:757)
	at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1056)
	at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:229)
	at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
	at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
	at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
	at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
	at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
	at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
	at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
	at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
	at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: SocketTimeoutException invoking https://localhost:11443/NhinInterfaceWSService/NhinInterfaceWS: Read timed out
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
	at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.mapException(HTTPConduit.java:1347)
	at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1331)
	at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56)
	at org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:223)
	at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
	at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:632)
	at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
	... 63 more
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:152)
	at java.net.SocketInputStream.read(SocketInputStream.java:122)
	at sun.security.ssl.InputRecord.readFully(InputRecord.java:442)
	at sun.security.ssl.InputRecord.read(InputRecord.java:480)
	at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:934)
	at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:891)
	at sun.security.ssl.AppInputStream.read(AppInputStream.java:102)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:689)
	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1324)
	at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
	at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:338)
	at org.apache.cxf.transport.http.URLConnectionHTTPConduit$URLConnectionWrappedOutputStream.getResponseCode(URLConnectionHTTPConduit.java:266)
	at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1543)
	at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1513)
	at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1318)
	... 68 more
|#]

I'd like to find this timeout and increase it.

I've tried a few things already but have not been able to get this timeout to budge.

I've tried following this guide:
https://connectopensource.atlassian.net/wiki/display/CONNECT4/Large+Payload

And have bumped:
* Glassfish Admin:
** JVM Options: -Dcom.sun.grizzly.writeTimeout from 60000 to 120000
* gateway.properties:
** QueryForDocuments.webserviceproxy.request.timeout from 60000 to 120000
** APPARENTLY this setting no longer matters per https://connectopensource.atlassian.net/browse/CONN-1604 and webserviceproxy.timeout should handle everything... but...
** webserviceproxy.timeout has been set to 2400000 from the beginning?
** CoreX12GenericBatchFutureTimeToLive from 60 to 120
** FutureTimeToLive from 60 to 120

So that's pretty much every instance of a 60 second timeout I could possibly find, all bumped to 120 seconds, but (after several restarts) I'm still timing out after 60 seconds!

What am I missing here?
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.2

Minh
Administrator
Hi John,

Can you double check that you are using CONNECT 4.4.2 since we officially haven't release 4.4.2?  In the meantime, let me try to duplicate (4.4.x) in my local and see what happens.
If you don't mind, what org/gov agency do you support?

Thanks,
Minh-Hai Nguyen
CONNECT Product Team Member
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.2

johnhd_at_zen
Hi Minh-Hai,

Sorry about that. CONNECT 4.4.1* not 4.4.2. I corrected the original post.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.2

johnhd_at_zen
In reply to this post by Minh
Sorry, I need to learn to read complete thoughts:

Minh wrote
If you don't mind, what org/gov agency do you support?
This is on behalf of a medium-sized HIE, who is Ehealth-Exchange onboard, in California. The queries are coming from another EHEX partner. I can PM you more specific information if that would be useful for you?
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.2

Minh
Administrator
Hi
When I look at the error log in yr first post, it tries to communicate to https://localhost:11443/NhinInterfaceWSService/NhinInterfaceWS.  Are you trying to target yourself?  60 seconds timeout regarding what you change in properties sounds like SSL communication issue.  Does this always happen to this organization? Make sure you have public certification from target gateway in your local cacert.jks.  If possible, can you gather clean server log with ssl debug on (-Djavax.net.debug=all)?
Minh-Hai Nguyen
CONNECT Product Team Member
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Caused by: java.net.SocketTimeoutException: Read timed out - CONNECT 4.4.2

johnhd_at_zen
Minh wrote
Hi
When I look at the error log in yr first post, it tries to communicate to https://localhost:11443/NhinInterfaceWSService/NhinInterfaceWS.  Are you trying to target yourself?  60 seconds timeout regarding what you change in properties sounds like SSL communication issue.  Does this always happen to this organization? Make sure you have public certification from target gateway in your local cacert.jks.  If possible, can you gather clean server log with ssl debug on (-Djavax.net.debug=all)?
Yes, this is the CONNECT gateway timing out waiting for a response from the CDR (where the patient data actually resides) on the same server. I'm able to get results for many other patients so I can safely rule out a SSL issue. The CDR is responding very slowly to marshall a response to a DocumentQuery for large patients. I've ticketed this with the vendor already.

I was actually able to finally get the timeout to change. There was a setting I missed in adapter.properties:

NhinInterfaceWSDocumentQueryReceiveTimeout=60000

I changed this to 120000 and restarted the gateway. One large patient succeeded after a little over 60 seconds. The other timed out at 2 minutes, meaning the change took effect.

Success!

I haven't played around with it to determine if this also depended on any of my above mentioned changes or if this is completely independent. I'll leave that as an exercise to the future reader who may benefit from this post. :)

Thanks!



Loading...