C:\Users\admin>vxlogview -p 51216 -X "jobid=48331" 22/04/2022 06:45:03.218 V-116-215 [BaseJob::run] jobid=48331 submitted to nbjm for processing 22/04/2022 06:45:03.249 [JobInstance::state] (00000000039B2480) state=0(JobInstance.cpp:365) 22/04/2022 06:45:03.249 V-117-56 [BackupJob::sendRequestToRB] requesting resources from RB for backup job (jobid=48331) 22/04/2022 06:45:03.249 V-118-227 [ResBroker_i::requestResources] received resource request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3}, priority 999, secondary priority 26376, description THE_BACKUP_JOB-48331-{50546BE3-CE35-42D6-804F-A87FCB1FC8B3} 22/04/2022 06:45:03.249 [ResBroker_i::requestResources] RequestSeq: Request=0 provider=NamedResourceProvider resourcename=bkp01.NBU_CATALOG.MAXJOBS CountedResourceRequest { max=1 } 22/04/2022 06:45:03.265 [ResBroker_i::evaluateOne] Evaluating request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3} 22/04/2022 06:45:03.265 [ProviderManager::allocate] NamedResourceProvider returned Allocation Granted for request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3} 22/04/2022 06:45:03.296 [JobInstance::state] (00000000039B2480) state=1(JobInstance.cpp:365) 22/04/2022 06:45:03.296 V-117-296 [BackupJob::extractResourceAttributes] unable to get storage unit resource attribute 22/04/2022 06:45:03.296 V-117-296 [BackupJob::extractResourceAttributes] unable to get media server resource attribute 22/04/2022 06:45:03.296 [BackupJob::extractResourceAttributes] (00000000039B2480) media server=(BackupJob.cpp:1439) 22/04/2022 06:45:03.296 V-117-296 [BackupJob::extractResourceAttributes] unable to get stu name resource attribute 22/04/2022 06:45:03.296 V-117-296 [BackupJob::extractResourceAttributes] unable to get mpxid resource attribute 22/04/2022 06:45:03.296 [BackupJob::processProxyResponse] (00000000039B2480) Done: flush proxy response, next:start job, jobid=48331(BackupJob.cpp:4081) 22/04/2022 06:45:03.296 [JobInstance::state] (00000000039B2480) state=1(JobInstance.cpp:365) 22/04/2022 06:45:03.296 [JobInstance::state] (00000000039B2480) state=1(JobInstance.cpp:365) 22/04/2022 06:45:03.296 [ResBroker_i::evaluateOne] resources found for request, requestId={50546BE3-CE35-42D6-804F-A87FCB1FC8B3}, userId=jobid=48331, birthTime=1650606303, timeToFirstEval=0 sec, timeToSuccessOrFailure=0 sec, numberOfTimesEvaluated=1 22/04/2022 06:45:03.296 V-118-109 [ResBroker_i::passOne] resources found for request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3}, following allocations are granted: 22/04/2022 06:45:03.296 V-118-228 [ResBroker_i::passOne] allocation ID {881757D7-BC1B-4FFB-815C-2B53AB5ACACD}, group ID {00000000-0000-0000-0000-000000000000}, provider NamedResourceProvider, resource bkp01.NBU_CATALOG.MAXJOBS 22/04/2022 06:45:03.296 [ResBroker_i::passOne] allocation: (Allocation: id={881757D7-BC1B-4FFB-815C-2B53AB5ACACD} provider=NamedResourceProvider resourcename=bkp01.NBU_CATALOG.MAXJOBS masterserver=bkp01 groupid={00000000-0000-0000-0000-000000000000} userSequence=-1 userid="jobid=48331" firstuserid="jobid=48331" named resource allocation) 22/04/2022 06:45:03.296 V-118-249 [CallbackQueue::resourcesAvailable] added allocations to the callback queue for request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3} 22/04/2022 06:45:03.296 V-118-250 [CallbackQueue::notifyClientAvailable] queueing notification of availability of resources for request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3} 22/04/2022 06:45:03.296 V-118-256 [CorbaCall_notifyClientAvailable::execute] sending availability of resources to nbjm for request ID {50546BE3-CE35-42D6-804F-A87FCB1FC8B3} 22/04/2022 06:45:03.671 [GenBackupJob::processProxyResponse] (00000000039B2480) Done: create image, Next: start genjob, proxy status=0(GenBackupJob.cpp:899) 22/04/2022 06:45:03.671 [JobInstance::state] (00000000039B2480) state=1(JobInstance.cpp:365) 22/04/2022 06:45:03.671 [GenBackupJob::spawnGenericJob] (00000000039B2480) start CommandActions(GenBackupJob.cpp:680) 22/04/2022 06:45:03.671 [GenBackupJob::spawnGenericJob] GenBackupJob Commandline Options= ************************** * GenBackupJob * ************************** Jobid = 48331 GroupId = 48331 SubType = 35 MediaServer = MasterServer = bkp01 PolicyName = Catalogue SchedName = incr_daily SchedType = 1 ClientName = bkp01 ClientType = 35 Stream Num = -1 Birthtime = 1650606303 BackupCopy = 0 BackupId = bkp01_1650606303 SnapshotId = User = root BMRSave = no StreamDiscovery = no Resume = no Checkpoint = no UseInternalJobid = no OpaqueString = -cbustart 0 -cbuend 0 -cbustart 0 -cbuend 0 ************************** *BackupJob * (jobid=48331 jobtype=6) ************************** isStdBackup = false backupType = 6 subtype = 35 mpxid = {00000000-0000-0000-0000-000000000000} maxmpx = 1 Birthtime = 1650606303 backupid = bkp01_1650606303 Active pid = 0 Job Count = 1 IPaddr = currentThrottle = -1 estimatedSize = 0 estimatedFileCount= 0 suspendable = 0 progressLogTimerID= -1 localBackup = 0 policy = Catalogue Num copies = 1 Include_file# = 1 resourceCount = 1 Stu = MSDP_DP-MSDP2 Pool = NetBackup Retention = 0 UseLocal = false (GenBackupJob.cpp:748) 22/04/2022 06:45:03.671 [Info] V-117-32 Map jobtype to column=7, column name=CATALOG_BACKUP: 22/04/2022 06:45:03.671 [Info] V-117-88 FSM JobTable[CATALOG_BACKUP:StartNotifyScript] m_JobStep=1, Jobid=48331 22/04/2022 06:45:03.687 [Info] V-117-122 started backup job for client bkp01, policy Catalogue, schedule incr_daily on storage unit 22/04/2022 06:45:04.234 [Info] V-117-94 FSM JobTable[CATALOG_BACKUP:StartNotifyScript] m_JobStep=1, Jobid=48331, returns=0 22/04/2022 06:45:04.234 [Info] V-117-88 FSM JobTable[CATALOG_BACKUP:DbmQuery] m_JobStep=2, Jobid=48331 22/04/2022 06:53:40.338 [JobInstance::state] (00000000039B2480) state=5(JobInstance.cpp:365) 22/04/2022 06:53:40.338 [Info] V-117-94 FSM JobTable[CATALOG_BACKUP:DbmQuery] m_JobStep=2, Jobid=48331, returns=0 22/04/2022 06:53:40.338 [Info] V-117-88 FSM JobTable[CATALOG_BACKUP:ValidateImage] m_JobStep=3, Jobid=48331 22/04/2022 06:53:40.385 [Info] V-117-174 validateSnapshot returns=0 22/04/2022 06:53:40.385 [Info] V-117-94 FSM JobTable[CATALOG_BACKUP:ValidateImage] m_JobStep=3, Jobid=48331, returns=0 22/04/2022 06:53:40.385 [Info] V-117-88 FSM JobTable[CATALOG_BACKUP:EndNotifyScript] m_JobStep=4, Jobid=48331 22/04/2022 06:53:40.776 [Info] V-117-94 FSM JobTable[CATALOG_BACKUP:EndNotifyScript] m_JobStep=4, Jobid=48331, returns=0 22/04/2022 06:53:40.776 [Info] V-117-107 *********** Jobid 48331 status summary for CATALOG_BACKUP: ********* 22/04/2022 06:53:40.776 [Info] V-117-114 Step 1 StartNotifyScript status 0 jobstatus - 22/04/2022 06:53:40.776 [Info] V-117-114 Step 2 DbmQuery status 0 jobstatus 0 22/04/2022 06:53:40.776 [Info] V-117-114 Step 3 ValidateImage status 0 jobstatus 0 22/04/2022 06:53:40.776 [Info] V-117-114 Step 4 EndNotifyScript status 0 jobstatus 0 22/04/2022 06:53:40.776 [Info] V-117-111 ********** job status is 0 ********** 22/04/2022 06:53:40.776 [Info] V-117-52 GenBackupJob Terminating status=0 22/04/2022 06:53:40.776 [JobInstance::state] (00000000039B2480) state=5(JobInstance.cpp:365) 22/04/2022 06:53:40.776 [JobInstance::state] (00000000039B2480) state=5(JobInstance.cpp:365) 22/04/2022 06:53:40.776 [JobInstance::state] (00000000039B2480) state=10(JobInstance.cpp:365) 22/04/2022 06:53:40.776 [BackupJob::sendNotifications] (00000000039B2480) disable resume=false, brm started=false(BackupJob.cpp:2717) 22/04/2022 06:53:40.776 V-117-239 [BackupJob::terminateThisJob] terminated job, jobid=48331, status=0 (null) 22/04/2022 06:53:40.776 V-116-216 [RecoverableJob::doJobCompletion] jobid=48331 completed with status 0 22/04/2022 06:53:40.776 [PemTask::taskComplete] (ID:0000000003A14438 CTX:000000000394A1A8) Active subtask count=0(PemTask.cpp:530) 22/04/2022 06:53:40.776 [Info] V-116-14 CLIENT bkp01 POLICY Catalogue SCHED incr_daily EXIT STATUS 0 (the requested operation was successfully completed) VBRF 1 0 22/04/2022 06:53:40.791 [RecoverableJob::unregisterForEmail] (ID:0000000003A14438 CTX:000000000394A1A8) Unregistered for email(RecoverableJob.cpp:3068) 22/04/2022 06:53:40.807 V-118-102 [ResBroker_i::releaseOne] releasing allocation ID {881757D7-BC1B-4FFB-815C-2B53AB5ACACD}