SOLVED [erledigt] BackitUP keine Emailbenachrichtigung bei Komplettbackup

[simatec]

Kannst du mal testen, ob die Benachrichtigung ohne einen Stop bei einem Total kommt?
So wie es aussieht startet dein Mail Adapter zu spät.

[sol21]

@simatec
Super! Hat geklappt. -> Email kam sofort an.

Spoiler

2019-03-05 15:43:09.736  - debug: backitup.0 statesDB connected
2019-03-05 15:43:09.905  - info: backitup.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.11.1
2019-03-05 15:43:09.975  - info: backitup.0 [minimal] backup was activated at 04:00 every 1 day(s)
2019-03-05 15:43:10.012  - debug: backitup.0 [minimal] 10 00 04 */1 * * 
2019-03-05 15:43:10.013  - info: backitup.0 [total] backup was activated at 15:45:00 every 1 day(s)
2019-03-05 15:43:10.019  - debug: backitup.0 [total] 10 45 15 */1 * * 
2019-03-05 15:43:14.240  - debug: backitup.0 system.adapter.admin.0: logging true
2019-03-05 15:45:00.046  - info: host.raspberrypi instance system.adapter.daswetter.0 started with pid 9680
2019-03-05 15:45:04.044  - info: daswetter.0 starting. Version 2.7.3 in /opt/iobroker/node_modules/iobroker.daswetter, node: v8.11.1
2019-03-05 15:45:10.052  - debug: backitup.0 [total] exec: done
2019-03-05 15:45:10.247  - info: admin.0 terminating http server on port 8081
2019-03-05 15:45:10.248  - info: web.0 terminating http server on port 8082
2019-03-05 15:45:10.249  - info: web.0 terminated http server on port 8082
2019-03-05 15:45:10.257  - info: tr-064.0 terminating
2019-03-05 15:45:10.259  - info: modbus.0 terminating
2019-03-05 15:45:10.264  - info: javascript.0 terminating
2019-03-05 15:45:10.272  - info: host.raspberrypi received SIGTERM
2019-03-05 15:45:10.272  - info: admin.0 terminating
2019-03-05 15:45:10.282  - info: web.0 terminating
2019-03-05 15:45:10.300  - info: host.raspberrypi instance system.adapter.tr-064.0 terminated with code 0 (OK)
2019-03-05 15:45:10.323  - info: host.raspberrypi instance system.adapter.admin.0 terminated with code 0 (OK)
2019-03-05 15:45:10.324  - debug: backitup.0 system.adapter.admin.0: logging false
2019-03-05 15:45:10.328  - info: host.raspberrypi instance system.adapter.web.0 terminated with code 0 (OK)
2019-03-05 15:45:10.334  - info: host.raspberrypi instance system.adapter.javascript.0 terminated with code 0 (OK)
2019-03-05 15:45:10.338  - info: host.raspberrypi instance system.adapter.modbus.0 terminated with code 0 (OK)
2019-03-05 15:45:10.748  - info: email.0 terminating
2019-03-05 15:45:10.755  - info: backitup.0 terminating
2019-03-05 15:45:10.766  - info: daswetter.0 terminating
2019-03-05 15:45:10.780  - info: host.raspberrypi instance system.adapter.backitup.0 terminated with code 0 (OK)
2019-03-05 15:45:10.810  - info: host.raspberrypi instance system.adapter.email.0 terminated with code 0 (OK)
2019-03-05 15:45:10.810  - info: host.raspberrypi instance system.adapter.daswetter.0 terminated with code 0 (OK)
2019-03-05 15:45:20.281  - info: host.raspberrypi force terminating
2019-03-05 15:47:17.982  - info: host.raspberrypi iobroker.js-controller version 1.4.2 js-controller starting
2019-03-05 15:47:17.991  - info: host.raspberrypi Copyright (c) 2014-2018 bluefox, 2014 hobbyquaker
2019-03-05 15:47:17.992  - info: host.raspberrypi hostname: raspberrypi, node: v8.11.1
2019-03-05 15:47:17.997  - info: host.raspberrypi ip addresses: 192.168.188.28 fe80::90f8:966e:754:6247
2019-03-05 15:47:18.169  - info: host.raspberrypi  inMem-states listening on port 9000
2019-03-05 15:47:18.709  - info: host.raspberrypi  inMem-objects listening on port 9001
2019-03-05 15:47:18.740  - info: host.raspberrypi InMemoryDB connected
2019-03-05 15:47:18.773  - info: host.raspberrypi 11 instances found
2019-03-05 15:47:18.815  - info: host.raspberrypi starting 11 instances
2019-03-05 15:47:18.880  - info: host.raspberrypi instance system.adapter.admin.0 started with pid 9761
2019-03-05 15:47:22.837  - info: host.raspberrypi instance system.adapter.web.0 started with pid 9767
2019-03-05 15:47:23.536  - error: admin.0 setObject id missing!!
2019-03-05 15:47:23.558  - info: admin.0 starting. Version 3.6.0 in /opt/iobroker/node_modules/iobroker.admin, node: v8.11.1
2019-03-05 15:47:23.619  - info: admin.0 requesting all states
2019-03-05 15:47:23.623  - info: admin.0 requesting all objects
2019-03-05 15:47:23.626  - info: admin.0 Request actual repository...
2019-03-05 15:47:25.711  - info: admin.0 received all states
2019-03-05 15:47:27.022  - error: web.0 setObject id missing!!
2019-03-05 15:47:27.045  - info: web.0 starting. Version 2.4.1 in /opt/iobroker/node_modules/iobroker.web, node: v8.11.1
2019-03-05 15:47:27.682  - info: web.0 socket.io server listening on port 8082
2019-03-05 15:47:27.688  - info: web.0 http server listening on port 8082
2019-03-05 15:47:28.060  - info: admin.0 received all objects
2019-03-05 15:47:28.208  - info: admin.0 http server listening on port 8081
2019-03-05 15:47:28.208  - info: admin.0 Use link "http://localhost:8081" to configure.
2019-03-05 15:47:28.332  - info: host.raspberrypi Update repository "latest" under "http://download.iobroker.net/sources-dist-latest.json"
2019-03-05 15:47:30.838  - info: host.raspberrypi instance system.adapter.javascript.0 started with pid 9789
2019-03-05 15:47:31.225  - info: admin.0 Repository received successfully.
2019-03-05 15:47:31.115  - info: vis.0 starting. Version 1.1.10 in /opt/iobroker/node_modules/iobroker.vis, node: v8.11.1
2019-03-05 15:47:31.378  - info: vis.0 vis license is OK.
2019-03-05 15:47:32.301  - info: host.raspberrypi instance system.adapter.vis.0 terminated while should be started once
2019-03-05 15:47:36.480  - info: javascript.0 starting. Version 3.6.4 in /opt/iobroker/node_modules/iobroker.javascript, node: v8.11.1
2019-03-05 15:47:36.498  - info: javascript.0 requesting all states
2019-03-05 15:47:36.501  - info: javascript.0 requesting all objects
2019-03-05 15:47:37.650  - info: javascript.0 received all states
2019-03-05 15:47:38.847  - info: host.raspberrypi instance system.adapter.modbus.0 started with pid 9803
2019-03-05 15:47:39.841  - info: javascript.0 received all objects
2019-03-05 15:47:39.961  - info: javascript.0 Start javascript script.js.Skalierung_PV_Leistung
2019-03-05 15:47:40.061  - info: javascript.0 script.js.Skalierung_PV_Leistung: registered 0 subscriptions and 0 schedules
2019-03-05 15:47:40.063  - info: javascript.0 Start javascript script.js.Skalierung_Meter_Leistung
2019-03-05 15:47:40.137  - info: javascript.0 script.js.Skalierung_Meter_Leistung: registered 0 subscriptions and 0 schedules
2019-03-05 15:47:40.138  - info: javascript.0 Start javascript script.js.Sonneuntergang
2019-03-05 15:47:40.234  - info: javascript.0 script.js.Sonneuntergang: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:40.235  - info: javascript.0 Start javascript script.js.PV_Leistung_Durchschnitt
2019-03-05 15:47:40.317  - info: javascript.0 script.js.PV_Leistung_Durchschnitt: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:40.318  - info: javascript.0 Start javascript script.js.eth002_R1
2019-03-05 15:47:40.404  - info: javascript.0 script.js.eth002_R1: registered 1 subscription and 0 schedules
2019-03-05 15:47:40.405  - info: javascript.0 Start javascript script.js.Steure_R1
2019-03-05 15:47:40.486  - info: javascript.0 script.js.Steure_R1: registered 1 subscription and 0 schedules
2019-03-05 15:47:40.487  - info: javascript.0 Start javascript script.js.Steure_R2
2019-03-05 15:47:40.568  - info: javascript.0 script.js.Steure_R2: registered 2 subscriptions and 0 schedules
2019-03-05 15:47:40.569  - info: javascript.0 Start javascript script.js.in_zeit_auto_R2
2019-03-05 15:47:40.655  - info: javascript.0 script.js.in_zeit_auto_R2: registered 1 subscription and 1 schedule
2019-03-05 15:47:40.656  - info: javascript.0 Start javascript script.js.eth002_R2
2019-03-05 15:47:40.742  - info: javascript.0 script.js.eth002_R2: registered 1 subscription and 0 schedules
2019-03-05 15:47:40.743  - info: javascript.0 Start javascript script.js.WLAN
2019-03-05 15:47:40.829  - info: javascript.0 script.js.WLAN: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:40.830  - info: javascript.0 Start javascript script.js.Zeit_WP_Sperre_Ein_dynamisch
2019-03-05 15:47:40.917  - info: javascript.0 script.js.Zeit_WP_Sperre_Ein_dynamisch: registered 0 subscriptions and 2 schedules
2019-03-05 15:47:40.918  - info: javascript.0 Start javascript script.js.in_zeit_sperre_R1_mitWetter
2019-03-05 15:47:41.006  - info: javascript.0 script.js.in_zeit_sperre_R1_mitWetter: registered 1 subscription and 1 schedule
2019-03-05 15:47:41.006  - info: javascript.0 Start javascript script.js.Test_Ausgaben
2019-03-05 15:47:41.095  - info: javascript.0 script.js.Test_Ausgaben: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:42.203  - info: modbus.0 starting. Version 2.0.9 in /opt/iobroker/node_modules/iobroker.modbus, node: v8.11.1
2019-03-05 15:47:42.256  - warn: modbus.0 Serial is not available
2019-03-05 15:47:42.635  - info: modbus.0 Connected to slave 192.168.188.36
2019-03-05 15:47:42.836  - info: host.raspberrypi instance system.adapter.tr-064.0 started with pid 9813
2019-03-05 15:47:46.789  - info: tr-064.0 starting. Version 0.4.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v8.11.1
2019-03-05 15:47:49.302  - error: tr-064.0 forEachConfiguredDevice: in GetSpecificHostEntry 0(fritz.box/5C:49:79:3E:4C:24):Error: sendSOAPActionRequest Error action=GetSpecificHostEntry serviceType=urn:dslforum-org:service:Hosts:1: 500 - {"code":500}
2019-03-05 15:47:50.853  - info: host.raspberrypi instance system.adapter.backitup.0 started with pid 9823
2019-03-05 15:47:54.128  - debug: backitup.0 objectDB connected
2019-03-05 15:47:54.203  - debug: backitup.0 statesDB connected
2019-03-05 15:47:54.379  - info: backitup.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.11.1
2019-03-05 15:47:54.858  - info: host.raspberrypi instance scheduled system.adapter.daswetter.0 */15 * * * *
2019-03-05 15:47:54.391  - debug: backitup.0 Printing logs of previous backup
2019-03-05 15:47:54.395  - debug: backitup.0 [DEBUG] [total/mount] done
2019-03-05 15:47:54.397  - debug: backitup.0 [DEBUG] [total/total] TAR started...
2019-03-05 15:47:54.397  - debug: backitup.0 [DEBUG] [total/total] Ignore dir: /opt/iobroker/backups
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/total] done
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/cifs] done
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/clean] delete /opt/iobroker/backups/total_2019_01_11-04_15_33_backupiobroker.tar.gz
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/clean] done
2019-03-05 15:47:54.399  - debug: backitup.0 [DEBUG] [total/start] done
2019-03-05 15:47:54.399  - debug: backitup.0 [DEBUG] [total/start] IoBroker started ...
2019-03-05 15:47:54.399  - debug: backitup.0 [DEBUG] [total/email] done
2019-03-05 15:47:55.335  - info: backitup.0 [minimal] backup was activated at 04:00 every 1 day(s)
2019-03-05 15:47:55.372  - debug: backitup.0 [minimal] 10 00 04 */1 * * 
2019-03-05 15:47:55.373  - info: backitup.0 [total] backup was activated at 15:45:00 every 1 day(s)
2019-03-05 15:47:55.389  - debug: backitup.0 [total] 10 45 15 */1 * * 
2019-03-05 15:47:55.487  - debug: backitup.0 mount activ... umount in 2 Seconds!!
2019-03-05 15:47:58.860  - info: host.raspberrypi instance system.adapter.email.0 started with pid 9846
2019-03-05 15:48:02.166  - info: email.0 starting. Version 1.0.4 in /opt/iobroker/node_modules/iobroker.email, node: v8.11.1
2019-03-05 15:48:05.274  - debug: backitup.0 [total/email] [total] used E-Mail-Instance: email.0
2019-03-05 15:48:05.281  - debug: backitup.0 sendTo "send" to system.adapter.email.0 from system.adapter.backitup.0
2019-03-05 15:48:05.282  - debug: backitup.0 [total/email] done
2019-03-05 15:48:05.316  - debug: backitup.0 [total/history] backitup.0.history.html
2019-03-05 15:48:05.521  - info: email.0 Send email: {"text":"BackItUp:\nEin neues total Backup wurde am 05. Maerz 2019 um 15:47 Uhr erstellt, und unter 192.168.188.40/Backup/iobroker/komplett/ gespeichert.","to":"xx.yy@gmx.ch","subject":"Backitup","from":"jj@gmail.com"}
2019-03-05 15:48:07.494  - info: email.0 sent to xx.yy@gmx.ch

Nochmals herzlichen Dank für die tolle Unterstützung!

[sol21]

Habe nun ein Backup auf 16:05 Uhr geplant (ohne Stop). Das Email wurde wunderbar verschickt.

Spoiler

2019-03-04 16:01:28.538  - debug: backitup.0 system.adapter.admin.0: logging true
2019-03-04 16:05:21.531  - debug: backitup.0 [total/mount] done
2019-03-04 16:05:21.547  - debug: backitup.0 [total/total] TAR started...
2019-03-04 16:05:21.549  - debug: backitup.0 [total/total] Ignore dir: /opt/iobroker/backups
2019-03-04 16:05:31.548  - debug: backitup.0 [total/total] Packed 17MB so far...
2019-03-04 16:05:41.550  - debug: backitup.0 [total/total] Packed 21MB so far...
2019-03-04 16:05:51.552  - debug: backitup.0 [total/total] Packed 29MB so far...
2019-03-04 16:06:01.556  - debug: backitup.0 [total/total] Packed 37MB so far...
2019-03-04 16:06:11.577  - debug: backitup.0 [total/total] Packed 47MB so far...
2019-03-04 16:06:21.686  - debug: backitup.0 [total/total] Packed 51MB so far...
2019-03-04 16:06:31.688  - debug: backitup.0 [total/total] Packed 57MB so far...
2019-03-04 16:06:41.693  - debug: backitup.0 [total/total] Packed 63MB so far...
2019-03-04 16:06:51.787  - debug: backitup.0 [total/total] Packed 68MB so far...
2019-03-04 16:07:01.789  - debug: backitup.0 [total/total] Packed 74MB so far...
2019-03-04 16:07:11.791  - debug: backitup.0 [total/total] Packed 78MB so far...
2019-03-04 16:07:19.873  - debug: backitup.0 [total/total] done
2019-03-04 16:07:19.884  - debug: backitup.0 [total/cifs] done
2019-03-04 16:07:19.913  - debug: backitup.0 [total/clean] delete /opt/iobroker/backups/total_2018_12_11-04_15_33_backupiobroker.tar.gz
2019-03-04 16:07:19.944  - debug: backitup.0 [total/clean] done
2019-03-04 16:07:19.954  - debug: backitup.0 [total/email] [total] used E-Mail-Instance: email.0
2019-03-04 16:07:19.958  - debug: backitup.0 sendTo "send" to system.adapter.email.0 from system.adapter.backitup.0
2019-03-04 16:07:19.959  - debug: backitup.0 [total/email] done
2019-03-04 16:07:20.002  - debug: backitup.0 [total/history] backitup.0.history.html
2019-03-04 16:07:20.047  - debug: backitup.0 [total/umount] mount activ... umount in 60 Seconds!!
2019-03-04 16:07:20.170  - info: email.0 Send email: {"text":"BackItUp:\nEin neues total Backup wurde am 04. Maerz 2019 um 16:07 Uhr erstellt, und unter //192.168.188.40/Backup/iobroker/komplett/ gespeichert.","to":"xx.yy@gmx.ch","subject":"Backitup","from":"qq@gmail.com"}
2019-03-04 16:07:21.931  - info: email.0 sent to xx.yy@gmx.ch
2019-03-04 16:08:20.276  - debug: backitup.0 [total/umount] done
2019-03-04 16:08:20.281  - debug: backitup.0 [total] exec: done

[simatec]

@sol21

Dann baue ich da mal eine Verzögerung ein, wenn iobroker gestoppt wird.

[sol21]

@simatec
Danke, kann ich dann wieder testen. Denke betrifft nicht nur mich...?

[simatec]

@sol21

Hmmm das kann ich schwer beurteilen.
Ich habe auf allen Testsystemen diese Probleme nicht nachvollziehen können.
Was nutzt du für ein System? Eventuell ist die Hardware etwas zu schwach.
Normal wird die Mail erst nach iobroker Start versendet.
Aber deine Adapter brauchen anscheinend sehr lange zum starten.
Könnte an der Hardware liegen

[sol21]

@simatec
Habe einen RaspberryPi 3B. Läuft aber sehr wenig darauf.

Solange sich nicht mehr Leute mit dem gleichen Problem melden, kannst Du es so belassen. Ich weiss ja, dass das Backup erstellt wird und kann auf die Benachrichtigung verzichten. Ich werde es aber mal noch länger im Auge behalten.

Nochmals vielen herzlichen Dank!

[simatec]

@sol21

Nutzt du redis? Wenn ja musst du nicht stoppen.
Auch ohne Redis musst du nicht stoppen.
Der stop ist nur dafür da, falls es Probleme beim erstellen des totals gibt.
Ich werde das aber fixen, damit die Meldung etwas zeitverzögert rausgeht

[simatec]

Installiere mal die Version 1.1.3 vom Github und berichte mal bitte, ob deine Benachrichtigung per Mail jetzt kommt.

[sol21]

@simatec
habe nun mit der Version 1.1.3 getestet. Leider kam auch keine Email-Benachrichtigung.
Hatte das Komplett-Backup auf 14:00:00 eingeplant.

Spoiler

2019-03-05 13:57:12.261  - info: backitup.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.11.1
2019-03-05 13:57:12.337  - info: backitup.0 [minimal] backup was activated at 04:00 every 1 day(s)
2019-03-05 13:57:12.373  - debug: backitup.0 [minimal] 10 00 04 */1 * * 
2019-03-05 13:57:12.373  - info: backitup.0 [total] backup was activated at 14:00:00 every 1 day(s)
2019-03-05 13:57:12.379  - debug: backitup.0 [total] 10 00 14 */1 * * 
2019-03-05 13:57:12.923  - debug: backitup.0 system.adapter.admin.0: logging true
2019-03-05 13:58:08.082  - debug: backitup.0 system.adapter.admin.0: logging false
2019-03-05 13:58:16.367  - debug: backitup.0 system.adapter.admin.0: logging true
2019-03-05 14:00:00.057  - info: host.raspberrypi instance system.adapter.daswetter.0 started with pid 8859
2019-03-05 14:00:04.429  - info: daswetter.0 starting. Version 2.7.3 in /opt/iobroker/node_modules/iobroker.daswetter, node: v8.11.1
2019-03-05 14:00:10.080  - debug: backitup.0 [total] exec: done
2019-03-05 14:00:10.358  - info: host.raspberrypi received SIGTERM
2019-03-05 14:00:10.359  - info: web.0 terminating http server on port 8082
2019-03-05 14:00:10.367  - info: admin.0 terminating http server on port 8081
2019-03-05 14:00:10.372  - info: javascript.0 terminating
2019-03-05 14:00:10.380  - info: web.0 terminated http server on port 8082
2019-03-05 14:00:10.386  - info: admin.0 terminating
2019-03-05 14:00:10.386  - info: tr-064.0 terminating
2019-03-05 14:00:10.393  - info: modbus.0 terminating
2019-03-05 14:00:10.434  - info: host.raspberrypi instance system.adapter.admin.0 terminated with code 0 (OK)
2019-03-05 14:00:10.435  - debug: backitup.0 system.adapter.admin.0: logging false
2019-03-05 14:00:10.439  - info: host.raspberrypi instance system.adapter.web.0 terminated with code 0 (OK)
2019-03-05 14:00:10.443  - info: host.raspberrypi instance system.adapter.javascript.0 terminated with code 0 (OK)
2019-03-05 14:00:10.447  - info: host.raspberrypi instance system.adapter.modbus.0 terminated with code 0 (OK)
2019-03-05 14:00:10.451  - info: host.raspberrypi instance system.adapter.tr-064.0 terminated with code 0 (OK)
2019-03-05 14:00:10.875  - info: backitup.0 terminating
2019-03-05 14:00:10.874  - info: daswetter.0 terminating
2019-03-05 14:00:10.882  - info: email.0 terminating
2019-03-05 14:00:10.898  - info: host.raspberrypi instance system.adapter.email.0 terminated with code 0 (OK)
2019-03-05 14:00:10.906  - info: host.raspberrypi instance system.adapter.backitup.0 terminated with code 0 (OK)
2019-03-05 14:00:10.908  - info: host.raspberrypi instance system.adapter.daswetter.0 terminated with code 0 (OK)
2019-03-05 14:00:20.368  - info: host.raspberrypi force terminating
2019-03-05 14:02:23.152  - info: host.raspberrypi iobroker.js-controller version 1.4.2 js-controller starting
2019-03-05 14:02:23.161  - info: host.raspberrypi Copyright (c) 2014-2018 bluefox, 2014 hobbyquaker
2019-03-05 14:02:23.162  - info: host.raspberrypi hostname: raspberrypi, node: v8.11.1
2019-03-05 14:02:23.167  - info: host.raspberrypi ip addresses: 192.168.188.28 fe80::90f8:966e:754:6247
2019-03-05 14:02:23.339  - info: host.raspberrypi  inMem-states listening on port 9000
2019-03-05 14:02:23.878  - info: host.raspberrypi  inMem-objects listening on port 9001
2019-03-05 14:02:23.909  - info: host.raspberrypi InMemoryDB connected
2019-03-05 14:02:23.943  - info: host.raspberrypi 11 instances found
2019-03-05 14:02:23.985  - info: host.raspberrypi starting 11 instances
2019-03-05 14:02:24.050  - info: host.raspberrypi instance system.adapter.admin.0 started with pid 8960
2019-03-05 14:02:28.006  - info: host.raspberrypi instance system.adapter.web.0 started with pid 8967
2019-03-05 14:02:28.724  - error: admin.0 setObject id missing!!
2019-03-05 14:02:28.743  - info: admin.0 starting. Version 3.6.0 in /opt/iobroker/node_modules/iobroker.admin, node: v8.11.1
2019-03-05 14:02:28.806  - info: admin.0 requesting all states
2019-03-05 14:02:28.810  - info: admin.0 requesting all objects
2019-03-05 14:02:28.813  - info: admin.0 Request actual repository...
2019-03-05 14:02:30.631  - info: admin.0 received all states
2019-03-05 14:02:32.169  - error: web.0 setObject id missing!!
2019-03-05 14:02:32.191  - info: web.0 starting. Version 2.4.1 in /opt/iobroker/node_modules/iobroker.web, node: v8.11.1
2019-03-05 14:02:32.786  - info: web.0 socket.io server listening on port 8082
2019-03-05 14:02:32.792  - info: web.0 http server listening on port 8082
2019-03-05 14:02:33.034  - info: admin.0 received all objects
2019-03-05 14:02:33.191  - info: admin.0 http server listening on port 8081
2019-03-05 14:02:33.192  - info: admin.0 Use link "http://localhost:8081" to configure.
2019-03-05 14:02:33.318  - info: host.raspberrypi Update repository "latest" under "http://download.iobroker.net/sources-dist-latest.json"
2019-03-05 14:02:35.794  - info: vis.0 starting. Version 1.1.10 in /opt/iobroker/node_modules/iobroker.vis, node: v8.11.1
2019-03-05 14:02:35.935  - info: admin.0 Repository received successfully.
2019-03-05 14:02:36.007  - info: host.raspberrypi instance system.adapter.javascript.0 started with pid 8991
2019-03-05 14:02:36.123  - info: vis.0 vis license is OK.
2019-03-05 14:02:37.084  - info: host.raspberrypi instance system.adapter.vis.0 terminated while should be started once
2019-03-05 14:02:41.450  - info: javascript.0 starting. Version 3.6.4 in /opt/iobroker/node_modules/iobroker.javascript, node: v8.11.1
2019-03-05 14:02:41.467  - info: javascript.0 requesting all states
2019-03-05 14:02:41.470  - info: javascript.0 requesting all objects
2019-03-05 14:02:42.638  - info: javascript.0 received all states
2019-03-05 14:02:44.008  - info: host.raspberrypi instance system.adapter.modbus.0 started with pid 9001
2019-03-05 14:02:44.960  - info: javascript.0 received all objects
2019-03-05 14:02:45.083  - info: javascript.0 Start javascript script.js.Skalierung_PV_Leistung
2019-03-05 14:02:45.182  - info: javascript.0 script.js.Skalierung_PV_Leistung: registered 0 subscriptions and 0 schedules
2019-03-05 14:02:45.184  - info: javascript.0 Start javascript script.js.Skalierung_Meter_Leistung
2019-03-05 14:02:45.256  - info: javascript.0 script.js.Skalierung_Meter_Leistung: registered 0 subscriptions and 0 schedules
2019-03-05 14:02:45.257  - info: javascript.0 Start javascript script.js.Sonneuntergang
2019-03-05 14:02:45.351  - info: javascript.0 script.js.Sonneuntergang: registered 0 subscriptions and 1 schedule
2019-03-05 14:02:45.352  - info: javascript.0 Start javascript script.js.PV_Leistung_Durchschnitt
2019-03-05 14:02:45.432  - info: javascript.0 script.js.PV_Leistung_Durchschnitt: registered 0 subscriptions and 1 schedule
2019-03-05 14:02:45.433  - info: javascript.0 Start javascript script.js.eth002_R1
2019-03-05 14:02:45.514  - info: javascript.0 script.js.eth002_R1: registered 1 subscription and 0 schedules
2019-03-05 14:02:45.515  - info: javascript.0 Start javascript script.js.Steure_R1
2019-03-05 14:02:45.594  - info: javascript.0 script.js.Steure_R1: registered 1 subscription and 0 schedules
2019-03-05 14:02:45.595  - info: javascript.0 Start javascript script.js.Steure_R2
2019-03-05 14:02:45.674  - info: javascript.0 script.js.Steure_R2: registered 2 subscriptions and 0 schedules
2019-03-05 14:02:45.675  - info: javascript.0 Start javascript script.js.in_zeit_auto_R2
2019-03-05 14:02:45.758  - info: javascript.0 script.js.in_zeit_auto_R2: registered 1 subscription and 1 schedule
2019-03-05 14:02:45.759  - info: javascript.0 Start javascript script.js.eth002_R2
2019-03-05 14:02:45.843  - info: javascript.0 script.js.eth002_R2: registered 1 subscription and 0 schedules
2019-03-05 14:02:45.844  - info: javascript.0 Start javascript script.js.WLAN
2019-03-05 14:02:45.928  - info: javascript.0 script.js.WLAN: registered 0 subscriptions and 1 schedule
2019-03-05 14:02:45.929  - info: javascript.0 Start javascript script.js.Zeit_WP_Sperre_Ein_dynamisch
2019-03-05 14:02:46.017  - info: javascript.0 script.js.Zeit_WP_Sperre_Ein_dynamisch: registered 0 subscriptions and 2 schedules
2019-03-05 14:02:46.018  - info: javascript.0 Start javascript script.js.in_zeit_sperre_R1_mitWetter
2019-03-05 14:02:46.103  - info: javascript.0 script.js.in_zeit_sperre_R1_mitWetter: registered 1 subscription and 1 schedule
2019-03-05 14:02:46.104  - info: javascript.0 Start javascript script.js.Test_Ausgaben
2019-03-05 14:02:46.191  - info: javascript.0 script.js.Test_Ausgaben: registered 0 subscriptions and 1 schedule
2019-03-05 14:02:47.440  - info: modbus.0 starting. Version 2.0.9 in /opt/iobroker/node_modules/iobroker.modbus, node: v8.11.1
2019-03-05 14:02:47.493  - warn: modbus.0 Serial is not available
2019-03-05 14:02:47.854  - info: modbus.0 Connected to slave 192.168.188.36
2019-03-05 14:02:48.007  - info: host.raspberrypi instance system.adapter.tr-064.0 started with pid 9011
2019-03-05 14:02:52.017  - info: tr-064.0 starting. Version 0.4.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v8.11.1
2019-03-05 14:02:54.555  - error: tr-064.0 forEachConfiguredDevice: in GetSpecificHostEntry 0(fritz.box/5C:49:79:3E:4C:24):Error: sendSOAPActionRequest Error action=GetSpecificHostEntry serviceType=urn:dslforum-org:service:Hosts:1: 500 - {"code":500}
2019-03-05 14:02:56.025  - info: host.raspberrypi instance system.adapter.backitup.0 started with pid 9021
2019-03-05 14:02:59.341  - debug: backitup.0 objectDB connected
2019-03-05 14:02:59.416  - debug: backitup.0 statesDB connected
2019-03-05 14:02:59.599  - info: backitup.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.11.1
2019-03-05 14:03:00.121  - info: host.raspberrypi instance scheduled system.adapter.daswetter.0 */15 * * * *
2019-03-05 14:02:59.611  - debug: backitup.0 Printing logs of previous backup
2019-03-05 14:02:59.615  - debug: backitup.0 [DEBUG] [total/mount] done
2019-03-05 14:02:59.617  - debug: backitup.0 [DEBUG] [total/total] TAR started...
2019-03-05 14:02:59.617  - debug: backitup.0 [DEBUG] [total/total] Ignore dir: /opt/iobroker/backups
2019-03-05 14:02:59.618  - debug: backitup.0 [DEBUG] [total/total] done
2019-03-05 14:02:59.618  - debug: backitup.0 [DEBUG] [total/cifs] done
2019-03-05 14:02:59.618  - debug: backitup.0 [DEBUG] [total/clean] delete /opt/iobroker/backups/total_2019_01_01-04_15_33_backupiobroker.tar.gz
2019-03-05 14:02:59.619  - debug: backitup.0 [DEBUG] [total/clean] done
2019-03-05 14:02:59.619  - debug: backitup.0 [DEBUG] [total/start] done
2019-03-05 14:02:59.619  - debug: backitup.0 [DEBUG] [total/start] IoBroker started ...
2019-03-05 14:02:59.619  - debug: backitup.0 [DEBUG] [total/email] done
2019-03-05 14:03:00.598  - info: backitup.0 [minimal] backup was activated at 04:00 every 1 day(s)
2019-03-05 14:03:00.634  - debug: backitup.0 [minimal] 10 00 04 */1 * * 
2019-03-05 14:03:00.634  - info: backitup.0 [total] backup was activated at 14:00:00 every 1 day(s)
2019-03-05 14:03:00.650  - debug: backitup.0 [total] 10 00 14 */1 * * 
2019-03-05 14:03:00.737  - debug: backitup.0 mount activ... umount in 2 Seconds!!
2019-03-05 14:03:04.028  - info: host.raspberrypi instance system.adapter.email.0 started with pid 9044
2019-03-05 14:03:05.545  - debug: backitup.0 [total/email] [total] used E-Mail-Instance: email.0
2019-03-05 14:03:05.554  - debug: backitup.0 sendTo "send" to system.adapter.email.0 from system.adapter.backitup.0
2019-03-05 14:03:05.556  - debug: backitup.0 [total/email] done
2019-03-05 14:03:05.603  - debug: backitup.0 [total/history] backitup.0.history.html
2019-03-05 14:03:07.317  - info: email.0 starting. Version 1.0.4 in /opt/iobroker/node_modules/iobroker.email, node: v8.11.1
2019-03-05 14:07:10.010  - debug: backitup.0 system.adapter.admin.0: logging false
2019-03-05 14:10:22.786  - debug: backitup.0 system.adapter.admin.0: logging true

[simatec]

Hatte 5 Sekunden Verzögerung drin. Aber laut Log startet dein mail Adapter weitere 2 Sekunden später.
Ich habe nun die zeit auf 10 Sekunden angepasst. Probiere bitte noch einmal

[sol21]

@simatec
Super! Hat geklappt. -> Email kam sofort an.

Spoiler

2019-03-05 15:43:09.736  - debug: backitup.0 statesDB connected
2019-03-05 15:43:09.905  - info: backitup.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.11.1
2019-03-05 15:43:09.975  - info: backitup.0 [minimal] backup was activated at 04:00 every 1 day(s)
2019-03-05 15:43:10.012  - debug: backitup.0 [minimal] 10 00 04 */1 * * 
2019-03-05 15:43:10.013  - info: backitup.0 [total] backup was activated at 15:45:00 every 1 day(s)
2019-03-05 15:43:10.019  - debug: backitup.0 [total] 10 45 15 */1 * * 
2019-03-05 15:43:14.240  - debug: backitup.0 system.adapter.admin.0: logging true
2019-03-05 15:45:00.046  - info: host.raspberrypi instance system.adapter.daswetter.0 started with pid 9680
2019-03-05 15:45:04.044  - info: daswetter.0 starting. Version 2.7.3 in /opt/iobroker/node_modules/iobroker.daswetter, node: v8.11.1
2019-03-05 15:45:10.052  - debug: backitup.0 [total] exec: done
2019-03-05 15:45:10.247  - info: admin.0 terminating http server on port 8081
2019-03-05 15:45:10.248  - info: web.0 terminating http server on port 8082
2019-03-05 15:45:10.249  - info: web.0 terminated http server on port 8082
2019-03-05 15:45:10.257  - info: tr-064.0 terminating
2019-03-05 15:45:10.259  - info: modbus.0 terminating
2019-03-05 15:45:10.264  - info: javascript.0 terminating
2019-03-05 15:45:10.272  - info: host.raspberrypi received SIGTERM
2019-03-05 15:45:10.272  - info: admin.0 terminating
2019-03-05 15:45:10.282  - info: web.0 terminating
2019-03-05 15:45:10.300  - info: host.raspberrypi instance system.adapter.tr-064.0 terminated with code 0 (OK)
2019-03-05 15:45:10.323  - info: host.raspberrypi instance system.adapter.admin.0 terminated with code 0 (OK)
2019-03-05 15:45:10.324  - debug: backitup.0 system.adapter.admin.0: logging false
2019-03-05 15:45:10.328  - info: host.raspberrypi instance system.adapter.web.0 terminated with code 0 (OK)
2019-03-05 15:45:10.334  - info: host.raspberrypi instance system.adapter.javascript.0 terminated with code 0 (OK)
2019-03-05 15:45:10.338  - info: host.raspberrypi instance system.adapter.modbus.0 terminated with code 0 (OK)
2019-03-05 15:45:10.748  - info: email.0 terminating
2019-03-05 15:45:10.755  - info: backitup.0 terminating
2019-03-05 15:45:10.766  - info: daswetter.0 terminating
2019-03-05 15:45:10.780  - info: host.raspberrypi instance system.adapter.backitup.0 terminated with code 0 (OK)
2019-03-05 15:45:10.810  - info: host.raspberrypi instance system.adapter.email.0 terminated with code 0 (OK)
2019-03-05 15:45:10.810  - info: host.raspberrypi instance system.adapter.daswetter.0 terminated with code 0 (OK)
2019-03-05 15:45:20.281  - info: host.raspberrypi force terminating
2019-03-05 15:47:17.982  - info: host.raspberrypi iobroker.js-controller version 1.4.2 js-controller starting
2019-03-05 15:47:17.991  - info: host.raspberrypi Copyright (c) 2014-2018 bluefox, 2014 hobbyquaker
2019-03-05 15:47:17.992  - info: host.raspberrypi hostname: raspberrypi, node: v8.11.1
2019-03-05 15:47:17.997  - info: host.raspberrypi ip addresses: 192.168.188.28 fe80::90f8:966e:754:6247
2019-03-05 15:47:18.169  - info: host.raspberrypi  inMem-states listening on port 9000
2019-03-05 15:47:18.709  - info: host.raspberrypi  inMem-objects listening on port 9001
2019-03-05 15:47:18.740  - info: host.raspberrypi InMemoryDB connected
2019-03-05 15:47:18.773  - info: host.raspberrypi 11 instances found
2019-03-05 15:47:18.815  - info: host.raspberrypi starting 11 instances
2019-03-05 15:47:18.880  - info: host.raspberrypi instance system.adapter.admin.0 started with pid 9761
2019-03-05 15:47:22.837  - info: host.raspberrypi instance system.adapter.web.0 started with pid 9767
2019-03-05 15:47:23.536  - error: admin.0 setObject id missing!!
2019-03-05 15:47:23.558  - info: admin.0 starting. Version 3.6.0 in /opt/iobroker/node_modules/iobroker.admin, node: v8.11.1
2019-03-05 15:47:23.619  - info: admin.0 requesting all states
2019-03-05 15:47:23.623  - info: admin.0 requesting all objects
2019-03-05 15:47:23.626  - info: admin.0 Request actual repository...
2019-03-05 15:47:25.711  - info: admin.0 received all states
2019-03-05 15:47:27.022  - error: web.0 setObject id missing!!
2019-03-05 15:47:27.045  - info: web.0 starting. Version 2.4.1 in /opt/iobroker/node_modules/iobroker.web, node: v8.11.1
2019-03-05 15:47:27.682  - info: web.0 socket.io server listening on port 8082
2019-03-05 15:47:27.688  - info: web.0 http server listening on port 8082
2019-03-05 15:47:28.060  - info: admin.0 received all objects
2019-03-05 15:47:28.208  - info: admin.0 http server listening on port 8081
2019-03-05 15:47:28.208  - info: admin.0 Use link "http://localhost:8081" to configure.
2019-03-05 15:47:28.332  - info: host.raspberrypi Update repository "latest" under "http://download.iobroker.net/sources-dist-latest.json"
2019-03-05 15:47:30.838  - info: host.raspberrypi instance system.adapter.javascript.0 started with pid 9789
2019-03-05 15:47:31.225  - info: admin.0 Repository received successfully.
2019-03-05 15:47:31.115  - info: vis.0 starting. Version 1.1.10 in /opt/iobroker/node_modules/iobroker.vis, node: v8.11.1
2019-03-05 15:47:31.378  - info: vis.0 vis license is OK.
2019-03-05 15:47:32.301  - info: host.raspberrypi instance system.adapter.vis.0 terminated while should be started once
2019-03-05 15:47:36.480  - info: javascript.0 starting. Version 3.6.4 in /opt/iobroker/node_modules/iobroker.javascript, node: v8.11.1
2019-03-05 15:47:36.498  - info: javascript.0 requesting all states
2019-03-05 15:47:36.501  - info: javascript.0 requesting all objects
2019-03-05 15:47:37.650  - info: javascript.0 received all states
2019-03-05 15:47:38.847  - info: host.raspberrypi instance system.adapter.modbus.0 started with pid 9803
2019-03-05 15:47:39.841  - info: javascript.0 received all objects
2019-03-05 15:47:39.961  - info: javascript.0 Start javascript script.js.Skalierung_PV_Leistung
2019-03-05 15:47:40.061  - info: javascript.0 script.js.Skalierung_PV_Leistung: registered 0 subscriptions and 0 schedules
2019-03-05 15:47:40.063  - info: javascript.0 Start javascript script.js.Skalierung_Meter_Leistung
2019-03-05 15:47:40.137  - info: javascript.0 script.js.Skalierung_Meter_Leistung: registered 0 subscriptions and 0 schedules
2019-03-05 15:47:40.138  - info: javascript.0 Start javascript script.js.Sonneuntergang
2019-03-05 15:47:40.234  - info: javascript.0 script.js.Sonneuntergang: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:40.235  - info: javascript.0 Start javascript script.js.PV_Leistung_Durchschnitt
2019-03-05 15:47:40.317  - info: javascript.0 script.js.PV_Leistung_Durchschnitt: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:40.318  - info: javascript.0 Start javascript script.js.eth002_R1
2019-03-05 15:47:40.404  - info: javascript.0 script.js.eth002_R1: registered 1 subscription and 0 schedules
2019-03-05 15:47:40.405  - info: javascript.0 Start javascript script.js.Steure_R1
2019-03-05 15:47:40.486  - info: javascript.0 script.js.Steure_R1: registered 1 subscription and 0 schedules
2019-03-05 15:47:40.487  - info: javascript.0 Start javascript script.js.Steure_R2
2019-03-05 15:47:40.568  - info: javascript.0 script.js.Steure_R2: registered 2 subscriptions and 0 schedules
2019-03-05 15:47:40.569  - info: javascript.0 Start javascript script.js.in_zeit_auto_R2
2019-03-05 15:47:40.655  - info: javascript.0 script.js.in_zeit_auto_R2: registered 1 subscription and 1 schedule
2019-03-05 15:47:40.656  - info: javascript.0 Start javascript script.js.eth002_R2
2019-03-05 15:47:40.742  - info: javascript.0 script.js.eth002_R2: registered 1 subscription and 0 schedules
2019-03-05 15:47:40.743  - info: javascript.0 Start javascript script.js.WLAN
2019-03-05 15:47:40.829  - info: javascript.0 script.js.WLAN: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:40.830  - info: javascript.0 Start javascript script.js.Zeit_WP_Sperre_Ein_dynamisch
2019-03-05 15:47:40.917  - info: javascript.0 script.js.Zeit_WP_Sperre_Ein_dynamisch: registered 0 subscriptions and 2 schedules
2019-03-05 15:47:40.918  - info: javascript.0 Start javascript script.js.in_zeit_sperre_R1_mitWetter
2019-03-05 15:47:41.006  - info: javascript.0 script.js.in_zeit_sperre_R1_mitWetter: registered 1 subscription and 1 schedule
2019-03-05 15:47:41.006  - info: javascript.0 Start javascript script.js.Test_Ausgaben
2019-03-05 15:47:41.095  - info: javascript.0 script.js.Test_Ausgaben: registered 0 subscriptions and 1 schedule
2019-03-05 15:47:42.203  - info: modbus.0 starting. Version 2.0.9 in /opt/iobroker/node_modules/iobroker.modbus, node: v8.11.1
2019-03-05 15:47:42.256  - warn: modbus.0 Serial is not available
2019-03-05 15:47:42.635  - info: modbus.0 Connected to slave 192.168.188.36
2019-03-05 15:47:42.836  - info: host.raspberrypi instance system.adapter.tr-064.0 started with pid 9813
2019-03-05 15:47:46.789  - info: tr-064.0 starting. Version 0.4.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v8.11.1
2019-03-05 15:47:49.302  - error: tr-064.0 forEachConfiguredDevice: in GetSpecificHostEntry 0(fritz.box/5C:49:79:3E:4C:24):Error: sendSOAPActionRequest Error action=GetSpecificHostEntry serviceType=urn:dslforum-org:service:Hosts:1: 500 - {"code":500}
2019-03-05 15:47:50.853  - info: host.raspberrypi instance system.adapter.backitup.0 started with pid 9823
2019-03-05 15:47:54.128  - debug: backitup.0 objectDB connected
2019-03-05 15:47:54.203  - debug: backitup.0 statesDB connected
2019-03-05 15:47:54.379  - info: backitup.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.11.1
2019-03-05 15:47:54.858  - info: host.raspberrypi instance scheduled system.adapter.daswetter.0 */15 * * * *
2019-03-05 15:47:54.391  - debug: backitup.0 Printing logs of previous backup
2019-03-05 15:47:54.395  - debug: backitup.0 [DEBUG] [total/mount] done
2019-03-05 15:47:54.397  - debug: backitup.0 [DEBUG] [total/total] TAR started...
2019-03-05 15:47:54.397  - debug: backitup.0 [DEBUG] [total/total] Ignore dir: /opt/iobroker/backups
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/total] done
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/cifs] done
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/clean] delete /opt/iobroker/backups/total_2019_01_11-04_15_33_backupiobroker.tar.gz
2019-03-05 15:47:54.398  - debug: backitup.0 [DEBUG] [total/clean] done
2019-03-05 15:47:54.399  - debug: backitup.0 [DEBUG] [total/start] done
2019-03-05 15:47:54.399  - debug: backitup.0 [DEBUG] [total/start] IoBroker started ...
2019-03-05 15:47:54.399  - debug: backitup.0 [DEBUG] [total/email] done
2019-03-05 15:47:55.335  - info: backitup.0 [minimal] backup was activated at 04:00 every 1 day(s)
2019-03-05 15:47:55.372  - debug: backitup.0 [minimal] 10 00 04 */1 * * 
2019-03-05 15:47:55.373  - info: backitup.0 [total] backup was activated at 15:45:00 every 1 day(s)
2019-03-05 15:47:55.389  - debug: backitup.0 [total] 10 45 15 */1 * * 
2019-03-05 15:47:55.487  - debug: backitup.0 mount activ... umount in 2 Seconds!!
2019-03-05 15:47:58.860  - info: host.raspberrypi instance system.adapter.email.0 started with pid 9846
2019-03-05 15:48:02.166  - info: email.0 starting. Version 1.0.4 in /opt/iobroker/node_modules/iobroker.email, node: v8.11.1
2019-03-05 15:48:05.274  - debug: backitup.0 [total/email] [total] used E-Mail-Instance: email.0
2019-03-05 15:48:05.281  - debug: backitup.0 sendTo "send" to system.adapter.email.0 from system.adapter.backitup.0
2019-03-05 15:48:05.282  - debug: backitup.0 [total/email] done
2019-03-05 15:48:05.316  - debug: backitup.0 [total/history] backitup.0.history.html
2019-03-05 15:48:05.521  - info: email.0 Send email: {"text":"BackItUp:\nEin neues total Backup wurde am 05. Maerz 2019 um 15:47 Uhr erstellt, und unter 192.168.188.40/Backup/iobroker/komplett/ gespeichert.","to":"xx.yy@gmx.ch","subject":"Backitup","from":"jj@gmail.com"}
2019-03-05 15:48:07.494  - info: email.0 sent to xx.yy@gmx.ch

Nochmals herzlichen Dank für die tolle Unterstützung!

[simatec]

Ab Version 1.1.3 ist die Zeitverzögerung im Menü einstellbar.