OSB FTP Poller continuously throwing exception – while no file pending on FTP Location


We have been recently facing an issue with an OSB Proxy using FTP Protocol, where in we kept getting the errors on the logs even when we were not putting new files in.

Errors lead us to believe there were some permission issues.

Unable to get file NYSolutionsSourcedir/43646343-dfh34d2.232dfg3d__testFile.txt.Stage on attempt number 0: java.io.IOException: Data: OpenSocket, Permission Denied? java.io.IOException: Data: OpenSocket, Permission Denied?

It ultimately lead to stuck threads and other issues on the server.

We even tried to restart the servers but still faced the same issue.

Stack Trace.

Unable to get file NYSolutionsSourcedir/43646343-dfh34d2.232dfg3d__testFile.txt.Stage on attempt number 0: java.io.IOException: Data: OpenSocket, Permission Denied? java.io.IOException: Data: OpenSocket, Permission Denied? at com.bea.wli.sb.transports.ftp.resource.FtpClient.openPassiveDataSocket(FtpClient.java:1349) at com.bea.wli.sb.transports.ftp.resource.FtpClient.executeDataCommand_in_PassiveMode(FtpClient.java:1526) at com.bea.wli.sb.transports.ftp.resource.FTPResource.getDataInputStream_in_PassiveMode(FTPResource.java:1398) at com.bea.wli.sb.transports.ftp.resource.FTPSource.getInputStream(FTPSource.java:52) at com.bea.wli.sb.transports.ftp.resource.FTPSource.writeTo(FTPSource.java:59) at com.bea.wli.sb.sources.StringTransformer.transform(StringTransformer.java:81) at com.bea.wli.sb.sources.MetaTransformer.doTransform(MetaTransformer.java:138) at com.bea.wli.sb.sources.MetaTransformer.transform(MetaTransformer.java:89) at com.bea.wli.sb.pipeline.PipelineContextImpl$LazyInitTransformer.transform(PipelineContextImpl.java:1694) at com.bea.wli.sb.context.SOAPMessageImpl.parseCheckPayload(SOAPMessageImpl.java:1227) at com.bea.wli.sb.context.SOAPMessageImpl.generateBody(SOAPMessageImpl.java:1040) at com.bea.wli.sb.context.SOAPMessageImpl.getBody(SOAPMessageImpl.java:260) at com.bea.wli.sb.context.BodyVariable.getTypedValue(BodyVariable.java:106) at com.bea.wli.sb.context.BodyVariable.getTypedValue(BodyVariable.java:25) at com.bea.wli.sb.context.SystemVariable.getValue(SystemVariable.java:49) at com.bea.wli.sb.context.MessageContextImpl.getVariableValue(MessageContextImpl.java:233) at com.bea.wli.sb.stages.expressions.xquery.XQueryExprExecutor.getVariables(XQueryExprExecutor.java:182) at com.bea.wli.sb.stages.expressions.xquery.XQueryExprExecutor.executeJavaObject(XQueryExprExecutor.java:129) at com.bea.wli.sb.stages.expressions.xquery.XQueryTransformExecutor.getVariables(XQueryTransformExecutor.java:216) at com.bea.wli.sb.stages.expressions.xquery.XQueryTransformExecutor.execute(XQueryTransformExecutor.java:108) at com.bea.wli.sb.stages.expressions.xquery.XQueryTransformExecutor.execute(XQueryTransformExecutor.java:90) at stages.transform.runtime.AssignRuntimeStep.processMessage(AssignRuntimeStep.java:51) at com.bea.wli.sb.stages.StageMetadataImpl$WrapperRuntimeStep.processMessage(StageMetadataImpl.java:346) at com.bea.wli.sb.stages.impl.SequenceRuntimeStep.processMessage(SequenceRuntimeStep.java:33) at com.bea.wli.sb.pipeline.PipelineStage.processMessage(PipelineStage.java:84) at com.bea.wli.sb.pipeline.PipelineContextImpl.execute(PipelineContextImpl.java:1098) at com.bea.wli.sb.pipeline.Pipeline.processMessage(Pipeline.java:141) at com.bea.wli.sb.pipeline.PipelineContextImpl.execute(PipelineContextImpl.java:1098) at com.bea.wli.sb.pipeline.PipelineNode.doRequest(PipelineNode.java:55) at com.bea.wli.sb.pipeline.Node.processMessage(Node.java:67) at com.bea.wli.sb.pipeline.PipelineContextImpl.execute(PipelineContextImpl.java:1098) at com.bea.wli.sb.pipeline.Router.processMessage(Router.java:214) at com.bea.wli.sb.pipeline.MessageProcessor.processRequest(MessageProcessor.java:101) at com.bea.wli.sb.pipeline.RouterManager$1.run(RouterManager.java:597) at com.bea.wli.sb.pipeline.RouterManager$1.run(RouterManager.java:595) at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:363) at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:146) at com.bea.wli.sb.security.WLSSecurityContextService.runAs(WLSSecurityContextService.java:55) at com.bea.wli.sb.pipeline.RouterManager.processMessage(RouterManager.java:594) at com.bea.wli.sb.transports.TransportManagerImpl.receiveMessage(TransportManagerImpl.java:398) at com.bea.wli.sb.transports.ftp.connector.FTPPublishedTask.processDirectStreaming(FTPPublishedTask.java:292) at com.bea.wli.sb.transports.ftp.connector.FTPPublishedTask.process(FTPPublishedTask.java:104) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB.__onMessage(PolledMessageListenerMDB.java:52) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB.access$000(PolledMessageListenerMDB.java:31) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB$1.run(PolledMessageListenerMDB.java:41) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB$1.run(PolledMessageListenerMDB.java:39) at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321) at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120) at weblogic.security.Security.runAs(Security.java:41) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB.onMessage(PolledMessageListenerMDB.java:39) at weblogic.ejb.container.internal.MDListener.execute(MDListener.java:583) at weblogic.ejb.container.internal.MDListener.transactionalOnMessage(MDListener.java:486) at weblogic.ejb.container.internal.MDListener.onMessage(MDListener.java:388) at weblogic.jms.client.JMSSession.onMessage(JMSSession.java:4659) at weblogic.jms.client.JMSSession.execute(JMSSession.java:4345) at weblogic.jms.client.JMSSession.executeMessage(JMSSession.java:3821) at weblogic.jms.client.JMSSession.access$000(JMSSession.java:115) at weblogic.jms.client.JMSSession$UseForRunnable.run(JMSSession.java:5170) at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:531) at weblogic.work.ExecuteThread.execute(ExecuteThread.java:252) at weblogic.work.ExecuteThread.run(ExecuteThread.java:221) Caused By: java.lang.Exception: 550 Failed to open file. at com.bea.wli.sb.transports.ftp.resource.FtpClient.openPassiveDataSocket(FtpClient.java:1330) at com.bea.wli.sb.transports.ftp.resource.FtpClient.executeDataCommand_in_PassiveMode(FtpClient.java:1526) at com.bea.wli.sb.transports.ftp.resource.FTPResource.getDataInputStream_in_PassiveMode(FTPResource.java:1398) at com.bea.wli.sb.transports.ftp.resource.FTPSource.getInputStream(FTPSource.java:54) at com.bea.wli.sb.transports.ftp.resource.FTPSource.writeTo(FTPSource.java:60) at com.bea.wli.sb.sources.StringTransformer.transform(StringTransformer.java:81) at com.bea.wli.sb.sources.MetaTransformer.doTransform(MetaTransformer.java:138) at com.bea.wli.sb.pipeline.PipelineContextImpl$LazyInitTransformer.transform(PipelineContextImpl.java:1694) at com.bea.wli.sb.context.SOAPMessageImpl.parseCheckPayload(SOAPMessageImpl.java:1227) at com.bea.wli.sb.context.SOAPMessageImpl.generateBody(SOAPMessageImpl.java:1040) at com.bea.wli.sb.context.SOAPMessageImpl.getBody(SOAPMessageImpl.java:260) at com.bea.wli.sb.context.BodyVariable.getTypedValue(BodyVariable.java:106) at com.bea.wli.sb.context.BodyVariable.getTypedValue(BodyVariable.java:25) at com.bea.wli.sb.context.SystemVariable.getValue(SystemVariable.java:49) at com.bea.wli.sb.context.MessageContextImpl.getVariableValue(MessageContextImpl.java:233) at com.bea.wli.sb.stages.expressions.xquery.XQueryExprExecutor.executeJavaObject(XQueryExprExecutor.java:129) at com.bea.wli.sb.stages.expressions.xquery.XQueryTransformExecutor.execute(XQueryTransformExecutor.java:90) at stages.transform.runtime.AssignRuntimeStep.processMessage(AssignRuntimeStep.java:54) at com.bea.wli.sb.stages.StageMetadataImpl$WrapperRuntimeStep.processMessage(StageMetadataImpl.java:346) at com.bea.wli.sb.stages.impl.SequenceRuntimeStep.processMessage(SequenceRuntimeStep.java:33) at com.bea.wli.sb.pipeline.PipelineStage.processMessage(PipelineStage.java:84) at com.bea.wli.sb.pipeline.PipelineContextImpl.execute(PipelineContextImpl.java:1098) at com.bea.wli.sb.pipeline.Pipeline.processMessage(Pipeline.java:141) at com.bea.wli.sb.pipeline.PipelineContextImpl.execute(PipelineContextImpl.java:1098) at com.bea.wli.sb.pipeline.PipelineNode.doRequest(PipelineNode.java:55) at com.bea.wli.sb.pipeline.Node.processMessage(Node.java:67) at com.bea.wli.sb.pipeline.PipelineContextImpl.execute(PipelineContextImpl.java:1098) at com.bea.wli.sb.pipeline.Router.processMessage(Router.java:214) at com.bea.wli.sb.pipeline.MessageProcessor.processRequest(MessageProcessor.java:101) at com.bea.wli.sb.pipeline.RouterManager$1.run(RouterManager.java:598) at com.bea.wli.sb.pipeline.RouterManager$1.run(RouterManager.java:595) at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:146) at com.bea.wli.sb.security.WLSSecurityContextService.runAs(WLSSecurityContextService.java:55) at com.bea.wli.sb.pipeline.RouterManager.processMessage(RouterManager.java:594) at com.bea.wli.sb.transports.TransportManagerImpl.receiveMessage(TransportManagerImpl.java:398) at com.bea.wli.sb.transports.ftp.connector.FTPPublishedTask.processDirectStreaming(FTPPublishedTask.java:292) at com.bea.wli.sb.transports.ftp.connector.FTPPublishedTask.process(FTPPublishedTask.java:104) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB.__onMessage(PolledMessageListenerMDB.java:52) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB.access$000(PolledMessageListenerMDB.java:31) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB$1.run(PolledMessageListenerMDB.java:42) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB$1.run(PolledMessageListenerMDB.java:39) at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120) at weblogic.security.Security.runAs(Security.java:41) at com.bea.wli.sb.transports.poller.listener.PolledMessageListenerMDB.onMessage(PolledMessageListenerMDB.java:45) at weblogic.ejb.container.internal.MDListener.onMessage(MDListener.java:388) at weblogic.jms.client.JMSSession.onMessage(JMSSession.java:4659) at weblogic.jms.client.JMSSession.execute(JMSSession.java:4345) at weblogic.jms.client.JMSSession.executeMessage(JMSSession.java:3822) at weblogic.jms.client.JMSSession.access$000(JMSSession.java:115) at weblogic.jms.client.JMSSession$UseForRunnable.run(JMSSession.java:5170) at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:531) at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)

Solution:

After much troubleshooting it felt something is stuck somewhere, the challenge was where…

Checking the error directory we found that file NYSolutionsSourcedir/43646343-dfh34d2.232dfg3d__testFile.txt.Stage was in this directory.

Then we identified that the message is stuck in the internal JMS queue.
In the WLS console, monitoring the JMS queue, there was 1 message in wlsb.internal.transport.task.queue.ftp.

Root Cause:

The file NYSolutionsSourcedir/43646343-dfh34d2.232dfg3d__testFile.txt.Stage in the stage directory cannot be processed correctly, so it was moved to the error directory. But some error occured, so that the message in wlsb.internal.transport.task.queue.ftp (poller-transport-specific JMS queue) was not discarded. This leads to the domain-wide message-driven bean (MDB) receiving the JMS task again and again, which triggers XA transaction to begin and rollback repeatedly.

Resolution Steps:

1. Delete message in wlsb.internal.transport.task.queue.ftp:

a. In the Administration Console, expand Services > Messaging > JMS Modules.
b. In the JMS Modules table, click JMS module: jmsResources.
c. In jmsResources’s Summary of Resources table, click the queue wlsb.internal.transport.task.queue.ftp.
d. Click the Monitoring > show Messages.
e. Choose the message which leads to this issue and delete it.
PS: Since we are using this proxy with a split join it had over 3 dozen messages for us, and hence we had to delete them all. but for others it may just be one message.

2. Reprocess: When you reprocess the file it will process correctly.

References: Oracle Support KB (Doc ID 1636352.1)

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s