Not completing backup

Support
1

Hi,
I just recently started using Duplicati - thanks to the community for building!

My setup:

  • Duplicati - 2.0.6.3_beta_2021-06-17 as Docker image on Debian 10.9 - runs smoothly afaik
  • 4 local shares on ZFS as source
  • 4 independent OneDrive for Business 1 TB hot drives as destination
  • 4 backup jobs, each to one specific OneDrive

My standard options:
–send-mail-level=all
–send-mail-body=%RESULT%
–send-mail-password=[…]
–send-mail-subject=Duplicati %OPERATIONNAME% report for %backup-name%
–send-mail-to=[…]
–send-mail-url=[…]
–send-mail-username=[…]
=> so nothing that should directly affect the backup process

I have successfully completed the “smaller” backups with sizes around 90-300 GB. One backup with 900 GB however will not finish. Upload process took ~6 days, which is feasible given my connection. It successfully managed several connection breakdowns on the way. After the upload it was stuck in “Waiting for backup/upload to finish” for another 6 days, so at some point I decided to 1) try and stop the process via the “X”-button on the GUI. It did say it would stop but after another 1 day, I then 2) pulled the plug and restarted the container running Duplicati. “Last successful backup” was still “never”, so I just restarted the backup process again. That helped with the other backup sets, too and eventually it would complete the process. With this one, however, it does not. It is now stuck on “Verifying files” / “Dateien überprüfen” in my German GUI for about 3 days and I cannot see the progress bar move.

Here’s what the logs say:
Log from within job Remote:

  1. Aug. 2021 15:03: list
    [ {“Name”:“config”,“LastAccess”:“0001-01-01T00:00:00”,“LastModification”:“2021-07-27T21:10:30Z”,“Size”:382,“IsFolder”:false}, {“Name”:“duplicati-20210808T141301Z.dlist.zip.aes”,“LastAccess”:“0001-01-01T00:00:00”,“LastModification”:“2021-08-15T12:55:30Z”,“Size”:26176205,“IsFolder”:false}, {“Name”:“duplicati-20210815T123725Z.dlist.zip.aes”,“LastAccess”:“0001-01-01T00:00:00”,“LastModification”:“2021-08-15T12:55:23Z”,“Size”:26176541,“IsFolder”:false}, {“Name”:“duplicati-b00054b9b6e2945e48a2b0d15ea001140.dblock.zip.aes”,“LastAccess”:“0001-01-01T00:00:00”,“LastModification”:“2021-08-09T06:17:26Z”,“Size”:52414477,“IsFolder”:false},

General log - Live - Verbose:

  1. Aug. 2021 15:03: Backend event: Get - Started: duplicati-20210808T141301Z.dlist.zip.aes (24,96 MB)

CPU usage of the container is close to 0%. RX and TX for the network adapter is stuck < 200 MB for a long time. I believe it’s hanging again but what can I do do finally complete the backup and preferably check it for consistency afterwards?

Thanks

2

Welcome to the forum @degudejung

Nice writeup, but ends in a mystery. So Verbose live log just stopped after an attempt to download a file?

The Verifying files status should follow a Verifying backend data which is done before and after backup itself. It should be after the last Put request. You should see a recent dlist file at the destination.

The test sampling tries to balance verifications. I’m not sure if your 20210808 was actually the last made.
If you use the Test connection button on the Destination screen, it should download a set of files too, which may or may not include the hung one (assuming it was hung – was a live log running at the time?).

It’s possible to download specific files using Duplicati.CommandLine.BackendTool.exe get with URL like Export As Command-line gives, with the specific filename added. Get operations are “supposed” to work.

You can look at OneDrive to see if the dlist file at end of backup is there. If so, backup itself is “complete”.

You might have had this once at Verifying backend data. Press Test connection to check it again, and next backup will also check it before actually starting on backup itself. If you have to kill things again, some extra checking is good… One can sometimes look at Profiling log level for activity, but the Get that seemingly said Started but not Completed (right?) is not a good sign. Low-level network debug is tough.

3

Hi and thanks @ts678,

Looks like it. Nothing else ever showed up afterwards UNTIL I tried to pull the plug again after my initial post by clicking “Pause 5 minutes”. General log - saved now has an update:

  1. Aug. 2021 11:15:
    Request for http://192.168.10.30:8200/api/v1/serverstate/pause?duration=5m gave error
    System.InvalidOperationException: Cannot add stuff to HttpInput.Empty.
    at HttpServer.HttpInput.Add (System.String name, System.String value) [0x00016] in :0
    at Duplicati.Server.WebServer.RESTHandler.DoProcess (Duplicati.Server.WebServer.RESTMethods.RequestInfo info, System.String method, System.String module, System.String key) [0x00264] in <156011ea63b34859b4073abdbf0b1573>:0
  1. Aug. 2021 11:15: Reporting error gave error
    System.ObjectDisposedException: Cannot write to a closed TextWriter.
    at System.IO.StreamWriter.Flush (System.Boolean flushStream, System.Boolean flushEncoder) [0x00008] in <254335e8c4aa42e3923a8ba0d5ce8650>:0
    at System.IO.StreamWriter.Flush () [0x00006] in <254335e8c4aa42e3923a8ba0d5ce8650>:0
    at Duplicati.Server.WebServer.RESTHandler.DoProcess (Duplicati.Server.WebServer.RESTMethods.RequestInfo info, System.String method, System.String module, System.String key) [0x003bc] in <156011ea63b34859b4073abdbf0b1573>:0

The quote from within job Remote I posted above, of course, is abbreviated. In reality it is incredibly much longer but all lines are similar to the ones posted.

Yes. There are actually 2 recent dlist files. Both have a timestamp of August 15 and are 25 MB big:

duplicati-20210808T141301Z.dlist.zip.aes
duplicati-20210815T123725Z.dlist.zip.aes

hmm, I can successfully test the connection but it does not create a log entry, nor do I see any other files. I don’t know if a live log was running, but would assume so, sorry.

Meanwhile, I restarted the Docker container, so I could try your recommended test-restore of a file. It actually worked via GUI even though the backup set claims to not have a backup at all. The restore finished with a warning:

Failed to find backup: Missing XSRF Token. Please reload the page

The log shows:

    1. Aug. 2021 22:08: Die Operation Restore ist abgeschlossen
    1. Aug. 2021 22:07: Testing restored file integrity: /pool2/pool2/pool2/Thumbs.db
    1. Aug. 2021 22:07: Testing restored file integrity: /pool2/pool2/pool2/How-to Scanner.pdf
    1. Aug. 2021 22:07: Testing restored file integrity: /pool2/pool2/pool2/.DS_Store
    1. Aug. 2021 22:07: Patching metadata with remote data: /pool2/pool2/pool2/Thumbs.db
    1. Aug. 2021 22:07: Patching metadata with remote data: /pool2/pool2/pool2/How-to Scanner.pdf
    1. Aug. 2021 22:07: Patching metadata with remote data: /pool2/pool2/pool2/.DS_Store
    1. Aug. 2021 22:07: Failed to apply metadata to file: “/pool2/pool2/pool2/”, message: Invalid parameter
    1. Aug. 2021 22:07: Patching metadata with remote data: /pool2/pool2/pool2/
    1. Aug. 2021 22:07: Recording metadata from remote data: /pool2/pool2/pool2/Thumbs.db
    1. Aug. 2021 22:07: Recording metadata from remote data: /pool2/pool2/pool2/How-to Scanner.pdf
    1. Aug. 2021 22:07: Recording metadata from remote data: /pool2/pool2/pool2/.DS_Store
    1. Aug. 2021 22:07: Recording metadata from remote data: /pool2/pool2/pool2/
    1. Aug. 2021 22:07: Backend event: Get - Completed: duplicati-b2ff5c2cedf9c4937ba9b1c5732811058.dblock.zip.aes (49,90 MB)
    1. Aug. 2021 22:07: Backend event: Get - Started: duplicati-b2ff5c2cedf9c4937ba9b1c5732811058.dblock.zip.aes (49,90 MB)
    1. Aug. 2021 22:07: 1 remote files are required to restore
    1. Aug. 2021 22:07: Target file is patched with some local data: /pool2/pool2/pool2/Thumbs.db
    1. Aug. 2021 22:07: Target file is patched with some local data: /pool2/pool2/pool2/How-to Scanner.pdf
    1. Aug. 2021 22:07: Target file is patched with some local data: /pool2/pool2/pool2/.DS_Store
    1. Aug. 2021 22:07: Target file does not exist: /pool2/pool2/pool2/Thumbs.db
    1. Aug. 2021 22:07: Target file does not exist: /pool2/pool2/pool2/How-to Scanner.pdf
    1. Aug. 2021 22:07: Restore list contains 8 blocks with a total size of 218,45 KB
    1. Aug. 2021 22:07: Mapping restore path prefix to “/pool1/eviscan/eviscan/Data/00 Orga/91 Scanner/” to “/pool2/pool2/pool2/”
    1. Aug. 2021 22:07: Needs to restore 3 files (216,43 KB)
    1. Aug. 2021 22:07: Searching backup 0 (8/15/2021 12:37:25 PM) …
    1. Aug. 2021 22:06: Backend event: List - Completed: (20,09 KB)
    1. Aug. 2021 22:05: Backend event: List - Started: ()
    1. Aug. 2021 22:05: Die Operation Restore wurde gestartet
    1. Aug. 2021 22:01: Server has started and is listening on 0.0.0.0, port 8200

The files did actually get restored correctly. So that’s pretty neat. :grinning:

As you suggested, I triggered a TEST command with 1 sample now to see what it says. I’ll report back later. Would you recommend I run a REPAIR job also? It looks like there is a complete backup on the OneDrive but Duplicati still claims “Last backup: never”.

4

The time seen in the name is around the start of the file. File filesystem time is, of course, upload time.

My mistake. I meant Verify files. Test connection is a list that isn’t logged. A Verify files log:

image

It’s good to get at least one done, because some maintenance operations don’t work without the first one.
On the other hand, possibly you have backups at the destination, but I’m not sure when they’re recorded.

I’d suggest Verify files (sorry about giving the wrong button earlier), and you can look at the log if you like. If that passes, I’m not sure Repair will see the need to repair, but you could probably try one anyway.

If you actually have good backup (or backups, because you got two dlist files uploaded), you can see if a Recreate can build the DB. Watching About → Show log → Live → Verbose should show it downloading dlist files, then dindex files. After that, a few dblock files might be normal, but if it gets to 90% on progress bar, then it’s downloading all the rest (could take awhile) in search of a missing block or some such thing.

I’m not sure how to solve an unreliable Get if it persists though. You could try standalone backend testing with Duplicati.CommandLine.BackendTester.exe pointing to an empty folder. Point to it with modified URL from Export As Command-line. This should give the uploading and downloading some additional exercise.

If you prefer something download-intensive, you can run test command with as many sets as you want to wait for (download speed is likely the slow spot). If it finishes, you can check its job Complate log to see:

“RetryAttempts”: 0,

or something non-zero, or maybe it will hang.

1 Like
5

thanks again @ts678 !

First, I believe right after the successful restore from that destination, I did not see the log entry, that is available now:

Warnings 1

  • 2021-08-18 22:07:38 +02 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: “/pool2/pool2/pool2/”, message: Invalid parameter

Under “Full protocol” there is:

{
“RestoredFiles”: 3,
“SizeOfRestoredFiles”: 221620,
“RestoredFolders”: 0,
“RestoredSymlinks”: 0,
“PatchedFiles”: 0,
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“DeletedSymlinks”: 0,
“MainOperation”: “Restore”,
“RecreateDatabaseResults”: null,
“ParsedResult”: “Warning”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2021-08-18T20:07:38.43874Z”,
“BeginTime”: “2021-08-18T20:05:08.358465Z”,
“Duration”: “00:02:30.0802750”,
“MessagesActualLength”: 7,
“WarningsActualLength”: 1,
“ErrorsActualLength”: 0,
“Messages”: [
“2021-08-18 22:05:08 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Restore wurde gestartet”,
“2021-08-18 22:05:08 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2021-08-18 22:06:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (20,09 KB)”,
“2021-08-18 22:07:00 +02 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (8/15/2021 12:37:25 PM) …”,
“2021-08-18 22:07:19 +02 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 1 remote files are required to restore”,
“2021-08-18 22:07:19 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b2ff5c2cedf9c4937ba9b1c5732811058.dblock.zip.aes (49,90 MB)”,
“2021-08-18 22:07:38 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b2ff5c2cedf9c4937ba9b1c5732811058.dblock.zip.aes (49,90 MB)”
],
“Warnings”: [
“2021-08-18 22:07:38 +02 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: "/pool2/pool2/pool2/", message: Invalid parameter”
],
“Errors”: ,
“BackendStatistics”: {
“RemoteCalls”: 2,
“BytesUploaded”: 0,
“BytesDownloaded”: 52328509,
“FilesUploaded”: 0,
“FilesDownloaded”: 1,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 382,
“UnknownFileCount”: 1,
“KnownFileCount”: 20573,
“KnownFileSize”: 539273462601,
“LastBackupDate”: “2021-08-15T14:37:25+02:00”,
“BackupListCount”: 2,
“TotalQuotaSpace”: 1099511627776,
“FreeQuotaSpace”: 560224478441,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Restore”,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2021-08-18T20:05:08.358469Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

That looks OK to me and as stated before, that files I called, did actually come.

Now on to the TEST command I ran from “command line via GUI”. When I wrote up the last post, I just triggered the TEST with 1 sample, meanwhile gave it 30+ hours so far. The GUI still said “Laufende Aufgabe: Sicherung wird gestartet…” (probably “Running task: starting backup…”). So far, there was no new log entry, neither at the job at General or Remote, nor in the About - Show Logs section under Saved or Live. Hitting the “abort” button showed the stop options but it seems I can click whatever I want, it has no effect. So, again, I had to force the container into restart, to get back in control. After restart, still no log entries about the job that ran for 30+ hours.

I then ran the VERIFY FILES command on another, smaller backup set to see if maybe it’s a network thing or it just hangs based on certain commands. It completed just fine:

{
“MainOperation”: “Test”,
“VerificationsActualLength”: 3,
“Verifications”: [
{
“Key”: “duplicati-20210808T093809Z.dlist.zip.aes”,
“Value”:
},
{
“Key”: “duplicati-ibc6b566cdab345b499fd34a2e463c52b.dindex.zip.aes”,
“Value”:
},
{
“Key”: “duplicati-b32cbd0a60cb84153bf10e9a78eaa3419.dblock.zip.aes”,
“Value”:
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2021-08-20T10:32:46.520301Z”,
“BeginTime”: “2021-08-20T10:31:45.618322Z”,
“Duration”: “00:01:00.9019790”,
“MessagesActualLength”: 9,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: [
“2021-08-20 12:31:45 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Test wurde gestartet”,
“2021-08-20 12:31:55 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2021-08-20 12:32:19 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (3,38 KB)”,
“2021-08-20 12:32:19 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20210808T093809Z.dlist.zip.aes (11,17 MB)”,
“2021-08-20 12:32:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20210808T093809Z.dlist.zip.aes (11,17 MB)”,
“2021-08-20 12:32:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ibc6b566cdab345b499fd34a2e463c52b.dindex.zip.aes (28,20 KB)”,
“2021-08-20 12:32:24 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ibc6b566cdab345b499fd34a2e463c52b.dindex.zip.aes (28,20 KB)”,
“2021-08-20 12:32:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b32cbd0a60cb84153bf10e9a78eaa3419.dblock.zip.aes (50,00 MB)”,
“2021-08-20 12:32:46 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b32cbd0a60cb84153bf10e9a78eaa3419.dblock.zip.aes (50,00 MB)”
],
“Warnings”: ,
“Errors”: ,
“BackendStatistics”: {
“RemoteCalls”: 4,
“BytesUploaded”: 0,
“BytesDownloaded”: 64170375,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 3460,
“KnownFileSize”: 90473071108,
“LastBackupDate”: “2021-08-08T11:52:12+02:00”,
“BackupListCount”: 4,
“TotalQuotaSpace”: 1099511627776,
“FreeQuotaSpace”: 906415691671,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Test”,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2021-08-20T10:31:45.619076Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

General verbose log is:

  • Aug 20, 2021 12:32 PM: Die Operation Test ist abgeschlossen

  • Aug 20, 2021 12:32 PM: Backend event: Get - Completed: duplicati-b32cbd0a60cb84153bf10e9a78eaa3419.dblock.zip.aes (50,00 MB)

  • Aug 20, 2021 12:32 PM: Backend event: Get - Started: duplicati-b32cbd0a60cb84153bf10e9a78eaa3419.dblock.zip.aes (50,00 MB)

  • Aug 20, 2021 12:32 PM: Backend event: Get - Completed: duplicati-ibc6b566cdab345b499fd34a2e463c52b.dindex.zip.aes (28,20 KB)

  • Aug 20, 2021 12:32 PM: Backend event: Get - Started: duplicati-ibc6b566cdab345b499fd34a2e463c52b.dindex.zip.aes (28,20 KB)

  • Aug 20, 2021 12:32 PM: Backend event: Get - Completed: duplicati-20210808T093809Z.dlist.zip.aes (11,17 MB)

  • Aug 20, 2021 12:32 PM: Backend event: Get - Started: duplicati-20210808T093809Z.dlist.zip.aes (11,17 MB)

  • Aug 20, 2021 12:32 PM: Backend event: List - Completed: (3,38 KB)

  • Aug 20, 2021 12:31 PM: Backend event: List - Started: ()

  • Aug 20, 2021 12:31 PM: Die Operation Test wurde gestartet

  • Aug 20, 2021 12:29 PM: Server has started and is listening on 0.0.0.0, port 8200

So next, I ran the VERIFY FILES on the backup set in question here (8x bigger). To my surprise, it completes within 3-4 minutes and concludes in positive log:

{
“MainOperation”: “Test”,
“VerificationsActualLength”: 3,
“Verifications”: [
{
“Key”: “duplicati-20210815T123725Z.dlist.zip.aes”,
“Value”:
},
{
“Key”: “duplicati-i7ecac5e668b44b3eb51f93c7d22a8719.dindex.zip.aes”,
“Value”:
},
{
“Key”: “duplicati-b4623746c4c334f678414840a57cac76b.dblock.zip.aes”,
“Value”:
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2021-08-20T10:42:40.467838Z”,
“BeginTime”: “2021-08-20T10:39:39.181759Z”,
“Duration”: “00:03:01.2860790”,
“MessagesActualLength”: 9,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: [
“2021-08-20 12:39:39 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Test has started”,
“2021-08-20 12:40:02 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2021-08-20 12:41:48 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (20.09 KB)”,
“2021-08-20 12:41:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20210815T123725Z.dlist.zip.aes (24.96 MB)”,
“2021-08-20 12:41:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20210815T123725Z.dlist.zip.aes (24.96 MB)”,
“2021-08-20 12:41:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i7ecac5e668b44b3eb51f93c7d22a8719.dindex.zip.aes (17.97 KB)”,
“2021-08-20 12:41:58 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i7ecac5e668b44b3eb51f93c7d22a8719.dindex.zip.aes (17.97 KB)”,
“2021-08-20 12:42:25 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b4623746c4c334f678414840a57cac76b.dblock.zip.aes (49.92 MB)”,
“2021-08-20 12:42:40 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b4623746c4c334f678414840a57cac76b.dblock.zip.aes (49.92 MB)”
],
“Warnings”: ,
“Errors”: ,
“BackendStatistics”: {
“RemoteCalls”: 4,
“BytesUploaded”: 0,
“BytesDownloaded”: 78544871,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 382,
“UnknownFileCount”: 1,
“KnownFileCount”: 20573,
“KnownFileSize”: 539273462601,
“LastBackupDate”: “2021-08-15T14:37:25+02:00”,
“BackupListCount”: 2,
“TotalQuotaSpace”: 1099511627776,
“FreeQuotaSpace”: 560224478441,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Test”,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2021-08-20T10:39:39.182485Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

So, next thing was I hit Database - Repair. Took another few minutes and (apart from many other log entries in Verbose, of course) resulted in successful completion:

Aug 20, 2021 12:48 PM: Destination and database are synchronized, not making any changes

Finally, I dared to simply hit Run Now and I’ll see if maybe all the finagling with restarts, test and verify commands broke the Gordian knot. After 2-3 minutes, an error popped:

Failed to connect: The database file is locked
database is locked

After I clicked OK, however, it continued to count files and gigabytes AND NOW… :slight_smile: it completed the d### f### backup with now 2 versions available. hahahah :slight_smile: :slight_smile: :slight_smile:

Well, I don’t know what exactly did the trick but @ts678 you certainly helped me maneuver through this. Thank you yet again!

For everyone else, who runs into the same trouble, maybe our extensive logging steps help find their way, too.

For the DevTeam, if I can contribute to preventing the same happening to others in anyways, please let me know!

Cheers, degudejung

6

I’m glad it finally settled down. Are you a developer? Yes or no, volunteers are encouraged in all areas. Developers tend to fix issues when they get reproducible steps that they can do. If you get that, file an Issue, however check for duplicates because there are quite a lot in the queue (some may be vague).

Logs are good too, but looking at one issue at a time and picking out relevant logs (maybe by time) will help. There’s a certain amount of art to testing and giving the key steps and logs for a given problem…

If you’re up for this (or development) great! If not, you’re at least better armed in case it happens again.

7

I don’t think I’ll go as a developer just now. But I’ll certainly stay in the forum and maybe can help even newer users with their questions. Always great to see active support communities.

1 Like