Regenerating database freezes at ~75%


#1

Hello,

I was unable to restore a file as there were files missing from the remote storage according to Duplicati if I remember correctly. I was prompted to do a repair of the database, which also eventually failed, so I had selected to recreate the database. This has been going well so far until about 75%, where the bar just freezes. Here’s a screenshot. NeOEwkrv.png - File Host

The recreation has been running for multiple days now and seems to be doing absolutely nothing. I don’t see any activity in network logs to the storage machine.

I have an urgent backup that I need to restore so I cannot start fresh, unfortunately.
I’m running Duplicati - 2.0.4.5_beta_2018-11-28 on Ubuntu 16.04.5 LTS.

Where would I be able to locate any logs that may resolve what is causing this?

Thanks in advance!


#2

Does anything appear in the database internal log?

SELECT  * 
  FROM  logdata 
 ORDER  BY timestamp DESC;

#3

I’m in a similar situation, also 2.0.4.5_beta but Ubuntu 18.04.

According to the live logs in the web UI, it is processing all of the dblock.zip.gpg files. Each one is taking about 6 minutes, and there are over 4000 of them. The CPU is pegged to 100%, and it has taken over a day to get to this point. If all the dblock files do need to be downloaded, I’m looking at an other 18 days of uninterrupted rebuild.


#4

How large is the backup source, and are there a lot of versions? Sometimes the (unfortunate) normal time for a backup to recreate its database is longer than desired. It would also be worth checking the live log at About --> Show log --> Live --> Profiling (for lots of output, or Information level for less) to see if there’s any activity seen. Looking for disk activity on the system with the database is also useful. Some DB queries can get slow.

For an urgent restore without a database, Restore --> Direct restore from backup files can be used, however it does need a Duplicati system that isn’t already busy. Installing a second system can allow Restoring files if your Duplicati installation is lost processing, however don’t try anything more than Direct restore because two Duplicati installations sharing a destination can suffer confusion and loss of backup.

Although I’d prefer to know what’s up with the database recreate, abandoning it will let the original Duplicati installation do your Direct restore. If you need information to feed in, you should be able to view the job normally because job configurations are in a different database than the (damaged) one on backup output.

EDIT: A direct restore creates a partial temporary database, which should run faster especially if the restore isn’t the complete backup. It also won’t have to try to recreate info on the other versions that there might be.


#5

I’d like to thank everyone for your suggestions of what to do.

How large is the backup source, and are there a lot of versions?

The backup source is 151.65 GB, the backup total is 162.70 GB / 12 Versions.

It would also be worth checking the live log at About --> Show log --> Live --> Profiling
It does seem like it is doing stuff, but just very very slowly.

I’m going to cancel the current progress and run a direct restore, then start the backups from fresh with a new database after.


#6

I’m getting this error when trying to directly restore the backup.
Here is a screenshot of the log. illrbxzQ.png - File Host


#7

As an update, trying to select repair database still seems to fail.


#8

I’ve been looking at “The version(s) being updated to, already exists” because it was where your screenshot ended," This has never been reported before in the forum, and only once in GitHub issues (without answer), therefore this might take awhile (or not be possible by me). Finding the code is easy, but the whole flow isn’t.

You could try a couple of things to see if you can dodge issues to at least get your urgent restore finished…

You’re presumably in the Database option of your backup doing the repair. When trying “Direct restore”, the partial recreation might be noticed and cause a complaint like you got about the version already being there. Moving the broken database out of the way might possibly avoid that, and allow the “Direct restore” to work.

Are there any other versions of interest other than the one you had tried “Direct restore” on, if it got that far? Possibly you can restore something more-or-less-the-same as your ideal version, if that would help anything.

If you have another Linux system to install Duplicati, maybe it won’t get tripped up by whatever this one sees, which from the code looks like it already sees this version in the database (or maybe it sees a version twice). Are you seeing any duplication signs, for example in “Restore” offerings or in “dlist” files with the same time?

If need be, there are about two more levels of increasingly manual restore that you could try using if needed. Possibly one of them will be relaxed enough about the error checking, yet still sound enough to do a restore.

Recovering by using the Duplicati Recovery tool is one that’s not too hard, but does require download + disk.

If that won’t do it, it will at least have left a download of everything, then there’s a script that can do a restore.

With about four types of restore available, maybe one will work without getting tripped up on some problem…

I’m sorry things are not going well. The recreate algorithm is getting some rewrites, but I doubt you can wait…


#9

I’ll try resetting my Duplicati configuration altogether by moving the databases out like you suggested, and trying a direct restore once again. If that fails, I’ll try on a new machine.

Within the Duplicati log I had set using some flag within the advanced options, I have this error here.

cat /tmp/duplicati.log
2018-12-09 02:15:05 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-09 02:15:05 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-09 02:16:44 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-09 02:17:44 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-09 02:19:30 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-09 02:19:30 +01 - [Warning-Duplicati.Library.Main.Operation.RepairHandler-InProgressDatabase]: The database is marked as "in-progress" and may be incomplete.
2018-12-09 02:28:15 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-09 02:28:15 +01 - [Warning-Duplicati.Library.Main.Operation.RepairHandler-InProgressDatabase]: The database is marked as "in-progress" and may be incomplete.
2018-12-09 02:32:20 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-12 17:14:27 +01 - [Error-Duplicati.Library.Main.Database.LocalRecreateDatabase-BlocksetInsertFailed]: Blockset insert failed, comitting temporary tables for trace purposes
System.Threading.ThreadAbortException: Thread was being aborted.
  at (wrapper managed-to-native) Mono.Data.Sqlite.UnsafeNativeMethods.sqlite3_step(intptr)
  at Mono.Data.Sqlite.SQLite3.Step (Mono.Data.Sqlite.SqliteStatement stmt) [0x00025] in <5874f0c55a674ffc901a91a755e391d7>:0
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x00104] in <5874f0c55a674ffc901a91a755e391d7>:0
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <5874f0c55a674ffc901a91a755e391d7>:0
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteDataReader..ctor(Mono.Data.Sqlite.SqliteCommand,System.Data.CommandBehavior)
  at Mono.Data.Sqlite.SqliteCommand.ExecuteReader (System.Data.CommandBehavior behavior) [0x00006] in <5874f0c55a674ffc901a91a755e391d7>:0
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <5874f0c55a674ffc901a91a755e391d7>:0
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteNonQuery (System.Data.IDbCommand self, System.Boolean writeLog, System.String cmd, System.Object[] values) [0x0005e] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteNonQuery (System.Data.IDbCommand self, System.String cmd, System.Object[] values) [0x00000] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
  at Duplicati.Library.Main.Database.LocalRecreateDatabase.FindMissingBlocklistHashes (System.Int64 hashsize, System.Int64 blocksize, System.Data.IDbTransaction transaction) [0x0012e] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
2018-12-12 17:14:39 +01 - [Warning-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-FailedRebuildingWithFile]: Failed to use information from duplicati-b896a276044564ec5afb6b49f6681459b.dblock.zip.aes to rebuild database: The recreate failed, please create a bug-report from this database and send it to the developers for further analysis
System.Exception: The recreate failed, please create a bug-report from this database and send it to the developers for further analysis
  at Duplicati.Library.Main.Database.LocalRecreateDatabase.FindMissingBlocklistHashes (System.Int64 hashsize, System.Int64 blocksize, System.Data.IDbTransaction transaction) [0x001b7] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
  at Duplicati.Library.Main.Operation.RecreateDatabaseHandler.DoRun (Duplicati.Library.Main.Database.LocalDatabase dbparent, System.Boolean updating, Duplicati.Library.Utility.IFilter filter, Duplicati.Library.Main.Operation.RecreateDatabaseHandler+NumberedFilterFilelistDelegate filelistfilter, Duplicati.Library.Main.Operation.RecreateDatabaseHandler+BlockVolumePostProcessor blockprocessor) [0x011e5] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
2018-12-12 17:14:39 +01 - [Warning-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-FailedRebuildingWithFile]: Failed to use information from duplicati-b89be740428444ef78f48b59ef1a3e1e7.dblock.zip.aes to rebuild database: Cancelled
Duplicati.Library.Interface.CancelException: Cancelled
  at Duplicati.Library.Main.BasicResults.TaskControlRendevouz () [0x00038] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
  at Duplicati.Library.Main.BasicResults.TaskControlRendevouz () [0x00008] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
  at Duplicati.Library.Main.Operation.RecreateDatabaseHandler.DoRun (Duplicati.Library.Main.Database.LocalDatabase dbparent, System.Boolean updating, Duplicati.Library.Utility.IFilter filter, Duplicati.Library.Main.Operation.RecreateDatabaseHandler+NumberedFilterFilelistDelegate filelistfilter, Duplicati.Library.Main.Operation.RecreateDatabaseHandler+BlockVolumePostProcessor blockprocessor) [0x010b4] in <c6c6871f516b48f59d88f9d731c3ea4d>:0
2018-12-12 17:15:28 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-12 17:16:11 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-12 19:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-12 22:16:53 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 01:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 04:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 07:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 10:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 13:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 16:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 19:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 22:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 22:40:37 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 22:40:37 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 22:47:48 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 23:21:55 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-13 23:21:55 +01 - [Warning-Duplicati.Library.Main.Operation.RepairHandler-InProgressDatabase]: The database is marked as "in-progress" and may be incomplete.
2018-12-14 01:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 04:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 07:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 10:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 13:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 16:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 17:47:13 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-14 17:47:13 +01 - [Warning-Duplicati.Library.Main.Operation.RepairHandler-InProgressDatabase]: The database is marked as "in-progress" and may be incomplete.
2018-12-14 19:00:00 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored

Would this be any help?


#10

Warning: “SSH Fingerprint is not supported” might cover that presumably understood-but-harmless message.

Unfortunately “Blockset insert failed, comitting temporary tables for trace purposes” is back in never-reported territory, but at least there’s some history to trace which might mean something to the right expert (not to me).

Added debugging code that dumps the temporary tables as permanent tables if the error from #1699, #2048, #2140, or #2178

#1699, #2048, #2140, and #2178 received a fix around Jan 2017 (which I have not looked for), but its debug code remained. It’s basically putting relevant information in a database that could be sent in to the right party.

To me, the code behind that message is interesting, in that an exception arose from an SQL query, somehow, however the specific stack trace that SQLite made is beyond my immediate ability to recognize SQLite issues.

EDIT: One possibility is that this sort of error happens due to an operator cancellation after many days wait…

2018-12-09 02:32:20 +01 - [Warning-Duplicati.Library.Main.Controller-UnsupportedOption]: The supplied option --ssh-fingerprint is not supported and will be ignored
2018-12-12 17:14:27 +01 - [Error-Duplicati.Library.Main.Database.LocalRecreateDatabase-BlocksetInsertFailed]: Blockset insert failed, comitting temporary tables for trace purposes
System.Threading.ThreadAbortException: Thread was being aborted.

#11

I hope that they won’t be causing much of an issue for the following holdups that I’m getting. So, I’ve now got to the point where I can choose the date of my direct restore, but when I select the date, it loads for some time and displays a timeout, although I assume my tiredness and stupidity may be playing a part here. Here’s a screenshot. LNuKTLtx.png - File Host

Also, thank you again, everyone who has helped along the way.


#12

The “Gateway Time-out” error does not seem to exist in Duplicati code, but from where it was seen, maybe it’s something returned to Duplicati from a third-party library used to get to destinations. What’s the storage type?

By the way, I’d think a Direct restore would need access to the backend to even offer the dates, so I’m not sure why it would start getting an error after awhile (assuming this is the backend). Or are speed and errors erratic?


#13

Our storage server is a Hetzner Storage Box.

All other Duplicati instances connect to it via FTP with SSL although when trying to directly restore and connect to it via that, it doesn’t work so I need to use SFTP. Directly generating the restore directly’s database thingy takes about 1 hour each time. I’m going to try copying the files straight to the machine which I’m trying to restore to so that potentially poor upload speeds from Hetzner won’t be a factor.


#14

Alright. Even from trying to load the files locally, I still seem to have the gateway timeout issue, although nothing within the profile live logging is displaying anything that might help, same with the regular stored log.

I get one folder within the list, and when I try and load files for it, it just shows a loading wheel and then times out.

I’ve taken a video (it’s about 1 minute long, just skip to about 55 seconds) SdqDdBXK.mp4 - File Host.


#15

TL;DR Maybe you can try command line restore without the server involved, in case this was an HTTP error.

I still have no solid idea of where that error is coming from. Searching Duplicati’s installation executables did find the string inside Microsoft.Data.OData.dll which seems to be mentioned in the Duplicati Microsoft Azure source code, however I don’t think you have any Azure uses. Another concept of a “Gateway Time-out” is a web server 504 response, however a quick scan of the web server that Duplicati includes to serve its web UI over an internal API doesn’t appear to show any code that can send a 504. Is your browser going directly to Duplicati by localhost:8200, or is it remotely connected, potentially going through a box that might be upset?

Someone who knows the Duplicati browser JavaScript code might do more with your video, but that’s not me.

Having shown that the Gateway Time-out isn’t in the path to the destination, one way to see if it’s in browser connection to Duplicati server is to not use that server. The web UI has an Export option as a command line which has all the usual server options for the job, but needs some changing to turn it to format for a restore.

Comparing formats for The BACKUP command and The RESTORE command looks like the main thing after changing the command may be to trim the list of source files. The restore is also a bit different because you don’t want it to use the broken database, so you could try deleting –dbpath and instead give it –no-local-db. Setting –restore-path to some empty space would be good, to make sure nothing is overwritten by accident. Setting –version to the desired numbered version (see the video) can be done if you want a certain version.

I just moved one of my backup local databases aside temporarily, did such a restore, and got a file restored. Setting –console-log-level=Verbose gave me some more logging without the (overwhelming) Profiling output. This might not really add much to your run, because anything at Warning or higher will be shown regardless.


#16

Hello,

Thank you so much. Using command line has successfully restored the files.


#17

That’s a relief. I’m sorry there was such a series of obstacles to go through. This one was unusually difficult. Slow database recreation is annoying, but a known thing. Fixes may be underway. Other issues were odd… Gateway Time-out might be explainable by the right IT person. Another workaround might be X, VNC, or NX.