#5 Updater binary sensor shows up as Unavailable

The "Updater" binary sensor is showing as "Unavailable", even though initially I'm pretty sure it used to say "off" (or maybe it was "false"?). I'm pretty sure I didn't change anything other than make the necessary plug connections specified in the docs.

Hope this helps! Let me know if you need more info and I'll post it asap. Thanks!

Hi,

Which revision are you using of the snap? What channel are you on?

Running snap info home-assistant-snap in a terminal should give you this information.

When did this start to happen?

Can you se any errors in the logs? You can see the logs with sudo snap logs home-assistant-snap -f.

You might want to give home assistant a restart while following the logs, to force the updater to run instantly.

Hey Joachim. Sorry for the initial lack of details. Here's the info:

snap info home-assistant-snap

name:      home-assistant-snap
summary:   Open source home automation that puts local control and privacy first
publisher: Giaever.online (giaever-online)
store-url: https://snapcraft.io/home-assistant-snap
license:   Apache-2.0
description: |
  Home Assistant is a home automation platform running on Python 3.
  It is able to track and control all devices at home and offer a
  platform for automating control.
  
  Your new installation will be available through your browser at http://localhost:8123/
  
  Please see official docs: https://git.giaever.org/joachimmg/home-assistant-snap and
  https://community.home-assistant.io for help on configuration etc.
  
  See `snap connections home-assistant-snap` for necessary plugs (such as access to USB etc).
  
  NOTE! Snap will automatically update whenever a new revision of the snap package is available.
commands:
  - home-assistant-snap.check-config
  - home-assistant-snap.open-localhost
services:
  home-assistant-snap: simple, enabled, active
snap-id:      BYa8IlUQqqTyhwCjoPWb8Pf2ZaBKQdSv
tracking:     2021.8/stable
refresh-date: 6 days ago, at 16:56 CDT
channels:
  2021.8/stable:    2021.8.8   2021-08-26 (360) 411MB -
  2021.8/candidate: ↑                                 
  2021.8/beta:      ↑                                 
  2021.8/edge:      ↑                                 
  latest/stable:    2021.8.8   2021-08-26 (360) 411MB -
  latest/candidate: ↑                                 
  latest/beta:      ↑                                 
  latest/edge:      2021.8.8   2021-08-22 (360) 411MB -
  2021.7/stable:    2021.7.4   2021-08-08 (334) 409MB -
  2021.7/candidate: ↑                                 
  2021.7/beta:      ↑                                 
  2021.7/edge:      2021.7.4   2021-08-08 (334) 409MB -
  2021.6/stable:    2021.6.6   2021-08-05 (295) 404MB -
  2021.6/candidate: ↑                                 
  2021.6/beta:      ↑                                 
  2021.6/edge:      ↑                                 
  2021.5/stable:    2021.5.5   2021-05-25 (253) 402MB -
  2021.5/candidate: ↑                                 
  2021.5/beta:      2021.5.0b7 2021-05-04 (229) 401MB -
  2021.5/edge:      ↑                                 
  2021.4/stable:    2021.4.6   2021-04-28 (218) 396MB -
  2021.4/candidate: ↑                                 
  2021.4/beta:      ↑                                 
  2021.4/edge:      ↑                                 
  2021.3/stable:    2021.3.4   2021-03-25 (178) 413MB -
  2021.3/candidate: ↑                                 
  2021.3/beta:      2021.3.0b4 2021-03-01 (151) 413MB -
  2021.3/edge:      ↑                                 
  2021.2/stable:    2021.2.3   2021-02-25 (138) 403MB -
  2021.2/candidate: ↑                                 
  2021.2/beta:      ↑                                 
  2021.2/edge:      ↑                                 
installed:          2021.8.8              (360) 411MB -

When did this start to happen?

Maybe a week or so ago. I've only used it for about a month total.

snap logs home-assistant-snap -f

2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:     return await async_aiohttp_proxy_stream(
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:   File "/snap/home-assistant-snap/360/lib/python3.8/site-packages/homeassistant/helpers/aiohttp_client.py", line 172, in async_aiohttp_proxy_stream
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:     await response.write(data)
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:   File "/snap/home-assistant-snap/360/lib/python3.8/site-packages/aiohttp/web_response.py", line 470, in write
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:     await self._payload_writer.write(data)
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:   File "/snap/home-assistant-snap/360/lib/python3.8/site-packages/aiohttp/http_writer.py", line 107, in write
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:     self._write(chunk)
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:   File "/snap/home-assistant-snap/360/lib/python3.8/site-packages/aiohttp/http_writer.py", line 67, in _write
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]:     raise ConnectionResetError("Cannot write to closing transport")
2021-09-01T12:04:04Z home-assistant-snap.home-assistant-snap[1144]: ConnectionResetError: Cannot write to closing transport

I just restarted while following the logs and got no additional errors (just a few warnings about custom integrations).

Let me know if I can provide more info. Cheers!

snap connections home-assistant-snap

Interface                Plug                                         Slot                                Notes
bluez                    home-assistant-snap:bluez                    :bluez                              manual
content                  -                                            home-assistant-snap:configurations  -
content[components]      home-assistant-hacs:components               home-assistant-snap:components      -
content[executables]     home-assistant-snap:bin                      home-assistant-toolbox:bin          -
desktop                  home-assistant-snap:desktop                  :desktop                            -
network                  home-assistant-snap:network                  :network                            -
network-bind             home-assistant-snap:network-bind             :network-bind                       -
network-control          home-assistant-snap:network-control          :network-control                    manual
physical-memory-control  home-assistant-snap:physical-memory-control  :physical-memory-control            manual
raw-usb                  home-assistant-snap:raw-usb                  :raw-usb                            manual
removable-media          home-assistant-snap:removable-media          :removable-media                    manual
serial-port              home-assistant-snap:serial-port              -                                   -

Hi, thanks.

The sensor is supposed to be on or off.

It's not super-clear what causes this. I found online that it might have something to do with the connections to close to early.

I'll do some investigation on it, but can you also give me an output of the connections you have:

snap connections home-assistant-snap

And what kind of internet connection are you using? Speed?

Hey Joachim,

My snap connections output is above. My connection uses fiber and the speed is at around 450/200 Mbps.

Hope this helps!

Wifi or ethernet? Or both? Are you using a proxy? I'm pushing a new update now. Waiting for ARMHF arch to finish. Should be up in +/- an hour.

Thanks! The server is connected over ethernet with no proxy server. I do have IPv6 and QoS enabled at the router level in case that makes a difference.

Not that I'm aware of. But to be honest, the code that is failing is part of the core, and I'm wondering if it could be an issue with the core itself.

There was a guy on Facebook that recently posted an issue he had with Supervisor, and the Updater failed in his setup too. (Screenshot)

This (custom) updater uses the same methods as the official one. It just checks for updates within the snap environment instead of the normal releases, so you'll know when there's an actual release to update to.

I see. It does seem to be related to this issue.

I'll let you know if the latest version fixes things on my end.

The newest build of 2021.8.8 is in 2021.8/stable. You should be able to refresh (if snapd haven't done so already by itself) with

sudo snap refresh home-assistant-snap

There's also 2021.9.0 in the channel 2021.9/candidate (will be moved to 2021.9/latest when I've been able to test this release). If you want to upgrade and test it out, do

sudo snap switch home-assistant-snap --channel=2021.9/candidate

and rollback if needed with

sudo snap revert home-assistant-snap

Looks like 2021.8.8 is already installed on my server, but unfortunately the issue persists. I'll give 2021.9/latest a shot a bit later today and report back.

It's hard to debug without any error messages to go after, except the ones from the core libraries. It works on all on my setups; however, I have not enabled IPv6 on the local network. But that shouldn't be the issue if you had it working a week ago. I guess IPv6 was enabled then too?

If it's no big issue for you to try to disable it and only use IPv4 for a test, that would be great. :)

2021.9.0 is in the candidate channel and not in the latest. :)

PS! I read in the thread on Facebook that a hard reboot (shutdown and power off, not just a sudo reboot command) had helped one of the guys. Have you tried? They're running the supervisor though.

Hey Joachim, sorry for the delay; work stuff got in the way and it slowed down this project considerably.

I switched to version 2021.9.1, but unfortunately the status remained the same. Also, the HACS integration stopped working and didn't have much time to look into it.

I'll try again in the next couple of days with more time on my hands, this time doing things like looking at errors and turning off IPv6.

Hey Joachim,

Still presenting the same error after disabling IPv6. Not sure what else to try, so please let me know if you have any ideas.

Hi,

This is strange. I make a package with the official updater, just to test if this occur at your end with this component too.

I used the same methods to call the snap-api, so for what I can see it's a problem with the core libs, that need to be filed in the home-assistant/core repository on github.

But we can first try the official updater, just to check if my beliefs as true. :)

I'll let you know when it's up and how you can switch. Just trying to solve the HACS problem first. Gave it a higher priority since it screwed up everyones installation. I think I found a solution to it. :)

Sure, no worries! I'm in the HACS train too, so I'm closely looking at that thread as well. :)

I have solved it=HACS problem :) (At least it works on the locally built snap, so it should work on the signed version)

PS! The amd64 version is out in the latest/edge. If you're running amd64 arch, try it out :D Arm64 coming next!

Sweet! I'm running amd64, so I'll try it right now and report back asap.

So the HACS issue does seem to be fixed on latest/edge (congrats!), but I did notice a few things that I'm posting in their own issue space to keep things organized. Hope that helps!

There is an amd64 version with the official updater in the channel latest/edge/dev, you can try it out with

sudo snap switch home-assistant-snap --channel=latest/edge/dev

Let me know if the issue persist with this or not :)

Just switched+refreshed latest/edge/dev but the status didn't change. Still showing up as Unavailable. :/

Did you also refresh?

sudo snap refresh home-assistant-snap

Yeah, but I just tried again to make sure:

⚡ sudo snap info home-assistant-snap                                     
...
snap-id:      BYa8IlUQqqTyhwCjoPWb8Pf2ZaBKQdSv
tracking:     latest/edge/dev
refresh-date: today at 11:23 CDT
...

⚡ sudo snap refresh home-assistant-snap                                     
snap "home-assistant-snap" has no updates available

Ok, but then I has to be with the official updater. That's what is bundled with the snap in latest/egde/dev.

Is there any log entries?

Or actually with aiohttp in the core.

No log errors (other than libturbojpeg).

Yeah, that lib doesn't exist in the /dev branch. I've pushed new ones with that included into the latest/edge. Fix was added after this and we're keeping the custom updater in the snap.

But did the error from the log go away now?

Opening the full log shows no other errors (just a few soft warnings about custom integrations):

2021-09-17 11:26:19 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration wyzeapi which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-17 11:26:19 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-17 11:26:19 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration nodered which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-17 11:26:19 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration browser_mod which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-17 11:26:19 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration helium which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-17 11:26:28 ERROR (MainThread) [homeassistant.components.camera.img_util] Error loading libturbojpeg; Cameras may impact HomeKit performance
Traceback (most recent call last):
File "/snap/home-assistant-snap/390/lib/python3.8/site-packages/homeassistant/components/camera/img_util.py", line 96, in __init__
TurboJPEGSingleton.__instance = TurboJPEG()
File "/snap/home-assistant-snap/390/lib/python3.8/site-packages/turbojpeg.py", line 147, in __init__
turbo_jpeg = cdll.LoadLibrary(
File "/usr/lib/python3.8/ctypes/__init__.py", line 451, in LoadLibrary
return self._dlltype(name)
File "/usr/lib/python3.8/ctypes/__init__.py", line 373, in __init__
self._handle = _dlopen(self._name, mode)
OSError: libturbojpeg.so.0: cannot open shared object file: No such file or directory

Yeah, that's a default log entry for all the custom_components, possibly added with hacs. And the last one should be fixed in latest/edge.

Anyway.... The updater runs once a day you might let it run for 24Hrs without a reboot, then verify both that the sensor is dead/unavail. and no log entries.

Yeah, I'll try that and report back. :)

The updater itself seems to be working fine since I have already seen automatic version changes (ie from 2021.8.8 to 2021.9.1), so I think it's just the sensor itself acting up.

The custom updater-component is just a part of the snap, so users will have the chance to create automations (notification?) whenever there is a new release in a new track.

The snap itself will update itself automatically on the same track/risk (e.g latest/stable) - that is handled by snapd, the snap daemon of your operating system.

But since almost every release of Home Assistant brings breaking changes, we change the default track for each release to prevent upgrades of major releases.

This is to prevent that anyone using (lets say) 2021.8 won't be upgraded to 2021.9 automatically. They should be upgraded between minor (e.g 2021.8.1 to 2021.8.2) versions automatically, but not major.

The updater will just tell you if there is a new version available in another track, so you can manually switch («upgrade») when you're ready for it.

If you're on the latest track; then you will upgrade whenever there is a new release. :)

That aside: I will look into the custom updater component and see if there are some bugs. I think that it can be made simpler too.

PS! Let me know if there is some changes to your sensor the upcoming 24 Hrs :)

Absolutely! Thanks for the detailed explanation.

Hey! So I see no changes over here regarding the binary sensor, although I did get a bunch of errors on the logs. Most of them seem to be related to my custom integrations, however, and at this point I'm not sure if it has something to do with the update itself.

I'll try and restart and keep an eye on the logs and let you know if I find something else.

Hi,

Any news about the status of the updater ? I suggest that you wait to debug the other custom integrations when you're on the track latest/stable or latest/edge (alternatively 2021.9 instead of latest).

HA 2021.9.7 with fix for HACS ++ is already out. :) This should also (hopefully) bring the fix for libturbojpeg too.

Same status as of today regarding the updater.

Yeah, I'm not really debugging those other integrations, but I'll keep it in mind. ;)

Thanks for the fixes regarding HACS and libturbojpeg! I'll test those today and let you know if I see anything weird.

Just switched to latest/stable and I see zero errors on the logs. Still no change regarding the updater sensor, though.

If the official updater didn't work with your setup either, I guess that's a problem with the Core library that is doing the request. Or an issue with your network configuration.

Suggest that you reach out to someone on the forums or discord and hear if someone else's have experienced and issue with the aiohttp-client package or what was giving you an error. :)

Guess the error «Cannot write to closing transport» can be helpful to them.

Hey Joachim,

Just wanted to let you know that I was finally able to fix this issue.

It seems that I removed the default_config: line from my configuration.yaml file at some point. The binary sensor came back online as soon as I put it back in and restarted.

Hope that helps! Sorry for making you work extra time on this issue, btw!

Ah, that makes sense! :D Never thought about that.... Thanks for the heads up, donation - I'm so happy that you solved it!

If you want (as me) to not have all the integrations (default_config) enabled, you can just add updater: to you configuration.yaml (or packages if you use that setup).

Thanks for the tip! I do like the idea of keeping things as clean as possible.

Keep up the good work!

Hey Joachim! So the issue seems to have returned (along with a bunch of new unrelated errors) on the latest version (2021.11.0). I haven't touched the config since we last chatted about this, so I'm not sure what's going on.

I'm attaching a copy of the full log in case it helps. Cheers!

Not sure if the attachment is going through, so here's the copypasta version just in case:

2021-11-05 18:17:51 WARNING (SyncWorker_0) [homeassistant.util.yaml.loader] YAML file /var/snap/home-assistant-snap/428/configuration.yaml contains duplicate key "frontend". Check lines 9 and 46
2021-11-05 18:17:51 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-11-05 18:17:51 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration wyzeapi which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-11-05 18:17:51 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration helium which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-11-05 18:17:51 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration browser_mod which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-11-05 18:17:51 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration nodered which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-11-05 18:17:52 WARNING (MainThread) [homeassistant.components.http] The 'base_url' option near /var/snap/home-assistant-snap/428/configuration.yaml:50 is deprecated, please remove it from your configuration
2021-11-05 18:17:52 WARNING (Recorder) [homeassistant.components.recorder.util] Version 3.31.1 of SQLite is not supported; minimum supported version is 3.32.1. Starting with Home Assistant 2022.2 this will prevent the recorder from starting. Please upgrade your database software before then
2021-11-05 18:17:54 ERROR (MainThread) [homeassistant.setup] Setup failed for updater: Integration not found.
2021-11-05 18:17:54 ERROR (MainThread) [haffmpeg.core] FFmpeg fails [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/haffmpeg/core.py", line 136, in open
self._proc = await self._loop.run_in_executor(None, proc_func)
File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.8/subprocess.py", line 858, in __init__
self._execute_child(args, executable, preexec_fn, close_fds,
File "/usr/lib/python3.8/subprocess.py", line 1704, in _execute_child
raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
2021-11-05 18:17:54 WARNING (MainThread) [haffmpeg.tools] Error starting FFmpeg.
2021-11-05 18:18:01 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: SYS.ResetInd.Callback(Reason=<ResetReason.PowerUp: 0>, TransportRev=2, ProductId=1, MajorRel=2, MinorRel=7, MaintRel=1)
2021-11-05 18:18:15 ERROR (MainThread) [zigpy.application] Couldn't start application
2021-11-05 18:18:15 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start ZNP = Texas Instruments Z-Stack ZNP protocol: CC253x, CC26x2, CC13x2 coordinator
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/api.py", line 395, in request
response = await response_future
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/components/zha/core/gateway.py", line 152, in async_initialize
self.application_controller = await app_controller_cls.new(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/application.py", line 69, in new
await app.startup(auto_form)
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 196, in startup
return await self._startup(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 209, in _startup
await znp.connect()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/api.py", line 116, in connect
self.capabilities = (await self.request(c.SYS.Ping.Req())).Capabilities
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/api.py", line 395, in request
response = await response_future
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/async_timeout/__init__.py", line 55, in __aexit__
self._do_exit(exc_type)
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/async_timeout/__init__.py", line 92, in _do_exit
raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
2021-11-05 18:18:15 WARNING (MainThread) [homeassistant.config_entries] Config entry 'CP2102N USB to UART Bridge Controller, s/n: 5c825e6f1493eb1180c11b4f3d98b6d1 - Silicon Labs' for zha integration not ready yet; Retrying in background
2021-11-05 18:18:15 WARNING (MainThread) [homeassistant.bootstrap] Support for the running Python version 3.8.10 is deprecated and will be removed in Home Assistant 2022.1. Please upgrade Python to 3.9.0 or higher.
2021-11-05 18:18:15 WARNING (Recorder) [homeassistant.components.recorder.migration] Database is about to upgrade. Schema version: 22
2021-11-05 18:18:15 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns name to table statistics_meta. Note: this can take several minutes on large databases and slow computers. Please be patient!
2021-11-05 18:18:19 ERROR (SyncWorker_0) [scapy.runtime] Cannot set filter: libpcap is not available. Cannot compile filter !
2021-11-05 18:18:19 ERROR (SyncWorker_0) [homeassistant.components.dhcp] Cannot watch for dhcp packets without a functional packet filter: libpcap is not available. Cannot compile filter !
2021-11-05 18:20:10 WARNING (Recorder) [homeassistant.components.sensor.recorder] The unit of sensor.helium_wallet_today (HNT) does not match the unit of already compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None
2021-11-05 18:20:10 WARNING (Recorder) [homeassistant.components.sensor.recorder] The unit of sensor.helium_wallet_weekly (HNT) does not match the unit of already compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None
2021-11-05 18:20:10 WARNING (Recorder) [homeassistant.components.sensor.recorder] The unit of sensor.helium_wallet_monthly (HNT) does not match the unit of already compiled statistics (None). Generation of long term statistics will be suppressed unless the unit changes back to None
2021-11-05 19:48:51 ERROR (MainThread) [homeassistant.components.roku.coordinator] Error fetching roku data: Invalid response from API: Timeout occurred while connecting to device
2021-11-05 20:18:00 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for sensor.energy_production_today (<class 'homeassistant.components.forecast_solar.sensor.ForecastSolarSensorEntity'>) took 0.477 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+forecast_solar%22
2021-11-05 22:17:58 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/topology.py", line 52, in scan_loop
await self.scan()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/topology.py", line 63, in scan
await self._scan_task
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/topology.py", line 86, in _scan
await device.neighbors.scan()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/neighbor.py", line 94, in scan
return await self._scan()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/neighbor.py", line 105, in _scan
status, rsp = await self._device.zdo.Mgmt_Lqi_req(idx, tries=3, delay=1)
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/util.py", line 110, in retry
r = await func()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/device.py", line 265, in request
result, msg = await self._application.request(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 627, in request
return await self._send_request(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 1588, in _send_request
response = await self._send_request_raw(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 1431, in _send_request_raw
return await self._send_zdo_request(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 1392, in _send_zdo_request
response = await self._znp.request_callback_rsp(
AttributeError: 'NoneType' object has no attribute 'request_callback_rsp'
2021-11-06 05:03:09 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.active_lime_cougar is taking over 10 seconds
2021-11-06 06:45:14 ERROR (MainThread) [homeassistant.components.roku.coordinator] Error fetching roku data: Invalid response from API: Timeout occurred while connecting to device
2021-11-06 08:45:36 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x48ED:1:0x0001]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>')]
2021-11-06 08:45:36 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x48ED:1:0x0500]: async_initialize: all attempts have failed: [DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>'), DeliveryError('Request failed after 5 attempts: <Status.MAC_NO_ACK: 233>')]
2021-11-06 09:29:24 ERROR (stream_worker) [homeassistant.components.stream.worker] Error demuxing stream: Timestamp overflow detected: last dts = 4289502620, dts = -5458676
2021-11-06 11:39:56 ERROR (MainThread) [haffmpeg.core] FFmpeg fails [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/haffmpeg/core.py", line 136, in open
self._proc = await self._loop.run_in_executor(None, proc_func)
File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.8/subprocess.py", line 858, in __init__
self._execute_child(args, executable, preexec_fn, close_fds,
File "/usr/lib/python3.8/subprocess.py", line 1704, in _execute_child
raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
2021-11-06 11:39:56 WARNING (MainThread) [haffmpeg.tools] Error starting FFmpeg.
2021-11-06 11:39:56 ERROR (MainThread) [haffmpeg.core] FFmpeg fails [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/haffmpeg/core.py", line 136, in open
self._proc = await self._loop.run_in_executor(None, proc_func)
File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.8/subprocess.py", line 858, in __init__
self._execute_child(args, executable, preexec_fn, close_fds,
File "/usr/lib/python3.8/subprocess.py", line 1704, in _execute_child
raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
2021-11-06 11:39:56 WARNING (MainThread) [haffmpeg.tools] Error starting FFmpeg.
2021-11-06 11:39:56 ERROR (MainThread) [haffmpeg.core] FFmpeg fails [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/haffmpeg/core.py", line 136, in open
self._proc = await self._loop.run_in_executor(None, proc_func)
File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.8/subprocess.py", line 858, in __init__
self._execute_child(args, executable, preexec_fn, close_fds,
File "/usr/lib/python3.8/subprocess.py", line 1704, in _execute_child
raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
2021-11-06 11:39:56 WARNING (MainThread) [haffmpeg.tools] Error starting FFmpeg.
2021-11-06 11:39:56 ERROR (MainThread) [haffmpeg.core] FFmpeg fails [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/haffmpeg/core.py", line 136, in open
self._proc = await self._loop.run_in_executor(None, proc_func)
File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.8/subprocess.py", line 858, in __init__
self._execute_child(args, executable, preexec_fn, close_fds,
File "/usr/lib/python3.8/subprocess.py", line 1704, in _execute_child
raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: '/snap/home-assistant-snap/390/usr/bin/ffmpeg'
2021-11-06 11:39:56 WARNING (MainThread) [haffmpeg.tools] Error starting FFmpeg.

Hi,

The first thing failing, that I can see is the Zigbee integration. Looks like it can't connect to the USB dongle. Can you try to do a power off? Then unplug the dongle, replug and start the device again?

Hey!

Yeah, I've done that and it doesn't seem to change matters, although judging by the logs it seems to retry and work after the second try.

Here's an abridged copy of my logs after a quick restart (I think that the warnings are especially interesting). Note the lack of updater errors, even though it still shows as unavailable on my dashboard:

2021-11-13 12:30:43 WARNING (Recorder) [homeassistant.components.recorder.util] Version 3.31.1 of SQLite is not supported; minimum supported version is 3.32.1. Starting with Home Assistant 2022.2 this will prevent the recorder from starting. Please upgrade your database software before then
2021-11-13 12:30:44 ERROR (MainThread) [haffmpeg.core] FFmpeg fails [Errno 2] No such file or directory: '/snap/home-assistant-snap/latest/usr/bin/ffmpeg'
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/haffmpeg/core.py", line 136, in open
self._proc = await self._loop.run_in_executor(None, proc_func)
File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.8/subprocess.py", line 858, in __init__
self._execute_child(args, executable, preexec_fn, close_fds,
File "/usr/lib/python3.8/subprocess.py", line 1704, in _execute_child
raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: '/snap/home-assistant-snap/latest/usr/bin/ffmpeg'
2021-11-13 12:30:44 WARNING (MainThread) [haffmpeg.tools] Error starting FFmpeg.
2021-11-13 12:30:50 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: SYS.ResetInd.Callback(Reason=<ResetReason.PowerUp: 0>, TransportRev=2, ProductId=1, MajorRel=2, MinorRel=7, MaintRel=1)
2021-11-13 12:30:54 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform helium is taking over 10 seconds.
2021-11-13 12:31:05 ERROR (MainThread) [zigpy.application] Couldn't start application
2021-11-13 12:31:05 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start ZNP = Texas Instruments Z-Stack ZNP protocol: CC253x, CC26x2, CC13x2 coordinator
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/api.py", line 395, in request
response = await response_future
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/components/zha/core/gateway.py", line 152, in async_initialize
self.application_controller = await app_controller_cls.new(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy/application.py", line 69, in new
await app.startup(auto_form)
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 196, in startup
return await self._startup(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 209, in _startup
await znp.connect()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/api.py", line 116, in connect
self.capabilities = (await self.request(c.SYS.Ping.Req())).Capabilities
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/zigpy_znp/api.py", line 395, in request
response = await response_future
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/async_timeout/__init__.py", line 55, in __aexit__
self._do_exit(exc_type)
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/async_timeout/__init__.py", line 92, in _do_exit
raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
2021-11-13 12:31:05 WARNING (MainThread) [homeassistant.config_entries] Config entry 'CP2102N USB to UART Bridge Controller, s/n: 5c825e6f1493eb1180c11b4f3d98b6d1 - Silicon Labs' for zha integration not ready yet; Retrying in background
2021-11-13 12:31:05 WARNING (MainThread) [homeassistant.bootstrap] Support for the running Python version 3.8.10 is deprecated and will be removed in Home Assistant 2022.1. Please upgrade Python to 3.9.0 or higher.
2021-11-13 12:31:06 ERROR (SyncWorker_0) [scapy.runtime] Cannot set filter: libpcap is not available. Cannot compile filter !
2021-11-13 12:31:06 ERROR (SyncWorker_0) [homeassistant.components.dhcp] Cannot watch for dhcp packets without a functional packet filter: libpcap is not available. Cannot compile filter !

Also, I don't know if this is related, but I can't enter the shell anymore:

⚡ snap run --shell home-assistant-snap                                                
/user.slice/user-1000.slice/session-3.scope is not a snap cgroup

I figured out why the updater integration wasn't in the logs… I had disabled it in the configuration since I spotted the error a few days ago. When I added it back and attempted to restart HA I got this error:

2021-11-13 18:15:27 ERROR (MainThread) [homeassistant.components.homeassistant] The system cannot restart because the configuration is not valid: Integration error: updater - Integration 'updater' not found.
2021-11-13 18:15:27 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139950211890672] The system cannot restart because the configuration is not valid: Integration error: updater - Integration 'updater' not found.
Traceback (most recent call last):
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/components/websocket_api/commands.py", line 185, in handle_call_service
await hass.services.async_call(
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/core.py", line 1495, in async_call
task.result()
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/core.py", line 1530, in _execute_service
await handler.job.target(service_call)
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/helpers/service.py", line 737, in admin_handler
await result
File "/snap/home-assistant-snap/428/lib/python3.8/site-packages/homeassistant/components/homeassistant/__init__.py", line 171, in async_handle_core_service
raise HomeAssistantError(
homeassistant.exceptions.HomeAssistantError: The system cannot restart because the configuration is not valid: Integration error: updater - Integration 'updater' not found.

Hi,

I've been working on updating Python in the HA snap. That might have caused the missing 'updater' plugin. Which channel are you on?

/user.slice/user-1000.slice/session-3.scope is not a snap cgroup

This cant't be anything related to this snap directly. Why would you need to access the shell?

Which channel are you on?

I'm currently on latest/stable (2021.11.4 to be more precise)

Why would you need to access the shell?

I was using it to figure out where some binaries are located within the snap (such as ffmpeg). It's not a huge deal, but I guess it would be nice to have it if possible ;)

FYI right now both HACS and the updater sensor are showing as Unavailable, so let me know if there's something in particular that you'd like me to try out.

I just did a full restart and both the updater sensor and HACS are back online. :)

Goody :))

Isn't ffmpeg in the snap? Though we fixed that earlier. Let me know how you use it so I can debug it further (e.g configuration data).

Sorry for the problems you've had. But the deprecation of Python 3.8 that id the default version bundled with snaps (in general) have been a hassle to fix.

But that should now be resolved too. And make it easier to update to newest supported python versions in the future.

I'm the only maintainer of this and I'm doing the work in my spare time, so cases with bigger issues can sometime take days to fix. But every fix should make it more stable in the future.