Release: 2.0.4.3 (canary) 2018-11-13

2.0.4.3-2.0.4.3_canary_2018-11-13

  • Removed “Got o warning(s)” message, thanks @LacunaSoftware
  • Rewrote path handling across the project to better support long paths, thanks @verhoek
  • Added missing assemblies to Docker images
  • Removed OneDrive v1 as it no longer works
  • Added support for exporting passwords, thanks @Pectojin

I upgraded one machine to this, a Windows server from the previous canary (2.0.3.14), and now I get a warning that snapshots are failing:

2018-11-13 13:23:38 +01 - [Warning-Duplicati.Library.Main.Operation.BackupHandler-SnapshotFailed]: Failed to create a snapshot: System.NullReferenceException: Object reference not set to an instance of an object.
   at Duplicati.Library.Common.IO.VssBackupComponents.SetupWriters(Guid[] includedWriters, Guid[] excludedWriters)
   at Duplicati.Library.Snapshots.WindowsSnapshot..ctor(IEnumerable`1 sources, IDictionary`2 options)
   at Duplicati.Library.Snapshots.SnapshotUtility.CreateWindowsSnapshot(IEnumerable`1 folders, Dictionary`2 options)
   at Duplicati.Library.Main.Operation.BackupHandler.GetSnapshot(String[] sources, Options options)
System.NullReferenceException: Object reference not set to an instance of an object.
   at Duplicati.Library.Common.IO.VssBackupComponents.SetupWriters(Guid[] includedWriters, Guid[] excludedWriters)
   at Duplicati.Library.Snapshots.WindowsSnapshot..ctor(IEnumerable`1 sources, IDictionary`2 options)
   at Duplicati.Library.Snapshots.SnapshotUtility.CreateWindowsSnapshot(IEnumerable`1 folders, Dictionary`2 options)
   at Duplicati.Library.Main.Operation.BackupHandler.GetSnapshot(String[] sources, Options options)

I run it as a service, Local System, usn is “on” and snapshots are set to “on” and none of the writers report a problem and nothing is logged in the Windows event logs. Disabling usn makes no difference, I have also rebooted.

If you downgrade to 2.0.3.14 do the snapshots work again?

@kenkendk, by removing OneDrive v1 have we just orphaned any v1 specific settings such that users migrating away for it can’t get to them in the GUI for removal anymore?

Spooky, that just went through my mind, and yes going back to 2.0.3.14 (re-ran installer then had to run a repair as the main exe had vanished and service would not start), snapshot is fine.

Can see this here too after running a backup on 2.0.4.2, installing upgrade, manual service restart, try again. Changing snapshot-policy to off avoids it, but with it on, which is what I want, profiling log shows the following:

2018-11-13 08:24:23 -05 - [Information-Duplicati.Server.WebServer.Server-ServerListening]: Server has started and is listening on 0.0.0.0, port 8200
2018-11-13 08:25:52 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Controller-RunBackup]: Starting - Running Backup
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Operation" ("Description", "Timestamp") VALUES ("Backup", 1542115552); SELECT last_insert_rowid();
2018-11-13 08:25:52 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Operation" ("Description", "Timestamp") VALUES ("Backup", 1542115552); SELECT last_insert_rowid(); took 0:00:00:00.223
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: Starting - ExecuteReader: SELECT "Key", "Value" FROM "Configuration" 
2018-11-13 08:25:52 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: ExecuteReader: SELECT "Key", "Value" FROM "Configuration"  took 0:00:00:00.000
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: Starting - ExecuteReader: SELECT "Key", "Value" FROM "Configuration" 
2018-11-13 08:25:52 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: ExecuteReader: SELECT "Key", "Value" FROM "Configuration"  took 0:00:00:00.000
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: SELECT COUNT(*) FROM "Block" WHERE "Size" > 102400
2018-11-13 08:25:52 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: SELECT COUNT(*) FROM "Block" WHERE "Size" > 102400 took 0:00:00:00.001
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: Starting - ExecuteReader: SELECT "Key", "Value" FROM "Configuration" 
2018-11-13 08:25:52 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: ExecuteReader: SELECT "Key", "Value" FROM "Configuration"  took 0:00:00:00.000
2018-11-13 08:25:52 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: Starting - ExecuteReader: SELECT "Key", "Value" FROM "Configuration" 
2018-11-13 08:25:52 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: ExecuteReader: SELECT "Key", "Value" FROM "Configuration"  took 0:00:00:00.000
2018-11-13 08:25:53 -05 - [Verbose-Duplicati.Library.Common.IO.VssBackupComponents-VSSTerminateError]: Failed to signal VSS completion
Alphaleonis.Win32.Vss.VssBadStateException: The VSS object was in an incorrect state for the requested operation.
   at Alphaleonis.Win32.Vss.VssBackupComponents.BackupComplete()
   at Duplicati.Library.Common.IO.VssBackupComponents.Dispose()
2018-11-13 08:25:53 -05 - [Verbose-Duplicati.Library.Common.IO.VssBackupComponents-VSSSnapShotDeleteCleanError]: Failed during VSS esnapshot closing
System.NullReferenceException: Object reference not set to an instance of an object.
   at Duplicati.Library.Common.IO.VssBackupComponents.Dispose()
2018-11-13 08:25:53 -05 - [Warning-Duplicati.Library.Main.Operation.BackupHandler-SnapshotFailed]: Failed to create a snapshot: System.NullReferenceException: Object reference not set to an instance of an object.
   at Duplicati.Library.Common.IO.VssBackupComponents.SetupWriters(Guid[] includedWriters, Guid[] excludedWriters)
   at Duplicati.Library.Snapshots.WindowsSnapshot..ctor(IEnumerable`1 sources, IDictionary`2 options)
   at Duplicati.Library.Snapshots.SnapshotUtility.CreateWindowsSnapshot(IEnumerable`1 folders, Dictionary`2 options)
   at Duplicati.Library.Main.Operation.BackupHandler.GetSnapshot(String[] sources, Options options)
System.NullReferenceException: Object reference not set to an instance of an object.
   at Duplicati.Library.Common.IO.VssBackupComponents.SetupWriters(Guid[] includedWriters, Guid[] excludedWriters)
   at Duplicati.Library.Snapshots.WindowsSnapshot..ctor(IEnumerable`1 sources, IDictionary`2 options)
   at Duplicati.Library.Snapshots.SnapshotUtility.CreateWindowsSnapshot(IEnumerable`1 folders, Dictionary`2 options)
   at Duplicati.Library.Main.Operation.BackupHandler.GetSnapshot(String[] sources, Options options)
2018-11-13 08:25:53 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingSourcePath]: Including source path: C:\PortableApps\Notepad++Portable\

Heh - I can think of some former co-workers that could benefit from a little mind sharing… :wink:

If you feel game, would you consider updating to .4.1 or .4.2 to see it we can pin down where the issue came in?

Edit: scratch that test - it sounds like @ts678 can confirm it worked fine in 2.0.4.2.

So it’s failing when CLOSING the snapshot?

Odd - I don’t know where that happens in the backup process but does that backup appear in your restore list?

Yes, and confirmed by doing another one with --snapshot-policy=On (and getting the Warning). In spite of the timed log I posted earlier, I also observed visually that I no longer got the 50-or-so-second delay VSS usually throws into my starting phase. Looking at announce and code, I see wide changes got done in path handling.

Yes, a lot of code was changed. Technically it should work as before, but I’m not surprised if something broke. I will look into it.

Edit: Can you open an issue on github? I will handle the problem from there then, so I can also refer to the issue number for upcoming commits.

2 Likes

2.0.4.3 canary --snapshot-policy Windows VSS System.NullReferenceException regression #3494 is GitHub’s version of this (with some additional testing). Thanks for your code @verhoek, and looking at apparent bug.

Possible regression (unless it’s an undocumented feature) from 2.0.4.2 is that GUI Commandline on a backup with a passphrase no longer includes job’s passphrase, and fails (e.g. on backup) as below. 2.0.4.4 does too.

ErrorID: PassphraseChangeNotSupported
You have attempted to change a passphrase to an existing backup, which is not supported. Please configure a new clean backup if you want to change the passphrase.
Return code: 100

Workaround is to manually add the passphrase option, or export as commandline for command prompt use.

added checkbox to allow exporting backup passwords #3467
hide encryption passphrase when exporting to commandline #3474
Exporting a backup configuration should not export passwords by default #3466

Maybe @Pectojin can say whether the GUI Commandline was supposed to be impacted. It IS more secure because previously the field of asterisks hiding the passphrase could be bypassed by clicking “Edit as text”.

1 Like

That’s definitely regression. It was never intended to affect the commandline UI :slight_smile:

I’ve made a fix: Fix commandline GUI regression by Pectojin · Pull Request #3512 · duplicati/duplicati · GitHub

1 Like