Error on purge with 2.1.0.3_beta_2025-01-22

Support
1

Hi All,

I’ve got version 2.1.0.3_beta_2025-01-22 running on a linux host with a BackBlaze B2 bucket as the backup destination. On the previous version I was able to run a purge command to remove files from the backup set however, when I attempt it on this version I get the following:

sudo duplicati-cli purge "b2://duplicati-online-2024-05-11//backup?auth-username=XXXXXXXXXXXXXXXXXXXXXXXX&auth-password=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX" /media/media_backup/path/to/files/*.foo --dbpath=/root/.config/Duplicati/WKMJYKXPBR.sqlite --dry-run
[sudo] password for klucas: 

Enter encryption passphrase: **********
  Listing remote folder ...
The operation PurgeFiles has failed with error: Fileset was reported with id 1, but could not be found? => Fileset was reported with id 1, but could not be found?

System.InvalidProgramException: Fileset was reported with id 1, but could not be found?
   at Duplicati.Library.Main.Operation.PurgeFilesHandler.DoRun(LocalPurgeDatabase db, IFilter filter, Action`3 filtercommand, Single pgoffset, Single pgspan)
   at Duplicati.Library.Main.Operation.PurgeFilesHandler.Run(IFilter filter)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass36_0.<PurgeFiles>b__0(PurgeFilesResults result)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[x]& paths, IFilter& filter, Action`1 method)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, Action`1 method)
   at Duplicati.Library.Main.Controller.PurgeFiles(IFilter filter)
   at Duplicati.CommandLine.Commands.PurgeFiles(TextWriter outwriter, Action`1 setup, List`1 args, Dictionary`2 options, IFilter filter)
   at Duplicati.CommandLine.Program.ParseCommandLine(TextWriter outwriter, Action`1 setup, Boolean& verboseErrors, String[] args)
   at Duplicati.CommandLine.Program.RunCommandLine(TextWriter outwriter, TextWriter errwriter, Action`1 setup, String[] args)

Additionally, in the web GUI after I run this command I no longer see the fileset in the drop-down to restore from. I just took a new clean backup and confirmed that prior to running the above purge command I had a fileset there to restore from (ID appeared to be 0 in the GUI) and there were no others.

I’m starting to wonder if something might be up with the purge command looking for the non-existent ID ‘1’ in this case. Could this potentially be a bug or am I missing something in the purge command parameters?

Any help would be greatly appreciated.

Thanks in advance.

kev.

P.S. if there’s more info I can provide to help troubleshoot please let me know and I can see what I can do to provide it.

2

This might need developer comment, but meanwhile I can try to collect some more information.

How many versions do you have Backblaze B2 keep? This setting would be on Options screen.

Do /media/media_backup/path/to/files/*.foo exist, e.g. if you echo it for shell expansion?

I’m not sure that’s what you want, as what’s there now might differ from what’s in backup history.

Are there lots of other files in every backup version? I think deleting all files might delete version.

What fileset? Do you mean 1? What do you see? 0 only? 0 is always the latest version existing.

EDIT 1:

Was the backup before this a normal one, or are you trying to purge after an error (if so, detail)?

You are using a combination of CLI and GUI. Is GUI the usual way? It has a Commandline page, which will save you the trouble (and possible errors) of having to add the right options on the CLI.

3

Thanks for getting back to me. It’s quite late here at the moment and I’ve just gotten kiddo down for bed. I’ll get you the details tomorrow.

kev.

4

Hi there, Thanks again for getting back to me.

Okay, let me take a stab at answering:

Yes, /media/media_backup/path/to/files/*.foo exists although I’ve changed the names in the posting for security purposes.

There are files stored in backblaze:

backblaze_file_listing
backblaze_file_listing1022×897 79.8 KB

However, the files that those blocks contain are not showing up if I attempt a restore. In other words, I see neither a set 0: or a set 1: or anything else (see below for an example).

duplicati_restore_window_missing_fileset
duplicati_restore_window_missing_fileset1789×724 83.8 KB

Prior to me running the purge command there was a set 0: in the list pictured above. I had just done a fresh initial backup prior to running the purge command. I did a fresh backup (i.e., deleting the backup config and the files in the folder in the B2 bucket where they were going) after running into this on an older backup set with multiple versions/filesets in that dropdown pictured. The prior backup did not error and completed normally–I was purging to save space in B2 after rearranging some things.

I up until now, I’d only used the command line for purging files I no longer needed from backups. Otherwise, I tend to stick to the GUI.

I’ll provide a bit more info here. Hopefully, it’ll be of some help. The backblaze bucket is set to only retain one version of the file:

backblaze_bucket_settings
backblaze_bucket_settings1374×735 67.3 KB

That being said, I have another backup that’s been running successfully to another folder in the same bucket–but I haven’t tried to purge anything from that one:

duplicati_other_backup_to_b2_showing_filesets
duplicati_other_backup_to_b2_showing_filesets1804×698 114 KB

I’m using ‘smart backup retention’ in the options for both backups:

duplicati_backup_options
duplicati_backup_options1721×741 119 KB

Finally, it spat this out (I have it configured to email me with output) when I attempted to list the files in the backup that’s not showing the files.

Filesets: []
MainOperation: List
ParsedResult: Success
Interrupted: False
Fatal: False
Version: 2.1.0.3 (2.1.0.3_beta_2025-01-22)
EndTime: 2/23/2025 9:27:18 PM (1740364038)
BeginTime: 2/23/2025 9:27:18 PM (1740364038)
Duration: 00:00:00.0537972
MessagesActualLength: 1
WarningsActualLength: 0
ErrorsActualLength: 0
LimitedMessages: [
    2025-02-23 21:27:18 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation List has started
]
LimitedWarnings: []
LimitedErrors: []

Let me know if there’s anything else I can dig up about this.

kev.

5

I don’t like seeing that empty space in the Restore version dropdown.
Can you look at job → Show log → Remote and go down to see List?

This list would not be of Source files, but of the files in the Destination.
If you find one, please click to expand. Does it see some dblock files?
It should show what Backblaze web UI does. Are there any dlist files?
You could also try that both ways, so Backblaze UI and also Duplicati.

Example:

image
image1141×208 28.6 KB

The files with dlist in name are the actual file listings for the backup date on the file name.
The dblock files hold blocks from the files in the dlist, and each dblock has its dindex.

FWIW I just tested deleting all of the files in a version, and Duplicati wouldn’t. It reported this:

  Listing remote folder ...
The operation PurgeFiles has failed with error: Refusing to purge 1 files from fileset with ID 1, as that would remove the entire fileset.
To delete a fileset, use the "delete" command. => Refusing to purge 1 files from fileset with ID 1, as that would remove the entire fileset.
To delete a fileset, use the "delete" command.

ErrorID: PurgeWouldRemoveEntireFileset
Refusing to purge 1 files from fileset with ID 1, as that would remove the entire fileset.
To delete a fileset, use the "delete" command.
Return code: 100

Did the list * command itself show files? Here’s mine, from Commandline:

Running commandline entry
Finished!

            
Listing contents 0 (2/24/2025 4:30:14 PM):
C:\backup source\A.txt (1 bytes)
Return code: 0
6

Sure, here’s the job–>Showlog–>Remote–>List. It goes on like this for a while and it does show dblock files

{"Name":".bzEmpty","LastAccess":"2025-02-14T21:39:12.656Z","LastModification":"2025-02-14T21:39:12.656Z","Size":0,"IsFolder":false},
{"Name":"duplicati-b0002d8d645834aca9ad66c5fe85b79bc.dblock.zip.aes","LastAccess":"2025-02-16T02:35:51.591Z","LastModification":"2025-02-16T02:35:51.591Z","Size":51931053,"IsFolder":false},
{"Name":"duplicati-b000ac8f97bb6495cb844f38aa79baff0.dblock.zip.aes","LastAccess":"2025-02-15T12:32:19.334Z","LastModification":"2025-02-15T12:32:19.334Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b000b33ad38304c4bb92bcebbcda9dbe5.dblock.zip.aes","LastAccess":"2025-02-15T01:43:32.558Z","LastModification":"2025-02-15T01:43:32.558Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b000f80b6d6cf45b2b0347d3f067672e8.dblock.zip.aes","LastAccess":"2025-02-15T04:57:46.092Z","LastModification":"2025-02-15T04:57:46.092Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b0013ee565ca44afd95359626116a1b93.dblock.zip.aes","LastAccess":"2025-02-15T05:27:56.946Z","LastModification":"2025-02-15T05:27:56.946Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b00197b9b21834dc1b9399b20b2852dbe.dblock.zip.aes","LastAccess":"2025-02-15T17:56:36.116Z","LastModification":"2025-02-15T17:56:36.116Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b001a07251bc446bdb5aaa8aa82d83830.dblock.zip.aes","LastAccess":"2025-02-16T11:37:42.028Z","LastModification":"2025-02-16T11:37:42.028Z","Size":51744557,"IsFolder":false},
{"Name":"duplicati-b001a888dfde249ddb84030b1f9a7bd23.dblock.zip.aes","LastAccess":"2025-02-15T02:24:12.872Z","LastModification":"2025-02-15T02:24:12.872Z","Size":52132205,"IsFolder":false},
{"Name":"duplicati-b001b8718b6e74cc0b3e646114d58e01d.dblock.zip.aes","LastAccess":"2025-02-14T23:13:04.939Z","LastModification":"2025-02-14T23:13:04.939Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b001bb59d778845cfaaebce0470b1a923.dblock.zip.aes","LastAccess":"2025-02-16T11:06:19.945Z","LastModification":"2025-02-16T11:06:19.945Z","Size":51467405,"IsFolder":false},
{"Name":"duplicati-b001bf253ce604847b827911c0901d29a.dblock.zip.aes","LastAccess":"2025-02-16T11:19:29.944Z","LastModification":"2025-02-16T11:19:29.944Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b0020ab5d7af547868b5a7f0b50942fdb.dblock.zip.aes","LastAccess":"2025-02-16T00:24:24.625Z","LastModification":"2025-02-16T00:24:24.625Z","Size":52167453,"IsFolder":false},
{"Name":"duplicati-b002317456a794e4aab7dbe3975080176.dblock.zip.aes","LastAccess":"2025-02-22T18:44:47.455Z","LastModification":"2025-02-22T18:44:47.455Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b002677bcb32044acaca62d26001945d9.dblock.zip.aes","LastAccess":"2025-02-15T17:46:44.712Z","LastModification":"2025-02-15T17:46:44.712Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b0028905bce5b4e5a9cb267cc129ee8da.dblock.zip.aes","LastAccess":"2025-02-15T12:51:28.325Z","LastModification":"2025-02-15T12:51:28.325Z","Size":52330845,"IsFolder":false},
{"Name":"duplicati-b002a3912d1334cc7997d418afcfc619f.dblock.zip.aes","LastAccess":"2025-02-16T05:15:52.803Z","LastModification":"2025-02-16T05:15:52.803Z","Size":51388861,"IsFolder":false},
...

I’ve been able to confirm that at least the first one b0002d8d645834aca9ad66c5fe85b79bc.dblock.zip.aes is present in the folder in the B2 bucket.

image
image899×803 58 KB

Could you give me the syntax of the list * command you’re using from the command line? I’m just getting over a cold and am not thinking totally straight.

kev.

7

Here’s a sample of other dblock files in the folder in the b2 bucket if it helps:

duplicati-b0002d8d645834aca9ad66c5fe85b79bc.dblock.zip.aes
duplicati-b000ac8f97bb6495cb844f38aa79baff0.dblock.zip.aes
duplicati-b000b33ad38304c4bb92bcebbcda9dbe5.dblock.zip.aes
duplicati-b000f80b6d6cf45b2b0347d3f067672e8.dblock.zip.aes
duplicati-b0013ee565ca44afd95359626116a1b93.dblock.zip.aes
duplicati-b00197b9b21834dc1b9399b20b2852dbe.dblock.zip.aes
duplicati-b001a07251bc446bdb5aaa8aa82d83830.dblock.zip.aes
duplicati-b001a888dfde249ddb84030b1f9a7bd23.dblock.zip.aes
duplicati-b001b8718b6e74cc0b3e646114d58e01d.dblock.zip.aes
duplicati-b001bb59d778845cfaaebce0470b1a923.dblock.zip.aes
duplicati-b001bf253ce604847b827911c0901d29a.dblock.zip.aes
duplicati-b0020ab5d7af547868b5a7f0b50942fdb.dblock.zip.aes
duplicati-b002317456a794e4aab7dbe3975080176.dblock.zip.aes
duplicati-b002677bcb32044acaca62d26001945d9.dblock.zip.aes
duplicati-b0028905bce5b4e5a9cb267cc129ee8da.dblock.zip.aes
duplicati-b002a3912d1334cc7997d418afcfc619f.dblock.zip.aes
duplicati-b002bb3ea55034d049531ee7144c5b19c.dblock.zip.aes
duplicati-b002c6c31c1804dd3937a16146e48db09.dblock.zip.aes
duplicati-b002edd13b3eb41eea21e1598880a461c.dblock.zip.aes
duplicati-b002fb89b8f98468984411e29346db780.dblock.zip.aes
duplicati-b002fe62af47247189c4809b8b18afb8c.dblock.zip.aes
duplicati-b0030b42bc43f4edcb5622f41e007de4e.dblock.zip.aes
duplicati-b00324955a71f47638ecc833845a0b2bb.dblock.zip.aes
duplicati-b003b4d46bc214cdda8a6a2f31d6334d6.dblock.zip.aes
duplicati-b003fc4999a5141c4b5866413e13506ca.dblock.zip.aes
...
8

I thought you ran one already. What was below log from?
Interestingly, GUI Commandline seems to not make logs.

I thought you ran GUI CommandLine with Command list and Commandline arguments as *.
Now I don’t know what you ran to get the log.

Given the lack of Restore versions, I’m more interested in presence or absence of dlist files.

Please check the Backblaze GUI and Duplicati job → Show log → Remote. If none, that’s bad.

9

No, haven’t run anything from the command line except for the purge command in my initial post. Everything else has been from the GUI. All the log stuff has been from the GUI and what it’s emailed me.

Let me mount the b2 bucket and see about the dlist files… one sec… Looks like they are absent from the b2 folder:

klucas@alpha:~/iso/b2/duplicati-online-2024-05-11/backup$ ls *dlist*
ls: cannot access '*dlist*': No such file or directory

There also appear to be no dlist files in Duplicati–>Job–>Show log–>remote.

I guess that’s bad then.

kev.

10

Yes. It confirms the bad news suggested by blank Restore dropdown.
Despite a prevention of deleting last (and only) version, it looks gone.

This could certainly be tried for a repro with extra logs to find the bug.
I’d prefer for the developer to weigh in with a comment at some point.

11

Okay, thanks for your help. I mentioned it earlier but I’ll point it out again that in previous versions this worked as expected so I suspect something got introduced to lead to this. In the meantime, I’d like to purge the dud backup and redo an initial so I’m not left without an off-site one. I’m pretty sure I can recreate the situation if needed but I’ll wait to hear back here.

kev.

12

Are you updating through Beta versions, so would have been at 2.1.0.2_beta_2024-11-29?

I’m testing on 2.1.0.107_canary_2025-01-17, so similar era but maybe Beta change is less.

I likely have more change introduced in this Canary than 2.1.0.3_beta_2025-01-22 has let in.
Maybe the combination of things let in is a cause, or maybe I need to do my testing on Linux.

Regardless, I tested a theory that maybe things were bad before purge. I deleted all versions:

Finished!

            
  Listing remote folder ...
  Deleting file duplicati-20250224T213014Z.dlist.zip  (662 bytes) ...
  Deleting file duplicati-b263f9545f30b42adab82e08e82c295d7.dblock.zip  (685 bytes) ...
  Deleting file duplicati-ic6197852b55d4ce9b3e1a250c97250e5.dindex.zip  (623 bytes) ...
These filesets were deleted:
0: 2/24/2025 4:30:14 PM
Return code: 0

but purge then said:

The operation PurgeFiles has failed with error: No backup at the specified date => No backup at the specified date

ErrorID: NoBackupAtDate
No backup at the specified date
Return code: 100

If you still have the old job and database, I suppose you could see if job → Show log → Remote mentions Delete of that last dlist file. If seen, the context of it might say what was happening.

Here’s my last dlist file delete, but (also visible from Commandline GUI), it also took dblock and dindex too, basically emptying destination. It also did a good job of emptying Restore dropdown.

Feb 25, 2025 11:56 AM: delete duplicati-ic6197852b55d4ce9b3e1a250c97250e5.dindex.zip
Feb 25, 2025 11:56 AM: delete duplicati-b263f9545f30b42adab82e08e82c295d7.dblock.zip
Feb 25, 2025 11:56 AM: delete duplicati-20250224T213014Z.dlist.zip
Feb 25, 2025 11:56 AM: list

Maybe the developer will have some ideas on your case.

13

I do still have the job and I’ll see if I can dig up any reference to it deleting dlist files but I also noticed something odd in job–>Show log–>General for the failure of the purge command. "LastBackupDate": "0001-01-01T00:00:00", and "EndTime": "0001-01-01T00:00:00", I’ll include the whole log entry below but to answer your question; yes, I’ve been updating on the beta channel. I don’t recall what the previous version was though.

            {
  "MainOperation": "PurgeFiles",
  "RemovedFileCount": 0,
  "RemovedFileSize": 0,
  "RewrittenFileLists": 0,
  "CompactResults": null,
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
  "EndTime": "2025-02-21T15:09:45.9386671Z",
  "BeginTime": "2025-02-21T15:09:03.2336142Z",
  "Duration": "00:00:42.7050529",
  "MessagesActualLength": 5,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 1,
  "Messages": [
    "2025-02-21 10:09:06 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation PurgeFiles has started",
    "2025-02-21 10:09:06 -05 - [Information-Duplicati.Library.Main.Operation.PurgeFilesHandler-StartingPurge]: Starting purge operation",
    "2025-02-21 10:09:11 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-02-21 10:09:44 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (55.407 KB)",
    "2025-02-21 10:09:45 -05 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Temporary: duplicati-20250220T152816Z.dlist.zip.aes"
  ],
  "Warnings": [],
  "Errors": [
    "2025-02-21 10:09:45 -05 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation PurgeFiles has failed with error: Fileset was reported with id 1, but could not be found?\nInvalidProgramException: Fileset was reported with id 1, but could not be found?"
  ],
  "BackendStatistics": {
    "RemoteCalls": 1,
    "BytesUploaded": 0,
    "BytesDownloaded": 0,
    "FilesUploaded": 0,
    "FilesDownloaded": 0,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 1,
    "KnownFileCount": 56736,
    "KnownFileSize": 1463762808544,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 1,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "PurgeFiles",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-02-21T15:09:03.2341439Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
14

2025-02-21 10:09:45 -05 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Temporary: duplicati-20250220T152816Z.dlist.zip.aes"

makes me wonder if the backup before purge finished. It shouldn’t leave that Temporary file.
Can you find a job log or email saying how job ended? Its time is in UTC, so convert to local.

1 Like
15

Tried to load the full log for the time that the purge command was run from job–>Show log–>Remote but it was 56739 lines and doesn’t seem to fit here in a forum post. Regardless, there’s no reference to dlist files in it. Here’s a sample:

[
{"Name":".bzEmpty","LastAccess":"2025-02-14T21:39:12.656Z","LastModification":"2025-02-14T21:39:12.656Z","Size":0,"IsFolder":false},
{"Name":"duplicati-b0002d8d645834aca9ad66c5fe85b79bc.dblock.zip.aes","LastAccess":"2025-02-16T02:35:51.591Z","LastModification":"2025-02-16T02:35:51.591Z","Size":51931053,"IsFolder":false},
{"Name":"duplicati-b000ac8f97bb6495cb844f38aa79baff0.dblock.zip.aes","LastAccess":"2025-02-15T12:32:19.334Z","LastModification":"2025-02-15T12:32:19.334Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b000b33ad38304c4bb92bcebbcda9dbe5.dblock.zip.aes","LastAccess":"2025-02-15T01:43:32.558Z","LastModification":"2025-02-15T01:43:32.558Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b000f80b6d6cf45b2b0347d3f067672e8.dblock.zip.aes","LastAccess":"2025-02-15T04:57:46.092Z","LastModification":"2025-02-15T04:57:46.092Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b0013ee565ca44afd95359626116a1b93.dblock.zip.aes","LastAccess":"2025-02-15T05:27:56.946Z","LastModification":"2025-02-15T05:27:56.946Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b00197b9b21834dc1b9399b20b2852dbe.dblock.zip.aes","LastAccess":"2025-02-15T17:56:36.116Z","LastModification":"2025-02-15T17:56:36.116Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b001a07251bc446bdb5aaa8aa82d83830.dblock.zip.aes","LastAccess":"2025-02-16T11:37:42.028Z","LastModification":"2025-02-16T11:37:42.028Z","Size":51744557,"IsFolder":false},
{"Name":"duplicati-b001a888dfde249ddb84030b1f9a7bd23.dblock.zip.aes","LastAccess":"2025-02-15T02:24:12.872Z","LastModification":"2025-02-15T02:24:12.872Z","Size":52132205,"IsFolder":false},
{"Name":"duplicati-b001b8718b6e74cc0b3e646114d58e01d.dblock.zip.aes","LastAccess":"2025-02-14T23:13:04.939Z","LastModification":"2025-02-14T23:13:04.939Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b001bb59d778845cfaaebce0470b1a923.dblock.zip.aes","LastAccess":"2025-02-16T11:06:19.945Z","LastModification":"2025-02-16T11:06:19.945Z","Size":51467405,"IsFolder":false},
{"Name":"duplicati-b001bf253ce604847b827911c0901d29a.dblock.zip.aes","LastAccess":"2025-02-16T11:19:29.944Z","LastModification":"2025-02-16T11:19:29.944Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b0020ab5d7af547868b5a7f0b50942fdb.dblock.zip.aes","LastAccess":"2025-02-16T00:24:24.625Z","LastModification":"2025-02-16T00:24:24.625Z","Size":52167453,"IsFolder":false},
{"Name":"duplicati-b002677bcb32044acaca62d26001945d9.dblock.zip.aes","LastAccess":"2025-02-15T17:46:44.712Z","LastModification":"2025-02-15T17:46:44.712Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b0028905bce5b4e5a9cb267cc129ee8da.dblock.zip.aes","LastAccess":"2025-02-15T12:51:28.325Z","LastModification":"2025-02-15T12:51:28.325Z","Size":52330845,"IsFolder":false},
{"Name":"duplicati-b002a3912d1334cc7997d418afcfc619f.dblock.zip.aes","LastAccess":"2025-02-16T05:15:52.803Z","LastModification":"2025-02-16T05:15:52.803Z","Size":51388861,"IsFolder":false},
{"Name":"duplicati-b002bb3ea55034d049531ee7144c5b19c.dblock.zip.aes","LastAccess":"2025-02-15T19:41:48.304Z","LastModification":"2025-02-15T19:41:48.304Z","Size":51388861,"IsFolder":false},
...
 {"Name":"duplicati-iffe57e8363ad4d65aa25c6bab1107400.dindex.zip.aes","LastAccess":"2025-02-14T22:15:51.437Z","LastModification":"2025-02-14T22:15:51.437Z","Size":2621,"IsFolder":false},
    {"Name":"duplicati-iffe773caab6542f2921db296e1372641.dindex.zip.aes","LastAccess":"2025-02-16T04:17:39.472Z","LastModification":"2025-02-16T04:17:39.472Z","Size":2621,"IsFolder":false},
    {"Name":"duplicati-iffecb605a1c341c6b2cc920cf2c23acd.dindex.zip.aes","LastAccess":"2025-02-15T06:51:47.723Z","LastModification":"2025-02-15T06:51:47.723Z","Size":2621,"IsFolder":false},
    {"Name":"duplicati-iffeeb1643ce54236bc667e4bf6763131.dindex.zip.aes","LastAccess":"2025-02-15T20:06:37.448Z","LastModification":"2025-02-15T20:06:37.448Z","Size":2621,"IsFolder":false},
    {"Name":"duplicati-iffeeb20293c647999d03cc83f4c88615.dindex.zip.aes","LastAccess":"2025-02-15T08:02:24.646Z","LastModification":"2025-02-15T08:02:24.646Z","Size":2621,"IsFolder":false},
    {"Name":"duplicati-ifff412edd76e4d1aac2c8d954a7b2b84.dindex.zip.aes","LastAccess":"2025-02-14T22:50:44.416Z","LastModification":"2025-02-14T22:50:44.416Z","Size":2685,"IsFolder":false},
    {"Name":"duplicati-ifff640b5f99a448c802b3c20f67c8a1b.dindex.zip.aes","LastAccess":"2025-02-16T11:21:49.879Z","LastModification":"2025-02-16T11:21:49.879Z","Size":2621,"IsFolder":false},
    {"Name":"duplicati-ifff73a9b29e74bb1ad01eb87076aba79.dindex.zip.aes","LastAccess":"2025-02-15T22:45:53.717Z","LastModification":"2025-02-15T22:45:53.717Z","Size":2685,"IsFolder":false},
    {"Name":"duplicati-ifff7db6763c649a88f05c97c645abcd2.dindex.zip.aes","LastAccess":"2025-02-16T09:59:28.946Z","LastModification":"2025-02-16T09:59:28.946Z","Size":9949,"IsFolder":false},
    {"Name":"duplicati-ifff8e05d4edc496d80d0b10ddacf16c1.dindex.zip.aes","LastAccess":"2025-02-15T20:45:54.439Z","LastModification":"2025-02-15T20:45:54.439Z","Size":2685,"IsFolder":false}
    ]
16

Sure, the previous backup job appears to have completed successfully according to job–>Show log–>General

image
image1249×507 79.3 KB

            {
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "ModifiedFiles": 0,
  "ExaminedFiles": 2944,
  "OpenedFiles": 2944,
  "AddedFiles": 2944,
  "SizeOfModifiedFiles": 0,
  "SizeOfAddedFiles": 1505390752120,
  "SizeOfExaminedFiles": 1505390752120,
  "SizeOfOpenedFiles": 1505390752120,
  "NotProcessedFiles": 0,
  "AddedFolders": 143,
  "TooLargeFiles": 0,
  "FilesWithError": 0,
  "ModifiedFolders": 0,
  "ModifiedSymlinks": 0,
  "AddedSymlinks": 2,
  "DeletedSymlinks": 0,
  "PartialBackup": false,
  "Dryrun": false,
  "MainOperation": "Backup",
  "CompactResults": null,
  "VacuumResults": null,
  "DeleteResults": {
    "DeletedSetsActualLength": 0,
    "DeletedSets": [],
    "Dryrun": false,
    "MainOperation": "Delete",
    "CompactResults": null,
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
    "EndTime": "2025-02-20T19:21:07.8098673Z",
    "BeginTime": "2025-02-20T19:20:52.364617Z",
    "Duration": "00:00:15.4452503",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 60,
      "BytesUploaded": 0,
      "BytesDownloaded": 0,
      "FilesUploaded": 0,
      "FilesDownloaded": 0,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 24,
      "UnknownFileSize": 0,
      "UnknownFileCount": 1,
      "KnownFileCount": 56736,
      "KnownFileSize": 1463762808544,
      "LastBackupDate": "0001-01-01T00:00:00",
      "BackupListCount": 1,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Interrupted": false,
      "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2025-02-20T15:28:16.6456474Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "RepairResults": null,
  "TestResults": {
    "MainOperation": "Test",
    "VerificationsActualLength": 0,
    "Verifications": [],
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
    "EndTime": "2025-02-20T19:21:42.4611683Z",
    "BeginTime": "2025-02-20T19:21:42.3998694Z",
    "Duration": "00:00:00.0612989",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 60,
      "BytesUploaded": 0,
      "BytesDownloaded": 0,
      "FilesUploaded": 0,
      "FilesDownloaded": 0,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 24,
      "UnknownFileSize": 0,
      "UnknownFileCount": 1,
      "KnownFileCount": 56736,
      "KnownFileSize": 1463762808544,
      "LastBackupDate": "0001-01-01T00:00:00",
      "BackupListCount": 1,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Interrupted": false,
      "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2025-02-20T15:28:16.6456474Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Success",
  "Interrupted": false,
  "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
  "EndTime": "2025-02-20T19:21:42.4639831Z",
  "BeginTime": "2025-02-20T15:28:16.645638Z",
  "Duration": "03:53:25.8183451",
  "MessagesActualLength": 226,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 0,
  "Messages": [
    "2025-02-20 10:28:16 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started",
    "2025-02-20 10:28:21 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-02-20 10:28:54 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (55.407 KB)",
    "2025-02-20 10:28:55 -05 - [Information-Duplicati.Library.Main.Operation.Backup.RecreateMissingIndexFiles-RecreateMissingIndexFile]: Re-creating missing index file for duplicati-b062403af61e0492bb3e825c8aa285990.dblock.zip.aes",
    "2025-02-20 10:28:56 -05 - [Information-Duplicati.Library.Main.Operation.Backup.RecreateMissingIndexFiles-RecreateMissingIndexFile]: Re-creating missing index file for duplicati-b3fc66b1568294d00931466b366746f12.dblock.zip.aes",
    "2025-02-20 10:28:56 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i0377a9fbd8c24f3c82ac7b648cab29d4.dindex.zip.aes (2.560 KB)",
    "2025-02-20 10:28:56 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i408a3a57daad41af9f3bbb38af718960.dindex.zip.aes (2.560 KB)",
    "2025-02-20 10:40:38 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0328d426fbf443ca81fe80dddc0cdf93.dblock.zip.aes (49.009 MB)",
    "2025-02-20 10:40:38 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b181a2fc469624a559afddd07ec37a686.dblock.zip.aes (49.009 MB)",
    "2025-02-20 10:40:41 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bfe6de3b48de14561ae03a2fb5c6efddd.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:40:42 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0264c7ff493e48c5b1aeb7ae84d26108.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:40:45 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b9bd13601aa114455808c435a643446c4.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:40:46 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bee18c66349754d8fad50f90172fae16c.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:40:48 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b8648b50765b34e18a4277159af238758.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:40:49 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb103e5e6f9684d21981e195f04024163.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:41:23 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3890451be42c4b779b769db019bd3011.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:41:23 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b852428dded534b4b82d51a625064f766.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:41:35 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b63e56387b84148a58c9b45d13c69b287.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:41:35 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bdd621902daf046d7aeb9e0e824f66fa1.dblock.zip.aes (49.008 MB)",
    "2025-02-20 10:55:47 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b09a4359223c044ecb241175fd37ae81b.dblock.zip.aes (49.008 MB)"
  ],
  "Warnings": [],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 60,
    "BytesUploaded": 0,
    "BytesDownloaded": 0,
    "FilesUploaded": 0,
    "FilesDownloaded": 0,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 24,
    "UnknownFileSize": 0,
    "UnknownFileCount": 1,
    "KnownFileCount": 56736,
    "KnownFileSize": 1463762808544,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 1,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-02-20T15:28:16.6456474Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
17

Here’s another view showing the order of what happened:

image
image1349×560 80 KB

18

I think Start time of 2025-02020 10:28:16 in the UTC-5 time zone should match this dlist file:

but I’m not sure how the seemingly complete backup left it as Temporary, if I read code right:

is a worry (is something flaky going to B2?), but the default job log only records 20 entries.
Backblaze B2 normally needs retries occasionally, by design, but 24 is possibly excessive.
You can view other job logs, or set options log-file=<path> log-file-log-level=retry.

Since this is part of your regular routine, maybe it would be seen next time (or maybe not?).

Still unclear to me what happened on that failed purge. Developer ideas welcome, as usual.

19

Had a look at the backup job log from 2025-02-20 and it also shows 24 retries, 37 for 2025-02-18, 2025-02-17 has 0, and 16 on the initial one started 2025-02-14.

kev.

20

The logs also show I did a failed purge on 2025-02-17:

            {
  "MainOperation": "PurgeFiles",
  "RemovedFileCount": 0,
  "RemovedFileSize": 0,
  "RewrittenFileLists": 0,
  "CompactResults": null,
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
  "EndTime": "2025-02-17T12:49:42.7519273Z",
  "BeginTime": "2025-02-17T12:48:58.997261Z",
  "Duration": "00:00:43.7546663",
  "MessagesActualLength": 5,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 1,
  "Messages": [
    "2025-02-17 07:49:02 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation PurgeFiles has started",
    "2025-02-17 07:49:02 -05 - [Information-Duplicati.Library.Main.Operation.PurgeFilesHandler-StartingPurge]: Starting purge operation",
    "2025-02-17 07:49:08 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-02-17 07:49:40 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (55.407 KB)",
    "2025-02-17 07:49:41 -05 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Temporary: duplicati-20250214T213959Z.dlist.zip.aes"
  ],
  "Warnings": [],
  "Errors": [
    "2025-02-17 07:49:42 -05 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation PurgeFiles has failed with error: Fileset was reported with id 1, but could not be found?\nInvalidProgramException: Fileset was reported with id 1, but could not be found?"
  ],
  "BackendStatistics": {
    "RemoteCalls": 1,
    "BytesUploaded": 0,
    "BytesDownloaded": 0,
    "FilesUploaded": 0,
    "FilesDownloaded": 0,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 1,
    "KnownFileCount": 56736,
    "KnownFileSize": 1463762808544,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 1,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "PurgeFiles",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.3 (2.1.0.3_beta_2025-01-22)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-02-17T12:48:58.9978392Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}