`forget: prune` on copied repositories results results in exit status 1, leaving a stale lock on remote repository

[jshank]

Describe the bug
Using configuration option forget: prune for a backup that uses copy results in an exit status 1 when collecting packs for deletion and repacking

Expected behavior
Pruning is done on the primary repository and then copied to the other repository without error

Environment

• OS: Ubuntu 22.04.5 LTS
• Version: autorestic version 1.8.3

Additional context
I've been using autorestic successfully for many years and recently reconfigured several locations to use copy instead of multiple repositories. My understanding is that all operations are done on the fast/local repository and then copied to slower/remote locations. This worked fine for a few weeks but has recently started failing during the step collecting packs for deletion and repacking which eventually leads to an exit status 1 and leaves the lock in place on the remote repository, causing all remaining backups to fail due to that stale lock. This could be due to the change from normal repository to copy.

For backend "zeus" #<--- this is now a copy repository and was a normal one before
> Executing: /usr/local/bin/restic --cache-dir /mnt/fastnvme/restic/cache forget --tag ar:location:grocy_configs --prune --keep-last 5 --keep-monthly 12 --keep-yearly 7 --keep-daily 4 --keep-within 14d --keep-weekly 1
Applying Policy: keep 5 latest, 4 daily, 1 weekly, 12 monthly, 7 yearly snapshots and all snapshots within 14d of the newest
keep 25 snapshots:
ID        Time                 Host        Tags                               Reasons           Paths                            Size
--------------------------------------------------------------------------------------------------------------------------------------------
4d9e0078  2023-08-07 16:43:52  myhost.tld  ar:location:grocy_configs          yearly snapshot   /mnt/fastnvme/docker-data/grocy
6de0afc4  2023-12-31 02:08:51  myhost.tld  ar:cron,ar:location:grocy_configs  yearly snapshot   /mnt/fastnvme/docker-data/grocy
d80e4fee  2024-06-30 02:05:01  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
774caccb  2024-07-31 02:08:54  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
b9adfb95  2024-08-31 02:09:22  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
d8a7191f  2024-09-30 02:07:09  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
419b1b5d  2024-10-31 02:15:33  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
d2e2325a  2024-11-30 02:13:18  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
b18c7c43  2024-12-31 02:18:19  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
                                                                              yearly snapshot
34ac7771  2025-01-31 02:18:59  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy
cbc2e032  2025-02-28 03:17:30  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy  119.151 MiB
7d874736  2025-03-31 02:20:57  myhost.tld  ar:cron,ar:location:grocy_configs  monthly snapshot  /mnt/fastnvme/docker-data/grocy  121.759 MiB
f064254b  2025-04-19 02:19:36  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  128.386 MiB
0bb9d07f  2025-04-20 02:06:13  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  127.425 MiB
58947e0f  2025-04-21 02:05:01  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  127.836 MiB
955d3a53  2025-04-22 02:55:42  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  128.879 MiB
d786b62c  2025-04-23 02:56:03  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  128.964 MiB
ec1455e1  2025-04-24 02:39:30  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  129.074 MiB
9116e528  2025-04-25 02:05:01  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  129.917 MiB
a00f0dc0  2025-04-26 02:24:57  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  130.297 MiB
1c46c59c  2025-04-27 02:39:15  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  124.817 MiB
                                                                              last snapshot
f766f508  2025-04-28 02:05:57  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  126.013 MiB
                                                                              last snapshot
                                                                              daily snapshot
da0052cf  2025-04-29 02:05:01  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  126.141 MiB
                                                                              last snapshot
                                                                              daily snapshot
59c9a7d6  2025-04-30 02:05:34  myhost.tld  ar:cron,ar:location:grocy_configs  within 14d        /mnt/fastnvme/docker-data/grocy  126.150 MiB
                                                                              last snapshot
                                                                              daily snapshot
                                                                              monthly snapshot
47a82ff2  2025-05-02 08:22:27  myhost.tld  ar:location:grocy_configs          within 14d        /mnt/fastnvme/docker-data/grocy  126.229 MiB
                                                                              last snapshot
                                                                              daily snapshot
                                                                              weekly snapshot
                                                                              monthly snapshot
                                                                              yearly snapshot
--------------------------------------------------------------------------------------------------------------------------------------------
25 snapshots

remove 4 snapshots:
ID        Time                 Host        Tags                               Paths                            Size
--------------------------------------------------------------------------------------------------------------------------
6b7036bc  2024-05-31 02:08:21  myhost.tld  ar:cron,ar:location:grocy_configs  /mnt/fastnvme/docker-data/grocy
7a816daf  2025-04-16 02:11:28  myhost.tld  ar:cron,ar:location:grocy_configs  /mnt/fastnvme/docker-data/grocy  126.262 MiB
34db2ad4  2025-04-17 02:33:57  myhost.tld  ar:cron,ar:location:grocy_configs  /mnt/fastnvme/docker-data/grocy  126.613 MiB
a92e3b4f  2025-04-18 02:14:42  myhost.tld  ar:cron,ar:location:grocy_configs  /mnt/fastnvme/docker-data/grocy  127.596 MiB
--------------------------------------------------------------------------------------------------------------------------
4 snapshots

[0:00] 100.00%  4 / 4 files deleted
4 snapshots have been removed, running prune
loading indexes...
loading all snapshots...
finding data that is still in use for 769 snapshots
[0:36] 100.00%  769 / 769 snapshots
searching used packs...
collecting packs for deletion and repacking
[15:03] 0.00%  0 / 20414 packs processed
exit status 1

[dcelasun]

I have a similar situation, just with exit code 127. Removing forget: prune or using forget: "yes" exits with 0. Config:

version: 2
locations:
  home:
    from:
    - /home/example
    to:
    - nas
    hooks:
      prevalidate:
        - "sh prepare.sh"
      success:
        - "./notify success"
      failure:
        - "./notify error"
    forget: prune
    options:
      forget:
        keep-daily: 7
        keep-weekly: 4
        keep-monthly: 6
        keep-yearly: 3

Failing run:

$ autorestic backup -av -c .autorestic.yml
Using config:    /tmp/example/.autorestic.yml
Using env:       /tmp/example/.autorestic.env
Using lock:      .autorestic.lock.yml


    Backing up location "home"


Running hooks
> sh prepare.sh
> Executing: /usr/bin/bash -c sh prepare.sh

Backend: nas
> Executing: /usr/bin/restic backup --exclude /lots/of/paths --tag ar:location:home /home/example
using parent snapshot 855b5264

Files:           1 new,    81 changed, 713489 unmodified
Dirs:            0 new,    64 changed, 162295 unmodified
Added to the repository: 61.911 MiB (23.645 MiB stored)

processed 713571 files, 64.069 GiB in 0:14
snapshot 04b8e4ec saved

Running hooks
> ./notify success
> Executing: /usr/bin/bash -c ./notify success



  Forgetting for location "home"

For backend "nas"
> Executing: /usr/bin/restic forget --tag ar:location:home --prune --keep-monthly 6 --keep-yearly 3 --keep-daily 7 --keep-weekly 4
Applying Policy: keep 7 daily, 4 weekly, 6 monthly, 3 yearly snapshots
keep 15 snapshots:
ID        Time                 Host        Tags              Reasons                 Paths           Size
----------------------------------------------------------------------------------------------------------------
d99cf4ca  2025-03-22 11:29:23  dccpc       ar:location:home  oldest yearly snapshot  /home/example  80.271 GiB
b27f331d  2025-05-31 02:16:06  dccpc       ar:location:home  monthly snapshot        /home/example  102.704 GiB
520ed2c9  2025-06-30 08:04:42  dccpc       ar:location:home  monthly snapshot        /home/example  64.387 GiB
ad0c2e04  2025-07-31 06:49:40  dccpc       ar:location:home  monthly snapshot        /home/example  70.070 GiB
2ea71759  2025-08-31 11:08:10  dccpc       ar:location:home  monthly snapshot        /home/example  72.116 GiB
926d3e4d  2025-09-28 06:34:50  dccpc       ar:location:home  weekly snapshot         /home/example  76.866 GiB
8610a185  2025-09-30 08:47:00  dccpc       ar:location:home  monthly snapshot        /home/example  77.000 GiB
57281547  2025-10-05 06:37:30  dccpc       ar:location:home  weekly snapshot         /home/example  77.071 GiB
0ef109ce  2025-10-12 08:01:50  dccpc       ar:location:home  daily snapshot          /home/example  85.223 GiB
                                                             weekly snapshot
49d70c5b  2025-10-13 07:10:30  dccpc       ar:location:home  daily snapshot          /home/example  85.229 GiB
39576a91  2025-10-14 06:36:14  dccpc       ar:location:home  daily snapshot          /home/example  85.367 GiB
b27bc880  2025-10-15 07:05:49  dccpc       ar:location:home  daily snapshot          /home/example  85.577 GiB
26ca68da  2025-10-16 08:18:02  dccpc       ar:location:home  daily snapshot          /home/example  86.088 GiB
ecc3dce7  2025-10-17 07:03:48  dccpc       ar:location:home  daily snapshot          /home/example  86.118 GiB
04b8e4ec  2025-10-18 11:53:05  dccpc       ar:location:home  daily snapshot          /home/example  64.069 GiB
                                                             weekly snapshot
                                                             monthly snapshot
                                                             yearly snapshot
----------------------------------------------------------------------------------------------------------------
15 snapshots

remove 1 snapshots:
ID        Time                 Host        Tags              Paths           Size
---------------------------------------------------------------------------------------
855b5264  2025-10-18 11:47:20  dccpc       ar:location:home  /home/example  64.069 GiB
---------------------------------------------------------------------------------------
1 snapshots

[0:00] 100.00%  1 / 1 files deleted
1 snapshots have been removed, running prune
loading indexes...
loading all snapshots...
finding data that is still in use for 15 snapshots
[0:09] 100.00%  15 / 15 snapshots
searching used packs...
collecting packs for deletion and repacking
[0:01] 100.00%  4738 / 4738 packs processed

to repack:         16535 blobs / 31.542 MiB
this removes:        111 blobs / 14.588 MiB
to delete:             0 blobs / 0 B
total prune:         111 blobs / 14.588 MiB
remaining:       1355222 blobs / 76.333 GiB
unused size after prune: 3.815 GiB (5.00% of remaining size)

repacking packs
[0:02] 100.00%  3 / 3 packs repacked
rebuilding index
[0:00] 100.00%  28 / 28 indexes processed
[0:00] 100.00%  6 / 6 old indexes deleted
removing 3 old packs
[0:00] 100.00%  3 / 3 files deleted
done
Done
exit status 127

Error: 1 errors were found