Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Einrichtung, Nutzung und Hilfe zu RaspberryMatic (OCCU auf Raspberry Pi)

Moderatoren: jmaus, Co-Administratoren

Antworten
civi
Beiträge: 4
Registriert: 12.11.2022, 15:11
System: Alternative CCU (auf Basis OCCU)

Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von civi » 12.11.2022, 16:04

Hallo,

vermutlich seit dem letzten Update auf 3.65.11.20221005 kann ich mit meiner Homematic-Zentrale (Charly) keine neuen HMIP-Geräte mehr anlernen, der Posteingang bleibt leer.
Die bisher angelernten HM und HMIP-Geräte funktionieren weiterhin, aber neue Geräte werden beim Anlernen weder über den lokalen noch den Internet-Modus gefunden.

Ich habe das Problem nach einem Ausfall eines HM-LC-Bl1PBU-FM (funktionierte auch lokal nicht mehr) gemerkt, als ich einen HMIP-BROLL eingebaut habe und anlernen wollte. Dieser wurde nicht gefunden. Dann habe ich einen zweiten HMIP-BROLL an gleicher Stelle eingebaut, der wurde ebenfalls nicht erkannt. Daraufhin habe ich die Zentrale neu gestartet und das Anlernen erneut probiert, aber auch ohne Erfolg.

Dann habe ich versucht, einen HMIP-SRH in der direkten Nähe der CCU anzulernen, was auch nicht ging. Um auszuschließen, dass es ein Problem mit dem Funkmodul (RPI-RF-MOD) gibt, habe ich dann eine HMIP-HAB anlernen wollen, was auch scheiterte (trotz aktueller Firmware, Resets, etc.).

An den Funkwerten sollte es hoffentlich nicht liegen, die schwanken für DC zwischen 3 und 8%, CS liegt bei 0 und max. 4% (direkt nach dem Reboot).

Ich habe dann ein erneutes Upgrade auf die o.g. Firmware-Version gemacht, in der Hoffnung, dass das Problem damit gelöst wird, aber leider hat das auch nicht geholfen.

Nach einiger Fehlersuche habe ich dann das hier https://github.com/jens-maus/RaspberryMatic/issues/613 genannte Script gefunden, dass genutzt werden kann, um Fehler bei der Erstellung der Geräte durch Re-Keying (wenn ich das richtig verstanden habe) zu identifizieren. Und dort wird auch der Ordner /etc/config/crRFD/data genannt. In dem Ordner konnte ich auch für meine Anmeldeversuche entsprechende .dev-Dateien finden (identifizierbar über den Zeitstempel). Neue Anlernversuche erzeugen dann auch neue .dev-Dateien, d.h. das Funkmodul scheint zumindest die HMIP-Geräte zu finden, aber irgendwas scheitert bei der Einrichtung, so dass diese nicht im Posteingang auftauchen.
Das Script meldet dann auch entsprechend SGTIN xxx not found in regadom.
Verschieben der Dateien mit der -f Option und Neustart des Dienstes bzw. der Zentrale lösen das Problem auch nicht.

In der Log-Datei hmserver.log finde ich nur diese Meldungen (die laut Forums-Suche ignoriert werden können):

Code: Alles auswählen

2022-11-12 13:53:06,988 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [HmIP-RF_java_WorkerPool-1] INFO: I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:39292: Broken pipe (Write failed)
2022-11-12 13:53:06,999 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [HmIP-RF_java_WorkerPool-1] Nov 12, 2022 1:53:06 PM org.apache.http.impl.client.DefaultHttpClient tryExecute
2022-11-12 13:53:07,000 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [HmIP-RF_java_WorkerPool-1] INFO: Retrying request to {}->http://127.0.0.1:39292
2022-11-12 15:02:38,375 de.eq3.cbcs.server.core.vertx.KeyServerWorker ERROR [vert.x-worker-thread-1] Missing key server configuration parameter (Network.Key) for  mode: KEYSERVER_LOCAL
/var/log/messages ist auch nicht hilfreich.

Leider habe ich keine Idee, wie ich diesen Fehler beheben soll und bin dankbar für Vorschläge.

Gruß
civi
Nach oben
Benutzeravatar
Baxxy
Beiträge: 10836
Registriert: 18.12.2018, 15:45
System: Alternative CCU (auf Basis OCCU)
Hat sich bedankt: 608 Mal
Danksagung erhalten: 2228 Mal

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von Baxxy » 12.11.2022, 19:09

Das Fehlerprotokoll für HmIP mal auf Tracing stellen und rebooten.

Dann einen Anlernversuch durchführen und danach das Logfile hier zur Einsicht posten.
Nach oben
civi
Beiträge: 4
Registriert: 12.11.2022, 15:11
System: Alternative CCU (auf Basis OCCU)

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von civi » 13.11.2022, 11:27

Hallo Baxxy,

Danke für die Antwort.

Hier der Trace vom Anlernversuch:

Code: Alles auswählen

2022-11-13 11:15:59,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:15:59,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:15:59,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:16:00,031 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: setInstallMode called null -> 60 
2022-11-13 11:16:00,602 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:01,178 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:01,749 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:02,274 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-1] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:16:02,315 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:02,385 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:02,395 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:02,396 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:02,421 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:02,421 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:02,421 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:02,422 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:02,423 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:02,454 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9500: Queueing with priority 1 (first task is AdapterTask) ... 
2022-11-13 11:16:02,454 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 1 Request handled 1C1688 (1C1688) 
2022-11-13 11:16:02,454 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9501: Executing AdapterTask (Priority 1) ... 
2022-11-13 11:16:02,454 de.eq3.cbcs.transaction.hmip.task.AsynchronousHmipTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9501: Starting task timer with timeout 5000 ms and ID 2065 
2022-11-13 11:16:02,455 de.eq3.cbcs.server.core.persistence.AbstractPersistency TRACE [vert.x-worker-thread-2] DEV 3014F711A00007DD899FB34E: Receive persistence command: PERSISTENCE_COMMAND_ADD_DEVICE 
2022-11-13 11:16:02,457 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 1 + 0 + 0 + 0 = 1, thereof active: 1 
2022-11-13 11:16:02,457 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: No tasks active, but transactions in queue. Make sure to retrigger ... 
2022-11-13 11:16:02,463 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-1] AP 3014F711A0001F5A4993F8DA: Task 9501: Handle message: {"accesspoint.id":"3014F711A0001F5A4993F8DA","task.id":9501,"command":{"command.type":"HM_GET_INCLUSION_DATA","command.inclusionRequest":"AQCPHBaI8AADEDAU9xGgAAfdiZ-zTgABAAABHgECCgQDMeDJVNgAoJaiFK_TJ1aw4g","command.newDeviceAddress":"eJTG","command.newBackboneAddress":null,"command.sequenceNumber":242213,"command.inclusionKeyMode":"VIA_DEVICE_MASTER_KEY","command.localKey":null}} 
2022-11-13 11:16:02,463 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-1] AP 3014F711A0001F5A4993F8DA: Task 9501: command: HM_GET_INCLUSION_DATA, hmipAdapter de.eq3.cbcs.server.local.base.internal.ShareableHomeMaticIPTRXCommAdapter@6870c798 
2022-11-13 11:16:02,476 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: HMIP Stack response 1 
2022-11-13 11:16:02,478 de.eq3.cbcs.server.core.internal.HMIPAdapterResponseListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Task 9501: Adapter response received with type ACK 
2022-11-13 11:16:02,484 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 2 response from get inclusion data 1C1688 (1C1688) -> Router null 
2022-11-13 11:16:02,488 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-0] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.0 KeyServerWorker Router null 
2022-11-13 11:16:02,495 de.eq3.cbcs.server.core.transaction.TransactionManagementVerticle TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9501: Processing task response of type TARGET_SUCCESS ... 
2022-11-13 11:16:02,495 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9501: Task finished normally 
2022-11-13 11:16:02,496 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9502: Executing SendBackendNotificationTask (Priority 1) ... 
2022-11-13 11:16:02,496 de.eq3.cbcs.server.core.task.eventbus.SendBackendNotificationTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9502: Sending backend notification of type RESPONSE_ACK (Caller ID: event, request ID: -1) ... 
2022-11-13 11:16:02,496 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9502: Task finished normally 
2022-11-13 11:16:02,497 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9500: Transaction finished 
2022-11-13 11:16:02,497 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 0 + 0 + 0 + 0 = 0, thereof active: 0 
2022-11-13 11:16:02,498 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-3] RESPONSE_ACK : {"caller.id":"event","request.id":-1,"notification.type":0,"accesspoint.id":"3014F711A0001F5A4993F8DA"} 
2022-11-13 11:16:02,740 io.netty.handler.ssl.JdkSslContext DEBUG [vert.x-worker-thread-0] Default protocols (JDK): [TLSv1.2]  
2022-11-13 11:16:02,741 io.netty.handler.ssl.JdkSslContext DEBUG [vert.x-worker-thread-0] Default cipher suites (JDK): [TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_AES_128_GCM_SHA256, TLS_AES_256_GCM_SHA384] 
2022-11-13 11:16:02,763 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:02,764 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:02,766 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Don't Route Frame Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) target F00003 (F00003) duplicated multicast 
2022-11-13 11:16:02,766 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:02,766 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:02,767 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:02,767 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:02,767 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:02,767 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:02,767 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:02,936 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:03,103 io.netty.util.ResourceLeakDetectorFactory DEBUG [vert.x-eventloop-thread-3] Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@3f0059eb 
2022-11-13 11:16:03,153 io.netty.resolver.dns.DnsQueryContext DEBUG [vert.x-eventloop-thread-3] [id: 0x9f1b78be] WRITE: UDP, [28117: /192.168.177.253:53], DefaultDnsQuestion(secgtw.homematic.com. IN A) 
2022-11-13 11:16:03,166 io.netty.resolver.dns.DnsQueryContext DEBUG [vert.x-eventloop-thread-3] [id: 0x9f1b78be] WRITE: UDP, [57618: /192.168.177.253:53], DefaultDnsQuestion(secgtw.homematic.com. IN AAAA) 
2022-11-13 11:16:03,203 io.netty.resolver.dns.DnsNameResolver DEBUG [vert.x-eventloop-thread-3] [id: 0x9f1b78be] RECEIVED: UDP [57618: /192.168.177.253:53], DatagramDnsResponse(from: /192.168.177.253:53, to: /0:0:0:0:0:0:0:0:50908, 57618, QUERY(0), NoError(0), RD RA)
	DefaultDnsQuestion(secgtw.homematic.com. IN AAAA)
	DefaultDnsRawRecord(homematic.com. 899 IN SOA 52B) 
2022-11-13 11:16:03,208 io.netty.resolver.dns.DnsNameResolver DEBUG [vert.x-eventloop-thread-3] [id: 0x9f1b78be] RECEIVED: UDP [28117: /192.168.177.253:53], DatagramDnsResponse(from: /192.168.177.253:53, to: /0:0:0:0:0:0:0:0:50908, 28117, QUERY(0), NoError(0), RD RA)
	DefaultDnsQuestion(secgtw.homematic.com. IN A)
	DefaultDnsRawRecord(secgtw.homematic.com. 3599 IN A 4B) 
2022-11-13 11:16:03,225 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:16:03,225 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:16:03,226 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:16:03,226 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@77af5e15 
2022-11-13 11:16:03,229 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:16:03,229 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device CENTRAL: key:PONG = ct-iobroker:hm-rpc.0:9a8983d67c900491b412be2e47f6c237 
2022-11-13 11:16:03,229 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:16:03,234 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@77af5e15 
2022-11-13 11:16:03,505 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:04,080 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:04,654 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:05,218 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:05,789 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:06,353 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:06,924 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:07,498 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:07,674 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:16:07,674 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:16:07,675 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:16:07,675 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@411edadd 
2022-11-13 11:16:07,677 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:16:07,677 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:16:07,678 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:16:07,680 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@411edadd 
2022-11-13 11:16:07,693 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:07,694 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:07,696 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:07,697 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:07,697 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:07,697 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:07,698 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:07,698 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:07,698 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:08,064 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:08,626 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:09,193 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:09,761 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:10,326 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:10,894 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:11,399 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:11,400 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:11,401 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:11,401 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:11,401 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:11,402 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:11,402 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:11,402 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:11,402 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:11,491 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:12,041 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:12,610 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:13,175 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:13,746 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:13,817 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:16:13,817 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:16:13,817 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:16:13,817 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@15806752 
2022-11-13 11:16:13,821 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:16:13,822 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:BOOT = true 
2022-11-13 11:16:13,822 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:ENERGY_COUNTER = 9608.3 
2022-11-13 11:16:13,822 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:POWER = 0.04 
2022-11-13 11:16:13,822 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:CURRENT = 0.0 
2022-11-13 11:16:13,822 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:VOLTAGE = 244.4 
2022-11-13 11:16:13,822 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:FREQUENCY = 49.99 
2022-11-13 11:16:13,823 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:16:13,826 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@15806752 
2022-11-13 11:16:14,303 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:16:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:16:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:16:14,864 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:15,431 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:15,998 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:16,563 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:17,135 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:17,699 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:18,266 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:18,823 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:19,387 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:19,956 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-4] RPCMethod: getInstallMode called 
2022-11-13 11:16:21,215 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:21,505 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:21,505 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:21,506 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:21,507 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:21,507 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:21,507 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:21,507 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:21,507 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:21,507 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:22,215 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:24,454 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: getInstallMode called 
2022-11-13 11:16:25,017 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:25,575 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:26,145 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:26,715 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-2] RPCMethod: getInstallMode called 
2022-11-13 11:16:27,281 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-0] RPCMethod: getInstallMode called 
2022-11-13 11:16:27,844 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-1] RPCMethod: getInstallMode called 
2022-11-13 11:16:29,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:16:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:16:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:16:31,618 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:31,618 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:31,619 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:31,619 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:31,619 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:31,620 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:31,620 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:31,620 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:31,620 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:32,275 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:16:34,004 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 12 00 83 3a 24 1e f0 00 01 00 05 cf 2b 14 11 5d 1a 88 00  
2022-11-13 11:16:34,004 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: ICMP 
2022-11-13 11:16:34,005 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: ICMP from 3A241E (3A241E) 
2022-11-13 11:16:34,005 de.eq3.cbcs.server.core.framehandling.CompressedICMPHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Received ICMP NEIGHBOR_ADVERTISEMENT from 3A241E 
2022-11-13 11:16:37,893 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:16:37,894 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:16:37,894 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:16:37,894 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5f61b090 
2022-11-13 11:16:37,896 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:16:37,897 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:16:37,897 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:16:37,900 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5f61b090 
2022-11-13 11:16:41,751 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:41,752 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:41,753 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:41,753 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:41,753 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:41,754 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:41,754 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:41,754 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:41,754 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:16:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:16:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:16:51,824 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:16:51,824 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:16:51,826 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:16:51,827 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:16:51,827 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:16:51,827 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:16:51,827 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:16:51,827 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:16:51,827 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:16:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:16:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:16:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:17:00,057 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-0] ACCESS_POINT_INCLUSION_MODE_INACTIVE : {"caller.id":"event","request.id":-1,"notification.type":56,"accesspoint.id":"3014F711A0001F5A4993F8DA"} 
2022-11-13 11:17:01,940 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:17:01,941 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:17:01,942 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:17:01,943 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:17:01,943 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:17:01,943 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:17:01,943 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:17:01,943 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:17:01,943 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:17:02,275 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-4] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:17:03,311 de.eq3.cbcs.server.core.vertx.keyserver.KeyServerOperation WARN  [vert.x-worker-thread-4] AP 3014F711A0001F5A4993F8DA: Exception while communicating to Frontend Server: 
io.netty.channel.ConnectTimeoutException: connection timed out: secgtw.homematic.com/62.113.249.75:8443
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:261) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) ~[HMIPServer.jar:?]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[HMIPServer.jar:?]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?]
	at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_345]
2022-11-13 11:17:03,318 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-4] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.1 KeyServerWorker response Router null 
2022-11-13 11:17:03,324 de.eq3.cbcs.server.core.internal.InclusionHandling INFO  [vert.x-eventloop-thread-3] AP 3014F711A0001F5A4993F8DA: Aborting inclusion process; device 3014F711A00007DD899FB34E will stay in inclusion state UNKNOWN 
2022-11-13 11:17:07,659 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-0] RECEIVED_STATUS_DATA : {"caller.id":"legacy","request.id":80,"notification.type":42,"accesspoint.id":"3014F711A0001F5A4993F8DA","device.id":"CENTRAL","device.channel":0,"device.parameters.values":{"PONG":"ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893"}} 
2022-11-13 11:17:07,659 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-0] No queue known for response ID: 80 
2022-11-13 11:17:07,660 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893_WorkerPool-1] QUEUE_LEGACY_BACKEND_NOTIFICATION_ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 - Handling message. 
2022-11-13 11:17:07,660 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893_WorkerPool-1] send event(s) to interface: ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 http URL: http://192.168.177.12:2010 
2022-11-13 11:17:07,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient TRACE [ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893_WorkerPool-1] Call ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 with event CENTRAL:0 PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:17:07,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [1009_WorkerPool-1] QUEUE_LEGACY_BACKEND_NOTIFICATION_1009 - Handling message. 
2022-11-13 11:17:07,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [1009_WorkerPool-1] send event(s) to interface: 1009 http URL: http://127.0.0.1:31999 
2022-11-13 11:17:07,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient TRACE [1009_WorkerPool-1] Call 1009 with event CENTRAL:0 PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:17:07,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [HmIP-RF_java_WorkerPool-1] QUEUE_LEGACY_BACKEND_NOTIFICATION_HmIP-RF_java - Handling message. 
2022-11-13 11:17:07,662 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [HmIP-RF_java_WorkerPool-1] send event(s) to interface: HmIP-RF_java http URL: http://127.0.0.1:39292/bidcos 
2022-11-13 11:17:07,662 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient TRACE [HmIP-RF_java_WorkerPool-1] Call HmIP-RF_java with event CENTRAL:0 PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:17:07,673 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:17:07,673 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:17:07,673 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:17:07,673 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@4cab69e0 
2022-11-13 11:17:07,675 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: event 
2022-11-13 11:17:07,675 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: HmIP-RF_java device CENTRAL:0: key:PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:17:07,675 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : event 
2022-11-13 11:17:07,677 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@4cab69e0 
2022-11-13 11:17:08,071 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:17:08,071 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:17:08,071 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:17:08,072 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@11ededf6 
2022-11-13 11:17:08,073 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:17:08,074 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:17:08,074 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:17:08,077 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@11ededf6 
2022-11-13 11:17:08,553 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-2] AP 3014F711A0001F5A4993F8DA: send routing entries via RF to F00002:  
2022-11-13 11:17:11,872 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:17:11,872 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:17:11,873 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:17:11,874 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:17:11,874 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:17:11,874 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:17:11,874 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:17:11,874 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:17:11,875 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 1 Request handled 1C1688 (1C1688) 
2022-11-13 11:17:11,875 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9600: Queueing with priority 1 (first task is AdapterTask) ... 
2022-11-13 11:17:11,875 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9601: Executing AdapterTask (Priority 1) ... 
2022-11-13 11:17:11,875 de.eq3.cbcs.transaction.hmip.task.AsynchronousHmipTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9601: Starting task timer with timeout 5000 ms and ID 2127 
2022-11-13 11:17:11,875 de.eq3.cbcs.server.core.persistence.AbstractPersistency TRACE [vert.x-worker-thread-3] DEV 3014F711A00007DD899FB34E: Receive persistence command: PERSISTENCE_COMMAND_ADD_DEVICE 
2022-11-13 11:17:11,877 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-2] AP 3014F711A0001F5A4993F8DA: Task 9601: Handle message: {"accesspoint.id":"3014F711A0001F5A4993F8DA","task.id":9601,"command":{"command.type":"HM_GET_INCLUSION_DATA","command.inclusionRequest":"AQCPHBaI8AADEDAU9xGgAAfdiZ-zTgABAAABHgECCgQDMeDJVNgAoJaiFK_TJ1aw4g","command.newDeviceAddress":"eJTG","command.newBackboneAddress":null,"command.sequenceNumber":242444,"command.inclusionKeyMode":"VIA_DEVICE_MASTER_KEY","command.localKey":null}} 
2022-11-13 11:17:11,877 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-2] AP 3014F711A0001F5A4993F8DA: Task 9601: command: HM_GET_INCLUSION_DATA, hmipAdapter de.eq3.cbcs.server.local.base.internal.ShareableHomeMaticIPTRXCommAdapter@6870c798 
2022-11-13 11:17:11,878 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 1 + 0 + 0 + 0 = 1, thereof active: 1 
2022-11-13 11:17:11,878 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: No tasks active, but transactions in queue. Make sure to retrigger ... 
2022-11-13 11:17:11,893 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: HMIP Stack response 1 
2022-11-13 11:17:11,893 de.eq3.cbcs.server.core.internal.HMIPAdapterResponseListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Task 9601: Adapter response received with type ACK 
2022-11-13 11:17:11,894 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 2 response from get inclusion data 1C1688 (1C1688) -> Router null 
2022-11-13 11:17:11,895 de.eq3.cbcs.server.core.transaction.TransactionManagementVerticle TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9601: Processing task response of type TARGET_SUCCESS ... 
2022-11-13 11:17:11,895 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9601: Task finished normally 
2022-11-13 11:17:11,895 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-4] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.0 KeyServerWorker Router null 
2022-11-13 11:17:11,895 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9602: Executing SendBackendNotificationTask (Priority 1) ... 
2022-11-13 11:17:11,895 de.eq3.cbcs.server.core.task.eventbus.SendBackendNotificationTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9602: Sending backend notification of type RESPONSE_ACK (Caller ID: event, request ID: -1) ... 
2022-11-13 11:17:11,896 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9602: Task finished normally 
2022-11-13 11:17:11,896 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9600: Transaction finished 
2022-11-13 11:17:11,896 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 0 + 0 + 0 + 0 = 0, thereof active: 0 
2022-11-13 11:17:11,896 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-0] RESPONSE_ACK : {"caller.id":"event","request.id":-1,"notification.type":0,"accesspoint.id":"3014F711A0001F5A4993F8DA"} 
2022-11-13 11:17:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:17:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:17:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:17:21,822 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:17:21,822 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:17:21,824 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:17:21,824 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:17:21,824 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:17:21,824 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:17:21,825 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:17:21,825 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:17:21,825 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:17:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:17:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:17:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:17:31,875 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:17:31,875 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:17:31,877 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:17:31,877 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:17:31,877 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:17:31,878 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:17:31,878 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:17:31,878 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:17:31,878 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:17:32,275 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-2] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:17:33,224 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:17:33,225 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:17:33,225 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:17:33,225 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5421cd7e 
2022-11-13 11:17:33,228 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:17:33,228 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device CENTRAL: key:PONG = ct-iobroker:hm-rpc.0:9a8983d67c900491b412be2e47f6c237 
2022-11-13 11:17:33,228 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:17:33,230 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5421cd7e 
2022-11-13 11:17:38,255 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:17:38,256 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:17:38,256 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:17:38,256 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5a0a2b87 
2022-11-13 11:17:38,258 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:17:38,258 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:17:38,259 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:17:38,262 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5a0a2b87 
2022-11-13 11:17:42,052 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:17:42,052 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:17:42,054 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:17:42,054 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:17:42,055 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:17:42,055 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:17:42,055 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:17:42,055 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:17:42,055 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:17:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:17:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:17:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:17:52,067 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:17:52,067 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:17:52,068 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:17:52,069 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:17:52,069 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:17:52,069 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:17:52,069 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:17:52,069 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:17:52,070 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:17:58,612 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:17:58,613 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:17:58,613 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:17:58,613 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@3c39aa52 
2022-11-13 11:17:58,616 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:17:58,616 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538339:2: key:BOOT = true 
2022-11-13 11:17:58,617 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:17:58,618 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@3c39aa52 
2022-11-13 11:17:58,620 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:17:58,621 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:17:58,621 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:17:58,621 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@12c294ff 
2022-11-13 11:17:58,623 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:17:58,623 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538339:2: key:ENERGY_COUNTER = 8583.4 
2022-11-13 11:17:58,623 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538339:2: key:POWER = 0.5 
2022-11-13 11:17:58,623 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538339:2: key:CURRENT = 92.0 
2022-11-13 11:17:58,623 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538339:2: key:VOLTAGE = 234.6 
2022-11-13 11:17:58,623 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538339:2: key:FREQUENCY = 49.99 
2022-11-13 11:17:58,624 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:17:58,625 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@12c294ff 
2022-11-13 11:17:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:17:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:17:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:18:02,175 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:18:02,175 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:18:02,177 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:18:02,177 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:18:02,177 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:18:02,177 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:18:02,178 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:18:02,178 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:18:02,178 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:18:02,275 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-0] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:18:08,443 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:18:08,443 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:18:08,443 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:18:08,443 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5a2f8749 
2022-11-13 11:18:08,445 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:18:08,447 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:18:08,447 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:18:08,450 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5a2f8749 
2022-11-13 11:18:11,940 de.eq3.cbcs.server.core.vertx.keyserver.KeyServerOperation WARN  [vert.x-worker-thread-4] AP 3014F711A0001F5A4993F8DA: Exception while communicating to Frontend Server: 
io.netty.channel.ConnectTimeoutException: connection timed out: secgtw.homematic.com/62.113.249.75:8443
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:261) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) ~[HMIPServer.jar:?]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[HMIPServer.jar:?]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?]
	at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_345]
2022-11-13 11:18:11,943 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-4] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.1 KeyServerWorker response Router null 
2022-11-13 11:18:11,945 de.eq3.cbcs.server.core.internal.InclusionHandling INFO  [vert.x-eventloop-thread-3] AP 3014F711A0001F5A4993F8DA: Aborting inclusion process; device 3014F711A00007DD899FB34E will stay in inclusion state UNKNOWN 
2022-11-13 11:18:12,165 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:18:12,165 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:18:12,166 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:18:12,167 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:18:12,167 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:18:12,167 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:18:12,167 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:18:12,167 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:18:12,168 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 1 Request handled 1C1688 (1C1688) 
2022-11-13 11:18:12,169 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9700: Queueing with priority 1 (first task is AdapterTask) ... 
2022-11-13 11:18:12,169 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9701: Executing AdapterTask (Priority 1) ... 
2022-11-13 11:18:12,169 de.eq3.cbcs.transaction.hmip.task.AsynchronousHmipTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9701: Starting task timer with timeout 5000 ms and ID 2144 
2022-11-13 11:18:12,170 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 1 + 0 + 0 + 0 = 1, thereof active: 1 
2022-11-13 11:18:12,170 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: No tasks active, but transactions in queue. Make sure to retrigger ... 
2022-11-13 11:18:12,170 de.eq3.cbcs.server.core.persistence.AbstractPersistency TRACE [vert.x-worker-thread-2] DEV 3014F711A00007DD899FB34E: Receive persistence command: PERSISTENCE_COMMAND_ADD_DEVICE 
2022-11-13 11:18:12,171 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: Task 9701: Handle message: {"accesspoint.id":"3014F711A0001F5A4993F8DA","task.id":9701,"command":{"command.type":"HM_GET_INCLUSION_DATA","command.inclusionRequest":"AQCPHBaI8AADEDAU9xGgAAfdiZ-zTgABAAABHgECCgQDMeDJVNgAoJaiFK_TJ1aw4g","command.newDeviceAddress":"eJTG","command.newBackboneAddress":null,"command.sequenceNumber":242645,"command.inclusionKeyMode":"VIA_DEVICE_MASTER_KEY","command.localKey":null}} 
2022-11-13 11:18:12,172 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: Task 9701: command: HM_GET_INCLUSION_DATA, hmipAdapter de.eq3.cbcs.server.local.base.internal.ShareableHomeMaticIPTRXCommAdapter@6870c798 
2022-11-13 11:18:12,186 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: HMIP Stack response 1 
2022-11-13 11:18:12,186 de.eq3.cbcs.server.core.internal.HMIPAdapterResponseListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Task 9701: Adapter response received with type ACK 
2022-11-13 11:18:12,187 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 2 response from get inclusion data 1C1688 (1C1688) -> Router null 
2022-11-13 11:18:12,188 de.eq3.cbcs.server.core.transaction.TransactionManagementVerticle TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9701: Processing task response of type TARGET_SUCCESS ... 
2022-11-13 11:18:12,188 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9701: Task finished normally 
2022-11-13 11:18:12,189 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-0] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.0 KeyServerWorker Router null 
2022-11-13 11:18:12,189 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9702: Executing SendBackendNotificationTask (Priority 1) ... 
2022-11-13 11:18:12,222 de.eq3.cbcs.server.core.task.eventbus.SendBackendNotificationTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9702: Sending backend notification of type RESPONSE_ACK (Caller ID: event, request ID: -1) ... 
2022-11-13 11:18:12,222 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9702: Task finished normally 
2022-11-13 11:18:12,223 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9700: Transaction finished 
2022-11-13 11:18:12,223 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 0 + 0 + 0 + 0 = 0, thereof active: 0 
2022-11-13 11:18:12,224 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-1] RESPONSE_ACK : {"caller.id":"event","request.id":-1,"notification.type":0,"accesspoint.id":"3014F711A0001F5A4993F8DA"} 
2022-11-13 11:18:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:18:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:18:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:18:22,225 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:18:22,225 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:18:22,227 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:18:22,227 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:18:22,227 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:18:22,227 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:18:22,228 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:18:22,228 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:18:22,228 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:18:29,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:18:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:18:29,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:18:32,275 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:18:32,380 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:18:32,381 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:18:32,382 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:18:32,382 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:18:32,382 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:18:32,382 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:18:32,382 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:18:32,382 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:18:32,383 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:18:33,484 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 12 00 83 55 c7 f8 f0 00 01 05 66 9a 9a 0b dc 41 4b 88 00  
2022-11-13 11:18:33,485 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: ICMP 
2022-11-13 11:18:33,486 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: ICMP from 55C7F8 (55C7F8) 
2022-11-13 11:18:33,486 de.eq3.cbcs.server.core.framehandling.CompressedICMPHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Received ICMP NEIGHBOR_ADVERTISEMENT from 55C7F8 
2022-11-13 11:18:37,658 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-2] RECEIVED_STATUS_DATA : {"caller.id":"legacy","request.id":81,"notification.type":42,"accesspoint.id":"3014F711A0001F5A4993F8DA","device.id":"CENTRAL","device.channel":0,"device.parameters.values":{"PONG":"ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893"}} 
2022-11-13 11:18:37,658 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-2] No queue known for response ID: 81 
2022-11-13 11:18:37,659 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893_WorkerPool-0] QUEUE_LEGACY_BACKEND_NOTIFICATION_ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 - Handling message. 
2022-11-13 11:18:37,660 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893_WorkerPool-0] send event(s) to interface: ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 http URL: http://192.168.177.12:2010 
2022-11-13 11:18:37,660 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient TRACE [ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893_WorkerPool-0] Call ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 with event CENTRAL:0 PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:18:37,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [1009_WorkerPool-0] QUEUE_LEGACY_BACKEND_NOTIFICATION_1009 - Handling message. 
2022-11-13 11:18:37,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [1009_WorkerPool-0] send event(s) to interface: 1009 http URL: http://127.0.0.1:31999 
2022-11-13 11:18:37,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [HmIP-RF_java_WorkerPool-0] QUEUE_LEGACY_BACKEND_NOTIFICATION_HmIP-RF_java - Handling message. 
2022-11-13 11:18:37,661 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient TRACE [1009_WorkerPool-0] Call 1009 with event CENTRAL:0 PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:18:37,662 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler DEBUG [HmIP-RF_java_WorkerPool-0] send event(s) to interface: HmIP-RF_java http URL: http://127.0.0.1:39292/bidcos 
2022-11-13 11:18:37,662 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient TRACE [HmIP-RF_java_WorkerPool-0] Call HmIP-RF_java with event CENTRAL:0 PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:18:37,676 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:18:37,676 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:18:37,677 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:18:37,677 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@70117dc7 
2022-11-13 11:18:37,678 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: event 
2022-11-13 11:18:37,679 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: HmIP-RF_java device CENTRAL:0: key:PONG = ct-iobroker:hm-rpc.1:514e166c66abd59272b58b57bd408893 
2022-11-13 11:18:37,679 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : event 
2022-11-13 11:18:37,681 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@70117dc7 
2022-11-13 11:18:38,619 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:18:38,620 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:18:38,620 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:18:38,620 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@f4eae2b 
2022-11-13 11:18:38,621 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:18:38,621 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:18:38,622 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:18:38,624 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@f4eae2b 
2022-11-13 11:18:42,417 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:18:42,418 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:18:42,419 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:18:42,419 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:18:42,420 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:18:42,420 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:18:42,420 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:18:42,420 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:18:42,420 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:18:44,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:18:44,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:18:44,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:18:52,480 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:18:52,481 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:18:52,482 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:18:52,482 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:18:52,482 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:18:52,482 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:18:52,482 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:18:52,483 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:18:52,483 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:18:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:18:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:18:59,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:19:02,275 de.eq3.cbcs.lib.backbone.lanrouting.RouteManagementWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: send routing table to: F00002 crRFD B9C72D Routing entries: B9C72D, B638D2, 60D6A2, 4C22F4, 47E710, 2ECF23, 2E464A, 44F694, 4E6C43, 3A241E, 55C7F8,  
2022-11-13 11:19:02,395 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:19:02,395 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:19:02,396 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:19:02,397 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:19:02,397 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:19:02,397 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:19:02,397 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:19:02,397 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:19:02,397 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion for device 3014F711A00007DD899FB34E already in progress (state: UNKNOWN, process state: RequestingKeyServer); Ignore the new inclusion request 
2022-11-13 11:19:03,224 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:19:03,224 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:19:03,224 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:19:03,224 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5ff7a208 
2022-11-13 11:19:03,226 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:19:03,226 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device CENTRAL: key:PONG = ct-iobroker:hm-rpc.0:9a8983d67c900491b412be2e47f6c237 
2022-11-13 11:19:03,226 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:19:03,228 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@5ff7a208 
2022-11-13 11:19:08,866 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/groups 
2022-11-13 11:19:08,867 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/groups', name=null, order=53, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@283ec1cf], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:19:08,867 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:19:08,867 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@190c914 
2022-11-13 11:19:08,883 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Incoming Request: system.listMethods 
2022-11-13 11:19:08,883 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega DEBUG [vert.x-eventloop-thread-0] system.listMethods 
2022-11-13 11:19:08,883 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.group Send Response for : system.listMethods 
2022-11-13 11:19:08,886 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@190c914 
2022-11-13 11:19:11,026 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler TRACE [vert.x-worker-thread-3] RPCMethod: setInstallMode called null -> null 
2022-11-13 11:19:12,244 de.eq3.cbcs.server.core.vertx.keyserver.KeyServerOperation WARN  [vert.x-worker-thread-1] AP 3014F711A0001F5A4993F8DA: Exception while communicating to Frontend Server: 
io.netty.channel.ConnectTimeoutException: connection timed out: secgtw.homematic.com/62.113.249.75:8443
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:261) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) ~[HMIPServer.jar:?]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[HMIPServer.jar:?]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[HMIPServer.jar:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?]
	at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_345]
2022-11-13 11:19:12,250 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.1 KeyServerWorker response Router null 
2022-11-13 11:19:12,251 de.eq3.cbcs.server.core.internal.InclusionHandling INFO  [vert.x-eventloop-thread-3] AP 3014F711A0001F5A4993F8DA: Aborting inclusion process; device 3014F711A00007DD899FB34E will stay in inclusion state UNKNOWN 
2022-11-13 11:19:12,562 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] IP Frame received: 01 00 8f 1c 16 88 f0 00 03 10 30 14 f7 11 a0 00 07 dd 89 9f b3 4e 00 01 00 00 01 1e 01 02 0a 04 03 31 e0 c9 54 d8 00 a0 96 a2 14 af d3 27 56 b0 e2  
2022-11-13 11:19:12,563 de.eq3.cbcs.server.core.internal.HMIPTRXListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] HM /IP Frame received Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST 
2022-11-13 11:19:12,564 de.eq3.cbcs.server.core.vertx.IncomingHMIPFrameHandler TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: HM /IP Frame received  Frametype: HMIP_NM_DEVICE_INCLUSION_REQUEST from 1C1688 (1C1688) 
2022-11-13 11:19:12,565 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion Request device with SGTIN: 3014F711A00007DD899FB34E; accept Master Key: true; accept Local Key: true 
2022-11-13 11:19:12,565 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Accept re inclusion 3014F711A00007DD899FB34E, no matter which inclusion mode is active 
2022-11-13 11:19:12,565 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Device description found. Type is DeviceType [label=HmIP-SRH, id=286, manufacturerCode=1, updatable=true, minVersion=66048, maxVersion=0] 
2022-11-13 11:19:12,565 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E Received inclusion request for device already known. 
2022-11-13 11:19:12,565 de.eq3.cbcs.server.core.internal.InclusionHandling TRACE [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Device 3014F711A00007DD899FB34E, Received inclusion request from known device was resetted and has a differnet radio address 
2022-11-13 11:19:12,566 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [vert.x-eventloop-thread-1] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 1 Request handled 1C1688 (1C1688) 
2022-11-13 11:19:12,567 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9800: Queueing with priority 1 (first task is AdapterTask) ... 
2022-11-13 11:19:12,568 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9801: Executing AdapterTask (Priority 1) ... 
2022-11-13 11:19:12,568 de.eq3.cbcs.transaction.hmip.task.AsynchronousHmipTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9801: Starting task timer with timeout 5000 ms and ID 2166 
2022-11-13 11:19:12,568 de.eq3.cbcs.server.core.persistence.AbstractPersistency TRACE [vert.x-worker-thread-4] DEV 3014F711A00007DD899FB34E: Receive persistence command: PERSISTENCE_COMMAND_ADD_DEVICE 
2022-11-13 11:19:12,568 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 1 + 0 + 0 + 0 = 1, thereof active: 1 
2022-11-13 11:19:12,569 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: No tasks active, but transactions in queue. Make sure to retrigger ... 
2022-11-13 11:19:12,570 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: Task 9801: Handle message: {"accesspoint.id":"3014F711A0001F5A4993F8DA","task.id":9801,"command":{"command.type":"HM_GET_INCLUSION_DATA","command.inclusionRequest":"AQCPHBaI8AADEDAU9xGgAAfdiZ-zTgABAAABHgECCgQDMeDJVNgAoJaiFK_TJ1aw4g","command.newDeviceAddress":"eJTG","command.newBackboneAddress":null,"command.sequenceNumber":242846,"command.inclusionKeyMode":"VIA_DEVICE_MASTER_KEY","command.localKey":null}} 
2022-11-13 11:19:12,570 de.eq3.cbcs.server.core.vertx.HMIPAbstractWriterWorker TRACE [vert.x-worker-thread-3] AP 3014F711A0001F5A4993F8DA: Task 9801: command: HM_GET_INCLUSION_DATA, hmipAdapter de.eq3.cbcs.server.local.base.internal.ShareableHomeMaticIPTRXCommAdapter@6870c798 
2022-11-13 11:19:12,584 de.eq3.cbcs.lib.hmiptrxcommadapter.internal.HMIPStack TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: HMIP Stack response 1 
2022-11-13 11:19:12,584 de.eq3.cbcs.server.core.internal.HMIPAdapterResponseListener TRACE [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Task 9801: Adapter response received with type ACK 
2022-11-13 11:19:12,584 de.eq3.cbcs.server.core.internal.InclusionHandling DEBUG [RXTXPortMonitor(/dev/mmd_hmip)] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 2 response from get inclusion data 1C1688 (1C1688) -> Router null 
2022-11-13 11:19:12,585 de.eq3.cbcs.server.core.transaction.TransactionManagementVerticle TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9801: Processing task response of type TARGET_SUCCESS ... 
2022-11-13 11:19:12,585 de.eq3.cbcs.server.core.vertx.KeyServerWorker DEBUG [vert.x-worker-thread-0] AP 3014F711A0001F5A4993F8DA: Inclusion 3014F711A00007DD899FB34E: Step 3.0 KeyServerWorker Router null 
2022-11-13 11:19:12,586 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9801: Task finished normally 
2022-11-13 11:19:12,586 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9802: Executing SendBackendNotificationTask (Priority 1) ... 
2022-11-13 11:19:12,586 de.eq3.cbcs.server.core.task.eventbus.SendBackendNotificationTask TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9802: Sending backend notification of type RESPONSE_ACK (Caller ID: event, request ID: -1) ... 
2022-11-13 11:19:12,586 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Task 9802: Task finished normally 
2022-11-13 11:19:12,587 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transaction 9800: Transaction finished 
2022-11-13 11:19:12,587 de.eq3.cbcs.transaction.management.TransactionManager TRACE [vert.x-eventloop-thread-4] AP 3014F711A0001F5A4993F8DA: Transactions by priority: 0 + 0 + 0 + 0 + 0 = 0, thereof active: 0 
2022-11-13 11:19:12,587 de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyNotificationHandler TRACE [vert.x-worker-thread-1] RESPONSE_ACK : {"caller.id":"event","request.id":-1,"notification.type":0,"accesspoint.id":"3014F711A0001F5A4993F8DA"} 
2022-11-13 11:19:14,521 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: OTAU periodic start handler is trying to start a handler 
2022-11-13 11:19:14,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any RF update handlers 
2022-11-13 11:19:14,522 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem TRACE [vert.x-eventloop-thread-0] SYSTEM: No suitable AP found - cannot start any wired update handlers 
2022-11-13 11:19:14,815 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:19:14,816 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:19:14,816 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:19:14,817 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@55d8d500 
2022-11-13 11:19:14,819 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:19:14,819 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:BOOT = true 
2022-11-13 11:19:14,820 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:19:14,823 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@55d8d500 
2022-11-13 11:19:14,827 io.vertx.ext.web.impl.RouterImpl TRACE [vert.x-eventloop-thread-0] Router: 1560563906 accepting request POST http://127.0.0.1:39292/bidcos 
2022-11-13 11:19:14,828 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Route matches: RouteState{path='/bidcos', name=null, order=52, enabled=true, methods=null, consumes=null, emptyBodyPermittedWithConsumes=false, produces=null, contextHandlers=[de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler@ab91cba], failureHandlers=null, added=true, pattern=null, groups=null, useNormalizedPath=true, namedGroupsInRegex=null, virtualHostPattern=null, pathEndsWithSlash=false, exclusive=false, exactPath=true} 
2022-11-13 11:19:14,828 io.vertx.ext.web.RoutingContext TRACE [vert.x-eventloop-thread-0] Calling the  handler 
2022-11-13 11:19:14,828 de.eq3.ccu.server.internal.BasicAPIHttpVertxHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@3f15be66 
2022-11-13 11:19:14,833 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Incoming Request: system.multicall 
2022-11-13 11:19:14,834 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:ENERGY_COUNTER = 9608.3 
2022-11-13 11:19:14,834 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:POWER = 0.04 
2022-11-13 11:19:14,834 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:CURRENT = 0.0 
2022-11-13 11:19:14,834 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:VOLTAGE = 245.2 
2022-11-13 11:19:14,834 de.eq3.ccu.bidcos.dispatcher.BidCosRpcDispatcher DEBUG [vert.x-eventloop-thread-0] event interface: BidCos-RF_java device LEQ0538162:2: key:FREQUENCY = 49.98 
2022-11-13 11:19:14,835 de.eq3.ccu.server.internal.RpcMessageHandler DEBUG [vert.x-eventloop-thread-0] rpc.api.bidcos Send Response for : system.multicall 
2022-11-13 11:19:14,838 de.eq3.ccu.server.internal.BasicAPIHttpResponseHandler DEBUG [vert.x-eventloop-thread-0] io.vertx.ext.web.impl.HttpServerRequestWrapper@3f15be66
Gruß
civi
Nach oben
frd030
Beiträge: 3622
Registriert: 14.07.2019, 20:49
System: CCU
Hat sich bedankt: 847 Mal
Danksagung erhalten: 542 Mal

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von frd030 » 13.11.2022, 11:51

Es scheint, dass es keine Verbindung zum homematic-Keyserver gibt:

Code: Alles auswählen

2022-11-13 11:19:12,244 de.eq3.cbcs.server.core.vertx.keyserver.KeyServerOperation WARN  [vert.x-worker-thread-1] AP 3014F711A0001F5A4993F8DA: Exception while communicating to Frontend Server: 
io.netty.channel.ConnectTimeoutException: connection timed out: secgtw.homematic.com/62.113.249.75:8443
Hat Deine Zentrale eine Internetverbindung? Gibt es eine Firewall, die den Zugriff verhindern könnte?
Beim automatischen Anlernen von HmIP-Geräten muss diese Verbindung möglich sein!
Nach oben
civi
Beiträge: 4
Registriert: 12.11.2022, 15:11
System: Alternative CCU (auf Basis OCCU)

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von civi » 13.11.2022, 12:28

Vielen Dank, da habe ich also die ganze Zeit an der falschen Stelle gesucht. :roll:
Nicht die Zentrale war Schuld, sondern meine Firewall.
Keine Ahnung, wann ich da in den letzten Monaten eine Änderung gemacht habe, aber zu den Ports 43439, 9292, 8888, 6969 habe ich jetzt noch den von dir genannten 8443 hinzugefügt, und schon geht alles wieder, HMIP-BROLL und Türsensor sind in wenigen Minuten angelernt gewesen.

Problem gelöst, jetzt kann ich die Einrichtung des alten Schalters übernehmen. Vielen Dank nochmal!

Gruß
civi
Nach oben
MichaelN
Beiträge: 9679
Registriert: 27.04.2020, 10:34
System: CCU
Hat sich bedankt: 700 Mal
Danksagung erhalten: 1626 Mal

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von MichaelN » 13.11.2022, 12:43

Du hast aber keine Portweiterleitung im Router auf die CCU eingerichtet?
LG, Michael.

Wenn du eine App zur Bedienung brauchst, dann hast du kein Smarthome.

Wettervorhersage über AccuWeather oder OpenWeatherMap+++ Rollladensteuerung 2.0 +++ JSON-API-Ausgaben auswerten +++ undokumentierte Skript-Befehle und Debugging-Tipps +++
Nach oben
Benutzeravatar
Baxxy
Beiträge: 10836
Registriert: 18.12.2018, 15:45
System: Alternative CCU (auf Basis OCCU)
Hat sich bedankt: 608 Mal
Danksagung erhalten: 2228 Mal

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von Baxxy » 13.11.2022, 12:46

Na das war ja diesmal einfach. :)
Ich hatte gedanklich schon wieder .dev Leichen im Kopf.
Nach oben
frd030
Beiträge: 3622
Registriert: 14.07.2019, 20:49
System: CCU
Hat sich bedankt: 847 Mal
Danksagung erhalten: 542 Mal

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von frd030 » 13.11.2022, 12:53

Halloween ist vorbei! :mrgreen:
Nach oben
frd030
Beiträge: 3622
Registriert: 14.07.2019, 20:49
System: CCU
Hat sich bedankt: 847 Mal
Danksagung erhalten: 542 Mal

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von frd030 » 13.11.2022, 12:55

civi hat geschrieben: ↑
13.11.2022, 12:28
 Keine Ahnung, wann ich da in den letzten Monaten eine Änderung gemacht habe
Prima, dass es jetzt geht. Und wieder haben wir ein gutes Beispiel für:
"Seit dem Update geht es nicht mehr, das Update muss Schuld sein!" - Äh. nö :!:
Meist küsst man das vor Monaten verursachte Problem einfach nur wach... :wink:
Nach oben
Benutzeravatar
jmaus
Beiträge: 9864
Registriert: 17.02.2015, 14:45
System: Alternative CCU (auf Basis OCCU)
Wohnort: Dresden
Hat sich bedankt: 464 Mal
Danksagung erhalten: 1882 Mal
Kontaktdaten:
Kontaktdaten von jmaus

Re: Kein Anlernen von neuen HMIP-Geräten möglich (Charly)

Beitrag von jmaus » 13.11.2022, 15:57

Am besten auch gleich dieses unsägliche panikhafte zudrehen der Firewall vom LAN ins WAN sein lassen! Ne Firewall soll einen vor allem vor Angriffen vom WAN aus schützen und nicht umgedreht weil das einfach - wie man hier sieht - zuviel thermik macht! So zumindestenst IMHO!
RaspberryMatic 3.75.7.20240420 @ ProxmoxVE – ~200 Hm-RF/HmIP-RF/HmIPW Geräte + ioBroker + HomeAssistant – GitHub / Sponsors / PayPal / ☕️
Nach oben
Antworten

Zurück zu „RaspberryMatic“