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

user_5251135 0
Viewed 2204

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
mule4 sftp connection
3 Answers

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

user_164429130

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

user_96361220
user_41128370
Related