I set up the backup job and attachet to she 2 bat files: Pre-job and Post-job
The first one works fine, but the second one issues a timeout.
The bat files are located in C:/Script
Also i tryed to make cmd and powershell scripts, the result is always the same
I set the full rights r for everyone and separately specified full access for the systems.
I tried putting the scripts in the Veam BM&R folder but this also did not give any positive result
My Backup log also do not tell any useful info
Code: Select all
[08.12.2023 11:07:38.136] <01> Info -------------------------------------------------------------------------------------
[08.12.2023 11:07:38.136] <01> Info STARTBACKUPJOB
[08.12.2023 11:07:38.136] <01> Info owner=[vbsvc]
[08.12.2023 11:07:38.136] <01> Info Normal
[08.12.2023 11:07:38.136] <01> Info f582576d-d3fb-4797-8f60-89854c7d363a
[08.12.2023 11:07:38.136] <01> Info 7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6
[08.12.2023 11:07:38.136] <01> Info -------------------------------------------------------------------------------------
[08.12.2023 11:07:38.151] <01> Info [CJobLogsManager] Cannot find quota. JobId : f582576d-d3fb-4797-8f60-89854c7d363a.
[08.12.2023 11:07:38.230] <01> Info Starting job mode: 'Normal'.
[08.12.2023 11:07:38.230] <01> Info [Session] Id '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6', State 'Working'.
[08.12.2023 11:07:38.388] <01> Info Running pre-job script
[08.12.2023 11:07:38.388] <01> Info Executing custom command [C:\Custom_script\poweron_fatsynology.bat], arguments []
[08.12.2023 11:09:38.232] <01> Info Pre-job script completed successfully
[08.12.2023 11:09:38.563] <01> Info Start acquiring move copy mutex for f582576d-d3fb-4797-8f60-89854c7d363a
[08.12.2023 11:09:38.573] <01> Info Creating mutex Global\MoveCopyJobBackupJobSynchronization[f582576d-d3fb-4797-8f60-89854c7d363a]
[08.12.2023 11:09:38.573] <01> Info Finish acquiring move copy mutex for f582576d-d3fb-4797-8f60-89854c7d363a
[08.12.2023 11:09:38.579] <01> Info Cached target repository d95dcbc8-c541-4da5-bcfb-d87155d65971
[08.12.2023 11:09:38.863] <01> Info [StorageDrsLocker] Reg key ViDisableDRSAtTaskBuilding equals 'True'
[08.12.2023 11:09:38.863] <01> Info Job type is ignored platform restrictions: False
[08.12.2023 11:09:39.050] <01> Info IsSplitStoragesPerVm: [TruePerVmBakcupState] PerVmState: TruePerVm (JobLvl backup and all child is TruePerVm)
[08.12.2023 11:09:39.082] <01> Info [JobLease] Creating job lease keeper. Lease timeout: '01:00:00', update timeout '60'
[08.12.2023 11:09:39.144] <01> Info [LeaseKeeper] Created. LeaseId: 9e8cdfd6-3d89-412b-99aa-b05d5ffd1a10, TTL: [60 sec], ignoreExceptions: [False].
[08.12.2023 11:09:39.300] <01> Info -------------------------------------------------------------------------------------
[08.12.2023 11:09:39.300] <01> Info Job ID: [f582576d-d3fb-4797-8f60-89854c7d363a]
[08.12.2023 11:09:39.300] <01> Info Job Name: [Тестовый на 9.13]
[08.12.2023 11:09:39.300] <01> Info Job Mode: [Normal]
[08.12.2023 11:09:39.300] <01> Info Job Type: [VDDK Backup]
[08.12.2023 11:09:39.300] <01> Info Job Target Type: [Other]
[08.12.2023 11:09:39.300] <01> Info Job Options: [<JobOptionsRoot><RunManually>True</RunManually><GroupSnapshotProcessing>True</GroupSnapshotProcessing><RetentionType>1</RetentionType><SourceProxyAutoDetect>True</SourceProxyAutoDetect><TargetProxyAutoDetect>True</TargetProxyAutoDetect><StgBlockSize>KbBlockSize1024</StgBlockSize><EnableDeduplication>True</EnableDeduplication><CompressionLevel>5</CompressionLevel><StorageEncryptionEnabled>False</StorageEncryptionEnabled><SetResultsToVmNotes>False</SetResultsToVmNotes><VmAttributeName>Notes</VmAttributeName><VmNotesAppend>True</VmNotesAppend><ExcludeSwapFile>True</ExcludeSwapFile><DirtyBlocksNullingEnabled>True</DirtyBlocksNullingEnabled><VMToolsQuiesce>False</VMToolsQuiesce><UseChangeTracking>True</UseChangeTracking><EnableChangeTracking>True</EnableChangeTracking><ResetChangeTrackingOnActiveFull>True</ResetChangeTrackingOnActiveFull><Algorithm>Increment</Algorithm><EnableFullBackup>False</EnableFullBackup><FullBackupScheduleKind>Daily</FullBackupScheduleKind><FullBackupMonthlyScheduleOptions><DayNumberInMonth>First</DayNumberInMonth><DayOfWeek>Monday</DayOfWeek><DayOfMonth>1</DayOfMonth><Months><EMonth>January</EMonth><EMonth>February</EMonth><EMonth>March</EMonth><EMonth>April</EMonth><EMonth>May</EMonth><EMonth>June</EMonth><EMonth>July</EMonth><EMonth>August</EMonth><EMonth>September</EMonth><EMonth>October</EMonth><EMonth>November</EMonth><EMonth>December</EMonth></Months></FullBackupMonthlyScheduleOptions><TransformFullToSyntethic>True</TransformFullToSyntethic><TransformToSyntethicKind>Daily</TransformToSyntethicKind><TransformToSyntethicMonthlyScheduleOptions><DayNumberInMonth>First</DayNumberInMonth><DayOfWeek>Monday</DayOfWeek><DayOfMonth>1</DayOfMonth><Months><EMonth>January</EMonth><EMonth>February</EMonth><EMonth>March</EMonth><EMonth>April</EMonth><EMonth>May</EMonth><EMonth>June</EMonth><EMonth>July</EMonth><EMonth>August</EMonth><EMonth>September</EMonth><EMonth>October</EMonth><EMonth>November</EMonth><EMonth>December</EMonth></Months></TransformToSyntethicMonthlyScheduleOptions><TransformIncrementsToSyntethic>False</TransformIncrementsToSyntethic><SnmpNotification>False</SnmpNotification><EmailNotification>False</EmailNotification><EmailNotificationAddresses></EmailNotificationAddresses><UseCustomEmailNotificationOptions>False</UseCustomEmailNotificationOptions><EmailNotifyOnceADay>False</EmailNotifyOnceADay><EmailNotifyTime>07/18/2023 22:00:00</EmailNotifyTime><EmailNotificationSubject>[%JobResult%] %JobName% (%ObjectCount% objects) %Issues%</EmailNotificationSubject><EmailNotifyOnSuccess>True</EmailNotifyOnSuccess><EmailNotifyOnWarning>True</EmailNotifyOnWarning><EmailNotifyOnError>True</EmailNotifyOnError><EmailNotifyOnLastRetryOnly>True</EmailNotifyOnLastRetryOnly><EmailNotifyOnWaitingTape>True</EmailNotifyOnWaitingTape><UseSanSnapshots>True</UseSanSnapshots><MultipleStorageSnapshotEnabled>False</MultipleStorageSnapshotEnabled><MultipleStorageSnapshotVmsCount>10</MultipleStorageSnapshotVmsCount><FailoverFromSan>False</FailoverFromSan><Failover2StorageSnapshotBackup>False</Failover2StorageSnapshotBackup><PostJobCommand><Periodicity>Cycles</Periodicity><PreScriptEnabled>True</PreScriptEnabled><PreScriptCommandLine>C:\Custom_script\poweron_fatsynology.bat</PreScriptCommandLine><Frequency>1</Frequency><Enabled>True</Enabled><CommandLine>C:\Custom_script\poweroff_fatsynology.cmd</CommandLine><Days><Day>Saturday</Day></Days></PostJobCommand><GenerationPolicy><EnableRecheck>False</EnableRecheck><EnableSimpleObjectStorageRecheck>False</EnableSimpleObjectStorageRecheck><RecheckScheduleKind>Monthly</RecheckScheduleKind><RecheckMonthlyScheduleOptions><DayNumberInMonth>Last</DayNumberInMonth><DayOfWeek>Friday</DayOfWeek><DayOfMonth>1</DayOfMonth><Months><EMonth>January</EMonth><EMonth>February</EMonth><EMonth>March</EMonth><EMonth>April</EMonth><EMonth>May</EMonth><EMonth>June</EMonth><EMonth>July</EMonth><EMonth>August</EMonth><EMonth>September</EMonth><EMonth>October</EMonth><EMonth>November</EMonth><EMonth>December</EMonth></Months></RecheckMonthlyScheduleOptions><RecheckTime>22:00:00</RecheckTime><EnableCompactFull>False</EnableCompactFull><EnableCompactFullLastTime /><CompactFullBackupScheduleKind>Monthly</CompactFullBackupScheduleKind><CompactMonthlyScheduleOptions><DayNumberInMonth>Last</DayNumberInMonth><DayOfWeek>Saturday</DayOfWeek><DayOfMonth>1</DayOfMonth><Months><EMonth>January</EMonth><EMonth>February</EMonth><EMonth>March</EMonth><EMonth>April</EMonth><EMonth>May</EMonth><EMonth>June</EMonth><EMonth>July</EMonth><EMonth>August</EMonth><EMonth>September</EMonth><EMonth>October</EMonth><EMonth>November</EMonth><EMonth>December</EMonth></Months></CompactMonthlyScheduleOptions><DeletionGuardDays>21</DeletionGuardDays><UseDeletionGuardDays>True</UseDeletionGuardDays><RecheckDays><DayOfWeek>Friday</DayOfWeek></RecheckDays><CompactFullBackupDays><DayOfWeek>Saturday</DayOfWeek></CompactFullBackupDays></GenerationPolicy><EnableDeletedVmDataRetention>False</EnableDeletedVmDataRetention><RetainDays>14</RetainDays><RetainDaysToKeep>7</RetainDaysToKeep><BackupIsAttached>False</BackupIsAttached><Templates>True</Templates><TemplatesOnce>True</TemplatesOnce><GfsPolicy IsEnabled="False"><Weekly IsEnabled="False" KeepBackupsForNumberOfWeeks="1" DesiredTime="0" /><Monthly IsEnabled="False" KeepBackupsForNumberOfMonths="1" DesiredTime="1" /><Yearly IsEnabled="False" KeepBackupsForNumberOfYears="1" DesiredTime="1" /></GfsPolicy><FullBackupDays><DayOfWeek>Saturday</DayOfWeek></FullBackupDays><TransformToSyntethicDays><DayOfWeek>Saturday</DayOfWeek></TransformToSyntethicDays></JobOptionsRoot>]
[08.12.2023 11:09:39.316] <01> Info Job VSS Settings: [VssSnapshotOptions: [Enabled: [False], ApplicationProcessingEnabled: [True], IgnoreErrors: [False], IsCopyOnly: [False], UsePersistentGuestAgent: [False]], WinGuestFSIndexingOptions: [Type: [None]], LinGuestFSIndexingOptions: [Type: [None]], SqlBackupOptions: [TransactionLogsProcessing: [TruncateOnlyOnSuccessJob], BackupLogsFrequencyMin: [15], UseDbBackupRetention: [True], RetainDays: [15], ProxyAutoSelect: [True]FailJobOnDbAbsenceOrBackupImpossibility: [False]], ExchangeBackupOptions: [TransactionLogsProcessing: [TruncateOnlyOnSuccessJob]], WinCredsId: [00000000-0000-0000-0000-000000000000], LinCredsId: [00000000-0000-0000-0000-000000000000], Old Properties: [Enabled: [False], IgnoreErrors: [False], GuestFSIndexingType: [None], IncludedIndexingFolders: [], ExcludedIndexingFolders: [], LinGuestFSIndexingType: [None], LinIncludedIndexingFolders: [], LinExcludedIndexingFolders: [], IsFirstUsage: [True]]]
[08.12.2023 11:09:39.331] <01> Info Job ScheduleOptions: [Start time: [08.12.2023 22:00:00], Latest run time: [20.07.2023 10:31:38], Timeout for backup completion: [180min], Next run time: [], Retry times on failure: [3], Retry timeout: [10 min], Daily options: [Enabled: True, DayNumberInMonth: Everyday, Days: Monday, Tuesday, Wednesday, Thursday, Friday, Saturday, Sunday]]
[08.12.2023 11:09:39.363] <01> Info Job AutoScheduleOptions: [<AutoScheduleOptions PerformActiveFullBackup="False" ActiveFullBackupKind="0" ActiveFullBackupDays="Saturday;" PerformTransformToSyntethic="True" TransformToSyntethicKind="0" TransformToSyntethicDays="Saturday;"><ActiveFullBackupMonthlyOption><DayNumberInMonth>First</DayNumberInMonth><DayOfWeek>Monday</DayOfWeek><DayOfMonth>1</DayOfMonth><Months><EMonth>January</EMonth><EMonth>February</EMonth><EMonth>March</EMonth><EMonth>April</EMonth><EMonth>May</EMonth><EMonth>June</EMonth><EMonth>July</EMonth><EMonth>August</EMonth><EMonth>September</EMonth><EMonth>October</EMonth><EMonth>November</EMonth><EMonth>December</EMonth></Months></ActiveFullBackupMonthlyOption><TransformToSyntethicMonthlyOption><DayNumberInMonth>First</DayNumberInMonth><DayOfWeek>Monday</DayOfWeek><DayOfMonth>1</DayOfMonth><Months><EMonth>January</EMonth><EMonth>February</EMonth><EMonth>March</EMonth><EMonth>April</EMonth><EMonth>May</EMonth><EMonth>June</EMonth><EMonth>July</EMonth><EMonth>August</EMonth><EMonth>September</EMonth><EMonth>October</EMonth><EMonth>November</EMonth><EMonth>December</EMonth></Months></TransformToSyntethicMonthlyOption></AutoScheduleOptions>]
[08.12.2023 11:09:39.363] <01> Info Enable parallel processing checkbox is on
[08.12.2023 11:09:39.363] <01> Info Session parameters: NGY5NTEgPyBWQlIgPyAzYzcy
[08.12.2023 11:09:39.395] <01> Info Object in job: [Id: [8865779d-8630-4d91-9f08-1afc15b33c9b], ObjectId: [dac044f4-cb6b-4295-87ca-aae8eb938f9c], JobId: [f582576d-d3fb-4797-8f60-89854c7d363a]FolderId: [00000000-0000-0000-0000-000000000000]
[08.12.2023 11:09:39.395] <01> Info Location: [192.168.10.3\CEPP Datacenter\CEPP cluster\#syspass], Type: [Include], ApproxSize: [3878682624]
[08.12.2023 11:09:39.395] <01> Info VssOptions: [VssSnapshotOptions: [Enabled: [True], ApplicationProcessingEnabled: [True], IgnoreErrors: [False], IsCopyOnly: [False], UsePersistentGuestAgent: [False]], WinGuestFSIndexingOptions: [Type: [ExceptSpecifiedFolders], IncludedFolders: [], ExcludedFolders: [%windir%; %ProgramFiles%; %ProgramFiles(x86)%; %ProgramW6432%; %TEMP%]], LinGuestFSIndexingOptions: [Type: [ExceptSpecifiedFolders], IncludedFolders: [], ExcludedFolders: [/cdrom; /dev; /media; /mnt; /proc; /tmp; /lost+found]], SqlBackupOptions: [TransactionLogsProcessing: [TruncateOnlyOnSuccessJob], BackupLogsFrequencyMin: [15], UseDbBackupRetention: [True], RetainDays: [15], ProxyAutoSelect: [True]FailJobOnDbAbsenceOrBackupImpossibility: [False]], ExchangeBackupOptions: [TransactionLogsProcessing: [TruncateOnlyOnSuccessJob]], WinCredsId: [00000000-0000-0000-0000-000000000000], LinCredsId: [00000000-0000-0000-0000-000000000000], Old Properties: [Enabled: [True], IgnoreErrors: [False], GuestFSIndexingType: [ExceptSpecifiedFolders], IncludedIndexingFolders: [], ExcludedIndexingFolders: [%windir%; %ProgramFiles%; %ProgramFiles(x86)%; %ProgramW6432%; %TEMP%], LinGuestFSIndexingType: [ExceptSpecifiedFolders], LinIncludedIndexingFolders: [], LinExcludedIndexingFolders: [/cdrom; /dev; /media; /mnt; /proc; /tmp; /lost+found], IsFirstUsage: [True]]],
[08.12.2023 11:09:39.395] <01> Info Platform: [EVmware], UpdateVmx: [True]
[08.12.2023 11:09:39.395] <01> Info DiskFilter: [<DiskFilterInfo><Mode>0</Mode></DiskFilterInfo>], ]
[08.12.2023 11:09:39.410] <01> Info [CRepositoryAccessorFactory] CheckMaintanceMode, repository ID d95dcbc8-c541-4da5-bcfb-d87155d65971, baseSession ID [7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6], cloudConnectionHolder is provided: False
[08.12.2023 11:09:39.410] <01> Info called from Veeam.Backup.Core.CPerVmBackupJobPerformer.CreateRepositoryAccessor
[08.12.2023 11:09:39.417] <01> Info [CRepositoryAccessorFactory] Creating CBackupRepositoryAccessorImpl with sharedAgentSpec.IsEmpty = True
[08.12.2023 11:09:39.426] <01> Info [CRepositoryAccessor] ctr, impl type [Veeam.Backup.Core.CBackupRepositoryAccessorImpl], repository ID d95dcbc8-c541-4da5-bcfb-d87155d65971
[08.12.2023 11:09:39.458] <01> Info [from CPolicyBackupEncryptionEnabledProvider] JobId=f582576d-d3fb-4797-8f60-89854c7d363a, JobName=Тестовый на 9.13, JobType=Backup (None of the conditions are met)
[08.12.2023 11:09:39.479] <01> Info [SharedAgentManager] Initializing shared repository client for repository 'Большой раздел на толстой помойке'.
[08.12.2023 11:09:39.479] <01> Info [SplitStoragesPerVmAgentManager] Initializing SplitStoragePerVM repository client for repository 'Большой раздел на толстой помойке'.
[08.12.2023 11:09:39.521] <01> Info Found existing backup, backup id '099c4a3b-fec8-4f9f-ab0d-1c0bba71234d'.
[08.12.2023 11:09:39.521] <01> Info [from CPolicyBackupEncryptionEnabledProvider] JobId=f582576d-d3fb-4797-8f60-89854c7d363a, JobName=Тестовый на 9.13, JobType=Backup (None of the conditions are met)
[08.12.2023 11:09:39.553] <01> Info [PolicyBackupEncryptedStateUpdater] Initializing backup encryption state (BackupId='099c4a3b-fec8-4f9f-ab0d-1c0bba71234d', IsEncryptionEnabled=False, EncryptionState=Unencrypted, ChildStates='Unencrypted')
[08.12.2023 11:09:39.584] <01> Info [CStorageCommanderFactoryImpl] Create storage commander for repository [id=d95dcbc8-c541-4da5-bcfb-d87155d65971:name=Большой раздел на толстой помойке:host_id=00000000-0000-0000-0000-000000000000:mount_host_id=6745a759-2205-4cd2-b172-8ec8f7e60ef8:path=\\192.168.9.13|veeambackup:useNfsOnMountHost=True:typeCifsShare]
[08.12.2023 11:09:39.667] <01> Info [SPerVmBackupJobPipelineFactory] Using channel task preparation pipeline.
[08.12.2023 11:09:39.823] <01> Info [VmListBuilder] Starting hierarchy cache fill
[08.12.2023 11:09:39.852] <01> Info Registering TCP client channel [bs2brs].
[08.12.2023 11:09:39.852] <01> Info tokenImpersonationLevel: [Impersonation].
[08.12.2023 11:09:39.868] <01> Info Checking compatibility between client and server (Client='12.0.0.1420', Server='12.0.0.1420', Components=2)
[08.12.2023 11:09:41.636] <01> Info [ViHierarchyLoader|Broker (594e8ef7-b95e-4a99-9940-ff4e2ad969f6)] Old session id is 00000000-0000-0000-0000-000000000000, new is b0001b97-6a45-4586-a55b-17464b86996e, hierarchy will be loaded in full mode
[08.12.2023 11:09:41.809] <01> Info [Hierarchy (594e8ef7-b95e-4a99-9940-ff4e2ad969f6)] Loaded 149 elements
[08.12.2023 11:09:41.951] <01> Info [Hierarchy (594e8ef7-b95e-4a99-9940-ff4e2ad969f6)] Loaded 149 elements
[08.12.2023 11:09:42.042] <01> Info [VmListBuilder] Finished hierarchy cache fill: 1 hierarchies loaded
[08.12.2023 11:09:42.109] <01> Info Got '0' VSS child objects. Sorting them.
[08.12.2023 11:09:42.323] <01> Info Container 'Hierarchy object "#syspass". Host: "192.168.10.3". Reference: "vm-94". Type: "VirtualMachine". Name: "VirtualMachine".' depth 1000
[08.12.2023 11:09:42.323] <01> Info Loading their content.
[08.12.2023 11:09:42.408] <01> Info Getting child VMs for the object Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3.
[08.12.2023 11:09:42.408] <01> Info VM name: #syspass, VM ref: vm-94, VM host name: 192.168.10.9, source host name: 192.168.10.3, source host id : 594e8ef7-b95e-4a99-9940-ff4e2ad969f6, source host is VC: True
[08.12.2023 11:09:42.408] <01> Info Got '0' FS Indexing child objects. Sorting them.
[08.12.2023 11:09:42.417] <01> Info Container 'Hierarchy object "#syspass". Host: "192.168.10.3". Reference: "vm-94". Type: "VirtualMachine". Name: "VirtualMachine".' depth 1000
[08.12.2023 11:09:42.417] <01> Info Loading their content.
[08.12.2023 11:09:42.424] <01> Info Getting child VMs for the object Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3.
[08.12.2023 11:09:42.424] <01> Info Skipped logging of 1 VMs. See log above for details
[08.12.2023 11:09:42.424] <01> Info Got '0' FS Exclude child objects. Sorting them.
[08.12.2023 11:09:42.424] <01> Info Container 'Hierarchy object "#syspass". Host: "192.168.10.3". Reference: "vm-94". Type: "VirtualMachine". Name: "VirtualMachine".' depth 1000
[08.12.2023 11:09:42.424] <01> Info Loading their content.
[08.12.2023 11:09:42.424] <01> Info Getting child VMs for the object Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3.
[08.12.2023 11:09:42.424] <01> Info Skipped logging of 1 VMs. See log above for details
[08.12.2023 11:09:42.424] <01> Info Got '0' guest creds child objects. Sorting them.
[08.12.2023 11:09:42.440] <01> Info Container 'Hierarchy object "#syspass". Host: "192.168.10.3". Reference: "vm-94". Type: "VirtualMachine". Name: "VirtualMachine".' depth 1000
[08.12.2023 11:09:42.440] <01> Info Loading their content.
[08.12.2023 11:09:42.440] <01> Info Getting child VMs for the object Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3.
[08.12.2023 11:09:42.440] <01> Info Skipped logging of 1 VMs. See log above for details
[08.12.2023 11:09:42.440] <01> Info Got '0' exclude disks child objects. Sorting them.
[08.12.2023 11:09:42.448] <01> Info Container 'Hierarchy object "#syspass". Host: "192.168.10.3". Reference: "vm-94". Type: "VirtualMachine". Name: "VirtualMachine".' depth 1000
[08.12.2023 11:09:42.448] <01> Info Loading their content.
[08.12.2023 11:09:42.448] <01> Info Getting child VMs for the object Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3.
[08.12.2023 11:09:42.448] <01> Info Skipped logging of 1 VMs. See log above for details
[08.12.2023 11:09:42.448] <01> Info Got '0' extended objects. Sorting them.
[08.12.2023 11:09:42.456] <01> Info Container 'Hierarchy object "#syspass". Host: "192.168.10.3". Reference: "vm-94". Type: "VirtualMachine". Name: "VirtualMachine".' depth 1000
[08.12.2023 11:09:42.456] <01> Info Loading their content.
[08.12.2023 11:09:42.456] <01> Info Getting child VMs for the object Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3.
[08.12.2023 11:09:42.456] <01> Info Skipped logging of 1 VMs. See log above for details
[08.12.2023 11:09:42.456] <01> Info Got 0 excluded objects
[08.12.2023 11:09:42.479] <01> Info
[08.12.2023 11:09:42.479] <01> Info Got 1 included objects
[08.12.2023 11:09:42.479] <01> Info [Id: [8865779d-8630-4d91-9f08-1afc15b33c9b], ObjectId: [dac044f4-cb6b-4295-87ca-aae8eb938f9c], JobId: [f582576d-d3fb-4797-8f60-89854c7d363a]FolderId: [00000000-0000-0000-0000-000000000000]
[08.12.2023 11:09:42.479] <01> Info Location: [192.168.10.3\CEPP Datacenter\CEPP cluster\#syspass], Type: [Include], ApproxSize: [3878682624]
[08.12.2023 11:09:42.479] <01> Info VssOptions: [VssSnapshotOptions: [Enabled: [True], ApplicationProcessingEnabled: [True], IgnoreErrors: [False], IsCopyOnly: [False], UsePersistentGuestAgent: [False]], WinGuestFSIndexingOptions: [Type: [ExceptSpecifiedFolders], IncludedFolders: [], ExcludedFolders: [%windir%; %ProgramFiles%; %ProgramFiles(x86)%; %ProgramW6432%; %TEMP%]], LinGuestFSIndexingOptions: [Type: [ExceptSpecifiedFolders], IncludedFolders: [], ExcludedFolders: [/cdrom; /dev; /media; /mnt; /proc; /tmp; /lost+found]], SqlBackupOptions: [TransactionLogsProcessing: [TruncateOnlyOnSuccessJob], BackupLogsFrequencyMin: [15], UseDbBackupRetention: [True], RetainDays: [15], ProxyAutoSelect: [True]FailJobOnDbAbsenceOrBackupImpossibility: [False]], ExchangeBackupOptions: [TransactionLogsProcessing: [TruncateOnlyOnSuccessJob]], WinCredsId: [00000000-0000-0000-0000-000000000000], LinCredsId: [00000000-0000-0000-0000-000000000000], Old Properties: [Enabled: [True], IgnoreErrors: [False], GuestFSIndexingType: [ExceptSpecifiedFolders], IncludedIndexingFolders: [], ExcludedIndexingFolders: [%windir%; %ProgramFiles%; %ProgramFiles(x86)%; %ProgramW6432%; %TEMP%], LinGuestFSIndexingType: [ExceptSpecifiedFolders], LinIncludedIndexingFolders: [], LinExcludedIndexingFolders: [/cdrom; /dev; /media; /mnt; /proc; /tmp; /lost+found], IsFirstUsage: [True]]],
[08.12.2023 11:09:42.479] <01> Info Platform: [EVmware], UpdateVmx: [True]
[08.12.2023 11:09:42.479] <01> Info DiskFilter: [<DiskFilterInfo><Mode>0</Mode></DiskFilterInfo>], ]
[08.12.2023 11:09:42.479] <01> Info VM name: #syspass, VM ref: vm-94, VM host name: 192.168.10.9, source host name: 192.168.10.3, source host id : 594e8ef7-b95e-4a99-9940-ff4e2ad969f6, source host is VC: True
[08.12.2023 11:09:42.511] <01> Info Got 1 processing entries
[08.12.2023 11:09:42.519] <01> Info [VM name: '#syspass', Host name: '192.168.10.3' Source job ids: []]
[08.12.2023 11:09:42.519] <01> Info Allowed repositories: All
[08.12.2023 11:09:42.542] <01> Info [DbScope] Finding SAN Feature By Job. JobId: 'f582576d-d3fb-4797-8f60-89854c7d363a'
[08.12.2023 11:09:42.836] <01> Info [ViStorageIntegrationVmPreparer] Prepare SAN availability information for VMs
[08.12.2023 11:09:42.852] <01> Info [ViTaskBuilder] Prepare SAN availability information for VM: '#syspass'
[08.12.2023 11:09:42.854] <01> Info [ViVmStorageIntegrationChecker] Detecting storage snapshot compatibility for datastores on '#syspass' VM
[08.12.2023 11:09:42.885] <01> Info [VirtualMachine] Obtaining list of datastores that the next snapshot will use
[08.12.2023 11:09:42.899] <01> Info [VirtualMachine] Snapshot directory was not specified or equals VMX directory
[08.12.2023 11:09:42.899] <01> Info [VirtualMachine] Considering all datastores on which VM's disks are located as snapshot holder datastores
[08.12.2023 11:09:42.899] <01> Info [ViVmStorageIntegrationChecker] Checking storage snapshot compatibility for 'SFP-2' datastore.
[08.12.2023 11:09:42.930] <01> Info [DatastoreSANInfo] Datastore 'SFP-2' ('datastore-20') LUNs and NFS information from '192.168.10.3', '594e8ef7-b95e-4a99-9940-ff4e2ad969f6'.
[08.12.2023 11:09:42.930] <01> Info iSCSI LUN: 'DisplayName: 'HP iSCSI Disk (naa.600c0ff0003b6bd6ef31c65a01000000)', CanonicalName: 'naa.600c0ff0003b6bd6ef31c65a01000000', ScsiLunUuid: '0200000000600c0ff0003b6bd6ef31c65a010000004d5341203230'HBAMapping: 'HBAIqn: 'iqn.1998-01.com.vmware:esxi-1-76198561'iSCSIPath: 'IQN: 'iqn.1986-03.com.hp:storage.msa2040.17423b365a', LunId: '0'', iSCSIPath: 'IQN: 'iqn.1986-03.com.hp:storage.msa2040.17423b365a', LunId: '0'', ', '
[08.12.2023 11:09:42.930] <01> Info [ViVmStorageIntegrationChecker] Datastore 'SFP-2', 'datastore-20' storage information from DB:
[08.12.2023 11:09:42.948] <01> Info Can't find LUN in database for iSCSI extent 'HP iSCSI Disk (naa.600c0ff0003b6bd6ef31c65a01000000)', 'naa.600c0ff0003b6bd6ef31c65a01000000'
[08.12.2023 11:09:42.948] <01> Info [ViVmStorageIntegrationChecker] Can't find datastore LUNs or information in Backup Infrastructure for 'SFP-2' datastore.
[08.12.2023 11:09:42.948] <01> Info [ViVmStorageIntegrationChecker] '#syspass' VM is not storage snapshot compatible.
[08.12.2023 11:09:42.948] <01> Info [ViTaskBuilder] Building datastore candidate information for VM: '#syspass'
[08.12.2023 11:09:42.979] <01> Info Dispose CSanLUNOrNFSVolumesSearcher
[08.12.2023 11:09:42.994] <01> Info [ViTaskBuilder] Update VM backup from snapshot transfer status
[08.12.2023 11:09:42.994] <01> Info [ViVmFilter] Filtering vms, selective processing spec is set: 'False'
[08.12.2023 11:09:43.057] <01> Info [ViTaskBuilder] Creating task for Vm '#syspass', object: 'dac044f4-cb6b-4295-87ca-aae8eb938f9c'
[08.12.2023 11:09:43.260] <01> Info Simple query 'InsertWithIncrementUsn' to table [dbo].[Backup.Model.BackupTaskSessions] [?@id: 82bfc8af-234f-41ac-9dd3-60ee7ade8d47, @session_id: 7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6, @parent_task_session_id: 00000000-0000-0000-0000-000000000000, @creation_time: 08.12.2023 11:09:43, @object_name: #syspass, @status: 6, @reason: , @object_id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, @end_time: 01.01.1900 0:00:00, @operation: , @progress: 0, @total_objects: 0, @processed_objects: 0, @total_size: 0, @total_used_size: 0, @processed_size: 0, @processed_used_size: 0, @mode: 0, @avg_speed: 0, @change_tracking: False, @read_size: 0, @read_average_size: 0, @stored_size: 0, @queued_time: 08.12.2023 11:09:43, @work_details: <?xml version="1.0"?><details GuestIndexingComplete="False" ContainsSynthesizedStorages="False" IsLatencyThrottlingEnabled="False"><TaskAlgorithm>0</TaskAlgorithm><EpPolicyDetails><EpPolicySessionDetails ConfigSent="False" /></EpPolicyDetails><TransformDetails><CTransformSessionDetails p1:Version="1" xmlns:p1="vxs">
[08.12.2023 11:09:43.260] <01> Info <_transformedOibStates p1:Count="0" />
[08.12.2023 11:09:43.260] <01> Info </CTransformSessionDetails></TransformDetails></details>, @object_platform: 0, @object_platform_id: 00000000-0000-0000-0000-000000000000, @tooltip: , @logs_folder: , @is_full: False, @advanced_stat: , @supports_backup_commands: True] executed.
[08.12.2023 11:09:43.323] <01> Info [ViTaskBuilder] Task session '82bfc8af-234f-41ac-9dd3-60ee7ade8d47' created for Vm '#syspass'
[08.12.2023 11:09:43.323] <01> Info Task total size: 64 GB. Task total used size: 7,7 GB
[08.12.2023 11:09:43.338] <01> Info Task progress: '0%', '0' of '68,719,476,736' bytes, '0' of '8,282,419,355' used bytes, object '0' of '0', totals calculated: No
[08.12.2023 11:09:43.354] <01> Info Cached target repository d95dcbc8-c541-4da5-bcfb-d87155d65971
[08.12.2023 11:09:43.416] <01> Info [Crypto] Encrypted DB entities will be saved
[08.12.2023 11:09:43.416] <01> Info [ViInitialSeedingTaskCreator] Skipping initial seeding task creation
[08.12.2023 11:09:43.479] <01> Info [ViProxyBuilder] Vm '#syspass', '594e8ef7-b95e-4a99-9940-ff4e2ad969f6 vm-94' from host '192.168.10.3' disks LUNs information:
[08.12.2023 11:09:43.479] <01> Info VmId '594e8ef7-b95e-4a99-9940-ff4e2ad969f6 vm-94', DiskKey '2000', LunIds ''
[08.12.2023 11:09:43.479] <01> Info [ViVmStorageIntegrationChecker] Detecting DirectNFS compatibility for backup '#syspass' VM
[08.12.2023 11:09:43.495] <01> Info [ViVmStorageIntegrationChecker] Backup VM '#syspass' is DirectNFS compatible.
[08.12.2023 11:09:43.558] <01> Info [ProxyDetector] VMware host API version is V672. Skipping not x64 proxies
[08.12.2023 11:09:43.604] <01> Info [ProxyDetector] Trying to detect source proxy modes for VM [#syspass], has snapshots:False, direct SAN allowed:True, disk types:[Scsi: True, Sata: False, Ide: False, Nvme: False]
[08.12.2023 11:09:43.620] <01> Info [ProxyDetector] Host storage 'VMware ESXi 6.7.0 build-13006603' has 9 luns
[08.12.2023 11:09:43.620] <01> Info [ProxyDetector] Searching for VMFS LUN and volumes of the following datastores: ['SFP-2']
[08.12.2023 11:09:43.620] <01> Info [ProxyDetector] Datastore 'SFP-2' lun was found, it uses vmfs
[08.12.2023 11:09:43.620] <01> Info [ProxyDetector] VMFS LUNs: ['HP iSCSI Disk (naa.600c0ff0003b6bd6ef31c65a01000000)'], NAS volumes: <no>
[08.12.2023 11:09:43.982] <01> Info [ProxyDetector] Proxy [VMware Backup Proxy]: Detecting san access level
[08.12.2023 11:09:44.013] <01> Info [ProxyDetector] Proxy [VMware Backup Proxy]: disks ['6000C294A138070A0CE7F9983F62510D566972747561']
[08.12.2023 11:09:44.013] <01> Info [ProxyDetector] Proxy [VMware Backup Proxy]: No disks are accessible through san but can failover to network
[08.12.2023 11:09:44.060] <01> Info [ProxyDetector] Detecting hotadd access level
[08.12.2023 11:09:44.060] <01> Info [ProxyDetector] Detected all suitable ESXs (where vm's datastores are mounted): host-11,host-14
[08.12.2023 11:09:44.092] <01> Info [ViProxyVmSearcher] VM Veeam B&R 12(vm-11051) has the same bios uuid as proxy vbr in the DB and located on host 192.168.10.9(host-14)
[08.12.2023 11:09:44.092] <01> Info [ProxyDetector] Found proxy is on suitable ESX: 'vm-11051'. All disk can be processed through hotadd
[08.12.2023 11:09:44.092] <01> Info [ProxyDetector] Detected hotadd storage access level for proxy [VMware Backup Proxy] - [HotAddDifferentHosts]
[08.12.2023 11:09:44.107] <01> Info [ProxyDetector] Detected mode [hotadd;nbd] for proxy [VMware Backup Proxy]
[08.12.2023 11:09:44.185] <01> Info [ProxyDetector] 1 detected.
[08.12.2023 11:09:44.248] <01> Info [VirtualMachine] Obtaining list of datastores that the next snapshot will use
[08.12.2023 11:09:44.248] <01> Info [VirtualMachine] Snapshot directory was not specified or equals VMX directory
[08.12.2023 11:09:44.248] <01> Info [VirtualMachine] Considering all datastores on which VM's disks are located as snapshot holder datastores
[08.12.2023 11:09:44.310] <01> Info Task total size: 64 GB. Task total used size: 3,6 GB
[08.12.2023 11:09:44.310] <01> Info Task progress: '0%', '0' of '68,719,476,736' bytes, '0' of '3,878,682,624' used bytes, object '0' of '0', totals calculated: No
[08.12.2023 11:09:44.310] <01> Info VM task VM name: '#syspass', VM host name: '192.168.10.9', VM host info: 'VMware ESXi 6.7.0 build-13006603', VM host apiVersion: '6.7.2', source host name: '192.168.10.3', source host id: '594e8ef7-b95e-4a99-9940-ff4e2ad969f6', source host type: 'VC', size: '68719476736', display name: '#syspass'.
[08.12.2023 11:09:44.310] <01> Info [ViTaskBuilder] Vm task created, id: '7a950a80-ecbd-4e09-8a5a-2a4d91b328ac'
[08.12.2023 11:09:44.310] <01> Info VSS options derived from 'Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3', disk exclusion: 'Object, id: dac044f4-cb6b-4295-87ca-aae8eb938f9c, name: #syspass, type: VM, vi type: VirtualMachine, host name: 192.168.10.3'.
[08.12.2023 11:09:44.342] <01> Info Licensing hosts from all backup tasks
[08.12.2023 11:09:44.404] <01> Info [JIT] Warming up JIT of VimApi.XmlSerializers.dll
[08.12.2023 11:09:44.624] <01> Warning [JIT] Warmed up 3985 methods in 00:00:00.2010399
[08.12.2023 11:09:44.624] <01> Info [Soap] Outgoing connection [CSoapConnectionKeyInfo]
[08.12.2023 11:09:44.624] <01> Info HostNameOrIpAddress: '192.168.10.3'
[08.12.2023 11:09:44.624] <01> Info Port: '443'
[08.12.2023 11:09:44.624] <01> Info UserName: 'administrator@vcenter.local'
[08.12.2023 11:09:44.624] <01> Info UseProxy: 'False'
[08.12.2023 11:09:44.624] <01> Info ProxyHostNameOrIpAddress: ''
[08.12.2023 11:09:44.624] <01> Info ProxyPort: '0'
[08.12.2023 11:09:44.624] <01> Info ManagedThreadId: '1'
[08.12.2023 11:09:44.624] <01> Info [Soap] Creating new connection [CSoapConnectionKeyInfo]
[08.12.2023 11:09:44.624] <01> Info HostNameOrIpAddress: '192.168.10.3'
[08.12.2023 11:09:44.624] <01> Info Port: '443'
[08.12.2023 11:09:44.624] <01> Info UserName: 'administrator@vcenter.local'
[08.12.2023 11:09:44.624] <01> Info UseProxy: 'False'
[08.12.2023 11:09:44.624] <01> Info ProxyHostNameOrIpAddress: ''
[08.12.2023 11:09:44.624] <01> Info ProxyPort: '0'
[08.12.2023 11:09:44.624] <01> Info ManagedThreadId: '1'
[08.12.2023 11:09:44.640] <01> Info [Soap] CClientConfig trying to download xml from 'https://192.168.10.3:443/client/clients.xml'.
[08.12.2023 11:09:44.760] <01> Info [Soap] Logging on to "192.168.10.3", port 443, user "administrator@vcenter.local", proxy srv: port:0, serviceType: public, timeout: 200000 ms
[08.12.2023 11:09:45.773] <01> Info RetrieveServiceContent for api version: 2.0.0
[08.12.2023 11:09:46.182] <01> Info [SOAP] Maximum supported vSphere api version: 7.0.2
[08.12.2023 11:09:46.182] <01> Info RetrieveServiceContent for api version: 8.0.0.1
[08.12.2023 11:09:46.417] <01> Info There is VC session cookie for url 'https://192.168.10.3:443/sdk'.
[08.12.2023 11:09:46.432] <01> Info [Soap] Host content info: host "192.168.10.3", type "vpx", version "8.0.0", build "20519528", apiVersion "8.0.0.1", hostTime "08.12.2023 7:39:49", sessionKey: "520e7a2f-816f-95f9-af53-e7148ec822ea"
[08.12.2023 11:09:46.448] <01> Info [Soap] Connection [CSoapConnectionKeyInfo]
[08.12.2023 11:09:46.448] <01> Info HostNameOrIpAddress: '192.168.10.3'
[08.12.2023 11:09:46.448] <01> Info Port: '443'
[08.12.2023 11:09:46.448] <01> Info UserName: 'administrator@vcenter.local'
[08.12.2023 11:09:46.448] <01> Info UseProxy: 'False'
[08.12.2023 11:09:46.448] <01> Info ProxyHostNameOrIpAddress: ''
[08.12.2023 11:09:46.448] <01> Info ProxyPort: '0'
[08.12.2023 11:09:46.448] <01> Info ManagedThreadId: '1'
[08.12.2023 11:09:46.448] <01> Info is disposing.
[08.12.2023 11:09:46.574] <01> Info Sharik is no longer processed by this job. Make sure this change is intentional
[08.12.2023 11:09:46.590] <01> Info Job size: 64 GB (3,6 GB provisioned).
[08.12.2023 11:09:46.606] <01> Info [JobSession] TotalObjects '1', totalSize '64 GB'
[08.12.2023 11:09:46.685] <01> Info [CPerVmBackupPreprocessor] Start of processing non backuped targets
[08.12.2023 11:09:46.748] <13> Info [CCommonPerVmSpecialProcessingAlg] Recrypting backup of 'Sharik'
[08.12.2023 11:09:47.017] <01> Info [CPerVmBackupPreprocessor] Processing of non backuped targets done
[08.12.2023 11:09:47.033] <01> Info Singling out not parallel tasks.
[08.12.2023 11:09:47.222] <01> Info Local BIOS uuid: 4BA73242-7B37-4406-B93F-A123515B976D
[08.12.2023 11:09:47.222] <01> Info SQL server IP addresses: 192.168.9.58
[08.12.2023 11:09:47.222] <01> Info VM [Name: #syspass, Ref: vm-94] is running.
[08.12.2023 11:09:47.229] <01> Info VM IP addresses: 172.18.0.1, fe80::42:ecff:fe9a:7772, 192.168.10.81, fe80::c435:136d:2cc0:aa6d
[08.12.2023 11:09:47.229] <01> Info Not parallel tasks allocated 0 out of 1.
[08.12.2023 11:09:47.237] <01> Info [PerVmBackupJobPerformer] Preparing 1 tasks
[08.12.2023 11:09:47.854] <26> Info [RPC] Loading options.
[08.12.2023 11:09:48.511] <26> Info [RPC] RPC confirm session has been created. Id: {78c576f3-550e-45c3-af50-005447ac4de1}
[08.12.2023 11:09:48.901] <26> Info [RPC] Destroying RPC confirm session. Id: {78c576f3-550e-45c3-af50-005447ac4de1}
[08.12.2023 11:09:49.729] <26> Info [RPC] RPC confirm session has been created. Id: {5e71631e-60f9-4434-bb68-e26bc9961d4e}
[08.12.2023 11:09:51.729] <01> Info [JobSession] Setting full mode (activeFull: False).
[08.12.2023 11:09:51.754] <01> Info [PerVmBackupJobPerformer] Preparing 0 tasks
[08.12.2023 11:09:53.314] <04> Info Task group 396ec9f8-b5a3-49e0-982a-be93f39e7098 is ready. Preparing next task group for processing
[08.12.2023 11:09:53.314] <04> Info - - Request: ViDisk_|ViProxyRepositoryPairResourceRequest, ProxyResourceRequest: [ViProxy, source proxies: [Vi proxy resource [id=18b661c1-d9dc-4233-90a0-7e7b10dc2d09 : srv name=VMware Backup Proxy : access level=HotAddDifferentHosts : max usage=2 : vddk modes=hotadd;nbd : direct nfs=False]] ], RepositoryResourceRequest : [Repository 'Большой раздел на толстой помойке' (storage count 1)]:1
[08.12.2023 11:09:53.323] <04> Info - - - - Response: Count: 1, details: [Subresponses: [Responces: [Vi proxy resource [id=18b661c1-d9dc-4233-90a0-7e7b10dc2d09 : srv name=VMware Backup Proxy : access level=HotAddDifferentHosts : max usage=2 : vddk modes=hotadd;nbd : direct nfs=False]],[Repository : resource allocated]
[08.12.2023 11:09:53.323] <04> Info - - Request: ViSnapshot, host: 192.168.10.9, datastores: SFP-2
[08.12.2023 11:09:53.323] <04> Info - - - - Response: Snapshot: resource allocated
[08.12.2023 11:09:53.323] <04> Info - - Request: Prepare Vi VMs, Vm '#syspass' on Host: '192.168.10.9'
[08.12.2023 11:09:53.323] <04> Info - - - - Response: VMs allocated for processing
[08.12.2023 11:09:53.323] <04> Info - - Request: File sessions
[08.12.2023 11:09:53.323] <04> Info - - - - Response: File sessions : resource allocated
[08.12.2023 11:09:53.330] <29> Info Use GetMetaCheckRequirement by repository
[08.12.2023 11:09:53.330] <29> Info Use Disabled meta check requirement
[08.12.2023 11:09:53.345] <29> Info [BackupMeta] Generate backup meta for 'Тестовый на 9.13 - #syspass:8bfbdbb0-0341-4e9d-9c03-7c2da755833f'
[08.12.2023 11:09:53.361] <29> Info [BackupMetaUpdater] Acquiring a lock for the backup Id [8bfbdbb0-0341-4e9d-9c03-7c2da755833f].
[08.12.2023 11:09:53.361] <29> Info [BackupMetaUpdater] A lock has been acquired for the backup Id [8bfbdbb0-0341-4e9d-9c03-7c2da755833f]. Elapsed: 00:00:00.0014674
[08.12.2023 11:09:53.361] <29> Info [BackupMetaUpdater] Acquiring a slot to generate metadata for the backup Id [8bfbdbb0-0341-4e9d-9c03-7c2da755833f].
[08.12.2023 11:09:53.361] <29> Info [BackupMetaUpdater] Activity slot has been acquired to generate metadata for the backup Id [8bfbdbb0-0341-4e9d-9c03-7c2da755833f]. Elapsed: 00:00:00.0028866
[08.12.2023 11:09:53.361] <29> Info [BackupMetaUpdater] Generating backup meta in current thread. BackupId :8bfbdbb0-0341-4e9d-9c03-7c2da755833f
[08.12.2023 11:09:53.408] <29> Info [Mutex] Created mutex [Global\BackupMeta[8bfbdbb0-0341-4e9d-9c03-7c2da755833f]]
[08.12.2023 11:09:53.408] <29> Info [Mutex] Acquired mutex [Global\BackupMeta[8bfbdbb0-0341-4e9d-9c03-7c2da755833f]]
[08.12.2023 11:09:53.424] <29> Info [IncrementalMetaGenerator] Generating meta for backup [8bfbdbb0-0341-4e9d-9c03-7c2da755833f], usn [0]
[08.12.2023 11:09:54.416] <29> Info [BackupMetaEncryptor] Encryption is not enabled in the linked job, so no need to encrypt the entities
[08.12.2023 11:09:54.416] <29> Info Create crypto context: [BackupId: 00000000-0000-0000-0000-000000000000, IsEncryptionEnabled: False (encryption is null), SessionKeySpec is null, BackupEncryptionKey: , MasterKey: ]
[08.12.2023 11:09:54.432] <29> Info CryptoContext: BackupId: 00000000-0000-0000-0000-000000000000, IsEncryptionEnabled: False (encryption is null), SessionKeySpec is null, BackupEncryptionKey: , MasterKey: (OK)
[08.12.2023 11:09:54.541] <29> Info [IncrementalMetaGenerator] Remove crypto keys from the meta increment because it has no entities to encrypt
[08.12.2023 11:09:54.619] <29> Info Generated backup meta in memory, Elapsed Time: 00:00:01.2066396, in seconds: 1,2066396
[08.12.2023 11:09:54.619] <29> Info Creating mutex Global\BackupMetaThis server_ 192.168.9.13|veeambackup|Тестовый на 9.13|#syspass_304EE.vbm
[08.12.2023 11:09:54.635] <29> Info [BackupMeta] Saving backup meta to '\\192.168.9.13|veeambackup|Тестовый на 9.13|#syspass_304EE.vbm'
[08.12.2023 11:09:54.713] <29> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [01.01.1753 0:00:00,-1] new value: [08.12.2023 8:09:54,1]
[08.12.2023 11:09:54.744] <29> Info Meta file saved to disk, Elapsed Time: 00:00:00.1238545, in seconds: 0,1238545
[08.12.2023 11:09:54.744] <29> Info [Mutex] Releasing mutex [Global\BackupMeta[8bfbdbb0-0341-4e9d-9c03-7c2da755833f]]
[08.12.2023 11:09:54.744] <29> Info [BackupMetaUpdater] Backup meta generated. BackupId :8bfbdbb0-0341-4e9d-9c03-7c2da755833f, Elapsed Time: 00:00:01.3784779, in seconds 1,3784779
[08.12.2023 11:09:54.744] <29> Info [BackupMeta] Backup meta for 'Тестовый на 9.13 - #syspass:8bfbdbb0-0341-4e9d-9c03-7c2da755833f' generated
[08.12.2023 11:11:40.556] <26> Info [RPC] RPC confirm session has been created. Id: {1a989fbf-af99-406b-9a23-622b7503bcca}
[08.12.2023 11:11:40.604] <26> Info [RPC] Destroying RPC confirm session. Id: {1a989fbf-af99-406b-9a23-622b7503bcca}
[08.12.2023 11:11:41.213] <26> Info [RPC] RPC confirm session has been created. Id: {490ea39f-cb0a-4f50-87f0-4b649560c3ac}
[08.12.2023 11:11:41.276] <26> Info [RPC] Destroying RPC confirm session. Id: {490ea39f-cb0a-4f50-87f0-4b649560c3ac}
[08.12.2023 11:11:45.901] <01> Info [CPolicyJobDeletedRetentionAlg] Deleted host retention is disabled in advanced options
[08.12.2023 11:11:45.917] <01> Info [PolicyBackupEncryptedStateUpdater] Committing backup encryption state (BackupId='099c4a3b-fec8-4f9f-ab0d-1c0bba71234d', EncryptionState=Unencrypted, ChildStates='Unencrypted')
[08.12.2023 11:11:45.932] <26> Info [RPC] Destroying RPC confirm session. Id: {5e71631e-60f9-4434-bb68-e26bc9961d4e}
[08.12.2023 11:11:45.932] <01> Info [CProxyRpcInvoker] RpcInvoker [41234998] was disposed
[08.12.2023 11:11:45.932] <01> Info [PerBackupSourceAgentMngr] Disposing
[08.12.2023 11:11:46.010] <01> Info Job has been stopped successfully. Name: [Тестовый на 9.13], JobId: [f582576d-d3fb-4797-8f60-89854c7d363a]
[08.12.2023 11:11:46.010] <01> Info [BackupJobPostActivity] JobSession '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6' PostActivity: 'AskService'
[08.12.2023 11:11:46.041] <01> Info [BackupJobPostActivity] Need post activity
[08.12.2023 11:11:46.041] <01> Info Running post-job script
[08.12.2023 11:11:46.057] <01> Info Executing custom command [C:\Custom_script\poweroff_fatsynology.cmd], arguments []
[08.12.2023 11:14:46.479] <32> Info Removing [CSoapConnectionKeyInfo]
[08.12.2023 11:14:46.479] <32> Info HostNameOrIpAddress: '192.168.10.3'
[08.12.2023 11:14:46.479] <32> Info Port: '443'
[08.12.2023 11:14:46.479] <32> Info UserName: 'administrator@vcenter.local'
[08.12.2023 11:14:46.479] <32> Info UseProxy: 'False'
[08.12.2023 11:14:46.479] <32> Info ProxyHostNameOrIpAddress: ''
[08.12.2023 11:14:46.479] <32> Info ProxyPort: '0'
[08.12.2023 11:14:46.479] <32> Info ManagedThreadId: '1'
[08.12.2023 11:14:46.479] <32> Info from cache. Reason: Expired
[08.12.2023 11:14:46.479] <32> Info [Soap] Logout from "https://192.168.10.3:443/sdk"
[08.12.2023 11:16:46.514] <54> Info Removing [CSoapConnectionKeyInfo]
[08.12.2023 11:16:46.514] <54> Info HostNameOrIpAddress: '192.168.10.3'
[08.12.2023 11:16:46.514] <54> Info Port: '443'
[08.12.2023 11:16:46.514] <54> Info UserName: 'administrator@vcenter.local'
[08.12.2023 11:16:46.514] <54> Info UseProxy: 'False'
[08.12.2023 11:16:46.514] <54> Info ProxyHostNameOrIpAddress: ''
[08.12.2023 11:16:46.514] <54> Info ProxyPort: '0'
[08.12.2023 11:16:46.514] <54> Info ManagedThreadId: '29'
[08.12.2023 11:16:46.514] <54> Info from cache. Reason: Expired
[08.12.2023 11:16:46.514] <54> Info [Soap] Logout from "https://192.168.10.3:443/sdk"
[08.12.2023 11:16:46.514] <54> Info [VapiSession] Delete opened session from 'https://192.168.10.3:443/api'
[08.12.2023 11:16:46.905] <54> Info Removing [CSoapConnectionKeyInfo]
[08.12.2023 11:16:46.905] <54> Info HostNameOrIpAddress: '192.168.10.3'
[08.12.2023 11:16:46.905] <54> Info Port: '443'
[08.12.2023 11:16:46.905] <54> Info UserName: 'administrator@vcenter.local'
[08.12.2023 11:16:46.905] <54> Info UseProxy: 'False'
[08.12.2023 11:16:46.905] <54> Info ProxyHostNameOrIpAddress: ''
[08.12.2023 11:16:46.905] <54> Info ProxyPort: '0'
[08.12.2023 11:16:46.905] <54> Info ManagedThreadId: '37'
[08.12.2023 11:16:46.905] <54> Info from cache. Reason: Expired
[08.12.2023 11:16:46.905] <54> Info [Soap] Logout from "https://192.168.10.3:443/sdk"
[08.12.2023 11:26:50.032] <01> Warning Post-job script timed out
[08.12.2023 11:26:50.174] <01> Warning Post-job script timed out
[08.12.2023 11:26:50.206] <01> Info [JobSession] Completing session '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6'.
[08.12.2023 11:26:50.206] <01> Info [JobSession] Updating backup stats. [Files: 1, Stats: BackupSize '1945792512', dataSize '68719504016', dedupRatio '4', compressRatio '56']
[08.12.2023 11:26:50.284] <01> Info Load: Source 0% > Proxy 23% > Network 0% > Target 85%
[08.12.2023 11:26:50.300] <01> Info Primary bottleneck: Target
[08.12.2023 11:26:50.419] <01> Info Backuped size: 1,8 GB, total backuped size: 32,9 GB
[08.12.2023 11:26:50.442] <01> Info Job session '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6' has been completed, status: 'Warning', '64 GB' of '64 GB' bytes, '1' of '1' tasks, '0' successful, '0' failed, details: '', PointIds: [10ec9d86-627d-49d5-ba71-6e5079f40828]
[08.12.2023 11:26:50.568] <01> Info [BackupJobPostActivity] JobSession '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6' PostActivity: 'AskService'
[08.12.2023 11:26:50.575] <01> Info [BackupJobPostActivity] Need post activity
[08.12.2023 11:26:50.742] <01> Info [DB] Generating xml report for sessions: [7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6]
[08.12.2023 11:26:50.994] <01> Info [DB] Transforming xml report to html report
[08.12.2023 11:26:51.216] <01> Info [SessionReportMailer] Sending report
[08.12.2023 11:26:51.231] <01> Info [CReportMailer] Sending report to support@eipc.center
[08.12.2023 11:26:51.231] <01> Info [CReportMailer] Sending e-mail notification, server 'SMTP Server 'webmail.eipc.center', port '25', timeout '100000', use ssl 'False'', to 'support@eipc.center'
[08.12.2023 11:26:51.465] <01> Info [CJobLogsManager] Cannot find quota. JobId : f582576d-d3fb-4797-8f60-89854c7d363a.
[08.12.2023 11:26:51.481] <01> Info Cleanup cloud connection cache for job f582576d-d3fb-4797-8f60-89854c7d363a
[08.12.2023 11:26:51.512] <01> Info Job event 'ready2finish' was created for session '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6'. Event full name: 'Global\ready2finishvmjobevent7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6'
[08.12.2023 11:26:51.606] <01> Info Job [Тестовый на 9.13] is ready to finish. SessionId: [7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6]
[08.12.2023 11:26:51.606] <01> Info Job event 'ready2finish' was disposed. Session: '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6'.
[08.12.2023 11:26:51.606] <01> Info Job event 'finished' was disposed. Session: '7a3b87f0-0192-42cb-bbdf-c55b52cf3fc6'.
[08.12.2023 11:26:51.606] <01> Info Unregistering TCP client channel [bs_tcp].
[08.12.2023 11:26:51.606] <01> Info Channel successfully unregistered.
[08.12.2023 11:26:51.606] <01> Info Unregistering TCP client channel [cat_tcp].
[08.12.2023 11:26:51.606] <01> Info Channel successfully unregistered.
[08.12.2023 11:26:51.606] <01> Info Job process lock was disposed.
[08.12.2023 11:26:51.606] <01> Info Job process lock was disposed.
[08.12.2023 11:26:51.622] <01> Info Disposing SVeeamBrokerService...
[08.12.2023 11:26:51.637] <08> Info [LicenseClient] License client stopped. Stopping refresh loop...
[08.12.2023 11:26:51.637] <08> Info [LicenseClient] License refresh loop stopped
[08.12.2023 11:26:51.637] <01> Info Disposing SVeeamBackupService...
[08.12.2023 11:26:51.637] <01> Info Unregistering TCP client channel [bstcp].
[08.12.2023 11:26:51.637] <01> Info Channel successfully unregistered.
[08.12.2023 11:26:51.653] <01> Info [Ssh] Clearing connection cache
[08.12.2023 11:26:51.653] <01> Info [Ssh] Connection cache cleared
[08.12.2023 11:26:51.715] <01> Info ------- Veeam Manager Stopped -------Please help me
((