UPDATE 31.10.: Amazon Alexa - ioBroker Skill läuft aus ?

[TepMan]

So, hat mir ja nun keine Ruhe gelassen, gerade mit der 1.5.6 probiert, FTP klappt nach wie vor nicht, gleiches Verhalten wie vorher, im Log steht FTP connected, das Backup wird lokal in /opt/iobroker/backups abgelegt, aber der Adapter macht offenbar keine Anstalten, das Backup per FTP hochzuladen. Der verwendete User hat auch mittlerweile keine Sonderzeichen mehr im Passwort.

Dafür habe ich die Ursache für das Problem vorhin nachvollziehen können. Auf dem NAS sind die Backup-Files weg, lokal auf dem Raspi liegen sie noch. D.h. der Mountpoint wahr tatsächlich nicht ausgehängt und das der Raspi die Dateiberechtigungen vom NAS nicht lesen kann ist nachvollziehbar. Wahrscheinlich war das die ganze Zeit der Grund für die Zugriffsprobleme. Irgendwann ist der Mountpoint nicht oder nicht richtig ausgehängt worden.

[simatec]

@TepMan
Zeige doch mal deine FTP Einstellungen in backitup und die auf deinem NAS.
Hast du mal das ganze per Konsole probiert?
Meist sind es Probleme mit den Rechten oder falsche Pfade

[TepMan]

Hier der erfolgreiche Upload via Konsole per FTP mit dem User, den ich auch im Adapter konfiguriert habe:

230 User ioBroker logged in, access restrictions apply.
Remote system type is UNIX.
Using binary mode to transfer files.
ftp> 
ftp> ls
200 PORT command successful.
150 Opening BINARY mode data connection for 'file list'.
drwxrwxr-x   1 ioBroker users            4096 May  9 15:32 ioBrokerBackups
drwxrwxrwx   1 ioBroker users            4096 May  4 22:45 test
226 Transfer complete.
ftp> cd ioBrokerBackups
250 CWD command successful.
ftp> ls
200 PORT command successful.
150 Opening BINARY mode data connection for 'file list'.
226 Transfer complete.
ftp> cd ..
250 CWD command successful.
ftp> ls
200 PORT command successful.
150 Opening BINARY mode data connection for 'file list'.
drwxrwxr-x   1 ioBroker users            4096 May  9 15:32 ioBrokerBackups
drwxrwxrwx   1 ioBroker users            4096 May  4 22:45 test
226 Transfer complete.
ftp> cd ioBrokerBackups
250 CWD command successful.
ftp> put
(local-file) /opt/iobroker/backups/iobroker_2020_05_09-20_28_09_backupiobroker.tar.gz
(remote-file) iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
local: /opt/iobroker/backups/iobroker_2020_05_09-20_28_09_backupiobroker.tar.gz remote: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
200 PORT command successful.
150 Opening BINARY mode data connection for 'iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz'.
226 Transfer complete.
2022271 bytes sent in 0.06 secs (32.2836 MB/s)
ftp> 

[TepMan]

FTP-Settings auf dem NAS:

[TepMan]

Und die Settings im Adapter:

[simatec]

@TepMan
Hmmm und im debug log kommt nix? Hab es mit der aktuellen Version gerade mal nachgestellt ... wird bei mir problemlos übertragen

[TepMan]

Startup der Instanz (das Backup-File, das er auf dem FTP-Laufwerk findet, ist genau das, das ich vorhin per Konsole hoch geschoben hatte):

backitup.0	2020-05-09 22:30:03.623	debug	(12930) detect last backup file: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
backitup.0	2020-05-09 22:30:03.620	debug	(12930) detect backup file 1: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
backitup.0	2020-05-09 22:30:01.603	debug	(12930) FTP connected.
backitup.0	2020-05-09 22:30:01.084	debug	(12930) [iobroker] 10 00 02 */1 * *
backitup.0	2020-05-09 22:30:01.072	info	(12930) [iobroker] backup was activated at 02:00 every 1 day(s)
backitup.0	2020-05-09 22:30:00.983	info	(12930) starting. Version 1.5.6 in /opt/iobroker/node_modules/iobroker.backitup, node: v12.15.0

Ausgabe im Log beim Erstellen des Backups:

backitup.0	2020-05-09 22:32:11.460	debug	(12930) [iobroker/iobroker] done
backitup.0	2020-05-09 22:32:10.437	debug	(12930) [iobroker/iobroker] Backup created: /opt/iobroker/backups/iobroker_2020_05_09-22_32_06_backupiobroker.tar.gz
backitup.0	2020-05-09 22:32:08.485	debug	(12930) [iobroker/iobroker] host.raspi4 2154 objects saved
backitup.0	2020-05-09 22:32:08.467	debug	(12930) [iobroker/iobroker] host.raspi4 3180 states saved
backitup.0	2020-05-09 22:32:06.414	debug	(12930) Backup has started ...

Ausgabe im Log-Window bei Ausführung des Backups:

Gestartet...
[DEBUG] [iobroker] start with {"type":"creator","time":"02:00","debugging":true,"everyXDays":"1","deleteBackupAfter":0,"ftp":{"enabled":true,"type":"storage","source":"local","host":"192.168.178.20","debugging":true,"deleteOldBackup":true,"ownDir":false,"dir":"/ioBrokerBackups","dirMinimal":"/backupDir/iobroker","user":"ioBroker","pass":"****","port":"21"},"dir":"/opt/iobroker","redis":{"enabled":false,"type":"creator","ftp":{"enabled":true,"type":"storage","source":"local","host":"192.168.178.20","debugging":true,"deleteOldBackup":true,"ownDir":false,"dir":"/ioBrokerBackups","dirMinimal":"/backupDir/iobroker","user":"ioBroker","pass":"****","port":"21"},"cifs":{"enabled":false,"mountType":"NFS","type":"storage","source":"local","mount":"","debugging":true,"fileDir":"/opt/iobroker/node_modules/iobroker.backitup","wakeOnLAN":false,"macAd":"20:DE:20:DE:20:DE","wolTime":"25","smb":"vers=1.0","sudo":false,"cifsDomain":"","deleteOldBackup":false,"ownDir":false,"dir":"sharename/backupDir","dirMinimal":"sharename/backupDir","user":"","pass":"****"},"dropbox":{"enabled":false,"type":"storage","source":"local","debugging":true,"deleteOldBackup":false,"accessToken":"****","ownDir":false,"dir":"/backupDir","dirMinimal":"/backupDir/iobroker"},"googledrive":{"enabled":false,"type":"storage","source":"local","debugging":true,"deleteOldBackup":false,"accessJson":"****","ownDir":false,"dir":"/backupDir","dirMinimal":"/backupDir/iobroker"},"path":"/var/lib/redis"},"historyDB":{"enabled":false,"type":"creator","ftp":{"enabled":true,"type":"storage","source":"local","host":"192.168.178.20","debugging":true,"deleteOldBackup":true,"ownDir":false,"dir":"/ioBrokerBackups","dirMinimal":"/backupDir/iobroker","user":"ioBroker","pass":"****","port":"21"},"cifs":{"enabled":false,"mountType":"NFS","type":"storage","source":"local","mount":"","debugging":true,"fileDir":"/opt/iobroker/node_modules/iobroker.backitup","wakeOnLAN":false,"macAd":"20:DE:20:DE:20:DE","wolTime":"25","smb":"vers=1.0","sudo":false,"cifsDomain":"","deleteOldBackup":false,"ownDir":false,"dir":"sharename/backupDir","dirMinimal":"sharename/backupDir","user":"","pass":"****"},"dropbox":{"enabled":false,"type":"storage","source":"local","debugging":true,"deleteOldBackup":false,"accessToken":"****","ownDir":false,"dir":"/backupDir","dirMinimal":"/backupDir/iobroker"},"googledrive":{"enabled":false,"type":"storage","source":"local","debugging":true,"deleteOldBackup":false,"accessJson":"****","ownDir":false,"dir":"/backupDir","dirMinimal":"/backupDir/iobroker"},"path":"media/usb/history"},"zigbee":{"enabled":true,"type":"creator","ftp":{"enabled":true,"type":"storage","source":"local","host":"192.168.178.20","debugging":true,"deleteOldBackup":true,"ownDir":false,"dir":"/ioBrokerBackups","dirMinimal":"/backupDir/iobroker","user":"ioBroker","pass":"****","port":"21"},"cifs":{"enabled":false,"mountType":"NFS","type":"storage","source":"local","mount":"","debugging":true,"fileDir":"/opt/iobroker/node_modules/iobroker.backitup","wakeOnLAN":false,"macAd":"20:DE:20:DE:20:DE","wolTime":"25","smb":"vers=1.0","sudo":false,"cifsDomain":"","deleteOldBackup":false,"ownDir":false,"dir":"sharename/backupDir","dirMinimal":"sharename/backupDir","user":"","pass":"****"},"dropbox":{"enabled":false,"type":"storage","source":"local","debugging":true,"deleteOldBackup":false,"accessToken":"****","ownDir":false,"dir":"/backupDir","dirMinimal":"/backupDir/iobroker"},"googledrive":{"enabled":false,"type":"storage","source":"local","debugging":true,"deleteOldBackup":false,"accessJson":"****","ownDir":false,"dir":"/backupDir","dirMinimal":"/backupDir/iobroker"},"path":"/opt/iobroker/iobroker-data"},"history":{"enabled":true,"type":"message","entriesNumber":"25","systemLang":"de"},"email":{"enabled":false,"notificationsType":"Telegram","type":"message","instance":"","NoticeType":"longEmailNotice","emailReceiver":"xxx@xxx.com","emailSender":"xxx@xxx.com","onlyError":false,"emailWaiting":0,"systemLang":"de"},"pushover":{"enabled":false,"notificationsType":"Telegram","type":"message","instance":"","SilentNotice":false,"NoticeType":"longPushoverNotice","deviceID":"","onlyError":false,"pushoverWaiting":0,"systemLang":"de"},"backupDir":"/opt/iobroker/backups"}
[DEBUG] [iobroker] - host.raspi4 3180 states saved

[DEBUG] [iobroker] - host.raspi4 2154 objects saved

[DEBUG] [iobroker] - Backup created: /opt/iobroker/backups/iobroker_2020_05_09-22_32_06_backupiobroker.tar.gz

[DEBUG] [iobroker] - done

[TepMan]

Theoretisch müsste es doch irgendeine Ausgabe geben, der man entnehmen könnte, ob er versucht, den Upload auszuführen, oder?

[simatec]

@TepMan
Der Backup Prozess bleibt hängen und wird nicht beendet.
Was steht im DP line.output

[TepMan]

[DEBUG] [iobroker] - done

[simatec]

@TepMan
OK ... wenn Backitup durchlaufen würde, müsste exit 0 stehen.
Wie sieht der Log aus, wenn du per nfs auf dein NAS ablegst?
FTP wird garnicht mehr ausgeführt bei dir.

[TepMan]

Bei NFS kann ich keinen User mehr konfigurieren:

Habe es dann per CIFS versucht, da kann er conntecten:

backitup.0	2020-05-09 22:57:55.989	debug	(13740) [iobroker/iobroker] done
backitup.0	2020-05-09 22:57:55.780	debug	(13740) [iobroker/iobroker] host.raspi4 Cannot pack directory /opt/iobroker/node_modules/iobroker.js-controller/tmp/backup: Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
backitup.0	2020-05-09 22:57:54.981	debug	(13740) [iobroker/iobroker] host.raspi4 Cannot pack directory /opt/iobroker/node_modules/iobroker.js-controller/tmp/backup: Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
backitup.0	2020-05-09 22:57:54.966	debug	(13740) [iobroker/iobroker] host.raspi4 Cannot pack directory /opt/iobroker/node_modules/iobroker.js-controller/tmp/backup: Error: EACCES: permission denied, open '/opt/iobroker/backups/iobroker_2020_
backitup.0	2020-05-09 22:57:53.853	debug	(13740) [iobroker/iobroker] host.raspi4 2154 objects saved
backitup.0	2020-05-09 22:57:53.833	debug	(13740) [iobroker/iobroker] host.raspi4 3180 states saved
backitup.0	2020-05-09 22:57:51.691	debug	(13740) [iobroker/mount] done
backitup.0	2020-05-09 22:57:41.292	debug	(13740) Backup has started ...
backitup.0	2020-05-09 22:57:14.962	debug	(13740) mount activ... umount in 2 Seconds!!
backitup.0	2020-05-09 22:57:07.659	debug	(13740) detect last backup file: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
backitup.0	2020-05-09 22:57:07.656	debug	(13740) detect backup file 1: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
backitup.0	2020-05-09 22:57:04.962	debug	(13740) [iobroker] 10 00 02 */1 * *
backitup.0	2020-05-09 22:57:04.951	info	(13740) [iobroker] backup was activated at 02:00 every 1 day(s)
backitup.0	2020-05-09 22:57:04.897	info	(13740) starting. Version 1.5.6 in /opt/iobroker/node_modules/iobroker.backitup, node: v12.15.0

Aber wie du siehst, schlägt er dann wieder mit dem Permission-Fehler auf...

[simatec]

@TepMan
Oha ... du hast da einige Bugs in deinem System, die du dringend beheben solltest.
Ich empfehle dir eine Neuinstallation.
Irgendwo ist bei dir was grundlegendes schief gelaufen. Denke bei einem node Update oder js-controller Update.
Die Probleme werden sich durchziehen und nicht nur Backitup betreffen.

[TepMan]

Was für Bugs sind denn das? Die ganze Installation läuft seit einem viertel Jahr ohne Probleme...

[simatec]

@TepMan sagte in Adapter Backitup kopiert nicht auf FTP:

Aber wie du siehst, schlägt er dann wieder mit dem Permission-Fehler auf...

Das zeigt auch, dass du auf dem NAS keine Schreibrechte hast

[simatec]

@TepMan sagte in Adapter Backitup kopiert nicht auf FTP:

Was für Bugs sind denn das? Die ganze Installation läuft seit einem viertel Jahr ohne Probleme...

Was nicht richtig kompiliert oder defekt.
Du kannst es mit einem rebuild versuchen, aber wenn du iobroker neu aufsetzt, bis du meist schneller und alles läuft danach sauber

[TepMan]

Bei CIFS fehlte tatsächlich eine Berechtigung, jetzt hat das Erstellen und Hochladen geklappt. Die Schlusmeldung ist allerdings weiterhin "[DEBUG] [iobroker] - done". Würde aber erklären, warum er die Mountpoints nicht aushängt.

Aber das Argument "das System ist schräg" kann ich so nicht gelten lassen. Es läuft, wie gesagt, seit einem viertel Jahr ohne Probleme. Alle anderen Adapter funktionieren auch ohne Probleme. Auch keine komischen Fehlermeldungen in den Logs oder so. Habe jetzt ehrlich gesagt keine Lust, das ganze System neu aufzusetzen und zu konfigurieren, zumal es eben stabil läuft.

[TepMan]

Letzter Post für heute - versprochen. Offenbar unmounted der Adapter nicht mehr. Ich hatte ja per CIFS ein Backup erfolgreich auf das NAS bekommen. Dann habe ich auf NFS umgeschaltet, man sieht im Log, er sagt, er könne nicht mounten, weil er keine Credentials bekommt. Das Backup wird aber trotzdem erstellt und landet auf dem NAS, also ist der Mountpoint noch drin:

backitup.0	2020-05-09 23:32:02.878	debug	(15061) [iobroker/iobroker] done
backitup.0	2020-05-09 23:32:01.831	debug	(15061) [iobroker/iobroker] Backup created: /opt/iobroker/backups/iobroker_2020_05_09-23_31_57_backupiobroker.tar.gz
backitup.0	2020-05-09 23:31:59.908	debug	(15061) [iobroker/iobroker] host.raspi4 2154 objects saved
backitup.0	2020-05-09 23:31:59.888	debug	(15061) [iobroker/iobroker] host.raspi4 3180 states saved
backitup.0	2020-05-09 23:31:57.803	debug	(15061) [iobroker/mount] mount.nfs: access denied by server while mounting 192.168.178.20:/ioBroker/ioBrokerBackups
backitup.0	2020-05-09 23:31:57.802	debug	(15061) [iobroker/mount] [IGNORED] Error: Command failed: sudo mount 192.168.178.20:/ioBroker/ioBrokerBackups /opt/iobroker/backups
backitup.0	2020-05-09 23:31:57.801	debug	(15061) [iobroker/mount] [undefined mount.nfs: access denied by server while mounting 192.168.178.20:/ioBroker/ioBrokerBackups
backitup.0	2020-05-09 23:31:47.283	debug	(15061) Backup has started ...
backitup.0	2020-05-09 23:30:25.756	debug	(15061) detect last backup file: iobroker_2020_05_09-23_27_29_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.753	debug	(15061) detect backup file 4: iobroker_2020_05_09-23_27_29_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.752	debug	(15061) detect backup file 3: iobroker_2020_05_09-23_24_25_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.751	debug	(15061) detect backup file 2: iobroker_2020_05_09-23_12_17_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.750	debug	(15061) detect backup file 1: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:23.744	error	(15061) Error: Command failed: sudo mount 192.168.178.20:/ioBroker/ioBrokerBackups /opt/iobroker/backups mount.nfs: access denied by server while mounting 192.168.178.20:/ioBroker/ioBrokerBackups
backitup.0	2020-05-09 23:30:23.271	debug	(15061) [iobroker] 10 00 02 */1 * *

Per FTP geht es gerade auch, eben weil der Mountpoint noch drin hängt.

Ich hoffe du fast die Kritik so konstruktiv auf, wie sie gemeint ist. Das einhängen der Mountpoints auf /opt/iobroker/backups ist zwar eine elegante Lösung, aber extrem verwirrend, wenn man nicht weiß, wie der Adapter arbeitet. Ausserdem birgt es - wie bei mir geschehen - das Risiko, das, wenn Mountpoints nicht ausgehängt werden können es, es zu einem echt seltsamen Systemverhalten führt. Dieses kann man sich dann schwer erklären, wenn man nicht weiß, was da passiert ist.

Wäre es nicht eine Option, die Mountpoints woanders, z.B. unter mnt zu hängen und die Files dann einfach darüber zu kopieren?

[simatec]

@TepMan
Hast du für den cifs mount ftp deaktiviert?

[simatec]

@TepMan sagte in Adapter Backitup kopiert nicht auf FTP:

Letzter Post für heute - versprochen. Offenbar unmounted der Adapter nicht mehr. Ich hatte ja per CIFS ein Backup erfolgreich auf das NAS bekommen. Dann habe ich auf NFS umgeschaltet, man sieht im Log, er sagt, er könne nicht mounten, weil er keine Credentials bekommt. Das Backup wird aber trotzdem erstellt und landet auf dem NAS, also ist der Mountpoint noch drin:

backitup.0	2020-05-09 23:32:02.878	debug	(15061) [iobroker/iobroker] done
backitup.0	2020-05-09 23:32:01.831	debug	(15061) [iobroker/iobroker] Backup created: /opt/iobroker/backups/iobroker_2020_05_09-23_31_57_backupiobroker.tar.gz
backitup.0	2020-05-09 23:31:59.908	debug	(15061) [iobroker/iobroker] host.raspi4 2154 objects saved
backitup.0	2020-05-09 23:31:59.888	debug	(15061) [iobroker/iobroker] host.raspi4 3180 states saved
backitup.0	2020-05-09 23:31:57.803	debug	(15061) [iobroker/mount] mount.nfs: access denied by server while mounting 192.168.178.20:/ioBroker/ioBrokerBackups
backitup.0	2020-05-09 23:31:57.802	debug	(15061) [iobroker/mount] [IGNORED] Error: Command failed: sudo mount 192.168.178.20:/ioBroker/ioBrokerBackups /opt/iobroker/backups
backitup.0	2020-05-09 23:31:57.801	debug	(15061) [iobroker/mount] [undefined mount.nfs: access denied by server while mounting 192.168.178.20:/ioBroker/ioBrokerBackups
backitup.0	2020-05-09 23:31:47.283	debug	(15061) Backup has started ...
backitup.0	2020-05-09 23:30:25.756	debug	(15061) detect last backup file: iobroker_2020_05_09-23_27_29_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.753	debug	(15061) detect backup file 4: iobroker_2020_05_09-23_27_29_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.752	debug	(15061) detect backup file 3: iobroker_2020_05_09-23_24_25_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.751	debug	(15061) detect backup file 2: iobroker_2020_05_09-23_12_17_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:25.750	debug	(15061) detect backup file 1: iobroker_2020_05_09-20_25_50_backupiobroker.tar.gz
backitup.0	2020-05-09 23:30:23.744	error	(15061) Error: Command failed: sudo mount 192.168.178.20:/ioBroker/ioBrokerBackups /opt/iobroker/backups mount.nfs: access denied by server while mounting 192.168.178.20:/ioBroker/ioBrokerBackups
backitup.0	2020-05-09 23:30:23.271	debug	(15061) [iobroker] 10 00 02 */1 * *

Per FTP geht es gerade auch, eben weil der Mountpoint noch drin hängt.

Ich hoffe du fast die Kritik so konstruktiv auf, wie sie gemeint ist. Das einhängen der Mountpoints auf /opt/iobroker/backups ist zwar eine elegante Lösung, aber extrem verwirrend, wenn man nicht weiß, wie der Adapter arbeitet. Ausserdem birgt es - wie bei mir geschehen - das Risiko, das, wenn Mountpoints nicht ausgehängt werden können es, es zu einem echt seltsamen Systemverhalten führt. Dieses kann man sich dann schwer erklären, wenn man nicht weiß, was da passiert ist.

Wäre es nicht eine Option, die Mountpoints woanders, z.B. unter mnt zu hängen und die Files dann einfach darüber zu kopieren?

Aus dem Grund überprüft backitup beim start des Adapters und auch vor jedem Backup, ob der mount noch vorhanden ist und führt einen umount aus.

Den mount punkt woanders zu setzen ist nicht Ziel, da bei Systemen mit sd garnicht erst auf diese geschrieben werden soll