Hello.
This is my first post here.
Please let me know if I'm doing anything wrong.
I'm using Veeam Community version 12.1.1.56 and since I updated to this version, my "file share" backups have been experiencing issues.
I have two backup jobs of this type.
The problem I'm going to report only occurs when I activate the option "Configure secondary destinations for this job" within "Backup Repository" in the job properties.
If I create a backup job now, it will execute the task normally. However, on the following days, Veeam starts to encounter problems. It always copies the files in the primary job normally, every day, but in the secondary jobs, it immediately starts the task along with the primary job and the logs show the following error:
"[12.03.2024 19:01:20.918] <28> Error (3) Item [Data from 03/12/24 7:00:28 PM restore point] is locked by running session SRV-02 - Arquivos [File Backup], SessionId: [aac32375-bfca-4f36-afe2-d7b1a6f5627a]
[12.03.2024 19:01:20.918] <28> Error (3) Item [Data from 03/12/24 7:00:28 PM restore point] is locked by running session SRV-02 - Arquivos [File Backup] (Veeam.Backup.Interaction.Management.LockedStorageException)
[12.03.2024 19:01:20.918] <28> Error (3) Server stack trace:
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Common.SExceptionExtensions.Rethrow(Exception exception)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.ServiceLib.CStorageLockBatchAlg.QueueRequest.CheckCompleted()
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.ServiceLib.CStorageLockBatchAlg.LockOrThrow(CLockRequest[] lockRequests)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.ServiceLib.CStgLockManager.LockOrThrow(IReadOnlyCollection`1 lockRequests)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.ServiceLib.CStgLockManager.LockGroupsOrThrow(CLockGroup[] lockGroups, Guid leaseId)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.ServiceLib.CLockService.LockGroups(Guid leaseId, CLockGroup[] lockGroups)
[12.03.2024 19:01:20.918] <28> Error (3) em System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Object[]& outArgs)
[12.03.2024 19:01:20.918] <28> Error (3) em System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg)
[12.03.2024 19:01:20.918] <28> Error (3) Exception rethrown at [0]:
[12.03.2024 19:01:20.918] <28> Error (3) em System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
[12.03.2024 19:01:20.918] <28> Error (3) em System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Interaction.Management.ILockService.LockGroups(Guid leaseId, CLockGroup[] lockGroups)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Interaction.Management.Client.CLockManService.<>c__DisplayClass4_0.<Veeam.Backup.Interaction.Management.ILockService.LockGroups>b__0()
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Common.Remoting.CRetryableMethod.DoInvoke[Ret](ActionDelegate`1 dlg)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Core.CDbAccessableLockManService.<>c__DisplayClass6_0.<LockGroups>b__0()
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Core.CDbAccessableLockManService.Invoke[T](Func`1 func)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Core.CLocker.LockInternal(Guid sessionId, CLockGroup[] lockGroups)
[12.03.2024 19:01:20.918] <28> Error (3) em Veeam.Backup.Core.CLocker.TryResolveAndLockInternal(Guid sessionId, CLockGroup[] lockGroups, Int32 attempt, Int32 retryCount, Exception& lastException, CDisposableLock& resolveAndLockGroups, CSessionLogLine& logLine)"
The log above is from a job that starts every day at 7:00 PM. Shouldn't the secondary job only start after the completion of the primary job?
If I try to run, the next day, the secondary job that had a problem, it runs, copies the data for the day, and then generates several identical lines showing that it didn't copy anything else, taking some time to process the next backup step.
Yesterday I backed up less than 2GB and it took several hours to get close to the end. Here's an example:
“12/03/2024 13:35:35 :: Required backup infrastructure resources have been assigned
12/03/2024 13:35:40 :: Backup copy started at 12/03/2024 13:35:40
12/03/2024 13:35:43 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:37:48 :: Backup metadata update completed successfully
12/03/2024 13:38:56 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:40:28 :: Backup metadata update completed successfully
12/03/2024 13:41:46 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:43:05 :: Backup metadata update completed successfully
12/03/2024 13:44:20 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:45:44 :: Backup metadata update completed successfully
12/03/2024 13:46:52 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:48:18 :: Backup metadata update completed successfully
12/03/2024 13:49:29 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:50:57 :: Backup metadata update completed successfully
12/03/2024 13:52:04 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:53:28 :: Backup metadata update completed successfully
12/03/2024 13:54:33 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:55:51 :: Backup metadata update completed successfully
12/03/2024 13:57:02 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 13:58:26 :: Backup metadata update completed successfully
12/03/2024 13:59:36 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 14:00:56 :: Backup metadata update completed successfully
12/03/2024 14:03:08 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 14:04:36 :: Backup metadata update completed successfully
12/03/2024 14:05:48 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 14:07:15 :: Backup metadata update completed successfully
12/03/2024 14:08:24 :: Copying restore point 05/03/2024 19:01:04 (0 B): 0 files (0 B) transferred at 0 KB/s.
12/03/2024 14:09:55 :: Backup metadata update completed successfully
12/03/2024 14:11:05 :: Copying restore point 06/03/2024 19:00:22 (259,9 MB): 160 files (259,9 MB) transferred at 121 KB/s.
12/03/2024 14:13:18 :: Backup metadata update completed successfully
12/03/2024 14:14:41 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 109 KB/s.
12/03/2024 14:16:18 :: Backup metadata update completed successfully
12/03/2024 14:17:19 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 103 KB/s.
12/03/2024 14:18:58 :: Backup metadata update completed successfully
12/03/2024 14:20:07 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 97 KB/s.
12/03/2024 14:21:39 :: Backup metadata update completed successfully
12/03/2024 14:22:45 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 91 KB/s.
12/03/2024 14:24:20 :: Backup metadata update completed successfully
12/03/2024 14:25:25 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 86 KB/s.
12/03/2024 14:27:08 :: Backup metadata update completed successfully
12/03/2024 14:28:11 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 82 KB/s.
12/03/2024 14:29:59 :: Backup metadata update completed successfully
12/03/2024 14:31:08 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 76 KB/s.
12/03/2024 14:34:24 :: Backup metadata update completed successfully
12/03/2024 14:35:30 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 72 KB/s.
12/03/2024 14:37:09 :: Backup metadata update completed successfully
12/03/2024 14:38:35 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 68 KB/s.
12/03/2024 14:41:24 :: Backup metadata update completed successfully
12/03/2024 14:42:37 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 64 KB/s.
12/03/2024 14:44:52 :: Backup metadata update completed successfully
12/03/2024 14:46:14 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 61 KB/s.
12/03/2024 14:48:09 :: Backup metadata update completed successfully
12/03/2024 14:49:30 :: Copying restore point 06/03/2024 19:00:22 (0 B): 0 files (0 B) transferred at 58 KB/s.
12/03/2024 14:51:43 :: Backup metadata update completed successfully
12/03/2024 14:53:07 :: Copying restore point 07/03/2024 19:01:05 (602,1 MB): 256 files (602,1 MB) transferred at 184 KB/s.
12/03/2024 14:56:20 :: Backup metadata update completed successfully
12/03/2024 14:58:07 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 174 KB/s.
12/03/2024 15:00:01 :: Backup metadata update completed successfully
12/03/2024 15:01:07 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 169 KB/s.
12/03/2024 15:02:47 :: Backup metadata update completed successfully
12/03/2024 15:03:46 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 164 KB/s.
12/03/2024 15:05:22 :: Backup metadata update completed successfully
12/03/2024 15:06:31 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 160 KB/s.
12/03/2024 15:08:01 :: Backup metadata update completed successfully
12/03/2024 15:09:07 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 155 KB/s.
12/03/2024 15:10:35 :: Backup metadata update completed successfully
12/03/2024 15:11:42 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 151 KB/s.
12/03/2024 15:13:06 :: Backup metadata update completed successfully
12/03/2024 15:14:18 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 147 KB/s.
12/03/2024 15:15:46 :: Backup metadata update completed successfully
12/03/2024 15:17:57 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 138 KB/s.
12/03/2024 15:22:10 :: Backup metadata update completed successfully
12/03/2024 15:23:24 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 135 KB/s.
12/03/2024 15:25:02 :: Backup metadata update completed successfully
12/03/2024 15:26:09 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 131 KB/s.
12/03/2024 15:27:41 :: Backup metadata update completed successfully
12/03/2024 15:28:55 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 128 KB/s.
12/03/2024 15:30:18 :: Backup metadata update completed successfully
12/03/2024 15:31:25 :: Copying restore point 07/03/2024 19:01:05 (0 B): 0 files (0 B) transferred at 126 KB/s.
12/03/2024 15:32:55 :: Backup metadata update completed successfully
12/03/2024 15:34:09 :: Copying restore point 08/03/2024 19:00:44 (1,1 GB): 516 files (1,1 GB) transferred at 276 KB/s.
12/03/2024 15:37:30 :: Backup metadata update completed successfully
12/03/2024 15:39:18 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 267 KB/s.
12/03/2024 15:40:26 :: Backup metadata update completed successfully
12/03/2024 15:41:47 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 262 KB/s.
12/03/2024 15:42:58 :: Backup metadata update completed successfully
12/03/2024 15:44:20 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 257 KB/s.
12/03/2024 15:45:33 :: Backup metadata update completed successfully
12/03/2024 15:46:58 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 252 KB/s.
12/03/2024 15:48:11 :: Backup metadata update completed successfully
12/03/2024 15:49:31 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 247 KB/s.
12/03/2024 15:50:43 :: Backup metadata update completed successfully
12/03/2024 15:52:06 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 242 KB/s.
12/03/2024 15:53:20 :: Backup metadata update completed successfully
12/03/2024 15:54:43 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 238 KB/s.
12/03/2024 15:55:52 :: Backup metadata update completed successfully
12/03/2024 15:57:22 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 234 KB/s.
12/03/2024 15:58:34 :: Backup metadata update completed successfully
12/03/2024 16:00:06 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 222 KB/s.
12/03/2024 16:06:01 :: Backup metadata update completed successfully
12/03/2024 16:07:30 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 218 KB/s.
12/03/2024 16:08:42 :: Backup metadata update completed successfully
12/03/2024 16:10:07 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 214 KB/s.
12/03/2024 16:11:18 :: Backup metadata update completed successfully
12/03/2024 16:12:47 :: Copying restore point 08/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 211 KB/s.
12/03/2024 16:13:58 :: Backup metadata update completed successfully
12/03/2024 16:15:26 :: Copying restore point 09/03/2024 19:00:44 (13,9 MB): 1 files (13,9 MB) transferred at 210 KB/s.
12/03/2024 16:16:49 :: Backup metadata update completed successfully
12/03/2024 16:18:15 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 205 KB/s.
12/03/2024 16:19:27 :: Backup metadata update completed successfully
12/03/2024 16:20:51 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 202 KB/s.
12/03/2024 16:22:00 :: Backup metadata update completed successfully
12/03/2024 16:23:24 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 198 KB/s.
12/03/2024 16:25:05 :: Backup metadata update completed successfully
12/03/2024 16:26:30 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 195 KB/s.
12/03/2024 16:27:37 :: Backup metadata update completed successfully
12/03/2024 16:29:07 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 192 KB/s.
12/03/2024 16:30:15 :: Backup metadata update completed successfully
12/03/2024 16:31:38 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 190 KB/s.
12/03/2024 16:32:47 :: Backup metadata update completed successfully
12/03/2024 16:34:16 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 187 KB/s.
12/03/2024 16:35:25 :: Backup metadata update completed successfully
12/03/2024 16:36:43 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 184 KB/s.
12/03/2024 16:37:49 :: Backup metadata update completed successfully
12/03/2024 16:39:24 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 182 KB/s.
12/03/2024 16:40:36 :: Backup metadata update completed successfully
12/03/2024 16:43:50 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 177 KB/s.
12/03/2024 16:44:54 :: Backup metadata update completed successfully
12/03/2024 16:46:23 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 175 KB/s.
12/03/2024 16:47:28 :: Backup metadata update completed successfully
12/03/2024 16:48:58 :: Copying restore point 09/03/2024 19:00:44 (0 B): 0 files (0 B) transferred at 173 KB/s.
12/03/2024 16:50:04 :: Backup metadata update completed successfully
12/03/2024 16:51:21 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 170 KB/s.
12/03/2024 16:52:36 :: Backup metadata update completed successfully
12/03/2024 16:54:07 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 168 KB/s.
12/03/2024 16:55:18 :: Backup metadata update completed successfully
12/03/2024 16:56:48 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 166 KB/s.
12/03/2024 16:57:54 :: Backup metadata update completed successfully
12/03/2024 16:59:16 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 164 KB/s.
12/03/2024 17:00:18 :: Backup metadata update completed successfully
12/03/2024 17:01:56 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 162 KB/s.
12/03/2024 17:03:02 :: Backup metadata update completed successfully
12/03/2024 17:04:53 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 160 KB/s.
12/03/2024 17:06:00 :: Backup metadata update completed successfully
12/03/2024 17:07:25 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 158 KB/s.
12/03/2024 17:08:34 :: Backup metadata update completed successfully
12/03/2024 17:10:05 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 156 KB/s.
12/03/2024 17:11:15 :: Backup metadata update completed successfully
12/03/2024 17:12:42 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 154 KB/s.
12/03/2024 17:13:48 :: Backup metadata update completed successfully
12/03/2024 17:15:21 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 152 KB/s.
12/03/2024 17:16:27 :: Backup metadata update completed successfully
12/03/2024 17:18:04 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 150 KB/s.
12/03/2024 17:19:10 :: Backup metadata update completed successfully
12/03/2024 17:21:10 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 147 KB/s.
12/03/2024 17:24:46 :: Backup metadata update completed successfully
12/03/2024 17:26:41 :: Copying restore point 10/03/2024 19:01:24 (0 B): 0 files (0 B) transferred at 145 KB/s.
12/03/2024 17:27:33 :: Backup metadata update completed successfully
12/03/2024 17:28:41 :: Copying restore point 11/03/2024 19:00:45 (288,2 MB): 287 files (288,2 MB) transferred at 165 KB/s.
12/03/2024 17:30:13 :: Backup metadata update completed successfully
12/03/2024 17:31:36 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 163 KB/s.
12/03/2024 17:32:34 :: Backup metadata update completed successfully
12/03/2024 17:33:59 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 161 KB/s.
12/03/2024 17:34:57 :: Backup metadata update completed successfully
12/03/2024 17:36:01 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 160 KB/s.
12/03/2024 17:36:59 :: Backup metadata update completed successfully
12/03/2024 17:38:04 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 158 KB/s.
12/03/2024 17:39:07 :: Backup metadata update completed successfully
12/03/2024 17:40:12 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 157 KB/s.
12/03/2024 17:41:12 :: Backup metadata update completed successfully
12/03/2024 17:42:21 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 155 KB/s.
12/03/2024 17:43:16 :: Backup metadata update completed successfully
12/03/2024 17:44:21 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 154 KB/s.
12/03/2024 17:45:15 :: Backup metadata update completed successfully
12/03/2024 17:46:23 :: Copying restore point 11/03/2024 19:00:45 (0 B): 0 files (0 B) transferred at 153 KB/s.
12/03/2024 17:47:16 :: Backup metadata update: transforming replica of metadata (0% done)"
I had skipped running this secondary job for a few days to observe its behavior.
This also happens with the other file backup job:
I don't know what to do.
In the logs within the folder C:\ProgramData\Veeam\Backup, in the task logs, I didn't find any clue as to what could be causing this. Could you help me?
