· 4 years ago · Sep 13, 2021, 05:26 PM
1[12.09.2021 12:51:37] <01> Warning [CCryptoKeyRecryptor(Backup:ea75d35c-bc17-4253-9265-fe5bc9b65ea5)] Cannot find user key for backup session
2[12.09.2021 12:51:37] <01> Info [CCryptoKeyRecryptor(Backup:ea75d35c-bc17-4253-9265-fe5bc9b65ea5)] Is recrypt required: False (Cannot find user key for backup session)
3[12.09.2021 12:51:37] <01> Info [LocalBackupTargetRepairAlg] Repair started
4[12.09.2021 12:51:37] <01> Info [BackupMeta] Generate backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
5[12.09.2021 12:51:37] <01> Info [BackupMetaUpdater] Waiting for backup meta to be generated in another thread <17>
6[12.09.2021 12:51:37] <17> Info [BackupMetaUpdater] Generating backup meta because it was requested by the following threads:
7[12.09.2021 12:51:37] <17> Info [BackupMetaUpdater] Thread <1>
8[12.09.2021 12:51:37] <17> Info [Mutex] Created mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
9[12.09.2021 12:51:37] <17> Info [Mutex] Acquired mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
10[12.09.2021 12:51:37] <17> Info [IncrementalMetaGenerator] Generating meta for backup [ea75d35c-bc17-4253-9265-fe5bc9b65ea5], usn [0]
11[12.09.2021 12:51:39] <17> Info [BackupMetaEncryptor] Encryption is not enabled in the linked job, so no need to encrypt the entities
12[12.09.2021 12:51:39] <17> Info [BackupMetaEncryptor] No need to encrypt the entities
13[12.09.2021 12:51:39] <17> Info Creating mutex Global\BackupMetaThis server_ 10.171.129.110|backups-repo|Teste3|Teste3.vbm
14[12.09.2021 12:51:39] <17> Info [BackupMeta] Saving backup meta to '\\10.171.129.110|backups-repo|Teste3|Teste3.vbm'
15[12.09.2021 12:51:39] <17> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [9/12/2021 3:27:45 PM,3] new value: [9/12/2021 3:51:39 PM,4]
16[12.09.2021 12:51:39] <17> Info [Mutex] Releasing mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
17[12.09.2021 12:51:39] <17> Info [BackupMetaUpdater] Backup meta generated
18[12.09.2021 12:51:39] <01> Info [BackupMeta] Backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5' generated
19[12.09.2021 12:51:39] <01> Info Repairing point id c4e09939-2310-4bdb-a9d6-9b2eff3f9045, date 9/12/2021 12:26:25 PM
20[12.09.2021 12:51:39] <01> Info [BackupMeta] Generate backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
21[12.09.2021 12:51:39] <01> Info [BackupMetaUpdater] Waiting for backup meta to be generated in another thread <17>
22[12.09.2021 12:51:39] <17> Info [BackupMetaUpdater] Generating backup meta because it was requested by the following threads:
23[12.09.2021 12:51:39] <17> Info [BackupMetaUpdater] Thread <1>
24[12.09.2021 12:51:39] <17> Info [Mutex] Created mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
25[12.09.2021 12:51:39] <17> Info [Mutex] Acquired mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
26[12.09.2021 12:51:39] <17> Info [IncrementalMetaGenerator] Generating meta for backup [ea75d35c-bc17-4253-9265-fe5bc9b65ea5], usn [25341]
27[12.09.2021 12:51:40] <17> Info Creating mutex Global\BackupMetaThis server_ 10.171.129.110|backups-repo|Teste3|Teste3.vbm
28[12.09.2021 12:51:40] <17> Info [BackupMeta] Saving backup meta to '\\10.171.129.110|backups-repo|Teste3|Teste3.vbm'
29[12.09.2021 12:51:41] <17> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [9/12/2021 3:51:39 PM,4] new value: [9/12/2021 3:51:41 PM,5]
30[12.09.2021 12:51:41] <17> Info [Mutex] Releasing mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
31[12.09.2021 12:51:41] <17> Info [BackupMetaUpdater] Backup meta generated
32[12.09.2021 12:51:41] <01> Info [BackupMeta] Backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5' generated
33[12.09.2021 12:51:41] <01> Info [BackupJobTarget] Job session is running in full mode
34[12.09.2021 12:51:41] <01> Info [BackupMeta] Generate backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
35[12.09.2021 12:51:41] <01> Info [BackupMetaUpdater] Waiting for backup meta to be generated in another thread <17>
36[12.09.2021 12:51:41] <17> Info [BackupMetaUpdater] Generating backup meta because it was requested by the following threads:
37[12.09.2021 12:51:41] <17> Info [BackupMetaUpdater] Thread <1>
38[12.09.2021 12:51:41] <17> Info [Mutex] Created mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
39[12.09.2021 12:51:41] <17> Info [Mutex] Acquired mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
40[12.09.2021 12:51:41] <17> Info [IncrementalMetaGenerator] Generating meta for backup [ea75d35c-bc17-4253-9265-fe5bc9b65ea5], usn [25364]
41[12.09.2021 12:51:42] <17> Info Creating mutex Global\BackupMetaThis server_ 10.171.129.110|backups-repo|Teste3|Teste3.vbm
42[12.09.2021 12:51:42] <17> Info [BackupMeta] Saving backup meta to '\\10.171.129.110|backups-repo|Teste3|Teste3.vbm'
43[12.09.2021 12:51:42] <17> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [9/12/2021 3:51:41 PM,5] new value: [9/12/2021 3:51:42 PM,6]
44[12.09.2021 12:51:42] <17> Info [Mutex] Releasing mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
45[12.09.2021 12:51:42] <17> Info [BackupMetaUpdater] Backup meta generated
46[12.09.2021 12:51:42] <01> Info [BackupMeta] Backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5' generated
47[12.09.2021 12:51:42] <01> Info Preparing point in full mode
48[12.09.2021 12:51:42] <01> Info [BackupJobTarget] Creating storage alg for object 00000000-0000-0000-0000-000000000000
49[12.09.2021 12:51:42] <01> Info [BackupJobTarget] Getting last storage in group: 51127554-fdb3-4f00-b492-4af6837c86dc
50[12.09.2021 12:51:42] <01> Info [Point] Finding previous point for 'c4e09939-2310-4bdb-a9d6-9b2eff3f9045'
51[12.09.2021 12:51:42] <01> Info [Point] Previous point for 'c4e09939-2310-4bdb-a9d6-9b2eff3f9045' not found
52[12.09.2021 12:51:42] <01> Info Last storage not found
53[12.09.2021 12:51:42] <01> Info Preparing storages in full mode
54[12.09.2021 12:51:42] <01> Info New storage id 19c6cd6d-c3e8-4974-b453-7385265674a6
55[12.09.2021 12:51:42] <01> Info [StorageRequestItem] Id: 19c6cd6d-c3e8-4974-b453-7385265674a6
56[12.09.2021 12:51:42] <01> Info [TaskRepositoryResourceHelper] Adding target repository resource request to task Boot Remoto
57[12.09.2021 12:51:42] <01> Info [StorageRequestItem] Id: 19c6cd6d-c3e8-4974-b453-7385265674a6
58[12.09.2021 12:51:42] <01> Info [TaskRepositoryResourceHelper] Adding file sessions resource request for 1 files to task Boot Remoto
59[12.09.2021 12:51:42] <01> Info Lock VM ID: 1285491ecb654fcda989787b3b5c10ae
60[12.09.2021 12:51:42] <01> Info Waiting for backup infrastructure resources availability
61[12.09.2021 12:51:48] <01> Info Task group 46547de8-2638-4d77-a137-04eb646fce6a is ready. Preparing next task group for processing
62[12.09.2021 12:51:48] <01> Info - - Request: HvSnapshot [vmname='Boot Remoto' : snapshot mode='enCrash' : offhost mode='enNone']
63[12.09.2021 12:51:48] <01> Info - - - - Response: HvSnapshot [IsHardware:False, OnhostAttempt:True, UseDefaultProvider:False, IsCrashConsistentFailover:False, proxy:Proxy resource [id=6d8094f7-c9bd-4185-ab79-95e33efb88a5 : srv name=MRC-HVN01 : max usage=4]]
64[12.09.2021 12:51:48] <01> Info - - Request: HvDisk_HvDiskProxy, CsvOwnerProxyDefined: False|Repository 'TrueNAS Legado' (storage count 1):1
65[12.09.2021 12:51:48] <01> Info - - - - Response: Count: 1, details: [Subresponses: [Resource allocated: HvDiskProxy],[Repository : resource allocated]]
66[12.09.2021 12:51:48] <01> Info - - Request: File sessions
67[12.09.2021 12:51:48] <01> Info - - - - Response: File sessions : resource allocated
68[12.09.2021 12:51:48] <01> Info All VMs have been queued for processing
69[12.09.2021 12:51:50] <19> Info [RPC] RPC confirm session has been created. Id: {9f1a32e8-e1f8-470a-afd9-61e636f9b337}
70[12.09.2021 12:51:50] <19> Info [RPC] Destroying RPC confirm session. Id: {9f1a32e8-e1f8-470a-afd9-61e636f9b337}
71[12.09.2021 12:52:02] <19> Info [RPC] RPC confirm session has been created. Id: {199cc66a-15e2-49a9-8803-4e818c8be49f}
72[12.09.2021 12:52:02] <19> Info [RPC] Destroying RPC confirm session. Id: {199cc66a-15e2-49a9-8803-4e818c8be49f}
73[12.09.2021 12:52:49] <24> Error Processing Boot Remoto
74[12.09.2021 12:52:49] <24> Error The network path was not found. (Veeam.Backup.Common.CCppComponentException)
75[12.09.2021 12:52:49] <24> Error in c++: Error code: 0x00000035
76[12.09.2021 12:52:49] <24> Error Failed to open storage for read/write access. Storage: [\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk]. (Veeam.Backup.Common.CCppComponentException)
77[12.09.2021 12:52:49] <24> Error in c++: Failed to open storage [HostFS://\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk] for write access.
78[12.09.2021 12:52:49] <24> Error Agent failed to process method {Stg.OpenReadWrite}. (Veeam.Backup.Common.CCppComponentException)
79[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Common.CVcpInvoker.Invoke(CVcpStreamBase stream, String command, CVcpCommandArgs inArgs, Boolean noLog)
80[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog, Boolean agentNoLog)
81[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog)
82[12.09.2021 12:52:49] <24> Error --- End of stack trace from previous location where exception was thrown ---
83[12.09.2021 12:52:49] <24> Error at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
84[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Common.ExceptionFactory.ThrowNecessaryAggregateException(IEnumerable`1 exceptionsCollection)
85[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClientImpl.ConstructException(Exception exception, String error)
86[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.ConstructException(Exception ex, String error, Object[] args)
87[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.OnInvokeError(Exception e, String command, CVcpCommandArgs inArgs)
88[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog)
89[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.StgOpenReadWrite(String storagePath, Boolean onRemoteServer)
90[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CFullStorageAlg.OpenReadWrite()
91[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CBackupJobTarget.RestartSharedClientIfNeeded(IStorageAlg storageAlg, CHost vmTargetHost, CBackupTaskSession taskSession)
92[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CBackupJobTarget.CreateTaskTargetRepositoryClient(IBackupTask vmTask, CBackupTaskSession taskSession, CHost targetHost)
93[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CBackupJobTarget.CreateVmTarget(IBackupTask vmTask, CBackupTaskSession taskSession)
94[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.HyperV.CHvBackupJobPerformer.ExecuteTask(CHvVmTask task)
95[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.HyperV.CHvBackupJobPerformer.ExecuteTaskAsync(CHvVmTask task)
96[12.09.2021 12:52:49] <24> Error The network path was not found. (Veeam.Backup.Common.CCppComponentException)
97[12.09.2021 12:52:49] <24> Error in c++: Error code: 0x00000035
98[12.09.2021 12:52:49] <24> Error Failed to open storage for read/write access. Storage: [\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk]. (Veeam.Backup.Common.CCppComponentException)
99[12.09.2021 12:52:49] <24> Error in c++: Failed to open storage [HostFS://\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk] for write access.
100[12.09.2021 12:52:49] <24> Error Agent failed to process method {Stg.OpenReadWrite}. (Veeam.Backup.Common.CCppComponentException)
101[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Common.CVcpInvoker.Invoke(CVcpStreamBase stream, String command, CVcpCommandArgs inArgs, Boolean noLog)
102[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog, Boolean agentNoLog)
103[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog)
104[12.09.2021 12:52:49] <24> Error --- End of stack trace from previous location where exception was thrown ---
105[12.09.2021 12:52:49] <24> Error at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
106[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Common.ExceptionFactory.ThrowNecessaryAggregateException(IEnumerable`1 exceptionsCollection)
107[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClientImpl.ConstructException(Exception exception, String error)
108[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.ConstructException(Exception ex, String error, Object[] args)
109[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.OnInvokeError(Exception e, String command, CVcpCommandArgs inArgs)
110[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog)
111[12.09.2021 12:52:49] <24> Error at Veeam.Backup.AgentProvider.CBackupClient.StgOpenReadWrite(String storagePath, Boolean onRemoteServer)
112[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CFullStorageAlg.OpenReadWrite()
113[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CBackupJobTarget.RestartSharedClientIfNeeded(IStorageAlg storageAlg, CHost vmTargetHost, CBackupTaskSession taskSession)
114[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CBackupJobTarget.CreateTaskTargetRepositoryClient(IBackupTask vmTask, CBackupTaskSession taskSession, CHost targetHost)
115[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.CBackupJobTarget.CreateVmTarget(IBackupTask vmTask, CBackupTaskSession taskSession)
116[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.HyperV.CHvBackupJobPerformer.ExecuteTask(CHvVmTask task)
117[12.09.2021 12:52:49] <24> Error at Veeam.Backup.Core.HyperV.CHvBackupJobPerformer.ExecuteTaskAsync(CHvVmTask task)
118[12.09.2021 12:52:49] <24> Info [CHvSnapshotHolder] Task completed. Closing shared snapshot for task '46547de8-2638-4d77-a137-04eb646fce6a'
119[12.09.2021 12:52:54] <01> Info [Session] Id '99c118ee-c956-4d7a-93cf-5d30ead558d3', State 'Postprocessing'.
120[12.09.2021 12:52:54] <01> Info Completing storages in full mode
121[12.09.2021 12:52:54] <01> Info Collecting storage statistic, file 'Teste3D2021-09-12T122625_83A7.vbk'
122[12.09.2021 12:52:54] <01> Info [AP] (d47c) command: 'stat\n\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk\n'
123[12.09.2021 12:52:54] <37> Error [AP] (d47c) error: The network path was not found.
124[12.09.2021 12:52:54] <37> Error --tr:Error code: 0x00000035
125[12.09.2021 12:52:54] <37> Error Failed to open storage for read access. Storage: [Teste3D2021-09-12T122625_83A7.vbk].
126[12.09.2021 12:52:54] <37> Error --tr:Failed to collect metrics of the storage [\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk].
127[12.09.2021 12:52:54] <37> Error --tr:Client failed to process the command. Command: [stat].
128[12.09.2021 12:52:54] <37> Error --tr:event:3:
129[12.09.2021 12:52:54] <01> Error The network path was not found.
130[12.09.2021 12:52:54] <01> Error --tr:Error code: 0x00000035
131[12.09.2021 12:52:54] <01> Error Failed to open storage for read access. Storage: [Teste3D2021-09-12T122625_83A7.vbk].
132[12.09.2021 12:52:54] <01> Error --tr:Failed to collect metrics of the storage [\\10.171.129.110\backups-repo\Teste3\Teste3D2021-09-12T122625_83A7.vbk].
133[12.09.2021 12:52:54] <01> Error --tr:Client failed to process the command. Command: [stat].
134[12.09.2021 12:52:54] <01> Error --tr:event:3:
135[12.09.2021 12:52:54] <01> Error (Veeam.Backup.Common.CAppException)
136[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.WaitUntilWorking(Int32 timeout)
137[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.DoAgentCommand(String command, String logCommand, Boolean doWait, Nullable`1 outputLogLevel)
138[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.Stat(String fileName)
139[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClient.Stat(String storageFileName)
140[12.09.2021 12:52:54] <01> Error --- End of stack trace from previous location where exception was thrown ---
141[12.09.2021 12:52:54] <01> Error at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
142[12.09.2021 12:52:54] <01> Error at Veeam.Backup.Common.ExceptionFactory.ThrowNecessaryAggregateException(IEnumerable`1 exceptionsCollection)
143[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClientImpl.ConstructException(Exception exception, String error)
144[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClient.ConstructException(Exception ex, String error, Object[] args)
145[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClient.Stat(String storageFileName)
146[12.09.2021 12:52:54] <01> Error at Veeam.Backup.Core.CStorageEx.TryUpdateStatsNoThrow()
147[12.09.2021 12:52:54] <01> Error Error in the application. (Veeam.Backup.Common.ConnectionException)
148[12.09.2021 12:52:54] <36> Info [AP] (d47c) state: closed
149[12.09.2021 12:52:54] <01> Info [Storage] Updating storage 'MRC-SRV-BKP.marcotextil.net:Teste3D2021-09-12T122625_83A7.vbk:19c6cd6d-c3e8-4974-b453-7385265674a6:9/12/2021 12:26:25 PM:9/12/2021 12:26:25 PM', modificationTime '9/12/2021 12:49:29 PM', old modificationTime '9/12/2021 12:26:25 PM'
150[12.09.2021 12:52:54] <01> Info [StorageLock] Unlocking storage, lockId: 'LockId: e769e8f7-1205-46f5-a72d-4b4ffd5a7e78, LeaseId: 694f5a0b-2c85-45e6-948b-8f908bb16a20'
151[12.09.2021 12:52:54] <01> Info [AP] (d47c) command: 'closeAllStorages\n'
152[12.09.2021 12:52:54] <01> Error Exception of type 'Veeam.Backup.AgentProvider.AgentClosedException' was thrown. (Veeam.Backup.AgentProvider.AgentClosedException)
153[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.WaitUntilWorking(Int32 timeout)
154[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.DoAgentCommand(String command, String logCommand, Boolean doWait, Nullable`1 outputLogLevel)
155[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CClientAgentProtocol.CloseAllStorages()
156[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClient.CloseAllStorages()
157[12.09.2021 12:52:54] <01> Error --- End of stack trace from previous location where exception was thrown ---
158[12.09.2021 12:52:54] <01> Error at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
159[12.09.2021 12:52:54] <01> Error at Veeam.Backup.Common.ExceptionFactory.ThrowNecessaryAggregateException(IEnumerable`1 exceptionsCollection)
160[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClientImpl.ConstructException(Exception exception, String error)
161[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClient.ConstructException(Exception ex, String error, Object[] args)
162[12.09.2021 12:52:54] <01> Error at Veeam.Backup.AgentProvider.CBackupClient.CloseAllStorages()
163[12.09.2021 12:52:54] <01> Error at Veeam.Backup.Core.CBackupJobTarget.CloseStoragesSafe(IStorageAlg storageAlg)
164[12.09.2021 12:52:54] <01> Info Retrieving space info for repository : Id [e94e2306-5726-436c-9f2b-f25924c70175]
165[12.09.2021 12:52:54] <01> Info [CProxyRpcInvoker] RpcInvoker [48883615] has been created. Host: [MRC-SRV-BKP.marcotextil.net:6160]
166[12.09.2021 12:52:54] <19> Info [RPC] RPC confirm session has been created. Id: {1b5b4893-eec2-4c7a-b9f7-dd1df1163045}
167[12.09.2021 12:52:54] <01> Info Physical host volume was not found for path '\\10.171.129.110\backups-repo' on host 'MRC-SRV-BKP.marcotextil.net'.
168[12.09.2021 12:52:54] <19> Info [RPC] Destroying RPC confirm session. Id: {1b5b4893-eec2-4c7a-b9f7-dd1df1163045}
169[12.09.2021 12:52:54] <01> Info [CProxyRpcInvoker] RpcInvoker [48883615] was disposed
170[12.09.2021 12:52:54] <01> Info [Repository] Updating repository space info, id: 'e94e2306-5726-436c-9f2b-f25924c70175', total space: 11257818120192, free: 4436723084288
171[12.09.2021 12:52:54] <01> Info [[dbo].[BackupRepositoryContainer]] Updated. [?@id: 17cd7311-c751-44ae-82b8-26f4a4e55d5c, @totalSpace: 11257818120192, @freeSpace: 4436723084288]
172[12.09.2021 12:52:54] <01> Info Checking free space
173[12.09.2021 12:52:54] <01> Info [BackupMeta] Generate backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
174[12.09.2021 12:52:54] <01> Info [BackupMetaUpdater] Waiting for backup meta to be generated in another thread <17>
175[12.09.2021 12:52:54] <17> Info [BackupMetaUpdater] Generating backup meta because it was requested by the following threads:
176[12.09.2021 12:52:54] <17> Info [BackupMetaUpdater] Thread <1> (full update)
177[12.09.2021 12:52:54] <17> Info [Mutex] Created mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
178[12.09.2021 12:52:54] <17> Info [Mutex] Acquired mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
179[12.09.2021 12:52:54] <17> Info [IncrementalMetaGenerator] Generating meta for backup [ea75d35c-bc17-4253-9265-fe5bc9b65ea5], usn [0]
180[12.09.2021 12:52:55] <17> Info [BackupMetaEncryptor] Encryption is not enabled in the linked job, so no need to encrypt the entities
181[12.09.2021 12:52:55] <17> Info [BackupMetaEncryptor] No need to encrypt the entities
182[12.09.2021 12:52:55] <17> Info Creating mutex Global\BackupMetaThis server_ 10.171.129.110|backups-repo|Teste3|Teste3.vbm
183[12.09.2021 12:52:55] <17> Info [BackupMeta] Saving backup meta to '\\10.171.129.110|backups-repo|Teste3|Teste3.vbm'
184[12.09.2021 12:52:56] <17> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [9/12/2021 3:51:42 PM,6] new value: [9/12/2021 3:52:56 PM,7]
185[12.09.2021 12:52:56] <17> Info [Mutex] Releasing mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
186[12.09.2021 12:52:56] <17> Info [BackupMetaUpdater] Backup meta generated
187[12.09.2021 12:52:56] <01> Info [BackupMeta] Backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5' generated
188[12.09.2021 12:52:56] <01> Info [CStorageLinksHelper] Asserting storage links...
189[12.09.2021 12:52:56] <01> Info [CStorageLinksHelper] Storage links checked successfully
190[12.09.2021 12:52:56] <01> Info [BackupImmutability] Skip immutability set. Reason: Skipping immutability processing because not all tasks completed successfully
191[12.09.2021 12:52:56] <01> Info [SimplePointGenerationPolicy] Entering VM retention.
192[12.09.2021 12:52:56] <01> Info [RetentionAlgorithm] Retain VMs from backup 'ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
193[12.09.2021 12:52:56] <01> Info [RetentionAlgorithm] Deleted VM data retention is disabled in advanced options
194[12.09.2021 12:52:56] <01> Info [SimplePointGenerationPolicy] Exiting VM retention
195[12.09.2021 12:52:56] <01> Info [SimplePointGenerationPolicy] Transformation begin
196[12.09.2021 12:52:56] <01> Info Transform type: Full (OK)
197[12.09.2021 12:52:56] <01> Info Is transformation needed: False (Transformation skipped. No previous restore points available.)
198[12.09.2021 12:52:56] <01> Info [SimplePointGenerationPolicy] Transformation is not needed.
199[12.09.2021 12:52:56] <01> Info [SimplePointGenerationPolicy] Transform successfully completed
200[12.09.2021 12:52:56] <01> Info [SimplePointGenerationPolicy] Entering storage retention
201[12.09.2021 12:52:56] <01> Info [RetentionAlgorithm] Retain storages from backup 'ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
202[12.09.2021 12:52:56] <01> Info [RetentionAlgorithm] DailyRetention selected, retain 7 days and min backup count 3
203[12.09.2021 12:52:56] <01> Info [RetentionAlgorithm] Will remove 0 points from chain with full point [Point for retention: id=c4e09939-2310-4bdb-a9d6-9b2eff3f9045:type=Basic:alg=Full:creation_time=9/12/2021 12:26:25 PM:creation_time_utc=9/12/2021 3:26:25 PM:link_id:00000000-0000-0000-0000-000000000000]. Points: []
204[12.09.2021 12:52:56] <01> Info [BackupImmutability] Skipping immutability processing because the immutability settings are not available for host 6745a759-2205-4cd2-b172-8ec8f7e60ef8
205[12.09.2021 12:52:56] <01> Info [LockedStorageFilter] Creating filter for storages locked by DAR job.
206[12.09.2021 12:52:56] <01> Info [LockedStorageFilter] Filtering locked storages from storages with ids:
207[12.09.2021 12:52:56] <01> Info [LockedStorageFilter] There is no locked storages.
208[12.09.2021 12:52:56] <01> Info [RetentionAlgorithm] No storages to delete
209[12.09.2021 12:52:56] <01> Info [CStorageHelper] Try to find and remove empty storages found for Remote Backup Job
210[12.09.2021 12:52:56] <01> Info [CProxyRpcInvoker] RpcInvoker [48014184] has been created. Host: [MRC-SRV-BKP.marcotextil.net:6160]
211[12.09.2021 12:52:56] <19> Info [RPC] RPC confirm session has been created. Id: {98b33038-b61b-4547-9e90-95f211d27f1c}
212[12.09.2021 12:52:56] <01> Info [Storage] Deleting storage 'MRC-SRV-BKP.marcotextil.net:Teste3D2021-09-12T122625_83A7.vbk:19c6cd6d-c3e8-4974-b453-7385265674a6:9/12/2021 12:49:29 PM:9/12/2021 12:26:25 PM' from DB
213[12.09.2021 12:52:56] <01> Warning Failed to find point created at 9/12/2021 12:26:25 PM for storage 19c6cd6d-c3e8-4974-b453-7385265674a6
214[12.09.2021 12:52:56] <19> Info [RPC] Destroying RPC confirm session. Id: {98b33038-b61b-4547-9e90-95f211d27f1c}
215[12.09.2021 12:52:56] <01> Info [CProxyRpcInvoker] RpcInvoker [48014184] was disposed
216[12.09.2021 12:52:56] <01> Info [BackupMeta] Generate backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5'
217[12.09.2021 12:52:56] <01> Info [BackupMetaUpdater] Generating backup meta in current thread
218[12.09.2021 12:52:56] <01> Info [CProxyRpcInvoker] RpcInvoker [63943666] has been created. Host: [MRC-SRV-BKP.marcotextil.net:6160]
219[12.09.2021 12:52:56] <19> Info [RPC] RPC confirm session has been created. Id: {d238019b-7b91-4570-8521-f6eda18ebc1f}
220[12.09.2021 12:52:56] <01> Info [Mutex] Created mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
221[12.09.2021 12:52:56] <01> Info [Mutex] Acquired mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
222[12.09.2021 12:52:56] <01> Info [IncrementalMetaGenerator] Generating meta for backup [ea75d35c-bc17-4253-9265-fe5bc9b65ea5], usn [0]
223[12.09.2021 12:52:58] <01> Info [BackupMetaEncryptor] Encryption is not enabled in the linked job, so no need to encrypt the entities
224[12.09.2021 12:52:58] <01> Info [BackupMetaEncryptor] No need to encrypt the entities
225[12.09.2021 12:52:58] <01> Info Creating mutex Global\BackupMetaThis server_ 10.171.129.110|backups-repo|Teste3|Teste3.vbm
226[12.09.2021 12:52:58] <01> Info [BackupMeta] Saving backup meta to '\\10.171.129.110|backups-repo|Teste3|Teste3.vbm'
227[12.09.2021 12:52:58] <01> Info [Backup] SetMetaUpdateTimeAndVersion, old value: [9/12/2021 3:52:56 PM,7] new value: [9/12/2021 3:52:58 PM,8]
228[12.09.2021 12:52:58] <01> Info [Mutex] Releasing mutex [Global\BackupMeta[cbffe532-fa5d-4a57-a79e-f09959d727cf]]
229[12.09.2021 12:52:58] <01> Info [BackupMeta] Backup meta for 'Teste3:ea75d35c-bc17-4253-9265-fe5bc9b65ea5' generated
230[12.09.2021 12:52:58] <19> Info [RPC] Destroying RPC confirm session. Id: {d238019b-7b91-4570-8521-f6eda18ebc1f}
231[12.09.2021 12:52:58] <01> Info [CProxyRpcInvoker] RpcInvoker [63943666] was disposed
232[12.09.2021 12:52:58] <01> Info Unpublishing oibs
233[12.09.2021 12:52:58] <01> Info Unpublishing [0] OIBs
234[12.09.2021 12:52:58] <01> Info Publishing post-transform catalog session
235[12.09.2021 12:52:58] <01> Info Building oib-files matching
236[12.09.2021 12:52:58] <01> Info [SimplePointGenerationPolicy] Exiting storage retention
237[12.09.2021 12:52:58] <01> Info [ParallelStorageCompact] Full compact is disabled
238[12.09.2021 12:52:58] <01> Info [CStorageLinksHelper] Asserting storage links...
239[12.09.2021 12:52:58] <01> Info [CStorageLinksHelper] Storage links checked successfully
240[12.09.2021 12:52:58] <01> Info [BackupHealthCheckScheduleCalculator] Previous schedule time is 8/27/2021 12:00:00 AM
241[12.09.2021 12:52:58] <01> Info [BackupHealthCheck] Recheck is disabled
242[12.09.2021 12:52:58] <01> Info [BackupHealthCheck] Integrity check is not needed
243[12.09.2021 12:52:58] <01> Info Disposing CBackupRepositoryClient [0xb7efa8]
244[12.09.2021 12:52:58] <01> Info [AP] Disposing client from thread 1
245[12.09.2021 12:52:58] <01> Info Disposing BaseAgentProtocol [0x232d474]
246[12.09.2021 12:52:58] <01> Info Disposing CSocketAgentService [0x3c97814], sessionId [658f]
247[12.09.2021 12:52:58] <01> Info [SocketAgentService] Closing connection to agent 'MRC-HVN01', id 658f
248[12.09.2021 12:52:58] <01> Info [ReconnectableSocket] Stop request was sent on [4d1f54fa-7fb8-4688-954e-2aebcaa0c42f].
249[12.09.2021 12:52:58] <01> Info [AP] Disposing client from thread 1
250[12.09.2021 12:52:58] <01> Info Disposing BaseAgentProtocol [0x2befe99]
251[12.09.2021 12:52:58] <01> Info Disposing CSocketAgentService [0xb6f367], sessionId [d47c]
252[12.09.2021 12:52:58] <01> Info [SocketAgentService] Closing connection to agent 'MRC-HVN01', id d47c
253[12.09.2021 12:52:58] <01> Info Disposing CRepositoryAgent [0x26e8ea7], agent id 47634b71-d080-46b3-9f6f-173ade4c6c45
254[12.09.2021 12:52:58] <01> Info [AP] Disposing client from thread 1
255[12.09.2021 12:52:58] <01> Info Disposing BaseAgentProtocol [0xfb22e5]
256[12.09.2021 12:52:58] <01> Info Disposing CSocketAgentService [0xd43a0d], sessionId [d25a]
257[12.09.2021 12:52:58] <01> Info [SocketAgentService] Closing connection to agent 'MRC-HVN01', id d25a
258[12.09.2021 12:52:58] <01> Info Disposing CProxyAgent [0x3760a7b], agent id 47634b71-d080-46b3-9f6f-173ade4c6c45
259[12.09.2021 12:52:58] <01> Info [AgentMngr] Stopping agent, id '47634b71-d080-46b3-9f6f-173ade4c6c45'
260[12.09.2021 12:52:58] <01> Info [AgentMngr] Closing port before agent stop, id '47634b71-d080-46b3-9f6f-173ade4c6c45'.
261[12.09.2021 12:52:58] <01> Info [AgentMngr] Sending signal to stop agent with timeout, id '47634b71-d080-46b3-9f6f-173ade4c6c45'. Host: 'MRC-HVN01'.
262[12.09.2021 12:52:58] <01> Info [AgentMngr] Checking whether agent '47634b71-d080-46b3-9f6f-173ade4c6c45' is alive on host 'MRC-HVN01' with timeout.
263[12.09.2021 12:52:59] <01> Info [AgentMngr] Checking whether agent '47634b71-d080-46b3-9f6f-173ade4c6c45' is alive on host 'MRC-HVN01' with timeout.
264[12.09.2021 12:52:59] <01> Info [AgentMngr] Agent has been stopped, id '47634b71-d080-46b3-9f6f-173ade4c6c45'
265[12.09.2021 12:52:59] <01> Info [CProxyRpcInvoker] RpcInvoker [66275879] was disposed
266[12.09.2021 12:52:59] <01> Info [StorageLock] Unlocking storage, lockId: 'LockId: 3e2a4020-d688-4aaa-9049-6756d0ea701d, LeaseId: 9bd633a5-973c-403c-ac15-c3af68461fb5'
267[12.09.2021 12:52:59] <01> Info [API] DestroyLease.Started, leaseId: [9bd633a5-973c-403c-ac15-c3af68461fb5]
268[12.09.2021 12:52:59] <01> Info [API] DestroyLease.Success, leaseId: [9bd633a5-973c-403c-ac15-c3af68461fb5]
269[12.09.2021 12:52:59] <01> Info [CHvSnapshotWrapper] Try dispose snapshot for task '46547de8-2638-4d77-a137-04eb646fce6a'
270[12.09.2021 12:52:59] <01> Info [CHvSnapshotWrapper] Remaining tasks count: '0'
271[12.09.2021 12:52:59] <01> Info [CHvSnapshotWrapper] Closing snapshot
272[12.09.2021 12:52:59] <19> Info [RPC] Destroying RPC confirm session. Id: {2e3393e6-bcd9-4a7f-b13e-4a0d87bce876}
273[12.09.2021 12:52:59] <01> Info [CProxyRpcInvoker] RpcInvoker [34322009] was disposed
274[12.09.2021 12:52:59] <01> Info [BackupMetaUpdater] Disposing
275[12.09.2021 12:53:01] <01> Info Job has been stopped successfully. Name: [Teste3], JobId: [cbffe532-fa5d-4a57-a79e-f09959d727cf]
276[12.09.2021 12:53:01] <01> Info [BackupJobPostActivity] JobSession '99c118ee-c956-4d7a-93cf-5d30ead558d3' PostActivity: 'AskService'
277[12.09.2021 12:53:01] <01> Info [BackupJobPostActivity] Session result is Failed. Checking if it is last retry
278[12.09.2021 12:53:01] <01> Info [BackupJobPostActivity] wouldBeRetried: 'False'. Need post activity: 'True'
279[12.09.2021 12:53:01] <01> Info Custom command execution (post script) disabled
280[12.09.2021 12:53:01] <01> Info [JobSession] Completing session '99c118ee-c956-4d7a-93cf-5d30ead558d3'.
281[12.09.2021 12:53:01] <01> Info Backuped size: 0 B, total backuped size: 0 B
282[12.09.2021 12:53:01] <01> Info Job session '99c118ee-c956-4d7a-93cf-5d30ead558d3' has been completed, status: 'Failed', '0 B' of '0 B' bytes, '1' of '1' tasks, '0' successful, '1' failed, details: '', PointId: [c4e09939-2310-4bdb-a9d6-9b2eff3f9045]
283[12.09.2021 12:53:01] <01> Info [BackupJobPostActivity] JobSession '99c118ee-c956-4d7a-93cf-5d30ead558d3' PostActivity: 'AskService'
284[12.09.2021 12:53:01] <01> Info [BackupJobPostActivity] Session result is Failed. Checking if it is last retry
285[12.09.2021 12:53:01] <01> Info [BackupJobPostActivity] wouldBeRetried: 'False'. Need post activity: 'True'
286[12.09.2021 12:53:01] <01> Info Email notification is disabled
287[12.09.2021 12:53:01] <01> Info Job event 'ready2finish' was created for session '99c118ee-c956-4d7a-93cf-5d30ead558d3'. Event full name: 'Global\ready2finishvmjobevent99c118ee-c956-4d7a-93cf-5d30ead558d3'
288[12.09.2021 12:53:01] <01> Info Job [Teste3] is ready to finish. SessionId: [99c118ee-c956-4d7a-93cf-5d30ead558d3]
289[12.09.2021 12:53:01] <01> Info Job event 'ready2finish' was disposed. Session: '99c118ee-c956-4d7a-93cf-5d30ead558d3'.
290[12.09.2021 12:53:01] <01> Info Job event 'finished' was disposed. Session: '99c118ee-c956-4d7a-93cf-5d30ead558d3'.
291[12.09.2021 12:53:01] <01> Info Disposing SVeeamBackupService...
292[12.09.2021 12:53:02] <01> Info Unregistering TCP client channel [bstcp]
293[12.09.2021 12:53:02] <01> Info Channel successfully unregistered
294[12.09.2021 12:53:02] <01> Info Unregistering TCP client channel [bs_tcp]
295[12.09.2021 12:53:02] <01> Info Channel successfully unregistered
296[12.09.2021 12:53:02] <01> Info Unregistering TCP client channel [cat_tcp]
297[12.09.2021 12:53:02] <01> Info Channel successfully unregistered
298[12.09.2021 12:53:02] <01> Info Cleanup cloud connection cache for job cbffe532-fa5d-4a57-a79e-f09959d727cf
299[12.09.2021 12:53:02] <01> Info Job process lock was disposed.
300[12.09.2021 12:53:02] <01> Info Job process lock was disposed.
301[12.09.2021 12:53:02] <01> Info [WmiProxy] Stopping background threads
302[12.09.2021 12:53:02] <01> Info [WmiProxy:MRC-HVN01] HviNotifyProcessClose: <InputArguments><Hvi_RequestId value="0000000000000019" /><Hvi_TimeoutMs value="0" /></InputArguments>
303[12.09.2021 12:53:06] <20> Info [WmiProxy] Purge thread terminated
304[12.09.2021 12:53:06] <10> Info [LicenseClient] License client stopped. Stopping refresh loop...
305[12.09.2021 12:53:06] <10> Info [LicenseClient] License refresh loop stopped
306[12.09.2021 12:53:06] <01> Info Disposing SVeeamBackupService...
307[12.09.2021 12:53:06] <01> Info [Ssh] Clearing connection cache
308[12.09.2021 12:53:06] <01> Info [Ssh] Connection cache cleared
309[12.09.2021 12:53:06] <01> Info ------- Veeam Manager Stopped -------
310