17:07:49.388 [13460] <2> bptm: INITIATING (VERBOSE = 5): -dup -cmd -nosig -v -L /usr/openv/netbackup/logs/user_ops/rn455g/logs/jbpDuplicate-20110802160501.log -ru root -rclnt wspebrms01-ebr -jobid 6551974 -mediasvr wspedb52-ebr -c p1tvt1d2-ebr -b p1tvt1d2-ebr_1310099209 -cl WDC_ORA_PP11XTVT -sl Default-Application-Backup -bt 1310099209 -st 2 -rl 4 -date 1315456009 -ct 4 -den 20 -rt 1 -rn 0 -p OFFSITE -twin_fail_on_error 0 -cn 2 -maxfrag 1048576 -stunit LTO3_wspedb52 -cj 4 -sg *ANY* -use_vnetd 17:07:49.389 [13460] <2> main: bptm.c.1696: maximum fragment size is 1048576000 Kbytes 17:07:49.389 [13460] <2> bptm: PORT_STATUS = 0x00000000 17:07:49.390 [13460] <2> hosts_equal: The second name is empty 17:07:49.390 [13460] <2> hosts_equal: Comparing hosts and 17:07:49.390 [13460] <2> hosts_equal: names are the same 17:07:49.390 [13460] <2> hosts_equal: Comparing hosts and 17:07:49.390 [13460] <2> hosts_equal: names are the same 17:07:49.391 [13460] <4> bptm: emmserver_name = wspebrms01-ebr 17:07:49.391 [13460] <4> bptm: emmserver_port = 1556 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1045: host_cache_size: 200 0x000000c8 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1046: cache_time: 3600 0x00000e10 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1060: host_failed_cache_size: 40 0x00000028 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1061: cache_time: 3600 0x00000e10 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1045: host_cache_size: 200 0x000000c8 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1046: cache_time: 3600 0x00000e10 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1060: host_failed_cache_size: 40 0x00000028 17:07:49.405 [13460] <2> init_cache: vnet_hosts.c.1061: cache_time: 3600 0x00000e10 17:07:49.437 [13460] <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'" -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf /dev/null -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(Orb.cpp:739) 17:07:49.605 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:49.649 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:49.649 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpjobd 17:07:49.651 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:49.652 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48942 TO 155.169.64.45.13724 fd = 8 17:07:49.652 [13460] <2> job_connect: SO_KEEPALIVE set on socket 8 for client wspebrms01-ebr 17:07:49.652 [13460] <2> logconnections: BPJOBD CONNECT FROM 10.86.214.41.48942 TO 155.169.64.45.13724 17:07:49.652 [13460] <2> vauth_get_user_name: vauth_comm.c.687: cached_user_name: root 17:07:49.652 [13460] <2> vauth_get_user_name: vauth_comm.c.689: cached_user_name: :root 17:07:49.652 [13460] <2> vauth_get_user_name: vauth_comm.c.695: user_name: :root 17:07:49.652 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:49.653 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:49.653 [13460] <2> job_authenticate_connection: no authentication required 17:07:49.653 [13460] <2> job_authenticate_connection: ignoring VxSS authentication check for now... 17:07:49.653 [13460] <2> job_connect: Connected to the host wspebrms01-ebr contype 10 jobid <6551974> socket <8> 17:07:49.653 [13460] <2> job_connect: Connected on port 48942 17:07:49.653 [13460] <2> set_job_details: Sending Tfile jobid (6551974) 17:07:49.653 [13460] <2> set_job_details: PROCESS 1312319269 13460 bptm 17:07:49.653 [13460] <2> set_job_details: Done 17:07:49.653 [13460] <2> main: Setting mud from bp.conf 17:07:49.654 [13460] <2> nbjm_media_request: Passing job control to NBJM, type WRITE/9 17:07:49.654 [13460] <2> nbjm_media_request: old_media_id = , media_id = NULL 17:07:49.655 [13460] <2> RequestInitialResources: starting 17:07:49.655 [13460] <2> RequestInitialResources: started 17:07:49.655 [13460] <2> Orb::init: Created anon service name: NB_13460_690493936(Orb.cpp:610) 17:07:49.655 [13460] <2> Orb::init: endpointvalue is : pbxiop://1556:NB_13460_690493936(Orb.cpp:628) 17:07:49.656 [13460] <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'" -ORBSvcConfDirective "static PBXIOP_Evaluator_Factory '-orb Default_CLIENT_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBEndpoint pbxiop://1556:NB_13460_690493936 -ORBSvcConf /dev/null -ORBSvcConfDirective "static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"(Orb.cpp:739) 17:07:49.788 [13460] <2> packageInitialResourceRequest: started 17:07:49.788 [13460] <2> packageInitialResourceRequest: retVal = 0 17:07:49.788 [13460] <2> RequestInitialResources: setting up callback and calling requestResources 17:07:49.791 [13460] <2> logResourceReq: req.versionId : 1 17:07:49.791 [13460] <2> logResourceReq: req.jobId : 6551974 17:07:49.791 [13460] <2> logResourceReq: req.startedViaJobManager : false 17:07:49.791 [13460] <2> logResourceReq: req.consumer : true 17:07:49.792 [13460] <2> logResourceReq: InitialSTUSelect - 17:07:49.792 [13460] <2> logResourceReq: reqNum : 0 17:07:49.792 [13460] <2> logResourceReq: preferredMediaServer : 17:07:49.792 [13460] <2> logResourceReq: requiredMediaServer : wspedb52-ebr 17:07:49.792 [13460] <2> logResourceReq: storageUnit : LTO3_wspedb52 17:07:49.792 [13460] <2> logResourceReq: mustBeNdmp : false 17:07:49.792 [13460] <2> logResourceReq: getMaxFreeSpace : false 17:07:49.792 [13460] <2> logResourceReq: mediaPool : OFFSITE 17:07:49.792 [13460] <2> logResourceReq: shareGroup : *ANY* 17:07:49.792 [13460] <2> logResourceReq: retentionLevel : 4 17:07:49.792 [13460] <2> logResourceReq: mustUseLocalMediaServer : false 17:07:49.792 [13460] <2> logResourceReq: failOnError : false 17:07:49.792 [13460] <2> logResourceReq: mpxRequired : false 17:07:49.792 [13460] <2> logResourceReq: client : p1tvt1d2-ebr 17:07:49.792 [13460] <2> logResourceReq: usageType : 9 17:07:49.797 [13460] <2> RequestInitialResources: BpxmiV->requestResourcesWithTimeout returns 0 17:07:49.803 [13460] <2> resourcesAvailable: m_allocationSeq.length() == 1 17:07:49.803 [13460] <2> resourcesAvailable: thisAllocation->mdar.Bsr.BptmStrings.length() == 7 17:07:49.804 [13460] <2> resourcesAvailable: MEDIADB 1 130664358 WPF898 4015243 ------ 20 1312319264 0 0 0 0 0 0 4 7 0 0 0 0 0 0 17:07:49.804 [13460] <2> resourcesAvailable: VOLUME 1 WPF898 4015243 WPF898 OFFSITE FUJIFILM 0852407134 24 1 0 0 7 {00000000-0000-0000-0000-000000000000} 0 17:07:49.804 [13460] <2> resourcesAvailable: DRIVE 3 L3_0_7_1_6_SL85_02 2000570 1210377713 /dev/rmt/3cbn -1 -1 -1 -1 0 7 1 6 *NULL* *NULL* *NULL* *NULL* 1 0 0 1 0 0 17:07:49.804 [13460] <2> resourcesAvailable: STORAGE 1 LTO3_wspedb52 20 1048576 2 1 0 0 wspedb52-ebr wspedb52-ebr *NULL* 17:07:49.804 [13460] <2> resourcesAvailable: DISKGROUP 0 6 *NULL* 6 *NULL* 6 *NULL* 17:07:49.804 [13460] <2> resourcesAvailable: DISKVOLUME 0 6 *NULL* 6 *NULL* 0 17:07:49.804 [13460] <2> resourcesAvailable: DISKMOUNTPOINT 0 6 *NULL* 17:07:51.805 [13460] <2> packageInitialResourceRequestResult: totalNumberOfAllocations == 1 17:07:51.805 [13460] <2> packageInitialResourceRequestResult: m_allocationSeq.length=1 17:07:51.805 [13460] <2> packageInitialResourceRequestResult: found MediaAllocation : reqNum == 0 17:07:51.805 [13460] <2> packageInitialResourceRequestResult: matched MediaAllocation to an initialStuReq 17:07:51.805 [13460] <2> packageInitialResourceRequestResult: retVal = 0 17:07:51.805 [13460] <2> RequestInitialResources: retVal = 0 emmStatus = 0 17:07:51.805 [13460] <2> RequestInitialResources: returning 17:07:51.805 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [MEDIADB 1 130664358 WPF898 4015243 ------ 20 1312319264 0 0 0 0 0 0 4 7 0 0 0 0 0 0], length 83 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [VOLUME 1 WPF898 4015243 WPF898 OFFSITE FUJIFILM 0852407134 24 1 0 0 7 {00000000-0000-0000-0000-000000000000} 0], length 110 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [DRIVE 3 L3_0_7_1_6_SL85_02 2000570 1210377713 /dev/rmt/3cbn -1 -1 -1 -1 0 7 1 6 *NULL* *NULL* *NULL* *NULL* 1 0 0 1 0 0], length 119 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [STORAGE 1 LTO3_wspedb52 20 1048576 2 1 0 0 wspedb52-ebr wspedb52-ebr *NULL*], length 75 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [DISKGROUP 0 6 *NULL* 6 *NULL* 6 *NULL*], length 38 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [DISKVOLUME 0 6 *NULL* 6 *NULL* 0], length 32 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: packaging bptm string [DISKMOUNTPOINT 0 6 *NULL*], length 25 17:07:51.806 [13460] <2> populateBptmOpaqueStrings: retVal = 0 17:07:51.806 [13460] <2> parse_resource_strings: MEDIADB 1 130664358 WPF898 4015243 ------ 20 1312319264 0 0 0 0 0 0 4 7 0 0 0 0 0 0 17:07:51.806 [13460] <2> parse_resource_strings: Parsed message type 15, version 1, 21 parameters 17:07:51.806 [13460] <2> parse_resource_strings: VOLUME 1 WPF898 4015243 WPF898 OFFSITE FUJIFILM 0852407134 24 1 0 0 7 {00000000-0000-0000-0000-000000000000} 0 17:07:51.806 [13460] <2> parse_resource_strings: Parsed message type 16, version 1, 14 parameters 17:07:51.806 [13460] <2> parse_resource_strings: DRIVE 3 L3_0_7_1_6_SL85_02 2000570 1210377713 /dev/rmt/3cbn -1 -1 -1 -1 0 7 1 6 *NULL* *NULL* *NULL* *NULL* 1 0 0 1 0 0 17:07:51.807 [13460] <2> check_touch_file: Found /usr/openv/volmgr/database/NO_TAPEALERT from (jmcomm.c.194) 17:07:51.807 [13460] <2> parse_resource_strings: Parsed message type 17, version 3, 23 parameters 17:07:51.807 [13460] <2> parse_resource_strings: STORAGE 1 LTO3_wspedb52 20 1048576 2 1 0 0 wspedb52-ebr wspedb52-ebr *NULL* 17:07:51.807 [13460] <2> parse_resource_strings: Parsed message type 18, version 1, 11 parameters 17:07:51.807 [13460] <2> parse_resource_strings: DISKGROUP 0 6 *NULL* 6 *NULL* 6 *NULL* 17:07:51.807 [13460] <2> parse_resource_strings: Parsed message type 21, version 0, 7 parameters 17:07:51.807 [13460] <2> parse_resource_strings: DISKVOLUME 0 6 *NULL* 6 *NULL* 0 17:07:51.807 [13460] <2> parse_resource_strings: Parsed message type 22, version 0, 6 parameters 17:07:51.807 [13460] <2> parse_resource_strings: DISKMOUNTPOINT 0 6 *NULL* 17:07:51.807 [13460] <2> parse_resource_strings: Parsed message type 23, version 0, 3 parameters 17:07:51.807 [13460] <2> nbjm_media_request: Job control returned to BPTM 17:07:51.807 [13460] <2> setup_twin_parameters: bptm.c.3973: maximum fragment size is 1048576000 Kbytes 17:07:51.807 [13460] <2> validate_parameters: tmcommon.c.5259: maximum fragment size is 1048576000 Kbytes 17:07:51.810 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:51.846 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:51.846 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:51.847 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:51.848 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48955 TO 155.169.64.45.13724 fd = 9 17:07:51.848 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48955 TO 155.169.64.45.13724 17:07:51.848 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:51.848 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:51.848 [13460] <2> check_authentication: no authentication required 17:07:51.848 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:51.848 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:52.093 [13460] <2> io_init: using 262144 data buffer size 17:07:52.093 [13460] <2> io_init: CINDEX 0, sched Kbytes for monitoring = 40000 17:07:52.093 [13460] <2> io_set_recvbuf: receive network buffer is 49640 bytes 17:07:52.093 [13460] <2> io_init: using 32 data buffers 17:07:52.093 [13460] <2> io_init: child delay = 10, parent delay = 15 (milliseconds) 17:07:52.094 [13460] <2> create_shared_memory: shm_size = 8389384, buffer address = 0xfbc00000, buf control = 0xfc400000, ready ptr = 0xfc400300 17:07:52.098 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:52.136 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:52.137 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:52.138 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:52.138 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48958 TO 155.169.64.45.13724 fd = 9 17:07:52.138 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48958 TO 155.169.64.45.13724 17:07:52.138 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:52.138 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:52.138 [13460] <2> check_authentication: no authentication required 17:07:52.138 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:52.138 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:52.463 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:52.501 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:52.501 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:52.502 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:52.502 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48961 TO 155.169.64.45.13724 fd = 9 17:07:52.502 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48961 TO 155.169.64.45.13724 17:07:52.502 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:52.503 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:52.503 [13460] <2> check_authentication: no authentication required 17:07:52.503 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:52.503 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:52.830 [13460] <4> report_client: VBRC 2 13460 1 p1tvt1d2-ebr_1310099209 4 WDC_ORA_PP11XTVT 2 Default-Application-Backup 0 1 2 17:07:52.832 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:52.881 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:52.881 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:52.882 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:52.883 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48963 TO 155.169.64.45.13724 fd = 9 17:07:52.883 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48963 TO 155.169.64.45.13724 17:07:52.883 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:52.883 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:52.883 [13460] <2> check_authentication: no authentication required 17:07:52.883 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:52.883 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:53.209 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:53.244 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:53.244 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:53.245 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:53.245 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48965 TO 155.169.64.45.13724 fd = 9 17:07:53.245 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48965 TO 155.169.64.45.13724 17:07:53.245 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:53.246 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:53.246 [13460] <2> check_authentication: no authentication required 17:07:53.246 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:53.246 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:53.581 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:53.618 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:53.618 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:53.619 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:53.619 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48968 TO 155.169.64.45.13724 fd = 9 17:07:53.619 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48968 TO 155.169.64.45.13724 17:07:53.619 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:53.619 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:53.619 [13460] <2> check_authentication: no authentication required 17:07:53.619 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:53.620 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:53.947 [13460] <2> drivename_open: Called with Create 1, file L3_0_7_1_6_SL85_02 17:07:53.947 [13460] <2> drivename_lock: lock established 17:07:53.947 [13460] <2> drivename_write: Called with mode 0 17:07:53.947 [13460] <2> db_byid: search for media id WPF898 17:07:53.967 [13460] <2> send_MDS_msg: MEDIADB 1 130664358 WPF898 4015243 *NULL* 20 1312319269 0 0 0 0 0 0 4 7 0 16 1024 0 0 0 17:07:54.029 [13460] <2> bptm media_id_to_monitor: job_id = 6551974 17:07:54.029 [13460] <2> bptm media_id_to_monitor: pDstMediaId = WPF898 17:07:54.029 [13460] <2> set_job_details: Sending jobData jobid (6551974) 17:07:54.029 [13460] <2> send_structure_data: Index 28 Field m_szDstMediaID Value 17:07:54.029 [13460] <2> set_job_details: Done 17:07:54.030 [13460] <2> create_data_socket: tmcommon.c.6388: listening on ipc_string: /tmp/vnet-13460312319274029804000000000-TWaGsA 17:07:54.030 [13460] <2> create_data_socket: tmcommon.c.6592: IPC, TIRIPC, PID, blksize: IPC /tmp/vnet-13460312319274029804000000000-TWaGsA NULL 13460 0 17:07:55.598 [13460] <2> vnet_receive_network_socket: vnet_vnetd.c.1251: hash_str1: NULL 17:07:55.598 [13460] <2> vnet_receive_network_socket: vnet_vnetd.c.1252: hash_str2: 17:07:55.598 [13460] <2> verify_hashes: vnet_vnetd.c.1765: hash_str1: NULL 17:07:55.598 [13460] <2> verify_hashes: vnet_vnetd.c.1767: hash_str2: 17:07:55.599 [13460] <2> io_set_recvbuf: receive network buffer is 57262 bytes 17:07:55.599 [13460] <2> create_data_socket: data socket created is 12, duping to stdin 17:07:55.604 [13460] <2> write_backup: backup child process is pid 13578 17:07:55.604 [13460] <2> mount_open_media: Waiting for mount of media id WPF898 (copy 2) on server wspedb52-ebr. 17:07:55.604 [13460] <2> set_job_details: Sending Tfile jobid (6551974) 17:07:55.604 [13460] <2> set_job_details: PROCESS 1312319275 13460 bptm 17:07:55.604 [13460] <2> set_job_details: Done 17:07:55.604 [13460] <2> set_job_details: Sending Tfile jobid (6551974) 17:07:55.604 [13460] <2> set_job_details: MOUNTING 1312319275 WPF898 17:07:55.604 [13460] <2> set_job_details: Done 17:07:55.606 [13460] <2> append_to_client_log: dbmisc.c.3335: about to call ConnectToBPCD connect_opts = 0xffffffff 17:07:55.609 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:55.655 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:55.655 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:07:55.656 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:55.657 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48987 TO 155.169.64.45.13724 fd = 0 17:07:55.657 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.48987 TO 155.169.64.45.13724 17:07:55.657 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:55.657 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:55.657 [13460] <2> check_authentication: no authentication required 17:07:55.657 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:07:55.657 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:07:55.966 [13460] <2> db_getCLIENT: db_CLIENTreceive: no entity was found 227 17:07:55.966 [13460] <2> ConnectToBPCD: db_getCLIENT(wspebrms01-ebr) failed: 227 17:07:55.967 [13460] <2> hosts_equal: Comparing hosts and 17:07:55.967 [13460] <2> hosts_equal: names are the same 17:07:55.968 [13460] <2> local_bpcr_connect: bpcr.c.276: connect_opts = 0x01000100 connect_opts2 = 0x01000100 17:07:55.968 [13460] <2> local_bpcr_connect: bpcr.c.283: connect_opts = 0x01000100 17:07:55.968 [13460] <2> local_bpcr_connect: bpcr.c.322: daemon_port_type = 0 17:07:55.971 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:07:56.010 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:07:56.010 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpcd 17:07:56.010 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:07:56.010 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.48990 TO 155.169.64.45.13724 fd = 0 17:07:56.010 [13460] <2> logconnections: BPCD CONNECT FROM 10.86.214.41.48990 TO 155.169.64.45.13724 17:07:56.011 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:07:56.011 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:07:56.011 [13460] <2> bpcr_authenticate_connection: no authentication required 17:07:56.011 [13460] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.182: msg: VNETD CONNECT FROM 10.86.214.41.48992 TO 155.169.64.45.13724 fd = 9 17:07:56.048 [13460] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.535: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a 17:07:56.050 [13460] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.552: ipc_string: /tmp/vnet-03034312319276049259000000000-rqaq7f 17:07:56.051 [13460] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.563: hash_str1: 707605b43710a26641e331d734a82fc4 17:07:56.860 [13460] <2> mount_open_media: setting mount timeout to 7200 seconds 17:07:56.860 [13460] <4> create_tpreq_file: symlink to path /dev/rmt/3cbn 17:07:56.863 [13460] <2> manage_scsi_reserve: SCSI RESERVE 17:07:56.867 [13460] <4> expandpath: /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02 17:07:57.781 [13460] <2> tapelib: wait_for_ltid, Mount, timeout 7200 17:08:42.795 [13460] <2> io_open: SCSI RESERVE 17:08:42.833 [13460] <2> manage_drive_attributes: report_attr, fl1 0x00000049, fl2 0x0000000c 17:08:42.833 [13460] <2> manage_drive_attributes: Matching medium manufacturer [FUJIFILM], sn [0852407134] 17:08:42.833 [13460] <2> manage_drive_attributes: Host Attributes: Vendor [SYMANTEC], Name [NetBackup BPTM], Version [6.5.6] 17:08:42.833 [13460] <2> manage_drive_attributes: DateLabeled [201105182006], Barcode [WPF898], Owninghost [whpnts5d-ebr] 17:08:42.833 [13460] <2> manage_drive_attributes: MediaPool [OFFSITE], MediaLabel [MEDIA=WPF898;] 17:08:42.852 [13460] <2> io_open: file /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02 successfully opened (mode 2) 17:08:42.852 [13460] <2> write_backup: media id WPF898 mounted on drive index 1, drivepath /dev/rmt/3cbn, drivename L3_0_7_1_6_SL85_02, copy 2 17:08:42.855 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:08:42.892 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:08:42.892 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:08:42.893 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:08:42.894 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.49071 TO 155.169.64.45.13724 fd = 9 17:08:42.894 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.49071 TO 155.169.64.45.13724 17:08:42.894 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:08:42.894 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:08:42.894 [13460] <2> check_authentication: no authentication required 17:08:42.894 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:08:42.894 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:08:43.214 [13460] <4> report_throughput: VBRT 1 13460 1 1 L3_0_7_1_6_SL85_02 WPF898 0 1 0 0 0 (bptm.c.20529) 17:08:43.220 [13460] <2> io_read_media_header: drive index 1, reading media header, buflen = 65536, buff = 0x7877c0, copy 2 17:08:43.220 [13460] <2> io_ioctl: command (5)MTREW 1 from (bptm.c.8175) on drive index 1 17:08:43.250 [13460] <2> io_write_media_header: drive index 1, writing media header 17:08:43.251 [13460] <2> io_close: closing /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02, from bptm.c.9481 17:08:43.253 [13460] <2> io_open: SCSI RESERVE 17:08:43.262 [13460] <2> io_open: file /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02 successfully opened (mode 2) 17:08:43.262 [13460] <2> io_ioctl: command (5)MTREW 1 from (bptm.c.9486) on drive index 1 17:08:43.336 [13460] <2> io_ioctl: command (0)MTWEOF 1 from (bptm.c.9527) on drive index 1 17:08:46.104 [13460] <2> io_write_host_attributes: Successfully wrote host attributes to media 17:08:46.115 [13460] <2> io_write_media_header: report_density, 0x44 [LTO-CVE U-316] 17:08:46.115 [13460] <2> send_MDS_msg: VOL_UPDATE 0 130664358 WPF898 4015243 FUJIFILM 0852407134 4 68 17:08:46.211 [13460] <2> append_to_client_log: dbmisc.c.3335: about to call ConnectToBPCD connect_opts = 0xffffffff 17:08:46.214 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:08:46.254 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:08:46.254 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:08:46.255 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:08:46.255 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.49077 TO 155.169.64.45.13724 fd = 9 17:08:46.255 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.49077 TO 155.169.64.45.13724 17:08:46.255 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:08:46.256 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:08:46.256 [13460] <2> check_authentication: no authentication required 17:08:46.256 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:08:46.256 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:08:46.583 [13460] <2> db_getCLIENT: db_CLIENTreceive: no entity was found 227 17:08:46.584 [13460] <2> ConnectToBPCD: db_getCLIENT(wspebrms01-ebr) failed: 227 17:08:46.584 [13460] <2> hosts_equal: Comparing hosts and 17:08:46.584 [13460] <2> hosts_equal: names are the same 17:08:46.584 [13460] <2> local_bpcr_connect: bpcr.c.276: connect_opts = 0x01000100 connect_opts2 = 0x01000100 17:08:46.584 [13460] <2> local_bpcr_connect: bpcr.c.283: connect_opts = 0x01000100 17:08:46.584 [13460] <2> local_bpcr_connect: bpcr.c.322: daemon_port_type = 0 17:08:46.586 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:08:46.618 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:08:46.618 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpcd 17:08:46.619 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:08:46.619 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.49080 TO 155.169.64.45.13724 fd = 9 17:08:46.619 [13460] <2> logconnections: BPCD CONNECT FROM 10.86.214.41.49080 TO 155.169.64.45.13724 17:08:46.619 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:08:46.619 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:08:46.619 [13460] <2> bpcr_authenticate_connection: no authentication required 17:08:46.620 [13460] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.182: msg: VNETD CONNECT FROM 10.86.214.41.49082 TO 155.169.64.45.13724 fd = 11 17:08:46.658 [13460] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.535: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a 17:08:46.660 [13460] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.552: ipc_string: /tmp/vnet-05501312319326658921000000000-cNaOVk 17:08:46.660 [13460] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.563: hash_str1: d878c04e170404542635f48686e71d84 17:08:47.479 [13460] <2> send_MDS_msg: MEDIADB 1 130664358 WPF898 4015243 *NULL* 20 1312319269 1312319269 1315456009 0 0 0 0 4 7 0 0 1024 0 0 0 17:08:47.554 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:08:47.592 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:08:47.592 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:08:47.593 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:08:47.593 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.49085 TO 155.169.64.45.13724 fd = 9 17:08:47.593 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.49085 TO 155.169.64.45.13724 17:08:47.593 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:08:47.593 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:08:47.593 [13460] <2> check_authentication: no authentication required 17:08:47.594 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:08:47.594 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:08:47.910 [13460] <4> write_backup: begin writing backup id p1tvt1d2-ebr_1310099209, copy 2, fragment 1, to media id WPF898 on drive L3_0_7_1_6_SL85_02 (index 1) 17:08:47.910 [13460] <2> write_data: twin_index: 0 active: 1 dont_process: 0 wrote_backup_hdr: 0 finished_buff: 0 saved_cindex: -1 twin_is_disk 0 delay_brm: 0 17:08:47.910 [13460] <2> write_data: Total Kbytes transferred 0 17:08:47.915 [13460] <2> write_data: absolute block position prior to writing backup header(s) is 2, copy 2 17:08:47.915 [13460] <2> io_write_back_header: drive index 1, p1tvt1d2-ebr_1310099209, file num = 1, mpx_headers = 0, copy 2 17:08:47.919 [13460] <2> write_data: completed writing backup header, start writing data when first buffer is available, copy 2 17:08:47.919 [13460] <2> write_data: first write, twin_index: 0 cindex: 0 dont_process: 1 wrote_backup_hdr: 1 finished_buff: 0 17:08:47.919 [13460] <2> write_data: received first buffer (262144 bytes), begin writing data 17:12:44.420 [15492] <2> drivename_checklock: PID 13460 has lock 17:12:44.420 [15492] <2> report_drives: PID = 13460 17:12:51.996 [15576] <2> drivename_checklock: PID 13460 has lock 17:12:51.996 [15576] <2> report_drives: PID = 13460 17:12:52.091 [15578] <2> drivename_checklock: PID 13460 has lock 17:12:52.091 [15578] <2> report_drives: PID = 13460 17:13:06.440 [13460] <2> Media_dispatch_signal: calling catch_signal for 1 (bptm.c:28045) delay 0 seconds 17:13:06.441 [13460] <2> Media_siginfo_print: 0: delay 0 signo SIGHUP:1 code 0 pid 15804 17:13:08.442 [13460] <2> set_job_details: Sending Tfile jobid (6551974) 17:13:08.442 [13460] <2> set_job_details: LOG 1312319588 16 bptm 13460 media manager terminated by parent process 17:13:08.442 [13460] <2> set_job_details: Done 17:13:08.445 [13460] <2> vnet_async_connect: vnet_vnetd.c.4039: connect in progress: 0 0x00000000 17:13:08.491 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2048: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006 17:13:08.492 [13460] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2062: service: bpdbm 17:13:08.597 [13460] <2> vnet_async_connect: vnet_vnetd.c.4225: in progress connect: 0 0x00000000 17:13:08.597 [13460] <2> vnet_async_connect: vnet_vnetd.c.4228: connect: async CONNECT FROM 10.86.214.41.49481 TO 155.169.64.45.13724 fd = 9 17:13:08.597 [13460] <2> logconnections: BPDBM CONNECT FROM 10.86.214.41.49481 TO 155.169.64.45.13724 17:13:08.597 [13460] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required 17:13:08.597 [13460] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required 17:13:08.597 [13460] <2> check_authentication: no authentication required 17:13:08.598 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002 17:13:08.598 [13460] <2> vnet_check_vxss_client_magic_with_info: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002 17:13:08.915 [13460] <16> catch_signal: media manager terminated by parent process 17:13:08.915 [13460] <2> KILL_MM_CHILD: Sending SIGUSR2 (kill) to child 13578 (tmcommon.c:1429) 17:13:08.916 [13460] <2> wait_for_sigcld: waiting for child to exit, timeout is 14400 17:13:08.916 [13460] <2> child_wait: waitpid returned zero, no children waiting (tmcommon.c:5639) 17:13:08.916 [13578] <2> Media_siginfo_print: 0: delay 0 signo SIGUSR2:17 code 0 pid 13460 17:13:09.144 [13460] <2> Media_siginfo_print: 1: delay 0 signo SIGCHLD:18 code 1 pid 13578 17:13:09.144 [13460] <2> child_wait: SIGCHLD: exit=0, signo=0 core=no, pid=13578 (tmcommon.c:5639) 17:13:09.144 [13460] <2> io_terminate_tape: writing empty backup header, drive index 1, copy 2 17:13:09.144 [13460] <2> io_terminate_tape: reposition to previous tapemark and rewrite header 17:13:09.144 [13460] <2> io_ioctl: command (2)MTBSF 1 from (bptm.c.8694) on drive index 1 17:14:26.708 [13460] <2> io_ioctl: command (0)MTWEOF 1 from (bptm.c.8725) on drive index 1 17:14:29.094 [13460] <2> io_write_back_header: drive index 1, empty_file, file num = 1, mpx_headers = 0, copy 2 17:14:29.102 [13460] <2> io_close: closing /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02, from bptm.c.8843 17:14:30.822 [13460] <2> io_terminate_tape: absolute block position prior to writing empty header is 2, copy 2 17:14:30.822 [13460] <2> send_MDS_msg: MEDIADB 1 130664358 WPF898 4015243 *NULL* 20 1312319269 1312319269 1315456009 0 0 0 0 4 7 0 0 1024 0 2 0 17:14:30.935 [13460] <2> io_open: SCSI RESERVE 17:14:30.945 [13460] <2> io_open: file /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02 successfully opened (mode 0) 17:14:30.945 [13460] <2> io_ioctl: command (2)MTBSF 2 from (bptm.c.9000) on drive index 1 17:14:32.512 [13460] <2> io_ioctl: command (1)MTFSF 1 from (bptm.c.9002) on drive index 1 17:14:32.520 [13460] <2> io_close: closing /usr/openv/netbackup/db/media/tpreq/drive_L3_0_7_1_6_SL85_02, from bptm.c.9008 17:14:32.521 [13460] <2> drivename_write: Called with mode 1 17:14:32.521 [13460] <2> drivename_unlock: unlocked 17:14:32.521 [13460] <2> drivename_close: Called for file L3_0_7_1_6_SL85_02 17:14:32.521 [13460] <2> send_MDS_msg: MEDIA_DONE 0 6551974 0 WPF898 4015243 180 {783269C4-1DD2-11B2-AA84-00144FB8B518} 17:14:32.521 [13460] <2> JobInst::sendIrmMsg: starting 17:14:32.521 [13460] <2> packageBptmResourceDoneMsg: msg (MEDIA_DONE 0 6551974 0 WPF898 4015243 180 {783269C4-1DD2-11B2-AA84-00144FB8B518}) 17:14:32.521 [13460] <2> packageBptmResourceDoneMsg: keyword MEDIA_DONE version 0 jobid 6551974 copyNum 0 mediaId WPF898 mediaKey 4015243 unloadDelay 180 allocId {783269C4-1DD2-11B2-AA84-00144FB8B518} 17:14:32.521 [13460] <2> packageBptmResourceDoneMsg: returns 0 17:14:32.525 [13460] <2> JobInst::sendIrmMsg: returning 17:14:32.525 [13460] <2> catch_signal: EXITING with status 82 [ sysops@wspedb52:/usr/openv/netbackup/logs/bptm/ ] $