spring spring-integration sftp apache-mina apache-sshd

Error while downloading with SftpInboundFileSynchronizingMessageSource Spring component a file to remove SFPT to a local directory

I have the following problem. I followed the documentation here and configured the SFTPInboundAdapter. An error occurs when the ssh client starts to download the file:

org.springframework.messaging.MessagingException: Failure occurred while copying 'remote-dir/MyFile.csv' from the remote to the local directory

The root cause is generic, and seems a bad response from the Server:

Caused by: SFTP error (SSH_FX_FAILURE): Failure

In the local directory I can see that the file has been created: remote-dir/MyFile.csv.writing, but the download didn't complete, the file size is zero.

Since the error is generic I enabled the debug level for org.apache.sshd.*. Before the exception is raised this is the log:

...
2024-05-06T16:19:21.445+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/my_ip, remote=sftp.server]) writing 80 bytes
2024-05-06T16:19:21.454+02:00 DEBUG 21336 --- []-nio2-thread-2] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[username@sftp.server]) process #190 SSH_MSG_CHANNEL_DATA
2024-05-06T16:19:21.455+02:00 DEBUG 21336 --- []-nio2-thread-2] o.a.sshd.common.channel.LocalWindow      : Consume LocalWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 2491 down to 2083722
2024-05-06T16:19:21.455+02:00 DEBUG 21336 --- []-nio2-thread-2] i.DefaultSftpClient$SftpChannelSubsystem : handleData(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) SSH_MSG_CHANNEL_DATA len=2491
2024-05-06T16:19:21.455+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.channel.RemoteWindow     : Consume RemoteWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 16 down to 2094190
2024-05-06T16:19:21.455+02:00 DEBUG 21336 --- [   scheduling-1] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[username@sftp.server]) packet #198 sending command=94[SSH_MSG_CHANNEL_DATA] len=25
2024-05-06T16:19:21.456+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/my_ip, remote=sftp.server]) writing 80 bytes
2024-05-06T16:19:21.464+02:00 DEBUG 21336 --- []-nio2-thread-4] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[username@sftp.server]) process #191 SSH_MSG_CHANNEL_DATA
2024-05-06T16:19:21.464+02:00 DEBUG 21336 --- []-nio2-thread-4] o.a.sshd.common.channel.LocalWindow      : Consume LocalWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 32 down to 2083690
2024-05-06T16:19:21.464+02:00 DEBUG 21336 --- []-nio2-thread-4] i.DefaultSftpClient$SftpChannelSubsystem : handleData(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) SSH_MSG_CHANNEL_DATA len=32
2024-05-06T16:19:21.467+02:00 DEBUG 21336 --- [   scheduling-1] o.a.s.s.c.impl.SftpDirEntryIterator      : close(/remote_directory) handle=/remote_directory: 687831
2024-05-06T16:19:21.468+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.channel.RemoteWindow     : Consume RemoteWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 16 down to 2094174
2024-05-06T16:19:21.468+02:00 DEBUG 21336 --- [   scheduling-1] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[username@sftp.server]) packet #199 sending command=94[SSH_MSG_CHANNEL_DATA] len=25
2024-05-06T16:19:21.468+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/my_ip, remote=sftp.server]) writing 80 bytes
2024-05-06T16:19:21.480+02:00 DEBUG 21336 --- []-nio2-thread-6] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[username@sftp.server]) process #192 SSH_MSG_CHANNEL_DATA
2024-05-06T16:19:21.480+02:00 DEBUG 21336 --- []-nio2-thread-6] o.a.sshd.common.channel.LocalWindow      : Consume LocalWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 28 down to 2083662
2024-05-06T16:19:21.480+02:00 DEBUG 21336 --- []-nio2-thread-6] i.DefaultSftpClient$SftpChannelSubsystem : handleData(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) SSH_MSG_CHANNEL_DATA len=28
2024-05-06T16:19:21.491+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.channel.RemoteWindow     : Consume RemoteWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 109 down to 2094065
2024-05-06T16:19:21.491+02:00 DEBUG 21336 --- [   scheduling-1] o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[username@sftp.server]) packet #200 sending command=94[SSH_MSG_CHANNEL_DATA] len=118
2024-05-06T16:19:21.491+02:00 DEBUG 21336 --- [   scheduling-1] o.a.sshd.common.io.nio2.Nio2Session      : writeBuffer(Nio2Session[local=/my_ip, remote=sftp.server]) writing 176 bytes
2024-05-06T16:19:21.882+02:00 DEBUG 21336 --- []-nio2-thread-8] o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[username@sftp.server]) process #193 SSH_MSG_CHANNEL_DATA
2024-05-06T16:19:21.884+02:00 DEBUG 21336 --- []-nio2-thread-8] o.a.sshd.common.channel.LocalWindow      : Consume LocalWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) by 28 down to 2083634
2024-05-06T16:19:21.884+02:00 DEBUG 21336 --- []-nio2-thread-8] i.DefaultSftpClient$SftpChannelSubsystem : handleData(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@sftp.server][sftp]) SSH_MSG_CHANNEL_DATA len=28

What captures my attention is the log for SftpDirEntryIterator which seems it is closing the channel. I suspect that this is the cause of the error even if I'm not sure since I don't see any ClosedChannelException!

What I'm sure is that something is wrong with the client. I can download the file using FileZilla.

UPDATE:

I tried to use the SftpRemoteFileTemplate:

sftpTemplate.get("remote-dir/MyFile.csv") {
    inputStream -> inputStream.use {
        localDir.mkdir()
        FileUtils.copyInputStreamToFile(inputStream, localDir)
}}

Also in this case I get SFTP error (SSH_FX_FAILURE): Failure. No close message is logged this time. Therefore the note about SftpDirEntryIterator's log is not worth. The problem happens only during downloading. I tried with the Sftp template to list all the files in the remote directory. This operation completes without errors.

Solution

The error was due to the missing / in the remote directory path:

sftpInboundFileSynchronizer.setRemoteDirectory("remote_folder") // Wrong
sftpInboundFileSynchronizer.setRemoteDirectory("/remote_folder")

Unfortunately I just solved the issue with "change and try" because the error returned by the sftp server was too generic plus the non consistent behaviour of the client. Although it could list the directories even without / this was necessary when downloading the file...