mina-sshd: exceptionCaught(ServerSessionImpl[user@/10.x.x.x:23232])[state=Opened] IllegalStateException: Bad length (32796) for cmd=SSH_MSG_CHANNEL_DATA - max. allowed=32768

@dragonknight88 : PR #405 has been merged. Using the 2.10.1-SNAPSHOT release from the Apache Snapshot maven repository you could test whether it really works with WS_FTP with different handle sizes. If not, feel free to re-open this.

Ultimately it would be good if the vendor of WS_FTP fixed that bug in their SFTP client.

Yes, that was my mistake when reading the code. File handle size 16 means it uses 16 bytes, but then converts these to a hex string, which gives 32 characters, and thus we have with SftpModuleProperties.FILE_HANDLE_SIZE = 16 32 bytes for the actual file handle and thus in the SSH network messages. As I wrote, the implementation is strange. 😦

Now that this is confirmed:

• As it definitely is a bug in WS_FTP, can you file a bug report there? Or comment on https://community.progress.com/s/question/0D54Q0000ASQm9FSQT/bad-length-32796-for-cmdsshmsgchanneldata-max-allowed32768 .
• I’ll see if I can rewrite this file handle stuff in Apache MINA sshd to use 4 bytes by default. Shouldn’t be too hard.

BTW, the “+4 confusion” is this: https://mailarchive.ietf.org/arch/msg/secsh/mIvfsnrukzaIvUBah5RJjDb3yyQ/

It’s basically unrelated to this handle size problem. But it makes the SFTP write from WS_FTP work if the handle size in Apache MINA sshd is set to 4: then we get 8 bytes of actual handle, and WS_FTP will send exactly 4 bytes too many, which Apache MINA sshd will accept, but for the wrong reason as it’s not this “+4 confusion” but a bug at another level that just happens to also cause exactly 4 extra bytes.

a possible quick fix could be…

Yes, I’ll also do something like that. Except that this validation is in the connection protocol (RFC 4254), and fileHandleSize is known only in the higher-layer SFTP protocol, so a bit more is needed to implement this in a proper way without layer breaks. We’d want to accept this extra size only in SFTP channels, and only if it’s exactly this expected extra amount of bytes.

All that said: I find the file handle implementation in Apache MINA sshd a little bit strange. I don’t know why it is done the way it is done; it strikes me as overly complicated. I see absolutely no reason why a file handle should be longer than 4 bytes, be it in memory or in the network packet.

So even if I think we may have found a bug in WS_FTP, I also think the Apache MINA sshd implementation could be simplified and use by default a handle size of 4 bytes.

Thanks, that helps. I was a bit confused for a moment by the log being chronologically descending, but that’s OK. The interesting bit are these two lines:

2023-08-17T03:46:06-07:00	2023-08-17T10:46:06.268Z TRACE 345 --- [] [] [] [)-nio2-thread-5] o.a.s.server.session.ServerSessionImpl   : decode(ServerSessionImpl[user@/10.209.10.5:23011]) packet #15 [chunk #2](128/65573) ff e3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................................................................
2023-08-17T03:46:06-07:00	2023-08-17T10:46:06.268Z TRACE 345 --- [] [] [] [)-nio2-thread-5] o.a.s.server.session.ServerSessionImpl   : decode(ServerSessionImpl[user@/10.209.10.5:23011]) packet #15 [chunk #1](64/65573) 5e 00 00 00 00 00 01 00 1c 00 01 00 18 06 00 00 04 d2 00 00 00 20 38 32 35 64 35 64 64 33 61 38 30 35 36 34 38 65 65 66 35 35 33 62 64 66 33 61 64 39 37 66 36 66 00 00 00 00 00 00 00 00 00 00    ^.....................825d5dd3a805648eef553bdf3ad97f6f..........

This shows the SSH message itself is internally consistent. We have

• 5e SSH_MSG_CHANNEL_DATA
• 00 00 00 00 Channel ID = 0
• 00 01 00 1c Length of data following: 65564 bytes, which is higher than the packet size you configured (65536)

Next comes the data itself, which is an SFTP write request:

• 00 01 00 18 Length of data following: 65560 bytes
• 06 SSH_FXP_WRITE
• 00 00 04 d2 SFTP request ID
• 00 00 00 20 SFTP file handle length (32)
• 32 bytes containing the SFTP file handle “825d5dd3a805648eef553bdf3ad97f6f”
• 00 00 00 00 00 00 00 00 File position to write to: offset 0
• 00 00 ff e3 number of bytes to write: 65507 bytes
• 65507 data bytes following (incidentally all zero bytes)

Also visible from the log: it’s the first SSH_FXP_WRITE request for this file (there’s an SSH_FXP_OPEN request just before).

So whatever that client is doing, it really is sending 28 bytes too many. I do notice that 28 = 32 - 4. OpenSSH returns handles that have only 4 bytes. Apache MINA sshd uses by default handles of 16 bytes AFAIK, and it stringifies these 16 bytes, so we end up with 32 bytes (one byte per hex character).

The SFTP draft RFCs say that SFTP file handles may be up to 256 bytes long.

If you set the handle size in the Apache MINA sshd server to 8, we should end up with 16 hex chars. Does that client then send 12 extra bytes? And if the handle size is 20, we should have 40 bytes, does it then send 36 extra bytes? (For the configuration, see SftpModuleProperties.FILE_HANDLE_SIZE. Apache MINA sshd allows values between 4 and 64.)

If so, we’d have established that this SFTP client can only handle SFTP file handles of 4 bytes. For larger handles, its length logic for SFTP write requests (SSH_FXP_WRITE) is wrong.

This would also explain why it works with OpenSSH: an OpenSSH server will use a handle size of 4 bytes.