2021-10-09 09:57:11,716 DEBUG [main] - drfLocalAgent:run: Initializing logging with configuration file: /usr/local/platform/conf/drfLA_log4j.xml 2021-10-09 09:57:11,729 INFO [main] - drfLocalAgent:run: Monitor UCM Trace Settings 2021-10-09 09:57:11,762 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 the appName is DRF Local Trace 2021-10-09 09:57:11,762 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 Entered NcsStart. 2021-10-09 09:57:11,763 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 Application successfully registered. 2021-10-09 09:57:11,764 DEBUG [Thread-0] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 [ReceiveThread] run() - starting up 2021-10-09 09:57:11,764 DEBUG [Thread-0] - Connecting to: localhost:8001 2021-10-09 09:57:11,775 DEBUG [main] - Oct.09 09:57:11.770 MSKNcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 Received Subscribe for PROCESSNODE 2021-10-09 09:57:11,775 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 subscribe() add to subscription list: PROCESSNODE 2021-10-09 09:57:11,775 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 Socket not open to the Server 2021-10-09 09:57:11,776 DEBUG [main] - Oct.09 09:57:11.775 MSKNcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 Received Subscribe for PROCESSNODESERVICE 2021-10-09 09:57:11,776 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 subscribe() add to subscription list: PROCESSNODESERVICE 2021-10-09 09:57:11,776 DEBUG [main] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 Socket not open to the Server 2021-10-09 09:57:11,791 DEBUG [Thread-0] - ncsClient Socket Success: Socket[addr=localhost/127.0.0.1,port=8001,localport=55494] 2021-10-09 09:57:11,791 DEBUG [Thread-0] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 connected. 2021-10-09 09:57:11,792 DEBUG [Thread-0] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 subscription sent for: PROCESSNODE 2021-10-09 09:57:11,792 DEBUG [Thread-0] - NcsClient:com.cisco.ccm.serviceability.conf.TableChangeSubscriberImpl$MyNcsClient@1e02286 subscription sent for: PROCESSNODESERVICE 2021-10-09 09:57:11,812 DEBUG [main] - Entering HashTextSHA 2021-10-09 09:57:13,045 INFO [main] - class java.security.MessageDigest$Delegate 2021-10-09 09:57:13,046 DEBUG [main] - Exiting HashTextSHA 2021-10-09 09:57:17,517 INFO [main] - TraceSetting: Prev - Level=DEBUG nFile=10 fSize=512000 path=/var/log/active/platform/drf/trace/drfLA00012.log 2021-10-09 09:57:17,517 INFO [main] - TraceSetting: New - Level=DEBUG nFile=15 fSize=1048576 path=/var/log/active/platform/drf/trace/drfLA00012.log 2021-10-09 09:57:17,715 DEBUG [main] - Loading RSA providers explicitly... 2021-10-09 09:57:17,732 DEBUG [main] - RSA providers are loaded explicitly... 2021-10-09 09:57:17,732 DEBUG [main] - New security.provider.1=JsafeJCE 2021-10-09 09:57:17,732 DEBUG [main] - New security.provider.2=RsaJsse 2021-10-09 09:57:17,732 DEBUG [main] - New security.provider.3=SUN 2021-10-09 09:57:17,746 DEBUG [main] - drfLocalWorker:: calling setLogger method 2021-10-09 09:57:17,845 DEBUG [main] - drfUtils.getClusterSetup(): Cluster is supported. Installed could be a cluster or a standalone 2021-10-09 09:57:17,845 DEBUG [main] - drfLocalAgent:SetupNetwork: Starting drfLocalAgent in secure mode. 2021-10-09 09:57:17,845 DEBUG [main] - drfNetServerClient.connect, setting isSecureMode to : true 2021-10-09 09:57:18,091 DEBUG [main] - drfNetServerClient:GetFirstNodeNameCcmDBHost tag exists 2021-10-09 09:57:18,091 DEBUG [main] - drfNetServerClient:GetFirstNodeNameiAmThePub is false.Returning hostname as: cucm-pub0 2021-10-09 09:57:18,091 DEBUG [main] - drfNetServerClient: Reconnect:refreshing the m_sHost value as:cucm-pub0 2021-10-09 09:57:18,091 DEBUG [main] - drfNetServerClient: Reconnect: Creating socket from Host: cucm-pub0 port: 4040 2021-10-09 09:57:18,091 DEBUG [main] - drfNetServerClient.Reconnect: detected isSecureMode is : true 2021-10-09 09:57:18,091 DEBUG [main] - drfNetSSLManager: createSSLSocketFactory: /usr/local/platform/.security/ipsec/trust-certs/ipsec-trust.keystore and /usr/local/platform/.security/ipsec/keys/ipsec-trust.passphrase files exists 2021-10-09 09:57:18,091 DEBUG [main] - drfNetSSLManager: retrievePassword: Retrieved password successfully 2021-10-09 09:57:18,091 DEBUG [main] - drfNetSSSLManager: setupSSLSettings: set up truststore(password) properties 2021-10-09 09:57:18,091 INFO [main] - IN -- RSACryptoEngine.java - loadKeyStore(keystoreFile, keystorePass) - 2021-10-09 09:57:18,493 INFO [main] - OUT -- RSACryptoEngine.java - loadKeyStore - 2021-10-09 09:57:18,493 DEBUG [main] - drfNetSSLManager.createSSLContext: Retrieved KeyStore Instance 2021-10-09 09:57:18,493 DEBUG [main] - drfNetSSLManager.createSSLContext: Loaded KeyStore Instance 2021-10-09 09:57:18,498 DEBUG [main] - drfNetSSLManager.createSSLContext:Initialised KeyManagerFactory 2021-10-09 09:57:18,508 DEBUG [main] - drfNetSSLManager.createSSLContext: Initialised TrustManagerFactory 2021-10-09 09:57:18,513 DEBUG [main] - drfNetSSLManager.createSSLContext: Received SSLContext Instance 2021-10-09 09:57:18,525 DEBUG [main] - drfNetSSLManager.createSSLContext: Successfully initialized SSLContext Instance 2021-10-09 09:57:18,608 DEBUG [main] - drfNetServerClient: Reconnect: SSLSocket socket created 2021-10-09 09:57:18,608 DEBUG [main] - drfNetServerClient. Reconnect: Object OutputStream to be created 2021-10-09 09:57:18,609 DEBUG [main] - drfNetServerClient: Reconnect: Object OutputStream connected 2021-10-09 09:57:18,609 DEBUG [main] - drfNetServerClient.Reconnect: Connected to Host: cucm-pub0, Port: 4040 2021-10-09 09:57:20,188 DEBUG [main] - drfNetServerClient.Reconnect: Sending version id: 11.0.1.10000-10 2021-10-09 09:57:21,876 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient. Reconnect: Object InStream to be created 2021-10-09 09:57:21,876 INFO [main] - drfLocalAgent::main: Connected to host: cucm-pub0, Port: 4040 2021-10-09 09:57:21,878 DEBUG [NetServerClient:KeepAlive.Run [cucm-pub0]] - KeepAlive.run, isSecureMode is : true 2021-10-09 09:57:21,878 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID300 has been validated successfully 2021-10-09 09:57:21,883 DEBUG [Thread-12] - drfNetServerClient: drfQueryTruststore: Retrieved password successfully 2021-10-09 09:57:21,883 INFO [Thread-12] - IN -- RSACryptoEngine.java - loadKeyStore(keystoreFile, keystorePass) - 2021-10-09 09:57:21,898 INFO [Thread-12] - OUT -- RSACryptoEngine.java - loadKeyStore - 2021-10-09 09:57:21,898 DEBUG [Thread-12] - drfNetServerClient: drfQueryTruststore: Number of entries in IPSec trustStore : 1 2021-10-09 09:57:21,898 DEBUG [Thread-12] - drfNetServerClient:drfQueryTruststore - Query truststore for every 20 hours 2021-10-09 09:57:21,940 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient: Reconnect : Object Input stream created 2021-10-09 09:57:27,752 DEBUG [drfLocalRegMonitorThread] - drfLocalRegMonitor.RegisterPlatformComponents: Creating registration file. 2021-10-09 09:57:27,752 INFO [drfLocalRegMonitorThread] - drfLocalRegMonitor.RegisterPlatformComponents: Installed product is Cisco Unified Communications Manager 2021-10-09 09:57:27,916 INFO [drfLocalRegMonitorThread] - drfLocalRegMonitor.RegisterPlatformComponents: Using UCM to Auto-register.. 2021-10-09 09:57:27,916 INFO [drfLocalRegMonitorThread] - drfLocalRegMonitor.autoRegisterComponents: Auto registering : UCM : PLATFORM 2021-10-09 09:57:27,918 INFO [drfLocalRegMonitorThread] - drfUtils:WriteXMLObject: File: /common/drf/UCM_PLATFORM_deregister.xml 2021-10-09 09:57:27,943 INFO [drfLocalRegMonitorThread] - drfSdkRegistration:drfSdkRegistration: deployment type is standalone 2021-10-09 09:57:27,943 INFO [drfLocalRegMonitorThread] - drfSdkRegistration:drfSdkRegistration: Feature is:UCM 2021-10-09 09:57:27,944 INFO [drfLocalRegMonitorThread] - drfUtils:WriteXMLObject: File: /common/drf/UCM_PLATFORM 2021-10-09 09:57:27,945 INFO [drfLocalRegMonitorThread] - drfLocalRegMonitor.createRegFile: Created registration file. 2021-10-09 09:57:28,035 DEBUG [drfLocalRegMonitorThread] - drfUtils.getClusterSetup(): Cluster is supported. Installed could be a cluster or a standalone 2021-10-09 09:57:28,035 INFO [drfLocalRegMonitorThread] - drfLocalRegMonitor.autoRegisterComponents: Auto registering : UCM : CLM 2021-10-09 09:57:28,035 INFO [drfLocalRegMonitorThread] - drfUtils:WriteXMLObject: File: /common/drf/UCM_CLM_deregister.xml 2021-10-09 09:57:28,036 INFO [drfLocalRegMonitorThread] - drfSdkRegistration:drfSdkRegistration: deployment type is standalone 2021-10-09 09:57:28,036 INFO [drfLocalRegMonitorThread] - drfSdkRegistration:drfSdkRegistration: Feature is:UCM 2021-10-09 09:57:28,036 INFO [drfLocalRegMonitorThread] - drfUtils:WriteXMLObject: File: /common/drf/UCM_CLM 2021-10-09 09:57:28,037 INFO [drfLocalRegMonitorThread] - drfLocalRegMonitor.createRegFile: Created registration file. 2021-10-09 09:57:28,038 INFO [drfLocalRegMonitorThread] - CheckDeRegistrationFiles: There are 2 DeRegistration files 2021-10-09 09:57:28,038 DEBUG [drfLocalRegMonitorThread] - CheckDeRegistrationFiles: Processing ... UCM_CLM_deregister.xml 2021-10-09 09:57:28,038 INFO [drfLocalRegMonitorThread] - drfUtils:ReadXMLObject: File: /common/drf/UCM_CLM_deregister.xml 2021-10-09 09:57:28,053 INFO [drfLocalRegMonitorThread] - CheckDeRegistrationFiles: AutoRegistered Component:true 2021-10-09 09:57:28,053 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleDeRegistrationReq: Received de-registration request 2021-10-09 09:57:28,056 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleDeRegistrationRequest: Processed registration file: UCM_CLM_deregister.xml 2021-10-09 09:57:28,056 DEBUG [drfLocalRegMonitorThread] - CheckDeRegistrationFiles: Processing ... UCM_PLATFORM_deregister.xml 2021-10-09 09:57:28,056 INFO [drfLocalRegMonitorThread] - drfUtils:ReadXMLObject: File: /common/drf/UCM_PLATFORM_deregister.xml 2021-10-09 09:57:28,058 INFO [drfLocalRegMonitorThread] - CheckDeRegistrationFiles: AutoRegistered Component:true 2021-10-09 09:57:28,058 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleDeRegistrationReq: Received de-registration request 2021-10-09 09:57:28,059 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleDeRegistrationRequest: Processed registration file: UCM_PLATFORM_deregister.xml 2021-10-09 09:57:28,059 INFO [drfLocalRegMonitorThread] - CheckRegistrationFiles: There are 2 registration files. 2021-10-09 09:57:28,059 INFO [drfLocalRegMonitorThread] - drfUtils:ReadXMLObject: File: /common/drf/UCM_CLM_register.xml 2021-10-09 09:57:28,063 INFO [drfLocalRegMonitorThread] - CheckRegistrationFiles: Registering UCM(CLM) File: UCM_CLM_register.xml 2021-10-09 09:57:28,063 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleRegistrationReq: Received registration request, feature [UCM] component [CLM] 2021-10-09 09:57:28,070 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleRegistrationReq: ========== BEGIN msgSubRegistration_REQ ========== Feature : UCM Server : cucm-sub1 Error File : /usr/local/platform/bin/clm/clm_drf_error_map.txt Depend File : /usr/local/platform/bin/clm/clm_drf_dependency.xml Script File : /usr/local/platform/bin/clm/clm_drf_script.xml Pre Backup : NOOPERATION Do Backup : /usr/local/platform/bin/clm/clm_drf_do_backup.py Post Backup : NOOPERATION Pre Restore : /usr/local/platform/bin/clm/clm_drf_pre_restore.py Do Restore : /usr/local/platform/bin/clm/clm_drf_do_restore.py Post Restore: /usr/local/platform/bin/clm/clm_drf_post_restore.py Deployment Type: standalone Direct Backup: yes Script Priority: 0 Reboot After Restore: REBOOT_SERVER Dependency : PLATFORM ========== END msgSubRegistration_REQ ========== 2021-10-09 09:57:28,075 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleRegistrationRequest: Registration request sent to Master Agent 2021-10-09 09:57:28,075 INFO [drfLocalRegMonitorThread] - drfLocalWorker.RemoveRegistrationFile: Removed [/common/drf/UCM_CLM_register.xml] 2021-10-09 09:57:28,075 INFO [drfLocalRegMonitorThread] - drfUtils:ReadXMLObject: File: /common/drf/UCM_PLATFORM_register.xml 2021-10-09 09:57:28,077 INFO [drfLocalRegMonitorThread] - CheckRegistrationFiles: Registering UCM(PLATFORM) File: UCM_PLATFORM_register.xml 2021-10-09 09:57:28,077 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleRegistrationReq: Received registration request, feature [UCM] component [PLATFORM] 2021-10-09 09:57:28,082 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleRegistrationReq: ========== BEGIN msgSubRegistration_REQ ========== Feature : UCM Server : cucm-sub1 Error File : /common/drf/scripts/platform/platform_error_map.txt Depend File : /common/drf/scripts/platform/platform_dependency.xml Script File : /common/drf/scripts/platform/platform_script.xml Pre Backup : /common/drf/scripts/platform/platform_pre_backup.py Do Backup : /common/drf/scripts/platform/platform_do_backup.py Post Backup : NOOPERATION Pre Restore : /common/drf/scripts/platform/platform_pre_restore.py Do Restore : /common/drf/scripts/platform/platform_do_restore.py Post Restore: /common/drf/scripts/platform/platform_post_restore.py Deployment Type: standalone Direct Backup: yes Script Priority: 0 Reboot After Restore: REBOOT_SERVER ========== END msgSubRegistration_REQ ========== 2021-10-09 09:57:28,085 INFO [drfLocalRegMonitorThread] - drfLocalWorker.HandleRegistrationRequest: Registration request sent to Master Agent 2021-10-09 09:57:28,085 INFO [drfLocalRegMonitorThread] - drfLocalWorker.RemoveRegistrationFile: Removed [/common/drf/UCM_PLATFORM_register.xml] 2021-10-09 09:57:28,253 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1510 has been validated successfully 2021-10-09 09:57:28,263 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1510 has been validated successfully 2021-10-09 09:57:28,294 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1410 has been validated successfully 2021-10-09 09:57:28,328 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1410 has been validated successfully 2021-10-09 09:59:52,988 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : PLM Component : ELM-AGENT Error File : /opt/cisco/elm/client/drs/elm_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/opt/cisco/elm/client/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-AGENT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_PLM_ELM-AGENT.tar Network Backup : true Commands List : "/opt/cisco/elm/client/drs/elm_pre_backup.py" "/common/drf/backup.log" Commands List : "/opt/cisco/elm/client/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-AGENT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Commands List : "/opt/cisco/elm/client/drs/elm_post_backup.py" "/common/drf/backup.log" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 09:59:52,988 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 09:59:52,995 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_ANN.log 2021-10-09 09:59:52,995 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_ANN.log 2021-10-09 09:59:52,995 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_TCT.log 2021-10-09 09:59:52,995 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_TCT.log 2021-10-09 09:59:52,995 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_CLM.log 2021-10-09 09:59:52,996 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_CLM.log 2021-10-09 09:59:52,996 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_CDPAGT.log 2021-10-09 09:59:52,996 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_CDPAGT.log 2021-10-09 09:59:52,996 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_MOH.log 2021-10-09 09:59:52,996 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_MOH.log 2021-10-09 09:59:52,996 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_CEF.log 2021-10-09 09:59:52,996 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_CEF.log 2021-10-09 09:59:52,996 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_PLATFORM.log 2021-10-09 09:59:52,997 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_PLATFORM.log 2021-10-09 09:59:52,997 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_SYSLOGAGT.log 2021-10-09 09:59:52,997 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_SYSLOGAGT.log 2021-10-09 09:59:52,997 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_PLM_ELM-AGENT.log 2021-10-09 09:59:52,997 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_PLM_ELM-AGENT.log 2021-10-09 09:59:52,997 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_PLM_ELM-SERVER.log 2021-10-09 09:59:52,998 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_PLM_ELM-SERVER.log 2021-10-09 09:59:52,998 DEBUG [drfJobThread] - drfUtils:deleteFiles: Removing path: /var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_REPORTER.log 2021-10-09 09:59:52,998 INFO [drfJobThread] - drfJobThread:run: Deleted full log file :/var/log/active/platform/drf/fulllog/2021-10-09-09-23-47_b_fulllog_CUCM-SUB1_UCM_REPORTER.log 2021-10-09 09:59:52,998 INFO [drfJobThread] - drfJobThread:run: Received request to execute [3] scripts 2021-10-09 09:59:52,999 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 09:59:53,007 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 09:59:53,009 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 09:59:53,588 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 09:59:53,588 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 09:59:53,588 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 09:59:53,590 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/opt/cisco/elm/client/drs/elm_pre_backup.py" "/common/drf/backup.log" 2021-10-09 09:59:53,654 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/opt/cisco/elm/client/drs/elm_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 09:59:53,654 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/opt/cisco/elm/client/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-AGENT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 09:59:53,654 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 09:59:53,655 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 09:59:53,656 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 09:59:53,656 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 09:59:53,658 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 09:59:53,658 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 09:59:53,658 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 09:59:53,658 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 09:59:53,659 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 09:59:53,731 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 09:59:53,732 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/opt/cisco/elm/client/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-AGENT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_PLM_ELM-AGENT.tar 2021-10-09 09:59:53,733 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 09:59:53,760 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 09:59:54,825 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 09:59:55,139 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 09:59:55,321 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 09:59:55,321 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/opt/cisco/elm/client/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-AGENT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 09:59:55,325 INFO [Thread-21] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 09:59:55,403 INFO [Thread-21] - Time to generate final checksum... 2021-10-09 09:59:55,469 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 09:59:55,469 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 09:59:55,470 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 09:59:55,470 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 09:59:55,470 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 09:59:55,470 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 1e50f607bea98d28940cea289d3c05c75c36c1e08032340c1d76b5bdf7d2fad18c7bb8228d9120e20d40d8b778903d51 2021-10-09 09:59:55,470 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 09:59:55,470 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 09:59:55,530 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 09:59:55,530 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 09:59:55,530 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 09:59:55,530 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 09:59:55,530 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 09:59:55,535 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 09:59:55,536 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 09:59:55,536 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 09:59:55,536 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/opt/cisco/elm/client/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-AGENT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 09:59:55,536 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/opt/cisco/elm/client/drs/elm_post_backup.py" "/common/drf/backup.log" 2021-10-09 09:59:55,581 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/opt/cisco/elm/client/drs/elm_post_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 09:59:55,581 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 09:59:55,581 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 09:59:55,582 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 09:59:55,584 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 09:59:55,584 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 09:59:55,585 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 09:59:55,719 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : PLM Component : ELM-SERVER Error File : /opt/cisco/elm/server/drs/elm_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/opt/cisco/elm/server/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-SERVER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_PLM_ELM-SERVER.tar Network Backup : true Commands List : "/opt/cisco/elm/server/drs/elm_pre_backup.py" "/common/drf/backup.log" Commands List : "/opt/cisco/elm/server/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-SERVER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Commands List : "/opt/cisco/elm/server/drs/elm_post_backup.py" "/common/drf/backup.log" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 09:59:55,719 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 09:59:55,720 INFO [drfJobThread] - drfJobThread:run: Received request to execute [3] scripts 2021-10-09 09:59:55,720 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 09:59:55,720 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 09:59:55,720 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 09:59:55,721 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 09:59:55,721 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 09:59:55,721 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 09:59:55,721 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/opt/cisco/elm/server/drs/elm_pre_backup.py" "/common/drf/backup.log" 2021-10-09 09:59:55,762 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/opt/cisco/elm/server/drs/elm_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 09:59:55,762 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/opt/cisco/elm/server/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-SERVER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 09:59:55,762 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 09:59:55,762 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 09:59:55,762 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 09:59:55,762 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 09:59:55,762 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 09:59:55,763 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 09:59:55,763 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 09:59:55,763 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 09:59:55,763 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 09:59:55,778 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 09:59:55,778 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/opt/cisco/elm/server/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-SERVER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_PLM_ELM-SERVER.tar 2021-10-09 09:59:55,778 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 09:59:55,778 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 09:59:56,764 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 09:59:57,081 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 09:59:57,262 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 09:59:57,262 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/opt/cisco/elm/server/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-SERVER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 09:59:57,264 INFO [Thread-36] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 09:59:57,671 INFO [Thread-36] - Time to generate final checksum... 2021-10-09 09:59:57,806 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 09:59:57,807 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 09:59:57,807 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 09:59:57,807 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 09:59:57,807 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 09:59:57,807 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 6f01bf9fea17f1152d8b4dc85122fe97db72dbd058c642b6e812e77841e7b96896de3ae566b16f832c4383314269b7f4 2021-10-09 09:59:57,807 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 09:59:57,807 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 09:59:57,866 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 09:59:57,866 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 09:59:57,866 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 09:59:57,866 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 09:59:57,866 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 09:59:57,867 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 09:59:57,867 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 09:59:57,867 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 09:59:57,867 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/opt/cisco/elm/server/drs/elm_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "PLM" "ELM-SERVER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 09:59:57,867 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/opt/cisco/elm/server/drs/elm_post_backup.py" "/common/drf/backup.log" 2021-10-09 09:59:57,913 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/opt/cisco/elm/server/drs/elm_post_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 09:59:57,913 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 09:59:57,913 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 09:59:57,913 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 09:59:57,913 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 09:59:57,914 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 09:59:57,914 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:00,651 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : PLATFORM Error File : /common/drf/scripts/platform/platform_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/common/drf/scripts/platform/platform_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "PLATFORM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_PLATFORM.tar Network Backup : true Commands List : "/common/drf/scripts/platform/platform_pre_backup.py" "/common/drf/backup.log" Commands List : "/common/drf/scripts/platform/platform_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "PLATFORM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:00,651 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:00,652 INFO [drfJobThread] - drfJobThread:run: Received request to execute [2] scripts 2021-10-09 10:05:00,653 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:00,653 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:00,653 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:00,653 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:00,653 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:00,653 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:00,653 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/platform/platform_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:02,153 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/platform/platform_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:02,153 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/platform/platform_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "PLATFORM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:02,153 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:02,153 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:02,153 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:02,153 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:02,153 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:02,154 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:02,154 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:02,154 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:02,154 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:02,166 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:02,166 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/common/drf/scripts/platform/platform_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "PLATFORM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_PLATFORM.tar 2021-10-09 10:05:02,166 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:02,166 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:03,219 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:03,555 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:03,750 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:03,750 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/common/drf/scripts/platform/platform_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "PLATFORM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:03,753 INFO [Thread-51] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:05,656 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [25], result: success 2021-10-09 10:05:06,419 INFO [Thread-51] - Time to generate final checksum... 2021-10-09 10:05:06,588 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:06,589 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:06,589 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:06,589 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:06,589 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:06,589 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 6f6e418addb4484ec74dfe2c4dd5983c94fc4d61858d64bcf5ed2290b33563ded391ea80ab7a9584374da284146d6611 2021-10-09 10:05:06,589 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:06,589 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:06,658 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:06,658 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:06,659 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:06,659 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:06,659 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:06,659 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:06,659 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:06,659 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:06,659 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/platform/platform_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "PLATFORM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:06,659 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:06,660 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:06,660 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:06,660 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:06,661 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:06,664 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:06,869 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : CLM Error File : /usr/local/platform/bin/clm/clm_drf_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/usr/local/platform/bin/clm/clm_drf_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CLM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_CLM.tar Network Backup : true Dependency : PLATFORM Commands List : "/usr/local/platform/bin/clm/clm_drf_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CLM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:06,869 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:06,869 INFO [drfJobThread] - drfJobThread:run: Received request to execute [1] scripts 2021-10-09 10:05:06,870 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:06,870 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:06,870 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:06,870 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:06,870 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:06,871 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:06,871 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/platform/bin/clm/clm_drf_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CLM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:06,871 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:06,871 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:06,871 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:06,871 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:06,871 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:06,871 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:06,872 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:06,872 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:06,872 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:06,886 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:06,886 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/usr/local/platform/bin/clm/clm_drf_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CLM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_CLM.tar 2021-10-09 10:05:06,886 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:06,886 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:07,902 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:08,218 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:08,400 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:08,401 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/usr/local/platform/bin/clm/clm_drf_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CLM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:08,402 INFO [Thread-60] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:08,482 INFO [Thread-60] - Time to generate final checksum... 2021-10-09 10:05:08,541 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:08,541 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:08,541 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:08,541 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:08,542 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:08,542 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 0562f9d809a3b9b5bf6c55b056696bc8b60943794db38a2bc8c54af8c71cc7dc329ce296d91c88c9bb688cb9283a177c 2021-10-09 10:05:08,542 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:08,542 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:08,602 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:08,602 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:08,602 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:08,602 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:08,602 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:08,602 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:08,602 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:08,602 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:08,603 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/platform/bin/clm/clm_drf_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CLM" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:08,603 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:08,603 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:08,603 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:08,603 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:08,603 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:08,604 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:08,750 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : CDPAGT Error File : /usr/local/cm/cdpagt/conf/cdpagt_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/usr/local/cm/cdpagt/backup/do_cdp_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CDPAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_CDPAGT.tar Network Backup : true Commands List : "/usr/local/cm/cdpagt/backup/pre_backup.py" "/common/drf/backup.log" Commands List : "/usr/local/cm/cdpagt/backup/do_cdp_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CDPAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Commands List : "/usr/local/cm/cdpagt/backup/post_backup.py" "/common/drf/backup.log" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:08,751 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:08,751 INFO [drfJobThread] - drfJobThread:run: Received request to execute [3] scripts 2021-10-09 10:05:08,751 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:08,752 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:08,752 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:08,752 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:08,752 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:08,752 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:08,752 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/cdpagt/backup/pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:08,818 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/cdpagt/backup/pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:08,818 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/cdpagt/backup/do_cdp_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CDPAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:08,818 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:08,818 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:08,818 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:08,818 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:08,818 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:08,818 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:08,819 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:08,819 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:08,819 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:08,831 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:08,831 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/usr/local/cm/cdpagt/backup/do_cdp_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CDPAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_CDPAGT.tar 2021-10-09 10:05:08,831 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:08,831 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:09,819 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:10,119 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:10,300 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:10,300 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/usr/local/cm/cdpagt/backup/do_cdp_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CDPAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:10,301 INFO [Thread-72] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:10,437 INFO [Thread-72] - Time to generate final checksum... 2021-10-09 10:05:10,519 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:10,520 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:10,520 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:10,520 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:10,520 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:10,520 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: db804ba08dadc468648a995fb1517f0a6b7930576167b76f9bb87a159138de342bbb561d462e0190ed7bfe67eac6c9f9 2021-10-09 10:05:10,520 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:10,520 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:10,583 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:10,583 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:10,583 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:10,583 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:10,583 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:10,583 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:10,583 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:10,583 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:10,584 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/cdpagt/backup/do_cdp_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CDPAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:10,584 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/cdpagt/backup/post_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:10,642 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/cdpagt/backup/post_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:10,642 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:10,642 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:10,642 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:10,643 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:10,643 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:10,643 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:10,776 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : SYSLOGAGT Error File : /usr/local/cm/syslogagt/conf/syslogagt_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/usr/local/cm/syslogagt/backup/do_syslog_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "SYSLOGAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_SYSLOGAGT.tar Network Backup : true Commands List : "/usr/local/cm/syslogagt/backup/pre_backup.py" "/common/drf/backup.log" Commands List : "/usr/local/cm/syslogagt/backup/do_syslog_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "SYSLOGAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Commands List : "/usr/local/cm/syslogagt/backup/post_backup.py" "/common/drf/backup.log" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:10,777 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:10,777 INFO [drfJobThread] - drfJobThread:run: Received request to execute [3] scripts 2021-10-09 10:05:10,777 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:10,777 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:10,777 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:10,778 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:10,778 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:10,778 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:10,778 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/syslogagt/backup/pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:10,846 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/syslogagt/backup/pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:10,846 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/syslogagt/backup/do_syslog_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "SYSLOGAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:10,846 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:10,846 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:10,846 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:10,846 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:10,852 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:10,852 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:10,852 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:10,852 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:10,853 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:10,859 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:10,859 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/usr/local/cm/syslogagt/backup/do_syslog_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "SYSLOGAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_SYSLOGAGT.tar 2021-10-09 10:05:10,859 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:10,860 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:11,926 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:12,229 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:12,426 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:12,426 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/usr/local/cm/syslogagt/backup/do_syslog_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "SYSLOGAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:12,428 INFO [Thread-87] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:12,506 INFO [Thread-87] - Time to generate final checksum... 2021-10-09 10:05:12,569 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:12,569 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:12,569 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:12,569 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:12,569 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:12,570 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 1ac81d1a1c36dcebabc883efb2a9b4316e55ca5de8d6c6fb15c31b960d6e79e5157fcd9f172c3c898d1075a2899c1d57 2021-10-09 10:05:12,570 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:12,570 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:12,634 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:12,634 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:12,635 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:12,635 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:12,635 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:12,635 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:12,635 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:12,635 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:12,635 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/syslogagt/backup/do_syslog_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "SYSLOGAGT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:12,636 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/syslogagt/backup/post_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:12,696 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/syslogagt/backup/post_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:12,696 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:12,696 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:12,696 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:12,697 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:12,697 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:12,697 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:12,829 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : TCT Error File : /common/drf/scripts/tct/tct_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/common/drf/scripts/tct/tct_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TCT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TCT.tar Network Backup : true Commands List : "/common/drf/scripts/tct/tct_pre_backup.py" "/common/drf/backup.log" Commands List : "/common/drf/scripts/tct/tct_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TCT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:12,829 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:12,829 INFO [drfJobThread] - drfJobThread:run: Received request to execute [2] scripts 2021-10-09 10:05:12,830 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:12,830 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:12,830 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:12,830 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:12,830 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:12,831 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:12,831 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/tct/tct_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:12,884 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/tct/tct_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:12,885 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/tct/tct_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TCT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:12,885 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:12,885 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:12,885 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:12,885 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:12,885 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:12,885 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:12,885 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:12,885 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:12,886 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:12,897 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:12,897 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/common/drf/scripts/tct/tct_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TCT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TCT.tar 2021-10-09 10:05:12,897 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:12,897 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:13,910 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:14,211 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:14,389 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:14,389 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/common/drf/scripts/tct/tct_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TCT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:14,391 INFO [Thread-102] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:14,462 INFO [Thread-102] - Time to generate final checksum... 2021-10-09 10:05:14,525 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:14,526 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:14,526 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:14,526 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:14,526 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:14,526 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 32c1c1e18462df3c2d9786b910d4c055b95fe2f951e84761e4974959bc01f5a1e2363eaf1310278a662a87d00a2e83af 2021-10-09 10:05:14,526 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:14,526 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:14,585 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:14,585 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:14,586 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:14,586 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:14,586 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:14,586 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:14,586 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:14,586 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:14,586 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/tct/tct_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TCT" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:14,586 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:14,586 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:14,586 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:14,587 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:14,587 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:14,587 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:14,720 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : CEF Error File : /common/drf/scripts/cef/cef_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/common/drf/scripts/cef/cef_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CEF" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_CEF.tar Network Backup : true Commands List : "/common/drf/scripts/cef/cef_pre_backup.py" "/common/drf/backup.log" Commands List : "/common/drf/scripts/cef/cef_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CEF" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:14,720 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:14,720 INFO [drfJobThread] - drfJobThread:run: Received request to execute [2] scripts 2021-10-09 10:05:14,721 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:14,721 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:14,721 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:14,721 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:14,721 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:14,721 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:14,722 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/cef/cef_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:14,783 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/cef/cef_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:14,783 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/cef/cef_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CEF" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:14,783 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:14,783 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:14,783 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:14,784 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:14,784 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:14,784 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:14,784 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:14,784 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:14,785 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:14,795 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:14,795 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/common/drf/scripts/cef/cef_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CEF" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_CEF.tar 2021-10-09 10:05:14,795 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:14,795 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:15,869 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:16,184 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:16,378 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:16,379 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/common/drf/scripts/cef/cef_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CEF" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:16,380 INFO [Thread-114] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:16,454 INFO [Thread-114] - Time to generate final checksum... 2021-10-09 10:05:16,521 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:16,521 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:16,521 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:16,522 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:16,522 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:16,522 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 41c3682d264a336a73d052b90f8dac6feec3f833ff0f24ab0d40071836bf4252a27791de8b0b373ad69558c550646d79 2021-10-09 10:05:16,522 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:16,522 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:16,590 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:16,590 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:16,590 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:16,590 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:16,590 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:16,590 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:16,590 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:16,591 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:16,591 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/cef/cef_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "CEF" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:16,591 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:16,591 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:16,591 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:16,591 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:16,592 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:16,592 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:16,725 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : MOH Error File : /usr/local/cm/conf/msa_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/usr/local/cm/bin/moh_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "MOH" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_MOH.tar Network Backup : true Commands List : "/usr/local/cm/bin/moh_pre_backup.py" "/common/drf/backup.log" Commands List : "/usr/local/cm/bin/moh_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "MOH" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:16,725 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:16,726 INFO [drfJobThread] - drfJobThread:run: Received request to execute [2] scripts 2021-10-09 10:05:16,726 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:16,726 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:16,726 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:16,727 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:16,727 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:16,727 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:16,727 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/bin/moh_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:16,785 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/bin/moh_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:16,785 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/bin/moh_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "MOH" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:16,785 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:16,785 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:16,785 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:16,785 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:16,785 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:16,786 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:16,786 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:16,786 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:16,786 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:16,797 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:16,797 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/usr/local/cm/bin/moh_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "MOH" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_MOH.tar 2021-10-09 10:05:16,797 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:16,797 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:17,820 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:18,120 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:18,300 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:18,300 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/usr/local/cm/bin/moh_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "MOH" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:18,302 INFO [Thread-126] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:21,727 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:05:21,786 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_MOH.tar 2021-10-09 10:05:21,786 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:05:21,789 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:05:21,791 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:05:21,791 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:05:21,791 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:05:22,794 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:23,216 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:05:23,217 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:05:23,217 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:23,217 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:05:23,217 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 4733325 2021-10-09 10:05:23,217 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 0 2021-10-09 10:05:23,217 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:05:26,728 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:05:31,729 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:05:35,013 INFO [Thread-126] - Time to generate final checksum... 2021-10-09 10:05:35,241 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:35,241 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:35,241 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:35,241 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:35,241 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:35,241 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: e75df1744a9b40a93ebc91eb46607ba21e650b621e31f04c5f3dc05505e9503895319ce75ed95ba8c90d203487c72e7f 2021-10-09 10:05:35,241 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:35,241 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:35,301 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:35,301 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:35,301 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:35,301 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:35,301 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:35,301 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:35,301 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:35,302 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:35,302 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/bin/moh_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "MOH" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:35,302 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:35,302 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:35,302 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:35,302 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:35,302 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:35,303 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:35,435 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : ANN Error File : /usr/local/cm/conf/msa_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/usr/local/cm/bin/ann_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "ANN" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_ANN.tar Network Backup : true Commands List : "/usr/local/cm/bin/ann_pre_backup.py" "/common/drf/backup.log" Commands List : "/usr/local/cm/bin/ann_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "ANN" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:35,435 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:35,435 INFO [drfJobThread] - drfJobThread:run: Received request to execute [2] scripts 2021-10-09 10:05:35,436 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:35,436 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:35,436 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:35,436 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:35,436 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:35,436 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:35,436 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/bin/ann_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:35,495 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/bin/ann_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:35,495 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/usr/local/cm/bin/ann_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "ANN" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:35,495 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:35,495 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:35,496 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:35,496 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:35,496 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:35,496 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:35,496 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:35,496 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:35,496 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:35,507 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:35,507 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/usr/local/cm/bin/ann_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "ANN" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_ANN.tar 2021-10-09 10:05:35,507 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:35,507 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:36,517 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:36,845 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:37,027 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:37,027 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/usr/local/cm/bin/ann_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "ANN" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:37,029 INFO [Thread-140] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:37,109 INFO [Thread-140] - Time to generate final checksum... 2021-10-09 10:05:37,168 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:37,168 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:37,168 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:37,169 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:37,169 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:37,169 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 7e651740d54ddb3d4db5ed7359a1dbc5f4f577b4bf755229439056ebbb3f2bb11301b5e0c3267509dd0a5558505d5866 2021-10-09 10:05:37,169 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:37,169 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:37,228 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:37,228 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:37,229 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:37,229 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:37,229 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:37,229 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:37,229 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:37,229 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:37,229 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/usr/local/cm/bin/ann_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "ANN" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:37,229 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:37,229 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:37,230 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:37,230 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:37,230 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:37,230 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:37,364 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : REPORTER Error File : /common/drf/scripts/reporter/reporter_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/common/drf/scripts/reporter/reporter_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "REPORTER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_REPORTER.tar Network Backup : true Commands List : "/common/drf/scripts/reporter/reporter_pre_backup.py" "/common/drf/backup.log" Commands List : "/common/drf/scripts/reporter/reporter_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "REPORTER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Commands List : "/common/drf/scripts/reporter/reporter_post_backup.py" "/common/drf/backup.log" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:37,364 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:37,365 INFO [drfJobThread] - drfJobThread:run: Received request to execute [3] scripts 2021-10-09 10:05:37,365 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:37,365 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:37,365 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:37,366 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:37,366 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:37,366 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:37,366 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/reporter/reporter_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:37,417 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/reporter/reporter_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:37,418 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/reporter/reporter_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "REPORTER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:37,418 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:37,418 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:37,418 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:37,418 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:37,418 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:37,418 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:37,418 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:37,418 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:37,419 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:37,437 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:37,437 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/common/drf/scripts/reporter/reporter_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "REPORTER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_REPORTER.tar 2021-10-09 10:05:37,437 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:37,437 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:40,093 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:40,409 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:40,607 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:40,607 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/common/drf/scripts/reporter/reporter_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "REPORTER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:40,609 INFO [Thread-152] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:40,683 INFO [Thread-152] - Time to generate final checksum... 2021-10-09 10:05:40,752 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Done Executing the script. Expected value is 0 for success. Command returned with a value 0 2021-10-09 10:05:40,752 DEBUG [drfJobThread] - drfAesEncrypter:encrypt: Password Encrypted. 2021-10-09 10:05:40,752 DEBUG [drfJobThread] - drfEncrypter:byteTohex: byte To hex Conversion done. 2021-10-09 10:05:40,752 DEBUG [drfJobThread] - drfAesEncrypter:encrypter: Password Encrypted. 2021-10-09 10:05:40,752 DEBUG [drfJobThread] - drfEncryption:fnEncPass: Password Encrypted. 2021-10-09 10:05:40,752 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Encrypted checksum during backup is: 11fa4e83f54d5b05a1d8a64c5aba16a6011bbf35f5c9567e78881ca06aea760bca0cf6a4d9d426dea87097c76f949004 2021-10-09 10:05:40,752 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: calling flush before closing a stream. 2021-10-09 10:05:40,752 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Op stream 2021-10-09 10:05:40,818 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closed Op Stream 2021-10-09 10:05:40,818 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Closing Channel 2021-10-09 10:05:40,818 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Channel closed 2021-10-09 10:05:40,818 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing Channel... 2021-10-09 10:05:40,818 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:40,819 DEBUG [drfJobThread] - drfLocalWorker:closeSFTPConnections: Closing connection to the server 2021-10-09 10:05:40,819 INFO [drfJobThread] - drfJobThread:run: Interrupted thread - addIntelligence 2021-10-09 10:05:40,819 ERROR [drfAddIntelligence] - drfAddIntelligence:run: Exception occursleep interrupted 2021-10-09 10:05:40,819 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/reporter/reporter_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "REPORTER" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Result Value=0 2021-10-09 10:05:40,819 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/reporter/reporter_post_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:40,861 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/reporter/reporter_post_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:40,861 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Completed execution of backup/restore commands 2021-10-09 10:05:40,861 INFO [drfJobThread] - drfLocalWorker.drfJobThread: Interrupted thread - jobStatusMonitor 2021-10-09 10:05:40,861 ERROR [drfJobStatusMonitor] - drfLocalWorker.run -> Message: [sleep interrupted] java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1715) 2021-10-09 10:05:40,862 INFO [drfJobThread] - drfLocalWorker.drfJobThread: After interrupting thread - jobStatusMonitor 2021-10-09 10:05:40,862 INFO [drfJobThread] - drfLocalWorker.ReadLogFile: File name changed successfully 2021-10-09 10:05:40,862 DEBUG [drfJobThread] - drfJobThread:run: Attempting to send a Reply. 2021-10-09 10:05:40,999 DEBUG [NetMessageDispatch] - drfMessageValidator.validateMessage(): Starting introspection for Message ID = 1100 Message Body = ========== BEGIN msgSubExecuteScript_REQ ========== Server : CUCM-SUB1 Feature : UCM Component : TFTP Error File : /common/drf/scripts/tftp/tftp_error_map.txt Direct Backup : yes Script Priority : 0 Tape Index : 0 Backup Request : true Log File : /common/drf/backup.log Status File : /common/drf/status.txt Remote User Name : cucm@ytss.ru Remote Machine Name : 172.16.160.152 Remote User Password : 42fc43b735ff09353a9c2fc872607b9202e4280f420866e414529e665c8132c2 DirectScript : "/common/drf/scripts/tftp/tftp_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TFTP" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" Tar File Name : \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar Network Backup : true Commands List : "/common/drf/scripts/tftp/tftp_pre_backup.py" "/common/drf/backup.log" Commands List : "/common/drf/scripts/tftp/tftp_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TFTP" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" ========== END msgSubExecuteScript_REQ ========== 2021-10-09 10:05:40,999 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID1100 has been validated successfully 2021-10-09 10:05:40,999 INFO [drfJobThread] - drfJobThread:run: Received request to execute [2] scripts 2021-10-09 10:05:41,000 INFO [drfJobThread] - drfJobStatusMonitor.drfJobStatusMonitor: Status file name=/common/drf/status.txt 2021-10-09 10:05:41,000 INFO [drfJobThread] - Entering decryptPassword 2021-10-09 10:05:41,000 INFO [drfJobThread] - Use Dkey to decrypt data 2021-10-09 10:05:41,000 INFO [drfJobThread] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:41,000 INFO [drfJobThread] - Using static key to decrypt data 2021-10-09 10:05:41,001 INFO [drfJobThread] - decryptPassword was successful 2021-10-09 10:05:41,001 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/tftp/tftp_pre_backup.py" "/common/drf/backup.log" 2021-10-09 10:05:41,043 INFO [drfJobThread] - drfJobThread:run: Local Agent is done executing Script: sudo /bin/nice -n 0 "/common/drf/scripts/tftp/tftp_pre_backup.py" "/common/drf/backup.log" Result Value=0 2021-10-09 10:05:41,043 INFO [drfJobThread] - drfJobThread:run: Local Agent Executing script: "/common/drf/scripts/tftp/tftp_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TFTP" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:41,043 INFO [drfJobThread] - drfJobThread:run: The script is of the type: do_backup and the DirectSFTPBackup is: true 2021-10-09 10:05:41,043 INFO [drfJobThread] - drfJobThread:run: spawning a thread to detect space in SFTP location 2021-10-09 10:05:41,043 DEBUG [drfJobThread] - drfEncrypter:: Default constructor. 2021-10-09 10:05:41,043 DEBUG [drfJobThread] - drfEncryption:fnGetKey: Extracting Security password (key) from platformConfig.xml... 2021-10-09 10:05:41,043 INFO [drfAddIntelligence] - Entering decryptPassword 2021-10-09 10:05:41,043 INFO [drfAddIntelligence] - Use Dkey to decrypt data 2021-10-09 10:05:41,044 INFO [drfAddIntelligence] - CCMENC::ERROR : Dkey decryption failed. Use recovery mechanism to decrypt data. 2021-10-09 10:05:41,044 INFO [drfAddIntelligence] - Using static key to decrypt data 2021-10-09 10:05:41,044 INFO [drfAddIntelligence] - decryptPassword was successful 2021-10-09 10:05:41,055 DEBUG [drfJobThread] - drfAesEncrypter:drfAesEncrypter: SecretKeySpec Created. 2021-10-09 10:05:41,055 INFO [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing direct SFTP command for: user: cucm@ytss.ru Machine: 172.16.160.152 script: sudo /bin/nice -n 0 "/common/drf/scripts/tftp/tftp_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TFTP" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" script type: do_backup tarFileName: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:05:41,055 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Trying to connect to the SFTP server. 2021-10-09 10:05:41,055 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Connecting to SFTP server... 2021-10-09 10:05:42,126 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Authenctication completed successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:42,450 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Digest Output stream is being forwarded to sftp Channel. 2021-10-09 10:05:42,641 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Set sftp timeout of 20 hours 2021-10-09 10:05:42,641 DEBUG [drfJobThread] - drfJobThread:executeDirectSftpCommand: Executing: /usr/local/platform/cli_scripts/run_script killpg sudo /bin/nice -n 0 "/common/drf/scripts/tftp/tftp_do_backup.py" "/common/drf/backup.log" "/common/drf/status.txt" "cucm-pub0" "-" " " "UCM" "TFTP" "| /usr/local/platform/bin/openssl aes-128-cbc -md sha1 -salt -k *********" 2021-10-09 10:05:42,643 INFO [Thread-167] - Using SHA-1 Message Digest from JsafeJCE, 2021-10-09 10:05:46,001 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:05:46,044 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:05:46,044 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:05:46,044 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:05:46,045 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:05:46,045 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:05:46,045 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:05:47,093 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:05:47,519 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:05:47,519 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:05:47,519 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:05:47,519 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:05:47,519 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 6192771 2021-10-09 10:05:47,519 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 0 2021-10-09 10:05:47,519 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:05:51,002 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:05:56,003 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:01,004 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:06,005 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:11,006 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:16,007 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:21,008 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:26,009 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:31,010 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:36,010 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:41,011 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:46,013 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:47,520 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:06:47,520 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:06:47,520 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:06:47,520 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:06:47,521 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:06:47,521 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:06:48,599 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:06:49,124 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:06:49,124 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:06:49,124 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:06:49,124 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:06:49,124 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 91307524 2021-10-09 10:06:49,124 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 6192771 2021-10-09 10:06:49,124 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:06:51,014 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:06:56,015 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:01,016 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:06,017 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:11,018 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:16,019 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:21,020 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:26,021 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:31,022 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:36,022 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:41,023 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:46,024 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:49,124 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:07:49,125 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:07:49,125 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:07:49,126 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:07:49,126 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:07:49,126 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:07:50,190 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:07:50,647 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:07:50,647 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:07:50,647 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:07:50,647 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:07:50,647 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 170786816 2021-10-09 10:07:50,647 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 91307524 2021-10-09 10:07:50,647 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:07:51,025 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:07:56,026 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:01,028 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:06,029 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:11,030 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:16,031 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:21,032 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:26,034 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:31,035 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:36,035 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:41,036 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:46,038 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:50,647 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:08:50,647 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:08:50,647 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:08:50,648 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:08:50,648 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:08:50,648 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:08:51,039 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:08:51,923 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:08:52,376 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:08:52,376 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:08:52,376 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:08:52,376 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:08:52,376 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 252083970 2021-10-09 10:08:52,376 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 170786816 2021-10-09 10:08:52,376 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:08:56,040 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:01,040 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:06,042 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:11,043 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:16,043 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:21,044 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:26,046 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:31,047 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:36,048 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:41,049 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:46,050 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:51,050 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:09:52,377 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:09:52,377 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:09:52,377 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:09:52,378 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:09:52,378 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:09:52,378 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:09:53,530 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:09:54,007 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:09:54,007 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:09:54,007 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:09:54,007 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:09:54,007 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 336707457 2021-10-09 10:09:54,007 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 252083970 2021-10-09 10:09:54,007 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:09:56,051 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:01,052 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:06,053 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:11,054 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:16,056 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:21,057 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:26,058 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:31,059 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:36,060 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:41,060 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:46,061 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:51,062 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:10:54,009 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:10:54,009 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:10:54,009 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:10:54,010 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:10:54,010 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:10:54,010 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:10:55,094 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:10:55,554 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:10:55,554 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:10:55,554 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:10:55,554 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:10:55,554 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 418971267 2021-10-09 10:10:55,555 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 336707457 2021-10-09 10:10:55,555 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:10:56,063 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:01,063 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:06,065 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:11,066 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:16,067 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:21,067 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:26,068 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:31,069 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:36,070 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:41,071 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:46,072 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:51,073 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:55,555 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:11:55,555 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:11:55,555 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:11:55,556 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:11:55,556 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:11:55,556 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:11:56,074 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:11:56,606 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:11:57,069 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:11:57,069 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:11:57,069 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:11:57,069 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:11:57,069 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 500891394 2021-10-09 10:11:57,069 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 418971267 2021-10-09 10:11:57,069 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:12:01,075 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:06,076 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:11,077 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:16,078 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:21,079 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:26,079 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:31,080 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:36,081 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:41,082 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:46,083 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:51,084 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:56,085 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:12:57,070 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:12:57,070 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:12:57,070 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:12:57,071 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:12:57,071 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:12:57,071 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:12:58,209 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:12:58,666 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:12:58,666 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:12:58,666 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:12:58,666 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:12:58,666 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 574799872 2021-10-09 10:12:58,666 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 500891394 2021-10-09 10:12:58,666 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:13:01,086 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:06,087 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:11,088 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:16,089 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:21,089 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:26,090 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:31,091 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:36,092 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:41,093 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:46,094 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:51,095 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:56,096 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:13:58,666 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:13:58,666 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:13:58,666 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:13:58,667 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:13:58,667 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:13:58,667 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:13:59,679 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:14:00,122 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:14:00,122 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:14:00,122 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:14:00,122 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:14:00,122 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 653606785 2021-10-09 10:14:00,123 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 574799872 2021-10-09 10:14:00,123 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:14:01,097 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:06,098 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:11,099 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:16,100 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:21,101 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:26,102 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:31,102 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:36,103 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:41,104 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:46,105 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:51,106 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:14:56,107 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:00,123 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:15:00,123 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:15:00,123 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:15:00,124 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:15:00,124 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:15:00,124 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:15:01,109 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:01,870 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:15:02,330 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:15:02,331 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:15:02,331 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:15:02,331 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:15:02,331 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 724639490 2021-10-09 10:15:02,331 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 653606785 2021-10-09 10:15:02,331 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:15:06,110 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:11,111 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:16,112 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:21,113 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:26,113 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:31,114 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:36,115 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:41,116 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:46,117 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:51,118 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:15:56,119 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:01,120 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:02,331 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:16:02,331 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:16:02,331 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:16:02,332 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:16:02,332 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:16:02,332 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:16:03,385 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:16:03,824 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:16:03,824 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:16:03,824 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:16:03,824 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:16:03,824 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 790961668 2021-10-09 10:16:03,824 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 724639490 2021-10-09 10:16:03,824 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:16:06,121 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:11,121 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:16,122 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:21,123 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:26,124 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:31,125 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:36,126 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:41,127 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:46,128 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:51,129 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:16:56,130 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:01,130 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:03,825 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:17:03,825 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:17:03,825 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:17:03,826 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:17:03,826 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:17:03,826 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:17:05,473 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:17:05,931 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:17:05,931 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:17:05,931 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:17:05,931 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:17:05,931 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 879108096 2021-10-09 10:17:05,931 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 790961668 2021-10-09 10:17:05,931 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:17:06,131 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:11,133 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:16,134 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:21,135 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:26,136 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:31,136 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:36,137 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:41,138 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:46,139 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:51,140 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:17:56,141 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:01,141 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:05,932 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:18:05,932 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:18:05,932 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:18:05,933 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:18:05,933 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:18:05,933 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:18:06,143 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:07,243 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:18:07,683 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:18:07,683 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:18:07,683 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:18:07,683 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:18:07,683 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 956022657 2021-10-09 10:18:07,683 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 879108096 2021-10-09 10:18:07,683 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:18:11,143 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:16,144 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:21,145 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:26,145 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:31,146 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:36,147 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:41,148 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:46,149 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:51,150 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:18:56,150 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:01,151 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:06,153 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:07,683 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:19:07,683 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:19:07,683 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:19:07,684 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:19:07,684 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:19:07,684 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:19:08,710 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:19:09,773 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:19:09,773 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:19:09,773 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:19:09,773 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:19:09,773 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 1047502340 2021-10-09 10:19:09,773 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 956022657 2021-10-09 10:19:09,773 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:19:11,153 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:16,154 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:21,155 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:26,156 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:31,157 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:36,158 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:41,158 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:46,159 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:51,160 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:19:56,161 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:01,162 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:06,163 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:09,773 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:20:09,774 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:20:09,774 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:20:09,775 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:20:09,775 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:20:09,775 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:20:10,810 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:20:11,163 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:11,247 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:20:11,248 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:20:11,248 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:20:11,248 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:20:11,248 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 1144405889 2021-10-09 10:20:11,248 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 1047502340 2021-10-09 10:20:11,248 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:20:16,164 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:21,165 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:26,170 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:31,172 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:36,173 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:41,173 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:46,174 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:51,175 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:20:56,176 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:01,177 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:06,178 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:11,179 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:11,248 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:21:11,248 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:21:11,248 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:21:11,249 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:21:11,249 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:21:11,249 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:21:12,286 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:21:12,731 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:21:12,732 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:21:12,732 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:21:12,732 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:21:12,732 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 1226604036 2021-10-09 10:21:12,732 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 1144405889 2021-10-09 10:21:12,732 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:21:16,180 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:21,180 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:26,182 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:31,183 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:36,183 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:41,184 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:46,185 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:51,186 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:21:56,187 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:22:01,189 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:22:06,190 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:22:11,191 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:22:12,732 INFO [drfAddIntelligence] - drfUtils:sftpLstatFile-: Executing JSch lstat command for - User: cucm@ytss.ru HostName: 172.16.160.152 for File: \cucm11_backup/2021-10-09-09-58-33_CUCM-SUB1_UCM_TFTP.tar 2021-10-09 10:22:12,732 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Trying to connect to the SFTP server. 2021-10-09 10:22:12,732 INFO [drfAddIntelligence] - IN -- CryptoUtil.java - isCallManagerInFipsMode(..) - 2021-10-09 10:22:12,733 INFO [drfAddIntelligence] - OUT -- CryptoUtil.java - isCallManagerInFipsMode - false 2021-10-09 10:22:12,733 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Server is in NONFIPS mode 2021-10-09 10:22:12,733 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Connecting SFTP server... 2021-10-09 10:22:13,768 DEBUG [drfAddIntelligence] - drfUtils:establishSftpConnection: Authenctication Completed Successfully, connected to remote server. Now opening a SFTP channel. 2021-10-09 10:22:14,212 INFO [drfAddIntelligence] - drfutils.sftpLstatFile: File attributes fetched successfully. 2021-10-09 10:22:14,213 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing ChannelSftp... 2021-10-09 10:22:14,213 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Disconnecting Channel... 2021-10-09 10:22:14,213 DEBUG [drfAddIntelligence] - drfUtils:closeSFTPConnections: Closing Session... 2021-10-09 10:22:14,213 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The current size of tar files is : 1326366339 2021-10-09 10:22:14,213 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The old size was : 1226604036 2021-10-09 10:22:14,213 DEBUG [drfAddIntelligence] - drfAddIntelligence:run: The sleep Increment countr is reset to: 1 2021-10-09 10:22:16,192 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: success 2021-10-09 10:22:18,228 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.run, i/o exception from host: [cucm-pub0], message: null 2021-10-09 10:22:18,228 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.sleepRandom: sleeping for: 23 seconds 2021-10-09 10:22:21,192 ERROR [drfJobStatusMonitor] - drfNetMessageConnect.Send: Send failure to host: cucm-pub0 java.net.SocketException: Socket is closed or output is shut down at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.ay.write(Unknown Source) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1822) at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:718) at com.cisco.cpi.common.socket.drfNetMessageConnect.Send(drfNetMessageConnect.java:70) at com.cisco.cpi.common.socket.drfNetMessage.Reply(drfNetMessage.java:135) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.sendStatusToMA(drfLocalWorker.java:1752) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1711) 2021-10-09 10:22:21,193 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: failure 2021-10-09 10:22:26,193 ERROR [drfJobStatusMonitor] - drfNetMessageConnect.Send: Send failure to host: cucm-pub0 java.net.SocketException: Socket output is shut down at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.ay.write(Unknown Source) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1822) at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:718) at com.cisco.cpi.common.socket.drfNetMessageConnect.Send(drfNetMessageConnect.java:70) at com.cisco.cpi.common.socket.drfNetMessage.Reply(drfNetMessage.java:135) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.sendStatusToMA(drfLocalWorker.java:1752) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1711) 2021-10-09 10:22:26,194 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: failure 2021-10-09 10:22:28,143 INFO [drfLocalRegMonitorThread] - drfLocalWorker.isLAConnected(): Unable to contact server. Master or Local Agent could be down...sleeping for 10 seconds 2021-10-09 10:22:31,194 ERROR [drfJobStatusMonitor] - drfNetMessageConnect.Send: Send failure to host: cucm-pub0 java.net.SocketException: Socket output is shut down at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.ay.write(Unknown Source) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1822) at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:718) at com.cisco.cpi.common.socket.drfNetMessageConnect.Send(drfNetMessageConnect.java:70) at com.cisco.cpi.common.socket.drfNetMessage.Reply(drfNetMessage.java:135) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.sendStatusToMA(drfLocalWorker.java:1752) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1711) 2021-10-09 10:22:31,194 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: failure 2021-10-09 10:22:36,195 ERROR [drfJobStatusMonitor] - drfNetMessageConnect.Send: Send failure to host: cucm-pub0 java.net.SocketException: Socket output is shut down at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.ay.write(Unknown Source) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1822) at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:718) at com.cisco.cpi.common.socket.drfNetMessageConnect.Send(drfNetMessageConnect.java:70) at com.cisco.cpi.common.socket.drfNetMessage.Reply(drfNetMessage.java:135) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.sendStatusToMA(drfLocalWorker.java:1752) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1711) 2021-10-09 10:22:36,195 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: failure 2021-10-09 10:22:38,143 INFO [drfLocalRegMonitorThread] - drfLocalWorker.isLAConnected(): Unable to contact server. Master or Local Agent could be down...sleeping for 10 seconds 2021-10-09 10:22:41,196 ERROR [drfJobStatusMonitor] - drfNetMessageConnect.Send: Send failure to host: cucm-pub0 java.net.SocketException: Socket output is shut down at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.aP.a(Unknown Source) at com.rsa.sslj.x.ay.write(Unknown Source) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1822) at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:718) at com.cisco.cpi.common.socket.drfNetMessageConnect.Send(drfNetMessageConnect.java:70) at com.cisco.cpi.common.socket.drfNetMessage.Reply(drfNetMessage.java:135) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.sendStatusToMA(drfLocalWorker.java:1752) at com.cisco.cpi.drf.drfLocalWorker$drfJobStatusMonitor.run(drfLocalWorker.java:1711) 2021-10-09 10:22:41,196 DEBUG [drfJobStatusMonitor] - drfLocalWorker.sendStatusToMA: Sent script execution progress [0], result: failure 2021-10-09 10:22:41,236 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient:GetFirstNodeNameCcmDBHost tag exists 2021-10-09 10:22:41,236 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient:GetFirstNodeNameiAmThePub is false.Returning hostname as: cucm-pub0 2021-10-09 10:22:41,236 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient: Reconnect:refreshing the m_sHost value as:cucm-pub0 2021-10-09 10:22:41,236 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient: Reconnect: Creating socket from Host: cucm-pub0 port: 4040 2021-10-09 10:22:41,236 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.Reconnect: detected isSecureMode is : true 2021-10-09 10:22:41,237 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager: createSSLSocketFactory: /usr/local/platform/.security/ipsec/trust-certs/ipsec-trust.keystore and /usr/local/platform/.security/ipsec/keys/ipsec-trust.passphrase files exists 2021-10-09 10:22:41,237 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager: retrievePassword: Retrieved password successfully 2021-10-09 10:22:41,237 DEBUG [NetServerClient-cucm-pub0] - drfNetSSSLManager: setupSSLSettings: set up truststore(password) properties 2021-10-09 10:22:41,237 INFO [NetServerClient-cucm-pub0] - IN -- RSACryptoEngine.java - loadKeyStore(keystoreFile, keystorePass) - 2021-10-09 10:22:41,247 INFO [NetServerClient-cucm-pub0] - OUT -- RSACryptoEngine.java - loadKeyStore - 2021-10-09 10:22:41,247 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager.createSSLContext: Retrieved KeyStore Instance 2021-10-09 10:22:41,247 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager.createSSLContext: Loaded KeyStore Instance 2021-10-09 10:22:41,247 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager.createSSLContext:Initialised KeyManagerFactory 2021-10-09 10:22:41,248 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager.createSSLContext: Initialised TrustManagerFactory 2021-10-09 10:22:41,248 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager.createSSLContext: Received SSLContext Instance 2021-10-09 10:22:41,248 DEBUG [NetServerClient-cucm-pub0] - drfNetSSLManager.createSSLContext: Successfully initialized SSLContext Instance 2021-10-09 10:22:41,319 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient: Reconnect: SSLSocket socket created 2021-10-09 10:22:41,319 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient. Reconnect: Object OutputStream to be created 2021-10-09 10:22:41,319 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient: Reconnect: Object OutputStream connected 2021-10-09 10:22:41,319 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.Reconnect: Connected to Host: cucm-pub0, Port: 4040 2021-10-09 10:22:41,319 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.Reconnect: Sending version id: 11.0.1.10000-10 2021-10-09 10:22:41,541 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.run, i/o exception from host: [cucm-pub0], message: null 2021-10-09 10:22:41,541 DEBUG [NetServerClient-cucm-pub0] - drfNetServerClient.sleepRandom: sleeping for: 18 seconds 2021-10-09 10:22:41,542 INFO [NetMessageDispatch] - drfMessageReceiver::HandleMessage: Message ID300 has been validated successfully 2021-10-09 10:22:41,542 FATAL [NetMessageDispatch] - drfLocalAgent.drfLocalWorker: Unable to send 'Local Agent' client identifier message to Master Agent. This may be due to Master or Local Agent being down.