We recently performed a new deployment of our system which included an upgrade of Apache Commons VFS from 1.1 to 2.0. Since the deployment our client has said they are no longer receiving a file that is generated by our system on a daily basis and transferred to their server over sftp. All of our logs seem to indicate no problem:
DEBUG 2019-05-06 16:30:22,237 VfsLog:70 debug-> Using "/home/tomcat/var/tomcat/temp/vfs_cache" as temporary files store.
DEBUG 2019-05-06 16:30:22,248 VfsLog:70 debug-> Skipping provider "org.apache.commons.vfs2.provider.webdav.WebdavFileProvider" because required class "org.apache.jackrabbit.webdav.client.methods.DavMethod" is not available.
DEBUG 2019-05-06 16:30:22,250 VfsLog:70 debug-> Skipping provider "org.apache.commons.vfs2.provider.hdfs.HdfsFileProvider" because required class "org.apache.hadoop.fs.FileSystem" is not available.
DEBUG 2019-05-06 16:30:22,262 Transporter:525 getFSOptions-> Not using strict host checking
DEBUG 2019-05-06 16:30:22,262 Transporter:528 getFSOptions-> user dir as root? true
DEBUG 2019-05-06 16:30:22,263 Transporter:214 transportOutbound-> Attempting to write to remote file [server]/[file].pgp
DEBUG 2019-05-06 16:30:22,264 VfsLog:70 debug-> Using "/home/tomcat/var/tomcat/temp/vfs_cache" as temporary files store.
DEBUG 2019-05-06 16:30:22,267 VfsLog:70 debug-> Skipping provider "org.apache.commons.vfs2.provider.webdav.WebdavFileProvider" because required class "org.apache.jackrabbit.webdav.client.methods.DavMethod" is not available.
DEBUG 2019-05-06 16:30:22,268 VfsLog:70 debug-> Skipping provider "org.apache.commons.vfs2.provider.hdfs.HdfsFileProvider" because required class "org.apache.hadoop.fs.FileSystem" is not available.
INFO 2019-05-06 16:30:22,372 SftpClientFactory$JSchLogger:324 log-> Connecting to [server] port 22
INFO 2019-05-06 16:30:22,394 SftpClientFactory$JSchLogger:324 log-> Connection established
INFO 2019-05-06 16:30:22,398 SftpClientFactory$JSchLogger:324 log-> Remote version string: SSH-2.0-Maverick_SSHD
INFO 2019-05-06 16:30:22,398 SftpClientFactory$JSchLogger:324 log-> Local version string: SSH-2.0-JSCH-0.1.54
INFO 2019-05-06 16:30:22,399 SftpClientFactory$JSchLogger:324 log-> CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256
INFO 2019-05-06 16:30:22,430 SftpClientFactory$JSchLogger:324 log-> CheckKexes: diffie-hellman-group14-sha1,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521
INFO 2019-05-06 16:30:22,525 SftpClientFactory$JSchLogger:324 log-> CheckSignatures: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
INFO 2019-05-06 16:30:22,535 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_KEXINIT sent
INFO 2019-05-06 16:30:22,536 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_KEXINIT received
INFO 2019-05-06 16:30:22,536 SftpClientFactory$JSchLogger:324 log-> kex: server: diffie-hellman-group1-sha1,diffie-hellman-group-exchange-sha1
INFO 2019-05-06 16:30:22,537 SftpClientFactory$JSchLogger:324 log-> kex: server: ssh-rsa
INFO 2019-05-06 16:30:22,537 SftpClientFactory$JSchLogger:324 log-> kex: server: aes256-cbc,aes192-cbc,aes128-cbc
INFO 2019-05-06 16:30:22,538 SftpClientFactory$JSchLogger:324 log-> kex: server: aes256-cbc,aes192-cbc,aes128-cbc
INFO 2019-05-06 16:30:22,539 SftpClientFactory$JSchLogger:324 log-> kex: server: hmac-sha1,hmac-sha1-96,hmac-md5-96
INFO 2019-05-06 16:30:22,539 SftpClientFactory$JSchLogger:324 log-> kex: server: hmac-sha1,hmac-sha1-96,hmac-md5-96
INFO 2019-05-06 16:30:22,540 SftpClientFactory$JSchLogger:324 log-> kex: server: none
INFO 2019-05-06 16:30:22,540 SftpClientFactory$JSchLogger:324 log-> kex: server: none
INFO 2019-05-06 16:30:22,541 SftpClientFactory$JSchLogger:324 log-> kex: server:
INFO 2019-05-06 16:30:22,541 SftpClientFactory$JSchLogger:324 log-> kex: server:
INFO 2019-05-06 16:30:22,542 SftpClientFactory$JSchLogger:324 log-> kex: client: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
INFO 2019-05-06 16:30:22,543 SftpClientFactory$JSchLogger:324 log-> kex: client: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
INFO 2019-05-06 16:30:22,543 SftpClientFactory$JSchLogger:324 log-> kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc
INFO 2019-05-06 16:30:22,544 SftpClientFactory$JSchLogger:324 log-> kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc
INFO 2019-05-06 16:30:22,544 SftpClientFactory$JSchLogger:324 log-> kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96
INFO 2019-05-06 16:30:22,545 SftpClientFactory$JSchLogger:324 log-> kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96
INFO 2019-05-06 16:30:22,545 SftpClientFactory$JSchLogger:324 log-> kex: client: none
INFO 2019-05-06 16:30:22,546 SftpClientFactory$JSchLogger:324 log-> kex: client: none
INFO 2019-05-06 16:30:22,547 SftpClientFactory$JSchLogger:324 log-> kex: client:
INFO 2019-05-06 16:30:22,547 SftpClientFactory$JSchLogger:324 log-> kex: client:
INFO 2019-05-06 16:30:22,548 SftpClientFactory$JSchLogger:324 log-> kex: server->client aes128-cbc hmac-sha1 none
INFO 2019-05-06 16:30:22,548 SftpClientFactory$JSchLogger:324 log-> kex: client->server aes128-cbc hmac-sha1 none
INFO 2019-05-06 16:30:22,567 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_KEX_DH_GEX_REQUEST(1024<2048<2048) sent
INFO 2019-05-06 16:30:22,568 SftpClientFactory$JSchLogger:324 log-> expecting SSH_MSG_KEX_DH_GEX_GROUP
INFO 2019-05-06 16:30:22,591 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_KEX_DH_GEX_INIT sent
INFO 2019-05-06 16:30:22,592 SftpClientFactory$JSchLogger:324 log-> expecting SSH_MSG_KEX_DH_GEX_REPLY
INFO 2019-05-06 16:30:22,620 SftpClientFactory$JSchLogger:324 log-> ssh_rsa_verify: signature true
INFO 2019-05-06 16:30:22,622 SftpClientFactory$JSchLogger:324 log-> Host '[server]' is known and matches the RSA host key
INFO 2019-05-06 16:30:22,623 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_NEWKEYS sent
INFO 2019-05-06 16:30:22,624 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_NEWKEYS received
INFO 2019-05-06 16:30:22,632 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_SERVICE_REQUEST sent
INFO 2019-05-06 16:30:22,635 SftpClientFactory$JSchLogger:324 log-> SSH_MSG_SERVICE_ACCEPT received
INFO 2019-05-06 16:30:22,642 SftpClientFactory$JSchLogger:324 log-> Authentications that can continue: publickey,keyboard-interactive,password
INFO 2019-05-06 16:30:22,642 SftpClientFactory$JSchLogger:324 log-> Next authentication method: publickey
INFO 2019-05-06 16:30:22,719 SftpClientFactory$JSchLogger:324 log-> Authentications that can continue: password
INFO 2019-05-06 16:30:22,719 SftpClientFactory$JSchLogger:324 log-> Next authentication method: password
INFO 2019-05-06 16:30:22,736 SftpClientFactory$JSchLogger:324 log-> Authentication succeeded (password).
DEBUG 2019-05-06 16:30:22,758 SoftRefFilesCache:130 putFile-> putFile: sftp://[user]:***@[server]/[filename].pgp
DEBUG 2019-05-06 16:30:23,143 SoftRefFilesCache:130 putFile-> putFile: sftp://[user]:***@[server]/
DEBUG 2019-05-06 16:30:23,181 SoftRefFilesCache:130 putFile-> putFile: sftp://[user]:***@[server]/TO_HR
DEBUG 2019-05-06 16:30:23,443 Transporter:220 transportOutbound-> Completed write to remote file [server]/TO_HR/[file].pgp
INFO 2019-05-06 16:30:23,444 SftpClientFactory$JSchLogger:324 log-> Disconnecting from [server] port 22
And this is the generic piece of code we have to perform transfers like this:
String safeUri = escapePassword(uriString, events);
String hostPath = getHostPath(uriString);
FileSystemManager fsManager = getFileSystemManager();
try {
FileSystemOptions opts = getFSOptions();
FileObject remoteFile = fsManager.resolveFile(safeUri + remoteFilename, opts);
IOUtils.copy(new FileInputStream(localFile), remoteFile.getContent().getOutputStream());
catch(IOException ioe) {
log.error("", ioe);
} finally {
close(fsManager);
}
The file is generated and stored on the server successfully, and we can manually transfer the file to the client using the server's sftp command (the server is CentOS 6 so I assume it's OpenSSH) using the same user credentials used by the application.
Any ideas on what might be going wrong?
Ended up rewriting our sftp file transfer code using the answer here: https://stackoverflow.com/a/14830708/3415090