Wechsel von HM-MOD-RPI-PCB auf RPI-RF-MOD keine HM-IP-Geräte mehr

[mpr3110]

Hallo,

ich hänge leider fest und würde mich über einen Tipp freuen.

Situation: Wechsel von Raspberrymatic auf PI3 mit HM-MOD-RPI-PCB auf PI4 mit HB-RF-USB-2 & RPI-RF-MOD

Firmwareversion (auf beiden Raspis): 3.55.10.20210213
Zusatzsoftware: CUx-Daemon 2.5.1

Vorgehen:

• Entfernen des LAN-Gateway, vorher Umstellen aller Geräte auf "Standard" in der Konfiguration der Homematic
• Reboot PI3
• Anfertigen eines Systembackups auf PI3
• Herunterfahren PI3
• Import Backup auf PI4

Problem: Nach dem Restore und dem Neustart sind keine HM-IP-Geräte mehr vorhanden. Auch nach ca. 8 Stunden Wartezeit nicht und auch ein weiterer Systemreset hat nicht geholfen.

Auszug aus messages nach Import Backup:

Code: Alles auswählen

Mar  3 07:38:33 ccu user.info root: Updating RF Lan Gateway Coprocessor Firmware
Mar  3 07:38:33 ccu user.debug update-coprocessor: firmware filename is: coprocessor_update_hm_only.eq3
Mar  3 07:38:33 ccu user.info root: Updating RF Lan Gateway Firmware
Mar  3 07:38:33 ccu user.info update-lgw-firmware: No gateway found in config file /etc/config/rfd.conf
Mar  3 07:38:35 ccu user.err setlgwkey: Could not find gateway by unicast with ip 172.XX.XX.XXX. Trying search by serial number.
Mar  3 07:38:37 ccu user.info setlgwkey: Performing key exchange for lan gateway PEQ0510100

Code: Alles auswählen

Mar  3 07:39:19 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"001098A98A1A18:1","STATE"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:19 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"001098A98A1A18:1","STATE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:19 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:22 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"00021BE99C0772:3","STATE"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:22 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"00021BE99C0772:3","STATE"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:22 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000855699C4168:7","ENERGY_COUNTER"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: ENERGY_COUNTER"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"000855699C4168:7","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000855699C3EA6:7","ENERGY_COUNTER"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"000855699C3EA6:7","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"000B9A498D73AA:5","ENERGY_COUNTER"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"000B9A498D73AA:5","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"00085A499DA607:7","ENERGY_COUNTER"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"00085A499DA607:7","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"00085A499BEF59:7","ENERGY_COUNTER"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"00085A499BEF59:7","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"00085A49A4A166:7","ENERGY_COUNTER"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"00085A49A4A166:7","ENERGY_COUNTER"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]
Mar  3 07:39:23 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"0017D709AE2FCF:1","ILLUMINATION"}, result: [faultCode:-2,faultString:"Invalid device"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"0017D709AE2FCF:1","ILLUMINATION"}) [CallGetValue():iseXmlRpc.cpp:1435]
Mar  3 07:39:23 ccu local0.err ReGaHss: ERROR: CallGetValue failed; sVal = 0.000000 [ReadValue():iseDOMdpHSS.cpp:124]

Diese Meldungen erscheinen für alle HM-IP-Geräte. Hier daher nur Auszugsweise.

Weiterer Fehler aus messages:

Code: Alles auswählen

Mar  3 07:40:00 ccu local0.warn ReGaHss: WARNING: XMLRPC 'getValue': rpcClient.isFault() failed (url: xmlrpc://127.0.0.1:32010, params: {"001F5A4993ED02:0","CARRIER_SENSE_LEVEL"}, result: [faultCode:-5,faultString:"Unknown Parameter value for value key: CARRIER_SENSE_LEVEL"]) [CallXmlrpcMethod():iseXmlRpc.cpp:2608]
Mar  3 07:40:00 ccu local0.err ReGaHss: ERROR: XMLRPC 'getValue' call failed (interface: 7770, params: {"001F5A4993ED02:0","CARRIER_SENSE_LEVEL"}) [CallGetValue():iseXmlRpc.cpp:1435]

Fehlermeldungen aus hmserver.log

Code: Alles auswählen

Mar 3 07:38:53 de.eq3.cbcs.server.core.persistence.AbstractPersistency ERROR [vert.x-worker-thread-1] Could not do command: PERSISTENCE_COMMAND_LOAD_DEVICES 
java.lang.NullPointerException
	at de.eq3.cbcs.persistence.kryo.KryoPersistenceWorker.loadDevice(KryoPersistenceWorker.java:878)
	at de.eq3.cbcs.persistence.kryo.KryoPersistenceWorker.loadAllDevices(KryoPersistenceWorker.java:826)
	at de.eq3.cbcs.persistence.kryo.KryoPersistenceWorker.handle(KryoPersistenceWorker.java:259)
	at de.eq3.cbcs.persistence.kryo.KryoPersistenceWorker.handle(KryoPersistenceWorker.java:89)
	at io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
	at io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
	at io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
	at io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
	at io.vertx.core.impl.TaskQueue.lambda$new$0(TaskQueue.java:60)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Code: Alles auswählen

Mar 3 07:38:55 de.eq3.cbcs.vertx.management.VertxManager WARN  [vert.x-eventloop-thread-3] SYSTEM: Exception during deployment of LegacyNotificationHandler - startup will continue 
Mar 3 07:38:55 de.eq3.cbcs.vertx.management.VertxManager WARN  [vert.x-eventloop-thread-3]  
java.lang.NullPointerException
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil.getDeviceDescriptions(DeviceUtil.java:339)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil.getDeviceDescriptionsByID(DeviceUtil.java:288)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler.initDeviceAddressList(LegacyNotificationHandler.java:180)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler.start(LegacyNotificationHandler.java:165)
	at io.vertx.core.AbstractVerticle.start(AbstractVerticle.java:111)
	at io.vertx.core.impl.DeploymentManager.lambda$doDeploy$8(DeploymentManager.java:434)
	at io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
	at io.vertx.core.impl.TaskQueue.lambda$new$0(TaskQueue.java:60)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Code: Alles auswählen

Mar 3 07:53:41 de.eq3.cbcs.server.core.vertx.KeyServerWorker ERROR [vert.x-worker-thread-1] Missing key server configuration parameter (Network.Key) for  mode: KEYSERVER_LOCAL 

Code: Alles auswählen

Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] TRX adapter state 1: HMIP_TRX_App 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] TRX adapter application is already running or started 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] No NWK, try to set address ... 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Try to set radio address 11936078... 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Set max send attempts for 3014F711A0001F5A4993ED02 to 3 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Try to get application version... 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Application version 4.2.6 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Bootloader version 1.0.1 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] hmos version 1.46.4 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] MCU type: CC1310 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Duty Cycle: 0.0 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] set DutyCycle limit to ffffffc8 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Set Duty Cycle Limit 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Current Security Counter: 768 
Mar 3 07:53:43 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Update security counter to calculation: 3476 
Mar 3 07:53:44 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] TRX adapter has no linkpartner 
Mar 3 07:53:44 de.eq3.cbcs.server.local.base.internal.HMIPTRXInitialResponseListener INFO  [Thread-7] Adapter with Access Point id 3014F711A0001F5A4993ED02 initialized

Scheinbar werden die HM-IP-Geräte beim ersten Boot nach dem Restore alle nach Fehlern entfernt und danach auch nicht mehr angesprochen / aufgerufen. Verwundert bin ich auch, dass obwohl ich den LAN-Adapter vor dem Backup entfernt habe, dieser scheinbar immer noch im Backup ist und beim ersten Boot auch über die IP angesprochen werden soll.

Kann mich mal bitte jemand in die richtige Richtung schubsen? Bin ein wenig mit meinem Latein am Ende.

Besten Dank!

[jmaus]

Das Problem wurde hier bereits mehrfach diskutiert/beleuchtet. Es handelt sich leider um ein in der aktuellen Version (3.55.10.20210213) existierender Bug der mit der nächsten Version behoben sein wird. Entweder also die Vorversion für den Umstieg nutzen und dann danach auf die Version updaten oder auf die nächste Version warten.

Lösungsansätze mit der aktuellen Version die den Bug beinhaltet hier:

viewtopic.php?f=26&t=65905#p647615
viewtopic.php?f=65&t=65535&start=50#p644325

[mpr3110]

Na prima. Mit allem möglichen gesucht und zig Threads gelesen und auf die nicht gekommen. Sorry!
Ich warte dann einfach auf die neue Version.

Besten Dank für deine schnelle Antwort und für die großartige Arbeit, die Du da machst!!!