Backup is not "finished" even though Last successful run shows start and elapsed time

Support
1

I’m still evaluating Duplicati as a replacement for CrashPlan.
I wanted to test restoration today and received a “The database file is locked database is locked” error when Duplicati tried to get the file list.

Searching revealed that this error happens when a backup is in progress.
Color me confused. The “Home” page indicates that the last backup started at 3:03 this morning and took 1:48 to finish and the next backup will start at 1:15 this afternoon.

It’s 9:30 now. It seems to me that I should be able to restore at this point in time.

The Home page:

data01: 478497 files (109.19 GB) to go 

Last successful run:     Today at 3:03 AM (took 01:48:48)     Run now 
Next scheduled run:     Today at 1:15 PM 
Source:     115.95 GB
Backup:    90.29 GB / 55 Versions

The first line (data01…) is the progress bar at the top of the page.
Since the previous backup is apparently complete and the next backup isn’t scheduled to start for some hours yet, I do not understand why the progress bar is active and the database is locked.

Explanations and suggestions most welcome.
TIA

2

At some point between 4:51ish and 9:30, a new backup started and at 9:30 was still in progress. The “Run now” link is not removed when a backup is in progress (it probably should be to reduce confusion).

As to why it started, there’s probably a schedule that triggered during that time.

3

If you go to the main menu “About” -> “System info” and scroll down to “Server state properties” you should see many fields including:

  • “activeTask” (What’s currently running)
  • “proposedSchedule” (what should happen eventually but isn’t currently in the queue like manually added jobs or the NEXT scheduled run of a job that might currently be running)
  • “schedulerQueueIds” (what’s currently in the queue to be run)

If a job runs long enough that it goes past it’s next scheduled run time, it will be added to the queue (as a “missed job”) even though it’s already currently running. This means as soon as the job finishes, it will start up again to cover the “missed” start time. That may be what happened to you.

It would likely look something like this (without the color highlighting):

activeTask : {"Item1":25,"Item2":"4"}
proposedSchedule : [{"Item1":"4","Item2":"2018-05-22T01:00:00Z"}]
schedulerQueueIds : [{"Item1":26,"Item2":"4"}]

The above shows:

  • Job ID 4 is currently running (it’s #25 in the queue)
  • Job ID 4 is scheduled to run again at 01:00:00Z on 2018-05-22
  • the Job ID 4 scheduled for 2018-05-22T01:00Z is #26 in the queue

This isn’t what you’re seeing, but there’s also a known issue with some older versions where a database cleanup step would run (locking the database) AFTER the job reported itself as being finished.