Host-based backup of VMware vSphere VMs.
Post Reply
Yukinobu
Enthusiast
Posts: 81
Liked: never
Joined: Apr 30, 2013 1:19 am
Full Name: Yukinobu Asami
Contact:

Backup copy job takes too long to generate blocks, causing source backup job to fail

Post by Yukinobu »

Hi,

Our cudtomer is using QNAP object storage as the target for a backup copy job with immutability enabled.

I don't know if this is a QNAP issue, but the backup copy job is completed every 10 days when blocks are generated, and takes more than 24 hours.
object-storage-as-backup-target-f52/qna ... 85139.html

As a result, even the backup job fails with the following error.

Code: Select all

Item [<vib file name>] is locked by running session Immutable Backup Job - <Backup copy job name> [Backup Copy]
When I checked the log, the incremental transfer was completed in
several tens of minutes, and it seems that the extension of the immutability period is taking time.

Code: Select all

[20.06.2025 02:06:57.051]    <46>    Info (3)    [ArchiveImmutabilityManager] Immutability settings: Generation interval in days 10, Immutability interval in days 60
[20.06.2025 02:06:57.051]    <46>    Info (3)    [ArchiveImmutabilityManager] Creating or updating generation info. New generation info: Expiration date UTC 2025/06/29 17:06:57, Immutable until UTC 2025/08/28 17:06:57
[20.06.2025 02:06:57.067]    <46>    Info (3)    [DirectBackupExtension] BackupId: 50cce671-9d22-440b-b760-46614307f065, ExtentId: 69fe5555-8cf5-442a-9d2f-356a7d7a0f70, GenerationExpirationDateUtc 2025-06-29T17:06:57.0518545Z, GenerationImmutableTillUtc 2025-08-28T17:06:57.0518545Z
[20.06.2025 02:06:57.067]    <46>    Info (3)    Setting immutability for backup Immutable Backup Job - QNAP-BK2\KANRI-FILE - KANRI-FILE:50cce671-9d22-440b-b760-46614307f065
[20.06.2025 02:06:57.067]    <46>    Info (3)    Using generation immutability interval, backup will be immutable until 2025/08/28 17:06:57
[20.06.2025 02:06:57.067]    <46>    Info (3)            [AP] (aead5e41) command: 'Invoke: Cloud.SetCurrentImmutabilityGeneration { (EString) ConnectionId = 69fe5555-8cf5-442a-9d2f-356a7d7a0f70; (EString) BackupId = 0bc67861-133f-431f-9ae2-6f96f87d8601; (EDateTime) ImmutableTillUtc = 2025-08-28 17:06:57; }'
[20.06.2025 02:06:57.864]    <56>    Info (4)            [AP] (aead5e41) output: <VCPCommandResult result="true" exception="" />
[20.06.2025 02:06:57.864]    <56>    Info (4)            [AP] (aead5e41) output: <VCPCommandArgs />
[20.06.2025 02:06:57.879]    <53>    Info (4)            [AP] (aead5e41) output: >
[20.06.2025 02:06:57.879]    <46>    Info (3)    Checking if reconnect is needed
[20.06.2025 02:06:57.879]    <46>    Info (3)    [CSimpleCopyStorageAlg] Creating incremental storage.
[20.06.2025 02:06:57.942]    <46>    Info (3)    [Mutex] Created mutex [Global\DirectBackupStorageInfo[d2490fa4-7531-4d99-a5fb-012f38ee69a9]]
[20.06.2025 02:06:57.942]    <46>    Info (3)    [Mutex] Acquired mutex [Global\DirectBackupStorageInfo[d2490fa4-7531-4d99-a5fb-012f38ee69a9]]
[20.06.2025 02:06:57.957]    <46>    Info (3)    [Mutex] Releasing mutex [Global\DirectBackupStorageInfo[d2490fa4-7531-4d99-a5fb-012f38ee69a9]]
[20.06.2025 02:06:57.957]    <46>    Info (3)            [AP] (aead5e41) command: 'prepStorageForWriteEx\ncloud://<Path ConnId="69fe5555-8cf5-442a-9d2f-356a7d7a0f70" BackupId="0bc67861-133f-431f-9ae2-6f96f87d8601" StgId="{dc981646-f54e-40e0-a08d-b2b1f43bc7f2}" LocalPath="" Tag="KANRI-FILE.vm-28D2025-06-19T225402_C6D8.vib"/>\n1024\n3\n'
[20.06.2025 02:06:59.113]    <73>    Info (4)            [AP] (aead5e41) output: >
[20.06.2025 02:06:59.129]    <46>    Info (3)    [CBlobStorageCommander] Creating checkpoint. Vbm will be loaded from blob storage
[20.06.2025 02:06:59.129]    <46>    Info (3)            [AP] (aead5e41) command: 'Invoke: Cloud.FindLastCheckpointId { (EString) ConnectionId = 69fe5555-8cf5-442a-9d2f-356a7d7a0f70; (EString) BackupId = 0bc67861-133f-431f-9ae2-6f96f87d8601; (EString) ClientId = 9797a14b-5e9e-4c52-8053-306be4393e78; }'
[20.06.2025 02:07:00.035]    <56>    Info (4)            [AP] (aead5e41) output: <VCPCommandResult result="true" exception="" />
[20.06.2025 02:07:00.035]    <56>    Info (4)            [AP] (aead5e41) output: <VCPCommandArgs><Item key="LastCheckpointId" type="EUInt64" value="1008" /></VCPCommandArgs>
[20.06.2025 02:07:00.035]    <56>    Info (4)            [AP] (aead5e41) output: >
[20.06.2025 02:07:00.035]    <46>    Info (3)            [AP] (aead5e41) command: 'Invoke: Cloud.GetCheckpointInfo { (EString) ConnectionId = 69fe5555-8cf5-442a-9d2f-356a7d7a0f70; (EString) BackupId = 0bc67861-133f-431f-9ae2-6f96f87d8601; (EUInt64) CheckpointId = 1008; (EString) ClientId = 9797a14b-5e9e-4c52-8053-306be4393e78; }'
[20.06.2025 02:07:01.551]    <46>    Info (3)    [CloudBackupServiceLocker] Locking cloudBackupId 0bc67861-133f-431f-9ae2-6f96f87d8601 for write
[20.06.2025 02:07:01.551]    <46>    Info (3)    [CloudBackupLock] Locking 1 cloudbackup(s) as write-only: 0bc67861-133f-431f-9ae2-6f96f87d8601
[20.06.2025 02:07:01.551]    <46>    Info (3)        [LockResolver] Getting conflicting sessions
[20.06.2025 02:07:01.551]    <46>    Info (3)        [LockResolver] No conflicting sessions found
[20.06.2025 02:07:01.551]    <46>    Info (3)        [API] Creating new lease. TTL: [00:05:00]
[20.06.2025 02:07:01.551]    <46>    Info (3)        [API] New lease was created. Id: [3727ac94-c119-4ee0-a7ca-e0258f721705], TTL: [00:05:00]
[20.06.2025 02:07:01.551]    <46>    Info (3)    [LeaseKeeper] Created. LeaseId: 3727ac94-c119-4ee0-a7ca-e0258f721705, TTL: [300 sec], ignoreExceptions: [False].
[20.06.2025 02:07:01.613]    <46>    Info (3)    [CloudBackupLock] CloudBackup(s) have been locked, lockIds: [79750ab3-fdd9-42dd-92ba-c389178101a4]
[20.06.2025 02:07:01.613]    <46>    Info (3)    Created CCloudBackupEmptyLocker
[20.06.2025 02:07:01.613]    <46>    Info (3)            [AP] (aead5e41) command: 'Invoke: Cloud.FindLastCheckpointId { (EString) ConnectionId = 69fe5555-8cf5-442a-9d2f-356a7d7a0f70; (EString) BackupId = 0bc67861-133f-431f-9ae2-6f96f87d8601; (EString) ClientId = 9797a14b-5e9e-4c52-8053-306be4393e78; }'
[20.06.2025 02:07:03.847]    <54>    Info (4)            [AP] (aead5e41) output: <VCPCommandResult result="true" exception="" />
[20.06.2025 02:07:03.847]    <56>    Info (4)            [AP] (aead5e41) output: <VCPCommandArgs><Item key="LastCheckpointId" type="EUInt64" value="1008" /></VCPCommandArgs>
[20.06.2025 02:07:03.847]    <56>    Info (4)            [AP] (aead5e41) output: >
[20.06.2025 02:07:03.863]    <46>    Info (3)    [CBlobStorageCommander] Creating checkpoint for cloud backup [50cce671-9d22-440b-b760-46614307f065]. Vbm version: [643]
[20.06.2025 02:07:03.910]    <46>    Info (3)            [AP] (aead5e41) command: 'Invoke: Cloud.CreateCheckpoint { (EString) ConnectionId = 69fe5555-8cf5-442a-9d2f-356a7d7a0f70; (EString) BackupId = 0bc67861-133f-431f-9ae2-6f96f87d8601; (EBlob) VbmContent = {EBlob: 597923 bytes}; (EUInt64) LastCheckpointId = 1008; }'
[20.06.2025 02:07:03.972]    <53>    Info (4)            [AP] (aead5e41) output: --size: 1000
[20.06.2025 02:07:07.596]    <54>    Info (4)            [AP] (aead5e41) output: 0
[20.06.2025 02:07:07.893]    <73>    Info (4)            [AP] (aead5e41) output: 20
[20.06.2025 02:10:33.386]    <44>    Info (4)            [AP] (aead5e41) output: 21
[20.06.2025 02:37:03.955]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 00:30:00.0450836
[20.06.2025 03:07:03.996]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 01:00:00.0869259
[20.06.2025 03:37:04.048]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 01:30:00.1385502
[20.06.2025 04:07:04.088]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 02:00:00.1780165
[20.06.2025 04:37:04.137]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 02:30:00.2273083
[20.06.2025 05:07:04.180]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 03:00:00.2701488
[20.06.2025 05:37:04.230]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 03:30:00.3207880
[20.06.2025 06:07:04.281]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 04:00:00.3712499
[20.06.2025 06:37:04.319]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 04:30:00.4091527
[20.06.2025 07:07:04.357]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 05:00:00.4471219
[20.06.2025 07:37:04.394]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 05:30:00.4848791
[20.06.2025 08:07:04.435]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 06:00:00.5254256
[20.06.2025 08:37:04.481]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 06:30:00.5712973
[20.06.2025 09:07:04.526]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 07:00:00.6165749
[20.06.2025 09:37:04.564]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 07:30:00.6545905
[20.06.2025 10:07:04.603]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 08:00:00.6938104
[20.06.2025 10:37:04.640]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 08:30:00.7305917
[20.06.2025 11:07:04.678]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 09:00:00.7687400
[20.06.2025 11:37:04.727]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 09:30:00.8177610
[20.06.2025 12:07:04.774]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 10:00:00.8646062
[20.06.2025 12:37:04.826]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 10:30:00.9162749
[20.06.2025 13:07:04.868]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 11:00:00.9589297
[20.06.2025 13:37:04.913]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 11:30:01.0031952
[20.06.2025 14:07:04.955]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 12:00:01.0457460
[20.06.2025 14:37:05.001]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 12:30:01.0911714
[20.06.2025 15:07:05.041]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 13:00:01.1318824
[20.06.2025 15:37:05.085]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 13:30:01.1751199
[20.06.2025 16:07:05.126]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 14:00:01.2169350
[20.06.2025 16:37:05.164]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 14:30:01.2548134
[20.06.2025 17:07:05.209]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 15:00:01.2999680
[20.06.2025 17:37:05.259]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 15:30:01.3498110
[20.06.2025 18:07:05.308]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 16:00:01.3981700
[20.06.2025 18:37:05.353]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 16:30:01.4430546
[20.06.2025 18:43:25.239]    <49>    Info (4)            [AP] (aead5e41) output: 22
[20.06.2025 18:44:00.329]    <53>    Info (4)            [AP] (aead5e41) output: 23
[20.06.2025 18:47:59.495]    <34>    Info (4)            [AP] (aead5e41) output: 24
[20.06.2025 18:50:39.753]    <62>    Info (4)            [AP] (aead5e41) output: 25
[20.06.2025 18:53:06.541]    <39>    Info (4)            [AP] (aead5e41) output: 26
[20.06.2025 18:56:22.073]    <52>    Info (4)            [AP] (aead5e41) output: 27
[20.06.2025 19:07:05.394]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 17:00:01.4847595
[20.06.2025 19:26:22.326]    <39>    Info (4)            [AP] (aead5e41) output: 28
[20.06.2025 19:30:23.346]    <67>    Info (4)            [AP] (aead5e41) output: 29
[20.06.2025 19:33:32.859]    <13>    Info (4)            [AP] (aead5e41) output: 30
[20.06.2025 19:34:24.507]    <51>    Info (4)            [AP] (aead5e41) output: 31
[20.06.2025 19:37:05.447]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 17:30:01.5369915
[20.06.2025 19:38:58.004]    <13>    Info (4)            [AP] (aead5e41) output: 32
[20.06.2025 19:43:09.384]    <53>    Info (4)            [AP] (aead5e41) output: 33
[20.06.2025 19:45:22.853]    <42>    Info (4)            [AP] (aead5e41) output: 34
[20.06.2025 19:49:30.482]    <52>    Info (4)            [AP] (aead5e41) output: 35
[20.06.2025 20:07:05.496]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 18:00:01.5862887
[20.06.2025 20:37:05.548]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 18:30:01.6382728
[20.06.2025 21:07:05.585]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 19:00:01.6757571
[20.06.2025 21:24:32.666]    <13>    Info (4)            [AP] (aead5e41) output: 36
[20.06.2025 21:29:45.219]    <68>    Info (4)            [AP] (aead5e41) output: 37
[20.06.2025 21:32:55.790]    <51>    Info (4)            [AP] (aead5e41) output: 38
[20.06.2025 21:36:19.661]    <13>    Info (4)            [AP] (aead5e41) output: 39
[20.06.2025 21:37:05.634]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 19:30:01.7240692
[20.06.2025 21:40:49.343]    <44>    Info (4)            [AP] (aead5e41) output: 40
[20.06.2025 21:44:32.063]    <35>    Info (4)            [AP] (aead5e41) output: 41
[20.06.2025 21:49:59.086]    <63>    Info (4)            [AP] (aead5e41) output: 42
[20.06.2025 22:04:03.761]    <71>    Info (4)            [AP] (aead5e41) output: 43
[20.06.2025 22:06:40.581]    <71>    Info (4)            [AP] (aead5e41) output: 44
[20.06.2025 22:07:05.671]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 20:00:01.7616610
[20.06.2025 22:10:57.269]    <42>    Info (4)            [AP] (aead5e41) output: 45
[20.06.2025 22:14:42.970]    <69>    Info (4)            [AP] (aead5e41) output: 46
[20.06.2025 22:17:33.631]    <04>    Info (4)            [AP] (aead5e41) output: 47
[20.06.2025 22:29:35.442]    <64>    Info (4)            [AP] (aead5e41) output: 48
[20.06.2025 22:34:28.160]    <62>    Info (4)            [AP] (aead5e41) output: 49
[20.06.2025 22:37:05.721]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 20:30:01.8113452
[20.06.2025 22:37:11.204]    <62>    Info (4)            [AP] (aead5e41) output: 50
[20.06.2025 22:42:13.328]    <58>    Info (4)            [AP] (aead5e41) output: 51
[20.06.2025 22:49:57.637]    <15>    Info (4)            [AP] (aead5e41) output: 52
[20.06.2025 22:53:42.945]    <71>    Info (4)            [AP] (aead5e41) output: 53
[20.06.2025 23:07:05.761]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 21:00:01.8513042
[20.06.2025 23:37:05.809]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 21:30:01.8997385
[20.06.2025 23:59:30.169]    <42>    Info (4)            [AP] (aead5e41) output: 54
[21.06.2025 00:02:12.343]    <13>    Info (4)            [AP] (aead5e41) output: 55
[21.06.2025 00:07:05.857]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 22:00:01.9478540
[21.06.2025 00:07:11.778]    <34>    Info (4)            [AP] (aead5e41) output: 56
[21.06.2025 00:11:56.660]    <56>    Info (4)            [AP] (aead5e41) output: 57
[21.06.2025 00:18:56.507]    <61>    Info (4)            [AP] (aead5e41) output: 58
[21.06.2025 00:22:01.486]    <55>    Info (4)            [AP] (aead5e41) output: 59
[21.06.2025 00:28:55.124]    <71>    Info (4)            [AP] (aead5e41) output: 60
[21.06.2025 00:31:46.123]    <13>    Info (4)            [AP] (aead5e41) output: 61
[21.06.2025 00:37:05.895]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 22:30:01.9855455
[21.06.2025 01:07:05.943]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 23:00:02.0335505
[21.06.2025 01:12:22.243]    <48>    Info (4)            [AP] (aead5e41) output: 62
[21.06.2025 01:19:13.048]    <67>    Info (4)            [AP] (aead5e41) output: 63
[21.06.2025 01:26:33.016]    <61>    Info (4)            [AP] (aead5e41) output: 64
[21.06.2025 01:30:17.739]    <48>    Info (4)            [AP] (aead5e41) output: 65
[21.06.2025 01:35:07.965]    <39>    Info (4)            [AP] (aead5e41) output: 66
[21.06.2025 01:37:05.983]    <46>    Info (3)    [AP] Waiting for completion. Id: [0x3765649], Time: 23:30:02.0735257
[21.06.2025 01:43:37.921]    <64>    Info (4)            [AP] (aead5e41) output: 67
[21.06.2025 01:49:50.119]    <50>    Info (4)            [AP] (aead5e41) output: 68
[21.06.2025 01:53:37.566]    <67>    Info (4)            [AP] (aead5e41) output: 73
[21.06.2025 01:53:38.581]    <69>    Info (4)            [AP] (aead5e41) output: 75
[21.06.2025 01:53:53.875]    <30>    Info (4)            [AP] (aead5e41) output: 76
[21.06.2025 01:54:16.606]    <04>    Info (4)            [AP] (aead5e41) output: 77
[21.06.2025 01:54:19.902]    <04>    Info (4)            [AP] (aead5e41) output: 80
[21.06.2025 01:54:21.027]    <69>    Info (4)            [AP] (aead5e41) output: 83
[21.06.2025 01:54:48.788]    <04>    Info (4)            [AP] (aead5e41) output: 84
[21.06.2025 01:57:23.744]    <66>    Info (4)            [AP] (aead5e41) output: 85
[21.06.2025 01:57:24.744]    <70>    Info (4)            [AP] (aead5e41) output: 86
[21.06.2025 02:00:05.997]    <37>    Info (4)            [AP] (aead5e41) output: <VCPCommandResult result="true" exception="" />
[21.06.2025 02:00:05.997]    <37>    Info (4)            [AP] (aead5e41) output: <VCPCommandArgs><Item key="CheckpointId" type="EUInt64" value="1009" /><Item key="Owner.Description" type="EString" value="DL380-BK" /><Item key="Owner.Exists" type="EBoolean" value="true" /><Item key="Owner.Id" type="EString" value="{9797a14b-5e9e-4c52-8053-306be4393e78}" /><Item key="Owner.Type" type="EString" value="VBR" /><Item key="Owner.UserData" type="EString" value="&lt;RepositoryState Signature=~=T3eZ0QajcTfpTuB44cgK4npy0y2NOh+p4m/gQCfmlWB8z88X/DMohJH68WbV6SDj8klzc9qCfRbL59pXQFzBFHtmQE+a4aXzYCDQBa3oyEz+txEz/7MsEp3T45Z7qE1J7ZNy3uGlxAvN0PwjvhXDQb6+Agda4aFl24Tj2uH8r5amZvLSOUQ4jck7tklpLrnOJcIzt7G5bCXjAm5Y6Y+mHIKisK8CbKsTdSj8LJDirLd7b3R+ELrMwR8BdXX8k6WxCm+mRDVkX7Dp34C9PXNDHGuC4egzg8IANzXluJMx7sH37wQUHxt4uUTL5GrSB+BoNuASzNOdxsAv7y6/886b3A==~=&gt;&lt;RepositoryState Status=~=2~= IsFull=~=False~= RepositoryVersion=~=1~= GenerationInterval=~=10.00:00:00~=&gt;&lt;DirectBackupImmutabilitySettings HasImmutableCapacityOrArchiveTierExtent=~=False~= IsGovernanceMode=~=False~=&gt;&lt;ImmutabilitySettings IsEnabled=~=True~= IntervalDays=~=60~= /&gt;&lt;/DirectBackupImmutabilitySettings&gt;&lt;StorageEncryptionInfo Enabled=~=False~= /&gt;&lt;JobList /&gt;&lt;/RepositoryState&gt;&lt;/RepositoryState&gt;" /></VCPCommandArgs>
[21.06.2025 02:00:05.997]    <39>    Info (4)            [AP] (aead5e41) output: >
[21.06.2025 02:00:05.997]    <46>    Info (3)    [DirectBackupExtension] SetLatestCheckpoint ExtentId: 69fe5555-8cf5-442a-9d2f-356a7d7a0f70, BackupId: 50cce671-9d22-440b-b760-46614307f065, LatestCheckpoint: 1009, UsedSize: 4415468857326,GenerationExpirationDateUtc: 2025/06/29 17:06:57, GenerationImmutableTillUtc: 2025/08/28 17:06:57
[21.06.2025 02:00:05.997]    <46>    Info (3)    Created CCloudBackupEmptyLocker
When I checked this with Veeam support (Case # 07740686), Veeam support was told that the backup copy job keeps the source backup locked during the immutability period extension process in order to analyze the chain structure of the source backup.

Is this true?

After analyzing the chain structure of the source backup and unlocking the source backup, is it possible to extend the immutability period without locking the source backup?

Also, if I could adjust the days of the week for this immutability extension process, I think I could avoid the error by not running the backup job on those days.

Is it possible to specify the day of the week as well as the interval?
https://www.veeam.com/kb4470

In addition, the backup job fails after checking the vib lock five times every 10 minutes.
Is there a way to change the number of retries or the interval?

Thank you in advance for your insights.
david.domask
Veeam Software
Posts: 2863
Liked: 657 times
Joined: Jun 28, 2016 12:12 pm
Contact:

Re: Backup copy job takes too long to generate blocks, causing source backup job to fail

Post by david.domask »

Hi Yukinobu,

Thank you very much for the detailed description and sorry to hear about the challenges. I can see the case is still on-going, so I ask you please continue with the Support Team on the investigation. If there are concerns about the processing of the case, please use the Talk to a Manager button from the case portal; this will connect you with Support Management who will review the case and adjust resources as required.

As for the issue itself, I'm not confident it's about the immutability extension alone; from your logs there, I see "Waiting for Completion" and some pretty long waits, which usually indicates insufficient resources on the server hosting the agents or potential outside interference (read: anti-virus typically). Support will review the situation a bit more closely and continue the investigation as such job schedule shuffling shouldn't be required.

A note however on QNAP S3, as you found in the topic you linked, many users have had a variety of experiences with QNAP, some of them better than others. Note the advised QNAP update and tested hardware configuration for the QNAP and compare it with your client's model, as a lesser hardware configuration will not be able to perform as well as what was tested with Veeam.
David Domask | Product Management: Principal Analyst
Post Reply

Who is online

Users browsing this forum: No registered users and 6 guests