Started getting this error yesterday on one of my backups. The backup’s backend is a local disk.
2018-12-17 09:46:10 -08 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-BackendQuotaExceeded]: Backend quota has been exceeded: Using 4.68 GB of 7.22 TB (0 bytes available)
There’s no quota on the backup. Any ideas how to resolve? I’m running the current beta 2.0.4.5, which I upgraded to from the previous beta.
This just started for no apparent reason? I wonder if whatever was perceived as quota was heading to 0, or whether there was some unknown change that caused it to take a sudden dive. What do old job logs say in BackendStatistics? This is available either in the web UI, or in the emailed report, and in various other ways.
What operating system is this, and (if you know), can you describe the partitioning plan and the filesystem?
Did you get any successful backups on 2.0.4.5, or did the quota error start at update to 2.0.4.5? Job logs in 2.0.4.5 also contain its Version number, so it should be easy to tell whether any of those was working well…
@ts678, apologies for the late reply.
The OS I’m running is Ubuntu 18.04.1 LTS. Filesystems for both source and target disks are ext4. Partitions on source and target disks are primary partitions. Though my root filesystem (that duplicati is installed to) is running on some SSD’s in an LVM logical volume.
The backup is basically backing up /mnt/data (where the source disk is mounted) to /mnt/backup/duplicati/backupfolder (target disk is mounted at /mnt/backup). No encryption on the backup. Duplicati is also running as root.
So, it did start coinciding with my external HDD enclosure starting to randomly drop the drives, and remount them read-only. I did get some mild filesystem corruption, but I’ve managed to get clean runs through fsck since, and I’ve built an entirely new PC so the drives are now internal rather than external. But otherwise, the OS install is the same (I just moved all the HDD’s from the old machine -> new machine).
I have gotten some successful backups on 2.0.45. Looking at the logs, here’s where the trouble started. I’ll post the last 3 logs:
Last successful run on 12/15/18 @ 1PM
DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 61729
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 5264424515467
SizeOfOpenedFiles: 0
NotProcessedFiles: 0
AddedFolders: 0
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults: null
DeleteResults:
DeletedSets: []
Dryrun: False
MainOperation: Delete
CompactResults: null
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 1:00:50 PM (1544907650)
BeginTime: 12/15/2018 1:00:35 PM (1544907635)
Duration: 00:00:14.9231050
Messages: [
2018-12-15 13:00:00 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
]
Warnings: []
Errors: []
BackendStatistics:
RemoteCalls: 5
BytesUploaded: 0
BytesDownloaded: 1078295667
FilesUploaded: 0
FilesDownloaded: 3
FilesDeleted: 0
FoldersCreated: 0
RetryAttempts: 0
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 9782
KnownFileSize: 5244404976139
LastBackupDate: 12/15/2018 6:00:00 AM (1544882400)
BackupListCount: 4
TotalQuotaSpace: 7937340719104
FreeQuotaSpace: 2235752841216
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
Messages: [
2018-12-15 13:00:00 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
]
Warnings: []
Errors: []
RepairResults: null
TestResults:
MainOperation: Test
Verifications: [
Key: duplicati-20181215T140000Z.dlist.zip
Value: [],
Key: duplicati-ibb59516c3ac6408094d1238ba7b02f61.dindex.zip
Value: [],
Key: duplicati-b3c9c62fde40d4150b9db0e77101d847c.dblock.zip
Value: []
]
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 1:01:03 PM (1544907663)
BeginTime: 12/15/2018 1:00:50 PM (1544907650)
Duration: 00:00:12.6436550
Messages: [
2018-12-15 13:00:00 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
]
Warnings: []
Errors: []
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 1:01:03 PM (1544907663)
BeginTime: 12/15/2018 1:00:00 PM (1544907600)
Duration: 00:01:03.2886630
Messages: [
2018-12-15 13:00:00 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 13:00:05 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
2018-12-15 13:00:35 -08 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
]
Warnings: []
Errors: []
Then the first problem - 12/15/18 at 3PM
DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 61729
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 5264424515467
SizeOfOpenedFiles: 0
NotProcessedFiles: 0
AddedFolders: 0
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults:
DeletedFileCount: 2
DownloadedFileCount: 0
UploadedFileCount: 0
DeletedFileSize: 1459
DownloadedFileSize: 0
UploadedFileSize: 0
Dryrun: False
MainOperation: Compact
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 2:54:14 PM (1544914454)
BeginTime: 12/15/2018 2:54:06 PM (1544914446)
Duration: 00:00:08.1265340
Messages: [
2018-12-15 14:51:50 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 14:52:45 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 14:52:46 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 14:53:20 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
2018-12-15 14:53:51 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:03:53 -08 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20181212T020000Z.dlist.zip
]
BackendStatistics:
RemoteCalls: 13
BytesUploaded: 1459
BytesDownloaded: 1096535361
FilesUploaded: 2
FilesDownloaded: 7
FilesDeleted: 2
FoldersCreated: 0
RetryAttempts: 4
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 9782
KnownFileSize: 5244404976139
LastBackupDate: 12/15/2018 6:00:00 AM (1544882400)
BackupListCount: 4
TotalQuotaSpace: 7937340719104
FreeQuotaSpace: 2235752841216
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
Messages: [
2018-12-15 14:51:50 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 14:52:45 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 14:52:46 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 14:53:20 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
2018-12-15 14:53:51 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:03:53 -08 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20181212T020000Z.dlist.zip
]
DeleteResults:
DeletedSets: []
Dryrun: False
MainOperation: Delete
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 2:54:14 PM (1544914454)
BeginTime: 12/15/2018 2:53:51 PM (1544914431)
Duration: 00:00:23.1006090
Messages: [
2018-12-15 14:51:50 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 14:52:45 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 14:52:46 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 14:53:20 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
2018-12-15 14:53:51 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:03:53 -08 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20181212T020000Z.dlist.zip
]
RepairResults: null
TestResults:
MainOperation: Test
Verifications: [
Key: duplicati-20181212T020000Z.dlist.zip
Value: [
Key: Error
Value: Hash mismatch on file "/tmp/dup-2404332b-89c7-49f7-bb4b-7d98f84060ce", recorded hash: 7p+x7mNYZ7e0Z+E4O/KAlyBUEDDqc2XQs93aqKELxgI=, actual hash 8xFoaggkagxNbp4Wro9ZLWlk5xYZU6DnSV80bCvHpQ4=
],
Key: duplicati-i3a10b6e675bd4763ab66b4215a4a9242.dindex.zip
Value: [],
Key: duplicati-b009fae965b17410ba2ff46e59269f066.dblock.zip
Value: []
]
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 3:04:47 PM (1544915087)
BeginTime: 12/15/2018 2:54:15 PM (1544914455)
Duration: 00:10:32.0530020
Messages: [
2018-12-15 14:51:50 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 14:52:45 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 14:52:46 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 14:53:20 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
2018-12-15 14:53:51 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:03:53 -08 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20181212T020000Z.dlist.zip
]
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 3:04:47 PM (1544915087)
BeginTime: 12/15/2018 2:51:49 PM (1544914309)
Duration: 00:12:57.8990370
Messages: [
2018-12-15 14:51:50 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 14:52:45 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 14:52:46 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 14:53:20 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
2018-12-15 14:53:51 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bb66cdb898bdc44a8b9d2e786109e440d.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:03:53 -08 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20181212T020000Z.dlist.zip
]
Then the last log entry, 12/15/18 @ 3:07PM
DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 61729
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 5264424515467
SizeOfOpenedFiles: 0
NotProcessedFiles: 0
AddedFolders: 0
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults:
DeletedFileCount: 0
DownloadedFileCount: 0
UploadedFileCount: 0
DeletedFileSize: 0
DownloadedFileSize: 0
UploadedFileSize: 0
Dryrun: False
MainOperation: Compact
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 3:06:21 PM (1544915181)
BeginTime: 12/15/2018 3:06:13 PM (1544915173)
Duration: 00:00:08.0995790
Messages: [
2018-12-15 15:04:48 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:04:53 -08 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-BackendQuotaExceeded]: Backend quota has been exceeded: Using 4.77 TB of 7.22 TB (0 bytes available)
]
BackendStatistics:
RemoteCalls: 10
BytesUploaded: 0
BytesDownloaded: 1078356998
FilesUploaded: 0
FilesDownloaded: 3
FilesDeleted: 0
FoldersCreated: 0
RetryAttempts: 5
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 9782
KnownFileSize: 5244404976139
LastBackupDate: 12/15/2018 6:00:00 AM (1544882400)
BackupListCount: 4
TotalQuotaSpace: 7937340719104
FreeQuotaSpace: 0
AssignedQuotaSpace: -1
ReportedQuotaError: True
ReportedQuotaWarning: False
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
Messages: [
2018-12-15 15:04:48 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:04:53 -08 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-BackendQuotaExceeded]: Backend quota has been exceeded: Using 4.77 TB of 7.22 TB (0 bytes available)
]
DeleteResults:
DeletedSets: []
Dryrun: False
MainOperation: Delete
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 3:06:21 PM (1544915181)
BeginTime: 12/15/2018 3:05:59 PM (1544915159)
Duration: 00:00:22.9127000
Messages: [
2018-12-15 15:04:48 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:04:53 -08 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-BackendQuotaExceeded]: Backend quota has been exceeded: Using 4.77 TB of 7.22 TB (0 bytes available)
]
RepairResults: null
TestResults:
MainOperation: Test
Verifications: [
Key: duplicati-20181213T050000Z.dlist.zip
Value: [],
Key: duplicati-i744ac9d7e7ae4c1094df34bb91ae0169.dindex.zip
Value: [],
Key: duplicati-ba1e8ebec9ae2410c8c56e94f0ea5c4fa.dblock.zip
Value: []
]
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 3:07:13 PM (1544915233)
BeginTime: 12/15/2018 3:06:22 PM (1544915182)
Duration: 00:00:50.8014170
Messages: [
2018-12-15 15:04:48 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:04:53 -08 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-BackendQuotaExceeded]: Backend quota has been exceeded: Using 4.77 TB of 7.22 TB (0 bytes available)
]
ParsedResult: Error
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/15/2018 3:07:13 PM (1544915233)
BeginTime: 12/15/2018 3:04:48 PM (1544915088)
Duration: 00:02:25.3611720
Messages: [
2018-12-15 15:04:48 -08 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-15 15:04:53 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (9.55 KB),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
2018-12-15 15:05:19 -08 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b54839cfbbfea42d78324d547e98555ae.dblock.zip (712 bytes),
...
]
Warnings: []
Errors: [
2018-12-15 15:04:53 -08 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-BackendQuotaExceeded]: Backend quota has been exceeded: Using 4.77 TB of 7.22 TB (0 bytes available)
]
I should note that I’m getting this backend quota exceeded message even when I click the repair button in the error message. I have multiple problems right now due to those drives dropping. When I click “run now” for the backup job in question, I get the error “Found 1 files that are missing from the remote storage, please run repair”. When I click the repair button in the error message, I just get another error message. Strangely enough, I seem to be getting logs written to the remote logs, but not to the general logs for this backup now.
Small update. So I ran the purge broken files CLI command on this backup, and the backend quota exceeded message went away.
While I’m glad the problem seems at least temporarily gone, if it returns you can try some other ways to examine filesystem space and inode values, such as stat -f and df -h and df -hi for /mnt/backup. Duplicati uses the space values as quota-equivalent to monitor how close you are to using all available. Ordinarily one would get a warning as space exhausts, but you went straight to error due to sudden 0…
Sample TotalQuotaSpace FreeQuotaSpace ReportedQuotaError ReportedQuotaWarning
1 7937340719104 2235752841216 False False
2 7937340719104 2235752841216 False False
3 7937340719104 0 True False
The FreeQuotaSpace suddenly dropping to 0 from a high value (per previous post) is rather mystifying. Possibly it’s from your intermittent drive. The number is basically what the OS reports through the .NET DriveInfo.AvailableFreeSpace Property, which on Linux is implemented in Mono not in .NET Framework.
Your second set of statistics did not show a quota error but was an inability to read the destination then, maybe a different symptom of whatever is going on with the drive. If it persists, try to get a –log-file view. Sometimes one can also find more detailed error info than these one-liners in emails, or the server logs.
Thank you for the location of the server logs. I can’t believe I never saw those. I’ve only ever seen the backup logs. This will be helpful for the future.