Error Log Remote

[petrhud]

Hello,
I sometimes get this message and I don't know why: "Error Log
Remote: Warning: Permanently added 'backup.domain.com' (ED25519) to the list of known hosts.
Failed to create/acquire the lock /var/bbs/home/30/freebsd/lock.exclusive (timeout)." The job won't run because of this.
Thanks for the info, Petr.

[marcpope]

@petrhud
That means the repo you are backing up is busy with some other process. Are you mounting your repo or something? You can break the lock by clicking the repo in the interface if you are sure you aren't running any other commands against it. If you are not, then this could be a bug but I haven't seen that happen before. Can you show a few lings of log of what the repo did before you tried the backup?

[petrhud]

Thank you. I'm not doing anything with the repository. Several backups have completed without any issues. This has happened to me several times. If it happens again, I'll send you the log information.

I just checked the log and saw this: PHP Warning:

Undefined variable $dayStart in /var/www/bbs/src/Services/ReportService.php on line 104
PHP Warning: Undefined variable $dayEnd in /var/www/bbs/src/Services/ReportService.php on line 104
PHP Warning: is_dir(): Unable to find the wrapper "ssh" - did you forget to enable it when you configured PHP? in /var/www/bbs/scheduler.php on line 173
PHP Warning: is_dir(): Unable to find the wrapper "ssh" - did you forget to enable it when you configured PHP? in /var/www/bbs/scheduler.php on line 173
PHP Warning: is_dir(): Unable to find the wrapper "ssh" - did you forget to enable it when you configured PHP? in /var/www/bbs/scheduler.php on line 173
PHP Warning: Undefined variable $dayStart in /var/www/bbs/src/Services/ReportService.php on line 104
PHP Warning: Undefined variable $dayEnd in /var/www/bbs/src/Services/ReportService.php on line 104

Translated with DeepL.com (free version)

[petrhud]

Once again, the job finished without any errors. But the subsequent job that ran ended with the error: "Remote: Warning: Permanently added 'backup.domain.com' (ED25519) to the list of known hosts.
Failed to create/acquire the lock /var/bbs/home/30/backup_server/lock.exclusive (timeout)." Removing the lock on the repository will resolve the issue. This only happens with one repository.

[marcpope]

Two fixes coming in the next release:

1. PHP warnings fixed:

• is_dir() was being called on SSH-format repo paths (ssh://user@host/./repo) which PHP doesn't understand as a filesystem path. Now uses the proper local path resolver.
• $dayStart/$dayEnd undefined variables in ReportService — now properly initialized.

2. Lock timeout:
The lock error means a previous borg operation (likely prune or compact) didn't release the lock before the next backup started. This can happen when prune runs slow on large repos. If it keeps happening on the same repo, let us know — we can look at the job timing to see if operations are overlapping.

[petrhud]

The same error again, but in a different repository.

[bbs-scheduler.log](https://github.com/user-attachments/files/26533896/bbs-scheduler.log)

[petrhud]

2026-04-04 08:17:01 Executing server-side: job #408 (break_lock)
2026-04-04 08:17:02 Server-side break_lock job #408: completed
2026-04-04 08:19:01 Sent: job #409 (backup) to agent #30
2026-04-04 08:22:01 Executing server-side: job #410 (prune)
2026-04-04 08:22:11 Server-side prune job #410: completed
2026-04-04 08:25:01 Executing server-side: job #412 (prune)
2026-04-04 08:25:07 Server-side prune job #412: completed
2026-04-04 08:25:08 Removed 1 pruned archive(s) from DB for repo #43
2026-04-04 08:32:02 Executing server-side: job #414 (prune)
2026-04-04 08:32:08 Server-side prune job #414: completed
2026-04-04 08:32:09 Removed 1 pruned archive(s) from DB for repo #43
2026-04-04 08:45:01 Marked 2 agent(s) offline (no heartbeat in 90s)
2026-04-04 08:55:01 Marked 1 agent(s) offline (no heartbeat in 90s)
2026-04-04 08:56:01 Marked 2 agent(s) offline (no heartbeat in 90s)
2026-04-04 17:39:02 Borg version sync: 0 new versions added
2026-04-04 19:04:02 Purged 1 server log entries older than 30 days
2026-04-04 19:15:02 Purged 5 server log entries older than 30 days
2026-04-04 19:22:01 Purged 1 server log entries older than 30 days
2026-04-04 19:23:01 Purged 4 server log entries older than 30 days
2026-04-04 19:24:01 Purged 2 server log entries older than 30 days
2026-04-04 19:29:01 Purged 2 server log entries older than 30 days
2026-04-04 19:30:02 Purged 2 server log entries older than 30 days
2026-04-04 19:31:01 Purged 1 server log entries older than 30 days
2026-04-04 19:34:02 Purged 1 server log entries older than 30 days
2026-04-04 19:35:02 Purged 4 server log entries older than 30 days
2026-04-04 19:40:02 Purged 4 server log entries older than 30 days
2026-04-04 19:41:01 Purged 1 server log entries older than 30 days
2026-04-04 19:46:01 Self-backup completed
2026-04-04 20:00:01 Queued: server_5 (job #415, agent #10)
2026-04-04 20:00:01 Queued: server_4 (job #416, agent #11)
2026-04-04 20:00:01 Queued: server_3 (job #417, agent #12)
2026-04-04 20:00:01 Queued: server_2 (job #418, agent #28)
2026-04-04 20:00:01 Queued: server_1 (job #419, agent #30)
2026-04-04 20:00:01 Sent: job #415 (backup) to agent #10
2026-04-04 20:00:01 Sent: job #416 (backup) to agent #11
2026-04-04 20:00:01 Sent: job #417 (backup) to agent #12
2026-04-04 20:00:01 Sent: job #418 (backup) to agent #28
2026-04-04 20:18:01 Executing server-side: job #420 (prune)
2026-04-04 20:18:03 Server-side prune job #420: completed
2026-04-04 20:18:04 Cleaned up 2 imported catalog log file(s)
2026-04-04 22:08:01 Executing server-side: job #421 (prune)
2026-04-04 22:08:13 Server-side prune job #421: completed
2026-04-05 00:16:01 Executing server-side: job #422 (prune)
2026-04-05 00:16:37 Server-side prune job #422: completed
2026-04-05 02:05:01 Auto-queued catalog_rebuild for repo #43 (missing archives in ClickHouse)
2026-04-05 02:05:01 Sent: job #423 (catalog_rebuild) to agent #30
2026-04-05 02:05:01 Executing server-side: job #423 (catalog_rebuild)
2026-04-05 02:05:01 Catalog rebuild job #423: starting for "server_1"
2026-04-05 02:05:02 Catalog rebuild job #423: synced 1 new archives from borg
2026-04-05 02:05:02 Catalog rebuild job #423: 22 recovery points found
2026-04-05 02:05:02 Catalog rebuild job #423: 2 of 22 archives need indexing
2026-04-05 02:05:03 Catalog rebuild 1/2: plan43-2026-03-23_13-49-22 (0 files)
2026-04-05 02:05:18 Catalog rebuild 2/2: plan43-2026-04-04_20-14-53 (247179 files)
2026-04-05 02:05:18 Catalog rebuild job #423 completed: 2 archives, 247179 files
2026-04-05 08:34:01 Executing server-side: job #426 (prune)
2026-04-05 08:34:17 Server-side prune job #426: completed
2026-04-05 08:41:01 Executing server-side: job #427 (break_lock)
2026-04-05 08:41:02 Server-side break_lock job #427: completed
2026-04-05 17:40:03 Borg version sync: 0 new versions added
2026-04-05 19:47:02 Self-backup completed
2026-04-05 20:00:01 Queued: server_5 (job #428, agent #10)
2026-04-05 20:00:01 Queued: server_4 (job #429, agent #11)
2026-04-05 20:00:01 Queued: server_3 (job #430, agent #12)
2026-04-05 20:00:01 Queued: server_2 (job #431, agent #28)
2026-04-05 20:00:01 Queued: server_1 (job #432, agent #30)
2026-04-05 20:00:01 Sent: job #428 (backup) to agent #10
2026-04-05 20:00:01 Sent: job #429 (backup) to agent #11
2026-04-05 20:00:01 Sent: job #430 (backup) to agent #12
2026-04-05 20:00:01 Sent: job #431 (backup) to agent #28
2026-04-05 20:01:01 Sent: job #432 (backup) to agent #30
2026-04-05 20:02:01 Executing server-side: job #433 (prune)
2026-04-05 20:02:07 Server-side prune job #433: completed
2026-04-05 20:02:08 Executing server-side: job #434 (prune)
2026-04-05 20:02:11 Server-side prune job #434: completed
2026-04-05 20:02:13 Cleaned up 1 imported catalog log file(s)
2026-04-05 20:03:01 Executing server-side: job #435 (prune)
2026-04-05 20:03:09 Server-side prune job #435: completed
2026-04-05 20:16:01 Executing server-side: job #436 (prune)
2026-04-05 20:16:25 Server-side prune job #436: completed
2026-04-06 01:20:01 Marked 2 agent(s) offline (no heartbeat in 90s)
2026-04-06 02:06:01 Auto-queued catalog_rebuild for repo #43 (missing archives in ClickHouse)
2026-04-06 02:06:01 Sent: job #437 (catalog_rebuild) to agent #30
2026-04-06 02:06:01 Executing server-side: job #437 (catalog_rebuild)
2026-04-06 02:06:01 Catalog rebuild job #437: starting for "server_1"
2026-04-06 02:06:02 Catalog rebuild job #437: synced 1 new archives from borg
2026-04-06 02:06:02 Catalog rebuild job #437: 23 recovery points found
2026-04-06 02:06:02 Catalog rebuild job #437: 2 of 23 archives need indexing
2026-04-06 02:06:03 Catalog rebuild 1/2: plan43-2026-03-23_13-49-22 (0 files)
2026-04-06 02:06:17 Catalog rebuild 2/2: plan43-2026-04-05_20-01-10 (247168 files)
2026-04-06 02:06:17 Catalog rebuild job #437 completed: 2 archives, 247168 files
2026-04-06 04:44:02 Update available: v2.23.0 (current: v2.22.1)
2026-04-06 05:03:01 Purged 1 server log entries older than 30 days
2026-04-06 05:04:01 Purged 1 server log entries older than 30 days
2026-04-06 05:06:01 Purged 5 server log entries older than 30 days
2026-04-06 12:34:01 Executing server-side: job #438 (break_lock)
2026-04-06 12:34:02 Server-side break_lock job #438: completed
2026-04-06 13:53:01 Update available: v2.24.0 (current: v2.23.0)
2026-04-06 14:54:01 Update available: v2.24.0 (current: v2.23.0)
2026-04-06 15:55:02 Update available: v2.24.0 (current: v2.23.0)
2026-04-06 15:57:01 Auto-update: queued agent updates for 5 client(s) to v2.23.0
2026-04-06 17:41:03 Borg version sync: 0 new versions added
2026-04-06 19:48:01 Self-backup completed
2026-04-06 20:00:01 Queued: server_5 (job #444, agent #10)
2026-04-06 20:00:01 Queued: server_4 (job #445, agent #11)
2026-04-06 20:00:01 Queued: server_3 (job #446, agent #12)
2026-04-06 20:00:01 Queued: server_2 (job #447, agent #28)
2026-04-06 20:00:01 Queued: server_1 (job #448, agent #30)
2026-04-06 20:00:01 Sent: job #444 (backup) to agent #10
2026-04-06 20:00:01 Sent: job #445 (backup) to agent #11
2026-04-06 20:00:01 Sent: job #446 (backup) to agent #12
2026-04-06 20:00:01 Sent: job #447 (backup) to agent #28
2026-04-06 20:01:02 Cleaned up 1 imported catalog log file(s)
2026-04-06 20:02:01 Executing server-side: job #449 (prune)
2026-04-06 20:02:04 Server-side prune job #449: completed
2026-04-06 20:03:01 Executing server-side: job #450 (prune)
2026-04-06 20:03:11 Server-side prune job #450: completed
2026-04-06 20:03:12 Executing server-side: job #451 (prune)
2026-04-06 20:03:25 Server-side prune job #451: completed
2026-04-06 20:16:01 Executing server-side: job #452 (prune)
2026-04-06 20:16:25 Server-side prune job #452: completed
2026-04-07 02:07:01 Auto-queued catalog_rebuild for repo #43 (missing archives in ClickHouse)
2026-04-07 02:07:01 Sent: job #453 (catalog_rebuild) to agent #30
2026-04-07 02:07:01 Executing server-side: job #453 (catalog_rebuild)
2026-04-07 02:07:01 Catalog rebuild job #453: starting for "server_1"
2026-04-07 02:07:02 Catalog rebuild job #453: 24 recovery points found
2026-04-07 02:07:02 Catalog rebuild job #453: 1 of 24 archives need indexing
2026-04-07 02:07:03 Catalog rebuild 1/1: plan43-2026-03-23_13-49-22 (0 files)
2026-04-07 02:07:03 Catalog rebuild job #453 completed: 1 archives, 0 files
2026-04-07 08:42:01 Purged 2 server log entries older than 30 days
2026-04-07 08:43:01 Purged 4 server log entries older than 30 days
2026-04-07 08:46:02 Purged 1 server log entries older than 30 days
2026-04-07 08:47:01 Purged 6 server log entries older than 30 days
2026-04-07 08:48:01 Purged 1 server log entries older than 30 days
2026-04-07 08:50:02 Purged 4 server log entries older than 30 days
2026-04-07 08:54:02 Purged 1 server log entries older than 30 days
2026-04-07 08:55:02 Purged 4 server log entries older than 30 days

[petrhud]

It's always the same error. It's happening on two servers. Both servers are running as Samba servers, and there are a lot of files—tens of gigabytes.

[petrhud]

I have the latest version installed. When I launch it, I get a new error.

[petrhud]

Some of the recent updates fixed the problem. Now everything is working again. Thank you, Petr.

[petrhud]

So the ED25519 error has occurred again.

[petrhud]

It backed up for three days without a problem. Today the error:

Backup failed for plan "server_alfa" on client "server_alfa" — Remote: Warning: Permanently added 'server.alfa.cz' (ED25519) to the list of known hosts.
Failed to release the lock /.cache/borg/049c408ee38730a73d658cee15f378d6e367910a8ee1740dd59a1a546c4b7b5e/lock.exclusive (was not locked).
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/borg/archiver.py", line 5759, in main
    exit_code = archiver.run(args)
                ^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/borg/archiver.py", line 5677, in run
    rc = func(args)
         ^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/borg/archiver.py", line 200, in wrapper
    return method(self, args, repository=repository, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/borg/archiver.py", line 677, in do_create
    with Cache(repository, key, manifest, progress=args.progress,
  File "/usr/local/lib/python3.11/site-packages/borg/cache.py", line 523, in exit
    self.close()
  File "/usr/local/lib/python3.11/site-packages/borg/cache.py", line 565, in close
    self.cache_config.close()
  File "/usr/local/lib/python3.11/site-packages/borg/cache.py", line 324, in close
    self.lock.release()
  File "/usr/local/lib/python3.11/site-packages/borg/locking.py", line 431, in release
    self._lock.release()
  File "/usr/local/lib/python3.11/site-packages/borg/locking.py", line 173, in release
    raise NotLocked(self.path)
borg.locking.NotLocked: Failed to release the lock /.cache/borg/049c408ee38730a73d658cee15f378d6e367910a8ee1740dd59a1a546c4b7b5e/lock.exclusive (was not locked).

Platform: FreeBSD server.alfa.cz 15.0-RELEASE FreeBSD 15.0-RELEASE releng/15.0-n280995-7aedc8de6446 GENERIC amd64
Borg: 1.4.4  Python: CPython 3.11.14 msgpack: 1.1.2 fuse: llfuse 1.5.2 [pyfuse3,llfuse]
PID: 9871  CWD: /
sys.argv: ['/usr/local/bin/borg', 'create', '--json', '--log-json', '--list', '--progress', '--lock-wait=600', 'ssh://bbs-server_alfa@backup.server.cz/./server_alfa::plan44-2026-04-26_20-01-15', '/etc', '/home', '/root', '/usr/local/etc', '/usr/local/virtual', '/usr/local/www', '/var/log']
SSH_ORIGINAL_COMMAND: None

[marcpope]

moving this to issues.