Unable to restore data

federico.ballarini · March 16, 2020, 2:35pm

Hi all,
I’m trying to restore data from a backup. But when I choose the backup (7 versions of files) I obtain this message:

How can I solve?

Bobo · March 16, 2020, 6:39pm

About --> Show Log --> Live --> Profiling
and post output here

federico.ballarini · March 16, 2020, 8:50pm

Hi @Bobo, here is the output:

 * Mar 16, 2020 9:49 PM: The operation List has completed

* Mar 16, 2020 9:49 PM: Running List took 0:00:03:51.716

* Mar 16, 2020 9:49 PM: ExecuteNonQuery: DROP TABLE IF EXISTS "Filesets-73AA753BBBBF3649B44B91AD248B9FC4" took 0:00:00:00.000

* Mar 16, 2020 9:49 PM: Starting - ExecuteNonQuery: DROP TABLE IF EXISTS "Filesets-73AA753BBBBF3649B44B91AD248B9FC4"

* Mar 16, 2020 9:49 PM: ExecuteReader: SELECT DISTINCT "A"."FilesetID", "B"."FileCount", "B"."FileSizes" FROM "Filesets-73AA753BBBBF3649B44B91AD248B9FC4" A LEFT OUTER JOIN ( SELECT "A"."FilesetID" AS "FilesetID", COUNT(*) AS "FileCount", SUM("C"."Length") AS "FileSizes" FROM "FilesetEntry" A, "File" B, "Blockset" C WHERE "A"."FileID" = "B"."ID" AND "B"."BlocksetID" = "C"."ID" AND "A"."FilesetID" IN (SELECT DISTINCT "FilesetID" FROM "Filesets-73AA753BBBBF3649B44B91AD248B9FC4") GROUP BY "A"."FilesetID" ) B ON "A"."FilesetID" = "B"."FilesetID" ORDER BY "A"."Timestamp" DESC took 0:00:00:23.126

* Mar 16, 2020 9:49 PM: Starting - ExecuteReader: SELECT DISTINCT "A"."FilesetID", "B"."FileCount", "B"."FileSizes" FROM "Filesets-73AA753BBBBF3649B44B91AD248B9FC4" A LEFT OUTER JOIN ( SELECT "A"."FilesetID" AS "FilesetID", COUNT(*) AS "FileCount", SUM("C"."Length") AS "FileSizes" FROM "FilesetEntry" A, "File" B, "Blockset" C WHERE "A"."FileID" = "B"."ID" AND "B"."BlocksetID" = "C"."ID" AND "A"."FilesetID" IN (SELECT DISTINCT "FilesetID" FROM "Filesets-73AA753BBBBF3649B44B91AD248B9FC4") GROUP BY "A"."FilesetID" ) B ON "A"."FilesetID" = "B"."FilesetID" ORDER BY "A"."Timestamp" DESC

* Mar 16, 2020 9:49 PM: ExecuteNonQuery: DROP TABLE IF EXISTS "Filenames-4011F7188611204B927FFEB9B89F9C02" took 0:00:00:00.156

* Mar 16, 2020 9:49 PM: Starting - ExecuteNonQuery: DROP TABLE IF EXISTS "Filenames-4011F7188611204B927FFEB9B89F9C02"

* Mar 16, 2020 9:49 PM: ExecuteNonQuery: DROP TABLE IF EXISTS "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" took 0:00:00:00.109

* Mar 16, 2020 9:49 PM: Starting - ExecuteNonQuery: DROP TABLE IF EXISTS "Filenames-C4ED8F230064564A9BB5CD40A98E38E0"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 16) = "E:\Condivisioni\" took 0:00:00:00.265

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 16) = "E:\Condivisioni\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 26) = "E:\Condivisioni\didattica\" took 0:00:00:00.281

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 26) = "E:\Condivisioni\didattica\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 36) = "E:\Condivisioni\didattica\2019-2020\" took 0:00:00:00.265

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 36) = "E:\Condivisioni\didattica\2019-2020\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 42) = "E:\Condivisioni\didattica\2019-2020\Varie\" took 0:00:00:00.249

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 42) = "E:\Condivisioni\didattica\2019-2020\Varie\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 55) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\" took 0:00:00:00.265

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 55) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 62) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\" took 0:00:00:00.312

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 62) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 77) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\" took 0:00:00:00.265

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 77) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 85) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\USBnull\" took 0:00:00:00.187

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 85) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\USBnull\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 91) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\USBnull\Null6\" took 0:00:00:00.265

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 91) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\USBnull\Null6\"

* Mar 16, 2020 9:49 PM: ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 98) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\USBnull\Null6\SputNX\" took 0:00:00:00.281

* Mar 16, 2020 9:49 PM: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Filenames-C4ED8F230064564A9BB5CD40A98E38E0" WHERE SUBSTR("Path", 1, 98) = "E:\Condivisioni\didattica\2019-2020\Varie\Progetto IDS\Lavori\inis_1.4.0null\USBnull\Null6\SputNX\"

Bobo · March 16, 2020, 8:54pm

Any other logs that could relate to the timing of the error. You have other type of logs there like: Error, warning etc

federico.ballarini · March 17, 2020, 9:34am

No logs, under Error or Warning…

ccmgr · March 17, 2020, 10:28am

Can you post the log of the backup that created version 0 (last backup)

federico.ballarini · March 17, 2020, 8:41pm

How can I retrieve this type of logs?
Thank you for your time

ccmgr · March 18, 2020, 11:31am

Click on the Down Arrow beside the Backup Job Name
Click Show Logs
Click Icon beside date
Click Complete Log
There is a copy Icon to the right once you expand it

federico.ballarini · March 18, 2020, 1:45pm

This?

Mar 16, 2020 8:30 AM: Result
MainOperation: Repair

RecreateDatabaseResults:

    MainOperation: Repair

    ParsedResult: Success

    Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

    EndTime: 16/03/2020 08:29:43 (1584343783)

    BeginTime: 15/03/2020 20:24:01 (1584300241)

    Duration: 12:05:41.3279687

    Messages: [

        2020-03-15 20:24:01 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started,

        2020-03-15 20:24:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

        2020-03-15 20:24:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (29 bytes),

        2020-03-15 20:24:20 +01 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 7 filelists,

        2020-03-15 20:24:20 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200308T034500Z.dlist.zip (41,19 MB),

...

    ]

    Warnings: []

    Errors: []

    BackendStatistics:

        RemoteCalls: 30

        BytesUploaded: 0

        BytesDownloaded: 246554718032

        FilesUploaded: 0

        FilesDownloaded: 29

        FilesDeleted: 0

        FoldersCreated: 0

        RetryAttempts: 0

        UnknownFileSize: 0

        UnknownFileCount: 0

        KnownFileCount: 0

        KnownFileSize: 0

        LastBackupDate: 01/01/0001 01:00:00 (-62135596800)

        BackupListCount: 0

        TotalQuotaSpace: 0

        FreeQuotaSpace: 0

        AssignedQuotaSpace: 0

        ReportedQuotaError: False

        ReportedQuotaWarning: False

        ParsedResult: Success

        Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

        Messages: [

            2020-03-15 20:24:01 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started,

            2020-03-15 20:24:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

            2020-03-15 20:24:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (29 bytes),

            2020-03-15 20:24:20 +01 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 7 filelists,

            2020-03-15 20:24:20 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200308T034500Z.dlist.zip (41,19 MB),

...

        ]

        Warnings: []

        Errors: []

ParsedResult: Success

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 16/03/2020 08:30:24 (1584343824)

BeginTime: 15/03/2020 20:24:01 (1584300241)

Duration: 12:06:22.4772198

Messages: [

    2020-03-15 20:24:01 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started,

    2020-03-15 20:24:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2020-03-15 20:24:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (29 bytes),

    2020-03-15 20:24:20 +01 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 7 filelists,

    2020-03-15 20:24:20 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200308T034500Z.dlist.zip (41,19 MB),

...

]

Warnings: []

Errors: []

ccmgr · March 18, 2020, 2:31pm

No that was a repair operation seems database is good/ok. The last backup Log which should be underneath it.

You might add Operating system been used. If you are access via browser or UI.

federico.ballarini · March 19, 2020, 8:35am

Sorry but I’m not able to find the log
Windows Server 2016 - Accessing via Firefox

ts678 · March 21, 2020, 12:24am

Welcome to the forum @federico.ballarini

Google search found only two forum and four GitHub reports with text “Failed to fetch path information”, and only two had no further details on the error, as yours showed, so not much help, but may help a bit.

Restore from onedrivev2 backend fails with “Failed to fetch path information” #3531 went away after a suspected speed upgrade of the network, and was never present on command line, just on the web UI.

Failed to fetch path information in Pale Moon browser [unimportant] #2392 happened using some web browsers, and had a theory involving a timeout. One thing I notice in your post is that the list operation took a long time, almost 4 minutes. Could you talk about the destination you’re backing up to, such as what destination type it is, hardware speed (if yours), and the network speed going to the destination?

The error message itself is in code that runs in the browser, so you can also test either Using Duplicati from the Command Line fed by Exporting a backup job configuration As Command-line, or Using the Command line tools from within the Graphical User Interface which might be as good, and a bit easier.

Either way, you will need to convert The BACKUP command into The RESTORE command. The main difference is that the backup source path list becomes a filename for a small test, or * or nothing if you want all files. You probably want at least the –restore-path option set to some empty area to restore to.

Is this the first restore, or did it work before? Is this a test, or an actual recovery need? How much of it are you trying to restore, and how big is the backup? Information on backup size is on its home screen.

If you’d rather wait on the command line test, giving at least the above answers will be a start, and if it continues to fail on a normal Restore, then About --> Show log --> Live --> Information will summarize. Right now it’s hard to get an overview of how slow things go, other than the 03:51.716 directory listing.

Example of Information level live log (in one tab) from a simple restore using web GUI (in another tab):

Mar 20, 2020 8:09 PM: The operation Restore has completed
Mar 20, 2020 8:09 PM: Backend event: Get - Completed: duplicati-b1caea9a9d9bd4f6893effa81f93b43cd.dblock.zip (20.03 MB)
Mar 20, 2020 8:08 PM: Backend event: Get - Started: duplicati-b1caea9a9d9bd4f6893effa81f93b43cd.dblock.zip (20.03 MB)
Mar 20, 2020 8:08 PM: 1 remote files are required to restore
Mar 20, 2020 8:08 PM: Searching backup 0 (3/14/2020 10:56:53 PM) ...
Mar 20, 2020 8:08 PM: Backend event: List - Completed: (15 bytes)
Mar 20, 2020 8:08 PM: Backend event: List - Started: ()
Mar 20, 2020 8:08 PM: The operation Restore has started
Mar 20, 2020 8:07 PM: The operation List has completed

federico.ballarini · March 21, 2020, 4:11pm

I tried by putting “*” in search field. It returns “Database is locked” but the only process using this database is Duplicati.

I try from CLI…

federico.ballarini · March 22, 2020, 2:59pm

From CLI I restored the file! Thank you!

federico.ballarini · March 23, 2020, 9:07am

Sorry @ts678. After that I re-created my backup. But still have the same problem.
Can you help me?

federico.ballarini · March 23, 2020, 9:25am

Can be a problem that I backup from 2 different disks in the same job?

ts678 · March 23, 2020, 1:56pm

Does that mean you ran a regular backup, you deleted the entire backup and started again, or other?

It shouldn’t be, especially if you aren’t seeing any warnings or errors other than the original post one.
Is that where it is now, that restore from command line works but web UI restore gives original error?
You showed a really slow list before. How long does screen 2 Destination’s Test connection take?

Need information requested earlier. Ask if anything’s unclear. Step-by-step of error with approximate timings might also help. You do something, and some time later it errors. The delay may be relevant.