Problems with local database, repair fails

lgretton · May 20, 2024, 9:43pm

I’m running 2.0.6.104_canary_2022-06-15 on FreeBSD with mono 6, but have also tried with duplicati-2.0.7.103_canary_2024-04-19 with the same result. Backups go to Jottacloud.

In the last couple of weeks the local database somehow got corrupted and stupidly I didn’t have any backups. Worse, attempts to repair the database also fail.

This is one the error thrown, but for all seven backups I have configured all complain about ‘no such column: Uploading’ in SQLite.

2024-05-02 04:01:06 +01 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error
Mono.Data.Sqlite.SqliteException (0x80004005): SQLite error
no such column: Uploading
  at Mono.Data.Sqlite.SQLite3.Prepare (Mono.Data.Sqlite.SqliteConnection cnn, System.String strSql, Mono.Data.Sqlite.SqliteStatement previous, System.UInt32 timeoutMS, System.String& strRemain) [0x001f8] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <fc0add2ecbf5433e96a69b44abcd0e26>: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 <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteCommand.ExecuteDbDataReader (System.Data.CommandBehavior behavior) [0x00000] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader () [0x00000] in <e352a0b066634c9fa13d1dfddeeb797a>:0
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteReader (System.Data.IDbCommand self, System.Boolean writeLog, System.String cmd, System.Object[] values) [0x0005e] in <7201532dcc0443468ec0ba778f89f3ac>:0
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteReader (System.Data.IDbCommand self, System.String cmd, System.Object[] values) [0x00000] in <7201532dcc0443468ec0ba778f89f3ac>:0
  at Duplicati.Library.Main.Database.LocalBackupDatabase+<GetIncompleteFilesets>d__48.MoveNext () [0x00056] in <7201532dcc0443468ec0ba778f89f3ac>:0
  at System.Collections.Generic.EnumerableHelpers.ToArray[T] (System.Collections.Generic.IEnumerable`1[T] source, System.Int32& length) [0x00032] in <4e0b4fa81dd04effbc4e22d8fabefb81>:0
  at System.Linq.Buffer`1[TElement]..ctor (System.Collections.Generic.IEnumerable`1[T] source) [0x00022] in <4e0b4fa81dd04effbc4e22d8fabefb81>:0
  at System.Linq.OrderedEnumerable`1[TElement].ToArray () [0x00000] in <4e0b4fa81dd04effbc4e22d8fabefb81>:0
  at System.Linq.Enumerable.ToArray[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x0001f] in <4e0b4fa81dd04effbc4e22d8fabefb81>:0
  at Duplicati.Library.Main.Operation.Backup.BackupDatabase.<GetIncompleteFilesetsAsync>b__26_0 () [0x00035] in <7201532dcc0443468ec0ba778f89f3ac>:0
  at Duplicati.Library.Main.Operation.Common.SingleRunner+<>c__DisplayClass4_0`1[T].<RunOnMain>b__0 () [0x00000] in <7201532dcc0443468ec0ba778f89f3ac>:0
  at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T] (System.Func`1[TResult] method) [0x000b0] in <7201532dcc0443468ec0ba778f89f3ac>:0
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x003e0] in <7201532dcc0443468ec0ba778f89f3ac>:0

I’ve therefore been trying to repair from the remote copy and it seems to make progress but fails with a missing column error. The repair error always occurs with the file duplicati-iff1942b529664874994901d4240eba83.dindex.zip.aes so I suppose that’s broken.

To force it to repair the local database files I’ve moved them all out of the way so there are none of the originals present.

mono /opt/duplicati/Duplicati.CommandLine.exe repair "jottacloud://NAS-home?authid=blahblah" --passphrase=secret --dbpath=/pool/duplicati/XXXXXXXX.sqlite
...
  Downloading file duplicati-ifa2c2e9d1c6d48f1b9f6c970eef5be3a.dindex.zip.aes (39.00 KB) ...
  Downloading file duplicati-ifa75ff0d6bb04cb3b6f7698e34d0f9d1.dindex.zip.aes (111.73 KB) ...
  Downloading file duplicati-ifc3582f9ee894856bc76386666108b31.dindex.zip.aes (38.25 KB) ...
  Downloading file duplicati-iff1942b529664874994901d4240eba83.dindex.zip.aes (39.17 KB) ...
The operation Repair has failed with error: SQLite error
no such column: Temporary => SQLite error
no such column: Temporary

Mono.Data.Sqlite.SqliteException (0x80004005): SQLite error
no such column: Temporary
  at Mono.Data.Sqlite.SQLite3.Prepare (Mono.Data.Sqlite.SqliteConnection cnn, System.String strSql, Mono.Data.Sqlite.SqliteStatement previous, System.UInt32 timeoutMS, System.String& strRemain) [0x001f8] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <fc0add2ecbf5433e96a69b44abcd0e26>: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 <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at Mono.Data.Sqlite.SqliteCommand.ExecuteDbDataReader (System.Data.CommandBehavior behavior) [0x00000] in <fc0add2ecbf5433e96a69b44abcd0e26>:0
  at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader () [0x00000] in <e352a0b066634c9fa13d1dfddeeb797a>:0
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteScalarInt64 (System.Data.IDbCommand self, System.Boolean writeLog, System.String cmd, System.Int64 defaultvalue, System.Object[] values) [0x00061] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteScalarInt64 (System.Data.IDbCommand self, System.String cmd, System.Int64 defaultvalue) [0x00000] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Database.LocalRecreateDatabase.CleanupMissingVolumes () [0x000a7] in <ae72375292024ca7973ea30ee968be19>: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) [0x00f53] in <ae72375292024ca7973ea30ee968be19>:0
  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 <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Operation.RepairHandler.RunRepairLocal (Duplicati.Library.Utility.IFilter filter) [0x000ba] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Operation.RepairHandler.Run (Duplicati.Library.Utility.IFilter filter) [0x00012] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Controller+<>c__DisplayClass18_0.<Repair>b__0 (Duplicati.Library.Main.RepairResults result) [0x0001c] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0036c] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x00007] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.Library.Main.Controller.Repair (Duplicati.Library.Utility.IFilter filter) [0x0001a] in <ae72375292024ca7973ea30ee968be19>:0
  at Duplicati.CommandLine.Commands.Repair (System.IO.TextWriter outwriter, System.Action`1[T] setup, System.Collections.Generic.List`1[T] args, System.Collections.Generic.Dictionary`2[TKey,TValue] options, Duplicati.Library.Utility.IFilter filter) [0x00030] in <b9dc98523f964e4ea76bc0460ac2f551>:0
  at (wrapper delegate-invoke) System.Func`6[System.IO.TextWriter,System.Action`1[Duplicati.Library.Main.Controller],System.Collections.Generic.List`1[System.String],System.Collections.Generic.Dictionary`2[System.String,System.String],Duplicati.Library.Utility.IFilter,System.Int32].invoke_TResult_T1_T2_T3_T4_T5(System.IO.TextWriter,System.Action`1<Duplicati.Library.Main.Controller>,System.Collections.Generic.List`1<string>,System.Collections.Generic.Dictionary`2<string, string>,Duplicati.Library.Utility.IFilter)
  at Duplicati.CommandLine.Program.ParseCommandLine (System.IO.TextWriter outwriter, System.Action`1[T] setup, System.Boolean& verboseErrors, System.String[] args) [0x00342] in <b9dc98523f964e4ea76bc0460ac2f551>:0
  at Duplicati.CommandLine.Program.RunCommandLine (System.IO.TextWriter outwriter, System.IO.TextWriter errwriter, System.Action`1[T] setup, System.String[] args) [0x00002] in <b9dc98523f964e4ea76bc0460ac2f551>:0

Trying to recover from any of the backups seems to be fine, though I haven’t thoroughly tested that. I can certainly browse the backups without any problems.

Is there any hope of repairing the local database?

Thanks for any assistance offered.

Jojo-1000 · May 20, 2024, 11:47pm

Seems to be about your sqlite version, combined with an incorrect (but usually working) query:

github.com

duplicati/duplicati/blob/54b9063f1ba807c78c1f31f412d36c0a803aff87/Duplicati/Library/Main/Database/LocalRecreateDatabase.cs#L708


      
          DROP TABLE ""{tablename}"";

          

          DELETE FROM ""IndexBlockLink"" WHERE ""BlockVolumeID"" IN (SELECT ""ID"" FROM ""RemoteVolume"" WHERE ""Type"" = ""{RemoteVolumeType.Blocks}"" AND ""State"" = ""{RemoteVolumeState.Temporary}"" AND ""ID"" NOT IN (SELECT DISTINCT ""VolumeID"" FROM ""Block""));

          DELETE FROM ""DuplicateBlock"" WHERE ""VolumeID"" IN (SELECT ""ID"" FROM ""RemoteVolume"" WHERE ""Type"" = ""Blocks"" AND ""State"" = ""{RemoteVolumeState.Temporary}"" AND ""ID"" NOT IN (SELECT DISTINCT ""VolumeID"" FROM ""Block""));

          DELETE FROM ""RemoteVolume"" WHERE ""Type"" = ""{RemoteVolumeType.Blocks}"" AND ""State"" = ""{RemoteVolumeState.Temporary}"" AND ""ID"" NOT IN (SELECT DISTINCT ""VolumeID"" FROM ""Block"");

          ";

          

          // We could delete these, but we don't have to, so we keep them around until the next compact is done

          // UPDATE ""RemoteVolume"" SET ""State"" = ""{3}"" WHERE ""Type"" = ""{5}"" AND ""ID"" NOT IN (SELECT ""IndexVolumeID"" FROM ""IndexBlockLink"");

          

          			var countsql = @"SELECT COUNT(*) FROM ""RemoteVolume"" WHERE ""State"" = ""Temporary"" AND ""Type"" = ""Blocks"" ";

          

          			using (var cmd = m_connection.CreateCommand())

          			{

          				var cnt = cmd.ExecuteScalarInt64(countsql);

          				if (cnt > 0)

          				{

          					Logging.Log.WriteWarningMessage(LOGTAG, "MissingVolumesDetected", null, "Found {0} missing volumes; attempting to replace blocks from existing volumes", cnt);

          					cmd.ExecuteNonQuery(sql);

          

          					var cnt2 = cmd.ExecuteScalarInt64(countsql);

This uses double quotes for strings, which is incorrect. It should be single quotes, but is accepted for compatibility.

https://www.sqlite.org/quirks.html#double_quoted_string_literals_are_accepted

As of SQLite 3.41.0 (2023-02-21) SQLITE_DBCONFIG_DQS_DDL and SQLTIE_DBCONFIG_DQS_DML are disabled by default in the CLI. Use the “.dbconfig” dot-command to reenable the legacy behavior if desired.

It seems that the since version 3.41 the default might have changed. That is a good motivation to finally clean up these statements.

Edit:

To clarify, there is probably nothing wrong with your database. If you still have the first original one, you can keep using that. It will save you some time from recreate and also keep the old logs.

I am not sure if you can manually change the defaults. While duplicati has an option to execute arbitrary PRAGMA options, the relevant one is not exposed as a pragma. Maybe it is possible to downgrade sqlite in your system?

Also relevant:
https://www.reddit.com/r/freebsd/comments/1chb82b/sqlite3_pkg_just_became_stricter_with_quoting/

lgretton · May 21, 2024, 7:03am

You star! Thank you very much, an updated version of SQLite was indeed the cause. I downgraded to 3.44 and the original configuration came back and backups have been able to proceed again.

I skim the FreeBSD subreddit every few days but completely missed that post you linked to, which is the exact problem here. Naturally I don’t read every changelog when doing my monthly pkg upgrade either.

It doesn’t look like this issue has been raised in the GH issue tracker, I’ll submit something there.

The other important lesson I’ve learned is to make sure I’ve at least got regular snapshots of the duplicati databases.