14:14:19.969 [7556.5216] <2> bptm: INITIATING (VERBOSE = 0): -w -pid 4608 -c servername -dpath PureDiskVolume -stunit PD_23_SU -cl CSxxxx_Dedupe -bt 1440594831 -b servername_1440594831 -st 4 -cj 1 -ost_shmcd -bclnthostname servername -ost_proxy -reqid -1438353808 -jm -brm -hostname servername -ru root -rclnt servername -rclnthostname servername -rl 11 -rp 3888000 -sl Daily -ct 13 -maxfrag 51200 -eari 0 -mediasvr mediaserver -no_callback -connect_options 0x01010100 -jobid 1808612 -jobgrpid 1808612 -masterversion 710000 -bpbrm_shm_id Global\NetBackup_BPBRM_SHM_Path_-142036741_4608_6412 -blks_per_buffer 512 
14:14:20.172 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:20.172 [7556.5216] <2> job_connect: SO_KEEPALIVE set on socket 812 for client master server
14:14:20.172 [7556.5216] <2> logconnections: BPJOBD CONNECT FROM ip address.50073 TO ip address.1556 fd = 812
14:14:20.172 [7556.5216] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
14:14:20.172 [7556.5216] <2> job_connect: Connected to the host master server contype 10 jobid <1808612> socket <812>
14:14:20.172 [7556.5216] <2> job_connect: Connected on port 50073
14:14:20.172 [7556.5216] <2> vnet_same_host: ../../libvlibs/vnet_addrinfo.c.2939: 0: name2 is empty: 0 0x00000000
14:14:20.172 [7556.5216] <4> bptm: emmserver_name = master server
14:14:20.172 [7556.5216] <4> bptm: emmserver_port = 1556
14:14:20.219 [7556.5216] <2> Orb::init: initializing ORB EMMlib_Orb with: dbstunitq -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:20.219 [7556.5216] <2> Orb::init: caching EndpointSelectorFactory(../Orb.cpp:838)
14:14:20.219 [7556.5216] <2> Orb::setOrbConnectTimeout: timeout seconds: 60(../Orb.cpp:1478)
14:14:20.219 [7556.5216] <2> Orb::setOrbRequestTimeout: timeout seconds: 1800(../Orb.cpp:1487)
14:14:20.234 [7556.5216] <2> nbjm_media_request: Passing job control to NBJM, type WRITE/1
14:14:20.234 [7556.5216] <2> nbjm_media_request: old_media_id = , media_id = NULL
14:14:20.234 [7556.5216] <2> Orb::init: Created anon service name: NB_7556_1328894058(../Orb.cpp:695)
14:14:20.234 [7556.5216] <2> Orb::init: endpointvalue is : pbxiop://1556:NB_7556_1328894058(../Orb.cpp:712)
14:14:20.234 [7556.5216] <2> Orb::init: initializing ORB Default_DAEMON_Orb with: Unknown -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb Default_DAEMON_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBEndpoint pbxiop://1556:NB_7556_1328894058 -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:20.234 [7556.5216] <2> Orb::init: caching EndpointSelectorFactory(../Orb.cpp:838)
14:14:20.281 [7556.5216] <2> RequestInitialResources: returning
14:14:20.281 [7556.5216] <2> parse_resource_strings: MEDIADB 1 592300 *NULL* 0 *NULL* 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 15, version 1, 21 parameters
14:14:20.281 [7556.5216] <2> parse_resource_strings: VOLUME 1 *NULL* 0 *NULL* *NULL* *NULL* *NULL* 0 0 0 0 0 {00000000-0000-0000-0000-000000000000} 0
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 16, version 1, 14 parameters
14:14:20.281 [7556.5216] <2> parse_resource_strings: DRIVE 3 *NULL* 0 *NULL* *NULL* 0 0 0 0 0 0 0 0 *NULL* *NULL* *NULL* *NULL* 0 0 0 1 0 0
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 17, version 3, 23 parameters
14:14:20.281 [7556.5216] <2> parse_resource_strings: STORAGE 1 PD_23_SU 0 51200 0 6 0 2 mediaserver mediaserver *NULL*
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 18, version 1, 11 parameters
14:14:20.281 [7556.5216] <2> parse_resource_strings: DISKGROUP 0 8 PureDisk 15 media server 16 PD_23_DP
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 21, version 0, 7 parameters
14:14:20.281 [7556.5216] <2> parse_resource_strings: DISKVOLUME 0 6 @aaaag 14 PureDiskVolume 0
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 22, version 0, 6 parameters
14:14:20.281 [7556.5216] <2> parse_resource_strings: DISKMOUNTPOINT 0 14 PureDiskVolume
14:14:20.281 [7556.5216] <2> parse_resource_strings: Parsed message type 23, version 0, 3 parameters
14:14:20.281 [7556.5216] <2> nbjm_media_request: Job control returned to BPTM
14:14:20.281 [7556.5216] <2> dsmlibp_emmserver: .\dsmlib_common.cpp: 151 sev 4 EMM server set to master server
14:14:20.281 [7556.5216] <2> dsmlibp_masterserver: .\dsmlib_common.cpp: 174 sev 4 Master server set to master server
14:14:20.281 [7556.5216] <2> dsmlibp_connect_dsm: .\dsmlib_common.cpp: 256 sev 4 Connecting to DiskServiceMgr on master server
14:14:20.281 [7556.5216] <2> dsmlibp_get_orb: .\dsmlib_common.cpp: 51 sev 4 Using dsmlib private orb
14:14:20.281 [7556.5216] <2> Orb::init: initializing ORB Default_CLIENT_Orb with: Unknown -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb Default_CLIENT_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:20.281 [7556.5216] <2> Orb::init: caching EndpointSelectorFactory(../Orb.cpp:838)
14:14:20.281 [7556.5216] <2> dsmlibp_connect_dsm: .\dsmlib_common.cpp: 264 sev 4 Connecting to NBDSMFSM using orb 00000000021FED10
14:14:20.297 [7556.5216] <2> dsmlibp_register_factories: .\dsmlib_common.cpp: 330 sev 4 Registerd Framework OBV factories with orb 00000000021FED10
14:14:20.297 [7556.5216] <2> dsmlibp_register_factories: .\dsmlib_common.cpp: 338 sev 4 Registerd DiskServiceMgr OBV factories with orb 00000000021FED10
14:14:20.297 [7556.5216] <2> dsm_get_diskvolumeinfo_by_mediaid: .\dsmlib_diskgroup.cpp: 1410 sev 2 diskvolume media ID = @aaaag
14:14:20.297 [7556.5216] <2> dsm_get_diskvolumeinfo_by_mediaid: .\dsmlib_diskgroup.cpp: 1413 sev 2 Calling dsm->getDiskVolumeInfoByMediaId()
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 464 sev 2 diskvolume.name = PureDiskVolume
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 472 sev 2 diskvolume.id = PureDiskVolume
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 478 sev 2 diskvolumeinfo.total_capacity = 26608441217024
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 482 sev 2 diskvolumeinfo.free_space = 11616963813376
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::master, property.value=master server
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::flags, property.value=14
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 549 sev 2 diskvolumeinfo.nbu_state = conv_fn(1)
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::fileSystemType, property.value=0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::fileSystemOrdinal, property.value=0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 564 sev 2 diskvolumeinfo.max_write_mounts = 1
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 569 sev 2 diskvolumeinfo.num_write_mounts = 1
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::maxReferenceWriters, property.value=2147483647
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 554 sev 2 diskvolumeinfo.max_read_mounts = 0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 559 sev 2 diskvolumeinfo.num_read_mounts = 0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::maxReferenceReaders, property.value=0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::freeSpace, property.value=11616963813376
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::freePhysicalSpace, property.value=11616963813376
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 511 sev 2 diskvolumeinfo.potential_free_space = 0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 516 sev 2 diskvolumeinfo.committed_space = 40438343680
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 521 sev 2 diskvolumeinfo.precommitted_space = 40438343680
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 531 sev 2 diskvolumeinfo.system_tag = Unknown
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 526 sev 2 diskvolumeinfo.disk_media_id = @aaaag
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::activeReadStreams, property.value=0
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::activeWriteStreams, property.value=2
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::createdTime, property.value=1321904196
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::lastModifiedTime, property.value=1440594831
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::totalPhysicalCapacity, property.value=26608441217024
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::totalCapacity, property.value=26608441217024
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::majorEventSyncToken, property.value=1440594831
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::minorEventSyncToken, property.value=267203
14:14:20.297 [7556.5216] <2> dsml_extract_diskvolumeinfo: .\dsmlib_popext.cpp: 574 sev 2 property.name=DSM::diskGroupName, property.value=PD_23_DP
14:14:20.328 [7556.5216] <2> dsm_get_diskvolumeinfo_by_mediaid: .\dsmlib_diskgroup.cpp: 1436 sev 2 diskvolumeinfo.diskgroup.name = PD_23_DP
14:14:20.328 [7556.5216] <2> dsm_get_diskvolumeinfo_by_mediaid: .\dsmlib_diskgroup.cpp: 1448 sev 2 diskvolumeinfo.diskgroup.master_server = master server
14:14:20.328 [7556.5216] <2> dsm_get_diskvolumeinfo_by_mediaid: .\dsmlib_diskgroup.cpp: 1459 sev 2 diskvolumeinfo.diskgroup.server_type = PureDisk
14:14:20.328 [7556.5216] <2> validate_parameters: OST_PROXY_SERVER is servername
14:14:20.328 [7556.5216] <2> io_init: bpbrm_handle = 1336, buffer address = 0x1b70000
14:14:20.328 [7556.5216] <2> io_init: found index: 0
14:14:20.328 [7556.5216] <2> read_config_file: using 262144 value from D:\Veritas\NetBackup\db\config\SIZE_DATA_BUFFERS
14:14:20.328 [7556.5216] <2> io_init: using 262144 data buffer size
14:14:20.328 [7556.5216] <2> io_init: CINDEX 0, sched Kbytes for monitoring = 20000
14:14:20.328 [7556.5216] <2> read_config_file: using 262144 value from D:\Veritas\NetBackup\NET_BUFFER_SZ
14:14:20.328 [7556.5216] <2> io_set_recvbuf: setting receive network buffer to 262144 bytes
14:14:20.328 [7556.5216] <2> read_config_file: using 32 value from D:\Veritas\NetBackup\db\config\NUMBER_DATA_BUFFERS
14:14:20.328 [7556.5216] <2> io_init: using 32 data buffers
14:14:20.328 [7556.5216] <2> io_init: child delay = 10, parent delay = 15 (milliseconds)
14:14:20.328 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 21
14:14:20.343 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:20.343 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50086 TO ip address.1556 fd = 1340
14:14:20.515 [7556.5216] <2> db_end: Need to collect reply
14:14:20.515 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:14:20.546 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:20.546 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50087 TO ip address.1556 fd = 1340
14:14:20.702 [7556.5216] <2> db_end: Need to collect reply
14:14:20.702 [7556.5216] <4> report_client: VBRC 2 7556 1 servername_1440594831 13 CSxxxx_Dedupe 4 Daily 0 1 1 
14:14:20.702 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:14:20.733 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:20.733 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50088 TO ip address.1556 fd = 1344
14:14:20.905 [7556.5216] <2> db_end: Need to collect reply
14:14:20.905 [7556.5216] <4> ost_proxy_backup: Using OpenStorage client direct to backup from client servername to media server
14:14:20.905 [7556.5216] <4> ost_proxy_backup: @(#) $Source: src/nb/media/ost_proxy_copy.c,v $ $Revision: 1.13.26.1 $ 
14:14:20.905 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 81
14:14:20.921 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:20.921 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50089 TO ip address.1556 fd = 1352
14:14:21.264 [7556.5216] <2> db_end: Need to collect reply
14:14:21.264 [7556.5216] <2> check_touch_file: Found D:\Veritas\NetBackup\db\config\OST_CD_BUSY_RETRY_LIMIT from (ost_proxy_copy.c.4894)
14:14:21.264 [7556.5216] <2> check_touch_file: Found D:\Veritas\NetBackup\db\config\CD_UPDATE_INTERVAL from (ost_proxy_copy.c.4905)
14:14:21.264 [7556.5216] <2> pxy_set_config: using 180 update interval value from D:\Veritas\NetBackup\db\config\CD_UPDATE_INTERVAL
14:14:21.264 [7556.5216] <2> pxy_set_config: using 30 number data buffers value from D:\Veritas\NetBackup\db\config\CD_NUMBER_DATA_BUFFERS
14:14:21.326 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:21.326 [7556.5216] <2> logconnections: BPCD CONNECT FROM 10.100.32.77.50090 TO 10.1.15.78.1556 fd = 1356
14:14:21.373 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:14:21.482 [7556.5216] <2> do_pbx_service: ../../libvlibs/vnet_connect.c.1776: 0: via PBX: VNETD CONNECT FROM 10.100.32.77.50091 TO 10.1.15.78.1556 fd = 1360
14:14:21.482 [7556.5216] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.445: 0: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
14:14:21.716 [7556.5216] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.462: 0: ipc_string: 50465
14:14:22.637 [7556.5216] <2> bpcr_get_version_rqst: bpcd version: 07100004
14:14:22.668 [7556.5216] <2> Orb::init: initializing ORB ProxyPluginOrb with: connectProxyServer -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static InsecureEndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb ProxyPluginOrb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:22.668 [7556.5216] <2> Orb::init: caching InsecureEndpointSelectorFactory(../Orb.cpp:838)
14:14:22.824 [7556.5216] <2> Orb::init: initializing ORB ProxyPluginOrb with: connectProxyServer -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static InsecureEndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb ProxyPluginOrb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:22.824 [7556.5216] <2> Orb::init: caching InsecureEndpointSelectorFactory(../Orb.cpp:838)
14:14:22.933 [7556.5216] <2> Orb::init: initializing ORB ProxyPluginOrb with: connectProxyServer -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static InsecureEndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb ProxyPluginOrb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:22.933 [7556.5216] <2> Orb::init: caching InsecureEndpointSelectorFactory(../Orb.cpp:838)
14:14:23.058 [7556.5216] <2> Orb::init: initializing ORB ProxyPluginOrb with: connectProxyServer -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static InsecureEndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb ProxyPluginOrb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:23.058 [7556.5216] <2> Orb::init: caching InsecureEndpointSelectorFactory(../Orb.cpp:838)
14:14:23.276 [7556.5216] <2> get_physical_machine_name: mediaserver is a Media server.  Setting physical machine name to mediaserver
14:14:23.276 [7556.5216] <2> Orb::init: initializing ORB ProxyPluginOrb with: connectProxyServer -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static InsecureEndpointSelectorFactory ''" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb ProxyPluginOrb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf nul -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(../Orb.cpp:823)
14:14:23.276 [7556.5216] <2> Orb::init: caching InsecureEndpointSelectorFactory(../Orb.cpp:838)
14:15:47.485 [7556.5216] <2> disk_span_enabled: learned disk_span_enabled = 1
14:15:47.485 [7556.5216] <2> construct_sts_isid: master_server master server, client servername, backup_time 1440594831, copy_number 1, stream_number 4294967295, fragment_number 1, resume_number 0, spl_name NULL
14:15:47.594 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 77
14:15:47.610 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:15:47.610 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50144 TO ip address.1556 fd = 1392
14:15:47.766 [7556.5216] <2> db_end: Need to collect reply
14:15:47.953 [7556.5216] <2> signal_parent: set bpbrm media ready event (pid = 4608)
14:15:47.953 [7556.5216] <2> construct_sts_isid: master_server master server, client servername, backup_time 1440594831, copy_number 1, stream_number 0, fragment_number 1, resume_number 0, spl_name NULL
14:16:11.213 [7556.5216] <4> start_job_data_timer: begin throughput timer
14:16:19.481 [7556.5216] <2> send_media_kbytes_written_establish_threshold: CINDEX 0, RB Kbytes for monitoring = 1000000
14:16:19.481 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:16:19.496 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:16:19.496 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50152 TO ip address.1556 fd = 1392
14:16:21.337 [7556.5216] <2> db_end: Need to collect reply
14:16:21.337 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 0 of 1500 
14:16:21.727 [1944.2128] <2> bptm: INITIATING (VERBOSE = 0): -rptdrv -jobid -1438353824 -jm 
14:16:21.727 [1944.2128] <2> main: Sending [EXIT STATUS 0] to NBJM
14:16:21.727 [1944.2128] <2> bptm: EXITING with status 0 <----------
14:16:30.182 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:16:30.198 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:16:30.198 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50156 TO ip address.1556 fd = 1392
14:16:30.354 [7556.5216] <2> db_end: Need to collect reply
14:16:30.354 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 1 of 1500 
14:16:39.261 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:16:39.277 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:16:39.277 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50160 TO ip address.1556 fd = 1392
14:16:39.433 [7556.5216] <2> db_end: Need to collect reply
14:16:39.433 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 2 of 1500 
14:16:48.325 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:16:48.325 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:16:48.325 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50161 TO ip address.1556 fd = 1392
14:16:48.497 [7556.5216] <2> db_end: Need to collect reply
14:16:48.497 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 3 of 1500 
14:16:57.420 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:16:57.420 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:16:57.420 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50162 TO ip address.1556 fd = 1416
14:16:57.591 [7556.5216] <2> db_end: Need to collect reply
14:16:57.591 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 4 of 1500 
14:17:06.421 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:17:06.452 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:17:06.452 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50163 TO ip address.1556 fd = 1392
14:17:06.608 [7556.5216] <2> db_end: Need to collect reply
14:17:06.608 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 5 of 1500 
14:17:15.734 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:17:15.765 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:17:15.765 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50164 TO ip address.1556 fd = 1392
14:17:15.921 [7556.5216] <2> db_end: Need to collect reply
14:17:15.921 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 6 of 1500 
14:17:24.813 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:17:24.845 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:17:24.845 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50165 TO ip address.1556 fd = 1392
14:17:25.016 [7556.5216] <2> db_end: Need to collect reply
14:17:25.016 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 7 of 1500 
14:17:33.846 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:17:33.861 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:17:33.861 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50166 TO ip address.1556 fd = 1392
14:17:34.017 [7556.5216] <2> db_end: Need to collect reply
14:17:34.017 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 8 of 1500 
14:17:42.847 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:17:42.863 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:17:42.863 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50171 TO ip address.1556 fd = 1416
14:17:43.034 [7556.5216] <2> db_end: Need to collect reply
14:17:43.034 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 9 of 1500 
14:17:52.285 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:17:52.316 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:17:52.316 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50172 TO ip address.1556 fd = 1392
14:17:52.472 [7556.5216] <2> db_end: Need to collect reply
14:17:52.472 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 10 of 1500 
14:18:01.302 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:18:01.317 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:18:01.317 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50173 TO ip address.1556 fd = 1392
14:18:01.473 [7556.5216] <2> db_end: Need to collect reply
14:18:01.473 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 11 of 1500 
14:18:10.303 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:18:10.319 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:18:10.319 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50174 TO ip address.1556 fd = 1392
14:18:10.475 [7556.5216] <2> db_end: Need to collect reply
14:18:10.475 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 12 of 1500 
14:18:19.351 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:18:19.351 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:18:19.351 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50175 TO ip address.1556 fd = 1392
14:18:19.523 [7556.5216] <2> db_end: Need to collect reply
14:18:19.523 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 13 of 1500 
14:18:28.711 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:18:28.711 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:18:28.711 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50176 TO ip address.1556 fd = 1416
14:18:28.883 [7556.5216] <2> db_end: Need to collect reply
14:18:28.883 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 14 of 1500 
14:21:36.644 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:21:36.660 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:21:36.660 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50236 TO ip address.1556 fd = 1392
14:21:36.816 [7556.5216] <2> db_end: Need to collect reply
14:21:36.816 [7556.5216] <2> ost_proxy_copy_whole_image: image copy is not ready, retry attempt: 15 of 1500 
14:21:54.615 [7556.5216] <16> 1808612:bptm:7556:mediaserver: [ERROR][proxy_copy_extent_v9]STSException is caught in proxy_copy_extent_v9:
sts errno: 2060017
error message: fail to call sts_copy_extent
14:21:54.615 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:21:54.615 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:21:54.615 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50240 TO ip address.1556 fd = 1392
14:21:54.787 [7556.5216] <2> db_end: Need to collect reply
14:21:54.787 [7556.5216] <16> ost_proxy_copy_whole_image: image copy failed: error 2060017: 
14:21:54.787 [7556.5216] <2> send_MDS_msg: KBYTES_WRITTEN 0 {E284BA33-65C2-4A74-AA2B-C4E77FCE9B2E} 592300 1 0 1808612
14:21:54.803 [7556.5216] <2> JobInst::sendIrmMsg: returning
14:21:54.803 [7556.5216] <4> stop_job_data_timer: end throughput timer (5120 343577 14)
14:22:16.861 [7556.5216] <16> 1808612:bptm:7556:mediaserver: [ERROR][proxy_close_image_v7]STSException is caught in proxy_close_image_v7:
sts errno: 2060017
error message: fail to close image 
14:22:16.861 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:22:16.861 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:22:16.861 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50241 TO ip address.1556 fd = 1416
14:22:17.033 [7556.5216] <2> db_end: Need to collect reply
14:22:17.033 [7556.5216] <32> bp_sts_close_target_image: sts_close_handle failed: 2060017 
14:22:17.033 [7556.5216] <2> ost_proxy_copy_backup: proxy copy data failed (1 1)
14:22:17.033 [7556.5216] <2> signal_parent: set bpbrm media ready event (pid = 4608)
14:22:17.189 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:22:17.189 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:22:17.189 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50242 TO ip address.1556 fd = 1392
14:22:17.360 [7556.5216] <2> db_end: Need to collect reply
14:22:17.360 [7556.5216] <4> report_dedup_stats: StorageServer=PureDisk:media server; Report=PDDO Stats for (media server): scanned: 12815 KB, stream rate: 0.06 MB/sec, CR sent: 1208 KB, dedup: 90.6%
14:22:17.485 [7556.5216] <2> job_monitoring_exex: ACK disconnect
14:22:17.485 [7556.5216] <2> job_disconnect: Disconnected
14:22:17.501 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:22:17.501 [7556.5216] <2> job_connect: SO_KEEPALIVE set on socket 812 for client master server
14:22:17.501 [7556.5216] <2> logconnections: BPJOBD CONNECT FROM ip address.50243 TO ip address.1556 fd = 812
14:22:17.501 [7556.5216] <2> job_authenticate_connection: ignoring VxSS authentication check for now...
14:22:17.501 [7556.5216] <2> job_connect: Connected to the host master server contype 10 jobid <1808612> socket <812>
14:22:17.501 [7556.5216] <2> job_connect: Connected on port 50243
14:22:17.703 [7556.5216] <2> job_monitoring_exex: ACK disconnect
14:22:17.703 [7556.5216] <2> job_disconnect: Disconnected
14:22:17.703 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 1
14:22:17.719 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:22:17.719 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50244 TO ip address.1556 fd = 1416
14:22:17.875 [7556.5216] <2> db_end: Need to collect reply
14:22:17.875 [7556.5216] <32> bp_sts_close_target_server: sts_close_server failed: error 2060005 
14:22:18.483 [7556.5216] <2> ConnectionCache::connectAndCache: Acquiring new connection for host master server, query type 161
14:22:18.483 [7556.5216] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:22:18.483 [7556.5216] <2> logconnections: BPDBM CONNECT FROM ip address.50245 TO ip address.1556 fd = 1348
14:22:18.655 [7556.5216] <2> db_end: Need to collect reply
14:22:23.834 [7556.5216] <2> send_MDS_msg: MEDIA_DONE 0 -1438353808 0 @aaaag 0 0 {E284BA33-65C2-4A74-AA2B-C4E77FCE9B2E}
14:22:23.850 [7556.5216] <2> packageBptmResourceDoneMsg: msg (MEDIA_DONE 0 -1438353808 0 @aaaag 0 0 {E284BA33-65C2-4A74-AA2B-C4E77FCE9B2E})
14:22:23.850 [7556.5216] <2> packageBptmResourceDoneMsg: keyword MEDIA_DONE version 0 jobid -1438353808 copyNum 0 mediaId @aaaag mediaKey 0 unloadDelay 0 allocId {E284BA33-65C2-4A74-AA2B-C4E77FCE9B2E}
14:22:23.850 [7556.5216] <2> packageBptmResourceDoneMsg: returns 0
14:22:23.850 [7556.5216] <2> JobInst::sendIrmMsg: returning
14:22:23.850 [7556.5216] <2> mm_terminate: EXITING with status 14
14:22:23.850 [7556.5216] <2> bp_sts_close_server: STS session not initialized
14:22:23.850 [7556.5216] <2> cleanup: Detached from BPBRM shared memory