moodiejo commented 3 years ago

The problem

All homekit devices show unavailable

What is version of Home Assistant Core has the issue?

2021.8.3

What was the last working version of Home Assistant Core?

2021.7.4

What type of installation are you running?

Home Assistant Core

Integration causing the issue

Homekit

Link to integration documentation on our website

https://www.home-assistant.io/integrations/homekit/

Example YAML snippet

Snippets from YAML in configuration.yaml

- name: Home Assistant Bridge 2
  port: 21065
  filter:
    include_entities:
      - light.koi_pond_1
      - light.koi_pond_2
      - light.koi_pond_3
      - light.koi_pond_4

- name: Home Assistant Bridge
  filter:
    include_entities:
      # Inside Entrance Portal Area
      - light.dining_room_1
      - light.dining_room_2
      - light.front_garden_1
      - light.front_garden_2
      - light.front_garden_3

Anything in the logs that might be useful for us?

Snippets from logs:

2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to homekit.bridge
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to homekit.bridge

2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Name to Home Assistant Bridge
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to default
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: FirmwareRevision to 2021.8.3
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Manufacturer to Home Assistant
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Model to Bridge
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to homekit.bridge
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Name to alarm_on
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to default
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: FirmwareRevision to 2021.8.3
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Manufacturer to Input Boolean
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Model to Input Boolean
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to input_boolean.alarm_on
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Name to driveway_alarm_on
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: SerialNumber to default
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: FirmwareRevision to 2021.8.3
2021-08-07 08:06:18 DEBUG (MainThread) [pyhap.characteristic] set_value: Manufacturer to Input Boolean

Additional information

Rollback to 2021.7.4 works perfectly.

probot-home-assistant[bot] commented 3 years ago

homekit documentation homekit source _{^{(message by IssueLinks)}}

probot-home-assistant[bot] commented 3 years ago

Hey there @bdraco, mind taking a look at this issue as it has been labeled with an integration (homekit) you are listed as a code owner for? Thanks! _{^{(message by CodeOwnersMention)}}

bdraco commented 3 years ago

Based on the limited debug output, it looks like the bridge is starting up ok so its likely a networking issue with mDNS/zeroconf.

Please post debug log for zeroconf, homeassistant.components.homekit, and pyhap

Are you using ipv6 ?
Do you have your network split into multiple vlans?
Have you manually configured the network integration in the General section of the UI or are you using auto detect?

t2889 commented 3 years ago

Same problem here. After upgrading to 2021.8.3 from 2021.8.2, all of my bridges stopped responding in the Home app.

I tried restarting:

Home Assistant
All home hubs (HomePod,s Apple TVs)
iPhone and iPad
APs, switch, network controller

... but to no avail. I then tried re-pairing one of my bridges and received "Accessory Not Found".

Rolling back to 2021.8.2 fixed it for me. I advise not installing 2021.8.2 either as that broke RGB lighting controls in the Home app and Siri.

lesterlo commented 3 years ago

I have a similar problem on 2021.8.2 and 2021.8.3.

When I restart the home assistant core or reload the homekit bridge, my Homepod mini cannot control all of the devices via the homekit bridge. The Homepod said “xxx device is not responding” I need to restart my homepod and everything become normal again.

I don’t want to reboot my HomePod after reloaded the homekit bridge services.

This phenomenon is NOT happening on iPad and iPhone. On every HA core restart or Homekit bridge reload, my iPad and iPhone can still control the device via the homekit bridge after the restart process.

Post in community

bdraco commented 3 years ago

That definitely sounds like an ipv6 or multicast reachability problem.

nfrede commented 3 years ago

Having the same issues as those posting above with all 2021.8.x versions it seems. All devices show as "not responding" and re-pairing doesn't work as it will never allow either bridge to pair in the Home app.

I had to revert my docker container back to 2021.7.4 and everything's working fine again.

lesterlo commented 3 years ago

@bdraco I found the folloing zeroconf log on my HA core

I didn't assign a ipv6 address to the hass OS. How to disable the ipv6 manuelly on the hass OS machine?

2021-08-07 16:58:37 DEBUG (MainThread) [zeroconf] IPv6 scope_id 3 associated to the receiving interface
2021-08-07 16:58:37 DEBUG (MainThread) [zeroconf] Received from 'fe80::xxxx:xxxx:xxxx:xxxx':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:{id=0, flags=0, truncated=False, n_q=2, n_ans=0, n_auth=0, n_add=0, questions=[ptr[question,QU,in,_360eye_mqtt._tcp.local.], ptr[question,QU,in,_dyson_mqtt._tcp.local.]], answers=[]}> (59 bytes) as [b'\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x0c_360eye_mqtt\x04_tcp\x05local\x00\x00\x0c\x80\x01\x0b_dyson_mqtt\xc0\x19\x00\x0c\x80\x01']
2021-08-07 16:58:37 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=pyscript>

pawg commented 3 years ago

I have posted a solution that worked for me in another issue:

For those struggling with this issue, this appears to be a dns problem. What worked for me was to type in the Terminal & SSH add-on:

ha dns restart

After the operation succeeded, my accessories have appeared immediately.

EDIT : however for some weird reason my lights have now separated RGB and Temperature. I'm going to rollback to 2021.7.4

Originally posted by @pawg in https://github.com/home-assistant/core/issues/53987#issuecomment-894358770

lesterlo commented 3 years ago

@pawg

ha dns restart cannot solve my problem 🥲

lesterlo commented 3 years ago

That definitely sounds like an ipv6 or multicast reachability problem.

Dear @bdraco, I disable the ipv6 address on supervisor-> System tab ->Host tab-> IP address setting. Everthing become normal. My Homepod can control the devices via homkit bridge after the system restart.

Thank you very much!!

bdraco commented 3 years ago

I setup a network with ipv6 enabled on Home Assistant, and disabled on the network gear. Which is what I assume is similar to @lesterlo 's setup.

Sending to ::ffff:224.0.0.251 on the ipv6 socket allowed both the ipv6 internal network on the device and and the local network ipv4 devices to see the responses.

If anyone wants to give it a shot: https://github.com/jstasiak/python-zeroconf/pull/938

lordmortis commented 3 years ago

Can confirm I had this issue. I just migrated from a docker container (which had no ipv6 setup) to a hass.io setup on a seperate raspberry pi 4, and my homekit bridge config wasn't working - all devices unavailable. I thought initially it needed to be setup again, and removed and re-added it. When that didn't work I disabled ipv6 on the hass.io instance like @lesterlo 's comment said, and after rebooting, pairing worked.

If there's a way I can get some more logging information, let me know and i'll try and get it for y'all.

bdraco commented 3 years ago

logger:
  default: warning
  logs:
     pyhap: debug
     homeassistant.components.homekit: debug
     zeroconf: debug

Here is logger incantation for configuration.yaml. You'll need to restart for it to apply.

To test the solution I opened the PR for:

Install the SSH & Web Terminal addon with protected mode DISABLED Then run

docker exec -it homeassistant /bin/bash
cd /config
git clone https://github.com/bdraco/python-zeroconf
cd python-zeroconf
git checkout -t origin/v4_v6_compat
pip3 install --upgrade .

Restart

moodiejo commented 3 years ago

Based on the limited debug output, it looks like the bridge is starting up ok so its likely a networking issue with mDNS/zeroconf.

Please post debug log for zeroconf, homeassistant.components.homekit, and pyhap These are the only log entries that appear after running for several minutes:

moodiejo@Johns-Mini-3 .homeassistant % cat home-assistant.log| grep zeroconf 2021-08-07 17:23:13 DEBUG (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf browser for: ['_Volumio._tcp.local.', '_airplay._tcp.local.', '_api._udp.local.', '_axis-video._tcp.local.', '_bond._tcp.local.', '_daap._tcp.local.', '_dkapi._tcp.local.', '_dvl-deviceapi._tcp.local.', '_easylink._tcp.local.', '_elg._tcp.local.', '_enphase-envoy._tcp.local.', '_esphomelib._tcp.local.', '_fbx-api._tcp.local.', '_googlecast._tcp.local.', '_hap._tcp.local.', '_homekit._tcp.local.', '_http._tcp.local.', '_ipp._tcp.local.', '_ipps._tcp.local.', '_kizbox._tcp.local.', '_leap._tcp.local.', '_mediaremotetv._tcp.local.', '_miio._udp.local.', '_nut._tcp.local.', '_plugwise._tcp.local.', '_powerview._tcp.local.', '_printer._tcp.local.', '_sonos._tcp.local.', '_spotify-connect._tcp.local.', '_ssh._tcp.local.', '_system-bridge._udp.local.', '_touch-able._tcp.local.', '_viziocast._tcp.local.', '_wled._tcp.local.', '_xbmc-jsonrpc-h._tcp.local.', '_home-assistant._tcp.local.', '_hap._udp.local.'] 2021-08-07 17:23:16 WARNING (MainThread) [zeroconf] Error with socket 28 (('::', 5353, 0, 0))): [Errno 65] No route to host 2021-08-07 17:23:26 INFO (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf broadcast

Are you using ipv6 ?- No, not at all

Do you have your network split into multiple vlans? - No, no multiple vlans

Have you manually configured the network integration in the General section of the UI or are you using auto detect? Network has been set to Auto Configure.

moodiejo commented 3 years ago

Just further zeroconf.txt to my post above. rolling back to 2021.7.4, the zerconf logs contain substantially more info:

bdraco commented 3 years ago

2021-08-07 17:23:16 WARNING (MainThread) [zeroconf] Error with socket 28 (('::', 5353, 0, 0))): [Errno 65] No route to host Looks helpful. There should have been a traceback after it. Can you send the full text?

moodiejo commented 3 years ago

2021-08-07 17:23:16 WARNING (MainThread) [zeroconf] Error with socket 28 (('::', 5353, 0, 0))): [Errno 65] No route to host Looks helpful. There should have been a traceback after it. Can you send the full text?

That is the full text, unfortunately, nothing further. Below is the full extract from my SSH session:

moodiejo@Johns-Mini-3 .homeassistant % ./restart.sh kill: 32052: No such process moodiejo@Johns-Mini-3 .homeassistant % tail -F home-assistant.log| grep zeroconf 2021-08-07 17:57:16 DEBUG (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf browser for: ['_Volumio._tcp.local.', '_airplay._tcp.local.', '_api._udp.local.', '_axis-video._tcp.local.', '_bond._tcp.local.', '_daap._tcp.local.', '_dkapi._tcp.local.', '_dvl-deviceapi._tcp.local.', '_easylink._tcp.local.', '_elg._tcp.local.', '_enphase-envoy._tcp.local.', '_esphomelib._tcp.local.', '_fbx-api._tcp.local.', '_googlecast._tcp.local.', '_hap._tcp.local.', '_homekit._tcp.local.', '_http._tcp.local.', '_ipp._tcp.local.', '_ipps._tcp.local.', '_kizbox._tcp.local.', '_leap._tcp.local.', '_mediaremotetv._tcp.local.', '_miio._udp.local.', '_nut._tcp.local.', '_plugwise._tcp.local.', '_powerview._tcp.local.', '_printer._tcp.local.', '_sonos._tcp.local.', '_spotify-connect._tcp.local.', '_ssh._tcp.local.', '_system-bridge._udp.local.', '_touch-able._tcp.local.', '_viziocast._tcp.local.', '_wled._tcp.local.', '_xbmc-jsonrpc-h._tcp.local.', '_home-assistant._tcp.local.', '_hap._udp.local.'] 2021-08-07 17:57:18 WARNING (MainThread) [zeroconf] Error with socket 26 (('::', 5353, 0, 0))): [Errno 65] No route to host 2021-08-07 17:57:32 INFO (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf broadcast

The log ends with 'Starting Zeroconf broadcast'

bdraco commented 3 years ago

The traceback likely does not have the string zeroconf in it. Can you try something like:

tail -F home-assistant.log| grep -A 15 zeroconf

moodiejo commented 3 years ago

Sure, did a restart, here is the output:

2021-08-07 18:04:32 DEBUG (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf browser for: ['_Volumio._tcp.local.', '_airplay._tcp.local.', '_api._udp.local.', '_axis-video._tcp.local.', '_bond._tcp.local.', '_daap._tcp.local.', '_dkapi._tcp.local.', '_dvl-deviceapi._tcp.local.', '_easylink._tcp.local.', '_elg._tcp.local.', '_enphase-envoy._tcp.local.', '_esphomelib._tcp.local.', '_fbx-api._tcp.local.', '_googlecast._tcp.local.', '_hap._tcp.local.', '_homekit._tcp.local.', '_http._tcp.local.', '_ipp._tcp.local.', '_ipps._tcp.local.', '_kizbox._tcp.local.', '_leap._tcp.local.', '_mediaremotetv._tcp.local.', '_miio._udp.local.', '_nut._tcp.local.', '_plugwise._tcp.local.', '_powerview._tcp.local.', '_printer._tcp.local.', '_sonos._tcp.local.', '_spotify-connect._tcp.local.', '_ssh._tcp.local.', '_system-bridge._udp.local.', '_touch-able._tcp.local.', '_viziocast._tcp.local.', '_wled._tcp.local.', '_xbmc-jsonrpc-h._tcp.local.', '_home-assistant._tcp.local.', '_hap._udp.local.'] 2021-08-07 18:04:32 WARNING (MainThread) [zeroconf] Error with socket 37 (('::', 5353, 0, 0))): [Errno 65] No route to host Traceback (most recent call last): File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/selector_events.py", line 1046, in sendto self._sock.sendto(data, addr) OSError: [Errno 65] No route to host 2021-08-07 18:04:32 WARNING (SyncWorker_40) [homeassistant.components.sql.sensor] SELECT * FROM states WHERE entity_id = 'sensor.netatmo_moodiejo_main_bedroom_rain_meter_rain_today' and DATE_TRUNC('day',last_updated) = CURRENT_DATE - interval '3 days' AND state <> 'unknown' AND state <> 'unavailable' ORDER BY state_id DESC LIMIT 1; returned no results 2021-08-07 18:04:33 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Behind Bar Swivel' for yeelight integration not ready yet: [Errno 65] No route to host; Retrying in background 2021-08-07 18:04:33 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-08-07 18:04:34 WARNING (MainThread) [homeassistant.components.light] Platform netatmo not ready yet: None; Retrying in background in 30 seconds 2021-08-07 18:04:34 WARNING (MainThread) [homeassistant.components.climate] Platform netatmo not ready yet: None; Retrying in background in 30 seconds 2021-08-07 18:04:40 INFO (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf broadcast 2021-08-07 18:04:40 WARNING (SyncWorker_35) [homeassistant.components.waze_travel_time.sensor] Error on retrieving data: empty response

2021-08-07 18:05:02 WARNING (SyncWorker_59) [homeassistant.components.sql.sensor] SELECT FROM states WHERE entity_id = 'sensor.netatmo_moodiejo_main_bedroom_rain_meter_rain_today' and DATE_TRUNC('day',last_updated) = CURRENT_DATE - interval '3 days' AND state <> 'unknown' AND state <> 'unavailable' ORDER BY state_id DESC LIMIT 1; returned no results x2021-08-07 18:05:33 WARNING (SyncWorker_5) [homeassistant.components.sql.sensor] SELECT FROM states WHERE entity_id = 'sensor.netatmo_moodiejo_main_bedroom_rain_meter_rain_today' and DATE_TRUNC('day',last_updated) = CURRENT_DATE - interval '3 days' AND state <> 'unknown' AND state <> 'unavailable' ORDER BY state_id DESC LIMIT 1; returned no results 2021-08-07 18:05:33 ERROR (SyncWorker_5) [homeassistant.components.yeelight] Unable to update device 192.168.1.34, Office Wall 6: A socket error occurred when sending the command. 2021-08-07 18:05:35 WARNING (SyncWorker_6) [homeassistant.components.ring] Error fetching Ring health data for device c8df844493cd: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response')) 2021-08-07 18:06:03 WARNING (SyncWorker_51) [homeassistant.components.sql.sensor] SELECT * FROM states WHERE entity_id = 'sensor.netatmo_moodiejo_main_bedroom_rain_meter_rain_today' and DATE_TRUNC('day',last_updated) = CURRENT_DATE - interval '3 days' AND state <> 'unknown' AND state <> 'unavailable' ORDER BY state_id DESC LIMIT 1; returned no results 2021-08-07 18:06:03 ERROR (SyncWorker_0) [homeassistant.components.yeelight] Unable to update device 192.168.1.43, Office Corner: A socket error occurred when sending the command.

Also, my logger settings - Do you need me to add any additional loggers for you?

logger: default: warning logs:

log level for HA core

homeassistant.core: warning

#Homekit
homeassistant.components.homekit: info
#pyhap: debug

# log level for all python scripts
homeassistant.components.python_script: warning
homeassistant.components.zeroconf: debug
#homeassistant.components.netatmo: debug
#homeassistant.components.rest_command: debug
# log level for the `aiohttp` Python package
aiohttp: error

# log level for both 'glances_api' and 'glances' integration
homeassistant.components.glances: fatal
glances_api: fatal

# log level for rest integration (Victron)
homeassistant.components.rest.sensor: warning

bdraco commented 3 years ago

Thanks. I think the PR I opened for zeroconf may resolve it.

Can you test PR I opened against zeroconf?

Instructions:

Install the SSH & Web Terminal addon with protected mode DISABLED Then run

docker exec -it homeassistant /bin/bash
cd /config
git clone https://github.com/bdraco/python-zeroconf
cd python-zeroconf
git checkout -t origin/v4_v6_compat
pip3 install --upgrade .

Restart

To revert to the zeroconf that comes with 2021.8.3:

docker exec -it homeassistant /bin/bash
pip3 install --upgrade zeroconf --force

moodiejo commented 3 years ago

Would be my honour to test, please allow me a few minutes to get this running. Will post results ASAP

moodiejo commented 3 years ago

OK, I have installed, however, possibly not correctly. I am not running hassio or docker, this runs directly on a MAC Mini. I have done the following:

35 git clone https://github.com/bdraco/python-zeroconf 36 cd python-zeroconf 37 git checkout -t origin/v4_v6_compat 38 pip3 install --upgrade .

Final line of output: Successfully installed zeroconf-0.33.4

The issue does however persist.

Please let me know what you need me to do - See below packages installed under pip3:

Johns-Mini-3:python-zeroconf root# pip3 list

Package Version

ifaddr 0.1.7 pip 21.1.3 setuptools 57.0.0 wheel 0.36.2 zeroconf 0.33.4

bdraco commented 3 years ago

If you are running in venv, you'll need to activate the venv first before running the pip install (usually source venv/bin/activate from the home-assistant directory)

moodiejo commented 3 years ago

Nope, no venv at all, simple direct python. The Mac Mini is dedicated for home assistant

bdraco commented 3 years ago

Sounds like the fix didn't work. I have an old mac that I can try installing Home Assistant on later today. Maybe I'll be able to replicate the issue

moodiejo commented 3 years ago

Awesome, I am very happy to help with anything you need, please let me know, I will try my utmost to be as responsive as you are..

Thank You for the assist, have installed 2021.7.4 and all working again.

bdraco commented 3 years ago

I've got another potential solution that can be installed as a custom component

Install instructions:

cd /config
mkdir custom_components
cd custom_components
git clone https://github.com/bdraco/zeroconf

Restart Skip the mkdir custom_components if it already exists

Removal

Delete /config/custom_components/zeroconf

fmonday commented 3 years ago

git clone https://github.com/bdraco/python-zeroconf cd python-zeroconf git checkout -t origin/v4_v6_compat pip3 install --upgrade .

This fixed the problem for me, thanks for that FYI: also Mac OS on a mini but running HA core in VENV

bdraco commented 3 years ago

git clone bdraco/python-zeroconf cd python-zeroconf git checkout -t origin/v4_v6_compat pip3 install --upgrade .

This fixed the problem for me, thanks for that FYI: also Mac OS on a mini but running HA core in VENV

Can you try https://github.com/home-assistant/core/issues/54196#issuecomment-894700716 as well after restoring the original version of zeroconf using pip3 install --upgrade --force zeroconf?

I'm hoping the alternate solution solves more uses cases, and its the one I'm planning to opening a PR for

nfrede commented 3 years ago

I used the proposed "custom_components" fix above and rebuilt my HA docker with 2021.8.3 and HomeKit appears to be working again!

jjlawren commented 3 years ago

Both the custom component and https://github.com/jstasiak/python-zeroconf/pull/938 seem to fix the issue in my environment.

With the custom component, I get an error on startup:

2021-08-07 21:43:22 WARNING (MainThread) [zeroconf] Error with socket 30 (('some:ipv6:addr', 5353, 0, 0))): [Errno 101] Network unreachable
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
    self._sock.sendto(data, addr)
OSError: [Errno 101] Network unreachable

The ipv6 address above is attached to an unused interface that does not have an ipv4 address assigned. Only a separate tagged vlan interface is used on that physical interface. The python-zeroconf PR does not throw similar exceptions or warnings.

nfrede commented 3 years ago

Also see the same error in the logs as @jjlawren but doesn't appear to impact HomeKit functionality at all.

Logger: zeroconf
Source: /usr/local/lib/python3.9/site-packages/zeroconf/_logger.py:74 
First occurred: August 7, 2021, 5:35:54 PM (1 occurrences) 
Last logged: August 7, 2021, 5:35:54 PM

Error with socket 32 (('<IPv6_ADDR>', 5353, 0, 2))): [Errno 101] Network unreachable
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 1056, in sendto
    self._sock.sendto(data, addr)
OSError: [Errno 101] Network unreachable

moodiejo commented 3 years ago

Confirmed - Custom Component solved this for me too.

Thanks, Everyone, you guys are awesome!

home-assistant / core

Homekit Integration - All devices Unavailable #54196

The problem

What is version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

log level for HA core