SFTP sendMessage() failed: Invalid argument during upload of huge file

Question

A customer is experiencing a problem where an SFTP transfer fails after 24GB of a 27GB file have been transferred.  We've checked for the usual things, timeouts, disk space, etc.  Using ftp/j Pro 4.7.  The transfer works when they use AIX command line sftp.  

I've tried to reproduce the issue here but I had no trouble transferring a 26GB file.  

My feeling is that this is an environmental issue and I am wondering if you can suggest steps to find the cause.  I'd appreciate any advice.  

Here are the relevant parts of the log:

2017-06-24 14:21:53,135 [FTPThread_edt_1] DEBUG com.enterprisedt.ConnectionProtocol  - Sent 4 bytes (4 total) for channel id 3
2017-06-24 14:21:53,135 [FTPThread_edt_1] DEBUG com.enterprisedt.ConnectionProtocol  - Sent total bytes 4 for channel id 3
2017-06-24 14:21:53,135 [FTPThread_edt_1] DEBUG com.enterprisedt.ConnectionProtocol  - Sending 16409 bytes for channel id 3 (maxSize=32648)
2017-06-24 14:21:53,135 [FTPThread_edt_1] DEBUG com.enterprisedt.ChannelDataWindow  - remote window consumed 16409 bytes of window space (948246 bytes left)
2017-06-24 14:21:53,135 [FTPThread_edt_1] DEBUG com.enterprisedt.TransportProtocolCommon  - Name=SSH_MSG_CHANNEL_DATA,MessageId=94
2017-06-24 14:21:53,140 [FTPThread_edt_1] ERROR com.enterprisedt.TransportProtocolOutputStream  - sendMessage() failed: Invalid argument (state=4)
2017-06-24 14:21:53,140 [Transport protocol 4] WARN  com.enterprisedt.TransportProtocolCommon  - The Transport Protocol thread failed: Connection reset
2017-06-24 14:21:53,140 [Transport protocol 4] DEBUG com.enterprisedt.TransportProtocolCommon  - stop() called
2017-06-24 14:21:53,140 [Transport protocol 4] DEBUG com.enterprisedt.State  - Updated state to 3
2017-06-24 14:21:53,140 [Transport protocol 4] DEBUG com.enterprisedt.Channel  - Remote side is closing channel
2017-06-24 14:21:53,140 [Transport protocol 4] DEBUG com.enterprisedt.Channel  - close() called
2017-06-24 14:21:53,140 [Transport protocol 4] DEBUG com.enterprisedt.ConnectionProtocol  - Local computer has closed channel 3[sftp]
2017-06-24 14:21:53,140 [Transport protocol 4] DEBUG com.enterprisedt.TransportProtocolCommon  - Name=SSH_MSG_CHANNEL_CLOSE,MessageId=97
2017-06-24 14:21:53,140 [Transport protocol 4] ERROR com.enterprisedt.TransportProtocolOutputStream  - sendMessage() failed: Invalid argument (state=4)
2017-06-24 14:21:53,140 [ssh-connection 4] DEBUG com.enterprisedt.State  - Updated state to 3
2017-06-24 14:21:53,140 [ssh-connection 4] DEBUG com.enterprisedt.AsyncService  - ssh-connection main loop finished
...

2017-06-24 14:21:53,141 [FTPThread_edt_1] ERROR com.enterprisedt.SftpClient  - put(/Current/TARBACKUPTARBACKUPSYM61120170624012006.Z) failed
com.enterprisedt.net.j2ssh.transport.TransportProtocolException: IO Error on socket: Invalid argument
    at com.enterprisedt.net.j2ssh.transport.b.a(TransportProtocolOutputStream.java:217)
    at com.enterprisedt.net.j2ssh.transport.TransportProtocolCommon.sendMessage(TransportProtocolCommon.java:473)
    at com.enterprisedt.net.j2ssh.connection.ConnectionProtocol.sendChannelData(ConnectionProtocol.java:276)
    at com.enterprisedt.net.j2ssh.connection.Channel.sendChannelData(Channel.java:229)
    at com.enterprisedt.net.j2ssh.subsystem.SubsystemChannel.sendMessage(SubsystemChannel.java:75)
    at com.enterprisedt.net.j2ssh.sftp.SftpSubsystemClient.writeFileAsync(SftpSubsystemClient.java:863)
    at com.enterprisedt.net.j2ssh.sftp.SftpFileOutputStream.write(SftpFileOutputStream.java:130)
    at com.enterprisedt.net.j2ssh.SftpClient.a(SftpClient.java:660)
    at com.enterprisedt.net.j2ssh.SftpClient.put(SftpClient.java:1232)
    at com.enterprisedt.net.j2ssh.SftpClient.put(SftpClient.java:1130)
    at com.enterprisedt.net.ftp.ssh.SSHFTPClient.put(SSHFTPClient.java:1085)
    at com.enterprisedt.net.ftp.async.internal.UploadFileTask.run(UploadFileTask.java:128)
    at com.enterprisedt.net.ftp.async.internal.FTPTaskProcessor$b.run(FTPTaskProcessor.java:593)
2017-06-24 14:21:53,142 [FTPThread_edt_1] DEBUG com.enterprisedt.SftpSubsystemClient  - Waiting for response
2017-06-24 14:21:53,142 [FTPThread_edt_1] DEBUG com.enterprisedt.SftpSubsystemClient  - Received response
2017-06-24 14:21:53,142 [FTPThread_edt_1] ERROR com.enterprisedt.SftpSubsystemClient  - Unexpected server response null
2017-06-24 14:21:53,142 [FTPThread_edt_1] ERROR com.enterprisedt.SftpClient  - Failed to close output stream in put()
java.io.IOException: Unexpected server response null
    at com.enterprisedt.net.j2ssh.sftp.SftpSubsystemClient.a(SftpSubsystemClient.java:284)
    at com.enterprisedt.net.j2ssh.sftp.SftpSubsystemClient.getOKRequestStatus(SftpSubsystemClient.java:1136)
    at com.enterprisedt.net.j2ssh.sftp.SftpFileOutputStream.b(SftpFileOutputStream.java:161)
    at com.enterprisedt.net.j2ssh.sftp.SftpFileOutputStream.close(SftpFileOutputStream.java:191)
    at com.enterprisedt.net.j2ssh.SftpClient.put(SftpClient.java:1246)
    at com.enterprisedt.net.j2ssh.SftpClient.put(SftpClient.java:1130)
    at com.enterprisedt.net.ftp.ssh.SSHFTPClient.put(SSHFTPClient.java:1085)
    at com.enterprisedt.net.ftp.async.internal.UploadFileTask.run(UploadFileTask.java:128)
    at com.enterprisedt.net.ftp.async.internal.FTPTaskProcessor$b.run(FTPTaskProcessor.java:593)

Comments

There's no obvious cause for the error.  With really large file transfers, it is worthwhile retrying (resuming) the transfer if you get an exception.

---

The Unexpected response null error is repeated several times after this.  Do you really think  a retry would help?  If so, can you point me to a sample.  Thanks.

---

What I mean is if you get this exception during a transfer, disconnect, then reconnect and initiate the transfer again, this time using resume.

To use resume mode with SecureFIleTransferClient:

uploadFile(localNmae, remoteFileName, WriteMode.RESUME) ;