search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
74.15k stars 31.13k forks source link

Homekit controller - Configured, but no entity available #14974

Closed beit-no1 closed 5 years ago

beit-no1 commented 6 years ago

Home Assistant release with the issue: 0.71.0

Last working Home Assistant release (if known): 0.71.0

Operating environment (Hass.io/Docker/Windows/etc.): Docker running on Synology NAS DSM918+ since version 0.65.0

Component/platform: https://www.home-assistant.io/components/homekit_controller/

Description of problem: I have 4 wifi switches (Insignia) which have an independent control app, but are also HomeKit compliant and have Homekit IDs for setup. I've wanted to use these in HA and was pleased when I saw the release of the HomeKit controller component. I've setup the switches as per documentation and once removed from the HomeKit app I was able to get the configuration link in the HA frontend. I configured the 4 switches by using the relevant HomeKit ID and they disappeared from the frontend.

I currently can't find any reference to the switches in the Entity listing, but as per the logs I can see they are being detected. I've filtered out lines containing homekit_controller, but can provide more relevant lines around the particular errors if necessary. I've been unable to determine the problem and have posted several queries in the forums. Others have also posted similar.

https://community.home-assistant.io/t/homekit-controller-not-working-correctly/54676 https://community.home-assistant.io/t/help-setup-devices-for-control-with-homekit-controller-component/55927 https://community.home-assistant.io/t/homekit-controller-how-to-find-entity-id-to-add-to-ui/55260

2018-06-14 18:10:01 DEBUG (SyncWorker_11) [homeassistant.components.homekit_controller] Discovered unique device D2:29:9D:1B:74:A9
2018-06-14 18:10:01 DEBUG (SyncWorker_10) [homeassistant.components.homekit_controller] Discovered unique device DE:2F:3E:B7:DA:C9
2018-06-14 18:10:01 DEBUG (SyncWorker_5) [homeassistant.components.homekit_controller] Discovered unique device 41:51:EE:B6:F6:90
2018-06-14 18:10:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Discovered unique device 05:74:78:20:68:EF
2018-06-14 18:10:01 DEBUG (SyncWorker_3) [homeassistant.components.homekit_controller] Discovered unique device E1:CA:79:52:0B:1B
2018-06-14 18:10:03 INFO (SyncWorker_11) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-14 18:10:03 INFO (SyncWorker_10) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-14 18:10:03 INFO (SyncWorker_5) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-14 18:10:03 INFO (SyncWorker_19) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-14 18:10:03 INFO (SyncWorker_3) [homeassistant.components.homekit_controller] Setting up Homekit device NL22
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

discovery:
   enable:
      - homekit

Traceback (if applicable):

Additional information:

MartinHjelmare commented 6 years ago

It's better to filter the log using the logger component than after the log was collected. There's a lot of lines missing now from the stack trace.

beit-no1 commented 6 years ago

@MartinHjelmare What filter do you recommend and I'll set it and do a restart. I had following configured.

logger:
  default: warning
  logs:
    homeassistant.components.homekit_controller: debug

Adding more of the details.

2018-06-15 03:26:24 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Discovered unique device 41:51:EE:B6:F6:90
2018-06-15 03:26:24 DEBUG (SyncWorker_3) [homeassistant.components.homekit_controller] Discovered unique device DE:2F:3E:B7:DA:C9
2018-06-15 03:26:24 DEBUG (SyncWorker_10) [homeassistant.components.homekit_controller] Discovered unique device D2:29:9D:1B:74:A9
2018-06-15 03:26:24 DEBUG (SyncWorker_13) [homeassistant.components.homekit_controller] Discovered unique device E1:CA:79:52:0B:1B
2018-06-15 03:26:24 DEBUG (SyncWorker_4) [homeassistant.components.homekit_controller] Discovered unique device 05:74:78:20:68:EF
2018-06-15 03:26:25 INFO (SyncWorker_14) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-15 03:26:25 INFO (SyncWorker_3) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-15 03:26:25 INFO (SyncWorker_10) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-15 03:26:25 INFO (SyncWorker_4) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-06-15 03:26:25 INFO (SyncWorker_13) [homeassistant.components.homekit_controller] Setting up Homekit device NL22
2018-06-15 03:26:28 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
    device = HKDevice(hass, host, port, model, hkid, config_num, config)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
    self.accessory_setup()
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
    data = json.loads(response.read().decode())
  File "/usr/local/lib/python3.6/http/client.py", line 462, in read
    s = self._safe_read(self.length)
  File "/usr/local/lib/python3.6/http/client.py", line 614, in _safe_read
    raise IncompleteRead(b''.join(s), amt)
http.client.IncompleteRead: IncompleteRead(0 bytes read, 747 more expected)
2018-06-15 03:26:28 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
    device = HKDevice(hass, host, port, model, hkid, config_num, config)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
    self.accessory_setup()
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
    data = json.loads(response.read().decode())
  File "/usr/local/lib/python3.6/http/client.py", line 462, in read
    s = self._safe_read(self.length)
  File "/usr/local/lib/python3.6/http/client.py", line 614, in _safe_read
    raise IncompleteRead(b''.join(s), amt)
http.client.IncompleteRead: IncompleteRead(0 bytes read, 747 more expected)
2018-06-15 03:26:28 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
    device = HKDevice(hass, host, port, model, hkid, config_num, config)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
    self.accessory_setup()
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
    data = json.loads(response.read().decode())
  File "/usr/local/lib/python3.6/http/client.py", line 462, in read
    s = self._safe_read(self.length)
  File "/usr/local/lib/python3.6/http/client.py", line 614, in _safe_read
    raise IncompleteRead(b''.join(s), amt)
http.client.IncompleteRead: IncompleteRead(0 bytes read, 747 more expected)
2018-06-15 03:26:28 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 243, in discovery_dispatch
    device = HKDevice(hass, host, port, model, hkid, config_num, config)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 98, in __init__
    self.accessory_setup()
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 112, in accessory_setup
    data = json.loads(response.read().decode())
  File "/usr/local/lib/python3.6/http/client.py", line 462, in read
    s = self._safe_read(self.length)
  File "/usr/local/lib/python3.6/http/client.py", line 614, in _safe_read
    raise IncompleteRead(b''.join(s), amt)
http.client.IncompleteRead: IncompleteRead(0 bytes read, 747 more expected)
MartinHjelmare commented 6 years ago

That filter is good. Thanks for providing the extended log. That log should be enough to start a conversation with someone that wants to fix the problem.

jcalderon71 commented 6 years ago

Same here, i have same kind of switches added to hassio v0.71 with the Homekit pin code but no entities were added

beit-no1 commented 6 years ago

@mjg59 Hi Mathew,
I reviewed your original development efforts on the HomeKit Controller and I also agree that it's a powerful feature for HA to open up an easy way to integrate HomeKit enable devices. Zwave could learn something from the method behind Homekit about making it end-user simple. I currently have 5 Insignia WiFi Homekit light switches that I can't control with HA and I don't really want to replace. I'm excited about the hope your efforts provide and I've seen others with the same desire.

Just wanted to make you aware of this and the issue that I posted (14974) around the homekit controller in the event you have some time to take a review.

https://github.com/home-assistant/home-assistant/pull/13346

Brian

mjg59 commented 6 years ago

I'm on vacation at the moment, but I'll work on this once I'm back. Thanks for the report!

beit-no1 commented 6 years ago

Enjoy your vacation and will watch for any help I can provide upon your return.

mjg59 commented 6 years ago

Ok I think I've identified the problem here and I'm working with upstream to come up with a fix. The issue is that the device is sending the headers and the body in two separate chunks, and the existing code can't detect that and so is ignoring the body. I have a patch that works, upstream has another approach, we'll see which looks better.

beit-no1 commented 6 years ago

Fantastic news. Maybe 0.73.0 will have it. If it gets in an 0.73.0b release let me know and I’ll test it as I’m in synology docker and should be quick. Brian

beit-no1 commented 6 years ago

@mjg59 Is there anyway to get your patch for 0.72.1 in advance to try it out early? (sorry, but excited to get my 5 switches up and running as I have some automations planned for them)

mjg59 commented 6 years ago

Try editing homeassistant/components/homekit_controller/__init__.py and replace

REQUIREMENTS = ['homekit==0.6']

with

REQUIREMENTS = ['https://github.com/mjg59/homekit_python/archive/http_read.zip#homekit==0.9']

and then restart hass.

beit-no1 commented 6 years ago

I made the change and did a restart. Not seeing any errors, but after quite some time I still don't see the light entities in HA. I have the one still for my daughters nanoleaf even though there are a couple of strange errors. See log so far. Will keep watching the log. Let me know if there is anything else that I can check to confirm it's in process.

2018-07-06 01:10:30 DEBUG (SyncWorker_5) [homeassistant.components.homekit_controller] Discovered unique device DE:2F:3E:B7:DA:C9
2018-07-06 01:10:30 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Discovered unique device D2:29:9D:1B:74:A9
2018-07-06 01:10:30 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Discovered unique device AE:2D:C4:BD:DD:82
2018-07-06 01:10:30 DEBUG (SyncWorker_11) [homeassistant.components.homekit_controller] Discovered unique device 05:74:78:20:68:EF
2018-07-06 01:10:30 DEBUG (SyncWorker_7) [homeassistant.components.homekit_controller] Discovered unique device 41:51:EE:B6:F6:90
2018-07-06 01:10:31 INFO (SyncWorker_5) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 01:10:31 INFO (SyncWorker_19) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 01:10:31 INFO (SyncWorker_7) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 01:10:31 INFO (SyncWorker_11) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 01:10:31 INFO (SyncWorker_14) [homeassistant.components.homekit_controller] Setting up Homekit device NL22
2018-07-06 01:10:31 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-06 01:10:31 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found Unknown Service: A18E1901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-06 01:10:31 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found Unknown Service: A18E7901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-06 01:10:31 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found Unknown Service: A18E6901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-06 01:10:31 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found lightbulb
2018-07-06 01:10:31 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found Unknown Service: A2
beit-no1 commented 6 years ago

@mjg59 I did notice that I have two entities for the nanoleaf (light.nl22 and light.aurora) so I'm thinking the homekit_controller one is the nl22 and it is not working correctly. the light.aurora is the one I've got in the UI and is working as expected (found by discovery via the new nanoleaf component). Just wanted to note that as the errors are related to the SyncWorker_14 that seems to be the NanoLeaf.

mjg59 commented 6 years ago

Ok I see it finding four of your switches, but unfortunately it doesn't seem to get much further. Do you see any messages about it taking over 10 seconds to do any setup? Are all of these devices paired with Home Assistant?

beit-no1 commented 6 years ago

I disconnected them from the Insignia software on the wifi and then paired them all with HA successfully.

I just checked the log file again before I responded and some errors came in. I only copied the first of what appears to be code errors for each device.

2018-07-06 01:42:24 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:42:55 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:43:26 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:43:56 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:44:27 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:44:57 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 244, in discovery_dispatch
    device = HKDevice(hass, host, port, model, hkid, config_num, config)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 99, in __init__
    self.accessory_setup()
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 113, in accessory_setup
    data = json.loads(response.read().decode())
  File "/usr/local/lib/python3.6/http/client.py", line 462, in read
    s = self._safe_read(self.length)
  File "/usr/local/lib/python3.6/http/client.py", line 612, in _safe_read
    chunk = self.fp.read(min(amt, MAXAMOUNT))
  File "/config/deps/lib/python3.6/site-packages/homekit/secure_http.py", line 48, in read
    self.data += self.parent._read_response()
  File "/config/deps/lib/python3.6/site-packages/homekit/secure_http.py", line 138, in _read_response
    data = self.sock.recv(exp_len)
ConnectionResetError: [Errno 104] Connection reset by peer
2018-07-06 01:44:58 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved

Then there is a series of timeouts.

2018-07-06 01:45:28 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:45:59 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:46:29 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:46:59 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:47:30 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:48:00 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:48:31 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:49:01 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:49:32 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:50:02 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:50:33 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:51:03 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:51:34 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:52:05 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:52:36 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:53:06 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 01:53:37 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
mjg59 commented 6 years ago

Ok, can you try making the changes in https://github.com/home-assistant/home-assistant/pull/15315 ? The put_characteristics bit may not exist, so ignore that. If that fails we're going to have to do some more debugging.

beit-no1 commented 6 years ago

I'm trying to make those edits, but got to the last changes in the init.py noted in 15315 and my file does not match at the end

`@@ -223,7 +227,8 @@ def update_characteristics(self, characteristics): def put_characteristics(self, characteristics): """Control a HomeKit device state from Home Assistant.""" body = json.dumps({'characteristics': characteristics})

I can't find the def put_characteristics

beit-no1 commented 6 years ago

Sorry.. just read your note to me again.. "The put_characteristics bit may not exist, so ignore that" making the other changes and testing

beit-no1 commented 6 years ago

Presume that I don't have to unpair from HA as I am not sure how to do that anyway.. restarting HA now.

beit-no1 commented 6 years ago

ok.. presuming my changes are now in use then it appears no change and we'll have to consider further debugging. Is there anything that I can do to gather you more info?

2018-07-06 02:55:11 DEBUG (SyncWorker_8) [homeassistant.components.homekit_controller] Discovered unique device 41:51:EE:B6:F6:90
2018-07-06 02:55:11 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Discovered unique device AE:2D:C4:BD:DD:82
2018-07-06 02:55:11 DEBUG (SyncWorker_12) [homeassistant.components.homekit_controller] Discovered unique device D2:29:9D:1B:74:A9
2018-07-06 02:55:11 DEBUG (SyncWorker_9) [homeassistant.components.homekit_controller] Discovered unique device DE:2F:3E:B7:DA:C9
2018-07-06 02:55:11 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Discovered unique device 05:74:78:20:68:EF
2018-07-06 02:55:12 INFO (SyncWorker_8) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 02:55:12 INFO (SyncWorker_18) [homeassistant.components.homekit_controller] Setting up Homekit device NL22
2018-07-06 02:55:12 INFO (SyncWorker_12) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 02:55:12 INFO (SyncWorker_9) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 02:55:12 INFO (SyncWorker_14) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-06 02:55:13 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-06 02:55:13 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Found Unknown Service: A18E1901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-06 02:55:13 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Found Unknown Service: A18E7901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-06 02:55:13 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Found Unknown Service: A18E6901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-06 02:55:13 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Found lightbulb
2018-07-06 02:55:13 DEBUG (SyncWorker_18) [homeassistant.components.homekit_controller] Found Unknown Service: A2
2018-07-06 02:56:40 WARNING (MainThread) [homeassistant.core] Unable to find service homekit/start
2018-07-06 03:29:39 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 248, in discovery_dispatch
    device = HKDevice(hass, host, port, model, hkid, config_num, config)
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 100, in __init__
    self.accessory_setup()
  File "/usr/src/app/homeassistant/components/homekit_controller/__init__.py", line 115, in accessory_setup
    data = json.loads(response.read().decode())
  File "/usr/local/lib/python3.6/http/client.py", line 462, in read
    s = self._safe_read(self.length)
  File "/usr/local/lib/python3.6/http/client.py", line 612, in _safe_read
    chunk = self.fp.read(min(amt, MAXAMOUNT))
  File "/config/deps/lib/python3.6/site-packages/homekit/secure_http.py", line 48, in read
    self.data += self.parent._read_response()
  File "/config/deps/lib/python3.6/site-packages/homekit/secure_http.py", line 138, in _read_response
    data = self.sock.recv(exp_len)
ConnectionResetError: [Errno 104] Connection reset by peer
beit-no1 commented 6 years ago

I tested again putting the light.nl22 entity back on the UI in a group and tried to turn it on as the log file had been static for a long time. After I did that the following error was generated and then the constant timeouts. Maybe there is a problem due to the Nanoleaf light and it being auto discovered as light.aurora as well as my having paired it for light.nl22? 

2018-07-06 04:16:39 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.nl22 is taking over 10 seconds
2018-07-06 04:16:41 ERROR (MainThread) [homeassistant.core] Error executing service <ServiceCall light.turn_on: entity_id=['light.nl22']>
Traceback (most recent call last):
  File "/usr/src/app/homeassistant/core.py", line 1007, in _event_to_service_call
    await service_handler.func(service_call)
  File "/usr/src/app/homeassistant/components/light/__init__.py", line 360, in async_handle_light_service
    await light.async_turn_on(**params)
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/app/homeassistant/components/light/homekit_controller.py", line 126, in turn_on
    self._securecon.put('/characteristics', body)
  File "/config/deps/lib/python3.6/site-packages/homekit/secure_http.py", line 83, in put
    return self._handle_request(data)
  File "/config/deps/lib/python3.6/site-packages/homekit/secure_http.py", line 100, in _handle_request
    self.sock.send(len_bytes + ciper_and_mac[0] + ciper_and_mac[1])
BrokenPipeError: [Errno 32] Broken pipe
2018-07-06 04:16:59 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 04:17:30 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 04:18:01 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 04:18:31 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
2018-07-06 04:19:01 WARNING (MainThread) [homeassistant.components.light] Updating homekit_controller light took longer than the scheduled update interval 0:00:30
mjg59 commented 6 years ago

Ok - before we start, are you comfortable setting up a virtualenv?

beit-no1 commented 6 years ago

I'm not a dev, but I should be able to follow directions if that's possible. I have a Synology NAS 918+ running docker, so would there be a docker environment that I could setup? Been in the IT industry for years working with devs and have administered and setup various server environments. If you are game then I am.

mjg59 commented 6 years ago

Hm, doing this with docker may be more complicated - let me think about what the easiest way to do this will be.

beit-no1 commented 6 years ago

I also have a Hyper-V server (2012) that I can run something on, so there are other options. Thought there might be a ready container for it, but let me know your thoughts.

beit-no1 commented 6 years ago

@mjg59 Just wanted to confirm that 0.73.0 does not seem to have resolved the problem. I have not made the same changes yet, but thought I'd let you know. Let me know if you've thought of anyway that I can test/check anything in my environment to help debug the problem.

beit-no1 commented 6 years ago

@mjg59 Just installed v 0.74.0 to check out the changes to the HomeKit Controller. It shows in the log a switch found, but as of yet can't find any reference under entities. Any guidance you can provide?

2018-07-20 19:03:00 DEBUG (SyncWorker_0) [homeassistant.components.homekit_controller] Discovered unique device DE:2F:3E:B7:DA:C9
2018-07-20 19:03:00 DEBUG (SyncWorker_2) [homeassistant.components.homekit_controller] Discovered unique device D2:29:9D:1B:74:A9
2018-07-20 19:03:00 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Discovered unique device 41:51:EE:B6:F6:90
2018-07-20 19:03:00 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Discovered unique device AE:2D:C4:BD:DD:82
2018-07-20 19:03:00 DEBUG (SyncWorker_6) [homeassistant.components.homekit_controller] Discovered unique device 05:74:78:20:68:EF
2018-07-20 19:03:00 INFO (SyncWorker_0) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-20 19:03:00 INFO (SyncWorker_2) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-20 19:03:00 INFO (SyncWorker_14) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-20 19:03:01 INFO (SyncWorker_6) [homeassistant.components.homekit_controller] Setting up Homekit device NS-CH1XIS8
2018-07-20 19:03:01 INFO (SyncWorker_19) [homeassistant.components.homekit_controller] Setting up Homekit device NL22
2018-07-20 19:03:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-20 19:03:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Found Unknown Service: A18E1901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-20 19:03:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Found Unknown Service: A18E7901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-20 19:03:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Found Unknown Service: A18E6901-CFA1-4D37-A10F-0071CEEEEEBD
2018-07-20 19:03:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Found lightbulb
2018-07-20 19:03:01 DEBUG (SyncWorker_19) [homeassistant.components.homekit_controller] Found Unknown Service: A2
2018-07-20 19:03:03 DEBUG (SyncWorker_2) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-20 19:03:03 DEBUG (SyncWorker_0) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-20 19:03:03 DEBUG (SyncWorker_2) [homeassistant.components.homekit_controller] Found switch
2018-07-20 19:03:03 DEBUG (SyncWorker_6) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-20 19:03:03 DEBUG (SyncWorker_0) [homeassistant.components.homekit_controller] Found switch
2018-07-20 19:03:03 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found accessory-information
2018-07-20 19:03:03 DEBUG (SyncWorker_6) [homeassistant.components.homekit_controller] Found switch
2018-07-20 19:03:03 DEBUG (SyncWorker_14) [homeassistant.components.homekit_controller] Found switch
beit-no1 commented 6 years ago

@mjg59 Hi Mathew, Not sure if you are going to have any time to look into this as I'm still available to assist in any testing or patch tests. I also saw another item that seems related and I posted some addition and recent info on 0.74.1

https://github.com/home-assistant/home-assistant/issues/14320#issuecomment-408066076

cadavre commented 6 years ago

Hi here! I'm having similar problem in #17544 . I actually found out that 0.8x version are corrupted with HomeKit controller configuration and reverted back to 0.79.3. With 0.7x I was able to configure homekit_controller without errors but my logs give me info that accessory was found, but – I can see nothing in HASS UI.

Are we moving anywhere from here?

gnkarn commented 6 years ago

still same prob , on 0.81.6

kayloehmann commented 6 years ago

Same here!

TORTAK2 commented 6 years ago

Has this problem been fixed or a solution. I'm using 0.82.1 and trying to get my Leviton DH6HD-1BZ switches to work. They seem to pair but don't show up on the Home Assistant front end. I do see when I pair the switch it creates a file in the /config/.homekit folder. I'm also getting the error "Disconnected: Did not receive auth message within 10 seconds"

marcgrc commented 5 years ago

accessory configured but not visible

rudgr commented 5 years ago

wanting to test the new homekit_controller garage-door-opener feature, same issue:

2019-01-24 17:09:53 DEBUG (SyncWorker_8) [homeassistant.components.homekit_controller] Discovered unique device abcde-12345
2019-01-24 17:09:53 INFO (SyncWorker_8) [homeassistant.components.homekit_controller] Setting up Homekit device Nice Spa - IT4WIFI - 575x
2019-01-24 17:09:53 DEBUG (SyncWorker_8) [homeassistant.components.homekit_controller] Found accessory-information
2019-01-24 17:09:53 DEBUG (SyncWorker_8) [homeassistant.components.homekit_controller] Found garage-door-opener
2019-01-24 17:09:53 DEBUG (SyncWorker_8) [homeassistant.components.homekit_controller] Found Unknown Service: 12345-abcde

yet still the component does show up in the UI

brettferrell commented 5 years ago

Is this still being supported? I'm an 80% homekit user coming back after several months, so I just installed .86 on an Ubuntu VM, enabled Homekit controller, but it doesn't show up in the interface to allow me to enter HK codes/devices either. I'm not seeing any HK errors in my log.

beit-no1 commented 5 years ago

I've been hoping to use this as well, but can't see that anyone is willing to pick it up and try to resolve the issues. I have several homekit only products I'd love to integrate.

TORTAK2 commented 5 years ago

I had to add this to configuration.yaml

discovery: enable:

and this to the automations.yaml

this worked for me (- instead of dots)

beit-no1 commented 5 years ago

@tortak2 I believe that is for the HomeKit component which allows apple to access and control HA but the HomeKit controller is a different module which allows HA to control a HomeKit enabled device. They are opposites. Thanks

I have 4 switches that work with their own proprietary app and have HomeKit #s but they do not show as entities in HA. I did try what you are saying in the beginning.

Brian

brettferrell commented 5 years ago

I'll try that. I did find the entity card in the new LoveLace UI, and tried to pair it, but it would not pair. I tried with both an iDevices iDEV0001 switch and an iHome iSP6x switch. (Discovery, enable, homekit is meant to start the controller for control of HK devices-https://www.home-assistant.io/components/homekit_controller/)

brettferrell commented 5 years ago

Hmm... Can't get that automation formatted properly... I'm really unfamiliar with the automations format.

"Invalid config for [automation]: [action] is an invalid option for [automation]. Check: automation->trigger->0->action. (See /config/configuration.yaml, line 70). Please check the docs at https://home-assistant.io/components/automation/"

id: '10a' alias: 'Start HomeKit' trigger:

beit-no1 commented 5 years ago

@brettferrell I am pretty sure that HomeKit is to expose your HA entities to apple HomeKit and not the other way around. This I believe would allow you to use Siri for some HA control. The controller is to control an apple HomeKit device in HA.

MartinHjelmare commented 5 years ago

Please stay on topic. This issue is about the homekit_controller component, not the homekit component. I'll hide posts that are off topic.

TORTAK2 commented 5 years ago

Before I added the delay my Leviton HomeKit switches would not show up in Home Assistant front end. I would get the card to enter my pass code, enter the pass code, the card would disappear and nothing would show up in Home Assistant even after a reboot. So the solution worked for me. I didn’t have problems with my other devices showing up on my iPhone Home app as long as they show up in Home Assistant.

beit-no1 commented 5 years ago

Thanks @tortak2. Will review that again and try it as it was a while ago when I reviewed. Certainly having trouble getting my devices setup or finding debug info.

TORTAK2 commented 5 years ago

I forgot I also added this, the "auto_start: false" and then the code in the automation.yaml

configuration.yaml

discovery:
  enable:
  - homekit

homekit:
 auto_start: false
 entity_config:
   light.leviton_dimmer_08235e:
      name: Dinning Room
   light.leviton_dimmer_0398f8:
      name: Kitchen
   light.leviton_dimmer_0823dc:
      name: Kitchen Hall

automations.yaml

- id: '10a'
  alias: 'Start HomeKit'
  trigger:
    - platform: homeassistant
      event: start
  action:
   - delay: 00:03  # Waits 3 minutes
   - service: homekit.start
  hide_entity: true
marcgrc commented 5 years ago

can we stay in argoment please? this is a post for homekit controller. thanks

JuniorGamingTime commented 5 years ago

@beit-no1 has your problem been fixed?

beit-no1 commented 5 years ago

Yes. All 4 insignia switches now functioning in 89.2. Had to do one at a time and rename entity as it assumes same. Thanks

jcalderon71 commented 5 years ago

beit-no1 I'm still having an issue with my insignia switches, now i cannot enter the PIN code I already reset my switches but every time I tried to enter the code I have the message "This accessory is already paired to another device". Any idea?

beit-no1 commented 5 years ago

Did you make sure they are not somehow linked in your Apple Home. I definitely went in there and made sure they were removed. I then did a hard reset on them and was able to get them into HA. I did have to do them one by one as they each had the same default entity_id and so I'd rename it once in HA. I now have 4 of them... image