You are viewing a plain text version of this content. The canonical link for it is here.

Posted to dev@mina.apache.org by "davidfilipovic (via GitHub)" <gi...@apache.org> on 2025/12/26 15:30:17 UTC

[I] Throwing a SSH_FX_BAD_MESSAGE exception when file_size % 32726 = 0 [mina-sshd]

davidfilipovic opened a new issue, #861:
URL: https://github.com/apache/mina-sshd/issues/861

   ### Version
   
   2.16.0
   
   ### Bug description
   
   For years, we have been uploading thousands of files to an SFTP server per day, using mina-sshd. But, once per six or seven months, we encounter a file for which the following is true: 
   
   ```
   file_size % 32276 = 0
   ```
   This was true for our files with sizes 32726B, 7625158B, and 916328B. 
   
   In cases like this, we have encountered that an additional packet with a length of zero is being sent after all previous packets are successfully sent. 
   
   By enabling TRACE logs in our application, we observe that a packet with zero length is sent, which results in an SSH_FX_BAD_MESSAGE exception being thrown. Although the exception is thrown, the file is successfully uploaded to the server. 
   
   
   
   ### Actual behavior
   
   For a file with a size divisible by 32726 without reminder an additional packet is being sent with a length of zero after all the packets are successfully sent. This leads to an exception being thrown and the file marked as not delivered althought it is uploaded successfully to the SFTP server. 
   
   ### Expected behavior
   
   A file with a size that is divisible by 32726 is uploaded successfully, just like any other file. 
   
   ### Relevant log output
   
   ```Shell
   o.a.s.s.client.impl.DefaultSftpClient    : send(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) cmd=SSH_FXP_WRITE, len=28, id=103
   DefaultSftpClient$SftpChannelSubsystem$1 : writePacket([SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]] cmd=SSH_MSG_CHANNEL_DATA)[resume=false] attempting to write 37 out of 37
   o.a.sshd.common.channel.RemoteWindow     : Consume RemoteWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) by 37 down to 2064269
   o.a.s.client.session.ClientSessionImpl   : encode(ClientSessionImpl[username@/0.0.0.0:22]) packet #14 sending command=94[SSH_MSG_CHANNEL_DATA] len=46
   ...
   o.a.s.s.c.impl.SftpOutputStreamAsync     : flush(SftpOutputStreamAsync[ClientSessionImpl[username@/0.0.0.0:22]][/file.csv]) enqueue pending ack=SftpAckData[id=103, offset=32726, length=0]
   o.a.sshd.common.io.nio2.Nio2Session      : handleCompletedWriteCycle(Nio2Session[local=/0.0.0.0:60186, remote=/0.0.0.0:22]) finished writing len=76 at cycle=16 after 91692 nanos
   DefaultSftpClient$SftpChannelSubsystem$1 : onWritten([SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]] cmd=SSH_MSG_CHANNEL_DATA) completed write len=37
   o.a.s.s.c.impl.SftpOutputStreamAsync     : close(SftpOutputStreamAsync[ClientSessionImpl[username@/0.0.0.0:22]][/file.csv]) processing ack #1: SftpAckData[id=102, offset=0, length=32726]
   ...
   i.DefaultSftpClient$SftpChannelSubsystem : handleData(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) SSH_MSG_CHANNEL_DATA len=21
   o.a.s.s.client.impl.DefaultSftpClient    : process(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) id=102, type=SSH_FXP_STATUS, len=17
   o.a.s.s.client.impl.DefaultSftpClient    : data(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) Processed 1 data messages
   o.a.s.s.c.impl.SftpOutputStreamAsync     : close(SftpOutputStreamAsync[ClientSessionImpl[username@/0.0.0.0:22]][/file.csv]) processing ack #1 response for SftpAckData[id=102, offset=0, length=32726]
   o.a.s.s.c.impl.SftpOutputStreamAsync     : close(SftpOutputStreamAsync[ClientSessionImpl[username@/0.0.0.0:22]][/file.csv]) processing ack #2: SftpAckData[id=103, offset=32726, length=0]
    o.a.s.client.session.ClientSessionImpl   : doHandleMessage(ClientSessionImpl[username@/0.0.0.0:22]) process #16 SSH_MSG_CHANNEL_DATA
    o.a.sshd.common.channel.LocalWindow      : Consume LocalWindow[client](SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) by 21 down to 2097076
    i.DefaultSftpClient$SftpChannelSubsystem : handleData(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) SSH_MSG_CHANNEL_DATA len=21
    o.a.s.s.client.impl.DefaultSftpClient    : process(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) id=103, type=SSH_FXP_STATUS, len=17
    o.a.s.s.client.impl.DefaultSftpClient    : data(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) Processed 1 data messages
   o.a.s.s.c.impl.SftpOutputStreamAsync     : close(SftpOutputStreamAsync[ClientSessionImpl[username@/0.0.0.0:22]][/file.csv]) processing ack #2 response for SftpAckData[id=103, offset=32726, length=0]
   o.a.s.s.client.impl.DefaultSftpClient    : throwStatusException(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp])[id=103] cmd=SSH_FXP_WRITE status=SSH_FXP_STATUS[SSH_FX_BAD_MESSAGE, language=, message=]
   o.a.s.s.c.impl.SftpOutputStreamAsync     : close(SftpOutputStreamAsync[ClientSessionImpl[username@/0.0.0.0:22]][/file.csv]) closing file handle
   o.a.s.s.client.impl.DefaultSftpClient    : close(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) /file.csv: 374635304337413138453130
   o.a.s.s.client.impl.DefaultSftpClient    : open(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp])[/file.csv: 374635304337413138453130]: send SSH_FXP_CLOSE
   o.a.s.s.client.impl.DefaultSftpClient    : send(SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]) cmd=SSH_FXP_CLOSE, len=16, id=104
   DefaultSftpClient$SftpChannelSubsystem$1 : writePacket([SftpChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[username@/0.0.0.0:22][sftp]] cmd=SSH_MSG_CHANNEL_DATA)[resume=false] attempting to write 25 out of 25
   ```
   
   ### Other information
   
   _No response_


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org
For additional commands, e-mail: dev-help@mina.apache.org

Re: [I] Throwing a SSH_FX_BAD_MESSAGE exception when file_size % 32726 = 0 [mina-sshd]

Posted by "yannickdeturck (via GitHub)" <gi...@apache.org>.

yannickdeturck commented on issue #861:
URL: https://github.com/apache/mina-sshd/issues/861#issuecomment-3704967679

   Thanks for already pushing a fix, @tomaswolf! Any idea when version 2.17.0 would be planned for release?


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org
For additional commands, e-mail: dev-help@mina.apache.org