Getting "Read Timed Out" while Reading Files Using the FTP Adapter in a BPEL Process (Doc ID 1363508.1)

Last updated on NOVEMBER 03, 2016

Applies to:

Oracle SOA Suite - Version 11.1.1.4.0 and later
Information in this document applies to any platform.
***Checked for relevance on 05-Apr-2013***

Symptoms

In SOA 11.1.1.4

Reading files with FtpAdapter gives errors "java.net.SocketTimeoutException" see error stack below

[2011-07-25T05:00:25.942+00:00] [soa_ms_1] [ERROR] [] [oracle.soa.adapter] [tid: orabpel.invoke.pool-4.thread-5] [userId: <anonymous>] [ecid: 5bce2d8dceba2cb5:-3f963e2f:1315c61bf30:-8000-0000000000013ad6,0:1:100000617] [APP: soa-infra] [composite_name: EMR_Knuerr_PO_Document_Archive] [component_name: EMR_Knuerr_PO_Document_Archive] [component_instance_id: 190309] JCABinding=> EMR_Knuerr_PO_Document_Archive:Read_InvoicePDF_FTP [ SynchRead_ptt::SynchRead(Empty,opaque) ] Could not invoke operation 'SynchRead' against the 'Ftp Adapter' due to: [[
BINDING.JCA-11007
No Data to process.
No Data to process.
File /dianaap/dianacomn/admin/out/diana_dianadb1/o46041463.pdf to be processed was not found or not available or has no content
Please make sure that the file exists in the specified directory.

]]
[2011-07-25T05:00:25.980+00:00] [soa_ms_1] [NOTIFICATION] [] [oracle.soa.adapter] [tid: orabpel.invoke.pool-4.thread-5] [userId: <anonymous>] [ecid: 5bce2d8dceba2cb5:-3f963e2f:1315c61bf30:-8000-0000000000013ad6,0:1:100000617] [APP: soa-infra] [composite_name: EMR_Knuerr_PO_Document_Archive] [component_name: EMR_Knuerr_PO_Document_Archive] [component_instance_id: 190309] JCABinding=> EMR_Knuerr_PO_Document_Archive:Read_InvoicePDF_FTP [ SynchRead_ptt::SynchRead(Empty,opaque) ] Change logging level to TRACE:n to see full error stack
[2011-07-25T05:00:26.718+00:00] [soa_ms_1] [ERROR] [] [oracle.soa.adapter] [tid: orabpel.invoke.pool-4.thread-5] [userId: <anonymous>] [ecid: 5bce2d8dceba2cb5:-3f963e2f:1315c61bf30:-8000-0000000000013ad6,0:1:100000617] [APP: soa-infra] [composite_name: EMR_Knuerr_PO_Document_Archive] [component_name: EMR_Knuerr_PO_Document_Archive] [component_instance_id: 190309] JCABinding=> [default/EMR_Knuerr_PO_Document_Archive!1.0*soa_de08baf8-8e47-43d6-8998-96d2ae10adf1.Read_InvoicePDF_FTP]:SynchRead Two-way operation SynchRead() failed
[2011-07-25T05:00:26.762+00:00] [soa_ms_1] [ERROR] [] [oracle.soa.bpel.engine.ws] [tid: orabpel.invoke.pool-4.thread-5] [userId: <anonymous>] [ecid: 5bce2d8dceba2cb5:-3f963e2f:1315c61bf30:-8000-0000000000013ad6,0:1:100000617] [APP: soa-infra] [composite_name: EMR_Knuerr_PO_Document_Archive] [component_name: EMR_Knuerr_PO_Document_Archive] [component_instance_id: 190309] got FabricInvocationException[[
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
at java.io.InputStreamReader.read(InputStreamReader.java:167)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.io.BufferedReader.readLine(BufferedReader.java:299)
at java.io.BufferedReader.readLine(BufferedReader.java:362)
at oracle.tip.adapter.ftp.FTP.getReply(FTP.java:697)
at oracle.tip.adapter.ftp.FTP.sendCommand(FTP.java:681)
at oracle.tip.adapter.ftp.FTP.pass(FTP.java:1083)
at oracle.tip.adapter.ftp.FTPClient.regularLogin(FTPClient.java:1635)
at oracle.tip.adapter.ftp.FTPClient.login(FTPClient.java:1593)
at oracle.tip.adapter.ftp.FTPAgent.login(FTPAgent.java:1170)
at oracle.tip.adapter.ftp.FTPAgent.preCall(FTPAgent.java:1632)
at oracle.tip.adapter.ftp.FTPAgent.getBinaryFileAsStream(FTPAgent.java:634)
at oracle.tip.adapter.ftp.FTPAgent.getContentAsStream(FTPAgent.java:700)
at oracle.tip.adapter.ftp.inbound.FTPSource.getContents(FTPSource.java:987)
at oracle.tip.adapter.ftp.inbound.FTPSource.getFileFromSource(FTPSource.java:912)
at oracle.tip.adapter.file.outbound.FileReader.readFile(FileReader.java:266)
at oracle.tip.adapter.file.outbound.FileReader.executeFileRead(FileReader.java:181)
at oracle.tip.adapter.file.outbound.FileInteraction.executeFileRead(FileInteraction.java:331)
at oracle.tip.adapter.ftp.outbound.FTPInteraction.execute(FTPInteraction.java:210)
at oracle.integration.platform.blocks.adapter.fw.jca.cci.JCAInteractionInvoker.executeJcaInteraction(JCAInteractionInvoker.java:311)
at oracle.integration.platform.blocks.adapter.fw.jca.cci.JCAInteractionInvoker.invokeJcaReference(JCAInteractionInvoker.java:548)
at oracle.integration.platform.blocks.adapter.fw.jca.cci.JCAInteractionInvoker.invokeSyncJcaReference(JCAInteractionInvoker.java:498)
at oracle.integration.platform.blocks.adapter.fw.jca.cci.JCAEndpointInteraction.performSynchronousInteraction(JCAEndpointInteraction.java:472)
at oracle.integration.platform.blocks.adapter.AdapterReference.request(AdapterReference.java:166)
at oracle.integration.platform.blocks.mesh.SynchronousMessageHandler.doRequest(SynchronousMessageHandler.java:139)
at oracle.integration.platform.blocks.mesh.MessageRouter.request(MessageRouter.java:179)
at oracle.integration.platform.blocks.mesh.MeshImpl.request(MeshImpl.java:155)
at sun.reflect.GeneratedMethodAccessor998.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
at oracle.integration.platform.metrics.PhaseEventAspect.invoke(PhaseEventAspect.java:71)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy299.request(Unknown Source)
at oracle.fabric.CubeServiceEngine.requestToMesh(CubeServiceEngine.java:820)
at com.collaxa.cube.ws.WSInvocationManager.invoke(WSInvocationManager.java:263)
at com.collaxa.cube.engine.ext.common.InvokeHandler.__invoke(InvokeHandler.java:1056)
at com.collaxa.cube.engine.ext.common.InvokeHandler.handleNormalInvoke(InvokeHandler.java:583)
at com.collaxa.cube.engine.ext.common.InvokeHandler.handle(InvokeHandler.java:130)
at com.collaxa.cube.engine.ext.bpel.common.wmp.BPELInvokeWMP.__executeStatements(BPELInvokeWMP.java:74)
at com.collaxa.cube.engine.ext.bpel.common.wmp.BaseBPELActivityWMP.perform(BaseBPELActivityWMP.java:158)
at com.collaxa.cube.engine.CubeEngine._performActivity(CubeEngine.java:2463)
at com.collaxa.cube.engine.CubeEngine.performActivity(CubeEngine.java:2334)
at com.collaxa.cube.engine.CubeEngine.handleWorkItem(CubeEngine.java:1115)
at com.collaxa.cube.engine.dispatch.message.instance.PerformMessageHandler.handleLocal(PerformMessageHandler.java:73)
at com.collaxa.cube.engine.dispatch.DispatchHelper.handleLocalMessage(DispatchHelper.java:220)
at com.collaxa.cube.engine.dispatch.DispatchHelper.sendMemory(DispatchHelper.java:328)
at com.collaxa.cube.engine.CubeEngine.endRequest(CubeEngine.java:4350)
at com.collaxa.cube.engine.CubeEngine.endRequest(CubeEngine.java:4281)
at com.collaxa.cube.engine.CubeEngine.createAndInvoke(CubeEngine.java:679)
at com.collaxa.cube.engine.delivery.DeliveryService.handleInvoke(DeliveryService.java:654)
at com.collaxa.cube.engine.ejb.impl.CubeDeliveryBean.handleInvoke(CubeDeliveryBean.java:293)
at sun.reflect.GeneratedMethodAccessor977.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:310)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
at com.bea.core.repackaged.springframework.jee.intercept.MethodInvocationInvocationContext.proceed(MethodInvocationInvocationContext.java:104)
at oracle.security.jps.ee.ejb.JpsAbsInterceptor$1.run(JpsAbsInterceptor.java:94)
at java.security.AccessController.doPrivileged(Native Method)
at oracle.security.jps.util.JpsSubject.doAsPrivileged(JpsSubject.java:313)
at oracle.security.jps.ee.util.JpsPlatformUtil.runJaasMode(JpsPlatformUtil.java:413)
at oracle.security.jps.ee.ejb.JpsAbsInterceptor.runJaasMode(JpsAbsInterceptor.java:81)
at oracle.security.jps.ee.ejb.JpsAbsInterceptor.intercept(JpsAbsInterceptor.java:112)
at oracle.security.jps.ee.ejb.JpsInterceptor.intercept(JpsInterceptor.java:105)
at sun.reflect.GeneratedMethodAccessor822.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:310)
at com.bea.core.repackaged.springframework.jee.intercept.JeeInterceptorInterceptor.invoke(JeeInterceptorInterceptor.java:69)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
at com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at com.bea.core.repackaged.springframework.jee.spi.MethodInvocationVisitorImpl.visit(MethodInvocationVisitorImpl.java:37)
at weblogic.ejb.container.injection.EnvironmentInterceptorCallbackImpl.callback(EnvironmentInterceptorCallbackImpl.java:54)
at com.bea.core.repackaged.springframework.jee.spi.EnvironmentInterceptor.invoke(EnvironmentInterceptor.java:50)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at com.bea.core.repackaged.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
at com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
at com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at com.bea.core.repackaged.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy282.handleInvoke(Unknown Source)
at com.collaxa.cube.engine.ejb.impl.bpel.BPELDeliveryBean_5k948i_ICubeDeliveryLocalBeanImpl.__WL_invoke(Unknown Source)
at weblogic.ejb.container.internal.SessionLocalMethodInvoker.invoke(SessionLocalMethodInvoker.java:39)
at com.collaxa.cube.engine.ejb.impl.bpel.BPELDeliveryBean_5k948i_ICubeDeliveryLocalBeanImpl.handleInvoke(Unknown Source)
at com.collaxa.cube.engine.dispatch.message.invoke.InvokeInstanceMessageHandler.handle(InvokeInstanceMessageHandler.java:35)
at com.collaxa.cube.engine.dispatch.DispatchHelper.handleMessage(DispatchHelper.java:140)
at com.collaxa.cube.engine.dispatch.BaseDispatchTask.process(BaseDispatchTask.java:88)
at com.collaxa.cube.engine.dispatch.BaseDispatchTask.run(BaseDispatchTask.java:64)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)

]]



Analyzing tcp dumps

The following conclusion could be drawn from analyzing tcp dumps of the communication between the ftp adapter and the ftp server. The tcp dumps were created to contain data and analyzed with Wireshark 6.2.1, a third-party tool.

The procedure of hand-shake with the ftp server passing user name and password was repeated many times before any attempt to set pasv mode happened. The set pasv mode happened once, and then a download a file started but never completed.
A new download was repeated later on, only this time it succeeded when receiving a transfer complete message from the ftp server.
Finally a few more packages arrived, probably from the first download and a second transfer complete message was received.

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms