Test Alpha Homekit-Controller 0.0.x

[Minta79]

@apollon77 Hier ein Auszug aus dem Log im Debug Modus:

Sobald der Schritt "Scheduled Characteristic update started ..." kommt, geht der Status der Instanz von grün auf gelb und es funktioniert nicht mehr. Muss dann die Instanz neu starten. Das geht aber nur ein paar Minuten gut. Es erscheint dann immer der Fehler "data polling failed: undefined"

[apollon77]

@minta79 Bist Du sicher das dsas BLE Device nicht noch von anderen Adapetrn oder Prozessen genutzt wird? dieser "unknown connecztion identifier 0x2" heisst nach erstem Googlen wohl das die Verbindung unterbrochen wurde auf dem Host ...

Mich würde ja mal ein etwas längeres Log passieren ob es sich irgendwann wieder gibt - oder ist da wirklich schluss?

[Minta79]

@apollon77 Ich wüsste nicht, in welchem Adapter es noch verwendet werden sollte. Der Zustand bleibt leider so. Stand jetzt über nen Tag in dem Zustand. Im Log wiederholt es sich dann...

[apollon77]

@minta79 Hm, kann nur raten ... ist irgendwas auf dem Bluetooth level. Da müssmer jetzt mal ganz tief reingehen

• Bitte sicherstellen das alles aktuell ist ... apt update && apt dist-upgrade
• Bitte auch mal sudo hciconfig hci0 reset versuchen
• Was sagt uname -a ? ALao welcher Kernel (ggf nach Updates und nach einem Reboot)
• Was sagt lsusb?
• Was für ein gert ist es? Raspi3 oder was?

Dann wäre cool wenn du in einer Shell mal sudo hcidump -t -x >log.txt laufen lassen kannst und dann den Adapter startest.... Dann das log.txt File mal hochladen zusammen mit dem iobroker debug log

EDIT: Den Adapter starten am besten wie hier --> https://forum.iobroker.net/post/720099 beschrieben in einem zweiten Shell Fenster ... dann die Shell Ausgaben

[pql]

Hi,

laut Readme unterstützt der Controller keine Thread Devices... Bezieht sich das auch auf Eve Geräte die mittlerweile als "based on Thread" betitelt sind? Oder sollen diese funktionieren?

[apollon77]

@pql eve ist meines Wissens thread UND Ble Bzw wlan. Ich kenne bisher kein „exklusiv thread“ gerät auf dem Markt. Von daher sollte es dennoch gehen. Musst halt schauen was das Gerät in Summe so kann

[tklein]

Hallo,

was kann ich tun, damit der Adapter grün wird? Der VP2 Steckerleiste habe ich inzwischen resetet. Wird mir jetzt nicht mehr angezeigt. Ferner find ich keinen DP, wo ich das Pairing triggern könnte.

Im Log steht dieses:

homekit-controller.0	2022-02-08 11:52:17.280	info	(7899) IP-7D:15:F7:88:80:A6 (iobroker 064B) found without known pairing data and already paired: ignoring
homekit-controller.0	2022-02-08 11:52:17.071	info	(7899) starting. Version 0.3.3 in /opt/iobroker/node_modules/iobroker.homekit-controller, node: v14.17.0, js-controller: 3.3.22

bzw:

pi@raspberrypi-iob:~ $ DEBUG=hap* node /opt/iobroker/node_modules/iobroker.homekit-controller/build/main.js 0 --debug --logs
2022-02-08 12:05:23.596  - debug: homekit-controller.0 (9559) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-02-08 12:05:23.677  - debug: homekit-controller.0 (9559) Objects client ready ... initialize now
2022-02-08 12:05:23.682  - debug: homekit-controller.0 (9559) Objects create System PubSub Client
2022-02-08 12:05:23.685  - debug: homekit-controller.0 (9559) Objects create User PubSub Client
2022-02-08 12:05:23.688  - debug: homekit-controller.0 (9559) Objects client initialize lua scripts
2022-02-08 12:05:24.690  - debug: homekit-controller.0 (9559) Objects connected to redis: 127.0.0.1:9001
2022-02-08 12:05:24.706  - debug: homekit-controller.0 (9559) objectDB connected
2022-02-08 12:05:24.710  - debug: homekit-controller.0 (9559) Redis States: Use Redis connection: 127.0.0.1:9000
2022-02-08 12:05:24.857  - debug: homekit-controller.0 (9559) States create System PubSub Client
2022-02-08 12:05:24.859  - debug: homekit-controller.0 (9559) States create User PubSub Client
2022-02-08 12:05:24.895  - debug: homekit-controller.0 (9559) States connected to redis: 127.0.0.1:9000
2022-02-08 12:05:24.896  - debug: homekit-controller.0 (9559) statesDB connected
2022-02-08 12:05:25.908  - debug: homekit-controller.0 (9559) Plugin sentry Initialize Plugin (enabled=true)
2022-02-08 12:05:26.405  - error: homekit-controller.0 (9559) adapter disabled
2022-02-08 12:05:26.412  - info: homekit-controller.0 (9559) starting. Version 0.3.3 in /opt/iobroker/node_modules/iobroker.homekit-controller, node: v14.17.0, js-controller: 3.3.22
2022-02-08 12:05:26.529  - debug: homekit-controller.0 (9559) state homekit-controller.0.info.connection changed: false (ack = true)
2022-02-08 12:05:26.567  - debug: homekit-controller.0 (9559) Discovered IP device up: 7d:15:f7:88:80:a6/iobroker 064B
2022-02-08 12:05:26.568  - debug: homekit-controller.0 (9559) IP-7D:15:F7:88:80:A6 Discovered IP device: {"name":"iobroker 064B","address":"192.168.0.20","port":43409,"c#":78,"ff":0,"id":"7d:15:f7:88:80:a6","md":"not configured","pv":"1.1","s#":1,"sf":0,"ci":2,"availableToPair":false}
2022-02-08 12:05:26.570  - info: homekit-controller.0 (9559) IP-7D:15:F7:88:80:A6 (iobroker 064B) found without known pairing data and already paired: ignoring
2022-02-08 12:05:31.690  - warn: homekit-controller.0 (9559) Got terminate signal. Checking desired PID: 0 vs own PID 9559
2022-02-08 12:05:31.753  - warn: homekit-controller.0 (9559) Got terminate signal. Checking desired PID: 9577 vs own PID 9559
2022-02-08 12:06:04.274  - warn: homekit-controller.0 (9559) Got terminate signal. Checking desired PID: 0 vs own PID 9559
2022-02-08 12:06:04.377  - warn: homekit-controller.0 (9559) Got terminate signal. Checking desired PID: 9633 vs own PID 9559
^C2022-02-08 12:06:14.527  - debug: homekit-controller.0 (9559) Plugin sentry destroyed
2022-02-08 12:06:14.529  - info: homekit-controller.0 (9559) Terminated (START_IMMEDIATELY_AFTER_STOP): Without reason

[apollon77]

@tklein Naja der Adapter wird grün wenn er mit mindestens einem Gerät verbunden ist - bei dir ist er mit keinem Gerät verbunden - ergo Gelb.

Wenn der Adapter sagt das das gerät bereits gepaired ist dann ist das erstmal so. Dann musst DU das Gerät resetten oder aus von da wo es gepaired ist wieder unpairen, Ein Gerät kann nur mit einem Controller gepaired sein.

[tklein]

@apollon77 said in Test Alpha Homekit-Controller 0.0.x:

Wenn der Adapter sagt das das gerät bereits gepaired ist dann ist das erstmal so. Dann musst DU das Gerät resetten oder aus von da wo es gepaired ist wieder unpairen, Ein Gerät kann nur mit einem Controller gepaired sein.

thx dafür. Das eine gepairte ist ja der iobroker als bridge selber. Die schaltbare Steckdosenleiste hatte ich ja resettet. Aber wo/wie kann ich den Pairingcode dann eingeben? Ich habe ja nicht den DP, mit dem ich das Triggern kann. So hatte ich das zumindest bei Github gelesen.

[apollon77]

@tklein wenn er ein Gerät als „ready to pair“ findet dann erscheint der state Bzw in der ui gibt es die Möglichkeit es zu pairen. Das debug log zeigt das dann auch so an … war bei dir oben aber nicht der Fall. Also sicher das reset geklappt hat?

[tklein]

@apollon77 said in Test Alpha Homekit-Controller 0.0.x:

Also sicher das reset geklappt hat?

jetzt sieht es zmindest etwas besser aus, Pairen geht aber immer nch nicht. Den Pin habe ich mit xxx-xx-xxx angegeben. Im DP und in der GUI-Popup

Nachtrag:

Jetzt konnte ich erfolgreich pairen. Keine Ahnung warum die Steckerleiste doppelt drin ist (mit unterschiedlichen IDs:

[apollon77]

@tklein

1.) EHOSTUNREACH bedeutet das das gerät in deinem Netzwerk nicht erreichbar war zu dem Zeitpunkt

2.) Was heisst "in Vocolinc App konfiguriert"? Hast du es dann dort gepaired? Naja dann kanns nicht nochmal sein

3.) Ich denke das Gerät hat mit dem Reset (oder dem pairing) seine ID gendert, damit kennt der Adapter beide. Kannst du in den Adapter-Objekten löschen

[tklein]

@apollon77 said in Test Alpha Homekit-Controller 0.0.x:

1.) EHOSTUNREACH bedeutet das das gerät in deinem Netzwerk nicht erreichbar war zu dem Zeitpunkt
--> thx für die Info
2.) Was heisst "in Vocolinc App konfiguriert"? Hast du es dann dort gepaired? Naja dann kanns nicht nochmal sein
--> nachdem es nach dem reset nicht geklappt hatte, habe ich das Device in der entsprechende App angelernt. Mir war/ist nicht bekannt, wie nach einem Device ohne konfigurierten WLAN nur mit dem Code eine Verbindung mit dem IOB erstellt werden kann
3.) Ich denke das Gerät hat mit dem Reset (oder dem pairing) seine ID gendert, damit kennt der Adapter beide. Kannst du in den Adapter-Objekten löschen
--> ok, werde ich dann löschen

[pql]

@apollon77 Versuche ein Eve Energy zu koppeln, aber ohne Erfolg.
Hardware ist ein RPI4 mit integriertem Bluetooth.

Noch eine Idee?

2022-02-13 12:30:06.032  - debug: homekit-controller.0 (17060) Discovered BLE device up: 0d:30:8f:xx:xx:xx/Eve Energy EA06
2022-02-13 12:30:06.033  - debug: homekit-controller.0 (17060) BLE-0D:30:8F:xx:xx:xx Discovered BLE device: {"name":"Eve Energy EA06","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"0d:30:8f:xx:xx:xx","ACID":7,"GSN":1,"CN":3,"CV":2,"c#":3,"id":"0d:30:8f:xx:xx:xx","ci":7,"availableToPair":true}
2022-02-13 12:30:06.035  - info: homekit-controller.0 (17060) BLE-0D:30:8F:xx:xx:xx (Eve Energy EA06) found without pairing data but available for pairing: Create basic objects
2022-02-13 12:30:06.036  - debug: homekit-controller.0 (17060) Service: {"name":"Eve Energy EA06","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"0d:30:8f:xx:xx:xx","ACID":7,"GSN":1,"CN":3,"CV":2,"c#":3,"id":"0d:30:8f:xx:xx:xx","ci":7,"availableToPair":true}
2022-02-13 12:30:06.088  - debug: homekit-controller.0 (17060) state homekit-controller.0.BLE-0D:30:8F:xx:xx:xx.info.connectionType changed: BLE (ack = true)
2022-02-13 12:30:06.114  - debug: homekit-controller.0 (17060) state homekit-controller.0.BLE-0D:30:8F:xx:xx:xx.info.id changed: 0d:30:8f:xx:xx:xx (ack = true)
2022-02-13 12:30:06.136  - debug: homekit-controller.0 (17060) state homekit-controller.0.BLE-0D:30:8F:xx:xx:xx.info.connected changed: false (ack = true)
2022-02-13 12:30:06.158  - debug: homekit-controller.0 (17060) state homekit-controller.0.BLE-0D:30:8F:xx:xx:xx.admin.isPaired changed: false (ack = true)
2022-02-13 12:30:06.171  - debug: homekit-controller.0 (17060) state homekit-controller.0.BLE-0D:30:8F:xx:xx:xx.info.lastDiscovered changed: 1644751806037 (ack = true)
2022-02-13 12:30:36.166  - debug: homekit-controller.0 (17060) Message getDiscoveredDevices received: {"command":"getDiscoveredDevices","message":null,"from":"system.adapter.admin.0","callback":{"message":null,"id":77,"ack":false,"time":1644751836163},"_id":61388363})
2022-02-13 12:30:36.167  - debug: homekit-controller.0 (17060) Response to Command getDiscoveredDevices: {"success":true,"error":false,"devices":[{"id":"BLE-0D:30:8F:xx:xx:xx","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":true,"discoveredName":"Eve Energy EA06","discoveredCategory":"Outlet","pairedWithThisInstance":false},{"id":"BLE-14:36:5E:xx:xx:xx","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":false,"discoveredName":"Nuki_XXXXX","discoveredCategory":"Lock","pairedWithThisInstance":false}]}
2022-02-13 12:30:36.169  - debug: homekit-controller.0 (17060) sendTo "getDiscoveredDevices" to system.adapter.admin.0 from system.adapter.homekit-controller.0
2022-02-13 12:30:48.359  - debug: homekit-controller.0 (17060) Message pairDevice received: {"command":"pairDevice","message":{"deviceId":"BLE-0D:30:8F:xx:xx:xx","pin":"yyy-yy-yyy"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-0D:30:8F:xx:xx:xx","pin":"yyy-yy-yyy"},"id":78,"ack":false,"time":1644751848356},"_id":61388364})
  hap-controller:gatt-connection connect peripheral +0ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Write for characteristic 0000004f0000100080000026bb765291 0003001100 +857ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Received data for characteristic 0000004f0000100080000026bb765291 0200000300010102 +58ms
  hap-controller:gatt-connection disconnect peripheral +1ms
  hap-controller:gatt-connection Peripheral disconnected +16ms
2022-02-13 12:30:49.301  - info: homekit-controller.0 (17060) Use PairMethod 0 to pair BLE-0D:30:8F:xx:xx:xx
2022-02-13 12:30:49.303  - debug: homekit-controller.0 (17060) BLE-0D:30:8F:xx:xx:xx Start Homekit Device Client initialization
  hap-controller:gatt-connection connect peripheral +8ms
  hap-controller:gatt-connection Peripheral disconnected +308ms
2022-02-13 12:30:49.616  - debug: homekit-controller.0 (17060) Response to Command pairDevice: {"success":false,"error":"Cannot pair with device BLE-0D:30:8F:xx:xx:xx because of error undefined (undefined): undefined"}
2022-02-13 12:30:49.617  - debug: homekit-controller.0 (17060) sendTo "pairDevice" to system.adapter.admin.0 from system.adapter.homekit-controller.0

[apollon77]

@pql In dem Fall bekommt das Adapter keine Antwort vom Gerät. Geht ein Identify? Ich hab inzwischen so bissl da sGefühl das der RPI "Onboard" BLE zickig ist ... ggf mal mit nem BLE USB Stick versuchen?

[pql]

@apollon77 Identify funktioniert, Gerät blinkt entsprechend und der Debug bestätigt dies auch mit einem "Success"

2022-02-13 13:36:36.527  - debug: homekit-controller.0 (28302) Message identify received: {"command":"identify","message":{"deviceId":"BLE-0D:30:8F:xx:xx:xx"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-0D:30:8F:xx:xx:xx"},"id":95,"ack":false,"time":1644755796524},"_id":61388381})
2022-02-13 13:36:36.529  - debug: homekit-controller.0 (28302) Device BLE-0D:30:8F:xx:xx:xx: Identify triggered
  hap-controller:gatt-connection connect peripheral +0ms
  hap-controller:tlv Add 1 bytes for tag 1: 01 +0ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Write for characteristic 000000140000100080000026bb765291 00020002000300010101 +924ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Received data for characteristic 000000140000100080000026bb765291 020000 +59ms
  hap-controller:gatt-connection disconnect peripheral +0ms
  hap-controller:gatt-connection Peripheral disconnected +17ms
2022-02-13 13:36:37.538  - debug: homekit-controller.0 (28302) Response to Command identify: {"success":true,"error":false}
2022-02-13 13:36:37.542  - debug: homekit-controller.0 (28302) sendTo "identify" to system.adapter.admin.0 from system.adapter.homekit-controller.0

USB BLE Stick hab ich nicht zur Hand, müsste mir dann erst einen besorgen

[apollon77]

@pql Also beimn Pairen sieht man das das Gerät auf den Connect versuch antwortet wo die unterstützten Pairing Methoden gelesen werden.Danach aber eine zweite Verbindung nicht annimmt um das eigentliche Pairing zu machen. Ich schaue nachher nochmal

EDIT: Code Seitig sieht an sich alles korrekt aus ... keine Ahnung warum das zickt und kann es auch nicht nachstellen

[pql]

@apollon77 Hab jetzt einen USB Stick, gleiches Spiel; Identify funktioniert, Pairing nicht.

Log-Output ist diesmal aber etwas mehr was den Pairing Connect an geht.. Es kommt auf jeden Fall etwas zurück

2022-02-15 17:46:01.425  - debug: homekit-controller.0 (3773) Message pairDevice received: {"command":"pairDevice","message":{"deviceId":"BLE-0D:30:8F:xx:xx:xx","pin":"xxx-xx-xxx"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-0D:30:8F:xx:xx:xx","pin":"xxx-xx-xxx"},"id":16,"ack":false,"time":1644943561422},"_id":32016392})
  hap-controller:gatt-connection connect peripheral +16s
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Write for characteristic 0000004f0000100080000026bb765291 0003001100 +538ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Received data for characteristic 0000004f0000100080000026bb765291 0200000300010102 +75ms
  hap-controller:gatt-connection disconnect peripheral +0ms
  hap-controller:gatt-connection Peripheral disconnected +2s
2022-02-15 17:46:04.048  - info: homekit-controller.0 (3773) Use PairMethod 0 to pair BLE-0D:30:8F:xx:xx:xx
2022-02-15 17:46:04.051  - debug: homekit-controller.0 (3773) BLE-0D:30:8F:xx:xx:xx Start Homekit Device Client initialization
  hap-controller:gatt-connection connect peripheral +7ms
  hap-controller:tlv Add 1 bytes for tag 6: 01 +19s
  hap-controller:tlv Add 1 bytes for tag 0: 00 +1ms
  hap-controller:tlv Add 6 bytes for tag 1: 060101000100 +0ms
  hap-controller:tlv Add 1 bytes for tag 9: 01 +0ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Write for characteristic 0000004c0000100080000026bb765291 0002000f000b000106060101000100090101 +435ms
  hap-controller:gatt-connection dbc159db8b1b/db:c1:59:db:8b:1b Received data for characteristic 0000004c0000100080000026bb765291 0200009d0101ff06010203ff78b224faeea2de3cf805707ecd32546d248663b4689e88ff20ccefbeb56632d66398a9baea47555684b3b09ec4afe72c4ed3c33f5ce78c69fa7191cad76c879e22e51321de66442d9c89850c39546c8e3643679ac751d8d539b0c73c56dd8280be4d14215ee81e1eeb14cc05061cb6e486aeb00699207138d0577e288bba6fb6c23c97c3157f69f2ba8da537ad274cab0d5f76cff5b4ae9a828cdac434a42bcbe0132f8c3638a48de223a01d2ba06c92284efbaa3b25c3742ac138b1ad182fa614d12fdfa44cb89ccf3323cf92e8d7627dcdb1ba27403853fea875693785a68ee6731e96172ad3f04677bc57a36352f5b0ff5e +583ms
  hap-controller:gatt-connection Peripheral disconnected +45ms
2022-02-15 17:46:05.118  - debug: homekit-controller.0 (3773) Response to Command pairDevice: {"success":false,"error":"Cannot pair with device BLE-0D:30:8F:xx:xx:xx because of error undefined (undefined): undefined"}
2022-02-15 17:46:05.119  - debug: homekit-controller.0 (3773) sendTo "pairDevice" to system.adapter.admin.0 from system.adapter.homekit-controller.0

[apollon77]

@pql Inndem Fall kommt er etwas weiter aber das Gerät macht immer noch einen Disconnect. IST es vllt zu nah oder zu weit weg? mal frisch resetten?

Also wenn ich es richtig verstehe, dann sagen die Daten das 500 Byte kommen, es sind aber nur 150 und dann disconnect ...

[pql]

@apollon77 frisch resettet (mehrfach) und näher dran leider ohne Erfolg. Gleiche Thematik.

Aber ok, dann wird das wohl am Eve Energy liegen. Direktes Pairing mit iOS funktioniert tadelos.