Issue: DRS backup fails at TFTP with false trigger of SFTP server full.
CUCM 10.5.2
Changes Made:
Backup worked fine on windows server issue started when trying to move to linux based sftp server.
SFTP server: Open SSH / Proftpd
SFTP server has 200 GB available and was able to upload 10 GB file using SFTP.
Logs:
016-06-05 03:17:54,227 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:17:59,232 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:04,233 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:09,235 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:14,238 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:19,266 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:24,266 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:29,267 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:30,296 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment count is : 5
2016-06-05 03:18:30,297 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm HostName: 131.172.36.105 for File: /CUCMbackup/2016-06-05-03-00-01_BUN-CUCM105-PUB_UCM_TFTP.tar
2016-06-05 03:18:30,297 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server.
2016-06-05 03:18:30,297 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) -
2016-06-05 03:18:30,297 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false
2016-06-05 03:18:30,297 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode
2016-06-05 03:18:30,297 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server...
2016-06-05 03:18:30,407 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel.
2016-06-05 03:18:30,426 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully.
2016-06-05 03:18:30,426 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp...
2016-06-05 03:18:30,426 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel...
2016-06-05 03:18:30,426 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session...
2016-06-05 03:18:30,426 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 2141306880
2016-06-05 03:18:34,267 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:39,267 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:44,268 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:49,269 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:54,269 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:18:59,269 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success
2016-06-05 03:19:01,200 INFO [Thread-16755] - Exception while writing into digest o/p stream .class java.io.IOExceptionchannel is broken
2016-06-05 03:19:01,208 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 1
2016-06-05 03:19:01,208 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted.
2016-06-05 03:19:01,208 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done.
2016-06-05 03:19:01,208 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted.
2016-06-05 03:19:01,208 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted.
2016-06-05 03:19:01,208 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 8074b973f45a1ec9aa6997454b38a381
2016-06-05 03:19:01,208 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream.
2016-06-05 03:19:01,208 ERROR [drfJobThread] - drfJobThread:executeDirectSftpCommand: Exception while closing output stream : java.io.IOException: Pipe closed
2016-06-05 03:19:01,208 INFO [drfJobThread] - The value of SFTP server is full :true
2016-06-05 03:19:01,209 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Command execution problems: error writing output file
.
2016-06-05 03:19:01,209 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel
2016-06-05 03:19:01,209 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed
2016-06-05 03:19:01,209 ERROR [drfJobThread] - drfJobThread:executeDirectSftpCommand: SshIOException - SFTP server is full. Please retry backup after releasing some space.
Troubleshooting done:
Restarted DRF master and local.
Tried multiple SFTP servers.
Log file attached.
Please let us know if any bug exist for this behavior.
