@apollon77 sagte in Alpha Test js-controller 4.0:
@fortune95 Legst Du dann bitte 4 GitHub issues an? ;-)) (bzw 3 weil ich glaube shelly gibts schon)
Done!
@apollon77 sagte in Alpha Test js-controller 4.0:
@fortune95 Legst Du dann bitte 4 GitHub issues an? ;-)) (bzw 3 weil ich glaube shelly gibts schon)
Done!
@apollon77
Upadate auf 4.0.3 lief mit den bereits bekannten Warnungen von den Adaptern Yamaha, Shelly und shuttercontrol durch.
Braucht der neue js-controller weniger Speicher?
Hi, hatte heute morgen folgenden Fehler nach einem Neustart des Adapters im Log:
2022-02-22 06:12:00.875 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.876 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.877 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.883 - warn: shelly.0 (15030) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-02-22 06:12:00.950 - error: host.iobroker Caught by controller[1]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.962 - error: host.iobroker Caught by controller[3]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.962 - error: host.iobroker instance system.adapter.shelly.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
@apollon77
OK, also nochmal...
Nachdem ich den Adapter über die Shell gestartet hatte passierte im Log erstmal gar nichts.
Darufhin habe ich mal den Knopf am Eve gedrückt um ihn aufzuwecken. Wenn ich es richtig interpretiere hat er sich dann auch im Adapter kurz gemeldet.
Beim nachfolgenden Identifizieren kam jedoch prompt die bekannte Fehlermeldung.
iobroker@iobroker:~$ DEBUG=hap* node /opt/iobroker/node_modules/iobroker.homekit-controller/build/main.js 0 --debug --logs
2022-03-17 06:11:29.897 - debug: homekit-controller.0 (23910) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-03-17 06:11:29.922 - debug: homekit-controller.0 (23910) Objects client ready ... initialize now
2022-03-17 06:11:29.923 - debug: homekit-controller.0 (23910) Objects create System PubSub Client
2022-03-17 06:11:29.924 - debug: homekit-controller.0 (23910) Objects create User PubSub Client
2022-03-17 06:11:29.957 - debug: homekit-controller.0 (23910) Objects client initialize lua scripts
2022-03-17 06:11:29.959 - debug: homekit-controller.0 (23910) Objects connected to redis: 127.0.0.1:9001
2022-03-17 06:11:29.975 - debug: homekit-controller.0 (23910) Redis States: Use Redis connection: 127.0.0.1:6379
2022-03-17 06:11:29.977 - debug: homekit-controller.0 (23910) States create System PubSub Client
2022-03-17 06:11:29.978 - debug: homekit-controller.0 (23910) States create User PubSub Client
2022-03-17 06:11:29.980 - debug: homekit-controller.0 (23910) States connected to redis: 127.0.0.1:6379
2022-03-17 06:11:29.991 - debug: homekit-controller.0 (23910) Plugin sentry Initialize Plugin (enabled=true)
2022-03-17 06:11:30.043 - error: homekit-controller.0 (23910) adapter disabled
2022-03-17 06:11:30.085 - info: homekit-controller.0 (23910) starting. Version 0.4.3 (non-npm: Apollon77/ioBroker.homekit-controller#b7c7f7174ee7700864d870c2125c4d00aba85aa5) in /opt/iobroker/node_modules/iobroker.homekit-controller, node: v14.19.0, js-controller: 4.0.21
2022-03-17 06:11:30.160 - debug: homekit-controller.0 (23910) state homekit-controller.0.info.connection changed: false (ack = true)
2022-03-17 06:11:30.164 - debug: homekit-controller.0 (23910) Init 1 known devices without discovery ...
2022-03-17 06:11:30.164 - debug: homekit-controller.0 (23910) Init BLE-6E:B1:4A:68:AA:BB as known device
2022-03-17 06:11:30.165 - info: homekit-controller.0 (23910) BLE-6E:B1:4A:68:AA:BB (Eve Degree 5980) found without pairing data but available for pairing: Create basic objects
2022-03-17 06:11:30.165 - debug: homekit-controller.0 (23910) Service: {"name":"Eve Degree 5980","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"6e:b1:4a:68:aa:bb","ACID":10,"GSN":6,"CN":3,"CV":2,"c#":3,"id":"6e:b1:4a:68:aa:bb","ci":10,"availableToPair":true}
2022-03-17 06:11:30.174 - debug: homekit-controller.0 (23910) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.connectionType changed: BLE (ack = true)
2022-03-17 06:11:30.177 - debug: homekit-controller.0 (23910) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.id changed: 6e:b1:4a:68:aa:bb (ack = true)
2022-03-17 06:11:30.181 - debug: homekit-controller.0 (23910) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.connected changed: false (ack = true)
2022-03-17 06:11:30.186 - debug: homekit-controller.0 (23910) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.admin.isPaired changed: false (ack = true)
2022-03-17 06:11:30.190 - debug: homekit-controller.0 (23910) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.lastDiscovered changed: 1647493890166 (ack = true)
2022-03-17 06:14:23.793 - debug: homekit-controller.0 (23910) Message getDiscoveredDevices received: {"command":"getDiscoveredDevices","message":null,"from":"system.adapter.admin.0","callback":{"message":null,"id":169,"ack":false,"time":1647494063792},"_id":67504347})
2022-03-17 06:14:23.794 - debug: homekit-controller.0 (23910) Response to Command getDiscoveredDevices: {"success":true,"error":false,"devices":[{"id":"BLE-6E:B1:4A:68:AA:BB","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":true,"discoveredName":"Eve Degree 5980","discoveredCategory":"Sensor","pairedWithThisInstance":false}]}
2022-03-17 06:15:33.249 - debug: homekit-controller.0 (23910) Message identify received: {"command":"identify","message":{"deviceId":"BLE-6E:B1:4A:68:AA:BB"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-6E:B1:4A:68:AA:BB"},"id":170,"ack":false,"time":1647494133248},"_id":67504348})
2022-03-17 06:15:33.249 - debug: homekit-controller.0 (23910) Device BLE-6E:B1:4A:68:AA:BB: Identify triggered
2022-03-17 06:15:33.250 - debug: homekit-controller.0 (23910) Response to Command identify: {"success":false,"error":"Cannot identify device BLE-6E:B1:4A:68:AA:BB because of error undefined: Cannot read property 'state' of undefined"}
Im hcidump gibt es aber keinen Eintrag zu dem Zeitpunkt wo ich den Eve geweckt hatte?
@apollon77
Manchmal ist es so einfach...
Hier die Logs:
log.txt
iobroker@iobroker:~$ DEBUG=hap* node /opt/iobroker/node_modules/iobroker.homekit-controller/build/main.js 0 --debug --logs
2022-03-16 05:17:11.668 - debug: homekit-controller.0 (16117) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-03-16 05:17:11.708 - debug: homekit-controller.0 (16117) Objects client ready ... initialize now
2022-03-16 05:17:11.709 - debug: homekit-controller.0 (16117) Objects create System PubSub Client
2022-03-16 05:17:11.710 - debug: homekit-controller.0 (16117) Objects create User PubSub Client
2022-03-16 05:17:11.733 - debug: homekit-controller.0 (16117) Objects client initialize lua scripts
2022-03-16 05:17:11.735 - debug: homekit-controller.0 (16117) Objects connected to redis: 127.0.0.1:9001
2022-03-16 05:17:11.749 - debug: homekit-controller.0 (16117) Redis States: Use Redis connection: 127.0.0.1:6379
2022-03-16 05:17:11.751 - debug: homekit-controller.0 (16117) States create System PubSub Client
2022-03-16 05:17:11.751 - debug: homekit-controller.0 (16117) States create User PubSub Client
2022-03-16 05:17:11.754 - debug: homekit-controller.0 (16117) States connected to redis: 127.0.0.1:6379
2022-03-16 05:17:11.766 - debug: homekit-controller.0 (16117) Plugin sentry Initialize Plugin (enabled=true)
2022-03-16 05:17:11.818 - error: homekit-controller.0 (16117) adapter disabled
2022-03-16 05:17:11.866 - info: homekit-controller.0 (16117) starting. Version 0.4.3 (non-npm: Apollon77/ioBroker.homekit-controller#b7c7f7174ee7700864d870c2125c4d00aba85aa5) in /opt/iobroker/node_modules/iobroker.homekit-controller, node: v14.19.0, js-controller: 4.0.21
2022-03-16 05:17:11.936 - debug: homekit-controller.0 (16117) state homekit-controller.0.info.connection changed: false (ack = true)
2022-03-16 05:17:11.940 - debug: homekit-controller.0 (16117) Init 1 known devices without discovery ...
2022-03-16 05:17:11.940 - debug: homekit-controller.0 (16117) Init BLE-6E:B1:4A:68:AA:BB as known device
2022-03-16 05:17:11.940 - info: homekit-controller.0 (16117) BLE-6E:B1:4A:68:AA:BB (Eve Degree 5980) found without pairing data but available for pairing: Create basic objects
2022-03-16 05:17:11.941 - debug: homekit-controller.0 (16117) Service: {"name":"Eve Degree 5980","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"6e:b1:4a:68:aa:bb","ACID":10,"GSN":6,"CN":3,"CV":2,"c#":3,"id":"6e:b1:4a:68:aa:bb","ci":10,"availableToPair":true}
2022-03-16 05:17:11.952 - debug: homekit-controller.0 (16117) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.connectionType changed: BLE (ack = true)
2022-03-16 05:17:11.955 - debug: homekit-controller.0 (16117) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.id changed: 6e:b1:4a:68:aa:bb (ack = true)
2022-03-16 05:17:11.958 - debug: homekit-controller.0 (16117) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.connected changed: false (ack = true)
2022-03-16 05:17:11.963 - debug: homekit-controller.0 (16117) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.admin.isPaired changed: false (ack = true)
2022-03-16 05:17:11.967 - debug: homekit-controller.0 (16117) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.lastDiscovered changed: 1647404231941 (ack = true)
2022-03-16 05:17:29.918 - debug: homekit-controller.0 (16117) Message getDiscoveredDevices received: {"command":"getDiscoveredDevices","message":null,"from":"system.adapter.admin.0","callback":{"message":null,"id":119,"ack":false,"time":1647404249917},"_id":67504295})
2022-03-16 05:17:29.919 - debug: homekit-controller.0 (16117) Response to Command getDiscoveredDevices: {"success":true,"error":false,"devices":[{"id":"BLE-6E:B1:4A:68:AA:BB","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":true,"discoveredName":"Eve Degree 5980","discoveredCategory":"Sensor","pairedWithThisInstance":false}]}
2022-03-16 05:17:35.645 - debug: homekit-controller.0 (16117) Message identify received: {"command":"identify","message":{"deviceId":"BLE-6E:B1:4A:68:AA:BB"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-6E:B1:4A:68:AA:BB"},"id":120,"ack":false,"time":1647404255644},"_id":67504296})
2022-03-16 05:17:35.645 - debug: homekit-controller.0 (16117) Device BLE-6E:B1:4A:68:AA:BB: Identify triggered
2022-03-16 05:17:35.646 - debug: homekit-controller.0 (16117) Response to Command identify: {"success":false,"error":"Cannot identify device BLE-6E:B1:4A:68:AA:BB because of error undefined: Cannot read property 'state' of undefined"}
^Ciobroker@iobroker:~$ DEBUG=hap* node /opt/iobroker/node_modules/iobroker.homekit-controller/build/main.js 0 --debug --logs
2022-03-16 05:19:05.630 - debug: homekit-controller.0 (16134) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-03-16 05:19:05.650 - debug: homekit-controller.0 (16134) Objects client ready ... initialize now
2022-03-16 05:19:05.656 - debug: homekit-controller.0 (16134) Objects create System PubSub Client
2022-03-16 05:19:05.657 - debug: homekit-controller.0 (16134) Objects create User PubSub Client
2022-03-16 05:19:05.688 - debug: homekit-controller.0 (16134) Objects client initialize lua scripts
2022-03-16 05:19:05.690 - debug: homekit-controller.0 (16134) Objects connected to redis: 127.0.0.1:9001
2022-03-16 05:19:05.703 - debug: homekit-controller.0 (16134) Redis States: Use Redis connection: 127.0.0.1:6379
2022-03-16 05:19:05.705 - debug: homekit-controller.0 (16134) States create System PubSub Client
2022-03-16 05:19:05.706 - debug: homekit-controller.0 (16134) States create User PubSub Client
2022-03-16 05:19:05.708 - debug: homekit-controller.0 (16134) States connected to redis: 127.0.0.1:6379
2022-03-16 05:19:05.720 - debug: homekit-controller.0 (16134) Plugin sentry Initialize Plugin (enabled=true)
2022-03-16 05:19:05.770 - error: homekit-controller.0 (16134) adapter disabled
2022-03-16 05:19:05.824 - info: homekit-controller.0 (16134) starting. Version 0.4.3 (non-npm: Apollon77/ioBroker.homekit-controller#b7c7f7174ee7700864d870c2125c4d00aba85aa5) in /opt/iobroker/node_modules/iobroker.homekit-controller, node: v14.19.0, js-controller: 4.0.21
2022-03-16 05:19:05.893 - debug: homekit-controller.0 (16134) state homekit-controller.0.info.connection changed: false (ack = true)
2022-03-16 05:19:05.897 - debug: homekit-controller.0 (16134) Init 1 known devices without discovery ...
2022-03-16 05:19:05.897 - debug: homekit-controller.0 (16134) Init BLE-6E:B1:4A:68:AA:BB as known device
2022-03-16 05:19:05.898 - info: homekit-controller.0 (16134) BLE-6E:B1:4A:68:AA:BB (Eve Degree 5980) found without pairing data but available for pairing: Create basic objects
2022-03-16 05:19:05.899 - debug: homekit-controller.0 (16134) Service: {"name":"Eve Degree 5980","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"6e:b1:4a:68:aa:bb","ACID":10,"GSN":6,"CN":3,"CV":2,"c#":3,"id":"6e:b1:4a:68:aa:bb","ci":10,"availableToPair":true}
2022-03-16 05:19:05.909 - debug: homekit-controller.0 (16134) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.connectionType changed: BLE (ack = true)
2022-03-16 05:19:05.913 - debug: homekit-controller.0 (16134) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.id changed: 6e:b1:4a:68:aa:bb (ack = true)
2022-03-16 05:19:05.915 - debug: homekit-controller.0 (16134) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.connected changed: false (ack = true)
2022-03-16 05:19:05.920 - debug: homekit-controller.0 (16134) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.admin.isPaired changed: false (ack = true)
2022-03-16 05:19:05.923 - debug: homekit-controller.0 (16134) state homekit-controller.0.BLE-6E:B1:4A:68:AA:BB.info.lastDiscovered changed: 1647404345899 (ack = true)
2022-03-16 05:19:30.853 - debug: homekit-controller.0 (16134) Message getDiscoveredDevices received: {"command":"getDiscoveredDevices","message":null,"from":"system.adapter.admin.0","callback":{"message":null,"id":121,"ack":false,"time":1647404370852},"_id":67504297})
2022-03-16 05:19:30.853 - debug: homekit-controller.0 (16134) Response to Command getDiscoveredDevices: {"success":true,"error":false,"devices":[{"id":"BLE-6E:B1:4A:68:AA:BB","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":true,"discoveredName":"Eve Degree 5980","discoveredCategory":"Sensor","pairedWithThisInstance":false}]}
2022-03-16 05:19:32.854 - debug: homekit-controller.0 (16134) Message identify received: {"command":"identify","message":{"deviceId":"BLE-6E:B1:4A:68:AA:BB"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-6E:B1:4A:68:AA:BB"},"id":122,"ack":false,"time":1647404372853},"_id":67504298})
2022-03-16 05:19:32.854 - debug: homekit-controller.0 (16134) Device BLE-6E:B1:4A:68:AA:BB: Identify triggered
2022-03-16 05:19:32.855 - debug: homekit-controller.0 (16134) Response to Command identify: {"success":false,"error":"Cannot identify device BLE-6E:B1:4A:68:AA:BB because of error undefined: Cannot read property 'state' of undefined"}
@apollon77
Wie kann ich denn beide Befehle über die Shell zeitgleich starten? Hast du da einen Tipp für mich. Wenn ich einen von beiden Befehle absetze, ist die Shell blockiert und lässt nur mit STRG - C abbrechen.
@apollon77
Wie gesagt hatte versucht den Treiber zu updaten... leider war mein letztes Image Backup ein Monat alt..., hab jetzt alles wieder auf Stand und der BLE Adapter ist auch wieder auffindbar.
Habe den Adapter über den Admin gestartet und vorab über die Shell den hcidump angeworfen. Im Admin bekam ich beim Versuch das BLE zu identifizieren, die folgende Fehlermeldung:
HCI sniffer - Bluetooth packet analyzer ver 5.55
device: hci0 snap_len: 1500 filter: 0xffffffffffffffff
2022-03-14 20:06:06.432692 < HCI Command: Set Event Mask (0x03|0x0001) plen 8
Mask: 0xfffffbff07f8bf3d
2022-03-14 20:06:06.433869 > HCI Event: Command Complete (0x0e) plen 4
Set Event Mask (0x03|0x0001) ncmd 2
status 0x00
2022-03-14 20:06:06.433896 < HCI Command: LE Set Event Mask (0x08|0x0001) plen 8
mask 0x1f00000000000000 (Reserved)
2022-03-14 20:06:06.434835 > HCI Event: Command Complete (0x0e) plen 4
LE Set Event Mask (0x08|0x0001) ncmd 2
status 0x00
2022-03-14 20:06:06.434858 < HCI Command: Read Local Version Information (0x04|0x0001) plen 0
2022-03-14 20:06:06.435878 > HCI Event: Command Complete (0x0e) plen 12
Read Local Version Information (0x04|0x0001) ncmd 2
status 0x00
HCI Version: 5.1 (0xa) HCI Revision: 0xb
LMP Version: 5.1 (0xa) LMP Subversion: 0x8761
Manufacturer: Realtek Semiconductor Corporation (93)
2022-03-14 20:06:06.435902 < HCI Command: Write LE Host Supported (0x03|0x006d) plen 2
01 00
2022-03-14 20:06:06.436832 > HCI Event: Command Complete (0x0e) plen 4
Write LE Host Supported (0x03|0x006d) ncmd 2
00
2022-03-14 20:06:06.436858 < HCI Command: Read LE Host Supported (0x03|0x006c) plen 0
2022-03-14 20:06:06.437836 > HCI Event: Command Complete (0x0e) plen 6
Read LE Host Supported (0x03|0x006c) ncmd 2
00 01 00
2022-03-14 20:06:06.437860 < HCI Command: LE Read Buffer Size (0x08|0x0002) plen 0
2022-03-14 20:06:06.438834 > HCI Event: Command Complete (0x0e) plen 7
LE Read Buffer Size (0x08|0x0002) ncmd 2
status 0x00 pktlen 0x00fb maxpkt 0x08
2022-03-14 20:06:06.438858 < HCI Command: Read BD ADDR (0x04|0x0009) plen 0
2022-03-14 20:06:06.439837 > HCI Event: Command Complete (0x0e) plen 10
Read BD ADDR (0x04|0x0009) ncmd 2
status 0x00 bdaddr 08:BE:AC:20:8E:F2
2022-03-14 20:06:06.442284 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
value 0x00 (scanning disabled)
filter duplicates 0x01 (enabled)
2022-03-14 20:06:06.443833 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00
2022-03-14 20:06:06.443859 < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
type 0x01 (active)
interval 10.000ms window 10.000ms
own address: 0x00 (Public) policy: All
2022-03-14 20:06:06.444827 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Parameters (0x08|0x000b) ncmd 2
status 0x00
2022-03-14 20:06:06.447855 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
value 0x00 (scanning disabled)
filter duplicates 0x01 (enabled)
2022-03-14 20:06:06.448834 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00
2022-03-14 20:06:06.448861 < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
type 0x01 (active)
interval 10.000ms window 10.000ms
@apollon77
hab mich wohl verrannt, hab versucht den treiber des BLE adatpters zu updaten.
Jetzt findet bluetoothctl keinen Controller mehr.
@apollon77
Mit sudo bekomme ich die gleiche Fehlermeldung
Hi, hab es jetzt mal über die Shell versucht, hier bekomme ich ein Authentication Fehler.
Hast Du eine Idee wie ich den beheben kann.
iobroker@iobroker:~$ bluetoothctl
Agent registered
[CHG] Controller 08:BE:AC:20:8E:F2 Pairable: yes
[bluetooth]# devices
Device 4D:C8:A4:58:F8:96 4D-C8-A4-58-F8-96
Device 09:CB:9E:AF:84:DF 09-CB-9E-AF-84-DF
Device FE:4F:B0:DD:AA:22 Eve Degree 5980
Device 71:B7:B8:6D:37:1D 71-B7-B8-6D-37-1D
Device 51:DA:80:04:EA:0C 51-DA-80-04-EA-0C
Device 50:2D:26:B8:7F:B1 50-2D-26-B8-7F-B1
[DEL] Device 50:2D:26:B8:7F:B1 50-2D-26-B8-7F-B1
[DEL] Device 71:B7:B8:6D:37:1D 71-B7-B8-6D-37-1D
[DEL] Device 09:CB:9E:AF:84:DF 09-CB-9E-AF-84-DF
[DEL] Device 51:DA:80:04:EA:0C 51-DA-80-04-EA-0C
[DEL] Device 4D:C8:A4:58:F8:96 4D-C8-A4-58-F8-96
[bluetooth]# pair FE:4F:B0:DD:AA:22
Attempting to pair with FE:4F:B0:DD:AA:22
[CHG] Device FE:4F:B0:DD:AA:22 Connected: yes
Failed to pair: org.bluez.Error.AuthenticationFailed
[CHG] Device FE:4F:B0:DD:AA:22 Connected: no
Hi, hatte heute morgen folgenden Fehler nach einem Neustart des Adapters im Log:
2022-02-22 06:12:00.875 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.876 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.877 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.883 - warn: shelly.0 (15030) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-02-22 06:12:00.950 - error: host.iobroker Caught by controller[1]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.962 - error: host.iobroker Caught by controller[3]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.962 - error: host.iobroker instance system.adapter.shelly.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
Node.js: v14.19.0
js-controller: 4.0.15
Habe gerade folgendes nach einem Neustart des Shelly Adapters im Log gefunden:
2022-02-22 06:12:00.875 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.876 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.877 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.883 - warn: shelly.0 (15030) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-02-22 06:12:00.950 - error: host.iobroker Caught by controller[1]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.962 - error: host.iobroker Caught by controller[3]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.962 - error: host.iobroker instance system.adapter.shelly.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
@apollon77
Habe den Adapter wie im Issue beschrieben von Gihub installiert und das Log erstellt:
iobroker@iobroker:~$ DEBUG=hap* node /opt/iobroker/node_modules/iobroker.homekit-controller/build/main.js 0 --debug --logs
2022-02-18 16:07:47.793 - debug: homekit-controller.0 (6682) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-02-18 16:07:47.815 - debug: homekit-controller.0 (6682) Objects client ready ... initialize now
2022-02-18 16:07:47.816 - debug: homekit-controller.0 (6682) Objects create System PubSub Client
2022-02-18 16:07:47.817 - debug: homekit-controller.0 (6682) Objects create User PubSub Client
2022-02-18 16:07:47.838 - debug: homekit-controller.0 (6682) Objects client initialize lua scripts
2022-02-18 16:07:47.840 - debug: homekit-controller.0 (6682) Objects connected to redis: 127.0.0.1:9001
2022-02-18 16:07:47.854 - debug: homekit-controller.0 (6682) Redis States: Use Redis connection: 127.0.0.1:6379
2022-02-18 16:07:47.856 - debug: homekit-controller.0 (6682) States create System PubSub Client
2022-02-18 16:07:47.857 - debug: homekit-controller.0 (6682) States create User PubSub Client
2022-02-18 16:07:47.860 - debug: homekit-controller.0 (6682) States connected to redis: 127.0.0.1:6379
2022-02-18 16:07:47.872 - debug: homekit-controller.0 (6682) Plugin sentry Initialize Plugin (enabled=true)
2022-02-18 16:07:47.933 - error: homekit-controller.0 (6682) adapter disabled
2022-02-18 16:07:47.978 - info: homekit-controller.0 (6682) starting. Version 0.4.3 (non-npm: Apollon77/ioBroker.homekit-controller#c614463e84bfe9c4e7d5d6038d0babdbcb55b852) in /opt/iobroker/node_modules/iobroker.homekit-controller, node: v14.19.0, js-controller: 4.0.12
2022-02-18 16:07:48.050 - debug: homekit-controller.0 (6682) state homekit-controller.0.info.connection changed: false (ack = true)
2022-02-18 16:07:53.221 - debug: homekit-controller.0 (6682) Discovered BLE device up: 25:3e:f0:cc:4c:64/Eve
2022-02-18 16:07:53.221 - debug: homekit-controller.0 (6682) BLE-25:3E:F0:CC:4C:64 Discovered BLE device: {"name":"Eve","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"25:3e:f0:cc:4c:64","ACID":10,"GSN":1,"CN":3,"CV":2,"c#":3,"id":"25:3e:f0:cc:4c:64","ci":10,"availableToPair":true}
2022-02-18 16:07:53.222 - info: homekit-controller.0 (6682) BLE-25:3E:F0:CC:4C:64 (Eve) found without pairing data but available for pairing: Create basic objects
2022-02-18 16:07:53.222 - debug: homekit-controller.0 (6682) Service: {"name":"Eve","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"25:3e:f0:cc:4c:64","ACID":10,"GSN":1,"CN":3,"CV":2,"c#":3,"id":"25:3e:f0:cc:4c:64","ci":10,"availableToPair":true}
2022-02-18 16:07:53.235 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.connectionType changed: BLE (ack = true)
2022-02-18 16:07:53.237 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.connectionType changed: BLE (ack = true)
2022-02-18 16:07:53.240 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.id changed: 25:3e:f0:cc:4c:64 (ack = true)
2022-02-18 16:07:53.243 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.connected changed: false (ack = true)
2022-02-18 16:07:53.248 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.admin.isPaired changed: false (ack = true)
2022-02-18 16:07:53.251 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.lastDiscovered changed: 1645196873223 (ack = true)
2022-02-18 16:07:53.255 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.admin.pairWithPin changed: (ack = true)
2022-02-18 16:07:53.258 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.admin.identify changed: false (ack = true)
2022-02-18 16:08:10.833 - debug: homekit-controller.0 (6682) Message getDiscoveredDevices received: {"command":"getDiscoveredDevices","message":null,"from":"system.adapter.admin.0","callback":{"message":null,"id":112,"ack":false,"time":1645196890832},"_id":85128405})
2022-02-18 16:08:10.833 - debug: homekit-controller.0 (6682) Response to Command getDiscoveredDevices: {"success":true,"error":false,"devices":[{"id":"BLE-25:3E:F0:CC:4C:64","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":true,"discoveredName":"Eve","discoveredCategory":"Sensor","pairedWithThisInstance":false}]}
2022-02-18 16:08:12.873 - debug: homekit-controller.0 (6682) Message identify received: {"command":"identify","message":{"deviceId":"BLE-25:3E:F0:CC:4C:64"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-25:3E:F0:CC:4C:64"},"id":113,"ack":false,"time":1645196892872},"_id":85128406})
2022-02-18 16:08:12.873 - debug: homekit-controller.0 (6682) Device BLE-25:3E:F0:CC:4C:64: Identify triggered
hap-controller:gatt-connection connect peripheral +0ms
hap-controller:tlv Add 1 bytes for tag 1: 01 +0ms
hap-controller:gatt-connection e60614286935/e6:06:14:28:69:35 Write for characteristic 000000140000100080000026bb765291 00020003000300010101 +6s
hap-controller:gatt-connection e60614286935/e6:06:14:28:69:35 Received data for characteristic 000000140000100080000026bb765291 020000 +180ms
hap-controller:gatt-connection disconnect peripheral +0ms
hap-controller:gatt-connection Peripheral disconnected +45ms
2022-02-18 16:08:18.600 - debug: homekit-controller.0 (6682) Response to Command identify: {"success":true,"error":false}
2022-02-18 16:08:20.110 - debug: homekit-controller.0 (6682) Message getDiscoveredDevices received: {"command":"getDiscoveredDevices","message":null,"from":"system.adapter.admin.0","callback":{"message":null,"id":114,"ack":false,"time":1645196900109},"_id":85128407})
2022-02-18 16:08:20.110 - debug: homekit-controller.0 (6682) Response to Command getDiscoveredDevices: {"success":true,"error":false,"devices":[{"id":"BLE-25:3E:F0:CC:4C:64","serviceType":"BLE","connected":false,"discovered":true,"availableToPair":true,"discoveredName":"Eve","discoveredCategory":"Sensor","pairedWithThisInstance":false}]}
2022-02-18 16:08:46.277 - debug: homekit-controller.0 (6682) Message pairDevice received: {"command":"pairDevice","message":{"deviceId":"BLE-25:3E:F0:CC:4C:64","pin":"843-54-008"},"from":"system.adapter.admin.0","callback":{"message":{"deviceId":"BLE-25:3E:F0:CC:4C:64","pin":"843-54-008"},"id":115,"ack":false,"time":1645196926277},"_id":85128408})
hap-controller:gatt-connection connect peripheral +28s
hap-controller:gatt-connection e60614286935/e6:06:14:28:69:35 Write for characteristic 0000004f0000100080000026bb765291 0003000f00 +4s
hap-controller:gatt-connection e60614286935/e6:06:14:28:69:35 Received data for characteristic 0000004f0000100080000026bb765291 0200000300010101 +225ms
hap-controller:gatt-connection disconnect peripheral +0ms
hap-controller:gatt-connection Peripheral disconnected +46ms
2022-02-18 16:08:50.462 - info: homekit-controller.0 (6682) Use PairMethod 0 to pair BLE-25:3E:F0:CC:4C:64
2022-02-18 16:08:50.463 - debug: homekit-controller.0 (6682) BLE-25:3E:F0:CC:4C:64 Start Homekit Device Client initialization
hap-controller:gatt-connection connect peripheral +2ms
2022-02-18 16:08:55.788 - debug: homekit-controller.0 (6682) Response to Command pairDevice: {"success":false,"error":"Cannot pair with device BLE-25:3E:F0:CC:4C:64 because of error undefined (undefined): Unknown Connection Identifier (0x2)"}
2022-02-18 16:11:45.843 - debug: homekit-controller.0 (6682) Discovered BLE device changed: 25:3e:f0:cc:4c:64/Eve Degree 5980
2022-02-18 16:11:45.843 - debug: homekit-controller.0 (6682) BLE-25:3E:F0:CC:4C:64 Discovered BLE device: {"name":"Eve Degree 5980","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"25:3e:f0:cc:4c:64","ACID":10,"GSN":2,"CN":3,"CV":2,"c#":3,"id":"25:3e:f0:cc:4c:64","ci":10,"availableToPair":true}
2022-02-18 16:11:45.843 - info: homekit-controller.0 (6682) BLE-25:3E:F0:CC:4C:64 (Eve Degree 5980) found without pairing data but available for pairing: Create basic objects
2022-02-18 16:11:45.844 - debug: homekit-controller.0 (6682) Service: {"name":"Eve Degree 5980","CoID":76,"TY":6,"AIL":49,"SF":1,"DeviceID":"25:3e:f0:cc:4c:64","ACID":10,"GSN":2,"CN":3,"CV":2,"c#":3,"id":"25:3e:f0:cc:4c:64","ci":10,"availableToPair":true}
2022-02-18 16:11:45.852 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.connectionType changed: BLE (ack = true)
2022-02-18 16:11:45.854 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.id changed: 25:3e:f0:cc:4c:64 (ack = true)
2022-02-18 16:11:45.858 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.connected changed: false (ack = true)
2022-02-18 16:11:45.863 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.admin.isPaired changed: false (ack = true)
2022-02-18 16:11:45.866 - debug: homekit-controller.0 (6682) state homekit-controller.0.BLE-25:3E:F0:CC:4C:64.info.lastDiscovered changed: 1645197105844 (ack = true)