[bpcd] 16:28:41.245 [73065] <2> process_requests: <---- NetBackup 8.3 0 ------------initiated 16:28:41.245 [73065] <2> process_requests: VERBOSE = 0 16:28:41.245 [73065] <2> process_requests: Not using VxSS authentication with babnbu2.bable.ad 16:28:41.246 [73065] <2> process_requests: BPCD_GET_VERSION_RQST 16:28:41.246 [73065] <2> process_requests: BPCD_WANT_STATUSMSGS_RQST 16:28:41.246 [73065] <2> process_requests: BPCD_GET_VERSION_RQST 16:28:41.246 [73065] <2> process_requests: BPCD_START_NBFSD_RQST 16:28:41.247 [73065] <2> start_nbfsd: nbfsdCmd: '"/usr/openv/netbackup/bin/nbfsd" -k -v 0 -p -j 7516 -B 'babadd.bable.ad_1600430417' -U 'DBM' -c 'babadd.bable.ad' -f 'babnbu2.bable.ad' -i '@aaaad' ' 16:28:41.384 [73065] <2> process_requests: BPCD_DISCONNECT_RQST 16:28:41.384 [73065] <2> bpcd exit_bpcd: exit status 0 ----------->exiting 16:28:41.575 [1808081] <2> bpcd main: accept sock = 17 16:28:41.576 [73070] <2> daemon_proxy_proto: Preparing to do daemon protocol for (10.240.100.14:13782 <- 10.240.100.14:47409) 16:28:41.578 [73070] <2> readJsonMapFileBaseEx: Reading certmapinfo 16:28:41.579 [73070] <2> process_requests: offset to GMT -36000 16:28:41.579 [73070] <2> logconnections: BPCD ACCEPT FROM 10.240.100.14.47409 TO 10.240.100.14.13782 fd = 0 [bpdbm] 16:28:40.860 [56264] <2> logconnections: BPDBM ACCEPT FROM 10.240.100.14.56055 TO 10.240.100.14.13721 fd = 11 16:28:40.860 [56264] <2> get_user_identity: Using local Admin creds(user_identity.cpp:158) 16:28:40.860 [56264] <2> image_db: Q_IMAGE_LIST_FILES 16:28:40.897 [56264] <2> logconnections: BPJOBD CONNECT FROM 10.240.100.14.53365 TO 10.240.100.14.13723 fd = 15 16:28:40.897 [56264] <2> job_authenticate_connection: VxSS authentication check for now... 16:28:40.938 [56264] <2> job_connect: Connected to the host babnbu2.bable.ad contype 53 jobid <0> socket <15> 16:28:40.938 [56264] <2> job_connect: Connected on port 53365 16:28:40.938 [56264] <4> JobdSockList::RegisterSocket: Register socket (15). 16:28:41.005 [56264] <2> CurlMgr::initCurl: hooking curl callback into library:/usr/openv/lib/libnbcurlST.so(curlmgr.h:76) 16:28:41.018 [56264] <8> checkService: Failed to find service: UTF8-Latin1_Factory in loaded service repository 16:28:41.236 [56264] <2> RequestInitialResources: returning 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: requestStatus is 0 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: allocationId : {8363D8C2-0478-11EB-BFD7-5C0AF6244182} 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdr_AllocationKey : 34163 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdr_TpReqFileName : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_MediaServer: babnbu2.bable.ad 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_MediaServerVersion : 830000 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_MediaServerClusterName: 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_MediaKey : 3 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_MediaId : @aaaad 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_DriveKey : 0 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_DriveName : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_PrimaryPath : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_PoolName : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_NdmpControlHost : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_NdmpUserName : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_NdmpClientUserName : 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_RetentionLevel : 0 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_PolicyType : 2 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_JobType : 2 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: results.mdar_MasterServer : babnbu2.bable.ad 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [MEDIADB 1 34163 @aaaad 3 *NULL* 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [VOLUME 1 @aaaad 3 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 {00000000-0000-0000-0000-000000000000} 0] 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [DRIVE 4 *NULL* 0 *NULL* *NULL* 0 0 0 0 0 0 0 0 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 0 ] 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [STORAGE 1 *NULL* 0 0 0 0 0 0 babnbu2.bable.ad babnbu2.bable.ad *NULL*] 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [DISKGROUP 0 8 PureDisk 16 babnbu2.bable.ad 15 babnbu2-msdp-dp] 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [DISKVOLUME 0 6 @aaaad 14 PureDiskVolume 0] 16:28:41.237 [56264] <2> jmcomm_PrintMediaResults: Bptm message : [DISKMOUNTPOINT 0 14 PureDiskVolume] 16:28:41.237 [56264] <2> dbm_start_nbfsd_and_open_nblbc_connection: Invoking nbfsd on media server babnbu2.bable.ad 16:28:41.240 [56264] <2> logconnections: BPCD CONNECT FROM 10.240.100.14.57391 TO 10.240.100.14.13782 fd = 24 16:28:41.246 [56264] <2> bpcr_get_version_rqst: bpcd version: 08300000 16:28:41.246 [56264] <2> bpcr_get_version_rqst: bpcd version: 08300000 16:28:41.385 [56264] <8> retry_getaddrinfo_for_real: [vnet_addrinfo.c:1236] getaddrinfo() failed RV=-1 NAME= SVC=0 errno=2 16:28:41.385 [56264] <8> retry_getaddrinfo: [vnet_addrinfo.c:1075] retry_getaddrinfo_for_real failed RV=-1 NAME= SVC=0 16:28:41.385 [56264] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1906] retry_getaddrinfo() failed RV=-1 NAME= SVC=NULL 16:28:41.385 [56264] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1534] vnet_cached_getaddrinfo_and_update() failed, name=, service=NULL, status=6 16:28:41.385 [56264] <8> vnet_is_local_host: [vnet_addrinfo.c:386] vnet_cached_getaddrinfo() failed STAT=6 RV=-1 NAME= 16:28:41.385 [56264] <8> retry_getaddrinfo_for_real: [vnet_addrinfo.c:1236] getaddrinfo() failed RV=-1 NAME= SVC=0 errno=2 16:28:41.385 [56264] <8> retry_getaddrinfo: [vnet_addrinfo.c:1075] retry_getaddrinfo_for_real failed RV=-1 NAME= SVC=0 16:28:41.385 [56264] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1906] retry_getaddrinfo() failed RV=-1 NAME= SVC=NULL 16:28:41.385 [56264] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1534] vnet_cached_getaddrinfo_and_update() failed, name=, service=NULL, status=6 16:28:41.385 [56264] <8> init_connect_recs: [vnet_connect.c:2199] vnet_cached_getaddrinfo() failed STAT=6 RV=-1 HOST= 16:28:41.385 [56264] <8> connect_to_service: [vnet_connect.c:1904] init_connect_recs() failed 6 0x6 16:28:41.385 [56264] <16> connect_to_service: JSON data = {"allow_large_status": {"timestamp": 1601620121, "who": "vnet_tss_init", "line_number": 32, "comment": "allow vnet status > 255", "data": false}, "direct_connect": {"timestamp": 1601620121, "who": "connect_to_service", "line_number": 1816, "comment": "connect parameters", "data": {"who": "vnet_connect_to_bpcd", "host": "", "service": "bpcd", "override_required_interface": null, "extra_tries_on_connect": 0, "getsock_disable_to": 0, "overide_connect_timeout": 0, "connect_options": {"server": null, "callback_kind": {"number": 1, "symbol": "NBCONF_CALLBACK_KIND_VNETD", "description": "Vnetd"}, "daemon_port_type": {"number": 0, "symbol": "NBCONF_DAEMON_PORT_TYPE_AUTOMATIC", "description": "Automatic"}, "reserved_port_kind": {"number": 0, "symbol": "NBCONF_RESERVED_PORT_KIND_LEGACY", "description": "Legacy"}}}}, "status": {"timestamp": 1601620121, "who": "connect_to_service", "line_number": 2082, "comment": "vnet status", "data": 6}} 16:28:41.385 [56264] <8> vnet_connect_to_bpcd: [vnet_connect.c:620] connect_to_service() failed 6 0x6 16:28:41.385 [56264] <16> local_bpcr_connect: vnet_connect_to_bpcd() failed: 6 16:28:41.385 [56264] <2> local_bpcr_connect: Can't connect to client 16:28:41.385 [56264] <2> ConnectToBPCD: bpcd_connect_and_verify(, ) failed: 48 16:28:41.386 [56264] <16> dbm_open_client_connection: Could not connect to for virtual browse operation, errno=2, bpcd_status=48 16:28:41.386 [56264] <2> put_short: (10) network write() error: Bad file descriptor (9); socket = -1 16:28:41.386 [56264] <2> bpcr_disconnect_rqst: bpcr protocol error - couldn't send request type 16:28:41.386 [56264] <16> path_match_file_list: get_file_rec() CLIENT error: 48 image: nfiles: 18 16:28:41.387 [56264] <4> JobdSockList::UnregisterSocket: Unregister socket (15). 16:28:41.391 [56264] <2> job_monitoring_exex: ACK disconnect 16:28:41.391 [56264] <2> job_disconnect: Disconnected 16:28:41.402 [56264] <2> jmcomm_ReleaseAllResourcesForJob: releaseAllResources returns [0] 16:28:41.402 [56264] <2> jmcomm_ReleaseAllResourcesForJob: returning 16:28:41.403 [56264] <2> db_sendSTATUS: Status:48 16:28:41.403 [56264] <2> process_request: request complete: exit status 48 client hostname could not be found; query type: 79 [nbfsd] 16:28:41.308 [73066] <2> debuglog: <2> common_init: nbfsd: starting... @(#) NetBackup_8.3 babnbu2.bable.ad (2020070918, 1601620121 201002.162841) 16:28:41.308 [73066] <2> debuglog: <2> common_init: nbfsd: unix - Linux, babnbu2.bable.ad, 4.18.0-193.19.1.el8_2.x86_64, #1 SMP Mon Sep 14 14:37:00 UTC 2020, x86_64 16:28:41.308 [73066] <2> logparams: /usr/openv/netbackup/bin/nbfsd -k -v 0 -p -j 7516 -B babadd.bable.ad_1600430417 -U DBM -c babadd.bable.ad -f babnbu2.bable.ad -i @aaaad 16:28:41.651 [73071] <2> debuglog: <2> common_init: nbfsd: starting... @(#) NetBackup_8.3 babnbu2.bable.ad (2020070918, 1601620121 201002.162841) 16:28:41.652 [73071] <2> debuglog: <2> common_init: nbfsd: unix - Linux, babnbu2.bable.ad, 4.18.0-193.19.1.el8_2.x86_64, #1 SMP Mon Sep 14 14:37:00 UTC 2020, x86_64 16:28:41.652 [73071] <2> logparams: /usr/openv/netbackup/bin/nbfsd -k -v 0 -p -j 7517 -B babadd.bable.ad_1600862419 -U DBM -c babadd.bable.ad -f babnbu2.bable.ad -i @aaaad 16:28:43.045 [73080] <2> debuglog: <2> common_init: nbfsd: starting... @(#) NetBackup_8.3 babnbu2.bable.ad (2020070918, 1601620123 201002.162843) [vxlogs - 16:40-16:42] 02/10/20 16:28:40.009 V-111-1061 [ImageCatalogImpl_3::ReleaseResultSet_3] Client signature HOST= VER=<830000> APP= PID=<1809085> 02/10/20 16:28:40.009 [ImageCatalogImpl_3::ReleaseResultSet_3] retval - <0> 02/10/20 16:28:40.038 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:40.039 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:40.039 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:40.039 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:40.039 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:40.039 [FATServiceManagerImpl::FATServiceManagerImpl()#26] Constructing FATServiceManagerImpl(FATServiceManagerImpl.cpp:62) 02/10/20 16:28:40.039 [MgrUtils_T::execute] FATService IOR: IOR:010000003f00000049444c3a53796d616e7465632f4e65744261636b75702f534c2f464154536572766963654d676d742f464154536572766963654d616e616765723a312e300000010000000149434fa100000001010250110000006261626e6275322e6261626c652e616400001406050000006e62736c007265001b00000014010f005253547de86b5f558c01004b0000000f000000c66a00003f03000000000000000800000001d10f24004f4154010000001400000001d10f240100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:40.052 V-111-1061 [ServerImpl::GetInterfaceRef] Client signature none 02/10/20 16:28:40.052 [ServerImpl::GetInterfaceRef] For version <1> 02/10/20 16:28:40.052 [ServerImpl::GetInterfaceRef] retval - <0> 02/10/20 16:28:40.054 V-111-1061 [MachineImpl::QueryMachine] Client signature none 02/10/20 16:28:40.054 [MachineImpl::QueryMachine] - MachineName = babnbu2.bable.ad MachineNbuType = 6 02/10/20 16:28:40.054 [MachineImpl::QueryMachine] retval - <0> 02/10/20 16:28:40.123 V-111-1061 [ServerImpl::GetInterfaceRef] Client signature none 02/10/20 16:28:40.123 [ServerImpl::GetInterfaceRef] For version <1> 02/10/20 16:28:40.123 [ServerImpl::GetInterfaceRef] retval - <0> 02/10/20 16:28:40.139 [FATServiceQueryFacetImpl::getFATServerList#26] getListOfFATServers returns 0 Number of servers(FATServiceQueryFacetImpl.cpp:81) 02/10/20 16:28:40.173 [FATServiceQueryFacetImpl::getSANClientList#26] getListOfFATClients returns 0 number of clients(FATServiceQueryFacetImpl.cpp:185) 02/10/20 16:28:40.237 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:40.237 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:40.237 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:40.237 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:40.237 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:40.238 [AuditManagerImpl::AuditManagerImpl] Constructing AuditManagerImpl(AuditManagerImpl.cpp:38) 02/10/20 16:28:40.238 [MgrUtils_T::execute] AuditManagerImpl IOR: IOR:010000003500000049444c3a53796d616e7465632f4e65744261636b75702f534c2f41756469744d676d742f41756469744d616e616765723a312e3000000000010000000149434fa100000001010274110000006261626e6275322e6261626c652e616400001406050000006e62736c007265001b00000014010f005253547de86b5f558c01000700000008000000c86a00003f03000000000000000800000001490524004f41540100000014000000014905240100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:40.300 [AuditManagerImpl::createFacetImpl] Creating a audit query facet implementation(AuditManagerImpl.cpp:69) 02/10/20 16:28:40.310 V-111-1061 [MachineConfigImpl::ListMachineConfig] Client signature HOST= VER=<830000> APP= PID=<1809085> 02/10/20 16:28:40.310 [MachineConfigImpl::ListMachineConfig] machineName = < babnbu2.bable.ad > type 1 02/10/20 16:28:40.313 [MachineConfigImpl::ListMachineConfig] retval - <0> 02/10/20 16:28:40.319 [AuditQueryFacetImpl::convert_AuditSettings#26] Auditing is : ENABLED(AuditQueryFacetImpl.cpp:105) 02/10/20 16:28:40.319 [AuditQueryFacetImpl::convert_AuditSettings#26] Audit retention period is : 90(AuditQueryFacetImpl.cpp:111) 02/10/20 16:28:40.369 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.389 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.389 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={82E778EA-0478-11EB-B873-2272F3712684} #RECS_NOW=1 #SO_FAR=1 #QS::m_lastark=4278(AuditTrailServant.cpp:673) 02/10/20 16:28:40.718 [isAlive()] isAlive failed or empty-object(Utils.cpp:501) 02/10/20 16:28:40.718 [makeIORPath()] Proxy IORPath Name is:/usr/openv/var/nbproxy_nbsl-JobManager-26-33-1601620120.ior 02/10/20 16:28:40.719 [HeartBeatableFacet::copyIORPath()] Heartbeat(Global) IOR written at:/usr/openv/var/nbproxy_nbsl-JobManager-26-33-1601620120.ior.mgr(BH_HeartBeatableFacet.cpp:80) 02/10/20 16:28:40.856 [NBPClient::CreateNBP] Writing IOR file::/usr/openv/var/nbproxy_nbsl-JobManager-26-33-1601620120.ior(ProxyHelper.cpp:173) 02/10/20 16:28:40.856 [NBPClient::CreateNBP] Finished writing IOR file::/usr/openv/var/nbproxy_nbsl-JobManager-26-33-1601620120.ior(ProxyHelper.cpp:177) 02/10/20 16:28:40.856 [ProxyHolder::proxy()] created new proxy with ID:JobManager-26-33-1601620120(CORBAConnection.h:506) 02/10/20 16:28:40.856 [ProxyHolder::proxy()] returning new proxy with ID:JobManager-26-33-1601620120(CORBAConnection.h:517) 02/10/20 16:28:40.856 [ProxyConnector::delegateConnect] checking reverse connect for host [babnbu2.bable.ad] and host IP is [10.240.100.14](ProxyConnector.cpp:56) 02/10/20 16:28:40.856 [ProxyConnector::delegateConnect] Reverse connection disabled, PBX direct connect will be tried(ProxyConnector.cpp:92) 02/10/20 16:28:40.892 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.892 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={82E778EA-0478-11EB-B873-2272F3712684} #RECS_NOW=0 #SO_FAR=1 #QS::m_lastark=4278(AuditTrailServant.cpp:673) 02/10/20 16:28:40.921 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.932 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.932 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={833B3D7C-0478-11EB-9A1A-16453D4FFB9B} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:40.980 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.987 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:40.987 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={834440C0-0478-11EB-B4AC-190DE32C20DC} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.014 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.020 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.020 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83495D08-0478-11EB-90A3-3C34507750CD} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.055 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.066 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.066 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={834FB77A-0478-11EB-AC82-24B49C5EC122} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.094 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.106 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.106 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={8355A1D0-0478-11EB-B726-E55FEC02033E} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.112 V-117-257 [JobInst_i::requestResourcesWithTimeout] requesting resource, jobid=7516, reqid=7516, version=1, count=1, caller requestid={83579E54-0478-11EB-9F5D-A86668329090} 02/10/20 16:28:41.112 V-117-298 [JobInst_i::requestResourcesWithTimeout] callback object timeout=600 02/10/20 16:28:41.124 [Info] V-117-64 Initiating foreign job (jobid=7516) VBRQ 1 1 7516 Unknown Unknown Unknown 02/10/20 16:28:41.124 [ExportedResourceMgr::ExportedResourceMgr] (0x7f738c050990) ExportedResourceMgr, jobid=7516, reqid=0(ExportedResourceMgr.cpp:118) 02/10/20 16:28:41.124 V-117-289 [JobInst_i::requestResourcesWithTimeout] starting foreign job, jobid=7516, priority=0, secondPriority=0 02/10/20 16:28:41.127 [ExportedResourceMgr::findExported_1] (0x7f738c050990) NO matching exported resource for request of type=13, reqNum=0, consume=false(ExportedResourceMgr.cpp:626) 02/10/20 16:28:41.127 [ExportedResourceMgr::findReservation] NO reservation found for ExportRequest = 13 reqNum = 0(ExportedResourceMgr.cpp:553) 02/10/20 16:28:41.127 [ExportedResourceMgr::findExported_1] (0x7f738c050990) NO matching exported resource for request of type=13, reqNum=0, consume=false(ExportedResourceMgr.cpp:626) 02/10/20 16:28:41.127 [ExportedResourceMgr::findGroupReservationId] (0x7f738c050990) NO group reservations found(ExportedResourceMgr.cpp:578) 02/10/20 16:28:41.127 [DefaultQueue::queueRequest] queue size: 0, queueing RB RBrequestResources : JMRequestID={835A9802-0478-11EB-B839-8FF9AF2864B1}, userAllocationId=jobid=7516, request timeout=0, priority=0, secondaryPriority=0, requestorDescription=FOREIGN_JOB_7516, master server=babnbu2.bable.ad, requestSequence[0] provider=DriveOperationProvider, resourcename=MEDIA RESOURCE -- retry count=-1(CallbackQueue.cpp:1374) 02/10/20 16:28:41.127 [DefaultQueue::handle_input] sending RB RBrequestResources : JMRequestID={835A9802-0478-11EB-B839-8FF9AF2864B1}, userAllocationId=jobid=7516, request timeout=0(CallbackQueue.cpp:1509) 02/10/20 16:28:41.127 [EndpointSelector_R2::SetEndPointHostname] epsr2: No Endpoint found with host name, All Endpoints are IP addresses(Endpoint_Selector.cpp:1973) 02/10/20 16:28:41.127 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:41.139 V-118-227 [ResBroker_i::requestResources] received resource request ID {835A9802-0478-11EB-B839-8FF9AF2864B1}, priority 0, secondary priority 0, description FOREIGN_JOB_7516 02/10/20 16:28:41.139 [ResBroker_i::requestResources] RequestSeq: Request=0 provider=DriveOperationProvider resourcename=MEDIA RESOURCE userSequence=0 MediaRequest { mediaId=@aaaad mediaServer= mediaKey=0 userReservationId= assignedTime=0 client= usageType=2 mustBeNdmp=no driveName= drivePath= mediaPool= robotNumber=-1 slotNumber=-1 density=-1 ndmpControlHost= failIfNoMedia=yes externalFile= mediaType=0 mediaSubType=6 isGranularExchange=true NDMPHostName= } 02/10/20 16:28:41.140 [DefaultQueue::handle_input] (0x2f2bfd0) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:41.140 V-118-104 [ResBroker_i::doEvaluation] Evaluation cycle started 02/10/20 16:28:41.141 V-111-1061 [DeviceConfigImpl::getRBCacheDriveList] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.141 [DeviceConfigImpl::getRBCacheDriveList] MasterServer 02/10/20 16:28:41.143 [DeviceConfigImpl::getRBCacheDriveList] retval - <0> 02/10/20 16:28:41.143 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.144 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnits] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.144 [StorageUnitImpl_2::ListRBCacheStorageUnits] Master = babnbu2.bable.ad 02/10/20 16:28:41.145 [StorageUnitImpl_2::ListRBCacheStorageUnits] retval - <0> 02/10/20 16:28:41.146 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.146 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Master = babnbu2.bable.ad 02/10/20 16:28:41.147 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] retval - <0> 02/10/20 16:28:41.148 V-111-1061 [MachineImpl::QueryMachine] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.148 [MachineImpl::QueryMachine] - MachineName = babnbu2.bable.ad MachineNbuType = 6 02/10/20 16:28:41.148 [MachineImpl::QueryMachine] retval - <0> 02/10/20 16:28:41.149 V-118-105 [ResBroker_i::doEvaluation] Resource evaluation started 02/10/20 16:28:41.149 [ResBroker_i::evaluateOne] Evaluating request ID {835A9802-0478-11EB-B839-8FF9AF2864B1} 02/10/20 16:28:41.153 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.153 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={835D1B2C-0478-11EB-962D-A00523495221} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.158 [allocateMedia] INITIATING: 02/10/20 16:28:41.158 [allocateMedia] masterServer = babnbu2.bable.ad, client = , jobType = 2, capabilityFlags = 1024, fatPipePreference = 0, statusOnly = 0 02/10/20 16:28:41.158 [allocateMedia] MediaRequest_Record: MediaServer = , PreferredMediaServer = , MediaId = @aaaad, MediaKey = 0, AssignedTime = 0, DriveName = , DrivePath = , PoolName = , Density = -1, RequiredNdmpTapeServer = , PreferredNdmpTapeServer = , MediaType = 0, MediaSubType = 6, StuNameForDupWrite = , FeatureNumber = -1 02/10/20 16:28:41.172 V-111-1061 [ServerImpl::GetInterfaceRef] Client signature none 02/10/20 16:28:41.172 [ServerImpl::GetInterfaceRef] For version <1> 02/10/20 16:28:41.172 [ServerImpl::GetInterfaceRef] retval - <0> 02/10/20 16:28:41.174 V-111-1061 [MachineImpl::QueryMachinesWithFilter] Client signature Config_Webapp_Sig 02/10/20 16:28:41.174 [MachineImpl::QueryMachinesWithFilter] MachineName <>, MachineNbuType <0>, MachineFlags <-1>, QueryType < (19) CEMM_MACHINE_QUERY_ALL_NBWSS_ENDPOINTS > 02/10/20 16:28:41.175 [MachineImpl::QueryMachinesWithFilter] retval - <0> 02/10/20 16:28:41.185 [fill_bsr] ALLOCATION: key = 34163, media server = babnbu2.bable.ad, mds_flags = 0, scsi_protection = 0, preempt_reservation = 0, preempted_ms_key = 0 02/10/20 16:28:41.185 [fill_bsr] MEDIA: id = @aaaad, key = 3 02/10/20 16:28:41.185 [fill_bsr] DRIVE: name = *NULL*, path = , secondary_path = , key = 0, ndmp_host_key = 0 02/10/20 16:28:41.185 [fill_bsr] STU: name = *NULL*, master server = *NULL* 02/10/20 16:28:41.185 [fill_bsr] DISKGROUP: id = babnbu2-msdp-dp, key = 2 02/10/20 16:28:41.185 [fill_bsr] DISKVOLUME: media_id = @aaaad, key = 3 02/10/20 16:28:41.185 [fill_bsr] DISKMOUNTPOINT: mount_point = PureDiskVolume, key = 2 02/10/20 16:28:41.185 [allocateMedia] EXIT INFO: 02/10/20 16:28:41.185 [allocateMedia] rbActions = 0 02/10/20 16:28:41.185 [allocateMedia] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:41.187 V-118-202 [EMMAccess::allocateMedia] request to allocate media (Master Server babnbu2.bable.ad, Client , Job Type 2, Media ID @aaaad, Drive Name , Media Server , Capabilities 1024, Fibre Transport Preference 0, Assigned Time 0) returned 0 02/10/20 16:28:41.187 [EMMAccess::allocateMedia] media allocated: mediaId=@aaaad, driveName=, mediaServer=babnbu2.bable.ad, allocationKey=34163 02/10/20 16:28:41.189 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.196 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.196 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83641AC6-0478-11EB-BDFF-735B806C4A0D} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.211 [ProviderManager::allocate] DriveOperationProvider returned Allocation Granted for request ID {835A9802-0478-11EB-B839-8FF9AF2864B1} 02/10/20 16:28:41.211 [ResBroker_i::evaluateOne] resources found for request, requestId={835A9802-0478-11EB-B839-8FF9AF2864B1}, userId=jobid=7516, birthTime=1601620121, timeToFirstEval=0 sec, timeToSuccessOrFailure=0 sec, numberOfTimesEvaluated=1 02/10/20 16:28:41.211 V-118-109 [ResBroker_i::passOne] resources found for request ID {835A9802-0478-11EB-B839-8FF9AF2864B1}, following allocations are granted: 02/10/20 16:28:41.211 V-118-228 [ResBroker_i::passOne] allocation ID {8363D8C2-0478-11EB-BFD7-5C0AF6244182}, group ID {00000000-0000-0000-0000-000000000000}, provider DriveOperationProvider, resource @aaaad 02/10/20 16:28:41.211 [ResBroker_i::passOne] allocation: (Allocation: id={8363D8C2-0478-11EB-BFD7-5C0AF6244182} provider=DriveOperationProvider resourcename=@aaaad masterserver=babnbu2.bable.ad groupid={00000000-0000-0000-0000-000000000000} userSequence=0 userid="jobid=7516" firstuserid="jobid=7516" (Media_Drive_Allocation_Record: allocationKey=34163 (Media_Drive_Record: MediaKey=3 MediaId=@aaaad MediaServer=babnbu2.bable.ad DriveKey=0 DriveName= PrimaryPath= PoolName= RobotNum=0 RobotType=0 MediaTypeName= DriveTypeName= NdmpControlHost= RetentionLevel=0 PolicyType=2 JobType=2 MasterServer=babnbu2.bable.ad) (Storage_Unit_Record: STU= STUType=0 MasterServer= MediaServer= RobotType=0 RobotNumber=0 Density=0 OnDemandOnly=0 ConcurrentJobs=0 ActiveJobs=0 MaxMultiplexing=0 NdmpAttachHost= AbsolutePath=) (Bptm_Strings_Record: 0="MEDIADB 1 34163 @aaaad 3 *NULL* 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0" 1="VOLUME 1 @aaaad 3 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 {00000000-0000-0000-0000-000000000000} 0" 2="DRIVE 4 *NULL* 0 *NULL* *NULL* 0 0 0 0 0 0 0 0 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 0" 3="STORAGE 1 *NULL* 0 0 0 0 0 0 babnbu2.bable.ad babnbu2.bable.ad *NULL*" 4="DISKGROUP 0 8 PureDisk 16 babnbu2.bable.ad 15 babnbu2-msdp-dp" 5="DISKVOLUME 0 6 @aaaad 14 PureDiskVolume 0" 6="DISKMOUNTPOINT 0 14 PureDiskVolume" ) TpReqFileName=) useFatPipeTransport=false diskPath=PureDiskVolume diskGroupName=babnbu2-msdp-dp storageServerType=PureDisk diskGroupStorageServerName=babnbu2.bable.ad failureCode=0) 02/10/20 16:28:41.213 V-118-249 [CallbackQueue::resourcesAvailable] added allocations to the callback queue for request ID {835A9802-0478-11EB-B839-8FF9AF2864B1} 02/10/20 16:28:41.215 V-118-250 [CallbackQueue::notifyClientAvailable] queueing notification of availability of resources for request ID {835A9802-0478-11EB-B839-8FF9AF2864B1} 02/10/20 16:28:41.215 V-118-106 [ResBroker_i::doEvaluation] Resource evaluation completed. Evaluated 1 requests, sent resource pending for 0 requests, evaluation time 66 msec 02/10/20 16:28:41.215 [ResBroker_i::doEvaluation] Evaluated 1 requests, evalTime=66 msec, numSucceeded=1, numQueued=0, numPended=0, numFailed=0, numMultipleCopyJobs=0, numMdsCacheMisses=0, restartedEvalCycle=0, numDriveReleasesBeforeEval=0, numDrivesAvailStart=0, numDrivesAvailEnd=0, requestQueueSize=0 02/10/20 16:28:41.215 V-118-256 [CorbaCall_notifyClientAvailable::execute] sending availability of resources to nbjm for request ID {835A9802-0478-11EB-B839-8FF9AF2864B1} 02/10/20 16:28:41.222 V-117-248 [ResCallback_i::resourcesAvailable] resources available for jobid=jobid=7516, reqid={835A9802-0478-11EB-B839-8FF9AF2864B1} 02/10/20 16:28:41.225 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.225 [JobMgrPriv::queueRequest] queue size: 0, queueing JMP resourcesAvailable : requestId={83579E54-0478-11EB-9F5D-A86668329090} -- retry count=3(CallbackQueue.cpp:1374) 02/10/20 16:28:41.226 [JobMgrPriv::handle_input] sending JMP resourcesAvailable : requestId={83579E54-0478-11EB-9F5D-A86668329090}(CallbackQueue.cpp:1509) 02/10/20 16:28:41.227 [ProxyConnector::delegateConnect] checking reverse connect for host [babnbu2.bable.ad] and host IP is [10.240.100.14](ProxyConnector.cpp:56) 02/10/20 16:28:41.227 [ProxyConnector::delegateConnect] Reverse connection disabled, PBX direct connect will be tried(ProxyConnector.cpp:92) 02/10/20 16:28:41.233 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.233 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={8369AAB8-0478-11EB-9C56-50A80C73C196} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.236 [JobMgrPriv::handle_input] (0x2f38880) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:41.236 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:41.263 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.269 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.269 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={836F590E-0478-11EB-BA1B-3908B956C987} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.300 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.308 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.308 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={837512FE-0478-11EB-9D43-244BC85DCFB2} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.334 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.340 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.340 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={837A4832-0478-11EB-A735-1E5C8A5D5034} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.363 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.373 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.373 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={837EA198-0478-11EB-9FE3-F3852C2A37A8} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.391 V-117-259 [JobInst_i::releaseAllResources] release all resources, jobid=7516 02/10/20 16:28:41.391 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:41.391 [ExportedResourceMediaDrive::getReleaseDelayCallback] no release delay specified for MediaDriveResource: MasterServer=babnbu2.bable.ad MediaServer=babnbu2.bable.ad MediaServerVersion=830000 MediaServerClusterName=None MediaId=@aaaad MediaKey=3 DriveKey=0 DriveName=None PrimaryPath=None SerialNumber=None PoolName=None NdmpControlHost=None NdmpUserName=None NdmpPassword=****** NdmpPasswordKey=****** NdmpClientUserName=None NdmpClientPassword=****** NdmpClientPasswordKey=****** RetentionLevel=0 PolicyType=2 JobType=2 AllocationType=1 exportable = 1 requestId = {835A9802-0478-11EB-B839-8FF9AF2864B1} JMowned = 0 Allocation -- id={8363D8C2-0478-11EB-BFD7-5C0AF6244182}, usn=0, groupId={00000000-0000-0000-0000-000000000000}, allowMultipleRetentions=false, allocationType=1, provider=DriveOperationProvider, resourcename=@aaaad, userAllocationId=jobid=7516, masterServer=babnbu2.bable.ad(ExportedResource.cpp:1268) 02/10/20 16:28:41.392 [DefaultQueue::queueRequest] queue size: 0, queueing RB RBrelease : id={8363D8C2-0478-11EB-BFD7-5C0AF6244182} -- retry count=-1(CallbackQueue.cpp:1374) 02/10/20 16:28:41.392 [DefaultQueue::handle_input] sending RB RBrelease : id={8363D8C2-0478-11EB-BFD7-5C0AF6244182}(CallbackQueue.cpp:1509) 02/10/20 16:28:41.392 [EndpointSelector_R2::SetEndPointHostname] epsr2: No Endpoint found with host name, All Endpoints are IP addresses(Endpoint_Selector.cpp:1973) 02/10/20 16:28:41.401 [Info] V-117-239 terminated job, jobid=7516, status=0 VBRF 1 0 02/10/20 16:28:41.401 [ExportedResourceMgr::~ExportedResourceMgr] (0x7f738c050990) nothing found to release or release on destruction is false(ExportedResourceMgr.cpp:162) 02/10/20 16:28:41.401 [DefaultQueue::handle_input] (0x2f2bfd0) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:41.401 V-118-93 [ResBroker_i::release(id)] releasing allocation ID {8363D8C2-0478-11EB-BFD7-5C0AF6244182}, status 0 02/10/20 16:28:41.401 V-118-104 [ResBroker_i::doEvaluation] Evaluation cycle started 02/10/20 16:28:41.401 V-118-102 [ResBroker_i::releaseOne] releasing allocation ID {8363D8C2-0478-11EB-BFD7-5C0AF6244182} 02/10/20 16:28:41.401 [EMMProvider::release(mdar)] received release of mediaId=@aaaad, driveName=, STU= 02/10/20 16:28:41.403 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.409 [downStuCnts] INITIATING: 02/10/20 16:28:41.409 [downStuCnts] allocationKey = 34163 02/10/20 16:28:41.409 [JobOtherAsyncDataHandler::handle_input] ERROR, still continue. Proxy::file-size failed backupId:babadd.bable.ad_1600430417, errorcode:48(JobManagerImpl.cpp:642) 02/10/20 16:28:41.409 [JobOtherAsyncDataHandler::handle_input] NOT calling back for backupid:babadd.bable.ad_1600430417, errorcode:48 is retriable(JobManagerImpl.cpp:669) 02/10/20 16:28:41.410 [downStuCnts] EXIT INFO: 02/10/20 16:28:41.410 [downStuCnts] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:41.410 V-118-217 [EMMAccess::downStuCnts] request to down STU counts (STU , Allocation Key 34163) returned 0 02/10/20 16:28:41.413 [deallocate] INITIATING: 02/10/20 16:28:41.413 [deallocate] deallocType = 1 02/10/20 16:28:41.413 [deallocate] allocationKey = 34163 02/10/20 16:28:41.417 [deallocate] EXIT INFO: 02/10/20 16:28:41.417 [deallocate] rbActions = 0 02/10/20 16:28:41.417 [deallocate] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:41.419 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.419 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={8384D6DA-0478-11EB-91AE-FF67A17ABD9C} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.420 V-118-215 [EMMAccess::deallocate] request to deallocate resources (Allocation Key 34163, Deallocation Type 1) returned 0 02/10/20 16:28:41.420 [EMMAccess::deallocate] deallocated resource (allocationKey=34163) 02/10/20 16:28:41.432 V-111-1061 [DeviceConfigImpl::getRBCacheDriveList] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.432 [DeviceConfigImpl::getRBCacheDriveList] MasterServer 02/10/20 16:28:41.434 [DeviceConfigImpl::getRBCacheDriveList] retval - <0> 02/10/20 16:28:41.435 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnits] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.435 [StorageUnitImpl_2::ListRBCacheStorageUnits] Master = babnbu2.bable.ad 02/10/20 16:28:41.436 [StorageUnitImpl_2::ListRBCacheStorageUnits] retval - <0> 02/10/20 16:28:41.437 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.437 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Master = babnbu2.bable.ad 02/10/20 16:28:41.438 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] retval - <0> 02/10/20 16:28:41.438 V-111-1061 [MachineImpl::QueryMachine] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.438 [MachineImpl::QueryMachine] - MachineName = babnbu2.bable.ad MachineNbuType = 6 02/10/20 16:28:41.438 [MachineImpl::QueryMachine] retval - <0> 02/10/20 16:28:41.439 V-118-105 [ResBroker_i::doEvaluation] Resource evaluation started 02/10/20 16:28:41.439 V-118-106 [ResBroker_i::doEvaluation] Resource evaluation completed. Evaluated 0 requests, sent resource pending for 0 requests, evaluation time 0 msec 02/10/20 16:28:41.439 [ResBroker_i::doEvaluation] Evaluated 0 requests, evalTime=0 msec, numSucceeded=0, numQueued=0, numPended=0, numFailed=0, numMultipleCopyJobs=0, numMdsCacheMisses=0, restartedEvalCycle=0, numDriveReleasesBeforeEval=0, numDrivesAvailStart=0, numDrivesAvailEnd=0, requestQueueSize=0 02/10/20 16:28:41.445 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.452 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.452 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={838B28BE-0478-11EB-A4AE-3138A01325B3} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.473 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.480 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.480 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={838F7FD6-0478-11EB-B74B-38776E611B56} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.509 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.516 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.516 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={8394E1D8-0478-11EB-B216-E29AEA7E215D} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.523 V-117-257 [JobInst_i::requestResourcesWithTimeout] requesting resource, jobid=7517, reqid=7517, version=1, count=1, caller requestid={8396B4D6-0478-11EB-8697-A982CC7268DA} 02/10/20 16:28:41.523 V-117-298 [JobInst_i::requestResourcesWithTimeout] callback object timeout=600 02/10/20 16:28:41.524 [Info] V-117-64 Initiating foreign job (jobid=7517) VBRQ 1 1 7517 Unknown Unknown Unknown 02/10/20 16:28:41.524 [ExportedResourceMgr::ExportedResourceMgr] (0x7f73a000abf0) ExportedResourceMgr, jobid=7517, reqid=0(ExportedResourceMgr.cpp:118) 02/10/20 16:28:41.524 V-117-289 [JobInst_i::requestResourcesWithTimeout] starting foreign job, jobid=7517, priority=0, secondPriority=0 02/10/20 16:28:41.524 [ExportedResourceMgr::findExported_1] (0x7f73a000abf0) NO matching exported resource for request of type=13, reqNum=0, consume=false(ExportedResourceMgr.cpp:626) 02/10/20 16:28:41.524 [ExportedResourceMgr::findReservation] NO reservation found for ExportRequest = 13 reqNum = 0(ExportedResourceMgr.cpp:553) 02/10/20 16:28:41.524 [ExportedResourceMgr::findExported_1] (0x7f73a000abf0) NO matching exported resource for request of type=13, reqNum=0, consume=false(ExportedResourceMgr.cpp:626) 02/10/20 16:28:41.524 [ExportedResourceMgr::findGroupReservationId] (0x7f73a000abf0) NO group reservations found(ExportedResourceMgr.cpp:578) 02/10/20 16:28:41.524 [DefaultQueue::queueRequest] queue size: 0, queueing RB RBrequestResources : JMRequestID={83973AFA-0478-11EB-9128-3D885E289D6D}, userAllocationId=jobid=7517, request timeout=0, priority=0, secondaryPriority=0, requestorDescription=FOREIGN_JOB_7517, master server=babnbu2.bable.ad, requestSequence[0] provider=DriveOperationProvider, resourcename=MEDIA RESOURCE -- retry count=-1(CallbackQueue.cpp:1374) 02/10/20 16:28:41.525 [DefaultQueue::handle_input] sending RB RBrequestResources : JMRequestID={83973AFA-0478-11EB-9128-3D885E289D6D}, userAllocationId=jobid=7517, request timeout=0(CallbackQueue.cpp:1509) 02/10/20 16:28:41.525 [EndpointSelector_R2::SetEndPointHostname] epsr2: No Endpoint found with host name, All Endpoints are IP addresses(Endpoint_Selector.cpp:1973) 02/10/20 16:28:41.525 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:41.525 V-118-227 [ResBroker_i::requestResources] received resource request ID {83973AFA-0478-11EB-9128-3D885E289D6D}, priority 0, secondary priority 0, description FOREIGN_JOB_7517 02/10/20 16:28:41.525 [ResBroker_i::requestResources] RequestSeq: Request=0 provider=DriveOperationProvider resourcename=MEDIA RESOURCE userSequence=0 MediaRequest { mediaId=@aaaad mediaServer= mediaKey=0 userReservationId= assignedTime=0 client= usageType=2 mustBeNdmp=no driveName= drivePath= mediaPool= robotNumber=-1 slotNumber=-1 density=-1 ndmpControlHost= failIfNoMedia=yes externalFile= mediaType=0 mediaSubType=6 isGranularExchange=true NDMPHostName= } 02/10/20 16:28:41.526 V-111-1061 [DeviceConfigImpl::getRBCacheDriveList] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.526 [DefaultQueue::handle_input] (0x2f2bfd0) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:41.526 V-118-104 [ResBroker_i::doEvaluation] Evaluation cycle started 02/10/20 16:28:41.527 [DeviceConfigImpl::getRBCacheDriveList] MasterServer 02/10/20 16:28:41.529 [DeviceConfigImpl::getRBCacheDriveList] retval - <0> 02/10/20 16:28:41.530 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnits] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.530 [StorageUnitImpl_2::ListRBCacheStorageUnits] Master = babnbu2.bable.ad 02/10/20 16:28:41.531 [StorageUnitImpl_2::ListRBCacheStorageUnits] retval - <0> 02/10/20 16:28:41.532 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.532 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Master = babnbu2.bable.ad 02/10/20 16:28:41.533 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] retval - <0> 02/10/20 16:28:41.534 V-111-1061 [MachineImpl::QueryMachine] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:41.534 [MachineImpl::QueryMachine] - MachineName = babnbu2.bable.ad MachineNbuType = 6 02/10/20 16:28:41.534 [MachineImpl::QueryMachine] retval - <0> 02/10/20 16:28:41.535 V-118-105 [ResBroker_i::doEvaluation] Resource evaluation started 02/10/20 16:28:41.535 [ResBroker_i::evaluateOne] Evaluating request ID {83973AFA-0478-11EB-9128-3D885E289D6D} 02/10/20 16:28:41.539 [allocateMedia] INITIATING: 02/10/20 16:28:41.539 [allocateMedia] masterServer = babnbu2.bable.ad, client = , jobType = 2, capabilityFlags = 1024, fatPipePreference = 0, statusOnly = 0 02/10/20 16:28:41.539 [allocateMedia] MediaRequest_Record: MediaServer = , PreferredMediaServer = , MediaId = @aaaad, MediaKey = 0, AssignedTime = 0, DriveName = , DrivePath = , PoolName = , Density = -1, RequiredNdmpTapeServer = , PreferredNdmpTapeServer = , MediaType = 0, MediaSubType = 6, StuNameForDupWrite = , FeatureNumber = -1 02/10/20 16:28:41.542 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.547 [fill_bsr] ALLOCATION: key = 34164, media server = babnbu2.bable.ad, mds_flags = 0, scsi_protection = 0, preempt_reservation = 0, preempted_ms_key = 0 02/10/20 16:28:41.548 [fill_bsr] MEDIA: id = @aaaad, key = 3 02/10/20 16:28:41.548 [fill_bsr] DRIVE: name = *NULL*, path = , secondary_path = , key = 0, ndmp_host_key = 0 02/10/20 16:28:41.548 [fill_bsr] STU: name = *NULL*, master server = *NULL* 02/10/20 16:28:41.548 [fill_bsr] DISKGROUP: id = babnbu2-msdp-dp, key = 2 02/10/20 16:28:41.548 [fill_bsr] DISKVOLUME: media_id = @aaaad, key = 3 02/10/20 16:28:41.548 [fill_bsr] DISKMOUNTPOINT: mount_point = PureDiskVolume, key = 2 02/10/20 16:28:41.548 [allocateMedia] EXIT INFO: 02/10/20 16:28:41.548 [allocateMedia] rbActions = 0 02/10/20 16:28:41.548 [allocateMedia] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:41.550 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.550 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={8399F736-0478-11EB-B941-91A7FD1F6691} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.551 V-118-202 [EMMAccess::allocateMedia] request to allocate media (Master Server babnbu2.bable.ad, Client , Job Type 2, Media ID @aaaad, Drive Name , Media Server , Capabilities 1024, Fibre Transport Preference 0, Assigned Time 0) returned 0 02/10/20 16:28:41.551 [EMMAccess::allocateMedia] media allocated: mediaId=@aaaad, driveName=, mediaServer=babnbu2.bable.ad, allocationKey=34164 02/10/20 16:28:41.565 [ProviderManager::allocate] DriveOperationProvider returned Allocation Granted for request ID {83973AFA-0478-11EB-9128-3D885E289D6D} 02/10/20 16:28:41.565 [ResBroker_i::evaluateOne] resources found for request, requestId={83973AFA-0478-11EB-9128-3D885E289D6D}, userId=jobid=7517, birthTime=1601620121, timeToFirstEval=0 sec, timeToSuccessOrFailure=0 sec, numberOfTimesEvaluated=1 02/10/20 16:28:41.565 V-118-109 [ResBroker_i::passOne] resources found for request ID {83973AFA-0478-11EB-9128-3D885E289D6D}, following allocations are granted: 02/10/20 16:28:41.565 V-118-228 [ResBroker_i::passOne] allocation ID {839B842A-0478-11EB-9885-0A97684254DA}, group ID {00000000-0000-0000-0000-000000000000}, provider DriveOperationProvider, resource @aaaad 02/10/20 16:28:41.565 [ResBroker_i::passOne] allocation: (Allocation: id={839B842A-0478-11EB-9885-0A97684254DA} provider=DriveOperationProvider resourcename=@aaaad masterserver=babnbu2.bable.ad groupid={00000000-0000-0000-0000-000000000000} userSequence=0 userid="jobid=7517" firstuserid="jobid=7517" (Media_Drive_Allocation_Record: allocationKey=34164 (Media_Drive_Record: MediaKey=3 MediaId=@aaaad MediaServer=babnbu2.bable.ad DriveKey=0 DriveName= PrimaryPath= PoolName= RobotNum=0 RobotType=0 MediaTypeName= DriveTypeName= NdmpControlHost= RetentionLevel=0 PolicyType=2 JobType=2 MasterServer=babnbu2.bable.ad) (Storage_Unit_Record: STU= STUType=0 MasterServer= MediaServer= RobotType=0 RobotNumber=0 Density=0 OnDemandOnly=0 ConcurrentJobs=0 ActiveJobs=0 MaxMultiplexing=0 NdmpAttachHost= AbsolutePath=) (Bptm_Strings_Record: 0="MEDIADB 1 34164 @aaaad 3 *NULL* 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0" 1="VOLUME 1 @aaaad 3 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 {00000000-0000-0000-0000-000000000000} 0" 2="DRIVE 4 *NULL* 0 *NULL* *NULL* 0 0 0 0 0 0 0 0 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 0" 3="STORAGE 1 *NULL* 0 0 0 0 0 0 babnbu2.bable.ad babnbu2.bable.ad *NULL*" 4="DISKGROUP 0 8 PureDisk 16 babnbu2.bable.ad 15 babnbu2-msdp-dp" 5="DISKVOLUME 0 6 @aaaad 14 PureDiskVolume 0" 6="DISKMOUNTPOINT 0 14 PureDiskVolume" ) TpReqFileName=) useFatPipeTransport=false diskPath=PureDiskVolume diskGroupName=babnbu2-msdp-dp storageServerType=PureDisk diskGroupStorageServerName=babnbu2.bable.ad failureCode=0) 02/10/20 16:28:41.566 V-118-249 [CallbackQueue::resourcesAvailable] added allocations to the callback queue for request ID {83973AFA-0478-11EB-9128-3D885E289D6D} 02/10/20 16:28:41.569 V-118-250 [CallbackQueue::notifyClientAvailable] queueing notification of availability of resources for request ID {83973AFA-0478-11EB-9128-3D885E289D6D} 02/10/20 16:28:41.569 V-118-106 [ResBroker_i::doEvaluation] Resource evaluation completed. Evaluated 1 requests, sent resource pending for 0 requests, evaluation time 34 msec 02/10/20 16:28:41.569 [ResBroker_i::doEvaluation] Evaluated 1 requests, evalTime=34 msec, numSucceeded=1, numQueued=0, numPended=0, numFailed=0, numMultipleCopyJobs=0, numMdsCacheMisses=0, restartedEvalCycle=0, numDriveReleasesBeforeEval=0, numDrivesAvailStart=0, numDrivesAvailEnd=0, requestQueueSize=0 02/10/20 16:28:41.569 V-118-256 [CorbaCall_notifyClientAvailable::execute] sending availability of resources to nbjm for request ID {83973AFA-0478-11EB-9128-3D885E289D6D} 02/10/20 16:28:41.571 V-117-248 [ResCallback_i::resourcesAvailable] resources available for jobid=jobid=7517, reqid={83973AFA-0478-11EB-9128-3D885E289D6D} 02/10/20 16:28:41.571 [JobMgrPriv::queueRequest] queue size: 0, queueing JMP resourcesAvailable : requestId={8396B4D6-0478-11EB-8697-A982CC7268DA} -- retry count=3(CallbackQueue.cpp:1374) 02/10/20 16:28:41.572 [JobMgrPriv::handle_input] sending JMP resourcesAvailable : requestId={8396B4D6-0478-11EB-8697-A982CC7268DA}(CallbackQueue.cpp:1509) 02/10/20 16:28:41.574 [JobMgrPriv::handle_input] (0x2f38880) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:41.574 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:41.579 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.587 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.587 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={839FA1A4-0478-11EB-9EB6-0AE07B43C2A6} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.616 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.622 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.622 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83A533C6-0478-11EB-8984-4C67224DE489} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.653 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.661 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.661 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83AAF284-0478-11EB-87E8-2334DF3238CB} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.686 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.693 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.693 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83AFEBAE-0478-11EB-AC8B-AA861028AA00} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.717 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.725 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.725 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83B4B706-0478-11EB-8DF4-1ECDA90515DE} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.755 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.763 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.763 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83BA8960-0478-11EB-B4D6-03E399188AAA} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.791 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.799 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.799 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83C00D18-0478-11EB-B253-AC2E6C7B4AAA} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.827 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.836 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.836 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83C585E0-0478-11EB-9D19-024B5E65F2AE} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.869 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.878 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.878 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83CBE692-0478-11EB-A342-9AF44F20978F} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.906 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.914 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.914 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83D1885E-0478-11EB-B7CE-4E7E80524F04} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:41.942 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.950 [DbConnectionManager::ReleaseMSRConnection] Potential Odbc statement leak <1>(DbConnectionManager.cpp:1231) 02/10/20 16:28:41.950 [AuditTrailServant::fetchWithLocalizedDataImpl] fetched records in current iteration. QH={83D7181E-0478-11EB-A10C-4392E5462503} #RECS_NOW=0 #SO_FAR=0 #QS::m_lastark=0(AuditTrailServant.cpp:673) 02/10/20 16:28:42.002 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:42.002 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:42.002 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:42.002 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:42.002 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:42.002 [ClientManagerImpl::ClientManagerImpl()#26] Constructing ClientManagerImpl(ClientManagerImpl.cpp:35) 02/10/20 16:28:42.002 [MgrUtils_T::execute] ClientManager IOR: IOR:010000003700000049444c3a53796d616e7465632f4e65744261636b75702f534c2f436c69656e744d676d742f436c69656e744d616e616765723a312e300000010000000149434fa1000000010102ff110000006261626e6275322e6261626c652e616400441406050000006e62736c004e65741b00000014010f005253547de86b5f558c01004800000023000000e76a00006103000000000000000800000001650228004f41540100000014000000016502280100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:42.071 [AsyncCollector_T::AsyncCollector_T] Constructing AsyncCollector(BH_AsyncCollector.cpp:39) 02/10/20 16:28:42.071 [isAlive()] isAlive failed or empty-object(Utils.cpp:501) 02/10/20 16:28:42.071 [makeIORPath()] Proxy IORPath Name is:/usr/openv/var/nbproxy_nbsl-ClientManager-26-34-1601620122.ior 02/10/20 16:28:42.072 [HeartBeatableFacet::copyIORPath()] Heartbeat(Global) IOR written at:/usr/openv/var/nbproxy_nbsl-ClientManager-26-34-1601620122.ior.mgr(BH_HeartBeatableFacet.cpp:80) 02/10/20 16:28:42.159 [InsecureNBSLServerEvaluator::serverListCheck] Peer is OpsCenter.(InsecureNBSLServerEvaluator.cpp:41) 02/10/20 16:28:42.168 [HostSessionFactoryImpl::getNBUVersionInfo] NBU Version Seq [1] = 8(HostSessionFactoryImpl.cpp:255) 02/10/20 16:28:42.168 [HostSessionFactoryImpl::getNBUVersionInfo] NBU Version Seq [2] = 3(HostSessionFactoryImpl.cpp:255) 02/10/20 16:28:42.169 [HostSessionFactoryImpl::getNBUVersionInfo] vesrion display:8.3(HostSessionFactoryImpl.cpp:262) 02/10/20 16:28:42.172 [HostSessionFactoryImpl::getNBUVersionInfo] NBU Version Seq [1] = 8(HostSessionFactoryImpl.cpp:255) 02/10/20 16:28:42.172 [HostSessionFactoryImpl::getNBUVersionInfo] NBU Version Seq [2] = 3(HostSessionFactoryImpl.cpp:255) 02/10/20 16:28:42.172 [HostSessionFactoryImpl::getNBUVersionInfo] vesrion display:8.3(HostSessionFactoryImpl.cpp:262) 02/10/20 16:28:42.177 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:42.178 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:42.178 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:42.178 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:42.178 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:42.178 [LicenseManagerImpl::LicenseManagerImpl()#26] Constructing LicenseManagerImpl(LicenseManagerImpl.cpp:42) 02/10/20 16:28:42.178 [MgrUtils_T::execute] LicenseManager IOR: IOR:010000003500000049444c3a53796d616e7465632f4e65744261636b75702f534c2f4c69634d676d742f4c6963656e73654d616e616765723a312e3000000000010000000149434fa100000001010274110000006261626e6275322e6261626c652e616400001406050000006e62736c00626c651b00000014010f005253547de86b5f558c01000600000006000000e96a00003203000000000000000800000001802260004f41540100000014000000018022600100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:42.186 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:42.186 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:42.186 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:42.186 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:42.186 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:42.186 [SearchManagerImpl:SearchManagerImpl()#26] Constructing SearchManagerImpl(SearchManagerImpl.cpp:35) 02/10/20 16:28:42.186 [MgrUtils_T::execute] SearchManager IOR: IOR:010000003700000049444c3a53796d616e7465632f4e65744261636b75702f534c2f5365617263684d676d742f5365617263684d616e616765723a312e300000010000000149434fa100000001010250110000006261626e6275322e6261626c652e616400001406050000006e62736c007265001b00000014010f005253547de86b5f558c01001d00000006000000ea6a00003f03000000000000000800000001790028004f41540100000014000000017900280100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:42.193 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:42.193 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:42.193 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:42.193 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:42.193 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:42.193 [RestoreManagerImpl:RestoreManagerImpl()#26] Constructing RestoreManagerImpl(RestoreManagerImpl.cpp:45) 02/10/20 16:28:42.194 [MgrUtils_T::execute] RestoreManager IOR: IOR:010000003900000049444c3a53796d616e7465632f4e65744261636b75702f534c2f526573746f72654d676d742f526573746f72654d616e616765723a312e3000000000010000000149434fa10000000101026f110000006261626e6275322e6261626c652e616400541406050000006e62736c000000001b00000014010f005253547de86b5f558c01001b00000005000000eb6a00001103000000000000000800000001ed0360004f4154010000001400000001ed03600100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:42.207 [NBPClient::CreateNBP] Writing IOR file::/usr/openv/var/nbproxy_nbsl-ClientManager-26-34-1601620122.ior(ProxyHelper.cpp:173) 02/10/20 16:28:42.208 [NBPClient::CreateNBP] Finished writing IOR file::/usr/openv/var/nbproxy_nbsl-ClientManager-26-34-1601620122.ior(ProxyHelper.cpp:177) 02/10/20 16:28:42.208 [ProxyHolder::proxy()] created new proxy with ID:ClientManager-26-34-1601620122(CORBAConnection.h:506) 02/10/20 16:28:42.208 [ProxyHolder::proxy()] returning new proxy with ID:ClientManager-26-34-1601620122(CORBAConnection.h:517) 02/10/20 16:28:42.208 [ProxyConnector::delegateConnect] checking reverse connect for host [babnbu2.bable.ad] and host IP is [10.240.100.14](ProxyConnector.cpp:56) 02/10/20 16:28:42.208 [ProxyConnector::delegateConnect] Reverse connection disabled, PBX direct connect will be tried(ProxyConnector.cpp:92) 02/10/20 16:28:42.208 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:42.208 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:42.208 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:42.208 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:42.208 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:42.208 [CloudManagerImpl:CloudManagerImpl()#26] Constructing CloudManagerImpl(CloudManagerImpl.cpp:65) 02/10/20 16:28:42.210 [MgrUtils_T::execute] CloudManagement IOR: IOR:010000003500000049444c3a53796d616e7465632f4e65744261636b75702f534c2f436c6f75644d676d742f436c6f75644d616e616765723a312e3000000000010000000149434fa100000001010274110000006261626e6275322e6261626c652e616400001406050000006e62736c007265001b00000014010f005253547de86b5f558c01001c0000000f000000ec6a00003f03000000000000000800000001650228004f41540100000014000000016502280100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:42.304 V-137-311 [LicenseCheck::isFeatureLicensed] Feature id: 77 is not licensed 02/10/20 16:28:42.304 [Error] V-230-20 RDSM has encountered an error: checkLicense():2572 02/10/20 16:28:42.304 [Error] V-230-1 RDSM has encountered a service exception: Error Location: checkLicense():2572, Error Text: checkLicense, Error Domain: 3, Error Code 2,055,003 02/10/20 16:28:42.304 [who] errorDomain=RDSM errorCode=2055003 errorText=checkLicense 02/10/20 16:28:42.304 [Critical] V-178-9 DSM license check on babnbu2.bable.ad failed 02/10/20 16:28:42.319 [StorageServerObject::getDataMovers] MasterServerKey = 0 Not Enabled 02/10/20 16:28:42.323 [StorageServerObject::getDataMovers] MasterServerKey = 0 Not Enabled 02/10/20 16:28:42.328 [CloudQFImpl::getCloudConfiguredMediaServers()] No. of storage servers returned from DSM::7(CloudQFImpl.cpp:546) 02/10/20 16:28:42.328 [CloudQFImpl::getCloudConfiguredMediaServers()] Number of cloud enabled media servers returned = 0(CloudQFImpl.cpp:585) 02/10/20 16:28:42.385 [EventSupplierTask::EventSupplierTask#26] EventSupplierTask constructed(EventSupplierTask.cpp:43) 02/10/20 16:28:42.385 [EventSupplierTask::initialize#26] Event supplier task initialized(EventSupplierTask.cpp:164) 02/10/20 16:28:42.385 [EventSupplier::EventSupplier] Event supplier constructed(EventSupplier.cpp:38) 02/10/20 16:28:42.385 [EventDispatcher::initialize] EventDispatcher initialized(EventDispatcher.cpp:63) 02/10/20 16:28:42.385 [EventSupplier::EventSupplier] Event dispatcher constructed(EventSupplier.cpp:41) 02/10/20 16:28:42.385 [HPManagerImpl:HPManagerImpl()#26] Constructing HPManagerImpl(HPManagerImpl.cpp:47) 02/10/20 16:28:42.386 [MgrUtils_T::execute] HPManager IOR: IOR:010000002f00000049444c3a53796d616e7465632f4e65744261636b75702f534c2f48504d676d742f48504d616e616765723a312e300000010000000149434fa10000000101026f110000006261626e6275322e6261626c652e6164002e1406050000006e62736c000000001b00000014010f005253547de86b5f558c01001e00000004000000ee6a00008303000000000000000800000001dd0220004f4154010000001400000001dd02200100010500000000090101000000000003000000210000000177c7030e00000031302e3234302e3130302e3134001406050000006e62736c00(MgrUtils_T.cpp:73) 02/10/20 16:28:42.406 [HPManagerImpl::registerEventConsumer#26] Requested policy : 5(SvcInterfaceImpl.h:104) 02/10/20 16:28:42.406 [SvcInterfaceImpl::registerConsumer_i] Callback IOR :IOR:010000004000000049444c3a53796d616e7465632f4e65744261636b75702f534c2f4576656e744d616e6167656d656e742f4e42534c4576656e74436f6e73756d65723a312e3000010000000149434f60000000010102740e00000031302e3234302e3130302e31320014060c00000053636c496e7365637572650020000000373330303434313333372f0f0222462a05112442480e161640300a3f4610350b010000000000000008000000000000004a414300(SvcInterfaceImpl.cpp:88) 02/10/20 16:28:42.406 [SvcInterfaceImpl::registerConsumer_i] Registering callback for the subsequent event register request:(SvcInterfaceImpl.cpp:95) 02/10/20 16:28:42.406 [EventSupplierTask::registerConsumer#26] Registering Consumer context:OPSCENTER_BABOPS::HPManager#26 (EventSupplierTask.cpp:310) 02/10/20 16:28:42.406 [EventSupplierTask::setCallbackStatus#26] New callback status = 2(EventSupplierTask.cpp:347) 02/10/20 16:28:42.406 [EventSupplierTask::setCallbackStatus#26] setting callback up, reseting m_ifQActive and m_nbslEventQueue(EventSupplierTask.cpp:352) 02/10/20 16:28:42.406 [EventSupplier::registerConsumer] Registered consumer(EventSupplier.cpp:70) 02/10/20 16:28:42.406 [EventSupplier::addEventModifier] Adding modifier : ClientEvent(EventSupplier.cpp:239) 02/10/20 16:28:42.406 [ChannelManagerEx::registerSupplier] Registered supplier(ChannelManagerEx.cpp:114) 02/10/20 16:28:42.406 [ChannelManagerUtil::registerSupplier] Supplier present for ClientEvent(ChannelManagerUtil.cpp:176) 02/10/20 16:28:42.406 [EventDispatcher::resetEventFilterDispatchPolicy()] Filter update venets is set to true(EventDispatcher.cpp:113) 02/10/20 16:28:42.406 [EventDispatcher::resetEventFilterDispatchPolicy()] EVENT_DISPATCH_100_EVENTS_5_SECONDS is set(EventDispatcher.cpp:121) 02/10/20 16:28:42.406 [HPManagerImpl::registerEventConsumer#26] Registered consumer(SvcInterfaceImpl.h:115) 02/10/20 16:28:42.424 [HPManagerImpl::aqueryFacet()#26] Getting the HPQueryFacetImpl(HPManagerImpl.cpp:114) 02/10/20 16:28:42.431 [isAlive()] isAlive failed or empty-object(Utils.cpp:501) 02/10/20 16:28:42.431 [makeIORPath()] Proxy IORPath Name is:/usr/openv/var/nbproxy_nbsl-HPManager-26-35-1601620122.ior 02/10/20 16:28:42.432 [HeartBeatableFacet::copyIORPath()] Heartbeat(Global) IOR written at:/usr/openv/var/nbproxy_nbsl-HPManager-26-35-1601620122.ior.mgr(BH_HeartBeatableFacet.cpp:80) 02/10/20 16:28:42.559 [TlsProxy::initConnection] Tls proxy request from: 10.240.100.14:58464 (../LibNbPxyTlsProxy.cpp:210) 02/10/20 16:28:42.559 [TlsProxy::setState] [234] Transitioning state from: TLS_PROXY_IDLE to: TLS_PROXY_CONNECTOR (../LibNbPxyTlsProxy.cpp:407) 02/10/20 16:28:42.560 [TlsProxy::setState] [337] Transitioning state from: TLS_PROXY_CONNECTOR to: TLS_PROXY_RUNNER (../LibNbPxyTlsProxy.cpp:407) 02/10/20 16:28:42.569 [NBPClient::CreateNBP] Writing IOR file::/usr/openv/var/nbproxy_nbsl-HPManager-26-35-1601620122.ior(ProxyHelper.cpp:173) 02/10/20 16:28:42.569 [NBPClient::CreateNBP] Finished writing IOR file::/usr/openv/var/nbproxy_nbsl-HPManager-26-35-1601620122.ior(ProxyHelper.cpp:177) 02/10/20 16:28:42.570 [ProxyHolder::proxy()] created new proxy with ID:HPManager-26-35-1601620122(CORBAConnection.h:506) 02/10/20 16:28:42.570 [ProxyHolder::proxy()] returning new proxy with ID:HPManager-26-35-1601620122(CORBAConnection.h:517) 02/10/20 16:28:42.570 [ProxyConnector::delegateConnect] checking reverse connect for host [babnbu2.bable.ad] and host IP is [10.240.100.14](ProxyConnector.cpp:56) 02/10/20 16:28:42.571 [ProxyConnector::delegateConnect] Reverse connection disabled, PBX direct connect will be tried(ProxyConnector.cpp:92) 02/10/20 16:28:42.583 [HPQueryFacetImpl::getClientInfo_i()#26] client babadc.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.584 [HPQueryFacetImpl::getClientInfo_i()#26] client babadd.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.584 [HPQueryFacetImpl::getClientInfo_i()#26] client babnbu2.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.584 [HPQueryFacetImpl::getClientInfo_i()#26] client babnuc.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.584 [HPQueryFacetImpl::getClientInfo_i()#26] client babops.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.584 [HPQueryFacetImpl::getClientInfo_i()#26] client babwin.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.584 [HPQueryFacetImpl::getClientInfo_i()#26] client hades.bable.ad isOnline : 1 Online At : 122192928000000000Offline At :122192928000000000(HPQueryFacetImpl.cpp:393) 02/10/20 16:28:42.652 [ReadTask::runTask] Connection has been closed by peer on handle: 23 (../LibNbPxyTasks.cpp:952) 02/10/20 16:28:42.652 [IoChannel::runTask] Set state to IOCHANNEL_SHUTDOWN on 0x7f4688019550 (../machines/LibNbPxyRunner.cpp:263) 02/10/20 16:28:42.652 [Runner::asyncIoTaskComplete] Async IO operation on IoChannel State: IOCHANNEL_SHUTDOWN Read Task Handle: 23 Write Task Handle:6 terminated; Connection was closed by peer., nbu status = 7640, severity = 2 (../machines/LibNbPxyRunner.cpp:571) 02/10/20 16:28:42.652 [AsyncIoTaskEngine::handle_input] Connection was closed by peer., nbu status = 7640, severity = 2 (../LibNbPxyAsyncIoTask.cpp:275) 02/10/20 16:28:42.652 [TlsProxy::setState] [134] Transitioning state from: TLS_PROXY_RUNNER to: TLS_PROXY_COMPLETE (../LibNbPxyTlsProxy.cpp:407) 02/10/20 16:28:42.652 [StateMachineEngine::transitionState] Info: State machine completed with status. (../LibNbPxyStateMachine.cpp:3655) 02/10/20 16:28:42.715 V-117-259 [JobInst_i::releaseAllResources] release all resources, jobid=7517 02/10/20 16:28:42.715 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:42.715 [ExportedResourceMediaDrive::getReleaseDelayCallback] no release delay specified for MediaDriveResource: MasterServer=babnbu2.bable.ad MediaServer=babnbu2.bable.ad MediaServerVersion=830000 MediaServerClusterName=None MediaId=@aaaad MediaKey=3 DriveKey=0 DriveName=None PrimaryPath=None SerialNumber=None PoolName=None NdmpControlHost=None NdmpUserName=None NdmpPassword=****** NdmpPasswordKey=****** NdmpClientUserName=None NdmpClientPassword=****** NdmpClientPasswordKey=****** RetentionLevel=0 PolicyType=2 JobType=2 AllocationType=1 exportable = 1 requestId = {83973AFA-0478-11EB-9128-3D885E289D6D} JMowned = 0 Allocation -- id={839B842A-0478-11EB-9885-0A97684254DA}, usn=0, groupId={00000000-0000-0000-0000-000000000000}, allowMultipleRetentions=false, allocationType=1, provider=DriveOperationProvider, resourcename=@aaaad, userAllocationId=jobid=7517, masterServer=babnbu2.bable.ad(ExportedResource.cpp:1268) 02/10/20 16:28:42.716 [DefaultQueue::queueRequest] queue size: 0, queueing RB RBrelease : id={839B842A-0478-11EB-9885-0A97684254DA} -- retry count=-1(CallbackQueue.cpp:1374) 02/10/20 16:28:42.716 [DefaultQueue::handle_input] sending RB RBrelease : id={839B842A-0478-11EB-9885-0A97684254DA}(CallbackQueue.cpp:1509) 02/10/20 16:28:42.716 [Info] V-117-239 terminated job, jobid=7517, status=0 VBRF 1 0 02/10/20 16:28:42.716 [ExportedResourceMgr::~ExportedResourceMgr] (0x7f73a000abf0) nothing found to release or release on destruction is false(ExportedResourceMgr.cpp:162) 02/10/20 16:28:42.716 [EndpointSelector_R2::SetEndPointHostname] epsr2: No Endpoint found with host name, All Endpoints are IP addresses(Endpoint_Selector.cpp:1973) 02/10/20 16:28:42.717 [DefaultQueue::handle_input] (0x2f2bfd0) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:42.717 V-118-93 [ResBroker_i::release(id)] releasing allocation ID {839B842A-0478-11EB-9885-0A97684254DA}, status 0 02/10/20 16:28:42.717 V-118-104 [ResBroker_i::doEvaluation] Evaluation cycle started 02/10/20 16:28:42.717 V-118-102 [ResBroker_i::releaseOne] releasing allocation ID {839B842A-0478-11EB-9885-0A97684254DA} 02/10/20 16:28:42.717 [EMMProvider::release(mdar)] received release of mediaId=@aaaad, driveName=, STU= 02/10/20 16:28:42.720 [JobOtherAsyncDataHandler::handle_input] ERROR, still continue. Proxy::file-size failed backupId:babadd.bable.ad_1600862419, errorcode:48(JobManagerImpl.cpp:642) 02/10/20 16:28:42.720 [JobOtherAsyncDataHandler::handle_input] NOT calling back for backupid:babadd.bable.ad_1600862419, errorcode:48 is retriable(JobManagerImpl.cpp:669) 02/10/20 16:28:42.724 [downStuCnts] INITIATING: 02/10/20 16:28:42.724 [downStuCnts] allocationKey = 34164 02/10/20 16:28:42.725 [downStuCnts] EXIT INFO: 02/10/20 16:28:42.725 [downStuCnts] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:42.726 V-118-217 [EMMAccess::downStuCnts] request to down STU counts (STU , Allocation Key 34164) returned 0 02/10/20 16:28:42.727 [deallocate] INITIATING: 02/10/20 16:28:42.727 [deallocate] deallocType = 1 02/10/20 16:28:42.727 [deallocate] allocationKey = 34164 02/10/20 16:28:42.731 [deallocate] EXIT INFO: 02/10/20 16:28:42.731 [deallocate] rbActions = 0 02/10/20 16:28:42.731 [deallocate] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:42.732 V-118-215 [EMMAccess::deallocate] request to deallocate resources (Allocation Key 34164, Deallocation Type 1) returned 0 02/10/20 16:28:42.732 [EMMAccess::deallocate] deallocated resource (allocationKey=34164) 02/10/20 16:28:42.739 V-111-1061 [DeviceConfigImpl::getRBCacheDriveList] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.739 [DeviceConfigImpl::getRBCacheDriveList] MasterServer 02/10/20 16:28:42.741 [DeviceConfigImpl::getRBCacheDriveList] retval - <0> 02/10/20 16:28:42.742 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnits] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.742 [StorageUnitImpl_2::ListRBCacheStorageUnits] Master = babnbu2.bable.ad 02/10/20 16:28:42.744 [StorageUnitImpl_2::ListRBCacheStorageUnits] retval - <0> 02/10/20 16:28:42.744 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.744 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Master = babnbu2.bable.ad 02/10/20 16:28:42.744 [TlsProxy::initConnection] Tls proxy request from: 10.240.100.13:65080 (../LibNbPxyTlsProxy.cpp:210) 02/10/20 16:28:42.744 [TlsProxy::setState] [234] Transitioning state from: TLS_PROXY_IDLE to: TLS_PROXY_CONNECTOR (../LibNbPxyTlsProxy.cpp:407) 02/10/20 16:28:42.745 [TlsProxy::setState] [337] Transitioning state from: TLS_PROXY_CONNECTOR to: TLS_PROXY_RUNNER (../LibNbPxyTlsProxy.cpp:407) 02/10/20 16:28:42.746 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] retval - <0> 02/10/20 16:28:42.748 V-111-1061 [MachineImpl::QueryMachine] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.748 [MachineImpl::QueryMachine] - MachineName = babnbu2.bable.ad MachineNbuType = 6 02/10/20 16:28:42.748 [MachineImpl::QueryMachine] retval - <0> 02/10/20 16:28:42.748 V-118-105 [ResBroker_i::doEvaluation] Resource evaluation started 02/10/20 16:28:42.749 V-118-106 [ResBroker_i::doEvaluation] Resource evaluation completed. Evaluated 0 requests, sent resource pending for 0 requests, evaluation time 0 msec 02/10/20 16:28:42.749 [ResBroker_i::doEvaluation] Evaluated 0 requests, evalTime=0 msec, numSucceeded=0, numQueued=0, numPended=0, numFailed=0, numMultipleCopyJobs=0, numMdsCacheMisses=0, restartedEvalCycle=0, numDriveReleasesBeforeEval=0, numDrivesAvailStart=0, numDrivesAvailEnd=0, requestQueueSize=0 02/10/20 16:28:42.807 [ReadTask::runTask] Connection has been closed by peer on handle: 6 (../LibNbPxyTasks.cpp:952) 02/10/20 16:28:42.807 [IoChannel::runTask] Set state to IOCHANNEL_SHUTDOWN on 0x7f46780079d0 (../machines/LibNbPxyRunner.cpp:263) 02/10/20 16:28:42.807 [Runner::asyncIoTaskComplete] Async IO operation on IoChannel State: IOCHANNEL_SHUTDOWN Read Task Handle: 6 Write Task Handle:23 terminated; Connection was closed by peer., nbu status = 7640, severity = 2 (../machines/LibNbPxyRunner.cpp:571) 02/10/20 16:28:42.807 [AsyncIoTaskEngine::handle_input] Connection was closed by peer., nbu status = 7640, severity = 2 (../LibNbPxyAsyncIoTask.cpp:275) 02/10/20 16:28:42.807 [TlsProxy::setState] [134] Transitioning state from: TLS_PROXY_RUNNER to: TLS_PROXY_COMPLETE (../LibNbPxyTlsProxy.cpp:407) 02/10/20 16:28:42.807 [StateMachineEngine::transitionState] Info: State machine completed with status. (../LibNbPxyStateMachine.cpp:3655) 02/10/20 16:28:42.919 V-117-257 [JobInst_i::requestResourcesWithTimeout] requesting resource, jobid=7518, reqid=7518, version=1, count=1, caller requestid={846BF59C-0478-11EB-A5ED-09863E441B5C} 02/10/20 16:28:42.919 V-117-298 [JobInst_i::requestResourcesWithTimeout] callback object timeout=600 02/10/20 16:28:42.920 [Info] V-117-64 Initiating foreign job (jobid=7518) VBRQ 1 1 7518 Unknown Unknown Unknown 02/10/20 16:28:42.920 [ExportedResourceMgr::ExportedResourceMgr] (0x7f738c050990) ExportedResourceMgr, jobid=7518, reqid=0(ExportedResourceMgr.cpp:118) 02/10/20 16:28:42.920 V-117-289 [JobInst_i::requestResourcesWithTimeout] starting foreign job, jobid=7518, priority=0, secondPriority=0 02/10/20 16:28:42.920 [ExportedResourceMgr::findExported_1] (0x7f738c050990) NO matching exported resource for request of type=13, reqNum=0, consume=false(ExportedResourceMgr.cpp:626) 02/10/20 16:28:42.920 [ExportedResourceMgr::findReservation] NO reservation found for ExportRequest = 13 reqNum = 0(ExportedResourceMgr.cpp:553) 02/10/20 16:28:42.920 [ExportedResourceMgr::findExported_1] (0x7f738c050990) NO matching exported resource for request of type=13, reqNum=0, consume=false(ExportedResourceMgr.cpp:626) 02/10/20 16:28:42.920 [ExportedResourceMgr::findGroupReservationId] (0x7f738c050990) NO group reservations found(ExportedResourceMgr.cpp:578) 02/10/20 16:28:42.920 [DefaultQueue::queueRequest] queue size: 0, queueing RB RBrequestResources : JMRequestID={846C3962-0478-11EB-9831-AFBE3A2119B9}, userAllocationId=jobid=7518, request timeout=0, priority=0, secondaryPriority=0, requestorDescription=FOREIGN_JOB_7518, master server=babnbu2.bable.ad, requestSequence[0] provider=DriveOperationProvider, resourcename=MEDIA RESOURCE -- retry count=-1(CallbackQueue.cpp:1374) 02/10/20 16:28:42.920 [DefaultQueue::handle_input] sending RB RBrequestResources : JMRequestID={846C3962-0478-11EB-9831-AFBE3A2119B9}, userAllocationId=jobid=7518, request timeout=0(CallbackQueue.cpp:1509) 02/10/20 16:28:42.920 [EndpointSelector_R2::SetEndPointHostname] epsr2: No Endpoint found with host name, All Endpoints are IP addresses(Endpoint_Selector.cpp:1973) 02/10/20 16:28:42.921 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227) 02/10/20 16:28:42.923 [DefaultQueue::handle_input] (0x2f2bfd0) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:42.923 V-118-227 [ResBroker_i::requestResources] received resource request ID {846C3962-0478-11EB-9831-AFBE3A2119B9}, priority 0, secondary priority 0, description FOREIGN_JOB_7518 02/10/20 16:28:42.923 [ResBroker_i::requestResources] RequestSeq: Request=0 provider=DriveOperationProvider resourcename=MEDIA RESOURCE userSequence=0 MediaRequest { mediaId=@aaaad mediaServer= mediaKey=0 userReservationId= assignedTime=0 client= usageType=2 mustBeNdmp=no driveName= drivePath= mediaPool= robotNumber=-1 slotNumber=-1 density=-1 ndmpControlHost= failIfNoMedia=yes externalFile= mediaType=0 mediaSubType=6 isGranularExchange=true NDMPHostName= } 02/10/20 16:28:42.923 V-118-104 [ResBroker_i::doEvaluation] Evaluation cycle started 02/10/20 16:28:42.924 V-111-1061 [DeviceConfigImpl::getRBCacheDriveList] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.924 [DeviceConfigImpl::getRBCacheDriveList] MasterServer 02/10/20 16:28:42.931 [DeviceConfigImpl::getRBCacheDriveList] retval - <0> 02/10/20 16:28:42.933 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnits] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.933 [StorageUnitImpl_2::ListRBCacheStorageUnits] Master = babnbu2.bable.ad 02/10/20 16:28:42.934 [StorageUnitImpl_2::ListRBCacheStorageUnits] retval - <0> 02/10/20 16:28:42.935 V-111-1061 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.935 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] Master = babnbu2.bable.ad 02/10/20 16:28:42.937 [StorageUnitImpl_2::ListRBCacheStorageUnitGroups] retval - <0> 02/10/20 16:28:42.937 V-111-1061 [MachineImpl::QueryMachine] Client signature Host= APP= PID=<1808843> 02/10/20 16:28:42.938 [MachineImpl::QueryMachine] - MachineName = babnbu2.bable.ad MachineNbuType = 6 02/10/20 16:28:42.938 [MachineImpl::QueryMachine] retval - <0> 02/10/20 16:28:42.938 V-118-105 [ResBroker_i::doEvaluation] Resource evaluation started 02/10/20 16:28:42.938 [ResBroker_i::evaluateOne] Evaluating request ID {846C3962-0478-11EB-9831-AFBE3A2119B9} 02/10/20 16:28:42.942 [allocateMedia] INITIATING: 02/10/20 16:28:42.942 [allocateMedia] masterServer = babnbu2.bable.ad, client = , jobType = 2, capabilityFlags = 1024, fatPipePreference = 0, statusOnly = 0 02/10/20 16:28:42.942 [allocateMedia] MediaRequest_Record: MediaServer = , PreferredMediaServer = , MediaId = @aaaad, MediaKey = 0, AssignedTime = 0, DriveName = , DrivePath = , PoolName = , Density = -1, RequiredNdmpTapeServer = , PreferredNdmpTapeServer = , MediaType = 0, MediaSubType = 6, StuNameForDupWrite = , FeatureNumber = -1 02/10/20 16:28:42.952 [fill_bsr] ALLOCATION: key = 34165, media server = babnbu2.bable.ad, mds_flags = 0, scsi_protection = 0, preempt_reservation = 0, preempted_ms_key = 0 02/10/20 16:28:42.952 [fill_bsr] MEDIA: id = @aaaad, key = 3 02/10/20 16:28:42.952 [fill_bsr] DRIVE: name = *NULL*, path = , secondary_path = , key = 0, ndmp_host_key = 0 02/10/20 16:28:42.952 [fill_bsr] STU: name = *NULL*, master server = *NULL* 02/10/20 16:28:42.952 [fill_bsr] DISKGROUP: id = babnbu2-msdp-dp, key = 2 02/10/20 16:28:42.952 [fill_bsr] DISKVOLUME: media_id = @aaaad, key = 3 02/10/20 16:28:42.952 [fill_bsr] DISKMOUNTPOINT: mount_point = PureDiskVolume, key = 2 02/10/20 16:28:42.952 [allocateMedia] EXIT INFO: 02/10/20 16:28:42.952 [allocateMedia] rbActions = 0 02/10/20 16:28:42.952 [allocateMedia] EXIT STATUS = 0 (EMM_ERROR_Success, Success) 02/10/20 16:28:42.953 V-118-202 [EMMAccess::allocateMedia] request to allocate media (Master Server babnbu2.bable.ad, Client , Job Type 2, Media ID @aaaad, Drive Name , Media Server , Capabilities 1024, Fibre Transport Preference 0, Assigned Time 0) returned 0 02/10/20 16:28:42.953 [EMMAccess::allocateMedia] media allocated: mediaId=@aaaad, driveName=, mediaServer=babnbu2.bable.ad, allocationKey=34165 02/10/20 16:28:42.955 [ProviderManager::allocate] DriveOperationProvider returned Allocation Granted for request ID {846C3962-0478-11EB-9831-AFBE3A2119B9} 02/10/20 16:28:42.955 [ResBroker_i::evaluateOne] resources found for request, requestId={846C3962-0478-11EB-9831-AFBE3A2119B9}, userId=jobid=7518, birthTime=1601620122, timeToFirstEval=0 sec, timeToSuccessOrFailure=0 sec, numberOfTimesEvaluated=1 02/10/20 16:28:42.955 V-118-109 [ResBroker_i::passOne] resources found for request ID {846C3962-0478-11EB-9831-AFBE3A2119B9}, following allocations are granted: 02/10/20 16:28:42.955 V-118-228 [ResBroker_i::passOne] allocation ID {847143DA-0478-11EB-A2A5-BD9BD224C95C}, group ID {00000000-0000-0000-0000-000000000000}, provider DriveOperationProvider, resource @aaaad 02/10/20 16:28:42.955 [ResBroker_i::passOne] allocation: (Allocation: id={847143DA-0478-11EB-A2A5-BD9BD224C95C} provider=DriveOperationProvider resourcename=@aaaad masterserver=babnbu2.bable.ad groupid={00000000-0000-0000-0000-000000000000} userSequence=0 userid="jobid=7518" firstuserid="jobid=7518" (Media_Drive_Allocation_Record: allocationKey=34165 (Media_Drive_Record: MediaKey=3 MediaId=@aaaad MediaServer=babnbu2.bable.ad DriveKey=0 DriveName= PrimaryPath= PoolName= RobotNum=0 RobotType=0 MediaTypeName= DriveTypeName= NdmpControlHost= RetentionLevel=0 PolicyType=2 JobType=2 MasterServer=babnbu2.bable.ad) (Storage_Unit_Record: STU= STUType=0 MasterServer= MediaServer= RobotType=0 RobotNumber=0 Density=0 OnDemandOnly=0 ConcurrentJobs=0 ActiveJobs=0 MaxMultiplexing=0 NdmpAttachHost= AbsolutePath=) (Bptm_Strings_Record: 0="MEDIADB 1 34165 @aaaad 3 *NULL* 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0" 1="VOLUME 1 @aaaad 3 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 {00000000-0000-0000-0000-000000000000} 0" 2="DRIVE 4 *NULL* 0 *NULL* *NULL* 0 0 0 0 0 0 0 0 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 0" 3="STORAGE 1 *NULL* 0 0 0 0 0 0 babnbu2.bable.ad babnbu2.bable.ad *NULL*" 4="DISKGROUP 0 8 PureDisk 16 babnbu2.bable.ad 15 babnbu2-msdp-dp" 5="DISKVOLUME 0 6 @aaaad 14 PureDiskVolume 0" 6="DISKMOUNTPOINT 0 14 PureDiskVolume" ) TpReqFileName=) useFatPipeTransport=false diskPath=PureDiskVolume diskGroupName=babnbu2-msdp-dp storageServerType=PureDisk diskGroupStorageServerName=babnbu2.bable.ad failureCode=0) 02/10/20 16:28:42.955 V-118-249 [CallbackQueue::resourcesAvailable] added allocations to the callback queue for request ID {846C3962-0478-11EB-9831-AFBE3A2119B9} 02/10/20 16:28:42.956 V-118-250 [CallbackQueue::notifyClientAvailable] queueing notification of availability of resources for request ID {846C3962-0478-11EB-9831-AFBE3A2119B9} 02/10/20 16:28:42.956 V-118-106 [ResBroker_i::doEvaluation] Resource evaluation completed. Evaluated 1 requests, sent resource pending for 0 requests, evaluation time 17 msec 02/10/20 16:28:42.956 [ResBroker_i::doEvaluation] Evaluated 1 requests, evalTime=17 msec, numSucceeded=1, numQueued=0, numPended=0, numFailed=0, numMultipleCopyJobs=0, numMdsCacheMisses=0, restartedEvalCycle=0, numDriveReleasesBeforeEval=0, numDrivesAvailStart=0, numDrivesAvailEnd=0, requestQueueSize=0 02/10/20 16:28:42.956 V-118-256 [CorbaCall_notifyClientAvailable::execute] sending availability of resources to nbjm for request ID {846C3962-0478-11EB-9831-AFBE3A2119B9} 02/10/20 16:28:42.960 V-117-248 [ResCallback_i::resourcesAvailable] resources available for jobid=jobid=7518, reqid={846C3962-0478-11EB-9831-AFBE3A2119B9} 02/10/20 16:28:42.960 [JobMgrPriv::queueRequest] queue size: 0, queueing JMP resourcesAvailable : requestId={846BF59C-0478-11EB-A5ED-09863E441B5C} -- retry count=3(CallbackQueue.cpp:1374) 02/10/20 16:28:42.960 [JobMgrPriv::handle_input] sending JMP resourcesAvailable : requestId={846BF59C-0478-11EB-A5ED-09863E441B5C}(CallbackQueue.cpp:1509) 02/10/20 16:28:42.961 [JobMgrPriv::handle_input] (0x2f38880) CallbackQueue now empty(CallbackQueue.cpp:1593) 02/10/20 16:28:42.961 [JobMapper::openParentJob] (0xe9f260) invalid parent jobid(JobMapper.cpp:227)