"The database file is locked" error even when the file is newly created

Ok, I have another odd one. I am getting this error when running repair. Both with an existing database, and after renaming the target file so it would be created from scratch.

Failed to load connection with path '/data/duplicati/PRODKAYAKO.sqlite'. => Mono.Data.Sqlite.SqliteException (0x80004005): The database file is locked
database is locked

This is using my custom docker image you can find here. (I haven’t had time to look into switching to the official image yet.)

I mount an nfs directory via docker volumes to /data/duplicati. That’s where the database lives. I then bind mount the data I want to backup to appropriate locations. The /data/duplicati directory is mounted rw, and Duplicati generates numerous backed up db files. So the issue is not that Duplicati can’t read/write to the database file.

All of these actions are performed by a bash script that is triggered by a gitlab-runner job.

To complicate things further, I have nearly identical scripts set up for a Wordpress site, and a Drupal site. Both use the same image. The only major difference is which directories I mount. And both jobs work just fine.

The obvious answer is that another process is grabbing the sqlite file after it’s created. But I’m really not sure how anything other than Duplicati could do that. Any suggestions on how to figure out if that is happening?

Here is the full log output: (Note that I put a mount -v command just before the duplicati-cli command to see if I could spot something wrong with the mounts.)

e[0KRunning with gitlab-runner 11.7.0 (8bb608ff)
e[0;me[0K  on root_at_hostname_duplicati-in-docker_shell XZfo7hxM
e[0;me[0KUsing Shell executor...
e[0;msection_start:1555672769:prepare_script
e[0KRunning on hostname...
section_end:1555672770:prepare_script
e[0Ksection_start:1555672770:get_sources
e[0Ke[32;1mFetching changes...e[0;m
HEAD is now at c4f3b64 Change prodkayako database file name.
e[32;1mChecking out c4f3b641 as lane-master...e[0;m
e[32;1mSkipping Git submodules setupe[0;m
section_end:1555672770:get_sources
e[0Ksection_start:1555672770:restore_cache
e[0Ksection_end:1555672770:restore_cache
e[0Ksection_start:1555672770:download_artifacts
e[0Ksection_end:1555672770:download_artifacts
e[0Ksection_start:1555672770:build_script
e[0Ke[32;1m$ docker login -u gitlab-ci-token -p $CI_JOB_TOKEN internal-gitlab-server:8443e[0;m
WARNING! Using --password via the CLI is insecure. Use --password-stdin.
WARNING! Your password will be stored unencrypted in /var/lib/gitlab-runner/.docker/config.json.
Configure a credential helper to remove this warning. See
https://docs.docker.com/engine/reference/commandline/login/#credentials-store

Login Succeeded
e[32;1m$ docker pull internal-gitlab-server:8443/sysadmin/working-duplicati-in-docker:mastere[0;m
master: Pulling from sysadmin/working-duplicati-in-docker
Digest: sha256:e9b51cfa55b94c2b9dbabbd35db6ab09fa1b78ca9e3d6a9a3bf75176036f25cc
Status: Image is up to date for internal-gitlab-server:8443/sysadmin/working-duplicati-in-docker:master
e[32;1m$ bash prodkayako.sh -t repaire[0;m
duplicati_data_prodkayako_storage
Starting repair at Fri Apr 19 04:19:31 PDT 2019.
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
udev on /dev type devtmpfs (rw,nosuid,relatime,size=990132k,nr_inodes=247533,mode=755)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /run type tmpfs (rw,nosuid,noexec,relatime,size=204168k,mode=755)
/dev/sda2 on / type ext4 (rw,relatime,data=ordered)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k)
tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755)
cgroup on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct)
cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)
cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids)
cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event)
cgroup on /sys/fs/cgroup/rdma type cgroup (rw,nosuid,nodev,noexec,relatime,rdma)
cgroup on /sys/fs/cgroup/net_cls,net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls,net_prio)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset)
cgroup on /sys/fs/cgroup/hugetlb type cgroup (rw,nosuid,nodev,noexec,relatime,hugetlb)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=25,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=14207)
debugfs on /sys/kernel/debug type debugfs (rw,relatime)
hugetlbfs on /dev/hugepages type hugetlbfs (rw,relatime,pagesize=2M)
mqueue on /dev/mqueue type mqueue (rw,relatime)
sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime)
fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime)
configfs on /sys/kernel/config type configfs (rw,relatime)
/var/lib/snapd/snaps/core_6405.snap on /snap/core/6405 type squashfs (ro,nodev,relatime,x-gdu.hide)
/var/lib/snapd/snaps/core_6531.snap on /snap/core/6531 type squashfs (ro,nodev,relatime,x-gdu.hide)
/var/lib/snapd/snaps/core_6673.snap on /snap/core/6673 type squashfs (ro,nodev,relatime,x-gdu.hide)
lxcfs on /var/lib/lxcfs type fuse.lxcfs (rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other)
/etc/auto.misc on /mounts/share type autofs (rw,relatime,fd=6,pgrp=1455,timeout=60,minproto=5,maxproto=5,direct,pipe_ino=23359)
overlay on /var/lib/docker/overlay2/fe1dbddef1ec5a601cf7d3186a11be334c9d8d4a2c00eb511ffa0f8713affa64/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/KFDFJEAM2R3UUGSO4C3BRFEJ47:/var/lib/docker/overlay2/l/OY5BFSU6YHZMYVWOSVIUITC7XQ:/var/lib/docker/overlay2/l/CU2XIBIGTGNUXX2TIBOUBT6OJL:/var/lib/docker/overlay2/l/Q2H4B5YD6LZDXATY4RM27D5CS4,upperdir=/var/lib/docker/overlay2/fe1dbddef1ec5a601cf7d3186a11be334c9d8d4a2c00eb511ffa0f8713affa64/diff,workdir=/var/lib/docker/overlay2/fe1dbddef1ec5a601cf7d3186a11be334c9d8d4a2c00eb511ffa0f8713affa64/work)
overlay on /var/lib/docker/overlay2/beb434eecefb15185a86668fac5a3947f83204676937d1bb8520c4bf783b8505/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/IIP47HLVS5O6FVGRVBEHHGYYCI:/var/lib/docker/overlay2/l/GTKT5HJEFGTNJBQDLTFPMOIWZS:/var/lib/docker/overlay2/l/KI2N4WON3VVHSQOQ5MZJRYMBRB:/var/lib/docker/overlay2/l/OV7WWENJ66DPLN35Q6S4J7KXL6,upperdir=/var/lib/docker/overlay2/beb434eecefb15185a86668fac5a3947f83204676937d1bb8520c4bf783b8505/diff,workdir=/var/lib/docker/overlay2/beb434eecefb15185a86668fac5a3947f83204676937d1bb8520c4bf783b8505/work)
nsfs on /run/docker/netns/default type nsfs (rw)
shm on /var/lib/docker/containers/461fc2779066a1577ebd31631a4ab33a13178daf3cc808ad2317798354c991b6/mounts/shm type tmpfs (rw,nosuid,nodev,noexec,relatime,size=65536k)
shm on /var/lib/docker/containers/1af8baeaceed0a92c7801d283ddbfb83dfe392ba34505f1b26a237cc9f66fc61/mounts/shm type tmpfs (rw,nosuid,nodev,noexec,relatime,size=65536k)
nsfs on /run/docker/netns/37965035aedb type nsfs (rw)
tmpfs on /run/user/113 type tmpfs (rw,nosuid,nodev,relatime,size=204164k,mode=700,uid=113,gid=117)
Input command: repair
Input arguments: 
    googledrive://apth?authid=redacted

Input options: 
backup-name: 2019 prodkayako to webteamappbackup@work.tld Google Drive
dbpath: /data/duplicati/PRODKAYAKO.sqlite
passphrase: password
send-mail-from: no-reply-duplicati@hostname.work.tld
send-mail-level: Warning,Error,Fatal
send-mail-password: password
send-mail-to: webservices@work.tld
send-mail-url: smtp://mailserver:25/?starttls=always
send-mail-username: username
disable-module: console-password-input
rebuild-missing-dblock-files: 
debug-output: true
debug-retry-errors: true
tempdir: /data/duplicati/tmp
console-log-level: profiling

The operation Repair has started
Starting - Running Repair
Failed to load connection with path '/data/duplicati/PRODKAYAKO.sqlite'. => Mono.Data.Sqlite.SqliteException (0x80004005): The database file is locked
database is locked
  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) [0x001ba] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <0cc49df22adc491bb0cafdad862d8990>: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 <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteConnection.Open () [0x00543] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.OpenSQLiteFile (System.Data.IDbConnection con, System.String path) [0x00021] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.LoadConnection (System.String targetpath) [0x00019] in <bf41edba44ef4c028d3669e9cb95841b>:0 
Failed to read local db /data/duplicati/PRODKAYAKO.sqlite, error: The database file is locked
database is locked => Mono.Data.Sqlite.SqliteException (0x80004005): The database file is locked
database is locked
  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) [0x001ba] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <0cc49df22adc491bb0cafdad862d8990>: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 <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteConnection.Open () [0x00543] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.OpenSQLiteFile (System.Data.IDbConnection con, System.String path) [0x00021] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.LoadConnection (System.String targetpath) [0x00048] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.Main.Database.LocalDatabase.CreateConnection (System.String path) [0x00021] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Database.LocalDatabase..ctor (System.String path, System.String operation, System.Boolean shouldclose) [0x00000] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Database.LocalRepairDatabase..ctor (System.String path) [0x00000] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Operation.RepairHandler.Run (Duplicati.Library.Utility.IFilter filter) [0x0003e] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
Renaming existing db from /data/duplicati/PRODKAYAKO.sqlite to /data/duplicati/PRODKAYAKO.backup
Starting - Recreate database for repair
Failed to load connection with path '/data/duplicati/PRODKAYAKO.sqlite'. => Mono.Data.Sqlite.SqliteException (0x80004005): The database file is locked
database is locked
  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) [0x001ba] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <0cc49df22adc491bb0cafdad862d8990>: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 <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteConnection.Open () [0x00543] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.OpenSQLiteFile (System.Data.IDbConnection con, System.String path) [0x00021] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.LoadConnection (System.String targetpath) [0x00019] in <bf41edba44ef4c028d3669e9cb95841b>:0 
Recreate database for repair took 0:00:00:30.958
Running Repair took 0:00:01:02.634

Mono.Data.Sqlite.SqliteException (0x80004005): The database file is locked
database is locked
  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) [0x001ba] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <0cc49df22adc491bb0cafdad862d8990>: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 <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteConnection.Open () [0x00543] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.OpenSQLiteFile (System.Data.IDbConnection con, System.String path) [0x00021] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.LoadConnection (System.String targetpath) [0x00048] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.Main.Database.LocalDatabase.CreateConnection (System.String path) [0x00021] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Database.LocalDatabase..ctor (System.String path, System.String operation, System.Boolean shouldclose) [0x00000] in <c6c6871f516b48f59d88f9d731c3ea4d>: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) [0x0001e] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Operation.RepairHandler.RunRepairLocal (Duplicati.Library.Utility.IFilter filter) [0x000ba] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Operation.RepairHandler.Run (Duplicati.Library.Utility.IFilter filter) [0x00159] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass17_0.<Repair>b__0 (Duplicati.Library.Main.RepairResults result) [0x0001c] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x00271] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x00007] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller.Repair (Duplicati.Library.Utility.IFilter filter) [0x0001a] in <c6c6871f516b48f59d88f9d731c3ea4d>: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 <04206d56f2084515b87543fcb90a7e00>: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) [0x00313] in <04206d56f2084515b87543fcb90a7e00>:0 
  at Duplicati.CommandLine.Program.RunCommandLine (System.IO.TextWriter outwriter, System.IO.TextWriter errwriter, System.Action`1[T] setup, System.String[] args) [0x00002] in <04206d56f2084515b87543fcb90a7e00>:0 
section_end:1555672842:build_script
e[0Ksection_start:1555672842:after_script
e[0Ksection_end:1555672842:after_script
e[0Ksection_start:1555672842:archive_cache
e[0Ksection_end:1555672842:archive_cache
e[0Ksection_start:1555672842:upload_artifacts_on_success
e[0Ksection_end:1555672842:upload_artifacts_on_success
e[0Ke[32;1mJob succeeded
e[0;m

Here is what the bash script actually runs: (gitlab-ci inserts values for variables like $local_data_dest).

mount -v
docker run \
 --rm \
 --name duplicati-run-repair-prodkayako \
 --hostname duplicati-run-repair-prodkayako.work.tld\
 --volume duplicati_data_prodkayako_storage:/data/duplicati \
 --volume /opt/databasedumps:/opt/databasedumps:rw \
 --volume /var/www/lanekayako:/var/www/lanekayako:ro \
 --volume /root/scripts:/root/scripts:ro \
 internal-gitlab-server:8443/sysadmin/working-duplicati-in-docker:master \
   duplicati-cli repair $local_data_dest \
     --backup-name="2019 prodkayako to webteamappbackup@work.tldGoogle Drive" \
     --dbpath=/data/duplicati/PRODKAYAKO.sqlite \
     --passphrase=$local_data_passphrase \
     --send-mail-from="no-reply-duplicati@host" \
     --send-mail-level="Warning,Error,Fatal" \
     --send-mail-password=$project_send_mail_password \
     --send-mail-to="email" \
     --send-mail-url="smtp://mailserver:25/?starttls=always" \
     --send-mail-username=username \
     --disable-module=console-password-input \
     --rebuild-missing-dblock-files \
     --debug-output=true \
     --debug-retry-errors=true \
     --tempdir=/data/duplicati/tmp \
     --console-log-level=profiling

Any ideas/solutions would be appreciated.

Thanks!

Anyone have any insight? I had this particular job working again for a while. I can’t remember exactly how I got it working again, but it recently started throwing that exact same error.

Of interest is that the sqlite file is on a NFS share. I did check to see if there was a stale NFS lock on the file, but there isn’t.

I’ve been able to replicate the error via duplicati-cli find.

# duplicati-cli find googledrive://path?authid=blah "filename" --passphrase=password --dbpath=db.sqlite
Failed to load connection with path '/data/duplicati/db.sqlite'. => The database file is locked
database is locked

Mono.Data.Sqlite.SqliteException (0x80004005): The database file is locked
database is locked
  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) [0x001ba] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.BuildNextCommand () [0x000d3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.GetStatement (System.Int32 index) [0x00008] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteCommand.GetStatement(int)
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x000b3] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <0cc49df22adc491bb0cafdad862d8990>: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 <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Mono.Data.Sqlite.SqliteConnection.Open () [0x00543] in <0cc49df22adc491bb0cafdad862d8990>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.OpenSQLiteFile (System.Data.IDbConnection con, System.String path) [0x00021] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.SQLiteHelper.SQLiteLoader.LoadConnection (System.String targetpath) [0x00048] in <bf41edba44ef4c028d3669e9cb95841b>:0 
  at Duplicati.Library.Main.Database.LocalDatabase.CreateConnection (System.String path) [0x00021] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Database.LocalDatabase..ctor (System.String path, System.String operation, System.Boolean shouldclose) [0x00000] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Database.LocalListDatabase..ctor (System.String path) [0x00000] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Operation.ListFilesHandler.Run (System.Collections.Generic.IEnumerable`1[T] filterstrings, Duplicati.Library.Utility.IFilter compositefilter) [0x0007d] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass20_0.<List>b__0 (Duplicati.Library.Main.ListResults result) [0x0001c] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x00271] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x00007] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.Library.Main.Controller.List (System.Collections.Generic.IEnumerable`1[T] filterstrings, Duplicati.Library.Utility.IFilter filter) [0x00021] in <c6c6871f516b48f59d88f9d731c3ea4d>:0 
  at Duplicati.CommandLine.Commands.List (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) [0x00274] in <04206d56f2084515b87543fcb90a7e00>: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) [0x00313] in <04206d56f2084515b87543fcb90a7e00>:0 
  at Duplicati.CommandLine.Program.RunCommandLine (System.IO.TextWriter outwriter, System.IO.TextWriter errwriter, System.Action`1[T] setup, System.String[] args) [0x00002] in <04206d56f2084515b87543fcb90a7e00>:0 

That is from within the running container. I was searching for a file I know exists.

Running lslocks directly after gives this:

# lslocks
COMMAND         PID   TYPE SIZE MODE  M START END PATH
(unknown)        -1 OFDLCK   0B READ  0     0   0 

So the sqlite file is not locked by the os.

Just tried sqlite3 directly.

# sqlite3 db.sqlite
SQLite version 3.7.17 2013-05-20 00:56:22
Enter ".help" for instructions
Enter SQL statements terminated with a ";"
sqlite> .databases
Error: database is locked
sqlite> 

Sure it’s not a UID/GID issue?
Which Duplicati docker image are you using? edit - nevermind I see your link

Not a UID/GID issue. Docker has root perms, and so does Duplicati. The db file was owned by a user, so I tried changing it to root:root, but that didn’t make a difference.

Perhaps it’s a root squash issue with NFS (when you try to connect using root, it will silently remap UID/GID to anonymous or something). You may need to flag your NFS export with no_root_squash.

Been a while since I have done stuff with NFS so I’m a bit rusty.

I have multiple other jobs running using the same nfs volume. Just different sub directories. Only this one is throwing the error. And I have had this one working before. So it’s not a remap issue.

As a side note, I was able to run a create-report job. So duplicati is able to read and write from the nfs mounted directory.

I think I did actually run into that kind of issue years ago when I had this volume set up, but we fixed it then.

Well it’s puzzling.

As a test can you do a chmod 777 on your sqlite database?

If that makes no difference then maybe it really has nothing to do with filesystem or NFS permissions, and is entirely a sqlite issue.

This thread had some interesting ideas:

# chmod 777 db.sqlite 
# sqlite3 db.sqlite 
SQLite version 3.7.17 2013-05-20 00:56:22
Enter ".help" for instructions
Enter SQL statements terminated with a ";"
sqlite> .databases 
Error: database is locked
sqlite> 

I actually found that stack overflow q/a earlier. I’ve tried the move to a different file name and copy back to the old one method. Didn’t work.

I saw the link to this doc: File Locking And Concurrency In SQLite Version 3 and it makes me wonder if there’s a way to find out what kind of lock the database is under…

Did you try the lsof command to see if you can find a process that has the file locked?

Out of curiosity are you running those sqlite3 tests on the host machine or from inside docker container? If inside docker container what if you try it on the host?

You could possibly fish around with strace or something if you really want to see what yours is doing.

On the article you cited (and in others), there’s talk about NFS bugs, and advice to keep your DB local.

You could certain try a local DB for test (not production). If that works, then maybe test with the nolock mount option described in the nfs man page being careful not to have interference from other systems.

The talk there about NLM is actually a little dated. In NFS versions 2 and 3, locks ran their own protocol, however NFS version 4 runs an integrated protocol, and some people say it can do locks more reliably.

There appear to be some other documented knobs to play with. I don’t run NFS now, so can’t try things.

Dear,

I experienced the same problem and the nolock option on the NFS mounted directory containing the database file solved the issue.

Many thanks.