16/02/2020 07:48:13 - Info nbjm(pid=7664) starting backup job (jobid=724780) for client KOSLOMRI032, policy KTSLO_WBI_MRI_Windows, schedule Weekly_Backup 16/02/2020 07:48:13 - Info nbjm(pid=7664) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=724780, request id:{0D119DFD-F3B8-4621-B81B-D75E48EC4A3F}) 16/02/2020 07:48:13 - requesting resource ktslobak001-hcart3-robot-tld0 16/02/2020 07:48:13 - requesting resource ktslobak001.kt.group.local.NBU_CLIENT.MAXJOBS.KOSLOMRI032 16/02/2020 07:48:13 - requesting resource ktslobak001.kt.group.local.NBU_POLICY.MAXJOBS.KTSLO_WBI_MRI_Windows 16/02/2020 07:48:13 - Info nbrb(pid=32608) Limit has been reached for the logical resource ktslobak001.kt.group.local.NBU_POLICY.MAXJOBS.KTSLO_WBI_MRI_Windows 16/02/2020 08:13:04 - awaiting resource ktslobak001-hcart3-robot-tld0 Reason: Media is in use, Media Server: ktslobak001.kt.group.local, Robot Number: 0, Robot Type: TLD, Media ID: N/A, Drive Name: N/A, Volume Pool: NetBackup, Storage Unit: ktslobak001-hcart3-robot-tld0, Drive Scan Host: N/A 16/02/2020 11:16:36 - awaiting resource ktslobak001-hcart3-robot-tld0 - Maximum job count has been reached for the storage unit 16/02/2020 11:17:24 - granted resource ktslobak001.kt.group.local.NBU_CLIENT.MAXJOBS.KOSLOMRI032 16/02/2020 11:17:24 - granted resource ktslobak001.kt.group.local.NBU_POLICY.MAXJOBS.KTSLO_WBI_MRI_Windows 16/02/2020 11:17:24 - granted resource 0578L3 16/02/2020 11:17:24 - granted resource IBM.ULT3580-TD3.012 16/02/2020 11:17:24 - granted resource ktslobak001-hcart3-robot-tld0 16/02/2020 11:17:25 - estimated 849266326 Kbytes needed 16/02/2020 11:17:25 - Info nbjm(pid=7664) started backup (backupid=KOSLOMRI032_1581851844) job for client KOSLOMRI032, policy KTSLO_WBI_MRI_Windows, schedule Weekly_Backup on storage unit ktslobak001-hcart3-robot-tld0 16/02/2020 11:17:28 - started process bpbrm (112452) 16/02/2020 11:17:32 - Info bpbrm(pid=112452) KOSLOMRI032 is the host to backup data from 16/02/2020 11:17:33 - Info bpbrm(pid=112452) reading file list from client 16/02/2020 11:17:33 - connecting 16/02/2020 11:17:37 - Info bpbrm(pid=112452) starting bpbkar32 on client 16/02/2020 11:17:37 - connected; connect time: 00:00:04 16/02/2020 11:17:42 - Info bpbkar32(pid=15284) Backup started 16/02/2020 11:17:42 - Info bptm(pid=112272) start 16/02/2020 11:17:42 - Info bptm(pid=112272) using 65536 data buffer size 16/02/2020 11:17:42 - Info bptm(pid=112272) setting receive network buffer to 263168 bytes 16/02/2020 11:17:42 - Info bptm(pid=112272) using 30 data buffers 16/02/2020 11:17:43 - Info bptm(pid=112272) start backup 16/02/2020 11:17:43 - Info bptm(pid=112272) backup child process is pid 116320.115532 16/02/2020 11:17:43 - Info bptm(pid=112272) media id 0578L3 mounted on drive index 12, drivepath {2,0,1,1}, drivename IBM.ULT3580-TD3.012, copy 1 16/02/2020 11:17:43 - mounted 16/02/2020 11:17:43 - positioning 0578L3 to file 2 16/02/2020 11:17:43 - positioned 0578L3; position time: 00:00:00 16/02/2020 11:17:43 - begin writing 16/02/2020 11:17:44 - Info bptm(pid=116320) start 16/02/2020 11:20:17 - Info bpbkar32(pid=15284) change journal NOT enabled for 16/02/2020 13:24:58 - current media 0578L3 complete, requesting next resource Any 16/02/2020 13:24:59 - current media -- complete, awaiting next media Any Reason: Media is in use, Media Server: ktslobak001.kt.group.local, Robot Number: 0, Robot Type: TLD, Media ID: N/A, Drive Name: N/A, Volume Pool: NetBackup, Storage Unit: ktslobak001-hcart3-robot-tld0, Drive Scan Host: N/A 16/02/2020 17:25:59 - Info bptm(pid=112272) Waiting for mount of media id 0118L3 (copy 1) on server ktslobak001.kt.group.local. 16/02/2020 17:25:59 - granted resource 0118L3 16/02/2020 17:25:59 - granted resource IBM.ULT3580-TD3.012 16/02/2020 17:25:59 - granted resource ktslobak001-hcart3-robot-tld0 16/02/2020 17:25:59 - end writing; write time: 06:08:16 16/02/2020 17:25:59 - mounting 0118L3 16/02/2020 17:26:11 - Info bptm(pid=112272) media id 0118L3 mounted on drive index 12, drivepath {2,0,1,1}, drivename IBM.ULT3580-TD3.012, copy 1 16/02/2020 17:26:11 - mounted; mount time: 00:00:12 16/02/2020 17:26:12 - positioning 0118L3 to file 1 16/02/2020 17:26:12 - positioned 0118L3; position time: 00:00:00 16/02/2020 17:26:12 - begin writing 16/02/2020 19:44:02 - current media 0118L3 complete, requesting next resource Any 16/02/2020 19:44:02 - current media -- complete, awaiting next media Any Reason: Drives are in use, Media Server: ktslobak001.kt.group.local, Robot Number: 0, Robot Type: TLD, Media ID: N/A, Drive Name: N/A, Volume Pool: NetBackup, Storage Unit: ktslobak001-hcart3-robot-tld0, Drive Scan Host: N/A 16/02/2020 19:44:07 - Info bptm(pid=112272) Waiting for mount of media id 0148L3 (copy 1) on server ktslobak001.kt.group.local. 16/02/2020 19:44:07 - granted resource 0148L3 16/02/2020 19:44:07 - granted resource IBM.ULT3580-TD3.012 16/02/2020 19:44:07 - granted resource ktslobak001-hcart3-robot-tld0 16/02/2020 19:44:07 - end writing; write time: 02:17:55 16/02/2020 19:44:07 - mounting 0148L3 16/02/2020 19:44:13 - Info bptm(pid=112272) media id 0148L3 mounted on drive index 12, drivepath {2,0,1,1}, drivename IBM.ULT3580-TD3.012, copy 1 16/02/2020 19:44:13 - mounted; mount time: 00:00:06 16/02/2020 19:44:14 - positioning 0148L3 to file 1 16/02/2020 19:44:14 - positioned 0148L3; position time: 00:00:00 16/02/2020 19:44:14 - begin writing 16/02/2020 21:30:41 - current media 0148L3 complete, requesting next resource Any 16/02/2020 21:30:42 - current media -- complete, awaiting next media Any Reason: Media is in use, Media Server: ktslobak001.kt.group.local, Robot Number: 0, Robot Type: TLD, Media ID: N/A, Drive Name: N/A, Volume Pool: NetBackup, Storage Unit: ktslobak001-hcart3-robot-tld0, Drive Scan Host: N/A 17/02/2020 02:27:51 - granted resource 0886L3 17/02/2020 02:27:51 - granted resource IBM.ULT3580-TD3.006 17/02/2020 02:27:51 - granted resource ktslobak001-hcart3-robot-tld0 17/02/2020 02:27:52 - Info bptm(pid=112272) Waiting for mount of media id 0886L3 (copy 1) on server ktslobak001.kt.group.local. 17/02/2020 02:27:52 - end writing; write time: 06:43:38 17/02/2020 02:27:52 - mounting 0886L3 17/02/2020 02:28:03 - Info bptm(pid=112272) media id 0886L3 mounted on drive index 6, drivepath {1,0,1,3}, drivename IBM.ULT3580-TD3.006, copy 1 17/02/2020 02:28:03 - mounted; mount time: 00:00:11 17/02/2020 02:28:03 - positioning 0886L3 to file 1 17/02/2020 02:28:03 - positioned 0886L3; position time: 00:00:00 17/02/2020 02:28:03 - begin writing 17/02/2020 02:28:04 - Error bpbrm(pid=112452) from client KOSLOMRI032: ERR - failure reading file: E:\Archive_DoNotDelete\cert4805133_20180209\src_on_KOSLOMRI032\Cert4805133.prev.mdd (WIN32 21: The device is not ready. ) 17/02/2020 02:28:04 - Error bpbrm(pid=112452) from client KOSLOMRI032: ERR - Snapshot Error while reading file: GLOBALROOT\Device\HarddiskVolumeShadowCopy20\Archive_DoNotDelete\cert4805133_20180209\src_on_KOSLOMRI032\Cert4805133.prev.mdd 17/02/2020 02:28:07 - Critical bpbrm(pid=112452) from client KOSLOMRI032: FTL - Backup operation aborted! 17/02/2020 02:28:09 - Error bpbrm(pid=112452) could not send server status message 17/02/2020 02:28:11 - Info bpbkar32(pid=15284) done. status: 156: snapshot error encountered 17/02/2020 02:28:11 - end writing; write time: 00:00:08 snapshot error encountered(156)