MULE-4 : SFTP Connection is not re-establishing after connection failure

Question

We are reading new or updated files for every 1 minute on SFTP server using SFTP

<sftp:listener doc:name="On New or Updated File"  config-ref="SFTP_Config" directory="abc/in" timeBetweenSizeCheck="2000" autoDelete="true" timeBetweenSizeCheckUnit="MILLISECONDS">
            <reconnect-forever frequency="60000" />
            <scheduling-strategy >
                <fixed-frequency frequency="60000"/>
            </scheduling-strategy>
        </sftp:listener>

Sometimes when sftp server is down it is trying to reconnect, as we given reconnect forever its keep on trying. Even after SFTP server is back online again, its not able to read files. I even tried giving reconnection attempts as 2, it was trying for 2 times and throwing error as pipe is closed. When SFTP server is online again, even though there are new files available it is not picking up.

Anyone faced this issue with Mule 4 SFTP connector (v1.3.10). Please help me out.

Below is the error message

[2020-12-04 10:04:34.662] ERROR  
org.mule.extension.sftp.internal.source.SftpDirectoryListener
[_pollingSource_sd-sftp-svc-flow/executor.01]: Found exception trying
to poll directory '/ABC/xyz/In/'. Will try again on the next poll. 
org.mule.runtime.api.exception.MuleRuntimeException: Found exception
trying to obtain path /ABC/xyz/In/  at
org.mule.extension.file.common.api.command.AbstractFileCommand.exception(AbstractFileCommand.java:209)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getFile(SftpCommand.java:92)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getExistingFile(SftpCommand.java:71)
    at
org.mule.extension.sftp.internal.command.SftpListCommand.list(SftpListCommand.java:77)
    at
org.mule.extension.file.common.api.AbstractFileSystem.list(AbstractFileSystem.java:112)
    at
org.mule.extension.sftp.internal.source.SftpDirectoryListener.poll(SftpDirectoryListener.java:184)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.lambda$poll$3(PollingSourceWrapper.java:193)
    at
org.mule.runtime.core.api.util.func.CheckedRunnable.run(CheckedRunnable.java:22)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.withWatermarkLock(PollingSourceWrapper.java:492)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.poll(PollingSourceWrapper.java:190)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.lambda$onStart$1(PollingSourceWrapper.java:143)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.DelegateRunnable.run(DelegateRunnable.java:41)
    at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)     at
org.mule.service.scheduler.internal.AbstractRunnableFutureDecorator.doRun(AbstractRunnableFutureDecorator.java:111)
    at
org.mule.service.scheduler.internal.RunnableRepeatableFutureDecorator.run(RunnableRepeatableFutureDecorator.java:83)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748) Caused by:
org.mule.runtime.api.exception.MuleRuntimeException: Could not obtain
attributes for path /ABC/xyz/In/    at
org.mule.extension.sftp.internal.connection.SftpClient.exception(SftpClient.java:415)
    at
org.mule.extension.sftp.internal.connection.SftpClient.exception(SftpClient.java:409)
    at
org.mule.extension.sftp.internal.connection.SftpClient.getAttributes(SftpClient.java:142)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getFile(SftpCommand.java:88)
    ... 17 more Caused by:
org.mule.runtime.api.connection.ConnectionException:    ... 20 more
Caused by: 4:   at
com.jcraft.jsch.ChannelSftp.stat(ChannelSftp.java:2204)     at
org.mule.extension.sftp.internal.connection.SftpClient.getAttributes(SftpClient.java:137)
    ... 18 more Caused by: java.io.IOException: Pipe closed     at
java.io.PipedInputStream.read(PipedInputStream.java:307)    at
com.jcraft.jsch.Channel$MyPipedInputStream.updateReadSide(Channel.java:362)
    at com.jcraft.jsch.ChannelSftp.stat(ChannelSftp.java:2194)  ... 19
more


[2020-12-04 10:04:34.769] WARN   
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource
[_pollingSource_sd-sftp-svc-flow/executor.01]: Message source
'listener' on flow 'sd-sftp-svc-flow' threw exception. Attempting to
reconnect... org.mule.runtime.api.connection.ConnectionException:   at
org.mule.extension.sftp.internal.connection.SftpClient.exception(SftpClient.java:409)
    at
org.mule.extension.sftp.internal.connection.SftpClient.getAttributes(SftpClient.java:142)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getFile(SftpCommand.java:88)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getExistingFile(SftpCommand.java:71)
    at
org.mule.extension.sftp.internal.command.SftpListCommand.list(SftpListCommand.java:77)
    at
org.mule.extension.file.common.api.AbstractFileSystem.list(AbstractFileSystem.java:112)
    at
org.mule.extension.sftp.internal.source.SftpDirectoryListener.poll(SftpDirectoryListener.java:184)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.lambda$poll$3(PollingSourceWrapper.java:193)
    at
org.mule.runtime.core.api.util.func.CheckedRunnable.run(CheckedRunnable.java:22)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.withWatermarkLock(PollingSourceWrapper.java:492)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.poll(PollingSourceWrapper.java:190)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.lambda$onStart$1(PollingSourceWrapper.java:143)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.DelegateRunnable.run(DelegateRunnable.java:41)
    at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)     at
org.mule.service.scheduler.internal.AbstractRunnableFutureDecorator.doRun(AbstractRunnableFutureDecorator.java:111)
    at
org.mule.service.scheduler.internal.RunnableRepeatableFutureDecorator.run(RunnableRepeatableFutureDecorator.java:83)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748) Caused by: 4:      at
com.jcraft.jsch.ChannelSftp.stat(ChannelSftp.java:2204)     at
org.mule.extension.sftp.internal.connection.SftpClient.getAttributes(SftpClient.java:137)
    ... 18 more Caused by: java.io.IOException: Pipe closed     at
java.io.PipedInputStream.read(PipedInputStream.java:307)    at
com.jcraft.jsch.Channel$MyPipedInputStream.updateReadSide(Channel.java:362)
    at com.jcraft.jsch.ChannelSftp.stat(ChannelSftp.java:2194)  ... 19
more


[2020-12-04 10:04:34.832] ERROR  
org.mule.runtime.core.api.retry.policy.ConnectNotifier
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Failed to connect/reconnect: Message Source Reconnection.
Root Exception was: Pipe closed. Type: class java.io.IOException
[2020-12-04 10:04:34.833] INFO   
org.mule.runtime.core.internal.retry.policies.SimpleRetryPolicy
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Waiting for 2000ms before reconnecting. Failed attempt 1
of 2 [2020-12-04 10:04:36.846] ERROR  
org.mule.runtime.core.api.retry.policy.ConnectNotifier
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Failed to connect/reconnect: Message Source Reconnection.
Root Exception was: Pipe closed. Type: class java.io.IOException
[2020-12-04 10:04:36.846] INFO   
org.mule.runtime.core.internal.retry.policies.SimpleRetryPolicy
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Waiting for 2000ms before reconnecting. Failed attempt 2
of 2 [2020-12-04 10:04:38.858] ERROR  
org.mule.runtime.core.api.retry.policy.ConnectNotifier
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Failed to connect/reconnect: Message Source Reconnection.
Root Exception was: Pipe closed. Type: class java.io.IOException
[2020-12-04 10:04:38.860] ERROR  
org.mule.runtime.core.internal.retry.async.RetryWorker
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Error retrying work
org.mule.runtime.core.api.retry.policy.RetryPolicyExhaustedException: 
    at
org.mule.runtime.core.api.retry.policy.AbstractPolicyTemplate.execute(AbstractPolicyTemplate.java:78)
    at
org.mule.runtime.core.internal.retry.async.RetryWorker.run(RetryWorker.java:56)
    at
org.mule.runtime.core.internal.util.rx.ImmediateScheduler.execute(ImmediateScheduler.java:150)
    at
org.mule.runtime.core.api.retry.async.AsynchronousRetryTemplate.execute(AsynchronousRetryTemplate.java:66)
    at
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.startSource(ExtensionMessageSource.java:209)
    at
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.restart(ExtensionMessageSource.java:350)
    at
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$5(ExtensionMessageSource.java:316)
    at reactor.core.publisher.MonoCreate.subscribe(MonoCreate.java:57)
    at
reactor.core.publisher.MonoPeekTerminal.subscribe(MonoPeekTerminal.java:57)
    at
reactor.core.publisher.MonoPeekTerminal.subscribe(MonoPeekTerminal.java:61)
    at
reactor.core.publisher.MonoPeekFuseable.subscribe(MonoPeekFuseable.java:74)
    at reactor.core.publisher.Mono.subscribe(Mono.java:3858)    at
reactor.core.publisher.Mono.subscribeWith(Mono.java:3964)   at
reactor.core.publisher.Mono.subscribe(Mono.java:3743)   at
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$onException$9(ExtensionMessageSource.java:327)
    at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)     at
org.mule.service.scheduler.internal.AbstractRunnableFutureDecorator.doRun(AbstractRunnableFutureDecorator.java:111)
    at
org.mule.service.scheduler.internal.RunnableFutureDecorator.run(RunnableFutureDecorator.java:54)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748) Caused by:
org.mule.runtime.api.connection.ConnectionException:    at
org.mule.extension.sftp.internal.connection.SftpClient.exception(SftpClient.java:409)
    at
org.mule.extension.sftp.internal.connection.SftpClient.getAttributes(SftpClient.java:142)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getFile(SftpCommand.java:88)
    at
org.mule.extension.sftp.internal.command.SftpCommand.getFile(SftpCommand.java:81)
    at
org.mule.extension.sftp.internal.command.SftpCommand.exists(SftpCommand.java:111)
    at
org.mule.extension.sftp.internal.command.SftpCommand.exists(SftpCommand.java:41)
    at
org.mule.extension.file.common.api.command.AbstractFileCommand.resolveExistingPath(AbstractFileCommand.java:135)
    at
org.mule.extension.sftp.internal.source.OnNewFileCommand.resolveRootPath(OnNewFileCommand.java:32)
    at
org.mule.extension.sftp.internal.source.SftpDirectoryListener.resolveRootPath(SftpDirectoryListener.java:307)
    at
org.mule.extension.sftp.internal.source.SftpDirectoryListener.doStart(SftpDirectoryListener.java:144)
    at
org.mule.runtime.extension.api.runtime.source.PollingSource.onStart(PollingSource.java:44)
    at
org.mule.runtime.module.extension.internal.runtime.source.poll.PollingSourceWrapper.onStart(PollingSourceWrapper.java:120)
    at
org.mule.runtime.module.extension.internal.runtime.source.SourceAdapter.start(SourceAdapter.java:412)
    at
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource$StartSourceCallback.doWork(ExtensionMessageSource.java:548)
    at
org.mule.runtime.core.api.retry.policy.AbstractPolicyTemplate.execute(AbstractPolicyTemplate.java:52)
    ... 21 more Caused by: 4:   at
com.jcraft.jsch.ChannelSftp._stat(ChannelSftp.java:2235)    at
com.jcraft.jsch.ChannelSftp._stat(ChannelSftp.java:2242)    at
com.jcraft.jsch.ChannelSftp.stat(ChannelSftp.java:2199)     at
org.mule.extension.sftp.internal.connection.SftpClient.getAttributes(SftpClient.java:137)
    ... 34 more Caused by: java.io.IOException: Pipe closed     at
java.io.PipedInputStream.read(PipedInputStream.java:307)    at
java.io.PipedInputStream.read(PipedInputStream.java:377)    at
com.jcraft.jsch.ChannelSftp.fill(ChannelSftp.java:2909)     at
com.jcraft.jsch.ChannelSftp.header(ChannelSftp.java:2935)   at
com.jcraft.jsch.ChannelSftp._stat(ChannelSftp.java:2216)    ... 37 more


[2020-12-04 10:04:38.867] WARN   
org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource
[[MuleRuntime].uber.11:
[phm-sd-prchs-ord-app-dev].uber@org.mule.runtime.module.extension.internal.runtime.source.ExtensionMessageSource.lambda$null$10:370
@314deb18]: Message source 'listener' on flow 'sd-sftp-svc-flow'
successfully reconnected

What is the Mule version? Please add the complete error message to the question. — aled, Dec 09 '20 at 19:03
It looks like it reconnected at `10:04:38.867`. Did it by itself? — aled, Dec 10 '20 at 12:24
It says its reconnected. But when we place a file in sftp server, we don't see file getting picked-up and no logs. — Prudhvi B, Dec 10 '20 at 13:33
I am trying out with below code to avoid this issue. Currently we are monitoring application whether this change fixed the issue or not. Once we know it got resolved I will update here and close the question. ` ` — Prudhvi B, Dec 12 '20 at 05:27
Hey, did you solved the questions? Or still using the pooling profile maxIdle? — Claudio Lopes, Jun 11 '21 at 14:31
Just out of curiosity, is there a solution to this? I am fighting the same battle it seems. — BigDevJames, Jun 18 '21 at 14:44
@BigDevJames Using maxidle did resolve issue but it is initiating new connection for every call which is not optimal for my application which has 5 calls for a transaction. So changed code to run on scheduler and pull all the files using list component. — Prudhvi B, Jul 06 '21 at 08:22

score 0 · Answer 1 · answered Jul 13 '21 at 22:03

We had the same issue with 1.3.10 version of Mule 4 SFTP connector and we raised the issue with Muelsoft and after lot of deliberation they fixed this issue in the latest 1.4.0 version of SFTP connector. Here is the official release notes and comment from Mulesoft

Engineering team has fixed the issue in SFTP connector and the official fix is included in SFTP connector v1.4.0 and has been released. https://docs.mulesoft.com/release-notes/connector/connector-sftp#1-4-0

score 0 · Answer 2 · answered Sep 07 '21 at 19:49

0

this error occurs due to SFTP server has been unavailable or there might be once your flow disconnected with SFTP server. Flow is not reconnecting again. like in attached image SFTP Reconnection setup click here

answered Sep 07 '21 at 19:49

Raja Ram Sharma

1
2

score 0 · Answer 3 · answered Mar 08 '22 at 16:03

I had the same issue but with the version 1.4.0. @Sandeep Karnati told that 1.4.0 would fix the problem. But i found in the mulesoft docs there is a new version 1.4.1 which according to MuleSoft fixes this problem. https://docs.mulesoft.com/release-notes/connector/connector-sftp#1-4-0

I am curious if this works for me.

MULE-4 : SFTP Connection is not re-establishing after connection failure

3 Answers3