BackendQuotaExceeded error on a backup with no quota configured


#1

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.


#2

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…


#3

@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.


#4

Small update. So I ran the purge broken files CLI command on this backup, and the backend quota exceeded message went away.


#5

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.


#6

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.