C:\Users\vrgel_veritas>vxlogview -p 51216 -X "jobid=3497"
19/10/2015 13:04:16.300 V-117-64 [ForeignJob::ForeignJob] Initiating foreign job
 (jobid=3497)
19/10/2015 13:04:16.315 V-118-227 [ResBroker_i::requestResources] received resou
rce request ID {AB2C3EA2-6039-4E3F-A2E3-D8999994CFB3}, priority 90000, secondary
 priority 0, description FOREIGN_JOB_3497
19/10/2015 13:04:16.315 [ResBroker_i::requestResources] RequestSeq:
Request=0 provider=DriveOperationProvider resourcename=MEDIA RESOURCE userSequen
ce=0 MediaRequest { mediaId=0015L5 mediaServer=media_server m
ediaKey=0 userReservationId= assignedTime=1444926736 client=xxx usageTyp
e=2 mustBeNdmp=no driveName= drivePath= mediaPool= robotNumber=-1 slotNumber=-1
density=-1 ndmpControlHost= failIfNoMedia=yes externalFile= mediaType=2 mediaSub
Type=0 NDMPHostName= }
19/10/2015 13:04:16.347 [allocateMedia] INITIATING:
19/10/2015 13:04:16.347 [allocateMedia] masterServer = sdebck31092.euro.pilkingt
on.net, client = xxx, jobType = 2, capabilityFlags = 0, fatPipePreferenc
e = 0, statusOnly = 0
19/10/2015 13:04:16.347 [allocateMedia] MediaRequest_Record: MediaServer = sdebc
k31090.euro.pilkington.net, PreferredMediaServer = , MediaId = 0015L5, MediaKey
= 0, AssignedTime = 1444926736, DriveName = , DrivePath = , PoolName = , Density
 = -1, RequiredNdmpTapeServer = , PreferredNdmpTapeServer = , MediaType = 2, Med
iaSubType = 0, StuNameForDupWrite =
19/10/2015 13:04:16.347 V-118-226 [ResBroker_i::evaluateOne] Evaluating request
ID {AB2C3EA2-6039-4E3F-A2E3-D8999994CFB3}
19/10/2015 13:04:16.409 [fill_bsr] ALLOCATION: key = 413, media server = sdebck3
1090.euro.pilkington.net, mds_flags = 16, scsi_protection = 1, preempt_reservati
on = 0, preempted_ms_key = 0
19/10/2015 13:04:16.409 [fill_bsr] MEDIA: id = 0015L5, key = 4000053
19/10/2015 13:04:16.409 [fill_bsr] DRIVE: name = IBM.ULT3580-HH5.000, path = {12
,0,0,0}, key = 2000017, ndmp_host_key = 0
19/10/2015 13:04:16.409 [fill_bsr] STU: name = *NULL*, master server = *NULL*
19/10/2015 13:04:16.409 [fill_bsr] DISKGROUP: id = *NULL*, key = 0
19/10/2015 13:04:16.409 [fill_bsr] DISKVOLUME: media_id = *NULL*, key = 0
19/10/2015 13:04:16.409 [fill_bsr] DISKMOUNTPOINT: mount_point = *NULL*, key = 0

19/10/2015 13:04:16.409 [allocateMedia] EXIT INFO:
19/10/2015 13:04:16.409 [allocateMedia] rbActions = 0
19/10/2015 13:04:16.409 [allocateMedia] alloc_med_list = 4000053
19/10/2015 13:04:16.409 [allocateMedia] alloc_drv_list = 2000017
19/10/2015 13:04:16.409 [allocateMedia] EXIT STATUS = 0 (EMM_ERROR_Success, Succ
ess)

19/10/2015 13:04:16.409 V-118-202 [EMMAccess::allocateMedia] request to allocate
 media (Master Server master_server, Client xxx, Job T
ype 2, Media ID 0015L5, Drive Name <?>, Media Server sdebck31090.euro.pilkington
.net, Capabilities 0, Fibre Transport Preference 0, Assigned Time 1444926736) re
turned 0
19/10/2015 13:04:16.409 [EMMAccess::allocateMedia] media allocated: mediaId=0015
L5, driveName=IBM.ULT3580-HH5.000, mediaServer=media_server,
allocationKey=413
19/10/2015 13:04:16.409 V-118-146 [ProviderManager::allocate] DriveOperationProv
ider returned Allocation Granted for request ID {AB2C3EA2-6039-4E3F-A2E3-D899999
4CFB3}
19/10/2015 13:04:16.425 [ResBroker_i::evaluateOne] resources found for request,
requestId={AB2C3EA2-6039-4E3F-A2E3-D8999994CFB3}, userId=jobid=3497, birthTime=1
445252656, timeToFirstEval=0 sec, timeToSuccessOrFailure=0 sec, numberOfTimesEva
luated=1
19/10/2015 13:04:16.425 V-118-109 [ResBroker_i::passOne] resources found for req
uest ID {AB2C3EA2-6039-4E3F-A2E3-D8999994CFB3}, following allocations are grante
d:
19/10/2015 13:04:16.425 V-118-228 [ResBroker_i::passOne] allocation ID {F08322B7
-2880-4D7B-A9F6-F2DD3D9ACC10}, group ID {00000000-0000-0000-0000-000000000000},
provider DriveOperationProvider, resource 0015L5
19/10/2015 13:04:16.425 [ResBroker_i::passOne] allocation: (Allocation: id={F083
22B7-2880-4D7B-A9F6-F2DD3D9ACC10} provider=DriveOperationProvider resourcename=0
015L5 masterserver=master_server groupid={00000000-0000-0000-0
000-000000000000} userSequence=0 userid="jobid=3497"  firstuserid="jobid=3497" (
Media_Drive_Allocation_Record: allocationKey=413 (Media_Drive_Record: MediaKey=4
000053 MediaId=0015L5 MediaServer=media_server DriveKey=20000
17 DriveName=IBM.ULT3580-HH5.000 PrimaryPath={12,0,0,0} PoolName=DC1 RobotNum=0
RobotType=8 MediaTypeName=NetBackup HCART2 DriveTypeName=NetBackup HCART2 NdmpCo
ntrolHost= RetentionLevel=0 PolicyType=2 JobType=2 MasterServer=sdebck31092.euro
.pilkington.net) (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="MEDI
ADB 1 413 0015L5 4000053 ------ 14 1444926736 1445212579 1453247779 1445248650 7
99938899 75 75 5 4 1 512 1024 0 12499237 0" 1="VOLUME 1 0015L5 4000053 500015L5
DC1 SONY N141106185 14 8 0 12 0 {00000000-0000-0000-0000-000000000000} 0" 2="DRI
VE 3 IBM.ULT3580-HH5.000 2000017 1068003235 {12,0,0,0} -1 -1 -1 -1 -1 -1 -1 -1 *
NULL* *NULL* *NULL* *NULL* 1 16 0 1 0 0" 3="STORAGE 1 *NULL* 0 0 0 0 0 0 sdebck3
1090.euro.pilkington.net media_server *NULL*" 4="DISKGROUP 0
6 *NULL* 6 *NULL* 6 *NULL*" 5="DISKVOLUME 0 6 *NULL* 6 *NULL* 0" 6="DISKMOUNTPOI
NT 0 6 *NULL*" ) TpReqFileName=) useFatPipeTransport=false diskPath= diskGroupNa
me= storageServerType= diskGroupStorageServerName= failureCode=0)
19/10/2015 13:04:16.425 V-118-249 [CallbackQueue::resourcesAvailable] added allo
cations to the callback queue for request ID {AB2C3EA2-6039-4E3F-A2E3-D8999994CF
B3}
19/10/2015 13:04:16.425 V-118-250 [CallbackQueue::notifyClientAvailable] queuein
g notification of availability of resources for request ID {AB2C3EA2-6039-4E3F-A
2E3-D8999994CFB3}
19/10/2015 13:04:16.425 V-118-256 [CorbaCall_notifyClientAvailable::execute] sen
ding availability of resources to nbjm for request ID {AB2C3EA2-6039-4E3F-A2E3-D
8999994CFB3}
19/10/2015 13:36:02.660 V-117-239 [ForeignJob::terminateThisJob] terminated job,
 jobid=3497, status=0
19/10/2015 13:36:02.691 [downStuCnts] INITIATING:
19/10/2015 13:36:02.691 [downStuCnts] allocationKey = 413
19/10/2015 13:36:02.691 [downStuCnts] alloc_med_list = 4000053
19/10/2015 13:36:02.691 [downStuCnts] alloc_drv_list = 2000017
19/10/2015 13:36:02.691 [downStuCnts] EXIT INFO:
19/10/2015 13:36:02.691 [downStuCnts] alloc_med_list = 4000053
19/10/2015 13:36:02.691 [downStuCnts] alloc_drv_list = 2000017
19/10/2015 13:36:02.691 [downStuCnts] EXIT STATUS = 0 (EMM_ERROR_Success, Succes
s)

19/10/2015 13:36:02.691 V-118-102 [ResBroker_i::releaseOne] releasing allocation
 ID {F08322B7-2880-4D7B-A9F6-F2DD3D9ACC10}
19/10/2015 13:36:02.691 [EMMProvider::release(mdar)] received release of mediaId
=0015L5, driveName=IBM.ULT3580-HH5.000, STU=
19/10/2015 13:36:02.707 [setAvailable] INITIATING:
19/10/2015 13:36:02.707 [setAvailable] force = 0, unloadFlags = 0
19/10/2015 13:36:02.707 [setAvailable] allocationKey = 413
19/10/2015 13:36:02.707 [setAvailable] alloc_med_list = 4000053
19/10/2015 13:36:02.707 [setAvailable] alloc_drv_list = 2000017
19/10/2015 13:36:02.707 V-118-217 [EMMAccess::downStuCnts] request to down STU c
ounts (STU <?>, Allocation Key 413) returned 0
19/10/2015 13:36:02.722 [setAvailable] EXIT INFO:
19/10/2015 13:36:02.722 [setAvailable] EXIT STATUS = 0 (EMM_ERROR_Success, Succe
ss)

19/10/2015 13:36:02.722 V-118-219 [EMMAccess::setAvailable] request to set media
-drive pair available (Media ID 0015L5, Drive Name IBM.ULT3580-HH5.000, Allocati
on Key 413, Force false, Unload Flags 0) returned 0
19/10/2015 13:36:31.536 V-117-64 [ForeignJob::ForeignJob] Initiating foreign job
 (jobid=3497)
19/10/2015 13:36:31.536 V-118-227 [ResBroker_i::requestResources] received resou
rce request ID {795C3265-A4E2-4AC5-A69D-2CB6ABC76AAE}, priority 90000, secondary
 priority 0, description FOREIGN_JOB_3497
19/10/2015 13:36:31.536 [ResBroker_i::requestResources] RequestSeq:
Request=0 provider=DriveOperationProvider resourcename=MEDIA RESOURCE userSequen
ce=0 MediaRequest { mediaId=0011L5 mediaServer=media_server m
ediaKey=0 userReservationId= assignedTime=1443715226 client=xxx usageTyp
e=2 mustBeNdmp=no driveName= drivePath= mediaPool= robotNumber=-1 slotNumber=-1
density=-1 ndmpControlHost= failIfNoMedia=yes externalFile= mediaType=2 mediaSub
Type=0 NDMPHostName= }
19/10/2015 13:36:31.598 [allocateMedia] INITIATING:
19/10/2015 13:36:31.598 [allocateMedia] masterServer = sdebck31092.euro.pilkingt
on.net, client = xxx, jobType = 2, capabilityFlags = 0, fatPipePreferenc
e = 0, statusOnly = 0
19/10/2015 13:36:31.598 [allocateMedia] MediaRequest_Record: MediaServer = sdebc
k31090.euro.pilkington.net, PreferredMediaServer = , MediaId = 0011L5, MediaKey
= 0, AssignedTime = 1443715226, DriveName = , DrivePath = , PoolName = , Density
 = -1, RequiredNdmpTapeServer = , PreferredNdmpTapeServer = , MediaType = 2, Med
iaSubType = 0, StuNameForDupWrite =
19/10/2015 13:36:31.598 V-118-226 [ResBroker_i::evaluateOne] Evaluating request
ID {795C3265-A4E2-4AC5-A69D-2CB6ABC76AAE}
19/10/2015 13:36:31.645 [fill_bsr] ALLOCATION: key = 414, media server = sdebck3
1090.euro.pilkington.net, mds_flags = 16, scsi_protection = 1, preempt_reservati
on = 0, preempted_ms_key = 0
19/10/2015 13:36:31.645 [fill_bsr] MEDIA: id = 0011L5, key = 4000079
19/10/2015 13:36:31.645 [fill_bsr] DRIVE: name = IBM.ULT3580-HH5.002, path = {13
,0,0,0}, key = 2000019, ndmp_host_key = 0
19/10/2015 13:36:31.645 [fill_bsr] STU: name = *NULL*, master server = *NULL*
19/10/2015 13:36:31.645 [fill_bsr] DISKGROUP: id = *NULL*, key = 0
19/10/2015 13:36:31.645 [fill_bsr] DISKVOLUME: media_id = *NULL*, key = 0
19/10/2015 13:36:31.645 [fill_bsr] DISKMOUNTPOINT: mount_point = *NULL*, key = 0

19/10/2015 13:36:31.645 [allocateMedia] EXIT INFO:
19/10/2015 13:36:31.645 [allocateMedia] rbActions = 0
19/10/2015 13:36:31.645 [allocateMedia] alloc_med_list = 4000079
19/10/2015 13:36:31.645 [allocateMedia] alloc_drv_list = 2000019
19/10/2015 13:36:31.645 [allocateMedia] EXIT STATUS = 0 (EMM_ERROR_Success, Succ
ess)

19/10/2015 13:36:31.645 V-118-202 [EMMAccess::allocateMedia] request to allocate
 media (Master Server master_server, Client xxx, Job T
ype 2, Media ID 0011L5, Drive Name <?>, Media Server sdebck31090.euro.pilkington
.net, Capabilities 0, Fibre Transport Preference 0, Assigned Time 1443715226) re
turned 0
19/10/2015 13:36:31.645 [EMMAccess::allocateMedia] media allocated: mediaId=0011
L5, driveName=IBM.ULT3580-HH5.002, mediaServer=media_server,
allocationKey=414
19/10/2015 13:36:31.645 V-118-146 [ProviderManager::allocate] DriveOperationProv
ider returned Allocation Granted for request ID {795C3265-A4E2-4AC5-A69D-2CB6ABC
76AAE}
19/10/2015 13:36:31.645 [ResBroker_i::evaluateOne] resources found for request,
requestId={795C3265-A4E2-4AC5-A69D-2CB6ABC76AAE}, userId=jobid=3497, birthTime=1
445254591, timeToFirstEval=0 sec, timeToSuccessOrFailure=0 sec, numberOfTimesEva
luated=1
19/10/2015 13:36:31.645 V-118-109 [ResBroker_i::passOne] resources found for req
uest ID {795C3265-A4E2-4AC5-A69D-2CB6ABC76AAE}, following allocations are grante
d:
19/10/2015 13:36:31.645 V-118-228 [ResBroker_i::passOne] allocation ID {BB8D2A30
-AF00-43C1-B4A9-C11674847275}, group ID {00000000-0000-0000-0000-000000000000},
provider DriveOperationProvider, resource 0011L5
19/10/2015 13:36:31.645 [ResBroker_i::passOne] allocation: (Allocation: id={BB8D
2A30-AF00-43C1-B4A9-C11674847275} provider=DriveOperationProvider resourcename=0
011L5 masterserver=master_server groupid={00000000-0000-0000-0
000-000000000000} userSequence=0 userid="jobid=3497"  firstuserid="jobid=3497" (
Media_Drive_Allocation_Record: allocationKey=414 (Media_Drive_Record: MediaKey=4
000079 MediaId=0011L5 MediaServer=media_server DriveKey=20000
19 DriveName=IBM.ULT3580-HH5.002 PrimaryPath={13,0,0,0} PoolName=DC1 RobotNum=0
RobotType=8 MediaTypeName=NetBackup HCART2 DriveTypeName=NetBackup HCART2 NdmpCo
ntrolHost= RetentionLevel=0 PolicyType=2 JobType=2 MasterServer=sdebck31092.euro
.pilkington.net) (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="MEDI
ADB 1 414 0011L5 4000079 ------ 14 1443715226 1445208851 1453244051 1445250530 2
158001209 268 268 5 4 1 512 1024 0 33719499 0" 1="VOLUME 1 0011L5 4000079 500011
L5 DC1 SONY D141106194 14 8 0 40 0 {00000000-0000-0000-0000-000000000000} 0" 2="
DRIVE 3 IBM.ULT3580-HH5.002 2000019 1068003252 {13,0,0,0} -1 -1 -1 -1 -1 -1 -1 -
1 *NULL* *NULL* *NULL* *NULL* 1 16 0 1 0 0" 3="STORAGE 1 *NULL* 0 0 0 0 0 0 sdeb
ck31090.euro.pilkington.net media_server *NULL*" 4="DISKGROUP
 0 6 *NULL* 6 *NULL* 6 *NULL*" 5="DISKVOLUME 0 6 *NULL* 6 *NULL* 0" 6="DISKMOUNT
POINT 0 6 *NULL*" ) TpReqFileName=) useFatPipeTransport=false diskPath= diskGrou
pName= storageServerType= diskGroupStorageServerName= failureCode=0)
19/10/2015 13:36:31.645 V-118-249 [CallbackQueue::resourcesAvailable] added allo
cations to the callback queue for request ID {795C3265-A4E2-4AC5-A69D-2CB6ABC76A
AE}
19/10/2015 13:36:31.661 V-118-250 [CallbackQueue::notifyClientAvailable] queuein
g notification of availability of resources for request ID {795C3265-A4E2-4AC5-A
69D-2CB6ABC76AAE}
19/10/2015 13:36:31.661 V-118-256 [CorbaCall_notifyClientAvailable::execute] sen
ding availability of resources to nbjm for request ID {795C3265-A4E2-4AC5-A69D-2
CB6ABC76AAE}
19/10/2015 13:44:07.405 V-117-239 [ForeignJob::terminateThisJob] terminated job,
 jobid=3497, status=0
19/10/2015 13:44:07.436 V-118-102 [ResBroker_i::releaseOne] releasing allocation
 ID {BB8D2A30-AF00-43C1-B4A9-C11674847275}
19/10/2015 13:44:07.436 [EMMProvider::release(mdar)] received release of mediaId
=0011L5, driveName=IBM.ULT3580-HH5.002, STU=
19/10/2015 13:44:07.452 [downStuCnts] INITIATING:
19/10/2015 13:44:07.452 [downStuCnts] allocationKey = 414
19/10/2015 13:44:07.452 [downStuCnts] alloc_med_list = 4000079
19/10/2015 13:44:07.452 [downStuCnts] alloc_drv_list = 2000019
19/10/2015 13:44:07.452 [downStuCnts] EXIT INFO:
19/10/2015 13:44:07.452 [downStuCnts] alloc_med_list = 4000079
19/10/2015 13:44:07.452 [downStuCnts] alloc_drv_list = 2000019
19/10/2015 13:44:07.452 [downStuCnts] EXIT STATUS = 0 (EMM_ERROR_Success, Succes
s)

19/10/2015 13:44:07.452 [setAvailable] INITIATING:
19/10/2015 13:44:07.452 [setAvailable] force = 0, unloadFlags = 0
19/10/2015 13:44:07.452 [setAvailable] allocationKey = 414
19/10/2015 13:44:07.452 [setAvailable] alloc_med_list = 4000079
19/10/2015 13:44:07.452 [setAvailable] alloc_drv_list = 2000019
19/10/2015 13:44:07.452 V-118-217 [EMMAccess::downStuCnts] request to down STU c
ounts (STU <?>, Allocation Key 414) returned 0
19/10/2015 13:44:07.467 [setAvailable] EXIT INFO:
19/10/2015 13:44:07.467 [setAvailable] EXIT STATUS = 0 (EMM_ERROR_Success, Succe
ss)

19/10/2015 13:44:07.467 V-118-219 [EMMAccess::setAvailable] request to set media
-drive pair available (Media ID 0011L5, Drive Name IBM.ULT3580-HH5.002, Allocati
on Key 414, Force false, Unload Flags 0) returned 0