Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock"

[RiHe]

We noticed backups failing due to the reason:
Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock"

We got a similar error (only at random times) as this thread: https://forum.proxmox.com/threads/b...-log-proxmox-backup-tasks-active-lock.183852/

Only for us it is not always at midnight (although also the case), but also when there are a lot of backups running.
Our setup is a big PBS with 600 datastores and users, and thus a lot of backups made.
So it is logical because of the locking happening when logging, but not desirable.


Some timestamps from our pbs001:

2026-06-02T21:07:26.040726+02:00 pbs001 proxmox-backup-proxy[7318]: Upload backup log to datastore 'Backup', root namespace vm/136/2026-06-02T19:05:46Z/client.log.blob
2026-06-02T21:07:27.101426+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/backup?backup-id=172&backup-time=1780427229&backup-type=vm&benchmark=false&debug=false&store=Backup: 400 Bad Request: [client [proxmox06]:58540] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-02T21:07:27.101768+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/backup?backup-id=158&backup-time=1780427229&backup-type=vm&benchmark=false&debug=false&store=Backup: 400 Bad Request: [client [proxmox01]:34536] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-02T21:07:29.845921+02:00 pbs001 proxmox-backup-proxy[7318]: Upload backup log to datastore 'Backup', root namespace vm/141/2026-06-02T19:07:26Z/client.log.blob

It is clear here that the backups happen too close together from different Proxmox nodes (notice I put proxmox06 and proxmox01 as IP)

proxmox06:

2026-06-02T21:07:09.119306+0200 proxmox06 pvescheduler[2451285]: INFO: Starting Backup of VM 172 (qemu)
2026-06-02T21:07:27.104441+0200 proxmox06 pvescheduler[2451285]: VM 172 qmp command failed - VM 172 qmp command 'backup' failed - backup connect failed: command error: Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-02T21:07:27.125829+0200 proxmox06 pvescheduler[2451285]: ERROR: Backup of VM 172 failed - VM 172 qmp command 'backup' failed - backup connect failed: command error: Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-02T21:07:27.126389+0200 proxmox06 pvescheduler[2451285]: INFO: Starting Backup of VM 174 (qemu)

proxmox01:

2026-06-02T21:07:09.191579+0200 proxmox01 pvescheduler[4023060]: INFO: Starting Backup of VM 158 (qemu)
2026-06-02T21:07:27.107185+0200 proxmox01 pvescheduler[4023060]: VM 158 qmp command failed - VM 158 qmp command 'backup' failed - backup connect failed: command error: Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-02T21:07:27.173078+0200 proxmox01 pvescheduler[4023060]: ERROR: Backup of VM 158 failed - VM 158 qmp command 'backup' failed - backup connect failed: command error: Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-02T21:07:27.174546+0200 proxmox01 pvescheduler[4023060]: INFO: Starting Backup of VM 159 (qemu)

Also interesting: we are seeing a lot of "error writing task result to the tasklog" arround 00:00:15 every night (is this the logrotate lock?):

...
2026-06-03T00:00:17.200466+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:17.204251+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:17.206101+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:17.683117+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:17.831324+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/reader?backup-id=102&backup-time=1771642388&backup-type=ct&debug=true&store=Datastore1: 400 Bad Request: [client [client1]:45926] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-03T00:00:17.831614+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/reader?backup-id=100&backup-time=1780432204&backup-type=ct&debug=true&store=Datastore2: 400 Bad Request: [client [client2]:59426] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-03T00:00:17.834885+02:00 pbs001 proxmox-backup-proxy[7318]: unable to start garbage collection job on datastore Datastore3 - Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-03T00:00:17.835861+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/backup?backup-id=pve4&backup-time=1780437601&backup-type=host&benchmark=false&debug=true&store=Datastore4: 400 Bad Request: [client [client3]:57552] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
...
2026-06-03T00:00:32.944562+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:33.178846+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:33.272093+02:00 pbs001 proxmox-backup-proxy[7318]: error writing task result to the tasklog
2026-06-03T00:00:33.887459+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/reader?backup-id=103&backup-time=1771632001&backup-type=ct&debug=true&store=Datastore1: 400 Bad Request: [client [client1]:45926] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
2026-06-03T00:00:33.888545+02:00 pbs001 proxmox-backup-proxy[7318]: GET //api2/json/reader?backup-id=103&backup-time=1780360281&backup-type=ct&debug=true&store=Datastore2: 400 Bad Request: [client [client2]:59426] Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
...

PBS version:

proxmox-backup-manager version --verbose
proxmox-backup                      4.2.0         running kernel: 7.0.0-3-pve
proxmox-backup-server               4.2.0-1       running version: 4.2.0
proxmox-kernel-helper               9.2.0
proxmox-kernel-7.0                  7.0.6-2
proxmox-kernel-7.0.0-3-pve-signed   7.0.0-3
proxmox-kernel-6.17                 6.17.13-13
proxmox-kernel-6.17.13-6-pve-signed 6.17.13-6
proxmox-kernel-6.17.13-2-pve-signed 6.17.13-2
proxmox-kernel-6.14                 6.14.11-9
proxmox-kernel-6.14.11-7-pve-signed 6.14.11-7
proxmox-kernel-6.14.11-6-pve-signed 6.14.11-6
proxmox-kernel-6.14.11-2-pve-signed 6.14.11-2
proxmox-kernel-6.8                  6.8.12-15
proxmox-kernel-6.8.12-15-pve-signed 6.8.12-15
proxmox-kernel-6.8.12-13-pve-signed 6.8.12-13
pve-kernel-5.13.19-2-pve            5.13.19-4
ifupdown2                           3.3.0-1+pmx12
libjs-extjs                         7.0.0-5
proxmox-backup-docs                 4.2.0-1
proxmox-backup-client               4.2.0-1
proxmox-mail-forward                unknown
proxmox-mini-journalreader          1.6
proxmox-offline-mirror-helper       unknown
proxmox-widget-toolkit              5.2.2
pve-xtermjs                         6.0.0-1
smartmontools                       7.5-pve2
zfsutils-linux                      2.4.2-pve1

I found this bug talking about optimizing this: https://bugzilla.proxmox.com/show_bug.cgi?id=5960
Would it be possible to make it wait a few seconds for the lock instead of throwing an error?

 

[Chris]

Would it be possible to make it wait a few seconds for the lock instead of throwing an error?

There already is a 15 second timeout when acquiring the task lock [1] as also state in [2]. So instead of us blindly bumping the value, please share the full excerpt of the systemd journal from a larger timespan when the issue happens, that might help identify why the lock is so contested.

[1] https://git.proxmox.com/?p=proxmox....4e6876a0f998b742c43948bf6c3747af;hb=HEAD#l133
[2] https://bugzilla.proxmox.com/show_bug.cgi?id=5960.