[gelöst] Iobroker Deamon stoppt laufend - nach JS Update

[Homoran]

hast du auch mal unter /opt/iobroker/logs nachgesehen?

da liegen die vollständigen logs der letzten 7 Tage.

Gruß

Rainer

[Bradock]

Danke Rainer,

hier mal ein Auszug aus dem Log um diese Zeit
2009_log_extrakt.txt

[Homoran]

leider fehlt auch hier die Zeit vor dem Absturz des harmony. Es beginnt erst wieder mit js-controller starting….

Allerdings scheinst du einige Adapter doppelt laufen zu haben, u.a. den admin!

Mach mal einen reboot vom Raspi

Gruß

Rainer

[Bradock]

Das mit doppelten Adaptern täuscht.

Siehe uneten Adapterübersicht.

Nur Cloud habe ich 2x, jedoch nur 1x aktiv

im angehängten Log habe ich noch die Zeilen vor dem Absturz rein (und App Key gelöscht)
2009_log_extrakt.txt
2009_adapter.png

[apollon77]

Naja erste Frage: Läuft es denn Stabil wenn harmony aus ist?

[Bradock]

Dieser Test läuft seit 5 Minuten.

Komisch ist nur, dass all das erst nach dem JS Upgrade instabil wurde.

Kann der Sprung zu groß gewesen sein von 0.15.3 auf 1.20.0?

Gesendet von iPhone mit Tapatalk Pro

[apollon77]

Ist der ganze Rest auch aktuell? Also Admin, web, cloud und so? und js-controller?

Und ggf mal harmony vom Github versuchen das es auch wirklich die aktuellste Version ist.

[Bradock]

Ich hatte heute einen funktionierenden Snapshot meiner VM (vor einigen Adapterupdates und dem JS Upgrade) wiederhergestellt.

Danach wieder alles aktualisiert. Erst nach dem JS Upgrade kam der automatische Absturz der Instanz wieder.

Vielleicht beißt sich irgendeine Kombi aus Adapter und JS….

Schwierig, vor allem da der WAF gerade massiv zurück geht [emoji1]

Gesendet von iPhone mit Tapatalk Pro

[Homoran]

@Bradock:

Das mit doppelten Adaptern täuscht. `
Das habe ich so nicht gesagt, ich meine nicht doppelte Instanzen, sondern dass die selbe Instanz doppelt läuft, also zwei Prozesse hat.

host.IoBroker instance system.adapter.hm-rpc.0 terminated with code 7 (Adapter already running)
host.IoBroker instance system.adapter.hm-rega.0 terminated with code 7 (Adapter already running)
host.IoBroker instance system.adapter.javascript.0 terminated with code 7 (Adapter already running)

Gruß

Rainer

[apollon77]

Nochmal gefragt (weil nicht beantwortet): Ist der ganze Rest auch aktuell? Also Admin, web, cloud und so? und js-controller?

Wenn Javascript so alt ist kann man durchaus annehmen das einige andere Updates auch fehlen.

[Bradock]

Hallo Rainer,

ich hatte schon vermutet das Du das meinst.

Mir kommt es auch seltsam vor, aber es wirkt so, als wenn beim Startprozess des Iobrokers Instanzen gestartet werden und danach nochmals versucht werden zu starten.

Diese Fehlermeldungen hatte ich auch gesehen, sie mir jedoch nicht erklären können.

Wie gesagt:

Es läuft eine VM mit einem IoBroker und auch keine doppelten Adapter (zumindest wüsste ich das nicht)

[Bradock]

@apollon77:

Nochmal gefragt (weil nicht beantwortet): Ist der ganze Rest auch aktuell? Also Admin, web, cloud und so? und js-controller?

Wenn Javascript so alt ist kann man durchaus annehmen das einige andere Updates auch fehlen. `
Hallo Apollon

Javascript ist auf der im IoBroker freigegebenen Version 3.4.0

Vielleicht zeigte das Log noch den Adapter "vor den Updates"

Mittlerweile sind alle Adapter auf dem hinterlegten, neusten Stand. (nicht zwingend von GIT, sondern die in Io offerierten)

[Homoran]

@Bradock:

aber es wirkt so, als wenn beim Startprozess des Iobrokers Instanzen gestartet werden und danach nochmals versucht werden zu starten.

Diese Fehlermeldungen hatte ich auch gesehen, sie mir jedoch nicht erklären können. `
Das passiert manchmal, wenn vor /während des Updates die Instanz nicht vollständig gestoppt wurde. Nach dem Update startet die SELBE Instanz dann zum zweiten mal.

Da hilft nur ein Reboot, oder ein händisches KILL (ggf -9) der doppelten Prozesse über die Konsole.

Gruß

Rainer

[Bradock]

Habe jetzt zur Sicherheit einen Reboot der VM gemacht und von GIT den Harmony Adapter geholt (alt: 0.70 / jetzt: 0.71)

Ich beobachte weiter.

Nebenbei an alle die hier so eifrig versuchen zu helfen schon mal vielen Dank zwischendrin!

Gesendet von iPhone mit Tapatalk Pro

[Bradock]

So….hier mal ein Update....

IoBroker Log unter /opt/iobroker/logs

! 2017-10-16 14:00:27.320 - [33mwarn[39m: harmony.0 lost Harmony Hub
! 2017-10-16 14:00:27.320 - [32minfo[39m: harmony.0 client ended: Harmony_Hub
! 2017-10-16 14:00:31.129 - [32minfo[39m: harmony.0 keep alive failed: Error: Timed out after 5000 ms
! 2017-10-16 14:00:41.214 - [33mwarn[39m: harmony.0 could not connect to Harmony Hub: Error: Timed out after 5000 ms
! 2017-10-16 14:00:54.373 - [32minfo[39m: harmony.0 discovered Harmony Hub
! 2017-10-16 14:00:54.387 - [32minfo[39m: harmony.0 connecting to Harmony Hub
! 2017-10-16 14:00:57.940 - [32minfo[39m: harmony.0 connected to Harmony Hub
! 2017-10-16 14:00:59.156 - [32minfo[39m: harmony.0 synced hub config
! 2017-10-16 14:01:57.521 - [33mwarn[39m: harmony.0 lost Harmony Hub
! 2017-10-16 14:01:57.521 - [32minfo[39m: harmony.0 client ended: Harmony_Hub
! 2017-10-16 14:01:58.641 - [32minfo[39m: harmony.0 discovered Harmony Hub
! 2017-10-16 14:02:05.750 - [32minfo[39m: harmony.0 connecting to Harmony Hub
! 2017-10-16 14:02:08.071 - [32minfo[39m: harmony.0 connected to Harmony Hub
! 2017-10-16 14:02:09.394 - [32minfo[39m: harmony.0 synced hub config
! 2017-10-16 14:03:00.044 - [32minfo[39m: host.IoBroker instance system.adapter.dwd.0 started with pid 1460
! 2017-10-16 14:03:00.433 - [32minfo[39m: dwd.0 starting. Version 2.1.1 in /opt/iobroker/node_modules/iobroker.dwd, node: v4.7.2
! 2017-10-16 14:03:01.175 - [32minfo[39m: host.IoBroker instance system.adapter.dwd.0 terminated with code 0 (OK)
! 2017-10-16 14:21:42.881 - [32minfo[39m: harmony.0 keep alive failed: Error: Timed out after 5000 ms
! 2017-10-16 14:21:42.882 - [32minfo[39m: harmony.0 client ended: Harmony_Hub
! 2017-10-16 14:21:44.806 - [33mwarn[39m: harmony.0 lost Harmony Hub
! 2017-10-16 14:22:26.223 - [32minfo[39m: harmony.0 discovered Harmony Hub[/spoiler]

Das Log im Admin hingegen hat den letzten Eintrag um 13:43 (siehe Bild)

Irgendwo dazwischen hat IoBroker wieder gestoppt.

Der Harmony-Adapter, welcher mir die Warnings erzeugt, bleibt jetzt erst mal ganz aus!

Ratlosigkeit geht weiter….

[Bradock]

Update 17:40

Ohne Harmony Adapter sah es erst gut aus.

ABER…

a) Wenn ich VIS im Browser am PC offen habe, lösen View-Wechsel kein Problem aus.

b) Am Tablet (mit Vis App) löste soeben ein View-Wechsel wieder einen Absturz des Iobroker Dienstes aus.

Somit sehe ich keine direkte Abhängigkeit vom Harmony Adapter und denke gerade darüber nach ob das VIS Update hier etwas ausgelöst hat.

Alles sehr seltsam.

Habt ihr ähnliche Abstürze oder Probleme mit VIS?

[Bradock]

So… mal wieder ein Update.

heute Morgen hat sich der IoBroker Deamon wieder selbst gestoppt.

Das Log zeigt folgendes:

! ````
host.IoBroker 2017-10-20 09:11:09.005 info instance system.adapter.admin.0 started with pid 7853
host.IoBroker 2017-10-20 09:11:08.932 info starting 19 instances
host.IoBroker 2017-10-20 09:11:08.928 info 28 instances found
host.IoBroker 2017-10-20 09:11:08.920 info InMemoryDB connected
host.IoBroker 2017-10-20 09:11:08.897 info inMem-objects listening on port 9001
host.IoBroker 2017-10-20 09:11:08.427 info inMem-states listening on port 9000
host.IoBroker 2017-10-20 09:11:00.024 info ip addresses: 192.168.0.13 fe80::20c:29ff:fea7:e65a
host.IoBroker 2017-10-20 09:11:00.023 info hostname: IoBroker, node: v4.7.2
host.IoBroker 2017-10-20 09:11:00.023 info Copyright (c) 2014-2017 bluefox, hobbyquaker
host.IoBroker 2017-10-20 09:11:00.021 info iobroker.js-controller version 1.2.0 js-controller starting
web.0 2017-10-20 09:10:41.353 info 2017-10-20T07:10:41.353Z Connected system.user.admin
harmony.0 2017-10-20 09:10:33.582 info discovered Harmony Hub
harmony.0 2017-10-20 09:09:49.132 warn lost Harmony Hub
web.0 2017-10-20 09:08:41.349 info 2017-10-20T07:08:41.349Z Connected system.user.admin
web.0 2017-10-20 09:08:41.347 info 2017-10-20T07:08:41.347Z Connected system.user.admin
web.0 2017-10-20 09:06:41.341 info 2017-10-20T07:06:41.341Z Connected system.user.admin
web.0 2017-10-20 09:06:41.340 info 2017-10-20T07:06:41.340Z Connected system.user.admin
web.0 2017-10-20 09:04:41.334 info 2017-10-20T07:04:41.334Z Connected system.user.admin
web.0 2017-10-20 09:04:41.332 info 2017-10-20T07:04:41.332Z Connected system.user.admin
web.0 2017-10-20 09:02:41.326 info 2017-10-20T07:02:41.326Z Connected system.user.admin
web.0 2017-10-20 09:02:41.324 info 2017-10-20T07:02:41.324Z Connected system.user.admin
web.0 2017-10-20 09:00:41.317 info 2017-10-20T07:00:41.317Z Connected system.user.admin
web.0 2017-10-20 09:00:41.316 info 2017-10-20T07:00:41.316Z Connected system.user.admin
web.0 2017-10-20 08:58:41.309 info 2017-10-20T06:58:41.309Z Connected system.user.admin
web.0 2017-10-20 08:58:41.309 info 2017-10-20T06:58:41.308Z Connected system.user.admin
harmony.0 2017-10-20 08:56:59.925 info discovered Harmony Hub
web.0 2017-10-20 08:56:41.304 info 2017-10-20T06:56:41.304Z Connected system.user.admin
web.0 2017-10-20 08:56:41.303 info 2017-10-20T06:56:41.303Z Connected system.user.admin
harmony.0 2017-10-20 08:56:33.929 warn lost Harmony Hub
web.0 2017-10-20 08:54:41.296 info 2017-10-20T06:54:41.296Z Connected system.user.admin
web.0 2017-10-20 08:54:41.295 info 2017-10-20T06:54:41.295Z Connected system.user.admin
web.0 2017-10-20 08:52:41.289 info 2017-10-20T06:52:41.289Z Connected system.user.admin
web.0 2017-10-20 08:52:41.289 info 2017-10-20T06:52:41.289Z Connected system.user.admin
web.0 2017-10-20 08:50:41.281 info 2017-10-20T06:50:41.281Z Connected system.user.admin
web.0 2017-10-20 08:50:41.280 info 2017-10-20T06:50:41.280Z Connected system.user.admin
web.0 2017-10-20 08:48:41.274 info 2017-10-20T06:48:41.274Z Connected system.user.admin
web.0 2017-10-20 08:48:41.273 info 2017-10-20T06:48:41.273Z Connected system.user.admin
web.0 2017-10-20 08:46:41.266 info 2017-10-20T06:46:41.266Z Connected system.user.admin
web.0 2017-10-20 08:46:41.265 info 2017-10-20T06:46:41.265Z Connected system.user.admin
web.0 2017-10-20 08:44:41.259 info 2017-10-20T06:44:41.258Z Connected system.user.admin
web.0 2017-10-20 08:44:41.257 info 2017-10-20T06:44:41.257Z Connected system.user.admin
web.0 2017-10-20 08:42:41.250 info 2017-10-20T06:42:41.250Z Connected system.user.admin
web.0 2017-10-20 08:42:41.250 info 2017-10-20T06:42:41.250Z Connected system.user.admin
web.0 2017-10-20 08:40:41.245 info 2017-10-20T06:40:41.245Z Connected system.user.admin
web.0 2017-10-20 08:40:41.244 info 2017-10-20T06:40:41.244Z Connected system.user.admin
harmony.0 2017-10-20 08:39:27.539 info discovered Harmony Hub
harmony.0 2017-10-20 08:38:53.759 warn lost Harmony Hub
web.0 2017-10-20 08:38:41.237 info 2017-10-20T06:38:41.237Z Connected system.user.admin
web.0 2017-10-20 08:38:41.236 info 2017-10-20T06:38:41.236Z Connected system.user.admin
web.0 2017-10-20 08:36:41.229 info 2017-10-20T06:36:41.229Z Connected system.user.admin
web.0 2017-10-20 08:36:41.228 info 2017-10-20T06:36:41.228Z Connected system.user.admin
web.0 2017-10-20 08:34:41.220 info 2017-10-20T06:34:41.220Z Connected system.user.admin
web.0 2017-10-20 08:34:41.219 info 2017-10-20T06:34:41.219Z Connected system.user.admin
web.0 2017-10-20 08:32:41.215 info 2017-10-20T06:32:41.215Z Connected system.user.admin
web.0 2017-10-20 08:32:41.215 info 2017-10-20T06:32:41.215Z Connected system.user.admin
web.0 2017-10-20 08:30:41.210 info 2017-10-20T06:30:41.210Z Connected system.user.admin
web.0 2017-10-20 08:30:41.209 info 2017-10-20T06:30:41.209Z Connected system.user.admin
web.0 2017-10-20 08:28:41.205 info 2017-10-20T06:28:41.205Z Connected system.user.admin
web.0 2017-10-20 08:28:41.204 info 2017-10-20T06:28:41.204Z Connected system.user.admin
harmony.0 2017-10-20 08:26:55.670 info discovered Harmony Hub
web.0 2017-10-20 08:26:41.199 info 2017-10-20T06:26:41.199Z Connected system.user.admin
web.0 2017-10-20 08:26:41.198 info 2017-10-20T06:26:41.198Z Connected system.user.admin
harmony.0 2017-10-20 08:26:13.577 warn lost Harmony Hub
web.0 2017-10-20 08:24:41.193 info 2017-10-20T06:24:41.193Z Connected system.user.admin
web.0 2017-10-20 08:24:41.192 info 2017-10-20T06:24:41.192Z Connected system.user.admin
web.0 2017-10-20 08:22:41.188 info 2017-10-20T06:22:41.187Z Connected system.user.admin
web.0 2017-10-20 08:22:41.187 info 2017-10-20T06:22:41.187Z Connected system.user.admin
web.0 2017-10-20 08:20:41.182 info 2017-10-20T06:20:41.182Z Connected system.user.admin
web.0 2017-10-20 08:20:41.181 info 2017-10-20T06:20:41.181Z Connected system.user.admin
web.0 2017-10-20 08:18:41.177 info 2017-10-20T06:18:41.177Z Connected system.user.admin
web.0 2017-10-20 08:18:41.176 info 2017-10-20T06:18:41.176Z Connected system.user.admin
web.0 2017-10-20 08:16:41.170 info 2017-10-20T06:16:41.170Z Connected system.user.admin
web.0 2017-10-20 08:16:41.169 info 2017-10-20T06:16:41.169Z Connected system.user.admin
web.0 2017-10-20 08:14:41.164 info 2017-10-20T06:14:41.164Z Connected system.user.admin
web.0 2017-10-20 08:14:41.164 info 2017-10-20T06:14:41.164Z Connected system.user.admin
harmony.0 2017-10-20 08:14:23.391 info discovered Harmony Hub
harmony.0 2017-10-20 08:13:53.465 warn lost Harmony Hub
web.0 2017-10-20 08:12:41.157 info 2017-10-20T06:12:41.156Z Connected system.user.admin
web.0 2017-10-20 08:12:41.155 info 2017-10-20T06:12:41.155Z Connected system.user.admin
web.0 2017-10-20 08:10:41.149 info 2017-10-20T06:10:41.149Z Connected system.user.admin
web.0 2017-10-20 08:10:41.147 info 2017-10-20T06:10:41.147Z Connected system.user.admin
harmony.0 2017-10-20 08:09:22.616 info discovered Harmony Hub
harmony.0 2017-10-20 08:08:48.411 warn lost Harmony Hub
web.0 2017-10-20 08:08:41.142 info 2017-10-20T06:08:41.142Z Connected system.user.admin
web.0 2017-10-20 08:08:41.141 info 2017-10-20T06:08:41.141Z Connected system.user.admin
web.0 2017-10-20 08:06:41.135 info 2017-10-20T06:06:41.135Z Connected system.user.admin
web.0 2017-10-20 08:06:41.134 info 2017-10-20T06:06:41.134Z Connected system.user.admin
web.0 2017-10-20 08:04:41.131 info 2017-10-20T06:04:41.131Z Connected system.user.admin
web.0 2017-10-20 08:04:41.131 info 2017-10-20T06:04:41.131Z Connected system.user.admin
web.0 2017-10-20 08:04:41.130 info 2017-10-20T06:04:41.130Z Connected system.user.admin
web.0 2017-10-20 08:04:41.130 info 2017-10-20T06:04:41.130Z Connected system.user.admin
web.0 2017-10-20 08:04:41.129 info 2017-10-20T06:04:41.129Z Connected system.user.admin
web.0 2017-10-20 08:04:41.125 info 2017-10-20T06:04:41.124Z Connected system.user.admin

Ab 8.04 Uhr gingen massiv viele Meldungen vom Web0 ins Log

Gegen 9.08 Uhr war er dann aus und ich musste den Deamon wieder neu starten was etwa gegen 09.09 Uhr war.

Habt ihr Ideen zu den Auslösern?

Harmony Adapter habe ich ja am WE schon ausschließen können.

Danke vorab!

Gruß Sascha

[apollon77]

Scheinbar kommen parallele Requests an. Das sagen die Logs. Und am Ende ist ja hier zu sehen das der js-controller weg ist und neu gestartet wird.

Gibt es irgendwas in den Systemlogs? Wurden vllt vom OS Prozesse gekillt weil SIe zuviel Speicher gebraucht haben?

[Bradock]

Ich hatte die Logs im Admin und unter /iobroker/Logs verglichen. Zeigen beide das gleiche an. Der VM stehen 4Gb RAM zur Verfügung. Sollte das nicht reichen?

Die Anzahl der Clients welche via Browser oder VIS App zugreifen wird hier ja hoffentlich keine Rolle spielen, oder?

Gesendet von iPhone mit Tapatalk Pro

[apollon77]

@Bradock:

Der VM stehen 4Gb RAM zur Verfügung. Sollte das nicht reichen? `
Deine VM sagt "Access denied" zu meinem User "Glaskugel" … Keine Ahnung was die VM alles noch macht.

Du musst schauen was ggf zum Zeitpunkt der Probleme im System los war.

@Bradock:

Die Anzahl der Clients welche via Browser oder VIS App zugreifen wird hier ja hoffentlich keine Rolle spielen, oder? `
Indirekt schon. Und je nachdem was Sie tun. Wenn Flot Diagramme hast die aus History Daten abholen dann kann durchaus kurzfristig Bedarf an CPU, I/O und/oder RAM sein und wnen zuviel parallel läuft …