Database is full database or disk is full when trying to restore

Support
1

I am running Duplicati - 2.0.2.1_beta_2017-08-01 with:

Arch Linux with 4.12.13 kernel
Mono JIT compiler version 5.0.0 (Stable 5.0.0.100/9667aa6 Wed Jul 12 17:00:30 UTC 2017)

I am trying to restore a backup (SFTP/SSH) that has the following characteristics:

Source: 14.81 GB
Backup: 15.16 GB / 109 Versions

However, I am getting the following error:

Insertion failed because the database is full database or disk is full

Prior to restoring, my system has 6 GB of RAM free, my /home partition has 190 GB free, and my / partition has 7 GB free. I do not have a TMPDIR environment variable defined. I noticed during the restore that the amount of RAM consumed increases to about 80% before I encounter the error.

Am I running into issues because of lack of RAM or disk space?

Some relevant logs are below:

Mono.Data.Sqlite.SqliteException (0x80004005): Insertion failed because the database is full
database or disk is full
  at Mono.Data.Sqlite.SQLite3.Reset (Mono.Data.Sqlite.SqliteStatement stmt) [0x00084] in <064c354e48ef46e5825b9a486d405fb4>:0 
  at Mono.Data.Sqlite.SQLite3.Step (Mono.Data.Sqlite.SqliteStatement stmt) [0x0003d] in <064c354e48ef46e5825b9a486d405fb4>:0 
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x00104] in <064c354e48ef46e5825b9a486d405fb4>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <064c354e48ef46e5825b9a486d405fb4>: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 <064c354e48ef46e5825b9a486d405fb4>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteDbDataReader (System.Data.CommandBehavior behavior) [0x00000] in <064c354e48ef46e5825b9a486d405fb4>:0 
  at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader () [0x00000] in <4d609d494dc64d199fc17ddf72e87a76>:0 
  at Duplicati.Library.Main.Database.ExtensionMethods.ExecuteReader (System.Data.IDbCommand self, System.String cmd, System.Object[] values) [0x0004e] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at Duplicati.Library.Main.Database.LocalListDatabase+FileSets+<SelectFolderContents>d__10.MoveNext () [0x00302] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at System.Linq.Enumerable+SelectEnumerableIterator`2[TSource,TResult].ToArray () [0x00030] in <a16ef142877c4302b96a103db87ba16b>:0 
  at System.Linq.Enumerable.ToArray[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x0001f] in <a16ef142877c4302b96a103db87ba16b>:0 
  at Duplicati.Library.Main.Operation.ListFilesHandler.Run (System.Collections.Generic.IEnumerable`1[T] filterstrings, Duplicati.Library.Utility.IFilter compositefilter) [0x001e9] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass23_0.<List>b__0 (Duplicati.Library.Main.ListResults result) [0x0001c] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0014b] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x00007] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at Duplicati.Library.Main.Controller.List (System.Collections.Generic.IEnumerable`1[T] filterstrings, Duplicati.Library.Utility.IFilter filter) [0x00021] in <118ad25945a24a3991f7b65e7a45ea1e>:0 
  at Duplicati.Server.Runner.Run (Duplicati.Server.Runner+IRunnerData data, System.Boolean fromQueue) [0x0047a] in <a6c0c2089b9a44ec9be5057a44f12116>:0
2

I tried specifying the tempdir advanced option to point to a partition that had a lot of free space. I was then able to restore without error. With the new tempdir, I also noticed that:

  1. The RAM usage does not increase significantly when trying to restore
  2. The new tempdir directory does not contain any files.

I reverted tempdir back to the default (/tmp) and was not able to restore (disk or database full error).

Is this behavior expected?

3

The error message is from SQLite, which writes some transaction files in the temp folder.
SQLite does not honor the --tempdir advanced option, it always uses the system environment variable TMPDIR which is also used as the default for --tempdir (in other words, if you set the TMPDIR environment variable and nothing else, all temp files go there).

I am guessing that you have some really large volumes that are downloaded into the temporary folder, which causes SQLite to run out of temporary space. What is the volume size you are using?

4

I’m using the default volume size (50MB). On the destination server, I can see a bunch of 50MB files.

The strange thing is that I see the RAM usage increase, but not the disk space usage (I will try and verify this again tonight). This is while Duplicati is trying to display the directory tree and before I’ve selected which files/folders to restore.

5

I was able to verify the following:

  1. My volume size is 50 MB.
  2. I do not have the TMPDIR environment variable set.
  3. If I set the --tempdir option, Duplicati is able to display the folder tree.
  4. If I do not set the --tempdir option, I get the error mentioned above.

Based on

Temporary Files Used By SQLite,

When --tempdir is not set, I checked the modification times of the /var/tmp, /usr/tmp, and /tmp folders, and they did not change (I would have expected the times to change if SQLite was writing to them, but I’m not sure).

My / partition has 7GB free…is it possible that Duplicati needs more than this when displaying the folder tree (my backup size is ~15GB)?

Below are some of the “profiling” logs, in case they’re helpful:

Sep 26, 2017 6:38 PM: Starting - ExecuteNonQuery: DROP TABLE IF EXISTS "Filenames-D2A47105FB845049A1E0CF93C045AB8F"
Sep 26, 2017 6:38 PM: ExecuteReader: SELECT "C"."Path", "D"."Length", "C"."FilesetID" FROM (SELECT "A"."Path", "B"."FilesetID" FROM "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB" A, (SELECT "FilesetID", "Timestamp" FROM "Filesets-B7BC630FC17C3C4CBE11296ABA9715FD" ORDER BY "Timestamp" DESC) B ORDER BY "A"."Path" ASC, "B"."Timestamp" DESC) C LEFT OUTER JOIN (SELECT "Length", "FilesetEntry"."FilesetID", "File"."Path" FROM "Blockset", "FilesetEntry", "File" WHERE "File"."BlocksetID" = "Blockset"."ID" AND "FilesetEntry"."FileID" = "File"."ID" ) D ON "C"."FilesetID" = "D"."FilesetID" AND "C"."Path" = "D"."Path" took 00:00:39.365
Sep 26, 2017 6:37 PM: Starting - ExecuteReader: SELECT "C"."Path", "D"."Length", "C"."FilesetID" FROM (SELECT "A"."Path", "B"."FilesetID" FROM "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB" A, (SELECT "FilesetID", "Timestamp" FROM "Filesets-B7BC630FC17C3C4CBE11296ABA9715FD" ORDER BY "Timestamp" DESC) B ORDER BY "A"."Path" ASC, "B"."Timestamp" DESC) C LEFT OUTER JOIN (SELECT "Length", "FilesetEntry"."FilesetID", "File"."Path" FROM "Blockset", "FilesetEntry", "File" WHERE "File"."BlocksetID" = "Blockset"."ID" AND "FilesetEntry"."FileID" = "File"."ID" ) D ON "C"."FilesetID" = "D"."FilesetID" AND "C"."Path" = "D"."Path"
Sep 26, 2017 6:37 PM: ExecuteNonQuery: CREATE INDEX "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB_PathIndex" ON "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB" ("Path") took 00:00:00.000
Sep 26, 2017 6:37 PM: Starting - ExecuteNonQuery: CREATE INDEX "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB_PathIndex" ON "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB" ("Path")
Sep 26, 2017 6:37 PM: ExecuteReader: SELECT DISTINCT "Path" FROM "Filenames-D2A47105FB845049A1E0CF93C045AB8F" took 00:00:00.000
Sep 26, 2017 6:37 PM: Starting - ExecuteReader: SELECT DISTINCT "Path" FROM "Filenames-D2A47105FB845049A1E0CF93C045AB8F"
Sep 26, 2017 6:37 PM: ExecuteNonQuery: CREATE TEMPORARY TABLE "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB" ("Path" TEXT NOT NULL) took 00:00:00.000
Sep 26, 2017 6:37 PM: Starting - ExecuteNonQuery: CREATE TEMPORARY TABLE "Filenames-97F6F39BD72A4842ADE6204A1E1CAFEB" ("Path" TEXT NOT NULL)
Sep 26, 2017 6:37 PM: ExecuteNonQuery: DELETE FROM "Filenames-D2A47105FB845049A1E0CF93C045AB8F" WHERE "Path" NOT IN (SELECT DISTINCT "Path" FROM "File", "FilesetEntry" WHERE "FilesetEntry"."FileID" = "File"."ID" AND "FilesetEntry"."FilesetID" IN (SELECT "FilesetID" FROM "Filesets-B7BC630FC17C3C4CBE11296ABA9715FD") ) took 00:00:01.192
Sep 26, 2017 6:37 PM: Starting - ExecuteNonQuery: DELETE FROM "Filenames-D2A47105FB845049A1E0CF93C045AB8F" WHERE "Path" NOT IN (SELECT DISTINCT "Path" FROM "File", "FilesetEntry" WHERE "FilesetEntry"."FileID" = "File"."ID" AND "FilesetEntry"."FilesetID" IN (SELECT "FilesetID" FROM "Filesets-B7BC630FC17C3C4CBE11296ABA9715FD") )
Sep 26, 2017 6:37 PM: ExecuteNonQuery: INSERT INTO "Filenames-D2A47105FB845049A1E0CF93C045AB8F" SELECT DISTINCT "Path" FROM "File" WHERE "Path" LIKE ? took 00:00:00.126
6

I hope not, but I can see from the log that it does create some temporary tables with filenames. I have a plan for rewriting the way the paths are stored, which should make this query much faster and less space consuming, but it is a rewrite that touches many places in the code.

7

Sounds good. Thanks!

8

TL;DR: See if you have --use-block-cache=true enabled in backup settings and remove it (Looking at the default behaviour on windows, what can be cached in memory is stored as Standby memory cached data anyway. This setting tells Duplicati to force the entire block cache in memory as RAM required by the application, whether it will fit or not. If not, it fails.)

I just had the same problem. However, the amount of RAM the recovery process wanted was insane!!! (+10GB on a 1TB backup) I had my memory rapidly being consumed when loading the file tree after it was done doing whatever building the temp data.

So let me tell you a story all about how, my memory got turned upside down, so why don’t you take a minute and sit right there, and I’ll tell you how I stopped this recovery nightmare. (Or, just try the above TL;DR)

I had 20GB of ram Free when I started to load the file tree. After using my SSD for a bit building the tmp data, it then started rapidly loading data into ram.

Duplicati : …
10GB of RAM: …
Duplicati : NOM

Windows then realized it had to free up some ram, and an additional 2GB was made available.

2GB of RAM: Wait, WHAT IS THA…!
Duplicati… NOM!..

I then closed “everything” (The app) to free up another 500MB…

NOM, went the verry hungry Duplicati.

Eventually it hit 75% ram usage and I got the database is full error.

This is absolutely un-useable… I have more free RAM then any general user will even have in their system, and 12.5 GB of it was not enough? I was even ready to ride it out and Kill Duplicati if it got to 95% ram usage, and that would of Nealy been 20GB of ram just for duplicati…

Something was going verry wrong here, so i decided to take a dive into my settings.

Backup:
–use-block-cache=true
–asynchronous-upload-limit=10
–concurrency-block-hashers=16
–concurrency-compressors=16
–concurrency-max-threads=32
–backup-name=Duplicati.Main.Backup
–dbpath=C:\Users(USER)\AppData\Local\Duplicati\LocalDB.sqlite
–encryption-module=aes
–compression-module=zip
–dblock-size=200MB
–passphrase=( Errr. No.)
–all-versions=true
–zip-compression-level=0
–blocksize=10MB
–tempdir=R:\TEMP
–auto-cleanup=true
–auto-vacuum=true
–snapshot-policy=Required
–exclude-files-attributes=system,temporary
–disable-module=console-password-input
(other individual excisions)

We are dealing with a memory related problem here, so the thing that stuck out to me was “–use-block-cache=true”. It is a setting that says that it keeps a copy of the block cache in memory. so, into the dumpster you go.

I restarted Duplicati and tried the restore again and this time i noticed something interesting.

Before when the recovery prosses started to dump data into memory, it was being allocated as actual memory needed by duplicati, but this time, windows were caching the data as… well… Standby cache. This is what you would expect, and it took all available free Memory and assigned it as Standby memory cached data.

So, one needs to ask, what is the point of --use-block-cache=true when what can be cached is put in memory anyway?

I think really this is a case of miss labelling. --use-block-cache should really be called --force-memory-cache. It seems to force the use of actual memory to hold a copy of all block cache data, instead of being just a cached data copy that would be nice to have in memory.

But a copy of what can fit is cached to memory anyway by default, And the existence of this setting implies it is not.