History: Restart alle paar Minuten - Downgrade geht nicht

[klassisch]

Heute um 00:11, ebenfalss "ex nihilo"

! hm-rpc.0.IEQ0067710.2.ADJUSTING_DATA, last-value=0, new-value=0, ts=1521760246507 2018-03-23 00:11:06.763 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ015xxxx.1.VALVE_STATE, last-value=0, new-value=0, ts=1521760246620 2018-03-23 00:11:06.765 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ015xxxx.1.ERROR, last-value=0, new-value=0, ts=1521760246629 2018-03-23 00:11:07.946 - [34mdebug[39m: history.0 statesDB connected 2018-03-23 00:11:08.129 - [34mdebug[39m: history.0 statesDB connected 2018-03-23 00:11:08.175 - [33mwarn[39m: history.0 Reconnection to DB. 2018-03-23 00:11:08.419 - [33mwarn[39m: history.0 Reconnection to DB. 2018-03-23 00:11:08.688 - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1 2018-03-23 00:11:08.713 - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1 2018-03-23 00:11:09.477 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.updated 2018-03-23 00:11:09.479 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.0.INSTALL_MODE 2018-03-23 00:11:09.480 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.LEVEL !
….

2018-03-23 00:11:31.664  - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_9.SWITCH_0a
2018-03-23 00:11:31.665  - [32minfo[39m: history.0 enabled logging of rflink.0.channels.ElroDB_1.CHIME_1
2018-03-23 00:11:31.666  - [32minfo[39m: history.0 enabled logging of rflink.0.channels.ElroDB_1.SWITCH_1
2018-03-23 00:11:31.666  - [32minfo[39m: history.0 enabled logging of rflink.0.channels.Eurodomest_1.SWITCH_02
2018-03-23 00:11:31.667  - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_10.SWITCH_0d
2018-03-23 00:11:31.668  - [32minfo[39m: history.0 enabled logging of data.0.leakage.Treppe
2018-03-23 00:13:36.300  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ0510473.2.ADJUSTING_COMMAND, last-value=0, new-value=0, ts=1521760416286
2018-03-23 00:13:36.323  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ0510473.2.ADJUSTING_DATA, last-value=12, new-value=12, ts=1521760416298
2018-03-23 00:13:36.415  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ0513285.1.VALVE_STATE, last-value=5, new-value=5, ts=1521760416407
>! ````
Aber schnell durchgelaufen < 1min.

um 04:25 mihome adapter gesartet

um 04:32 der nächste history Neustart

>! ````
2018-03-23 04:32:49.918  - [34mdebug[39m: history.0 Min-Delta ignored because no number hm-rpc.0.JEQ004xxxx.1.STATE, last-value=true, new-value=false, ts=1521775937571
2018-03-23 04:32:49.921  - [34mdebug[39m: history.0 Min-Delta ignored because no number hm-rpc.0.JEQ004xxxx.1.WORKING, last-value=true, new-value=false, ts=1521775937582
2018-03-23 04:32:49.974  - [34mdebug[39m: history.0 value not changed rflink.0.channels.SelectPlus_1.CHIME_02, last-value=1, new-value=1, ts=1521775941299
2018-03-23 04:32:50.006  - [34mdebug[39m: history.0 value not changed hm-rpc.0.MEQ0272133.2.BOOT, last-value=true, new-value=true, ts=1521775948623
2018-03-23 04:32:50.011  - [34mdebug[39m: history.0 Min-Delta reached hm-rpc.0.MEQ0272133.2.FREQUENCY, last-value=49.99, new-value=50.01, ts=1521775948637
2018-03-23 04:32:50.314  - [33mwarn[39m: history.0 Reconnection to DB.
2018-03-23 04:32:50.433  - [33mwarn[39m: history.0 Reconnection to DB.
2018-03-23 04:32:51.268  - [34mdebug[39m: history.0 statesDB connected
2018-03-23 04:32:51.320  - [34mdebug[39m: history.0 statesDB connected
2018-03-23 04:32:57.659  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ051xxxx.2.ADJUSTING_COMMAND, last-value=0, new-value=0, ts=1521775977638
2018-03-23 04:32:57.664  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ051xxxx.2.ADJUSTING_DATA, last-value=36, new-value=36, ts=1521775977648
2018-03-23 04:32:57.692  - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1
2018-03-23 04:32:57.734  - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1
2018-03-23 04:32:58.148  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ051xxxx.1.VALVE_STATE, last-value=14, new-value=14, ts=1521775978121
2018-03-23 04:32:58.150  - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ051xxxx.1.ERROR, last-value=0, new-value=0, ts=1521775978127
2018-03-23 04:32:58.349  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.updated
2018-03-23 04:32:58.351  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.0.INSTALL_MODE
2018-03-23 04:32:58.353  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.LEVEL
2018-03-23 04:32:58.354  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_LONG
2018-03-23 04:32:58.355  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_SHORT
2018-03-23 04:32:58.356  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.2.LEVEL
2018-03-23 04:32:58.356  - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.2.PRESS_LONG
>! ````
….

2018-03-23 04:33:29.705 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_9.SWITCH_0e
2018-03-23 04:33:29.705 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_9.SWITCH_0a
2018-03-23 04:33:29.706 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.ElroDB_1.CHIME_1
2018-03-23 04:33:29.707 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.ElroDB_1.SWITCH_1
2018-03-23 04:33:29.708 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.Eurodomest_1.SWITCH_02
2018-03-23 04:33:29.709 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_10.SWITCH_0d
2018-03-23 04:33:29.709 - [32minfo[39m: history.0 enabled logging of data.0.leakage.Treppe
2018-03-23 04:35:30.168 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ015xxxx.1.TEMPERATURE, last-value=18.2, new-value=18.2, ts=1521776130161
2018-03-23 04:35:30.234 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ015xxxx.1.HUMIDITY, last-value=53, new-value=53, ts=1521776130166
2018-03-23 04:35:41.190 - [34mdebug[39m: history.0 value not changed hm-rpc.0.MEQ044xxxx.4.CONTROL_MODE, last-value=0, new-value=0, ts=1521776141182

! ````
Durchlauf ebenfalls <1 Minute

04:36 startet auch noch admin neu

! 2018-03-23 04:36:22.499 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ0067710.1.TEMPERATURE, last-value=19, new-value=19, ts=1521776182492 2018-03-23 04:36:22.506 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ006xxxx.1.HUMIDITY, last-value=51, new-value=51, ts=1521776182499 2018-03-23 04:36:23.803 - [32minfo[39m: admin.0 starting. Version 2.0.9 in /opt/iobroker/node_modules/iobroker.admin, node: v6.13.1 2018-03-23 04:36:23.901 - [32minfo[39m: admin.0 requesting all states 2018-03-23 04:36:23.908 - [32minfo[39m: admin.0 requesting all objects 2018-03-23 04:36:29.991 - [32minfo[39m: admin.0 received all states 2018-03-23 04:36:31.333 - [34mdebug[39m: history.0 Min-Delta reached hm-rpc.0.HEQ051xxxx.1.TEMPERATURE, last-value=18.1, new-value=18.2, ts=1521776191326 2018-03-23 04:36:31.342 - [34mdebug[39m: history.0 value not changed hm-rpc.0.HEQ051xxxx.1.HUMIDITY, last-value=39, new-value=39, ts=1521776191334 2018-03-23 04:36:33.298 - [32minfo[39m: admin.0 received all objects 2018-03-23 04:36:33.772 - [32minfo[39m: admin.0 http server listening on port 8081 2018-03-23 04:36:33.773 - [32minfo[39m: admin.0 Use link "http://localhost:8081" to configure. 2018-03-23 04:36:34.322 - [32minfo[39m: admin.0 Request actual repository... 2018-03-23 04:36:34.501 - [32minfo[39m: host.orangepiplus2e Update repository "default" under "http://download.iobroker.net/sources-dist.json" 2018-03-23 04:36:35.769 - [32minfo[39m: admin.0 Change log subscriber state: true 2018-03-23 04:36:35.787 - [32minfo[39m: web.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.787 - [32minfo[39m: hm-rega.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.790 - [32minfo[39m: simple-api.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.783 - [32minfo[39m: email.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.781 - [32minfo[39m: hm-rpc.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.780 - [32minfo[39m: hm-rpc.1 system.adapter.admin.0: logging true 2018-03-23 04:36:35.785 - [32minfo[39m: javascript.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.818 - [32minfo[39m: mihome-vacuum.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.820 - [32minfo[39m: history.0 system.adapter.admin.0: logging true 2018-03-23 04:36:35.809 - [32minfo[39m: rflink.0 system.adapter.admin.0: logging true 2018-03-23 04:36:36.291 - [34mdebug[39m: history.0 value not changed admin.0.info.updatesNumber, last-value=2, new-value=2, ts=1521776196285 2018-03-23 04:36:37.573 - [34mdebug[39m: history.0 value not changed admin.0.info.updatesList, last-value=flot, history, new-value=flot, history, ts=1521776197567 2018-03-23 04:36:37.687 - [32minfo[39m: admin.0 Repository received successfully. 2018-03-23 04:36:37.700 - [32minfo[39m: admin.0 system.adapter.admin.0: logging true 2018-03-23 04:36:42.547 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ006xxxx.2.ADJUSTING_COMMAND, last-value=0, new-value=0, ts=1521776202538 2018-03-23 04:36:42.576 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ006xxxx.2.ADJUSTING_DATA, last-value=0, new-value=0, ts=1521776202553 2018-03-23 04:36:42.639 - [34mdebug[39m: history.0 value not changed hm-rpc.0.IEQ015xxxx.1.VALVE_STATE, last-value=0, new-value=0, ts=1521776202633 !

Und um 04:44 gleich nochmal history

! ```
2018-03-23 04:44:14.636 - [34mdebug[39m: history.0 value not changed hm-rpc.1.CUX9000009.1.STATE, last-value=0, new-value=0, ts=1521776648130 2018-03-23 04:44:14.637 - [34mdebug[39m: history.0 Min-Delta reached hm-rpc.1.CUX9000007.1.STATE, last-value=5, new-value=4, ts=1521776648148 2018-03-23 04:44:14.721 - [33mwarn[39m: history.0 Reconnection to DB. 2018-03-23 04:44:14.828 - [33mwarn[39m: history.0 Reconnection to DB. 2018-03-23 04:44:15.410 - [34mdebug[39m: history.0 statesDB connected 2018-03-23 04:44:15.470 - [34mdebug[39m: history.0 statesDB connected 2018-03-23 04:44:15.740 - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1 2018-03-23 04:44:15.767 - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1 2018-03-23 04:44:16.520 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.updated 2018-03-23 04:44:16.522 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.0.INSTALL_MODE 2018-03-23 04:44:16.523 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.LEVEL 2018-03-23 04:44:16.524 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_LONG 2018-03-23 04:44:16.524 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_SHORT[/code]
....
~~[code]~~2018-03-23 04:44:44.006 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_9.SWITCH_07 2018-03-23 04:44:44.007 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_9.SWITCH_0e 2018-03-23 04:44:44.008 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_9.SWITCH_0a 2018-03-23 04:44:44.008 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.ElroDB_1.CHIME_1 2018-03-23 04:44:44.009 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.ElroDB_1.SWITCH_1 2018-03-23 04:44:44.010 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.Eurodomest_1.SWITCH_02 2018-03-23 04:44:44.011 - [32minfo[39m: history.0 enabled logging of rflink.0.channels.EV1527_10.SWITCH_0d 2018-03-23 04:44:44.012 - [32minfo[39m: history.0 enabled logging of data.0.leakage.Treppe 2018-03-23 04:45:49.683 - [34mdebug[39m: history.0 value not changed hm-rpc.1.CUX9002002.1.DEW_POINT, last-value=3.4, new-value=3.4, ts=1521776749653 2018-03-23 04:45:49.687 - [34mdebug[39m: history.0 value not changed hm-rpc.1.CUX9002002.1.ABS_HUMIDITY, last-value=5.94, new-value=5.94, ts=1521776749654 2018-03-23 04:46:01.392 - [34mdebug[39m: history.0 value not changed hm-rpc.1.CUX9001001.1.SWITCH_1H, last-value=2, new-value=2, ts=1521776761357 2018-03-23 04:46:01.396 - [34mdebug[39m: history.0 Min-Delta reached hm-rpc.1.CUX9001001.1.TIME_ON_1H, last-value=45.03, new-value=44.05, ts=1521776761359 [/code]
Durchlauf < 1min

[apollon77]

Also der Adapter wird nicht wirklich komplett neu gestartet, sondern durch dsas "states connected" wird die "Main"-Methode wieder aufgerufen die wieder alles neu inizialisiert.

Also Auslöser ist der States-Reconnect.

Hast Du ne Idee was zu den Urzeiten auf dem Rechner los war? Loadspitzen?

[klassisch]

Vielen Dank!

Ich habe auch noch keine funktionierende Korrelation gefunden.

Lastspitzen könnten sein, wenn 20 Flot-Charts aktualisiert werden. Zumindest manchmal. Aber es gibt auch deutlich höhere Lastspitzen, die nicht zu dem Event führen und andererseits kommen die Events auch nachts oder wenn ich nicht hier bin.

Werde mal den OPi Adapter anwerfen und mitloggen. Mal sehen, ob es sich eine Korrelation ergibt.

Was hat es mit den states-reconnects auf sich?

[apollon77]

AUs irgendeinem Grund verliert der history-Adapter zu dem Zeitpunkt die TCP-Verbindung zur States-DB. Die States-DB ist vom js-controller auf Port 9000 oder 9001 (weiss nimmer, eins ist States, eins Objects).

[klassisch]

Also eine OS-Sache (armbian)? Bisher habe ich ja noch einen Host, den Opi unter armbian.

Und das letzte armbian-Update hat mir schon Probleme bereitet. Da konnte die SSD, auf der die History-Daten sind, nicht mehr eingebunden /angesprochen werden. Wahrscheinlich eine Treiber Geschichte. Ich habe dann einen anderen USB-SATA-Adapter genommen und es lief wieder. Der alte Adapter läuft unter Windows noch immer sehr gut. Bin kein Linux-Profi und habe das nur herausgefunden, indem ich die Serial des OPi abgehört habe. Da sah ich dann, daß irgendwas mit der SSD nicht klappte und der Bootprozess dann hängen blieb. Weil aber SSD incl. Adapter an Windows prima laufen, hats gedauert, bis ich mal den anderen Adapter getestet habe.

Aber die Schwierigkeiten mit dem history Adapter kamen erst später nach einem ioBroker Generalupdate.

[klassisch]

Habe jetzt mal 2 Stresstest gemacht.

1. Dateniput oerload: Betreibe ja etliche ESPs, die über simpleAPI Daten einliefern. Habe nun bei einem ESP32 (der ESP8266 würde dabei selbst abschmieren) in der Loop über bulk Daten an den ioBroker geliefert. Jeweils ca. 1 Minute lang. Der ioBroker brauchte daraufhin mehrere Minuten, um aufzuholen. Ist aber nicht ausser Tritt gekommen, kann aber auch nicht sagen, ob er alle Daten verarbeitet hat. War auch nicht die Fragestellung. Habe das Experiment dreimal wiederholt. Kein History Neustart.

2. FLOT-Load: 24 Firefox Tabs mit FLOT Charts geöffnet. Meine alltägliche Prozedur. CPU Last ging laut armbianmonitor auf 3.6, laut OPi-Adapter auf 2.6. Das war die größte Spitze seit ich die Werte wieder mitloggen (seit heute 00:13). Kein History Neustart.

[klassisch]

Hatte gerade wieder einen event ohne erkennbare Ursache. Bin nach Hause gekommen, HM-Öffnungen von Garage, Keymatic, ein paar Bewegungsmelder beim Einräumen der Einkäufe, Beim Firefox (Rechner lief durch) den Admin in focus nehmen und da wars schon da. Wahrscheinloch war das event schon vorher.

! 2018-03-24 12:31:20.515 - [34mdebug[39m: history.0 Min-Delta reached hm-rpc.1.CUX9002066.1.ABS_HUMIDITY, last-value=6.13, new-value=6.38, ts=1521891065485 2018-03-24 12:31:20.545 - [34mdebug[39m: history.0 Min-Delta reached hm-rpc.0.KEQ019xxxx.1.BRIGHTNESS, last-value=219, new-value=218, ts=1521891072585 2018-03-24 12:31:20.547 - [34mdebug[39m: history.0 Min-Delta ignored because no number hm-rpc.0.KEQ019xxxx.1.MOTION, last-value=false, new-value=true, ts=1521891072594 2018-03-24 12:31:20.549 - [34mdebug[39m: history.0 value not changed hm-rpc.0.KEQ019xxxxx.1.INSTALL_TEST, last-value=true, new-value=true, ts=1521891072599 2018-03-24 12:31:20.551 - [34mdebug[39m: history.0 value not changed hm-rpc.0.JEQ029xxxx.1.STATE, last-value=false, new-value=false, ts=1521891072707 2018-03-24 12:31:20.553 - [34mdebug[39m: history.0 value not changed hm-rpc.0.JEQ029xxxx.1.WORKING, last-value=false, new-value=false, ts=1521891072716 2018-03-24 12:31:20.758 - [33mwarn[39m: history.0 Reconnection to DB. 2018-03-24 12:31:20.860 - [33mwarn[39m: history.0 Reconnection to DB. 2018-03-24 12:31:21.513 - [34mdebug[39m: history.0 statesDB connected 2018-03-24 12:31:21.561 - [34mdebug[39m: history.0 statesDB connected 2018-03-24 12:31:22.086 - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1 2018-03-24 12:31:22.377 - [32minfo[39m: history.0 starting. Version 1.5.3 in /opt/iobroker/node_modules/iobroker.history, node: v6.13.1 2018-03-24 12:31:22.950 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.updated 2018-03-24 12:31:22.952 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.0.INSTALL_MODE 2018-03-24 12:31:22.953 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.LEVEL 2018-03-24 12:31:22.953 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_LONG 2018-03-24 12:31:22.954 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_SHORT 2018-03-24 12:31:22.955 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.2.LEVEL 2018-03-24 12:31:22.956 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.2.PRESS_LONG 2018-03-24 12:31:22.957 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.2.PRESS_SHORT 2018-03-24 12:31:22.958 - [32minfo[39m: history.0 enabled logging of hm-rpc.0.BidCoS-RF.3.LEVEL !
….

`2018-03-24 12:31:42.975  - [32minfo[39m: history.0 enabled logging of data.0.weather.garden.Humid-SHT31
2018-03-24 12:31:42.976  - [32minfo[39m: history.0 enabled logging of data.0.weather.garden.Humid-abs-SHT31
2018-03-24 12:31:42.977  - [32minfo[39m: history.0 enabled logging of data.0.weather.garden.DewTemp-SHT31
2018-03-24 12:32:15.411  - [34mdebug[39m: history.0 value not changed hm-rpc.0.JEQ029xxxx.1.STATE, last-value=false, new-value=false, ts=1521891135395
2018-03-24 12:32:15.459  - [34mdebug[39m: history.0 value not changed hm-rpc.0.JEQ029xxxx.1.WORKING, last-value=false, new-value=false, ts=1521891135400
2018-03-24 12:32:15.463  - [34mdebug[39m: history.0 value not changed hm-rpc.0.KEQ019xxxx.1.BRIGHTNESS, last-value=218, new-value=218, ts=1521891135403
2018-03-24 12:32:15.466  - [34md[/code]` 
>! Mäßige peaks bei Auslastung CPU1 von 0.22 auf 1.7 und bei der Temp von 27 auf 36°C aber mutmasslich als Folge des history enable events.
>! Könnte folgende Vorwärtsstrategie aufgehen?
>! - Das Problem scheint ja ein lokales zu sein. Andere haben das nicht, warum auch immer. Könnte jetzt den Rechner wechseln aber worauf? Eigentlich lief der OPi stabil und recht entspannt. Macht es Sinn History auf einen anderen Rechner auszulagern?
>! - Kann noch ein, zwei Tage auf gut Glück suchen. Mehr als gut Glück wirds wohl nicht, zumindest sehe ich keine weitere Möglichkeit mit meinen Mitteln und Kenntnissen.
>! - Mein ioBroker ist derzeit massiv downgegradet, das hat keine lange Zukunft.
>! - Kann dann in einer Nachtschicht ioBroker neu aufsetzen.
>! - Wenn dann das Problem immer noch besteht (wovon ich ausgehe), müßte ich History bei mir aufgeben. 
>! - Wäre Influx-DB die geeignete Vorwärtsstrategie?
>! - Habe irgendwo gelesen, daß man den Datenbestand von history nach InfluxDB portieren kann. Das würde ich versuchen.
>!  Mein History-Datenbestand sind ca. 1.3 GByte auf einer 32GB SSD 
>! - Nehme an daß FLOT dann auch mit Influx-DB arbeitet, oder gibt es da andere Tools?

[apollon77]

Naja, die andere Frage ist - was exakt sind denn die Nebenwirkungen des History-Restarts?! Wenn es nur ein bissl logging ist … loglevel hochsetzen und fertig

Aber Du hast Recht schon komisch und ich wüsste jetzt weitersuchtechnisch auch nicht weiter.

Ist der "History" der einzige Adapter der hier und da das problem mit dem Reconnect hat? Oder andere auch?

Die Frage ist wenn Du auf was anderes umsteigst (ich bin InfluxDB Fan, andere nehmen eher SQL) ob das Problem nicht mitwandert - genau weil es eher ein "lokales" ist

[klassisch]

Beim upgegradeten System kamen die history restarts viel zu oft. eher im 10 min Takt. Und jedes Mal dauerte die enablerei länger. Und irgendwann kamen rote overloadmeldungen und IoBroker hat sich neu gestartet. Völlig ungesund.

Habe jetzt mal den USB-SATA - SSD Adapter modifiziert, so daß sicher ausreichend Strom und Pufferung zur Verfügung stehen wird. Falls es je daran gelegen haben sollte….

Wenn der Fehler mitwandert, dann weiss ich genauer, daß es an der HW oder armbian liegt. Dann muß ich mich nach einer anderen Plattform umschauen.

[klassisch]

Habe jetzt nochmals ein Eperiment gestartet:

Aufgrund der Rechteerfahrungen beim Versuch influxDB oder MariaDB zu installieren und die Daten auf die FAT32 formatierte SSD zu veragern, habe ich meine Reserve-/Spiel-SSD mit ext4 formatiert und history auf diese ext4 SSD umgestellt.

Das läuft jetzt 6h stabil ohne history-Neustarts. Wenn es morgen noch stabil läuft, werde ich ioBroker wieder auf den neuesten Stand bringen und weiter beobachten.

Wenn es nichts wird, dann werde ich mein altes Notebook (i5-3210M, 8GB; 200GB SSD und 1TBHDD), das jetzt im Hobbyraum Dienst tut und mit dem gelegentlichen Auslesen von Messgeräten und Recherchen nicht ausgelastet ist, als ioBroker Plattform ausbauen. Bin gerade bei der Langzeit Energieverbrauchsmessung; 12W im idle kann ich mir dann auch noch leisten.

Keine Ahnung wie gut sich Win 10 und ioBroker vertragen, aber so wie es die letzten Tage und Wochen war, geht es auch nicht weiter. Kann ja den Mulithost nutzen und mit dem OPI z.B. den RFLink weiter betreiben. Könnte mir vorstellen, daß IoBroker und USB durch Windows durch Probleme macht.

[Homoran]

Was die Formatierung der SSD/HDD angeht kann ich mich im Moment nur auf die uralte Cubietruck-Anleitung beziehen, wo die HDD am SATA Port hängt.

Hier war explizit ext4 gefordert.

Alles andere hatte auch nicht geklappt.

ich kann mir vorstellen, dass das bei USB-Platten genau so ist, auch wenn es sich "nur" um eine Daten-Platte handelt.

Gruß

Rainer

[klassisch]

Hat ja das letzte Jahr über gut funktioniert. Die ersten Probleme gabs mit dem Kernelupdate Ende Januar/Anfang Februar und dann ganz massiv mit einen großflächigen ioBroker-Update.

Habe die letzten Tage versucht parallel zu Hilstory influx oder MariaDB mit der FAT32-SSD in Betrieb zu nehmen und das hat nicht funktioniert. Ein Rechteübertragungsbefehl lief nicht durch und dann startete die Datenbank nicht mehr. Bei den entsprechenden Recherchen habe ich gelesen, daß FAT32 keine Rechte verwalten kann und deshalb einige Applikationen damit nicht gehen. Es gibt mittlerweile Leute, die NTFS als generelles Austauschformat empfehlen, weil es damit am wenigsten Probleme gäbe.

Bin gespannt wie es jetzt läuft. Falls der Umstieg auf mein Win 10 Notebook erforderlich werden sollte: Wie sind denn die Erfahrungen der Windows- ioBroker Nutzer?

[klassisch]

Seit der Umstellung der Datenplatte von FAT32 auf ext4 vor 40h hatte ich keine history reconecting to DB mehr. Warum verstehe ich nicht, bin aber auch kein Linux Spezialist und habe nach diesem event in meiner Annäherung an Linux wieder einen kräftigen Dämfer erfahren. Ich nehme an, Linux, debian, armbian hat mit dem letzten Kernel-Update Anfang des Jahres die Fähigkeit verloren, ordentlich mit FAT32 umzugehen.

Mein altes Windows 10 Notebook (i5, 8GB) würde im Dauerbetrieb ca. 25 EUR/Jahr an Stromkosten erzeugen. Beim nächsten größeren Problem mit meinem Linux/armbian System wird auf Windows umgestellt. Dann bräuchte ich auch kein Reservesystem mehr zu kaufen, denn da könnte dann im Ernstfall mein jeweiliges Hauptnotebook herhalten. Und gebrauchte Notebooks dieser Kategorie gäbe es für ca. 200EUR mit 2 jähriger Garantie. Was mich noch am meisten abhält sind die seit Win 10 nicht mehr voll kontrollierbaren update-Zeitpunkte.

Vielen Dank jedenfalls für alle Zeit, Sachverstand und Tipps bei der Analyse der logs etc.

[apollon77]

Hochinteressant … hätte nicht erwartet das es am Filesystem liegt ... Auch wieder was gelernt

[klassisch]

Ich hätte es auch nicht erwartet, zumal es ja bislang klaglos funktioniert hat. Weiss auch nicht, ob die Erkenntnis verallgemeinerbar ist und vielleicht wäre nach dem nächsten Kernel-Update der Spuk vorbei. Das sind halt die Kosten der Vielfalt, um es mal neutral zu formulieren.

[TomT]

Hallo Klassisch,

deine Erkenntnisse sind klasse !

Schön das dein System wieder läuft und beim durchlesen dieses Threats bin ich meinem eigenen Problem wahrscheinlich auch auf die Schliche gekommen.

Seit dem letzten Armbian Update vor 2 Wochen hatte ich nämlich auch große Probleme, an meinen mit FAT32 gemounteten USB-Stick ranzukommen.

Das Verzeichnis in media war unter rootanmeldung angeblich nicht verfügbar, wollte ich mit mkdir das Verzeichnis neu anlegen, hat armbian bemotzt, es wäre schon vorhanden.

Strange :shock:

Werde die Tage mal schauen, was passiert, wenn ich den Stick ext4 formatiere und einbinde….

Danke für das teilen deiner Erfahrungen !

Grüße

Tom

[klassisch]

Viel Erfolg, keine Ahnung, ob es bei Dir ähnlich gelagert ist. Aber irgendetwas ist mit armbian und FAT32 passiert.

Mein System ist wieder seit 47h stabil.

BTW: Bei ali ist gerade wieder ein Sale. Man bekommt Kingdian SSD 32GB für <15EUR und die etwas performantere 60GB für <21EUR, Orico 20UT Adapter für 4,50EUR. Nicht, daß man eine solche Datenmenge in den nächsten Jahren brauchen würde, aber es soll sich kein Performance-Bottleneck auftun und ich war froh, noch eine Reserve da zu haben…

[klassisch]

So, nach update auf 1.8.5 ist das Problem wieder da! Alle paar Stunden startet history neu und hinteläßt Psudomesswerte und versaut die Messkurven:
Siehe Grüne Kurve. Tankinhalt wird nur einmal am Tang um 01:11 gemessen. Durch die sporadischen History-Neustarts werden unechte Messpunkte eingezeichnet und die Kurve verfälscht.
Was tun? Downgraden?
Log:

2019-03-09 21:39:30.544  - warn: history.0 Reconnection to DB.
2019-03-09 21:39:30.702  - warn: history.0 Reconnection to DB.
2019-03-09 21:39:30.862  - info: history.0 starting. Version 1.8.5 in /opt/iobroker/node_modules/iobroker.history, node: v6.14.3
2019-03-09 21:39:30.887  - info: history.0 starting. Version 1.8.5 in /opt/iobroker/node_modules/iobroker.history, node: v6.14.3
2019-03-09 21:39:31.846  - info: history.0 enabled logging of system.adapter.admin.0.uptime (Count=1), Alias=false
2019-03-09 21:39:31.848  - info: history.0 enabled logging of system.adapter.admin.0.memRss (Count=2), Alias=false
2019-03-09 21:39:31.849  - info: history.0 enabled logging of system.adapter.admin.0.memHeapTotal (Count=3), Alias=false
2019-03-09 21:39:31.850  - info: history.0 enabled logging of system.adapter.admin.0.memHeapUsed (Count=4), Alias=false
2019-03-09 21:39:31.850  - info: history.0 enabled logging of system.adapter.admin.0.connected (Count=5), Alias=false
2019-03-09 21:39:31.851  - info: history.0 enabled logging of system.adapter.admin.0.alive (Count=6), Alias=false
2019-03-09 21:39:31.851  - info: history.0 enabled logging of system.host.$__hostname__$.mem (Count=7), Alias=false
2019-03-09 21:39:31.852  - info: history.0 enabled logging of system.host.$__hostname__$.memHeapUsed (Count=8), Alias=false
2019-03-09 21:39:31.853  - info: history.0 enabled logging of system.host.$__hostname__$.memHeapTotal (Count=9), Alias=false
2019-03-09 21:39:31.853  - info: history.0 enabled logging of system.host.$__hostname__$.memRss (Count=10), Alias=false
2019-03-09 21:39:31.854  - info: history.0 enabled logging of system.host.$__hostname__$.uptime (Count=11), Alias=false
2019-03-09 21:39:31.855  - info: history.0 enabled logging of system.host.$__hostname__$.load (Count=12), Alias=false
2019-03-09 21:39:31.855  - info: history.0 enabled logging of system.host.$__hostname__$.alive (Count=13), Alias=false
2019-03-09 21:39:31.856  - info: history.0 enabled logging of hm-rpc.0.updated (Count=14), Alias=false
2019-03-09 21:39:31.857  - info: history.0 enabled logging of system.adapter.hm-rpc.0.uptime (Count=15), Alias=false
2019-03-09 21:39:31.858  - info: history.0 enabled logging of system.adapter.hm-rpc.0.memRss (Count=16), Alias=false
2019-03-09 21:39:31.858  - info: history.0 enabled logging of system.adapter.hm-rpc.0.memHeapTotal (Count=17), Alias=false
2019-03-09 21:39:31.859  - info: history.0 enabled logging of system.adapter.hm-rpc.0.memHeapUsed (Count=18), Alias=false
2019-03-09 21:39:31.859  - info: history.0 enabled logging of system.adapter.hm-rpc.0.connected (Count=19), Alias=false
2019-03-09 21:39:31.860  - info: history.0 enabled logging of system.adapter.hm-rpc.0.alive (Count=20), Alias=false
2019-03-09 21:39:31.860  - info: history.0 enabled logging of system.adapter.hm-rega.0.uptime (Count=21), Alias=false
2019-03-09 21:39:31.861  - info: history.0 enabled logging of system.adapter.hm-rega.0.memRss (Count=22), Alias=false
2019-03-09 21:39:31.861  - info: history.0 enabled logging of system.adapter.hm-rega.0.memHeapTotal (Count=23), Alias=false
2019-03-09 21:39:31.862  - info: history.0 enabled logging of system.adapter.hm-rega.0.memHeapUsed (Count=24), Alias=false
2019-03-09 21:39:31.863  - info: history.0 enabled logging of system.adapter.hm-rega.0.connected (Count=25), Alias=false
2019-03-09 21:39:31.863  - info: history.0 enabled logging of system.adapter.hm-rega.0.alive (Count=26), Alias=false
2019-03-09 21:39:31.864  - info: history.0 enabled logging of system.adapter.web.0.uptime (Count=27), Alias=false
2019-03-09 21:39:31.864  - info: history.0 enabled logging of system.adapter.web.0.memRss (Count=28), Alias=false
2019-03-09 21:39:31.865  - info: history.0 enabled logging of system.adapter.web.0.memHeapTotal (Count=29), Alias=false
2019-03-09 21:39:31.865  - info: history.0 enabled logging of system.adapter.web.0.memHeapUsed (Count=30), Alias=false
2019-03-09 21:39:31.866  - info: history.0 enabled logging of system.adapter.web.0.connected (Count=31), Alias=false
2019-03-09 21:39:31.866  - info: history.0 enabled logging of system.adapter.web.0.alive (Count=32), Alias=false
2019-03-09 21:39:31.867  - info: history.0 enabled logging of hm-rpc.0.BidCoS-RF.0.INSTALL_MODE (Count=33), Alias=false
2019-03-09 21:39:31.868  - info: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.LEVEL (Count=34), Alias=false
2019-03-09 21:39:31.868  - info: history.0 enabled logging of hm-rpc.0.BidCoS-RF.1.PRESS_LONG (Count=35), Alias=false

[klassisch]

Der Vollständigkeit halber:
Nach Umstieg auf eine Windows-Notebook alles gut. Der hat genügend Rechenleistung und Bandbreite.
Aber bei der Sichtung der Datenmengen bin ich auf die wahrscheinliche Ursache gestoßen:

• Februar 2019 habe ich alle Datenpunkte in History abonniert, um History zu vervollständigen. Nichts ungewöhnliches an sich.
• Dabei war aber anscheinend die Expertenansicht aktiviert. Und das sollte man bei einer solchen Aktion nicht machen.
• Dadurch wurden auch alle system.adapter. Datenpunkte abonniert. Waen nicht sehr viele, knapp unter 300. Aber die werden sehr häufig geschrieben, so daß jeder Datenpunkt täglich ca. 400kB bis 500kB (für mich nutzlose) Daten und damit den zugehörigen Traffic erzeugt. Dadurch hat sich auch mein tägliches Datenvolumen (für mich) sinnlos verfünffacht. Diesem Daten(raten)-Aufkommen war der OPi nicht wirklich gewachsen.
  Wie gesagt mit einem ordentlichen Windows Notebook kein Problem aber auch da für mich unnötig.