File size remaining goes negative

Fedora 31 workstation, Duplicati -
When nearing the end of the backup, the file size remaining to be backed up becomes a negative number. I am attempting to upload a screenshot here.

This is a fairly fresh installation. I upgraded Fedora 31 about a week ago, then reinstalled Duplicati Canary

When the backup first starts, Duplicati scans the filesystem to find files that should be backed up and it also notes the total size of all those files.

If some files grow larger after they are scanned at the start of the backup - but before Duplicati has backed them up - then it can throw off this ‘bytes to go’ calculation.

It is superficial and can be ignored. The UI should probably be adjusted to hide the ‘xx bytes’ portion if it goes negative.

A fix was made a few months ago for another situation where this number could be negative: files were temporarily counted twice against the total bytes processed. But your version has that fix so this is a different issue - probably file growth during backup.

Just adding that I think I ran into the same bug. While the backup was occurring, I added some zip files. I then ended up with this and the backup got “stuck”. I had to restart the Duplicati service entirely.

1 Like

If you can reproduce this problem, it might be interesting to see what About -> Show Log -> Live -> Verbose shows.

I’ve had this same problem since I started using duplicati a few years ago. I get both negative files remaining and negative bytes remaining:

It happens all the time, every backup that runs. If there’s some log info you want, let me know and I’ll try to provide it.
I’m running on a debian linux distro.

1 Like

How long does your backup job run? As I mentioned above, one cause of this issue is when the files change between the time the job starts and the time Duplicati actually gets around to backing up those files. But your numbers are really large. Seems quite odd especially if your backups complete in a short timeframe.

The negative values show up immediately when the job starts, so doubtful it has to do with a file changing between the scan and the actual backup. Also not sure what you consider a “short timeframe”. Most of the jobs I have are examining and backing up 10s if not 100s of GB, depending on activity. The shortest backups I have take a few minutes, the longest nearly an hour.

To my programmer nose, this smells like bad signed int → long, long → int conversion.

Can you give me more detail on your Debian system? What version of mono are you using, and what filesystem format are you using (ext4, etc)? (They are local files, right?)

Mono 6.8.0.
Debian testing disto (currently bookworm).
fs is a 3TB raid1 (software raid, mdadm), ext4.
All files are local.

Try this… open two tabs to the Duplicati Web UI. On the first tab navigate to About → Show Log → Live → and set the dropdown to Verbose. On the second tab, start your backup job. Quickly go back to the first tab and watch for any errors while the filesystem is enumerated.

Tried, but it spits out hundreds of lines way too fast to catch and truncates the log in the browser. Is this logged to file somewhere?

Yeah we don’t need a full log… I was just hoping some sort of problem would be visible that you could screen capture. Maybe try the test with Live Log set to “Warning”, it should help reduce the output.

Nothing when log level set the Warning.

Even though you’re getting a ton of log entries when set to Verbose, anything look relevant?

Nothing I can see. Let me try and create a test backup with very few files in it and see if it still shows negative numbers.

Ran a test backup with a single 10G file. The UI showed negative values for the progress and definitely nothing obviously useful being logged. Just mundane stuff about what’s it’s doing.

Ok, I like your idea of testing with a small amount of data. I think you might need to use the various log-file options to save logs to a file. Try setting the log level to Verbose and run your test again.

That’s actually what I did. Had logging set to verbose. The logging was basically telling me what was happening, but nothing would indicate why it was showing negative values.

I meant logging to a file instead of the Live Log.

Which progress? I can see how a math error might make size negative. Was files negative too?
If you suspect an integer overflow problem, maybe trying a file size of about 2 GB might be helpful.

You can see the progress in a more raw form on About → System info. Ctrl-A and Ctrl-C the page.
Pasting that into notepad for a look let me test how the status bar values were derived. Status bar:

562 files (518.73 MB) to go

Server state properties:

lastPgEvent : {“BackupID”:“1”,“TaskID”:25,“BackendAction”:“List”,“BackendPath”:null,“BackendFileSize”:-1,“BackendFileProgress”:0,“BackendSpeed”:-1,“BackendIsBlocking”:false,“CurrentFilename”:null,“CurrentFilesize”:0,“CurrentFileoffset”:0,“CurrentFilecomplete”:true,“Phase”:“Backup_ProcessingFiles”,“OverallProgress”:0,“ProcessedFileCount”:225,“ProcessedFileSize”:25079669,“TotalFileCount”:787,“TotalFileSize”:569002300,“StillCounting”:false}

For files, remaining is 787 - 225 = 562. For size, remaining is 569002300 - 25079669 = 543922631.
That’s 518.73 MiB (I guess the status bar MB is really MiB). From message search, I think the code is

I don’t really do JavaScript or C#, but I think @drwtsn32 has looked at the C# end of computing these.
The web UI gets it from the server, so it’s also possible to capture packets or maybe use browser tools.
Edge F12 Developer Tools caught a series of progressstate. An example of what the server returned:

  "BackupID": "1",
  "TaskID": 26,
  "BackendAction": "List",
  "BackendPath": null,
  "BackendFileSize": -1,
  "BackendFileProgress": 0,
  "BackendSpeed": -1,
  "BackendIsBlocking": false,
  "CurrentFilename": null,
  "CurrentFilesize": 0,
  "CurrentFileoffset": 0,
  "CurrentFilecomplete": true,
  "Phase": "Backup_ProcessingFiles",
  "OverallProgress": 0,
  "ProcessedFileCount": 62,
  "ProcessedFileSize": 11989702,
  "TotalFileCount": 364,
  "TotalFileSize": 36373549,
  "StillCounting": true