My file server is down. The last backup, of which I have a copy, contains relevant logs I need to inspect. So I go to restore direct from backup. The restore appears to work… almost. Every directory in my log repo got created in the alternate destination. And every file got created, with 0 length. And for every file, I got one of these: {"ClassName":"System.IO.FileNotFoundException","Message":"Could not find file \"/home/david/ServerLogs/wtmp\"","Data":null,"InnerException":null,"HelpURL":null,"StackTraceString":" at System.IO.FileStream..ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share, System.Int32 bufferSize, System.Boolean anonymous, System.IO.FileOptions options) [0x0019e] in <533173d24dae460899d2b10975534bb0>:0 \n at System.IO.FileStream..ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share) [0x00000] in <533173d24dae460899d2b10975534bb0>:0 \n at (wrapper remoting-invoke-with-check) System.IO.FileStream..ctor(string,System.IO.FileMode,System.IO.FileAccess,System.IO.FileShare)\n at System.IO.File.OpenRead (System.String path) [0x00000] in <533173d24dae460899d2b10975534bb0>:0 \n at Duplicati.Library.Common.IO.SystemIOLinux.FileOpenRead (System.String path) [0x00000] in <6e4f34e913fd4d89b628a5a76045f19c>:0 \n at Duplicati.Library.Main.Operation.RestoreHandler.DoRun (Duplicati.Library.Main.Database.LocalDatabase dbparent, Duplicati.Library.Utility.IFilter filter, Duplicati.Library.Main.RestoreResults result) [0x00658] in <e60bc008dd1b454d861cfacbdd3760b9>:0 ","RemoteStackTraceString":null,"RemoteStackIndex":0,"ExceptionMethod":null,"HResult":-2147024894,"Source":"mscorlib","FileNotFound_FileName":"/home/david/ServerLogs/wtmp","FileNotFound_FusionLog":null}
This really feels like I am doing something just one degree shy of brilliant. But what might it be?
This is the specified alternate restore destination, correct?
Are backup & restore Linux, or is there Windows involved?
What log were those in? Restore is capable of quite detailed logging, but you’d either watch in About → Show log → Live → Verbose or have to figure out where to set up the log file and log level. I think it’s in screen 2 for Direct restore, but you have to type it in manually (no dropdown offering the options…).
I found this log behind the Live Logs button, after choosing Show Logs from the About screen. There is a selector for Stored or Live, and with Live you get a dropdown to select the level. I chose Warning.
The logs from Verbose are there - the log sample I gave was for that one of the 500+ files that failed to restore. Nothing more except a log item for each file detail that only says, “Testing restored file integrity: /home/david/ServerLogs/wtmp” And so on for all those.
This is at the end of the restore. What was before those? Must be something. Do a test restore if needed.
EDIT:
Here’s an example of a verbose restore log. Live log showed the same thing, when it’s set up in advance.
2021-06-30 18:15:35 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation List has started
2021-06-30 18:15:35 -04 - [Information-Duplicati.Library.Main.Operation.ListFilesHandler-NoLocalDatabase]: No local database, accessing remote store
2021-06-30 18:15:35 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2021-06-30 18:15:35 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (3 bytes)
2021-06-30 18:15:35 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20210630T221242Z.dlist.zip.aes (1.59 KB)
2021-06-30 18:15:35 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20210630T221242Z.dlist.zip.aes (1.59 KB)
2021-06-30 18:15:36 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started
2021-06-30 18:15:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2021-06-30 18:15:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (3 bytes)
2021-06-30 18:15:37 -04 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 1 filelists
2021-06-30 18:15:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20210630T221242Z.dlist.zip.aes (1.59 KB)
2021-06-30 18:15:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20210630T221242Z.dlist.zip.aes (1.59 KB)
2021-06-30 18:15:37 -04 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RecreateOrUpdateOnly]: Recreate/path-update completed, not running consistency checks
2021-06-30 18:15:38 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation List has started
2021-06-30 18:15:38 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation List has started
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (3 bytes)
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 1 filelists
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20210630T221242Z.dlist.zip.aes (1.59 KB)
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20210630T221242Z.dlist.zip.aes (1.59 KB)
2021-06-30 18:16:37 -04 - [Verbose-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-ProcessingFilelistVolumes]: Processing filelist volume 1 of 1
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-FilelistsRestored]: Filelists restored, downloading 1 index files
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ic236933dfe6f477998b0974bc11e46d8.dindex.zip.aes (1.47 KB)
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ic236933dfe6f477998b0974bc11e46d8.dindex.zip.aes (1.47 KB)
2021-06-30 18:16:37 -04 - [Verbose-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-ProcessingIndexlistVolumes]: Processing indexlist volume 1 of 1
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RecreateCompletedCheckingDatabase]: Recreate completed, verifying the database consistency
2021-06-30 18:16:37 -04 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RecreateCompleted]: Recreate completed, and consistency checks completed, marking database as complete
2021-06-30 18:16:38 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Restore has started
2021-06-30 18:16:38 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2021-06-30 18:16:38 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (3 bytes)
2021-06-30 18:16:38 -04 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (6/30/2021 10:12:42 PM) ...
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Database.LocalRestoreDatabase-RestoreTargetFileCount]: Needs to restore 8 files (77.16 KB)
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MappingRestorePath]: Mapping restore path prefix to "/tmp/source/" to "/tmp/restore/"
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Database.LocalRestoreDatabase-RestoreSourceSize]: Restore list contains 17 blocks with a total size of 78.84 KB
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.1
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.2.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.3.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.4.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.5.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.6.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-MissingTargetFile]: Target file does not exist: /tmp/restore/syslog.7.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.1
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.1
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.2.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.2.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.3.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.3.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.4.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.4.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.5.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.5.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.6.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.6.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-LocalSourceMissing]: Local source file not found: /tmp/source/syslog.7.gz
2021-06-30 18:16:38 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-FilePatchedWithLocal]: Target file is not patched any local data: /tmp/restore/syslog.7.gz
2021-06-30 18:16:38 -04 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 1 remote files are required to restore
2021-06-30 18:16:38 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b97511684f1784bddb9386bc332c639a4.dblock.zip.aes (24.62 KB)
2021-06-30 18:16:39 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b97511684f1784bddb9386bc332c639a4.dblock.zip.aes (24.62 KB)
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.1
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.2.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.3.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.4.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.5.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.6.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFile]: Patching file with remote data: /tmp/restore/syslog.7.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.1
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.2.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.3.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.4.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.5.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.6.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-RecordingMetadata]: Recording metadata from remote data: /tmp/restore/syslog.7.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.1
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.2.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.3.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.4.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.5.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.6.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-PatchingMetadata]: Patching metadata with remote data: /tmp/restore/syslog.7.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.1
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.2.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.3.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.4.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.5.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.6.gz
2021-06-30 18:16:39 -04 - [Verbose-Duplicati.Library.Main.Operation.RestoreHandler-TestFileIntegrity]: Testing restored file integrity: /tmp/restore/syslog.7.gz
root@ted-VirtualBoxLinuxMint:/tmp#
Test here was a copy of /var/log/syslog* moved to /tmp/source, backed up, then folder renamed to mimic direct restore to a different system. Only thing changed on the restore screen was the folder to restore to.
The Patching file with remote data lines are how files are built. If original source were around (and possibly in your restore you have some similar-looking files due to distro similarity), files are scanned for any blocks that still apply to restore (avoids some downloading). For administrative files, some might not allow non-root to read them. I didn’t test this scenario. My test backup and restore were both done as root.
Whatever can’t be obtained locally is obtained remotely, then blocks from remote are patched into restore.
Local scan can be avoided by setting no-local-blocks option. I’m not sure where yours is getting confused.
OK - test restore of 1 file. After reading all the index blocks it threw this error:
{"ClassName":"Mono.Data.Sqlite.SqliteException","Message":"SQLite error\r\ncannot rollback - no transaction is active","Data":null,"InnerException":null,"HelpURL":null,"StackTraceString":" at Mono.Data.Sqlite.SQLite3.Reset (Mono.Data.Sqlite.SqliteStatement stmt) [0x00084] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SQLite3.Step (Mono.Data.Sqlite.SqliteStatement stmt) [0x0003d] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x00104] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteDataReader..ctor(Mono.Data.Sqlite.SqliteCommand,System.Data.CommandBehavior)\n at Mono.Data.Sqlite.SqliteCommand.ExecuteReader (System.Data.CommandBehavior behavior) [0x00006] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SqliteTransaction.IssueRollback (Mono.Data.Sqlite.SqliteConnection cnn) [0x00012] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SqliteTransaction.Rollback () [0x00008] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at Mono.Data.Sqlite.SqliteTransaction.Dispose (System.Boolean disposing) [0x00018] in <83c72f6e53eb49f28420feee73a4aa07>:0 \n at System.Data.Common.DbTransaction.Dispose () [0x00000] in <d3b33a5f75ba43539b447fcfaf55c885>:0 \n 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) [0x00f14] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Library.Main.Operation.RecreateDatabaseHandler.Run (System.String path, Duplicati.Library.Utility.IFilter filter, Duplicati.Library.Main.Operation.RecreateDatabaseHandler+NumberedFilterFilelistDelegate filelistfilter, Duplicati.Library.Main.Operation.RecreateDatabaseHandler+BlockVolumePostProcessor blockprocessor) [0x00037] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Library.Main.Operation.RepairHandler.RunRepairLocal (Duplicati.Library.Utility.IFilter filter) [0x000ba] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Library.Main.Operation.RepairHandler.Run (Duplicati.Library.Utility.IFilter filter) [0x00012] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Library.Main.Controller+<>c__DisplayClass18_0.<Repair>b__0 (Duplicati.Library.Main.RepairResults result) [0x0001c] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action1[T] method) [0x0026f] in :0 \n at Duplicati.Library.Main.Controller.RunAction[T] (T result, Duplicati.Library.Utility.IFilter& filter, System.Action1[T] method) [0x00007] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Library.Main.Controller.Repair (Duplicati.Library.Utility.IFilter filter) [0x0001a] in <e60bc008dd1b454d861cfacbdd3760b9>:0 \n at Duplicati.Server.Runner.Run (Duplicati.Server.Runner+IRunnerData data, System.Boolean fromQueue) [0x003ad] in <156011ea63b34859b4073abdbf0b1573>:0 ","RemoteStackTraceString":null,"RemoteStackIndex":0,"ExceptionMethod":null,"HResult":-2147467259,"Source":"Mono.Data.Sqlite"}
The target machine (my desktop) runs mono 6.12 under Debian 10. The powered-off server from which this backup originates runs mono 6.8 under Ubuntu 20.04.
My tmp drive was filling up. It’s too small, I can fix that later. That was killing my restore’s DB rebuild.
I set the tempdir to a new directory on a very big drive
Duplicati used the /tmp/ ANYWAY, for the rebuilt database. After a restart of the service, even.
Duplicati did use the new tempdir for opening and inspecting all the index files, but that was not enough to save the restore attempt because the database build could not finish.
Log files (especially at Profiling, but there’s no telling what you want at any given time) can be large.
You need to ask for them to be made. For Direct restore, it’s not quite as simple as for regular jobs.
–log-file=<path> –log-file-log-level=verbose (can be higher or lower, but verbose gives a good view without showing SQL)
Or watch live log during the first part of the restore. I’m not sure how far back it can go, but disk logs can keep as long a history as you’re willing to have. Use less or some similar large-text viewer if you need to.
The info here is still short on context, including the short error message on the first line, and nearby lines.
sounds a bit like it got through the Processing indexlist volume 1 of * line. What were the next lines (without clicking for details)? I’m surprised that it made files at this point, let alone do the verification at end.
Note that SQLite will always put temporary files in the system default temporary folder.
Consider using the TMPDIR environment variable on Linux to set the temporary folder for both Duplicati and SQLite.
I suppose an enhancement (at least sometimes, for some people) might be to set TMPDIR from tempdir, however it would need to be studied (possibly using a GitHub issue) for unwanted effects, e.g. on scripts.
You can certainly open one (which might sit in the big queue), especially if you have steps to reproduce it.
Ideally it would be a procedure that anyone can do with little special equipment, which might be a bit hard.
I’m pretty sure Linux itself can have trouble when tmp fills, and you don’t want to break anyone’s systems.
The Difference Between a tmpfs and ramfs RAM Disk suggests that maybe tmpfs would be suitable for a space-limited area that Duplicati and SQLite could be pointed to. Even the SQLite database (I think) using dup-* for its file name, so it’s hard to know what’s what among the live files (or any leftovers that happen).
Generally one has to do some sort of a dump of the file start (and guess a bit), or see what tools can open whatever it is. Or maybe the file command can help guess. Most files are probably either .zip or SQLite, provided you can get the problem without encryption. With encryption, there may be encrypted files as well.
Whether or not you can get a handle on the actual tmp files, some sort of log file would probably be helpful.
