ikifar2012 / remote-backup-addon

Automatically create and backup HA snapshots using SCP
30 stars 4 forks source link

SFTP port number other than 22 fails #75

Closed TheoMol closed 1 year ago

TheoMol commented 1 year ago

Remote Backup fails when setting the SFTP port number om my DSM to 222 and remote_port in the config also to 222. Log:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/00-banner.sh
-----------------------------------------------------------
 Add-on: Remote Backup
 Automatically create and transfer HA backups using SFTP (SCP), rsync, or rclone (experimental)
-----------------------------------------------------------
 Add-on version: 2022.9.4
 You are running the latest version of this add-on.
 System: Home Assistant OS 9.0  (amd64 / qemux86-64)
 Home Assistant Core: 2022.9.7
 Home Assistant Supervisor: 2022.09.1
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
cont-init: info: /etc/cont-init.d/00-banner.sh exited 0
cont-init: info: running /etc/cont-init.d/01-log-level.sh
cont-init: info: /etc/cont-init.d/01-log-level.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
[19:36:03] INFO: Adding SSH configuration.
[19:36:04] WARNING: No password set, creating a local backup without password.
[19:36:04] INFO: Creating partial backup: "Automated backup 2022-10-05 19-36"
[19:36:04] NOTICE: Excluded folder(s):
media
share
[19:36:05] NOTICE: Excluded addon(s):
core_mariadb
core_ssh
core_mosquitto
[19:36:41] INFO: Backup created: ff68e4c5
[19:36:41] INFO: Copying backup using SFTP/SCP.
[19:36:41] WARNING: SFTP transfer failed, falling back to SCP.
[19:36:41] ERROR: Error copying backup ff68e4c5.tar to /Backup/BackupHA on 192.168.178.160.
jq: error (at :1): Cannot index array with string "result"
jq: error (at :1): Cannot index array with string "data"
[19:36:42] FATAL: Cloning backup(s) to remote host 192.168.178.160 failed! See log for details.
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

The add-on works flawlessly when setting both ports back to 22.

patman15 commented 1 year ago

Hi! Could it be a firewall issue? Can you post a log with debug enabled?

TheoMol commented 1 year ago

No I do not think it is a firewall issue. Manual sftp works fine when DSM port is set to 222:

➜  backup ls -alsrt
total 274572
     4 drwxr-xr-x    1 root     root          4096 Sep 17 20:01 ..
     4 -rw-r--r--    1 root     root           242 Oct  4 23:31 .samba_backup.sensor
 38940 -rw-r--r--    1 root     root      39874560 Oct  5 19:36 ff68e4c5.tar
 38960 -rw-r--r--    1 root     root      39895040 Oct  5 19:45 0f2b3b84.tar
 38980 -rw-r--r--    1 root     root      39915520 Oct  5 19:51 e1812982.tar
 38980 -rw-r--r--    1 root     root      39915520 Oct  5 19:53 a90b1341.tar
 39340 -rw-r--r--    1 root     root      40284160 Oct  5 23:00 77df4d4b.tar
 39600 -rw-r--r--    1 root     root      40550400 Oct  6 23:00 3f25505c.tar
 39760 -rw-r--r--    1 root     root      40714240 Oct  7 23:00 5eef0577.tar
     4 drwxr-xr-x    2 root     root          4096 Oct  7 23:01 .
➜  backup sftp -P 222 Backup@192.168.178.160
Connected to 192.168.178.160.
sftp> cd Backup/BackupHA
sftp> put 5eef0577.tar 
Uploading 5eef0577.tar to /Backup/BackupHA/5eef0577.tar
5eef0577.tar                                                                        100%   39MB  50.8MB/s   00:00    
sftp> bye
➜  backup 

i am not sure how to enable debugging. I have set this in configuration.yaml:

logger:
  default: warning
  logs:
    homeassistant.components.remote-backup-addon: debug 

I also tried this:

logger:
  default: debug

But the logging is in both cases exactly the same as posted earlier.

patman15 commented 1 year ago

i am not sure how to enable debugging.

In the GUI of the add-on: screenshot

or when using YAML (still config of the add-on): debug: true

I'll try to replicate with my DSM.

patman15 commented 1 year ago

I can replicate your issue. The add-on does respect the port number but for some reason the transfer does not work as you described. Currently, I have no idea, but it seams like a strange issue with Synology. Please note that the add-on does not use sftp but scp -s or scp -O as fallback. Needs more debugging ...

TheoMol commented 1 year ago

Ah, I do see the option now. Output:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/00-banner.sh
-----------------------------------------------------------
 Add-on: Remote Backup
 Automatically create and transfer HA backups using SFTP (SCP), rsync, or rclone (experimental)
-----------------------------------------------------------
 Add-on version: 2022.9.4
 You are running the latest version of this add-on.
 System: Home Assistant OS 9.0  (amd64 / qemux86-64)
 Home Assistant Core: 2022.9.7
 Home Assistant Supervisor: 2022.09.1
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
cont-init: info: /etc/cont-init.d/00-banner.sh exited 0
cont-init: info: running /etc/cont-init.d/01-log-level.sh
cont-init: info: /etc/cont-init.d/01-log-level.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
[20:23:29] INFO: Adding SSH configuration.
[20:23:29] WARNING: No password set, creating a local backup without password.
[20:23:29] INFO: Creating partial backup: "Automated backup 2022-10-08 20-23"
[20:23:29] DEBUG: Requested API resource: http://supervisor/supervisor/info
[20:23:29] DEBUG: Request method: GET
[20:23:29] DEBUG: Request data: {}
[20:23:29] DEBUG: API HTTP Response code: 200
[20:23:29] DEBUG: API Response: {"result": "ok", "data": {"version": "2022.09.1", "version_latest": "2022.09.1", "update_available": false, "channel": "stable", "arch": "amd64", "supported": true, "healthy": true, "ip_address": "172.30.32.2", "wait_boot": 5, "timezone": "Europe/Amsterdam", "logging": "info", "debug": false, "debug_block": false, "diagnostics": false, "auto_update": true, "addons": [{"name": "Remote Backup", "slug": "3490a758_remote_backup", "version": "2022.9.4", "version_latest": "2022.9.4", "update_available": false, "state": "started", "repository": "3490a758", "icon": true}, {"name": "Samba share", "slug": "core_samba", "version": "10.0.0", "version_latest": "10.0.0", "update_available": false, "state": "started", "repository": "core", "icon": true}, {"name": "SSH & Web Terminal", "slug": "a0d7b954_ssh", "version": "12.0.2", "version_latest": "12.0.2", "update_available": false, "state": "started", "repository": "a0d7b954", "icon": true}, {"name": "File editor", "slug": "core_configurator", "version": "5.4.1", "version_latest": "5.4.1", "update_available": false, "state": "started", "repository": "core", "icon": true}, {"name": "Mosquitto broker", "slug": "core_mosquitto", "version": "6.1.3", "version_latest": "6.1.3", "update_available": false, "state": "started", "repository": "core", "icon": true}, {"name": "Samba Backup", "slug": "15d21743_samba_backup", "version": "5.1.2", "version_latest": "5.1.2", "update_available": false, "state": "stopped", "repository": "15d21743", "icon": true}], "addons_repositories": [{"name": "Local add-ons", "slug": "local"}, {"name": "ESPHome", "slug": "5c53de3b"}, {"name": "Matheson's HA Add-ons", "slug": "3490a758"}, {"name": "Official add-ons", "slug": "core"}, {"name": "Home Assistant Community Add-ons", "slug": "a0d7b954"}, {"name": "Tom's Home Assistant Add-ons", "slug": "15d21743"}]}}
[20:23:30] NOTICE: Excluded addon(s):
core_mariadb
core_ssh
core_mosquitto
[20:23:30] DEBUG: Including folder(s) ["addons/local","homeassistant","media","share","ssl"]
[20:23:30] DEBUG: Including addon(s) ["3490a758_remote_backup","core_samba","a0d7b954_ssh","core_configurator","15d21743_samba_backup"]
[20:24:06] DEBUG: Requested API resource: http://supervisor/backups/new/partial
[20:24:06] DEBUG: Request method: POST
[20:24:06] DEBUG: Request data: {"name":"Automated backup 2022-10-08 20-23", "addons": ["3490a758_remote_backup","core_samba","a0d7b954_ssh","core_configurator","15d21743_samba_backup"], "folders": ["addons/local","homeassistant","media","share","ssl"]}
[20:24:06] DEBUG: API HTTP Response code: 200
[20:24:06] DEBUG: API Response: {"result": "ok", "data": {"slug": "6ba2945f"}}
[20:24:06] DEBUG: Filtering response using: .slug
[20:24:06] INFO: Backup created: 6ba2945f
[20:24:06] INFO: Copying backup using SFTP/SCP.
[20:24:06] WARNING: SFTP transfer failed, falling back to SCP.
[20:24:06] ERROR: Error copying backup 6ba2945f.tar to /Backup/BackupHA on 192.168.178.160.
[20:24:06] DEBUG: Rsync disabled.
[20:24:07] DEBUG: Rclone disabled.
[20:24:07] DEBUG: Requested API resource: http://supervisor/core/api/services/persistent_notification/create
[20:24:07] DEBUG: Request method: POST
[20:24:07] DEBUG: Request data: {"message":"Cloning backup(s) to remote host 192.168.178.160 failed! See log for details.", "title":"Addon: Remote Backup Failed!", "notification_id":"addon-remote-backup"}
[20:24:07] DEBUG: API HTTP Response code: 200
[20:24:07] DEBUG: API Response: [{"entity_id":"persistent_notification.addon_remote_backup","state":"notifying","attributes":{"message":"Cloning backup(s) to remote host 192.168.178.160 failed! See log for details.","title":"Addon: Remote Backup Failed!","friendly_name":"Addon: Remote Backup Failed!"},"last_changed":"2022-10-08T18:24:07.066837+00:00","last_updated":"2022-10-08T18:24:07.066837+00:00","context":{"id":"01GEWDE5CKD623MYWV2YYYQ86J","parent_id":null,"user_id":"6eb6a85de3324c9a815252d3dabae378"}}]
jq: error (at :1): Cannot index array with string "result"
jq: error (at :1): Cannot index array with string "data"
[20:24:07] DEBUG: Requested API resource: http://supervisor/core/api/events/remote_backup_status
[20:24:07] DEBUG: Request method: POST
[20:24:07] DEBUG: Request data: {"result":"error","message:":"Cloning backup(s) to remote host 192.168.178.160 failed! See log for details."}
[20:24:07] DEBUG: API HTTP Response code: 200
[20:24:07] DEBUG: API Response: {"message":"Event remote_backup_status fired."}
[20:24:07] FATAL: Cloning backup(s) to remote host 192.168.178.160 failed! See log for details.
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
patman15 commented 1 year ago

Thanks for the debug information. I found two possible problems that might affect you (not related to the add-on itself):

  1. when changing the port you need to run ssh-keyscan -p <port> -t rsa <remote host> >> /ssl/known_hosts again or completely remove the file /ssl/known_hosts file to allow the plugin to auto generate it temporary. (for security reasons you shouldn't keep the second as a permanent solution and it will generate a warning.
  2. DSM - Control Panel - File Services - FTP - Advanced Settings - Security Settings => check change user root directories and verify the root directory for the user. The path must be relative to that one. Please let me know if either 1 or 2 solves your issue.

By fixing these on/with the DSM I could change the port and it worked.

TheoMol commented 1 year ago

Thanks for your reply and the test work done. Currently I am on vacation (life is tough 😬) and I do not have a laptop with me. When I'm back I will test it on my side and let you know the outcome. Thanks!

patman15 commented 1 year ago

@ikifar2012 I have prepared a few enhancements to get better logging output in such scenarios. In that sense I wanted to ask you whether you want to push people to encrypt backups. If so, I would also suggest to use bashio::config.suggest.password(). Let me know your thoughts, I will provide a PR for you to review as soon as I get feedback from @TheoMol.

ikifar2012 commented 1 year ago

@ikifar2012 I have prepared a few enhancements to get better logging output in such scenarios. In that sense I wanted to ask you whether you want to push people to encrypt backups. If so, I would also suggest to use bashio::config.suggest.password(). Let me know your thoughts, I will provide a PR for you to review as soon as I get feedback from @TheoMol.

I am all for pushing people to encrypt

TheoMol commented 1 year ago

@ikifar2012: back in town. When setting the port to 222 (both DSM and Remote Backup) and running ssh-keyscan -p <port> -t rsa <remote host> >> /ssl/known_hosts again it works flawlessly. No need to change anything at the DSM side (security setting root directory for the user, nothing was set nor has been set). I inspected /ssl/kown_hosts file and it has now 2 entries:

192.168.178.160 ssh-rsa AAAA……
[192.168.178.160]:222 ssh-rsa AAAA…..

I guess the second one does the trick. Thanks!

patman15 commented 1 year ago

@TheoMol Thanks for the feedback, so I guessed the right issue. Will work on the logging to make it more obvious.

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

ikifar2012 commented 1 year ago

This debug change was implemented in 2022.12.0, I will now close this issue, feel free to reopen if you have any concerns