Port access to Opendal Hetzner for StorageBox

[devhell]

Hi,

Love that the backend is not relying on rclone now, but it appears that my existing Hetzner storagebox repo can't be backed up to any more.

The backup is called as follows: rustic -P machine backup

Config file:

repository]
repository = "opendal:sftp"
password-file = "XXXXXXX"

[repository.options]
endpoint = "ssh://XXXXXX.your-storagebox.de"
user = "XXXXXXX"
key = "~/.ssh/XXXXXXX"
root = "/rustic/backup"

[backup]
exclude-if-present = [".nobackup", "CACHEDIR.TAG"]
one-file-system = true

[[backup.sources]]
source = "/home/dev/temp/storagebox"

Output:

[INFO] using config /home/dev/.config/rustic/machine.toml
[INFO] session_task; session=Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connection4aCS1f" }), ctl: "/home/dev/.local/state/.ssh-connection4aCS1f/master", master_log: Some("/home/dev/.local/state/.ssh-connection4aCS1f/log") }))
[INFO] Connecting to sftp subsystem, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connection4aCS1f" }), ctl: "/home/dev/.local/state/.ssh-connection4aCS1f/master", master_log: Some("/home/dev/.local/state/.ssh-connection4aCS1f/log") }))
[INFO] Connection to sftp subsystem established, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connection4aCS1f" }), ctl: "/home/dev/.local/state/.ssh-connection4aCS1f/master", master_log: Some("/home/dev/.local/state/.ssh-connection4aCS1f/log") }))
[INFO] flush_task; write_end_buffer_size=100 flush_interval=500µs
[INFO] read_task; read_end_buffer_size=1024
[INFO] repository opendal:: password is correct.
[INFO] using cache at /home/dev/.cache/rustic/472f44f2c9250e7daa1f2e9221b0f3fd7751e6eab6d0c236902535fa317ffbea
[00:00:00] reading index...               ████████████████████████████████████████          6/6                                                           [INFO] using all backup sources from config file.
[INFO] merging source="/home/dev/temp/storagebox" section from config file
[00:00:00] getting latest snapshot...     ████████████████████████████████████████         46/46                                                          [INFO] using parent b5c7b1e3
[INFO] starting to backup "/home/dev/temp/storagebox"...
[00:00:04] backing up...                  ███████████████████████████████████████░ 120.61 GiB/123.06 GiB 22.66 GiB/s  (ETA 0s)                            [WARN] service=sftp operation=write path=snapshots/63883030ce8df0a9c9b5ec09565a5701cb9af3a19e218dc7e8ff708aac12018a -> NotFound (persistent) at write, context: { service: sftp, path: snapshots/63883030ce8df0a9c9b5ec09565a5701cb9af3a19e218dc7e8ff708aac12018a } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
error: NotFound (persistent) at write, context: { service: sftp, path: snapshots/63883030ce8df0a9c9b5ec09565a5701cb9af3a19e218dc7e8ff708aac12018a } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
[INFO] Requesting graceful shutdown of flush_task from read_task, shared_data = 0x55d1431fd670
[INFO] flush_task graceful shutdown, shared_data = 0x55d1431fd670

Every time I run the backup command, the snapshot ID it says it can't find, changes.

I ran rustic -P machine check which came back fine. I've also tried rustic -P machine repair index and rustic -P machine repair snapshots, both of which don't flag anything. Running the backup again simply results in a random snapshot ID apparently not being found.

System is NixOS Unstable, rustic version is 0.7.0.

[aawsome]

It seems the write command of the snapshotfile generated by that backup just failed. Which is a bit weird as obviously reading was successful.

Just guessing: From https://github.com/rustic-rs/rustic/blob/main/config/services/sftp_hetzner_sbox.toml I see that other users use port 23 to access the storage box. Could it be that using the default port 22 you just have read-only access?

[devhell]

It seems the write command of the snapshotfile generated by that backup just failed. Which is a bit weird as obviously reading was successful.

Just guessing: From https://github.com/rustic-rs/rustic/blob/main/config/services/sftp_hetzner_sbox.toml I see that other users use port 23 to access the storage box. Could it be that using the default port 22 you just have read-only access?

Storagebox allows for both port 22 and 23 to be used, see here: https://docs.hetzner.com/robot/storage-box/backup-space-ssh-keys

I can't use 23 because of how my work network is configured. I've used rustic via rclone backend on port 22 just fine in the past.

I'll try on a different machine that is on a less restricted network, and change to port 22 just to be sure, and I'll report back.

[simonsan]

https://docs.hetzner.com/robot/storage-box/access/access-ssh-rsync-borg

The Storage Box provides an extended SSH service on port 23. With this service, you can use rsync, BorgBackup, and some additional command line tools.
It is possible to get interactive SSH access, but this access is limited. It is not possible to have interactive access via port 22, but it is possible via port 23. There is no full shell. For example, it is not possible to use pipes or redirects. It is also not possible to execute uploaded scripts.

So please use port 23. ;-)

[devhell]

Sorry, but as I wrote before, I can't use port 23 at work, only port 22. I've used port 22 successfully in the past using the rclone backend, so I don't think that it's read-only, but I'm happy to test on a network that has no port restrictions.

[aawsome]

@devhell I'd like to see if only the snapshot is affected or if this was the only data to upload.
Can you do a dry-run and see if there are any changes which would have been uploaded?

[devhell]

I'll try to create a new repository directory and report back.

[devhell]

Alright, so here's the result:

I've adapted the config to back up test-storagebox as the only source to /rustic-test/backup on the storagebox:

[repository]
repository = "opendal:sftp"
password-file = XXXXXXXXX

[repository.options]
endpoint = "ssh://XXXXXXX.your-storagebox.de"
user = XXXXXXX
key = XXXXXXX
root = "/rustic-test/backup"

[backup]
exclude-if-present = [".nobackup", "CACHEDIR.TAG"]
one-file-system = true

[[backup.sources]]
source = "/home/dev/temp/test-storagebox"

Inside the source directory is a simple text document:

❯ ls -l temp/test-storagebox
.rw-r--r-- dev users 19 B Sat Mar 16 16:55:18 2024 testfile.txt

After that, I initialized the repository:

❯ rustic -P machine init
[INFO] using config /home/dev/.config/rustic/machine.toml
[INFO] session_task; session=Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connection2C62YL" }), ctl: "/home/dev/.local/state/.ssh-connection2C62YL/master", master_log: Some("/home/dev/.local/state/.ssh-connection2C62YL/log") }))
[INFO] Connecting to sftp subsystem, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connection2C62YL" }), ctl: "/home/dev/.local/state/.ssh-connection2C62YL/master", master_log: Some("/home/dev/.local/state/.ssh-connection2C62YL/log") }))
[INFO] Connection to sftp subsystem established, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connection2C62YL" }), ctl: "/home/dev/.local/state/.ssh-connection2C62YL/master", master_log: Some("/home/dev/.local/state/.ssh-connection2C62YL/log") }))
[INFO] flush_task; write_end_buffer_size=100 flush_interval=500µs
[INFO] read_task; read_end_buffer_size=1024
[WARN] service=sftp operation=stat path=config -> NotFound (persistent) at stat, context: { service: sftp, path: config } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
[WARN] service=sftp operation=stat path=config -> NotFound (persistent) at stat, context: { service: sftp, path: config } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
[WARN] service=sftp operation=write path=keys/22c6fe9d444879e667701ce1167244ac22ebf366864c6ff56dfccc17daebd6c4 -> NotFound (persistent) at write, context: { service: sftp, path: keys/22c6fe9d444879e667701ce1167244ac22ebf366864c6ff56dfccc17daebd6c4 } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
error: NotFound (persistent) at write, context: { service: sftp, path: keys/22c6fe9d444879e667701ce1167244ac22ebf366864c6ff56dfccc17daebd6c4 } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
[INFO] Requesting graceful shutdown of flush_task from read_task, shared_data = 0x55a2623847a0

Checking the Hetzner storagebox repo via sftp shows that indeed, the rustic-test/backup directory was created despite the above error, including all the subdirectories, etc.:

sftp> ls -l rustic-test/backup
drwxr-xr-x  258 XXXXXXX  XXXXXXX       258 Mar 16 17:22 data
drwxr-xr-x    2 XXXXXXX  XXXXXXX         2 Mar 16 17:22 index
drwxr-xr-x    2 XXXXXXX  XXXXXXX         2 Mar 16 17:22 keys
drwxr-xr-x    2 XXXXXXX  XXXXXXX         2 Mar 16 17:22 snapshots

Executing rustic -P machine backup gives the following:

❯ rustic -P machine backup
[INFO] using config /home/dev/.config/rustic/machine.toml
[INFO] session_task; session=Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connectionHnZmZa" }), ctl: "/home/dev/.local/state/.ssh-connectionHnZmZa/master", master_log: Some("/home/dev/.local/state/.ssh-connectionHnZmZa/log") }))
[INFO] Connecting to sftp subsystem, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connectionHnZmZa" }), ctl: "/home/dev/.local/state/.ssh-connectionHnZmZa/master", master_log: Some("/home/dev/.local/state/.ssh-connectionHnZmZa/log") }))
[INFO] Connection to sftp subsystem established, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connectionHnZmZa" }), ctl: "/home/dev/.local/state/.ssh-connectionHnZmZa/master", master_log: Some("/home/dev/.local/state/.ssh-connectionHnZmZa/log") }))
[INFO] flush_task; write_end_buffer_size=100 flush_interval=500µs
[INFO] read_task; read_end_buffer_size=1024
[WARN] service=sftp operation=stat path=config -> NotFound (persistent) at stat, context: { service: sftp, path: config } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag: en-US
error: No repository config file found. Is there a repo at opendal:?
[INFO] Requesting graceful shutdown of flush_task from read_task, shared_data = 0x55db010b5670

Now, this was on port 22, so I figured I'd delete the rustic-test repository via sftp and try again from scratch but with port 23. Here's the config change, everything else is the same as up top:

endpoint = "ssh://XXXXXXX.your-storagebox.de:23"

The result of rustic -P machine init:

[INFO] using config /home/dev/.config/rustic/machine.toml
[INFO] session_task; session=Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connectionYro29k" }), ctl: "/home/dev/.local/state/.ssh-connectionYro29k/master", master_log: Some("/home/dev/.local/state/.ssh-connectionYro29k/log") }))
[INFO] Connecting to sftp subsystem, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connectionYro29k" }), ctl: "/home/dev/.local/state/.ssh-connectionYro29k/master", master_log: Some("/home/dev/.local/state/.ssh-connectionYro29k/log") }))
[INFO] Connection to sftp subsystem established, session = Session(ProcessImpl(Session { tempdir: Some(TempDir { path: "/home/dev/.local/state/.ssh-connectionYro29k" }), ctl: "/home/dev/.local/state/.ssh-connectionYro29k/master", master_log: Some("/home/dev/.local/state/.ssh-connectionYro29k/log") }))
[INFO] flush_task; write_end_buffer_size=100 flush_interval=500µs
[INFO] read_task; read_end_buffer_size=1024
[WARN] service=sftp operation=stat path=config -> NotFound (persistent) at stat, context: { service: sftp, path: config } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag:
[WARN] service=sftp operation=stat path=config -> NotFound (persistent) at stat, context: { service: sftp, path: config } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag:
[WARN] service=sftp operation=write path=keys/e9dcf3b89d7222bd90b788479ebc0fc56f2f936f4d4e63f7f9dd6d3a151b8ef9 -> NotFound (persistent) at write, context: { service: sftp, path: keys/e9dcf3b89d7222bd90b788479ebc0fc56f2f936f4d4e63f7f9dd6d3a151b8ef9 } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag:
error: NotFound (persistent) at write, context: { service: sftp, path: keys/e9dcf3b89d7222bd90b788479ebc0fc56f2f936f4d4e63f7f9dd6d3a151b8ef9 } => sftp error, source: Sftp server reported error kind NoSuchFile, msg: Err Message: No such file, Language Tag:
[INFO] Requesting graceful shutdown of flush_task from read_task, shared_data = 0x5652325037a0
[INFO] flush_task graceful shutdown, shared_data = 0x5652325037a0

Checking the remote with sftp shows that no rustic-test/backup was created.

[devhell]

If you'd like, I can switch back to the rclone backend for comparison?

[devhell]

I've now reverted back to the rclone backend, and it succeeds with the backup:

❯ rustic -P herja backup
[INFO] using config /home/dev/.config/rustic/machine.toml
[INFO] repository rclone:sbx-machine:rustic/backup: password is correct.
[INFO] using cache at /home/dev/.cache/rustic/472f44f2c9250e7daa1f2e9221b0f3fd7751e6eab6d0c236902535fa317ffbea
[00:00:00] reading index...               ████████████████████████████████████████          6/6                                                           [INFO] using all backup sources from config file.
[INFO] merging source="/home/dev/temp/storagebox" section from config file
[00:00:00] getting latest snapshot...     ████████████████████████████████████████         46/46                                                          [INFO] using parent b5c7b1e3
[INFO] starting to backup "/home/dev/temp/storagebox"...
[00:00:04] backing up...                  ████████████████████████████████████████ 123.06 GiB/123.06 GiB 26.56 GiB/s  (ETA 0s)                            Files:       1 new, 0 changed, 39916 unchanged
Dirs:        0 new, 5 changed, 2256 unchanged
Added to the repo: 1.5 kiB (raw: 3.0 kiB)
processed 39917 files, 123.1 GiB
snapshot b0339221 successfully saved.
[INFO] backup of "/home/dev/temp/storagebox" done.

[aawsome]

@devhell Sorry for the late reply.

Actually there seems that there is a problem with the combination of opendal sftp service, the hetzner storage box - and maybe the configuration you are using locally to access the storage box.
As it works using rclone, I think there is a bug in opendal which happens in your setting.

I can confirm that sftp using a simple ssh server over port 22 on a local network does work for me. Is there anyone who has an already working configuration for the hetzner storage box?

[aawsome]

@devhell You could also try to open an issue in the opendal project: https://github.com/apache/OpenDAL
It seems to me that Operator::write and maybe Operator::is_exist (in the config file case) error with the error messages you are observing...

[devhell]

I'll look into it, thank you.