[SSHD-1215] WinsCP transfer failure to Apache SSHD Server

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: 2.6.0
• Fix Version/s: 2.8.0
• Assignee: Thomas Wolf
• Reporter: Roberto Deandrea
• Created: 21/Sep/21 15:14
• Updated: 16/Nov/21 17:16
• Resolved: 14/Oct/21 20:06

Description

Hi

I have a failure transferring small files from a WinSCP SFTP client version 5.19.2 to a front-end Apache SSHD Server 2.6.0.

The front-end Apache SSHD server is configured with a Filesystem built upon SFTPFileSystemProvider to proxy files to an Apache SSHD back-end server.

WinSCP SFTP transfer files successfully directly to back-end Apache SSHD Server.

I traced the SFTP file transfer on the front-end server and back-end server and it seems that something get wrong in the remote FileSystem set on the front-end server.

From traces it seems that the first chunk of file is received correctly by the back-end server, but something is wrong on the second chuck of file transmitted.

-------------------------------------------------------------------------------------------------------------------------

First SSH_FXP_WRITE chunk received from front-end server :

[16/09/21 09:18:26:364 CEST] 00000175 id=00000000 org.apache.sshd.sftp.server.AbstractSftpSubsystemHelper 1 process process(ServerSessionImpl[allfuser1@/172.18.202.33:55400])[length=32757, type=SSH_FXP_WRITE, id=19718] processing
[16/09/21 09:18:26:364 CEST] 00000175 id=00000000 org.apache.sshd.sftp.server.SftpSubsystem 3 doWrite doWrite(ServerSessionImpl[allfuser1@/172.18.202.33:55400])[id=19718] SSH_FXP_WRITE (handle=de6fcf635cb34b0e6d3d56643b7539a3[/upload/rsa.key, offset=0, data=byte[32704])

First SSH_FXP_WRITE chunk sent by front-end SFTP client to back.end-server :

[16/09/21 09:18:26:913 CEST] 00000175 id=00000000 org.apache.sshd.sftp.client.impl.DefaultSftpClient 3 send send(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[DMZ/172.18.202.33/allfuser1@/10.6.6.22:6471][sftp]) cmd=SSH_FXP_WRITE, len=32752, id=139

[16/09/21 09:18:27:010 CEST] 00000175 id=00000000 org.apache.sshd.sftp.client.impl.AbstractSftpClient 3 checkResponseStatus checkResponseStatus(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[DMZ/172.18.202.33/allfuser1@/10.6.6.22:6471][sftp])[id=139] cmd=SSH_FXP_WRITE status=SSH_FX_OK lang= msg=

 

First SSH_FXP_WRITE chunk received succesfully from back-end server :

[16/09/21 09:18:27:007 CEST] 00005c15 id=00000000 org.apache.sshd.sftp.server.SftpSubsystem 3 doWrite doWrite(ServerSessionImpl[DMZ/172.18.202.33/allfuser1@/10.6.6.22:34445])[id=139] SSH_FXP_WRITE (handle=c88cfd55dd514ccdd0428571191f5ea1[/upload/rsa.key, offset=0, data=byte[32704])
[16/09/21 09:18:27:545 CEST] 00005c15 id=00000000 org.apache.sshd.sftp.server.AbstractSftpSubsystemHelper 1 process process(ServerSessionImpl[DMZ/172.18.202.33/allfuser1@/10.6.6.22:34445])[length=32757,

 

-----------------------------------------------------------------------------------------------------

Second SSH_FXP_WRITE chunk received from front-end server:

[16/09/21 09:18:27:012 CEST] 00000175 id=00000000 org.apache.sshd.sftp.server.AbstractSftpSubsystemHelper 1 process process(ServerSessionImpl[allfuser1@/172.18.202.33:55400])[length=32757, type=SSH_FXP_WRITE, id=19974] processing
[16/09/21 09:18:27:013 CEST] 00000175 id=00000000 org.apache.sshd.sftp.server.SftpSubsystem 3 doWrite doWrite(ServerSessionImpl[allfuser1@/172.18.202.33:55400])[id=19974] SSH_FXP_WRITE (handle=de6fcf635cb34b0e6d3d56643b7539a3[/upload/rsa.key, offset=32704, data=byte[32704])

 

Second SSH_FXP_WRITE chunk sent by front-end SFTP client to back-end server:

[16/09/21 09:18:27:473 CEST] 00000175 id=00000000 org.apache.sshd.sftp.client.impl.DefaultSftpClient 3 send send(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[DMZ/172.18.202.33/allfuser1@/10.6.6.22:6471][sftp]) cmd=SSH_FXP_WRITE, len=32752, id=141

 

Second SSH_FXP_WRITE chunk received from back-end server:

type=SSH_FXP_WRITE, id=141] processing
[16/09/21 09:18:27:545 CEST] 00005c15 id=00000000 org.apache.sshd.sftp.server.SftpSubsystem 3 doWrite doWrite(ServerSessionImpl[DMZ/172.18.202.33/allfuser1@/10.6.6.22:34445])[*id=141*] SSH_FXP_WRITE (handle=c88cfd55dd514ccdd0428571191f5ea1[/upload/rsa.key, *offset=0, data=byte[32704*])

Now the back-end server complains about this data. The back-end server is expecting a chunk of data at offset=32704 and not offset = 0.

java.io.IOException: position(/upload/rsa.key) illegal file channel position, expected frsPosition: 32704, found: 0

This is a blocking error and causes the connection closing of the parts involved.

----------------------------------------------------------------------------------------------------------------------

Full traces are attached to this jira.

 

Questions and considerations.

1. Is this a known problem and is fixed in the latest release of Apache SSHD?
2. If this is a new problem can you suggest me how to fix it, or better troubleshoot it
3. Let me know if you need further info for troubleshooting

 

Thanks in advance  for your support

 

Kind Regards

Roberto Deandrea