[erledigt] hm-rpc verliert auf einmal verbindung -> debugging?

adarof

Hallo

Ich habe davor Wochenlang nichts geändert ... (jaja, das sagen die DAUs immer ... aber ist wirklich so. Keine HW Änderungen und keine Programmierungsänderungen auf CCU oder ioBroker) ... und dann das:

Freitag fing es an: Plötzlich bekam ich von meiner Verbindungsüberwachung alle paar Stunden 4-5 Mails (d.h. immer so Anhäufungen), dass die Verbindung hm-rpc->CCU2 abgerissen ist.
Das Skript sieht so aus:

Die Meldungen im ioBroker Log so (hm-rpc.0 = CuxD und hm.rpc1 = "Wireless"; RoofServer = iorbroker (früher Raspi, nun NUC); 192.168.66.111 = CCU2):

2019-03-19 03:00:03.727 - error: host.RoofServer instance system.adapter.daswetter.0 terminated with code 11 ()
2019-03-19 03:02:00.115 - info: host.RoofServer instance system.adapter.ical.0 started with pid 5189
2019-03-19 03:02:09.066 - info: host.RoofServer instance system.adapter.ical.0 terminated with code 0 (OK)
2019-03-19 03:03:52.470 - error: hm-rpc.0 Ping error: Error: response timeout
2019-03-19 03:03:52.470 - info: hm-rpc.0 Disconnected
2019-03-19 03:04:14.906 - error: hm-rpc.1 Ping error: Error: response timeout
2019-03-19 03:04:14.907 - info: hm-rpc.1 Disconnected
2019-03-19 03:04:14.909 - warn: javascript.0 script.js.MailOnCCUConnectionLost: email: Io Broker hat die Verbindung mit der CCU verloren
2019-03-19 03:04:14.932 - info: email.0 Send email: {"text":"Io Broker hat die Verbindung mit der CCU verloren","to":"XXXXMailADr","subject":"io Broker Lost CCU Connection!","from":"IoBroker "}
2019-03-19 03:04:16.957 - info: email.0 sent to iobroker@hmersch.de
2019-03-19 03:04:27.478 - error: hm-rpc.0 init error: Error: response timeout
2019-03-19 03:04:49.914 - error: hm-rpc.1 init error: Error: response timeout
2019-03-19 03:04:57.478 - error: hm-rpc.0 init error: Error: response timeout
2019-03-19 03:05:00.019 - info: host.RoofServer instance system.adapter.dwd.0 started with pid 5248
2019-03-19 03:05:01.628 - info: host.RoofServer instance system.adapter.dwd.0 terminated with code 0 (OK)
2019-03-19 03:05:19.919 - error: hm-rpc.1 init error: Error: response timeout
2019-03-19 03:05:27.489 - error: hm-rpc.0 init error: Error: response timeout
2019-03-19 03:05:49.923 - error: hm-rpc.1 init error: Error: response timeout
2019-03-19 03:05:57.490 - error: hm-rpc.0 init error: Error: response timeout
2019-03-19 03:06:18.978 - error: hm-rega.0 post request error: connect ETIMEDOUT 192.168.66.111:8181
2019-03-19 03:06:18.979 - error: hm-rega.0 CCU 192.168.66.111 unreachable
2019-03-19 03:06:19.924 - error: hm-rpc.1 init error: Error: response timeout
2019-03-19 03:06:27.496 - error: hm-rpc.0 init error: Error: response timeout
2019-03-19 03:06:49.924 - error: hm-rpc.1 init error: Error: response timeout
2019-03-19 03:06:57.498 - error: hm-rpc.0 init error: Error: response timeout
2019-03-19 03:07:19.930 - error: hm-rpc.1 init error: Error: response timeout

Was mir am Log auffällt:
~~- ErsteZeile habe ich daswetter-Adapter mit kopiert ... das schlägt nämlich auch auffallend häufig (aber nicht immer) fehl. Ist das normal? Oder deutet das auch auf ein Netzwerkproblem bei mir hin?~~ Scheint ein bekanntes Problem hab ich hier gefunden https://forum.iobroker.net/topic/20173/probleme-mit-daswetter-adapter

ansonsten scheint auch das Netzwerk zur CCU komplett weg zu sein; dwd tut aber ....
ich habe parallel mal eine SSH Session aufgemacht von iobroker -> CCU2. Diese überlebt das alles aber!

Okay, Umzug von Raspi auf NUC stand eh an, da der Raspi an der Kotzgrenze vom RAM her war... allerdings das gleiche Verhalten auch vom NUC aus.
Okay, dann wohl der (Managed) Switch defekt? Austausch gegen uralt-Switch:
Besserung, aber immernoch 3 Verbindungsabbrüche heute. Also noch keine End-Lösung.

Habt Ihr da noch eine Idee?
--> Kann ich dem/den hm-rpc mehr Infos entlocken auf welche Art und Weise die Verbindugn abgerissen ist? Oder kann ich sehen ob auf der CCU2 der Prozess (welcher?) gelegentlich abschmiert und neu gestartet wird?
--> Kann ich Netzwerk/tcp-Probleme irgendwie mitloggen ohne mit WIreshark o.ä. riesige Datenmengen aufzubauen, die ja vom ioBroker->CCU durchaus anfallen.

Gruss -

Edit: daswetter ist hinfällig als weiterer Indiz für Netzerkprobleme -> gestrichen

sigi234

@adarof sagte in hm-rpc verliert auf einmal verbindung -> debugging?:

Kann ich dem/den hm-rpc mehr Infos entlocken auf welche Art und Weise die Verbindugn abgerissen ist?

Hast du Ihn auf debug gestellt?

adarof

jetzt schon, danke, ...dann warte ich mal auf das nächste vorkommnis

wendy2702

@adarof sagte in hm-rpc verliert auf einmal verbindung -> debugging?:

Die Meldungen im ioBroker Log so (hm-rpc.0 = CuxD und hm.rpc1 = "Wireless"

Was genau bedeutet denn das?

Ist irgendwas per WLAN verbunden?

adarof

@wendy2702 Nein, alles LAN.
Das "wireless" steht bei mir im Adapter-Bezeichnung:

Gruss -

adarof

Hallo

Hier einmal ein beispielhafter Verbindungsabbruch.
Hat dazu jemand eine Idee? Eher Netzwerk oder stürzt doch etwas auf der CCU ab und wird neugestartet?

Die DB Fehler machen wir auch etwas Sorgen - kommt das von meinem Umzug von Raspi->NUC?

192.168.66.111 = CCU2
192.168.66.75 = NUC mit ioBroker

Gruss

2019-03-20 01:33:24.054 - debug: hm-rpc.0 [KEEPALIVE] Check if connection is alive
2019-03-20 01:33:24.055 - debug: hm-rpc.0 Send PING...
2019-03-20 01:33:24.061 - debug: hm-rpc.0 PING ok
2019-03-20 01:33:24.068 - debug: hm-rpc.0 bin multicall : CUxD,CENTRAL,PONG,hm-rpc.0
2019-03-20 01:33:24.068 - debug: hm-rpc.0 binrpc <- event ["CUxD","CENTRAL","PONG","hm-rpc.0"]
2019-03-20 01:33:24.068 - debug: hm-rpc.0 hm-rpc.0.CENTRAL.PONG ==> UNIT: "none" (min: none, max: none) From "hm-rpc.0" => "hm-rpc.0"
2019-03-20 01:34:54.062 - debug: hm-rpc.0 [KEEPALIVE] Check if connection is alive
2019-03-20 01:34:54.062 - debug: hm-rpc.0 Send PING...
2019-03-20 01:34:54.067 - debug: hm-rpc.0 PING ok
2019-03-20 01:34:54.077 - debug: hm-rpc.0 bin multicall : CUxD,CENTRAL,PONG,hm-rpc.0
2019-03-20 01:34:54.078 - debug: hm-rpc.0 binrpc <- event ["CUxD","CENTRAL","PONG","hm-rpc.0"]
2019-03-20 01:34:54.078 - debug: hm-rpc.0 hm-rpc.0.CENTRAL.PONG ==> UNIT: "none" (min: none, max: none) From "hm-rpc.0" => "hm-rpc.0"
2019-03-20 01:35:00.018 - info: host.RoofServer instance system.adapter.dwd.0 started with pid 31693
2019-03-20 01:35:01.637 - info: host.RoofServer instance system.adapter.dwd.0 terminated with code 0 (OK)
2019-03-20 01:36:15.926 - error: hm-rpc.1 Ping error: Error: response timeout
2019-03-20 01:36:15.926 - info: hm-rpc.1 Disconnected
2019-03-20 01:36:15.928 - warn: javascript.0 script.js.MailOnCCUConnectionLost: email: Io Broker hat die Verbindung mit der CCU verloren
2019-03-20 01:36:15.955 - info: email.0 Send email: {"text":"Io Broker hat die Verbindung mit der CCU verloren","to":"XXXX","subject":"io Broker Lost CCU Connection!","from":"IoBroker "}
2019-03-20 01:36:18.345 - info: email.0 sent to iobroker@hmersch.de
2019-03-20 01:36:24.070 - debug: hm-rpc.0 [KEEPALIVE] Check if connection is alive
2019-03-20 01:36:24.070 - debug: hm-rpc.0 Send PING...
2019-03-20 01:36:29.070 - error: hm-rpc.0 Ping error: Error: response timeout
2019-03-20 01:36:29.071 - info: hm-rpc.0 Disconnected
2019-03-20 01:36:29.071 - debug: hm-rpc.0 Connect...
2019-03-20 01:36:29.071 - debug: hm-rpc.0 clear ping interval
2019-03-20 01:36:29.071 - debug: hm-rpc.0 start connecting interval
2019-03-20 01:36:50.938 - error: hm-rpc.1 init error: Error: response timeout
2019-03-20 01:36:59.073 - debug: hm-rpc.0 binrpc -> 192.168.66.111:8701/ init ["xmlrpc_bin://192.168.66.75:18701","hm-rpc.0"]
2019-03-20 01:37:04.074 - error: hm-rpc.0 init error: Error: response timeout
2019-03-20 01:37:20.943 - error: hm-rpc.1 init error: Error: response timeout
2019-03-20 01:37:29.078 - debug: hm-rpc.0 binrpc -> 192.168.66.111:8701/ init ["xmlrpc_bin://192.168.66.75:18701","hm-rpc.0"]
2019-03-20 01:37:34.082 - error: hm-rpc.0 init error: Error: response timeout
2019-03-20 01:37:35.202 - error: hm-rega.0 post request error: connect ETIMEDOUT 192.168.66.111:8181
2019-03-20 01:37:35.202 - error: hm-rega.0 CCU 192.168.66.111 unreachable
2019-03-20 01:37:38.731 - info: hm-rpc.1 Connected
2019-03-20 01:37:59.090 - debug: hm-rpc.0 binrpc -> 192.168.66.111:8701/ init ["xmlrpc_bin://192.168.66.75:18701","hm-rpc.0"]
2019-03-20 01:38:01.847 - info: hm-rpc.1 binrpc <- system.listMethods ["hm-rpc.1"]
2019-03-20 01:38:01.860 - info: hm-rpc.1 binrpc <- listDevices ["hm-rpc.1"]
2019-03-20 01:38:01.885 - info: hm-rpc.1 binrpc -> 361 devices
2019-03-20 01:38:04.094 - error: hm-rpc.0 init error: Error: response timeout
2019-03-20 01:38:05.373 - info: hm-rega.0 ReGaHSS 192.168.66.111 up
2019-03-20 01:38:05.396 - info: hm-rega.0 time difference local-ccu 0s
2019-03-20 01:38:05.432 - info: hm-rega.0 added/updated 1 favorites to enum.favorites
2019-03-20 01:38:05.540 - info: hm-rega.0 added/updated functions to enum.functions
2019-03-20 01:38:05.637 - info: hm-rega.0 added/updated rooms to enum.rooms
2019-03-20 01:38:06.654 - info: hm-rega.0 got 101 programs
2019-03-20 01:38:06.750 - info: hm-rega.0 added/updated 101 programs
2019-03-20 01:38:06.750 - info: hm-rega.0 deleted 0 programs
2019-03-20 01:38:06.765 - info: hm-rega.0 got 104 variables
2019-03-20 01:38:07.084 - info: hm-rega.0 added/updated 104 variables
2019-03-20 01:38:07.084 - info: hm-rega.0 deleted 0 variables
2019-03-20 01:38:07.084 - info: hm-rega.0 request state values
2019-03-20 01:38:08.093 - error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(222, 2019000, 20.7, 1, 8, 0);: Error: ER_DUP_ENTRY: Duplicate entry '222-2019000' for key 'PRIMARY'
2019-03-20 01:38:08.095 - error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(73, 2019000, -45, 1, 8, 0);: Error: ER_DUP_ENTRY: Duplicate entry '73-2019000' for key 'PRIMARY'
2019-03-20 01:38:08.096 - error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(72, 2019000, 34, 1, 8, 0);: Error: ER_DUP_ENTRY: Duplicate entry '72-2019000' for key 'PRIMARY'
2019-03-20 01:38:08.303 - info: hm-rega.0 got state values
2019-03-20 01:38:14.129 - info: hm-rpc.0 Connected
2019-03-20 01:38:14.130 - debug: hm-rpc.0 clear connecting interval
2019-03-20 01:38:14.130 - debug: hm-rpc.0 start ping interval
2019-03-20 01:38:14.130 - debug: hm-rpc.0 bin multicall : CUxD,CENTRAL,PONG,hm-rpc.0
2019-03-20 01:38:14.130 - debug: hm-rpc.0 binrpc <- event ["CUxD","CENTRAL","PONG","hm-rpc.0"]
2019-03-20 01:38:14.130 - debug: hm-rpc.0 hm-rpc.0.CENTRAL.PONG ==> UNIT: "none" (min: none, max: none) From "hm-rpc.0" => "hm-rpc.0"
2019-03-20 01:39:44.144 - debug: hm-rpc.0 [KEEPALIVE] Check if connection is alive
2019-03-20 01:39:44.144 - debug: hm-rpc.0 Send PING...
2019-03-20 01:39:44.151 - debug: hm-rpc.0 PING ok

wendy2702

Nicht so leicht zu sagen.

Installier doch mal den Ping Adapter, Ping zur CCU und zeichne das auf.

Dann schauen ob der PING zur selben Zeit abbricht.

Eventuell auch mal ins CCU log schauen.

adarof

Hat sich glaub ich erledigt ... die Unifi Server Software hat mir bei betrachtung eine abbrechende Verbindung zu einem AP angezeigt ... und genau an dem "downlink" war per LAN auch die CCU dran.
Schrank abgerückt -> Stecker hing nurnoch halb in der Wand -> reingesteckt -> Ruhe

Danke für Eure mühe

Community Forum

NEWS

[erledigt] hm-rpc verliert auf einmal verbindung -> debugging?

Support us

531

32.8k

82.7k

1.3m