Sync job fails for newly created snapshots

P

PolakPL2002

New Member
Jul 19, 2025
1
0
1
Hi,

I have a problem with a remote push sync task logging following error for new snapshots (still being backed up, created seconds ago):

Code: 
2025-07-19T08:00:03+02:00: Encountered errors: while reading snapshot 'BackupDir { store: "backup_pool", ns: BackupNamespace { inner: ["ext"], len: 3 }, dir: BackupDir { group: BackupGroup { ty: Host, id: "dc1" }, time: 1752904801 }, backup_time_string: "2025-07-19T06:00:01Z" }' for a sync job: unable to acquire shared snapshot lock "/run/proxmox-backup/locks/backup_pool/ext/host-dc1-2025\\x2d07\\x2d19T06\\x3a00\\x3a01Z": Unable to acquire lock "/run/proxmox-backup/locks/backup_pool/ext/host-dc1-2025\\x2d07\\x2d19T06\\x3a00\\x3a01Z" - Resource temporarily unavailable (os error 11)
2025-07-19T08:00:03+02:00: Failed to push group host/dc1 to remote!

I attach full logs of related tasks from the source machine. There are no anomalies in dmesg or journal:

Code: 
Jul 19 08:00:01 pve proxmox-backup-proxy[3184]: starting new backup on datastore 'backup_pool' from ::ffff:10.0.69.14: "ns/ext/host/rpi5/2025-07-19T06:00:01Z"
Jul 19 08:00:02 pve proxmox-backup-proxy[3184]: starting new backup on datastore 'backup_pool' from ::ffff:10.0.69.12: "ns/ext/host/dc1/2025-07-19T06:00:01Z"
Jul 19 08:00:04 pve proxmox-backup-proxy[3184]: TASK ERROR: Sync failed with some errors!
Jul 19 08:00:08 pve proxmox-backup-proxy[3184]: processed 562.504 GiB in 4d 5h 14m 9s, uploaded 536.563 GiB
Jul 19 08:00:25 pve proxmox-backup-proxy[3184]: processed 10.903 GiB in 6d 6h 31m 12s, uploaded 1.325 GiB
Jul 19 08:00:26 pve proxmox-backup-proxy[3184]: starting new backup on datastore 'backup_pool' from ::ffff:10.0.69.11: "ns/ext/host/<redacted>/2025-07-19T06:00:26Z"
Jul 19 08:00:32 pve proxmox-backup-proxy[3184]: processed 61.938 GiB in 6d 7h 39m 13s, uploaded 46.426 GiB
Jul 19 08:00:40 pve proxmox-backup-proxy[3184]: processed 50.004 GiB in 1w 23h 28m 15s, uploaded 34.758 GiB
Jul 19 08:00:44 pve proxmox-backup-proxy[3184]: processed 10.71 GiB in 3d 9h 31m 6s, uploaded 1004.247 MiB
Jul 19 08:00:51 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 1w 1d 16h 15m 15s, uploaded 4.966 MiB
Jul 19 08:00:51 pve proxmox-backup-proxy[3184]: processed 31.82 GiB in 4d 14h 43m 8s, uploaded 10.039 GiB

I am not exactly sure where the "processed" messages come from as there are no tasks running according to UI and proxmox-backup-manager. Those messages started after sync task was aborted in the UI. Not a single one was logged before this:

Code: 
Jul 10 15:44:55 pve proxmox-backup-proxy[3184]: TASK ERROR: Sync failed with some errors!
Jul 10 15:45:42 pve proxmox-backup-proxy[3184]: received abort request ...
Jul 10 15:45:42 pve proxmox-backup-proxy[3184]: TASK ERROR: sync aborted
Jul 10 15:46:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 1m, uploaded 4.966 MiB
Jul 10 15:47:20 pve proxmox-backup-proxy[3184]: processed 991.937 MiB in 1m, uploaded 673.432 MiB
Jul 10 15:47:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 2m, uploaded 4.966 MiB
Jul 10 15:47:56 pve proxmox-backup-proxy[3184]: rrd journal successfully committed (33 files in 0.007 seconds)
Jul 10 15:48:20 pve proxmox-backup-proxy[3184]: processed 1.379 GiB in 2m, uploaded 1.206 GiB
Jul 10 15:48:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 3m, uploaded 4.966 MiB
Jul 10 15:49:20 pve proxmox-backup-proxy[3184]: processed 1.826 GiB in 3m, uploaded 1.625 GiB
Jul 10 15:49:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 4m, uploaded 4.966 MiB
Jul 10 15:50:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 5m, uploaded 4.966 MiB
Jul 10 15:51:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 6m, uploaded 4.966 MiB
Jul 10 15:52:31 pve proxmox-backup-proxy[3184]: processed 319.377 MiB in 1m, uploaded 186.934 MiB
Jul 10 15:52:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 7m, uploaded 4.966 MiB
Jul 10 15:53:31 pve proxmox-backup-proxy[3184]: processed 753.107 MiB in 2m, uploaded 493.832 MiB
Jul 10 15:53:36 pve proxmox-backup-proxy[3184]: processed 255.216 MiB in 8m, uploaded 4.966 MiB


proxmox-backup-server 3.4.2-1 running version: 3.4.1

Is there any way I can fix those sync tasks failing (they succeed on next hourly run) in other way than manual schedule change? Thanks.
 

Attachments

Hi,
PolakPL2002 said:
2025-07-19T08:00:03+02:00: Encountered errors: while reading snapshot 'BackupDir { store: "backup_pool", ns: BackupNamespace { inner: ["ext"], len: 3 }, dir: BackupDir { group: BackupGroup { ty: Host, id: "dc1" }, time: 1752904801 }, backup_time_string: "2025-07-19T06:00:01Z" }' for a sync job: unable to acquire shared snapshot lock "/run/proxmox-backup/locks/backup_pool/ext/host-dc1-2025\\x2d07\\x2d19T06\\x3a00\\x3a01Z": Unable to acquire lock "/run/proxmox-backup/locks/backup_pool/ext/host-dc1-2025\\x2d07\\x2d19T06\\x3a00\\x3a01Z" - Resource temporarily unavailable (os error 11) 2025-07-19T08:00:03+02:00: Failed to push group host/dc1 to remote!
Click to expand...
this is expected, the backup snapshot for the ongoing backup cannot be locked for shared read access, because the backup job holds an exclusive lock for write access. Therefore this snapshot and any snapshot following it cannot be synced (as otherwise this could not be synced for the next run, as only newer snapshots can be synced).

The error message is however not very telling and should be improved upon. Please add this as comment to issue https://bugzilla.proxmox.com/show_bug.cgi?id=5956 so it is not forgotten.

Regarding the processed log lines, this is indeed a bug, while the progress status might be of interest for the sync job as well (it uses the same logic as the proxmox-backup-client used for host/container backups), the progress task should be aborted when the sync job is aborted. Please open an new issue at https://bugzilla.proxmox.com for this. For the time being I'm afraid you will have to restart the proxmox-backup.service and proxmox-backup-proxy.service to get rid of these.
 
  • Like
Reactions: Johannes S
Hi,

i have a similar error:
Code: 
2025-10-11T17:00:02+02:00: sync group vm/105 failed - while reading snapshot 'BackupDir { store: "xxx", ns: BackupNamespace { inner: [], len: 0 }, dir: BackupDir { group: BackupGroup { ty: Vm, id: "105" }, time: 1760194800 }, backup_time_string: "2025-10-11T15:00:00Z" }'
there was no other backup around that time so I don't think it's an lock issue (unless there are dead locks). A subsequent sync job worked just fine.
 
You must log in or register to reply here.
Top Bottom