"The request timed out" error during verification

Support
1

Hello,

actually I experience the same effect. Please see below those details. Is this just a warning or is a real error. Thanks.

Apr 19, 2018 2:04 PM: Result
DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 41425
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 228872137393
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: null
RepairResults: null
TestResults:
    MainOperation: Test
    Verifications: [
        Key: duplicati-20180403T140954Z.dlist.zip.aes
        Value: [
            Key: Error
            Value: The request timed out
        ],
        Key: duplicati-ie3242562308845d089b7175ad7c9d876.dindex.zip.aes
        Value: [
            Key: Error
            Value: The request timed out
        ],
        Key: duplicati-b8ba48fc991b442b09424af2b7a5ab369.dblock.zip.aes
        Value: [
            Key: Error
            Value: The request timed out
        ]
    ]
    ParsedResult: Error
    EndTime: 4/19/2018 2:04:09 PM (1524139449)
    BeginTime: 4/19/2018 1:16:17 PM (1524136577)
    Duration: 00:47:52.0260760
    Messages: [
        2018-04-19 13:15:34 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
        2018-04-19 13:15:35 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
        2018-04-19 13:15:43 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (261 bytes),
        2018-04-19 13:16:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
        2018-04-19 13:16:16 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (261 bytes),
...
    ]
    Warnings: []
    Errors: [
        2018-04-19 13:32:14 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20180403T140954Z.dlist.zip.aes,
        2018-04-19 13:48:11 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-ie3242562308845d089b7175ad7c9d876.dindex.zip.aes,
        2018-04-19 14:04:09 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b8ba48fc991b442b09424af2b7a5ab369.dblock.zip.aes
    ]
    BackendStatistics:
        RemoteCalls: 17
        BytesUploaded: 0
        BytesDownloaded: 0
        FilesUploaded: 0
        FilesDownloaded: 0
        FilesDeleted: 0
        FoldersCreated: 0
        RetryAttempts: 12
        UnknownFileSize: 0
        UnknownFileCount: 0
        KnownFileCount: 261
        KnownFileSize: 138896014593
        LastBackupDate: 4/3/2018 4:09:54 PM (1522764594)
        BackupListCount: 1
        TotalQuotaSpace: 0
        FreeQuotaSpace: 0
        AssignedQuotaSpace: -1
        ReportedQuotaError: False
        ReportedQuotaWarning: False
        ParsedResult: Error
        Messages: [
            2018-04-19 13:15:34 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
            2018-04-19 13:15:35 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
            2018-04-19 13:15:43 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (261 bytes),
            2018-04-19 13:16:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
            2018-04-19 13:16:16 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (261 bytes),
...
        ]
        Warnings: []
        Errors: [
            2018-04-19 13:32:14 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20180403T140954Z.dlist.zip.aes,
            2018-04-19 13:48:11 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-ie3242562308845d089b7175ad7c9d876.dindex.zip.aes,
            2018-04-19 14:04:09 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b8ba48fc991b442b09424af2b7a5ab369.dblock.zip.aes
        ]
ParsedResult: Error
EndTime: 4/19/2018 2:04:09 PM (1524139449)
BeginTime: 4/19/2018 1:15:33 PM (1524136533)
Duration: 00:48:35.3328590
Messages: [
    2018-04-19 13:15:34 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
    2018-04-19 13:15:35 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
    2018-04-19 13:15:43 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (261 bytes),
    2018-04-19 13:16:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
    2018-04-19 13:16:16 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (261 bytes),
...
]
Warnings: []
Errors: [
    2018-04-19 13:32:14 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20180403T140954Z.dlist.zip.aes,
    2018-04-19 13:48:11 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-ie3242562308845d089b7175ad7c9d876.dindex.zip.aes,
    2018-04-19 14:04:09 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b8ba48fc991b442b09424af2b7a5ab369.dblock.zip.aes
2

I had the same error before updating to the new version… Sorry, I didn’t mention that on my previous post :slight_smile:

3

any updates on this? For debugging I can send any logs if needed. thanks.

4

In your particular case those look like real errors but I believe they’re all caused by the “The request timed out” problem.

So when Duplicati made a request to the destination for a set of 1 dlist, 1 dindex, and 1 dblock file from the destination timed out and didn’t send the files. This caused all the later warnings / errors about not being able to process the files.

In this case, the step that failed was the verification step that checks destination files for issues, so your backup is actually running (you can even check that it shows up in the Restore list).

If this timeout happens EVERY run there’s probably an issue with your destination or connection speed and there are some settings we can try to increase the timeout duration.