Rekeying-Odyssee bei Funkmodulwechsel

[qwertz]

war: IP-Geräte weg nach Migration von Raspi3+ auf TinkerS mit neuem Funkmod.

Hallo zusammen !

Ich habe meine produktive Rasperrymatic auf tinkerS mit neuem Funkmodul migriert und die IP-Geräte sind alle weg.

Quellsystem
Raspi3b+
RM 3.49.17.20200131
BackUp gezogen über WebUI
HM-MOD-RPI-PCB direkt auf GPIO

Zielsystem
TinkerboardS
leeres RM 3.49.17.20200131 mit etcher auf eMMc gespielt
über WebUI Backup vom Quellsystem eingespielt
RPI-RF-MOD direkt auf GPIO

-Habe 24h gewartet für Rekeying.
-alte Zentrale ist stromlos
-Internet funktioniert
-keine Alarm oder Servicemeldungen
-HM sowie IP-Anlernen ist in der WebUI verfügbar
-virtuelle ip-Tasten HMIP-RCV-50 ist da
-habe die IP-Geräte nicht angerührt und insb. noch kein Reset oder Neuanlernen probiert.


-laut /var/log/hmserver.log feuern die verlorenen Geräte traurig die RaspiMatic an ohne Antwort
Auszug

Code: Alles auswählen

Feb 6 22:28:52 de.eq3.cbcs.server.core.framehandling.HMIPApplicationHandler WARN  [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993E107: Frame HMIP_APP_STATUS received from Device with unknown address 8E85F1 
Feb 6 22:28:54 de.eq3.cbcs.server.core.framehandling.HMIPApplicationHandler WARN  [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993E107: Frame HMIP_APP_STATUS received from Device with unknown address 663E2A 
Feb 6 22:28:58 de.eq3.cbcs.server.core.framehandling.HMIPApplicationHandler WARN  [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993E107: Frame HMIP_APP_STATUS received from Device with unknown address 3BCD65 
Feb 6 22:28:59 de.eq3.cbcs.server.core.framehandling.HMIPApplicationHandler WARN  [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993E107: Frame HMIP_APP_STATUS received from Device with unknown address 25DBD3 
Feb 6 22:29:02 de.eq3.cbcs.server.core.framehandling.HMIPApplicationHandler WARN  [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993E107: Frame HMIP_
Feb 6 22:33:44 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] SYSTEM: 0 Accesspoints in Queue 
Feb 6 22:33:44 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] SYSTEM: Permanent-/Burstlistener Handler utilization: 0/50 used 
Feb 6 22:33:44 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-2] SYSTEM: Eventlistener Handler utilization: 0/50 used 
Feb 6 22:33:45 de.eq3.cbcs.lib.remotecommadapter.device.service.AccessPointWatchdog INFO  [vert.x-eventloop-thread-0] SYSTEM: Access Point Watchdog running periodic connection check... 

Deshalb ist vermutlich auch der DutyCycle aktuell nicht bei gewohnen 20% sondern 40%

In den sonstigen logs habe ich nur noch dieses auffällige open.close.open.close gefunden

Code: Alles auswählen

  47.114902] eq3loop: created slave mmd_hmip
<6>[   47.115148] eq3loop: created slave mmd_bidcos
<6>[   49.209622] eq3loop: eq3loop_open_slave() mmd_bidcos
<6>[   68.683069] eq3loop: eq3loop_open_slave() mmd_hmip
<6>[   68.683190] eq3loop: eq3loop_close_slave() mmd_hmip
<6>[   68.684924] eq3loop: eq3loop_open_slave() mmd_hmip
<6>[   68.685009] eq3loop: eq3loop_close_slave() mmd_hmip
<6>[   68.691112] eq3loop: eq3loop_open_slave() mmd_hmip

Was ist denn da passiert ?

Besten Dank und Gruß,
Sebastian

[qwertz]

PS

Code: Alles auswählen

/etc/config/hmip_adress.conf


#Create random address
#Fri Aug 24 17:20:15 CEST 2018
Adapter.1.Address=B6FA41

/etc/config/crRFD/old liegen Dateien zu den fehlenden IP-Geräten !

[qwertz]

Ich dokumentiere mal für die Nachwelt meine Recherche zum Problem:

Nach meinen Verständnis werden die dev-Dateien nach crRFD/data/old geschoben, wenn kein KEY (im Log NWK) für das HMIP-Gerät auf dem Funkmodul gefunden wurde. Das Script checkHmIPdevices.sh erledigt dies. Das Verschieben der dev-Dateien soll das Rekeying ermöglichen, da die vorhandenen DEV-Dateien das Rekeying stören:
Quelle: https://github.com/jens-maus/RaspberryMatic/issues/613

Das Rekeying kann in hmserver.log kontrolliert werden und sollte laut angegebener Quelle bei Erfolg diese Logeinträge erzeugen:

Code: Alles auswählen

Jan 6 01:19:05 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] Exchanging adapter from 3014F711A0001F58A9XXXXXX to 3014F711A061A7D3CXXXXXX ... 
...
Jan 6 01:19:04 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] No NWK, try to set address ... 
...
Jan 6 01:19:23 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [vert.x-eventloop-thread-1] Adapter exchange successful. 

Quelle: viewtopic.php?f=58&t=55738&start=10#p554172

Nun habe ich meine Migration komplett sauber wiederholt und das hmserver.log Zeile für Zeile durchgegangen:
Dabei fällt dies auf (Auszug):

Code: Alles auswählen

Feb 7 13:20:22 de.eq3.cbcs.server.core.vertx.KeyServerWorker ERROR [vert.x-worker-thread-1] Missing key server configuration parameter (Network.Key) for  mode: KEYSERVER_LOCAL 
Feb 7 13:20:22 de.eq3.cbcs.lib.remotecommadapter.device.security.RouterKeyServerWorker ERROR [vert.x-worker-thread-0] Missing key server configuration parameter (Network.Key) for  mode: KEYSERVER_LOCAL
Feb 7 13:20:24 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-6] No NWK, try to set address ... 
Feb 7 13:20:42 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO  [vert.x-worker-thread-4] Added InterfaceId: 10_HmIP-RF 
Feb 7 13:20:42 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO  [vert.x-worker-thread-4] updateDevicesForClient 10_HmIP-RF -> 52 device addresses will be added 

In meinem Log nach Migration fehlt also: "Exchanging adapter from" und "Adapter exchange"

[qwertz]

P.S. ich habe aktuell unter /etc/config/ keine hmip_networkkey.conf mit festem NWK, welche KEY-Probleme bei alten mitgezogenen Installationen aus 2016 machen kann.
Quelle: viewtopic.php?f=65&t=37031&p=360953&hil ... el#p360953

[qwertz]

Jetzt brat mir einer einen Storch:

Heute, Tage später, beim dritten Versuch mit identischem Ablauf und Geräten ist die Migration mit Rekeying problemlos durchgelaufen: im Log erscheint jetzt HMIPTRXInitialResponseListener INFO [Thread-6] Exchanging adapter from

So langsam vermute ich, dass der HMIP-Key-Server (secgtw.homematic.com) beim Rekeying unzuverlässig ist.

Erkenntnisse:

1.Wir sind auch als Nerds mit RaspiMatic/CCU3 von der Cloud abhängig.

<Polemik>Wenn Ostfriesland in ein paar Jahrzehnten klimabedingt absäuft können wir bei Funkmodulwechsel unsere Systeme schön neu aufsetzen und je nach Konfig einigen IP-Geräte verschrotten (wenn lokaler Reset deaktiviert)</Polemik>

2. Folgende Log-Meldungen vom hmserver.log sind (bei mir) normal und erscheinen immer:
Missing key server configuration parameter (Network.Key) for mode: KEYSERVER_LOCAL

[jp112sdl]

1.Wir sind auch als Nerds mit RaspiMatic/CCU3 von der Cloud abhängig.

<Polemik>Wenn Ostfriesland in ein paar Jahrzehnten klimabedingt absäuft können wir bei Funkmodulwechsel unsere Systeme schön neu aufsetzen und je nach Konfig einigen IP-Geräte verschrotten (wenn lokaler Reset deaktiviert)</Polemik>

Aber eben "nur" HmIP... ich meide es und setze weiterhin auf das gute abgehangene Bidcos.

[Hütte]

... das gute abgehangene Bidcos.

Der ist gut und kommt in die Kiste für später

[Matthias K.]

<Ironie>Ist doch ganz einfach: Einfach vor dem Funkmodulwechsel alle HmIP-Komponenten ablernen und nach dem Wechsel über Key und SGTIN wieder anlernen. Dann brauchst du keine Cloud. Dauert bei den üblichen 30 - 100 Geräten pro Haushalt mit diversen Programmen doch maximal ein paar Tage. Und wenn die Frau sich wegen Vernachlässigung dann scheiden lässt hast du ja auch endlich Zeit für sowas...</Ironie>

Ja, das stört mich als Cloud-Phobiker an HmIP auch massiv, dass es dann eben unter bestimmten Umständen doch nicht so richtig ohne Cloud geht.
Können wir nur hoffen dass EQ-3 da nicht irgendwann den Hahn zudreht oder bestenfalls das System ganz Open Source frei zur Verfügung stellt, dann kann man's zur Not nachbauen...

[Chris89]

Jetzt brat mir einer einen Storch:

Heute, Tage später, beim dritten Versuch mit identischem Ablauf und Geräten ist die Migration mit Rekeying problemlos durchgelaufen: im Log erscheint jetzt HMIPTRXInitialResponseListener INFO [Thread-6] Exchanging adapter from

So langsam vermute ich, dass der HMIP-Key-Server (secgtw.homematic.com) beim Rekeying unzuverlässig ist.

Erkenntnisse:

1.Wir sind auch als Nerds mit RaspiMatic/CCU3 von der Cloud abhängig.

<Polemik>Wenn Ostfriesland in ein paar Jahrzehnten klimabedingt absäuft können wir bei Funkmodulwechsel unsere Systeme schön neu aufsetzen und je nach Konfig einigen IP-Geräte verschrotten (wenn lokaler Reset deaktiviert)</Polemik>

2. Folgende Log-Meldungen vom hmserver.log sind (bei mir) normal und erscheinen immer:
Missing key server configuration parameter (Network.Key) for mode: KEYSERVER_LOCAL

Hallo qwertz,

du schreibst, dass du es beim dritten Versuch geschafft hast. D. h. du hast das dritte mal rasperrymatic neu aufgesetzt (oder das Backup neu in Rpmatic geladen oder nur einen Neustart gemacht?). Ich hänge leider auch an dem Punkt und will es irgendwie vermeiden alle Komponenten neu anlernen zu müssen.

Anbei noch meine Logdateien.

hmserver.log

(56.04 KiB) 17-mal heruntergeladen

hmserver_2022-02-07.log

(212.47 KiB) 16-mal heruntergeladen

Gruß
Christian