Regression: SFTP connection to Synology NAS broke in restic releases past restic_0.12.0

[wesselih]

Output of restic version

Current restic version I detected the problem with:
restic 0.15.0 compiled with go1.19.5 on linux/amd64

Last working version:
restic 0.12.0 compiled with go1.15.8 on linux/amd64

First version I could track down to contain the error:
restic 0.12.1 compiled with go1.16.6 on linux/amd64

How did you run restic exactly?

Environment is clean from RESTIC vars except for $RESTIC_PASSWORD_FILE

restic -r sftp:hwesseli@homestation:/backups/restic/pluto_repo snapshots
hwesseli@homestation's password: 
enter password for repository: 

What backend/server/service did you use to store the repository?

SFTP

Expected behavior

I have an elderly NAS with a huge harddisk that contains a lot of backups from the past. The NAS is a Synology DS110j.
The repository on the NAS was created with version 'restic_0.10.0_linux_amd64'

When calling restic snapshot I expect restic to show the snapshots of the repository on the Synology NAS.
This is the case e.g. with version restic_0.12.0. Versions past 0.12.0 are broken.

hwesseli@pluto ~ :( bin/restic_0.12.0_linux_amd64 -r sftp:hwesseli@homestation:/backups/restic/pluto_repo snapshots
hwesseli@homestation's password: 
repository 0d87c448 opened successfully, password is correct
ID        Time                 Host        Tags                                                  Paths
------------------------------------------------------------------------------------------------------------------
d52648bb  2020-10-30 23:24:14  pluto                                                             /allhome/hwesseli
....

Actual behavior

The snapshot command (and any other command) fails with the following error message:

hwesseli@pluto ~ :) bin/restic_0.12.1_linux_amd64 -r sftp:hwesseli@homestation:/backups/restic/pluto_repo snapshots
hwesseli@homestation's password: 
repository 0d87c448 opened successfully, password is correct
Save(<lock/3ae1b9b00e>) returned error, retrying after 552.330144ms: Close: connection lost
exit status 255
ssh command exited
github.com/restic/restic/internal/backend/sftp.startClient.func2
        /restic/internal/backend/sftp/sftp.go:79
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1371
unable to create lock in backend

Since version restic_0.15 the error message is a bit different, but the result is the same:

hwesseli@pluto ~ :) bin/restic_0.15.0_linux_amd64 -r sftp:hwesseli@homestation:/backups/restic/pluto_repo snapshots
hwesseli@homestation's password: 
repository 0d87c448 opened (version 1)
Save(<lock/ca5eff01d6>) returned error, retrying after 552.330144ms: Close: connection lost
unable to create lock in backend: ssh command exited: exit status 255

Restic leaves a stale lock on the repository when exiting.
The Repository itself is in sane state, I can run restic_0.15.0_linux_arm check directly on the device w/o errors.

Steps to reproduce the behavior

Behaviour is reproducible everytime with restic versions > 0.12.0, with any command.
When creating a new repository with restic_0.12.0_linux_amd64 -r sftp:hwesseli@homestation:/backups/restic/test_0.12.0 init
the result in the filesystem of the NAS looks different to (broken) version restic_0.12.1_linux_amd64

HomeStation> ls test_0.12.0/
config     data       index      keys       locks      snapshots

HomeStation> ls test_0.12.1/
data       index      keys       locks      snapshots
HomeStation> 

Do you have any idea what may have caused this?

No

Do you have an idea how to solve the issue?

One workaround is to create a rclone SFTP configuration and use the rclone backend with restic.

hwesseli@pluto ~ :) restic -r rclone:homestation:/backups/restic/pluto_repo snapshots
repository 0d87c448 opened (version 1)
ID        Time                 Host        Tags                                                  Paths
------------------------------------------------------------------------------------------------------------------
d52648bb  2020-10-30 23:24:14  pluto                                                             /allhome/hwesseli

Did restic help you today? Did it make you happy in any way?

This is the greatest backup tool I ever used. Since I trust in restic I dared to scan all my paper documents and shred them.
Thank you for this, it exactly matches my needs and way of working.

[MichaelEischer]

I have an elderly NAS with a huge harddisk that contains a lot of backups from the past. The NAS is a Synology DS110j.

The issue looks a lot like a bug in the sftp implementation on the NAS (which hasn't received any updates for 4 years by now). With a more recent Synology NAS, restic 0.14.0 works for me.

[wesselih]

I have an elderly NAS with a huge harddisk that contains a lot of backups from the past. The NAS is a Synology DS110j.

The issue looks a lot like a bug in the sftp implementation on the NAS (which hasn't received any updates for 4 years by now). With a more recent Synology NAS, restic 0.14.0 works for me.

I just created an rclone config for the SSH backend to see if rclone might be able to access the repository.
restic_0.15.0 works in combination with rclone (rclone v1.53.3-DEV from the Ubuntu 22.04 repositories).

restic_0.15.0_linux_amd64 -r rclone:homestation:/backups/restic/pluto_repo snapshots
repository 0d87c448 opened (version 1)
ID        Time                 Host        Tags                                                  Paths
------------------------------------------------------------------------------------------------------------------
d52648bb  2020-10-30 23:24:14  pluto                                                             /allhome/hwesseli
...

The ssh demon on the NAS is indeed quite old:

OpenSSH_6.6p2-hpn14v4, OpenSSL 1.0.1u-fips  22 Sep 2016

I will update the workaround section of the ticket accordingly. However something must have changed between restic versions 0.12.0 and 0.12.1

[MichaelEischer]

The ssh demon on the NAS is indeed quite old:

OpenSSH_6.6p2-hpn14v4, OpenSSL 1.0.1u-fips  22 Sep 2016

Judging from other SFTP issues with Synology NAS, there's also a custom (?) sftp-server implementation in use. For openssh that seems to be located at /usr/lib/ssh/sftp-server (not sure where it's located on the NAS). And that sftp-server is the part which causes the problem. For the ssh connection itself, restic just calls ssh such that this doesn't change between restic versions.

The only sftp related changes in restic between 0.12.0 and 0.12.1 are that we've updated pkg/sftp from 1.12 to 1.13.2 (up to 1.13.5 by now) and added a call to explicitly set the file permissions of uploaded files. Without being able to reproduce, it's hard to tell what of that is the cause.

To get a better idea where to look, you'd have to use git bisect to iteratively build different restic versions (about 6 times) until the it's clear which commit introduced the problem. Feel free to ask if you need help with that.

[AlBundy33]

fyi no issues with DS213

> sshd -v
unknown option -- v
OpenSSH_7.4p1, OpenSSL 1.0.2u-fips  20 Dec 2019
usage: sshd [-46DdeiqTt] [-C connection_spec] [-c host_cert_file]
            [-E log_file] [-f config_file] [-g login_grace_time]
            [-h host_key_file] [-o option] [-p port] [-u len]

[wesselih]

To get a better idea where to look, you'd have to use git bisect to iteratively build different restic versions (about 6 times) until the it's clear which commit introduced the problem. Feel free to ask if you need help with that.

Hi @MichaelEischer ,
I'm not a developer, but I can try. Could you point me to a page or ticket with a description how it works or (likely more important) how I can setup the required Go environment under Linux?

[AlBundy33]

I've tried an old centos docker-image without issues 😞

sh-4.1# sshd -version
sshd: illegal option -- v
OpenSSH_5.3p1, OpenSSL 1.0.1e-fips 11 Feb 2013
usage: sshd [-46DdeiqTt] [-b bits] [-C connection_spec] [-c host_cert_file]
            [-f config_file] [-g login_grace_time] [-h host_key_file]
            [-k key_gen_time] [-o option] [-p port] [-u len]
sh-4.1# ./restic_0.15.1_linux_amd64 version
restic 0.15.1 compiled with go1.19.5 on linux/amd64
sh-4.1# ./restic_0.15.1_linux_amd64 -r sftp:root@localhost:/root/backup snapshots
repository 527a75d9 opened (version 2, compression level auto)

[AlBundy33]

could this maybe related to ##4209?

[wesselih]

could this maybe related to ##4209?

Hello @AlBundy33 ,
thank you for pointing out #4209.
Indeed, it looks as if the new SFTP library is the culprit in both cases.
That would mean, a bug ticket should be opened against the library instead of restic.

However, I'm not shure how to do that and whether I'd be able to provide reproducible evidence for the developers.
I'm going to stick to the workaround with rclone I've described and close this ticket.

Thanks for your support @MichaelEischer , @AlBundy33