I have 1 backup copy job, with 4 tasks in it. 3 of them processed properly and 1 not.
VBR gives only this info:
28.07.2021 2:02:02 :: Backup copy for WEB1 started at 28.07.2021 2:02:02
28.07.2021 2:02:02 :: Task was not processed in the current session
28.07.2021 2:02:02 :: Failed to process WEB1 (0 B) at 28.07.2021 2:02:03
Im not good at english and reading logs so i ask u to help me. Whats the problem?
Code: Select all
Job.WEB1.BackupSync.log
[28.07.2021 02:02:02] <17> Info Creating mutex Global\BackupMetaThis server_ fileserv|Backup|VM|VM Copy to FileServ|WEB1|WEB1.vbm
[28.07.2021 02:02:02] <17> Info [BackupMeta] Saving backup meta to '\\fileserv|Backup|VM|VM Copy to FileServ|WEB1|WEB1.vbm'
[28.07.2021 02:02:02] <17> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [26.07.2021 23:02:12,88] new value: [27.07.2021 23:02:02,89]
[28.07.2021 02:02:02] <17> Info [Mutex] Releasing mutex [Global\BackupMeta[b2203dda-c5c2-420f-96e7-f4e1b393bbc6]]
[28.07.2021 02:02:02] <17> Info [BackupMetaUpdater] Backup meta generated
[28.07.2021 02:02:02] <01> Info [BackupMeta] Backup meta for 'VM Copy to FileServ\WEB1:9ae25045-b3d0-4ef2-a44c-208f76e08e6d' generated
[28.07.2021 02:02:02] <01> Info [RpoPointAlg] Preparing point in RPO mode.
[28.07.2021 02:02:02] <01> Info [Point] Finding next point by link for '033b8143-388f-4cf6-a2ab-c1b0e6d9d1fc'
[28.07.2021 02:02:02] <01> Info [Point] Next point by link for '033b8143-388f-4cf6-a2ab-c1b0e6d9d1fc' found: 'id=465d4c0e-4c15-4c48-a692-e472b41c457c:type=Normal:alg=Increment:creation_time=08.07.2021 2:01:37:creation_time_utc=07.07.2021 23:01:37:link_id:608d4fa3-81ac-4dfc-ae40-025cf48d64d4'
[28.07.2021 02:02:02] <01> Info [Point] Finding next point by link for '465d4c0e-4c15-4c48-a692-e472b41c457c'
[28.07.2021 02:02:02] <01> Info [Point] Next point by link for '465d4c0e-4c15-4c48-a692-e472b41c457c' found: 'id=608d4fa3-81ac-4dfc-ae40-025cf48d64d4:type=Basic:alg=Full:creation_time=07.07.2021 2:01:54:creation_time_utc=06.07.2021 23:01:54:link_id:00000000-0000-0000-0000-000000000000'
[28.07.2021 02:02:02] <01> Info [Point] Finding next point by link for '608d4fa3-81ac-4dfc-ae40-025cf48d64d4'
[28.07.2021 02:02:02] <01> Info [Point] Next point by link for '608d4fa3-81ac-4dfc-ae40-025cf48d64d4' not found
[28.07.2021 02:02:02] <01> Info [RpoPointAlg] Creating incremental point
[28.07.2021 02:02:02] <01> Info [CPoint] Creating point id=9d7588be-7671-49a5-82c2-28d2beb9beb7:type=Normal:alg=Increment:creation_time=28.07.2021 2:01:34:creation_time_utc=27.07.2021 23:01:34:link_id:033b8143-388f-4cf6-a2ab-c1b0e6d9d1fc
[28.07.2021 02:02:02] <01> Info [Point] Create, id '9d7588be-7671-49a5-82c2-28d2beb9beb7', link_id '033b8143-388f-4cf6-a2ab-c1b0e6d9d1fc', num '4,0000000000', creation_time '28.07.2021 2:01:34', creation_time_utc '27.07.2021 23:01:34', type 'Normal', alg 'Increment', group_id '35ac3ebb-5811-40a6-8652-ac9c3b06e491', backup_id '9ae25045-b3d0-4ef2-a44c-208f76e08e6d'
[28.07.2021 02:02:02] <01> Info [BackupJobTarget] Creating storage alg for object 00000000-0000-0000-0000-000000000000
[28.07.2021 02:02:02] <01> Info [BackupJobTarget] Getting last storage in group: 35ac3ebb-5811-40a6-8652-ac9c3b06e491
[28.07.2021 02:02:02] <01> Info [Point] Finding previous point for '9d7588be-7671-49a5-82c2-28d2beb9beb7'
[28.07.2021 02:02:02] <01> Info [Point] Previous point for '9d7588be-7671-49a5-82c2-28d2beb9beb7' found: 'id=033b8143-388f-4cf6-a2ab-c1b0e6d9d1fc:type=Normal:alg=Increment:creation_time=09.07.2021 2:02:04:creation_time_utc=08.07.2021 23:02:04:link_id:465d4c0e-4c15-4c48-a692-e472b41c457c'
[28.07.2021 02:02:02] <01> Info [BackupJobTarget] Last storage found: EXP-SERV.rgs.kbr:WEB1D2021-07-09T020204_05F4.vib:6843ab0b-c4ac-4621-aef4-55f62ec6be28:09.07.2021 2:12:42:09.07.2021 2:02:04
[28.07.2021 02:02:02] <01> Info [RpoStorageAlg] Preparing storage for the sync interval
[28.07.2021 02:02:02] <01> Info [RpoStorageAlg] New storage type is vib
[28.07.2021 02:02:02] <01> Info [BackupHealthCheckScheduleCalculator] Previous schedule time is 26.06.2021 0:00:00
[28.07.2021 02:02:02] <01> Info [BackupHealthCheck] Storage group 00000000-0000-0000-0000-000000000000 last recheck time is 26.06.2021 0:00:01
[28.07.2021 02:02:02] <01> Info [BackupHealthCheckScheduleCalculator] Previous schedule time is 26.06.2021 0:00:00
[28.07.2021 02:02:02] <01> Info [BackupHealthCheck] Recheck already performed recently (26.06.2021 0:00:01). This could be due to the last changes in the job settings
[28.07.2021 02:02:02] <01> Info [BackupHealthCheck] Integrity check is not needed
[28.07.2021 02:02:02] <01> Info [RemoteBackupTaskBuilder] Corrupted target OIB not found
[28.07.2021 02:02:02] <01> Info [OibFinder] Searching source Oib for VM 'NL-SRV-WEB1', object 'a58a9442-b1ca-4740-8518-379dd8363b22', created on interval [Monday, January 01, 0001 00:00:00 - Friday, December 31, 9999 23:59:59]. TargetStorage: not exists
[28.07.2021 02:02:02] <01> Info [OibFinder] Searching Oibs in backup [WEB1:e5e5693f-1c1e-499d-8d5f-801ee1f77aae]
[28.07.2021 02:02:02] <01> Info [OibFinder] Found 5 Oibs
[28.07.2021 02:02:02] <01> Info [OibFinder] Using blockSize KbBlockSize1024 from VBK 7a6621c1-9dcd-4018-8d1c-3e5c761c964c (FullMode: False)
[28.07.2021 02:02:02] <01> Info [OibFinder] Following Oibs are located in storages with different (KbBlockSize1024 expected) block sizes and excluded from search:
[28.07.2021 02:02:02] <01> Info id='edd5bd59-d4e2-499e-ab1f-9fb70b99af05', time='24.07.2021 2:01:17', block_size='KbBlockSize512'
[28.07.2021 02:02:02] <01> Info id='f4342597-bbc6-46aa-8b0d-9c1142c7ea4a', time='25.07.2021 2:01:18', block_size='KbBlockSize512'
[28.07.2021 02:02:02] <01> Info id='8c9287b0-50ff-42d9-9c6b-82c34b1df4eb', time='26.07.2021 2:01:20', block_size='KbBlockSize512'
[28.07.2021 02:02:02] <01> Info id='2585e9d9-3687-46a0-8a52-065146a5c8c3', time='27.07.2021 2:01:06', block_size='KbBlockSize512'
[28.07.2021 02:02:02] <01> Info id='b28b1fcc-18d1-4999-8598-57128e846e31', time='28.07.2021 2:01:03', block_size='KbBlockSize512'
[28.07.2021 02:02:02] <01> Info Calc simple action for reason DifferentBlockSize
[28.07.2021 02:02:02] <01> Info Source oib is null. Set NoAction
[28.07.2021 02:02:02] <01> Info Source backup file has different block size. Expected block size: 1024, actual: ([backup name: WEB1, block size: 512]). ObjectId: [a58a9442-b1ca-4740-8518-379dd8363b22]
[28.07.2021 02:02:02] <01> Info [VbVmSizeCalculator] Calculated sizes for VM NL-SRV-WEB1. TotalSize: 230 GB. TotalUsedSize: 21,3 GB (from Oib b28b1fcc-18d1-4999-8598-57128e846e31)
[28.07.2021 02:02:02] <01> Info [JobSession] TotalObjects '1', totalSize '230 GB'
[28.07.2021 02:02:02] <01> Info [SourceSessionState] Current source session eacac31f-8f2b-4d1c-bcea-ebcc404dcbcd
[28.07.2021 02:02:02] <01> Info [RemoteBackupTaskBuilder] Can build task
[28.07.2021 02:02:02] <01> Info [RemoteBackupTaskBuilder] Corrupted target OIB not found
[28.07.2021 02:02:02] <01> Info Calc simple action for reason DifferentBlockSize
[28.07.2021 02:02:02] <01> Info Source oib is null. Set NoAction
[28.07.2021 02:02:02] <01> Info Action for entry a58a9442-b1ca-4740-8518-379dd8363b22 is NoOibAction, IsWaitable Unwaitable
[28.07.2021 02:02:02] <01> Info [RemoteBackupTaskBuilder] Oib usn will be updated: True, after reason: DifferentBlockSize
[28.07.2021 02:02:02] <01> Info [RemoteBackupTaskBuilder] Task list is empty
[28.07.2021 02:02:02] <01> Info [IdleStateVmController] Starting idle
[28.07.2021 02:02:02] <01> Info [RemoteTaskManager] Failing task (can't be retried). Calculated HasMoreRetries value: True
[28.07.2021 02:02:03] <01> Info Task session [70e9a845-8d08-4fab-9159-8cd0747f686d] has been completed, status: Failed, 0 of 0 bytes, 0 of 0 used bytes, 0 of 0 objects, details:
[28.07.2021 02:02:03] <01> Info Need stop state: isAnySourceOibsFound [True], isNoProcessingTasks [True], isSourceSessionFinished [True], isNoRetryableTasks [True], isNoPendingTasks [True]
[28.07.2021 02:02:03] <01> Info Not waiting for more tasks. No source oibs are available, all tasks are in pending state and source session is stopped
[28.07.2021 02:02:03] <01> Warning [RemoteBackupJobPerformer] Some tasks were not processed but no more retries left
[28.07.2021 02:02:03] <01> Info [RemoteBackupJobPerformer] No more tasks will be built
[28.07.2021 02:02:03] <01> Info [RemoteBackupJobPerformer] Waiting for tasks to complete
[28.07.2021 02:02:03] <01> Info [RemoteBackupJobPerformer] All tasks completed
[28.07.2021 02:02:03] <01> Info [BackupCopyTasksLauncher] Waiting for tasks execution thread to stop
[28.07.2021 02:02:03] <24> Info [BackupCopyTasksLauncher] Tasks launch thread has been cancelled
[28.07.2021 02:02:03] <24> Info [BackupCopyTasksLauncher] Tasks launch thread has been stopped
[28.07.2021 02:02:03] <01> Info [IntervalManager] Completing interval [Id: f0e11fd1-3ae8-4113-9446-884b167fb516, CreationTime: Wednesday, July 28, 2021 02:01:34, ExpirationTime: Wednesday, July 28, 2021 02:01:34, State: 'Active']. Setting state to 'Inactive'
[28.07.2021 02:02:03] <01> Info [BackupCopyInterval] Updating backup copy interval [Id=f0e11fd1-3ae8-4113-9446-884b167fb516, BackupId=9ae25045-b3d0-4ef2-a44c-208f76e08e6d CreationTime=28.07.2021 2:01:34, ExpirationTime=28.07.2021 2:01:34, State=Inactive, ForcedActiveFull=False]
[28.07.2021 02:02:03] <01> Info [Mutex] Created mutex [Global\BackupMeta[b2203dda-c5c2-420f-96e7-f4e1b393bbc6]]
[28.07.2021 02:02:03] <01> Info [Mutex] Acquired mutex [Global\BackupMeta[b2203dda-c5c2-420f-96e7-f4e1b393bbc6]]
[28.07.2021 02:02:03] <01> Info [FC] Loading content from file '\\fileserv\Backup\VM\VM Copy to FileServ\WEB1\WEB1.vbm'
[28.07.2021 02:02:03] <01> Info [FC] Loading content from file '\\fileserv\Backup\VM\VM Copy to FileServ\WEB1\WEB1.vbm'
[28.07.2021 02:02:03] <01> Info Backup meta version in DB 89, meta version in vbm 89
[28.07.2021 02:02:03] <01> Info [Mutex] Releasing mutex [Global\BackupMeta[b2203dda-c5c2-420f-96e7-f4e1b393bbc6]]
[28.07.2021 02:02:03] <01> Info [RpoStorageAlg] Completing storages in RPO mode
[28.07.2021 02:02:03] <01> Info Retrieving space info for repository : Id [e9fb687b-e31b-4ea6-af81-bd3fb7c320fc]
[28.07.2021 02:02:03] <01> Info [CProxyRpcInvoker] RpcInvoker [34627969] has been created. Host: [EXP-SERV:6160]
[28.07.2021 02:02:03] <19> Info [RPC] RPC confirm session has been created. Id: {2c989856-0c3c-43a5-a0e9-cce7e1783042}
[28.07.2021 02:02:03] <01> Info Physical host volume was not found for path '\\fileserv\Backup\VM' on host 'EXP-SERV'.