Release 2.0.6.1 (beta) 2021 - SFTP failure (Synology)

Support
1

Hello everyone,

I’m having some trouble after upgrading to the latest release and am wondering if anybody has any ideas.

I’m running the Synology build on a DS720+ and it has been working great. My backup device is a WD Passport that doesn’t support many protocols. It does, however, work with SFTP, which is what I’ve been using.

Since updating, the backup has been failing. I edited the backup config to see if anything had changed and realized that when I try to test the connection, I get “Failed to connect: The method or operation is not implemented.”

I read the mention of the SSH backend changing, so I deleted the key that I had stored with the backup config, just in case that was an error. Ultimately, there was no change in behaviour.

Does anybody have any ideas?

I’ve checked out the posts in https://forum.duplicati.com/t/release-2-0-6-1-beta-2021-05-03-ssh-validation-of-server-fingerprint-failed/12321 because there was some relevant info, but it doesn’t seem to be the same problem.

In the meantime, I’ve been able to run the backup by switching to FTP. Since my storage device is offsite, I’d like to switch back to SFTP if possible.

2

and then the suggested next step was Test connection, which failed for you.
Have you tried the Export as Command-line to make sure key isn’t around?

The end symptom does look different. Possibly it’s another result of the new code though.

Can’t connect (SCP, SSH) in Xamarin Android #807 is similar, but your post lacks a stack.

You can see if About → Show log → Live → Information says anything on Test Connection.

If it can’t list files (which is what Test connection does), it probably can’t backup but it might give you a better error message (though backup errors tend to show up in About → Show log → Stored instead).

You can take your Export As Command-line to a command line to hope for better message.

What does mono --version say? Duplicati 2.0.6.1 needs at least mono 5.10.

You can try netstat -an | fgrep <remote> to see if it attempted to contact.

EDIT 1:

Duplicati.CommandLine.BackendTool.exe can take the URL from the export and let you test as you like.
Starting with a list would be similar to what the Test connection button runs.

EDIT 2:

Yes. Even if Duplicati data is encrypted, somebody might get user and password and delete the backup.
You’d know about that because Duplicati checks the remote files – unless of course the list is broken.
I’m not seeing that your device can do FTPS, but if you have a manual you might look if it can encrypt…

3

Thank you for the troubleshooting tips. I’ll tell you what I’ve seen so far:

I exported the command line and verified that the key was not there.

I took a look at About → Show log → Live and didn’t see anything about the test connect. However, the recorded log did have a stack, as follows:

May 7, 2021 4:42 PM: Request for http://192.168.1.4:5000/api/v1/remoteoperation/test gave error
System.NotImplementedException: The method or operation is not implemented.
  at Renci.SshNet.Session.WaitOnHandle (System.Threading.WaitHandle waitHandle, System.TimeSpan timeout) [0x00041] in <8c66a76a693c4e52b456ec0712c863dd>:0 
  at Renci.SshNet.Session.WaitOnHandle (System.Threading.WaitHandle waitHandle) [0x0000d] in <8c66a76a693c4e52b456ec0712c863dd>:0 
  at Renci.SshNet.Session.Connect () [0x00184] in <8c66a76a693c4e52b456ec0712c863dd>:0 
  at Renci.SshNet.BaseClient.CreateAndConnectSession () [0x00053] in <8c66a76a693c4e52b456ec0712c863dd>:0 
  at Renci.SshNet.BaseClient.Connect () [0x0001f] in <8c66a76a693c4e52b456ec0712c863dd>:0 
  at Duplicati.Library.Backend.SSHv2.CreateConnection () [0x0010d] in <4da241fbc91e44a2bfb358a60db32dd6>:0 
  at Duplicati.Library.Backend.SSHv2+<List>d__39.MoveNext () [0x0002c] in <4da241fbc91e44a2bfb358a60db32dd6>:0 
  at Duplicati.Library.Interface.BackendExtensions.TestList (Duplicati.Library.Interface.IBackend backend) [0x00017] in <655587971ad24e1098eeff3f882f88c5>:0 
  at Duplicati.Library.Backend.SSHv2.Test () [0x00000] in <4da241fbc91e44a2bfb358a60db32dd6>:0 
  at Duplicati.Server.WebServer.RESTMethods.RemoteOperation.TestConnection (System.String url, Duplicati.Server.WebServer.RESTMethods.RequestInfo info) [0x000b7] in <87f95256fc6a4c3ea353de8d2aacf89b>:0 
  at Duplicati.Server.WebServer.RESTMethods.RemoteOperation.POST (System.String key, Duplicati.Server.WebServer.RESTMethods.RequestInfo info) [0x00094] in <87f95256fc6a4c3ea353de8d2aacf89b>:0 
  at Duplicati.Server.WebServer.RESTHandler.DoProcess (Duplicati.Server.WebServer.RESTMethods.RequestInfo info, System.String method, System.String module, System.String key) [0x00289] in <87f95256fc6a4c3ea353de8d2aacf89b>:0 
May 7, 2021 4:42 PM: 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 <4a89e81f3d9644e6a5d556824ae3eaf1>:0 
  at System.IO.StreamWriter.Flush () [0x00006] in <4a89e81f3d9644e6a5d556824ae3eaf1>:0 
  at Duplicati.Server.WebServer.RESTHandler.DoProcess (Duplicati.Server.WebServer.RESTMethods.RequestInfo info, System.String method, System.String module, System.String key) [0x003bc] in <87f95256fc6a4c3ea353de8d2aacf89b>:0

My mono version is: 5.20.1.34
My netstat shows no attempt to contact the remote.

Oh, and I ran it using the “CommandLine” option from the GUI and got this:

Backup started at 05/07/2021 16:52:58
Checking remote backup ...
  Listing remote folder ...
  Listing remote folder ...
  Listing remote folder ...
  Listing remote folder ...
  Listing remote folder ...
Fatal error => The method or operation is not implemented.

System.NotImplementedException: The method or operation is not implemented.
  at Duplicati.Library.Main.BackendManager.List () [0x00049] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.FilelistProcessor.RemoteListAnalysis (Duplicati.Library.Main.BackendManager backend, Duplicati.Library.Main.Options options, Duplicati.Library.Main.Database.LocalDatabase database, Duplicati.Library.Main.IBackendWriter log, System.Collections.Generic.IEnumerable`1[T] protectedFiles) [0x0000d] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList (Duplicati.Library.Main.BackendManager backend, Duplicati.Library.Main.Options options, Duplicati.Library.Main.Database.LocalDatabase database, Duplicati.Library.Main.IBackendWriter log, System.Collections.Generic.IEnumerable`1[T] protectedFiles) [0x00000] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify (Duplicati.Library.Main.BackendManager backend, System.String protectedfile) [0x0011d] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <34c05650075c4a0583e29e116862f000>:0 
  at CoCoL.ChannelExtensions.WaitForTaskOrThrow (System.Threading.Tasks.Task task) [0x00050] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.Run (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00009] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0026f] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Controller.Backup (System.String[] inputsources, Duplicati.Library.Utility.IFilter filter) [0x00074] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.CommandLine.Commands.Backup (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) [0x00119] in <28143d111af14d1eb877912a2f4948a3>: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) [0x00342] in <28143d111af14d1eb877912a2f4948a3>:0 
  at Duplicati.CommandLine.Program.RunCommandLine (System.IO.TextWriter outwriter, System.IO.TextWriter errwriter, System.Action`1[T] setup, System.String[] args) [0x00002] in <28143d111af14d1eb877912a2f4948a3>:0 
Return code: 100

Unfortunately, the backup device doesn’t support FTPS. I will, however, try the BackendTool and see what I can find.

Thank you for your help!

4

If you can get a GitHub account, I suppose you could add onto the known SSH.NET issue that hasn’t gotten any response yet. Or for developer support here (although they won’t be SSH.NET experts), open an Issue.

For a shortcut, let me ask if @warwickmm (who I think at least runs SFTP backups on Linux) has an idea.

EDIT:

Is this the SynoCommunity mono? I think @drwtsn32 use to run directly but now uses a Docker on Syno.
I’m not familiar with the DS720+ but possibly there’s a Docker that works better (not sure why, just hoping).

EDIT 2:

On the SynoCommunity mono page I’m noticing that they went through three versions of 5.20.1.34 without saying much about them. They do have dates. Can you find a suffix or a date to guess what you’re using?

Looks to me like it runs a Celeron J4125, which would be a 32-bit (x86) model. ARM gets more confusing.
EDIT: J4125 actually looks like it can run the 64-bit instruction set, so I suppose that’d be the proper mono.

5

Do you have the ability to test with an alternate SFTP target, to see if the problem remains? I’m wondering if the issue is with the WD Passport.

If not, I do have a Synology and I can try testing 2.0.6.1 with mono 5.20.1.34 but it will be with a different SFTP back end (I don’t have a WD Passport).

6

I’m not sure, my guess is there’s a problem with the Synocommunity distribution of mono. In this issue (Mono: 5.20.1.34-16 on Synology DS418), it is mentioned that there is

a known issue with the CPU architecture, and it is related to SSL/TLS and mono.

Also, they

have now deleted the mono packages for aarch64 except version 5.8.0.108-11 .
The packages where already deactivated, but it was possible to manually download and install. Now such nonworking packages do not exist anymore.

EDIT: Sorry, I just noticed that this is on Celeron J4125, so the above is probably not related.

7

I’ve been a bit pressed for time since this afternoon but when I saw your suggestion for trying another SFTP, I realized that I have another Synology that supports it. I didn’t have it turned on but after a really short configuration, fired it up and pointed my backup to it.

And, yes, it immediately asked me to approve the new key, then tested successfully!

A very nice peg in the board, indeed. Great call! It probably would have been a really long time before I tried this, given that it worked with the same WD Passport prior to the upgrade.

Over the weekend, I’ll try to do a bit more digging, time permitting. It could be something as simple as one of the SSH.NET settings or parameters, but I’m guessing that I’m due for some trial and error.

I’ll try some of the other suggestions here and post another update once I get somewhere.

8

Maybe there’s a firmware update for your WD Passport that might help resolve the issue?

Also I guess it’s possible it’s still some flaw in SSH.NET that is causing the issue with your WD Passport. Or an interaction with a specific mono version. Does your Synology support Docker? That’s how I run Duplicati nowadays, it’s another thing you could try…

9

To WD Passport SFTP:

and then changing the remote to another Synology used as SFTP server got

is odd. The stack also looked like the error was on the client connect attempt.

Perhaps netstat missed something. Do the client or Passport have tcpdump?
sudo tcpdump -i any -vv port 22 may show if anything is actually going.
The -vv is optional but it might give a decode. I’m not set up right now to test it.
If need be, a much better decode is probably available in Wireshark or tshark.

EDIT:

I just edited my earlier thought on your CPU to think it’s 64-bit, but for more info:
32-bit, 64-bit CPU op-mode on Linux because there’s also a Linux to consider.
So beyond the which-mono-version concern earlier, there’s which-architecture.

10

Don’t want to hijack @Rob_Canada his issue, but I’m having the exact same issue after upgrading to 2.0.6.1 beta.

Source: Debian Buster (amd64) / Mono 5.18 / SFTP with key authentication
Destination: Bitvise SSH Server 8.47

Tried to remove the SSH host key, even allow any fingerprint, but this does not change the outcome of a “test connection”. Destination does not show any issues in the log files as well.
Tried to connect to another (local) OpenSSH server from Duplicati (also key authentication), and this works without issues.
If I make the SFTP connection from the local SSH client on Debian to remote Bitvise server, the same connection can be made without issues. So the issue is not limited to Synology’s SSH implementation (can’t imagine they also use Bitvise)

Full error message:

System.NotImplementedException: The method or operation is not implemented.
  at Duplicati.Library.Main.BackendManager.List () [0x00049] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.FilelistProcessor.RemoteListAnalysis (Duplicati.Library.Main.BackendManager backend, Duplicati.Library.Main.Options options, Duplicati.Library.Main.Database.LocalDatabase database, Duplicati.Library.Main.IBackendWriter log, System.Collections.Generic.IEnumerable`1[T] protectedFiles) [0x0000d] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList (Duplicati.Library.Main.BackendManager backend, Duplicati.Library.Main.Options options, Duplicati.Library.Main.Database.LocalDatabase database, Duplicati.Library.Main.IBackendWriter log, System.Collections.Generic.IEnumerable`1[T] protectedFiles) [0x00000] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify (Duplicati.Library.Main.BackendManager backend, System.String protectedfile) [0x0011d] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <34c05650075c4a0583e29e116862f000>:0 
  at CoCoL.ChannelExtensions.WaitForTaskOrThrow (System.Threading.Tasks.Task task) [0x00050] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.Run (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00009] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0026f] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Library.Main.Controller.Backup (System.String[] inputsources, Duplicati.Library.Utility.IFilter filter) [0x00074] in <34c05650075c4a0583e29e116862f000>:0 
  at Duplicati.Server.Runner.Run (Duplicati.Server.Runner+IRunnerData data, System.Boolean fromQueue) [0x00349] in <87f95256fc6a4c3ea353de8d2aacf89b>:0
11

This sounds like it could be related, but supposedly it was fixed in mono 5.12.0.226.

Are you willing to try upgrading mono to see if that helps?

12

@warwickmm Both @Rob_Canada and I are running a version of Mono >5.12 already. Debian stable package has not been updated in a while:

# mono --version
Mono JIT compiler version 5.18.0.240 (Debian 5.18.0.240+dfsg-3 Wed Apr 17 16:37:36 UTC 2019)
13

I did some hacking around and built the 2.0.6.1 Duplicati Docker but with mono 5.18.0.225 (that’s the closest image I could find) and didn’t experience any connection issues with a newly configured SFTP backup.

It is strange that @Rob_Canada’s problem was fixed by changing the SSH server. Perhaps the handshake or key negotiation results in a different code path somehow?

14

I can get this on Linux Mint 19.3 (Ubuntu based) going to Bitvise on Windows.

Mono JIT compiler version 6.12.0.122 (tarball Mon Feb 22 17:29:18 UTC 2021)

I got a tcpdump packet capture which I decoded with Wireshark on Windows.

SSH Protocol
    SSH Version 2 (encryption:aes256-ctr mac:hmac-sha1 compression:none)
        Packet Length: 324
        Padding Length: 10
        Key Exchange (method:curve25519-sha256)
            Message Code: Elliptic Curve Diffie-Hellman Key Exchange Reply (31)
            KEX host key (type: ecdsa-sha2-nistp384)
            ECDH server's ephemeral public key length: 32
            ECDH server's ephemeral public key (Q_S): 193d7cfb1860b26a9cc8021f31ba38c3fae3c7cce40a61c145d5de07616e8c29
            KEX H signature length: 132
            KEX H signature: 0000001365636473612d736861322d6e697374703338340000006900000030362ce28bc4…
        Padding String: 8d228564fd5fbfd863b0
    SSH Version 2 (encryption:aes256-ctr mac:hmac-sha1 compression:none)
        Packet Length: 84
        Padding Length: 82
        Key Exchange (method:curve25519-sha256)
            Message Code: New Keys (21)
        Padding String: 9af273440c38fb5bebb72beeb302f50922b011115fc926554bcf9b5b4b3d05b3ecc65711…
    [Direction: server-to-client]

was the final SSH protocol packet from either side before Duplicati closed TCP.
I thought maybe the new Key Exchange (method:curve25519-sha256) was bad.
Bitvise Settings let me turn off Key exchange curve22519, but it didn’t stop error.
Key Exchange (method:ecdh-sha2-nistp256) is what was seen on this attempt.

I can reproduce the error in Duplicati.CommandLine.BackendTool.exe list

I don’t have any other SFTP servers set up yet. What server are you running to?

I don’t have any Linux debugger, and mono’s --trace filters aren’t working for me.

15

Nice troubleshooting… I will try to reproduce this on my dev machine if I get some time today.

16

As a side note, 2.0.5.114 on Windows was fine, and “should” be the same as 2.0.6.1.
Whatever’s going on (so far) appears to need mono. Thanks for pursuing it further…

17

Thanks @ts678 and @drwtsn32, it sounds like we are getting somewhere. Unfortunately, I am unable to reproduce this with my setup:

  • Duplicati 2.0.5.114 running with Mono JIT compiler version 6.12.0.107 (makepkg/a22ed3f094e Tue Dec 22 06:01:50 PM -03 2020)
  • SSH server running OpenSSH_7.7p1, LibreSSL 2.7.4
  • SSH server running OpenSSH_8.4p1, OpenSSL 1.1.1k 25 Mar 2021.
  • Public key authentication

It would be nice if someone can try and reproduce the issue with the minimal example here to further isolate the problem. Even better if a debugger can be hooked up to get some more details.

18

Know of a reasonable free mono debugger? Most of them look dead now.
I’m not sure what gear @drwtsn32 has. I guess you have no Windows?

This issue is annoying because it needs just the right blend of equipment.
For one more data point, the free Core FTP mini SFTP server worked OK.
That runs on Windows. Maybe you can test different SFTP servers there?

19

I don’t have Windows. All I have is what’s mentioned above.

Easiest way to debug on Linux is to use Visual Studio Code or MonoDevelop. Then, set a breakpoint (either in the Duplicati source here or in the suggested example) and run the TrayIcon project in debug mode. There’s a suggested patch for SSH.NET that seems to hint that the exception we’re seeing isn’t providing as much detail as it potentially can, so perhaps stepping through the debugger might reveal some more info.

Rider has the ability to decompile and set breakpoints in external assemblies, so that could be useful if you need to step into SSH.NET or mono code. I think we might have a spare license for you to use if you want.

20

I’m trying monodevelop first on the hope that the latest version (Oct 8, 2018) is less dead than mdb is.
If that doesn’t work, Visual Studio Code is next. I guess I need the Mono Debug extension installed too.