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
72.98k stars 30.53k forks source link

IO Error in ZHA component on HA restart #32726

Closed sam-ward closed 4 years ago

sam-ward commented 4 years ago

Home Assistant release with the issue: 0.100.2

Operating environment (HassOS/Generic): hass.io image on RPi 3B+ (hassio version 192)

Supervisor logs:

home-assistant.log

Description of problem: I have HA setup and running the ZHA component connected to a conbee 2 zigbee stick. When performing a restart of HA (configuration -> server control -> restart) often, but not always, the ZHA component will not work on the restart. After the HA devs looked at the logs (home-assistant/home-assistant/issues/28637) it was found that there was an OSError: [Errno 5] I/O error occurring, and they suggested I raise an issue here. The only way to get the ZHA component working again is to do a full reboot of the Pi.

I don't have supervisor logs as yet, but will grab them when it fails again.

stale[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

sam-ward commented 4 years ago

Do any of the dev's have a suggestion how I can troubleshoot this?? as it is very annoying when trying to work on homeassistant.

sam-ward commented 4 years ago

I have just upgraded to hass 0.104.1 and hassos 3.8 and the issue still persists.

The following is appears in the hass log file: 2020-01-18 10:38:41 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.read_parameter' command 2020-01-18 10:38:41 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry /dev/serial/by-id/usb-dresden_elektronik_ingenieurtechnik_GmbH_ConBee_II_DE2124127-if00 for zha Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/config_entries.py", line 215, in async_setup hass, self File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 103, in async_setup_entry await zha_gateway.async_initialize() File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 124, in async_initialize await self.application_controller.startup(auto_form=True) File "/usr/local/lib/python3.7/site-packages/zigpy_deconz/zigbee/application.py", line 45, in startup self.version = await self._api.version() File "/usr/local/lib/python3.7/site-packages/zigpy_deconz/api.py", line 310, in version (self._proto_ver,) = await self[NetworkParameter.protocol_version] File "/usr/local/lib/python3.7/site-packages/zigpy_deconz/api.py", line 280, in read_parameter r = await self._command(Command.read_parameter, 1 + len(data), param, data) File "/usr/local/lib/python3.7/site-packages/zigpy_deconz/api.py", line 210, in _command return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT) File "/usr/local/lib/python3.7/asyncio/tasks.py", line 449, in wait_for raise futures.TimeoutError() concurrent.futures._base.TimeoutError

sam-ward commented 4 years ago

And still getting the problem on 0.105.4, Supervisor 200, and HassOS 3.10.

I would really appreciate some help with this one, as not only does it loose connection to the zigbee stick after an update, but I am also getting intermittent strangeness with ZHA in general (seems like events fire multiple times for no reasons, error messages saying it failed to send a packet etc).

To me the problem is reminiscent of the ModemManager grabbing the device, but I dont know if this is possible with the HomeAssistant built (formally hassio) or how to check something lower level like that on the Rpi (too many layers of docker containers in the way).

basnagel commented 4 years ago

I am having a similar problem in a different setup, not HASS.IO Some restarts the conbee2 is working, other restarts it is not. A complete reboot of the jail is not neccesary in my case.

Setup is a Freenas server with following HA install https://github.com/tprelog/iocage-homeassistant It is a python virtualenv

arch | amd64 dev | false docker | false hassio | false os_name | FreeBSD os_version | 11.3-RELEASE-p6 python_version | 3.7.6 timezone | Europe/Amsterdam version | 0.106.5 virtualenv | true

zigpy-deconz 0.7.0 zigpy-homeassistant 0.16.0

Log off failing reboot: 2020-03-10 21:21:32 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for zha_map which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant. 2020-03-10 21:21:32 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant. 2020-03-10 21:21:37 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.read_parameter' command 2020-03-10 21:21:37 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry /dev/cuaU0 for zha Traceback (most recent call last): File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/config_entries.py", line 215, in async_setup hass, self File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/zha/init.py", line 103, in async_setup_entry await zha_gateway.async_initialize() File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/zha/core/gateway.py", line 137, in async_initialize await self.application_controller.startup(auto_form=True) File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/zigbee/application.py", line 45, in startup self.version = await self._api.version() File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/api.py", line 310, in version (self._proto_ver,) = await self[NetworkParameter.protocol_version] File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/api.py", line 280, in read_parameter r = await self._command(Command.read_parameter, 1 + len(data), param, data) File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/api.py", line 210, in _command return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT) File "/usr/local/lib/python3.7/asyncio/tasks.py", line 449, in wait_for raise futures.TimeoutError() concurrent.futures._base.TimeoutError

pvizeli commented 4 years ago

I sounds like an serial deadlock

Adminiuga commented 4 years ago

Didn't we have something similar in the past, when it was initializing too fast? Iirc had to do something with udev?

Nixellion commented 4 years ago

+1

Proxmox, Debian 10, Hass.io install script, device shows up under Supervisor - Hardware. Elelabs ZigBee USB

2020-03-11 23:59:17 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry /dev/ttyUSB0 for zha
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 215, in async_setup
    hass, self
  File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 103, in async_setup_entry
    await zha_gateway.async_initialize()
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 137, in async_initialize
    await self.application_controller.startup(auto_form=True)
  File "/usr/local/lib/python3.7/site-packages/bellows/zigbee/application.py", line 135, in startup
    await self.initialize()
  File "/usr/local/lib/python3.7/site-packages/bellows/zigbee/application.py", line 72, in initialize
    await e.reset()
  File "/usr/local/lib/python3.7/site-packages/bellows/ezsp.py", line 57, in reset
    await self._gw.reset()
  File "/usr/local/lib/python3.7/site-packages/bellows/uart.py", line 222, in reset
    return await asyncio.wait_for(self._reset_future, timeout=RESET_TIMEOUT)
  File "/usr/local/lib/python3.7/asyncio/tasks.py", line 449, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError
probot-home-assistant[bot] commented 4 years ago

Hey there @dmulcahey, mind taking a look at this issue as its been labeled with a integration (zha) you are listed as a codeowner for? Thanks!

Adminiuga commented 4 years ago

enable bellows: debug reproduce and send the logs. We're closing serial port on homeassistant.close event and re-open it when integration is being setup. I'm at loss how else we should be handling it. Both reports it on HassOS and no reports when running in venv. Is home assistant core restart different on HassOS?

Adminiuga commented 4 years ago

i guess we could try rising ConfigEntryNotReady on timeouts, but that more of a workaround.

Adminiuga commented 4 years ago

@Nixellion can you try installing pip3 install bellows-homeassistant and then run bellows -v DEBUG -d /dev/PATH_TO_YOUR_DEVICE info ?

Nixellion commented 4 years ago

@Adminiuga 

root@hass:~# bellows -v DEBUG -d /dev/ttyUSB0
Usage: bellows [OPTIONS] COMMAND [ARGS]...
Try 'bellows --help' for help.

Error: Missing command.

root@hass:~# ls /dev
autofs           gpiochip0           ppp       sr0     tty20  tty37  tty53    ttyS2    vcsa5
block            hidraw0             psaux     stderr  tty21  tty38  tty54    ttyS3    vcsa6
bsg              hpet                ptmx      stdin   tty22  tty39  tty55    ttyUSB0  vcsu
btrfs-control    hugepages           pts       stdout  tty23  tty4   tty56    uhid     vcsu1
bus              initctl             random    tty     tty24  tty40  tty57    uinput   vcsu2
cdrom            input               rfkill    tty0    tty25  tty41  tty58    urandom  vcsu3
char             kmsg                rtc       tty1    tty26  tty42  tty59    vcs      vcsu4
console          log                 rtc0      tty10   tty27  tty43  tty6     vcs1     vcsu5
core             loop-control        sda       tty11   tty28  tty44  tty60    vcs2     vcsu6
cpu_dma_latency  mapper              sda1      tty12   tty29  tty45  tty61    vcs3     vfio
cuse             mem                 sda2      tty13   tty3   tty46  tty62    vcs4     vga_arbiter
disk             memory_bandwidth    sda5      tty14   tty30  tty47  tty63    vcs5     vhci
dri              mqueue              serial    tty15   tty31  tty48  tty7     vcs6     vhost-net
dvd              net                 sg0       tty16   tty32  tty49  tty8     vcsa     vhost-vsock
fb0              network_latency     sg1       tty17   tty33  tty5   tty9     vcsa1    zero
fd               network_throughput  shm       tty18   tty34  tty50  ttyACM0  vcsa2
full             null                snapshot  tty19   tty35  tty51  ttyS0    vcsa3
fuse             port                snd       tty2    tty36  tty52  ttyS1    vcsa4
Adminiuga commented 4 years ago

info??? "`bellows -v DEBUG -d /dev/PATH_TO_YOUR_DEVICE info"

Adminiuga commented 4 years ago

bellows -v DEBUG -d /dev/ttyUSB0 info

Nixellion commented 4 years ago

@Adminiuga oops sorry, did not sleep well lately

root@hass:~# bellows -v DEBUG -d /dev/ttyUSB0 info
debug: Using selector: EpollSelector
debug: Using selector: EpollSelector
debug: Connected. Resetting.
debug: Resetting EZSP
debug: Resetting ASH
debug: Sending: b'1ac038bc7e'
Traceback (most recent call last):
  File "/usr/local/bin/bellows", line 10, in <module>
    sys.exit(main())
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/bellows/cli/util.py", line 38, in inner
    loop.run_until_complete(f(*args, **kwargs))
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.7/dist-packages/bellows/cli/ncp.py", line 66, in info
    s = await util.setup(ctx.obj["device"], ctx.obj["baudrate"])
  File "/usr/local/lib/python3.7/dist-packages/bellows/cli/util.py", line 102, in setup
    await s.reset()
  File "/usr/local/lib/python3.7/dist-packages/bellows/ezsp.py", line 57, in reset
    await self._gw.reset()
  File "/usr/local/lib/python3.7/dist-packages/bellows/uart.py", line 222, in reset
    return await asyncio.wait_for(self._reset_future, timeout=RESET_TIMEOUT)
  File "/usr/lib/python3.7/asyncio/tasks.py", line 423, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError

Then just seems to hang there

Adminiuga commented 4 years ago

are you sure that dongle actually works? you don't happen to have any other machine with linux as a host OS?

Either the problem is with the dongle or the problem is with USB pass through into virtual machine. Bellows does send data to UART: debug: Sending: b'1ac038bc7e' but doesn't get anything in response.

Nixellion commented 4 years ago

@Adminiuga I will try to test it on another linux machine tomorrow

Nixellion commented 4 years ago

@Adminiuga So tried it on a Kubuntu laptop, and it's the same:

root@nix-N56VZ:/home/nix# bellows -v DEBUG -d /dev/ttyUSB0 info
debug: Using selector: EpollSelector
debug: Using selector: EpollSelector
debug: Connected. Resetting.
debug: Resetting EZSP
debug: Resetting ASH
debug: Sending: b'1ac038bc7e'
Traceback (most recent call last):
  File "/usr/local/bin/bellows", line 10, in <module>
    sys.exit(main())
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 1137, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python3.7/dist-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/click/decorators.py", line 17, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/lib/python3.7/dist-packages/bellows/cli/util.py", line 38, in inner
    loop.run_until_complete(f(*args, **kwargs))
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.7/dist-packages/bellows/cli/ncp.py", line 66, in info
    s = await util.setup(ctx.obj["device"], ctx.obj["baudrate"])
  File "/usr/local/lib/python3.7/dist-packages/bellows/cli/util.py", line 102, in setup
    await s.reset()
  File "/usr/local/lib/python3.7/dist-packages/bellows/ezsp.py", line 57, in reset
    await self._gw.reset()
  File "/usr/local/lib/python3.7/dist-packages/bellows/uart.py", line 222, in reset
    return await asyncio.wait_for(self._reset_future, timeout=RESET_TIMEOUT)
  File "/usr/lib/python3.7/asyncio/tasks.py", line 423, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError

So does it mean my USB stick is faulty? Should I RMA it or is there another way to test it?

Just in case, I did run ls /dev | grep USB before and after I plugged it in, so quite certain it's the one, no other usb devices attached.

Adminiuga commented 4 years ago

Hrm, This does sound like a bad stick. Try connecting to the stick, using a regular terminal, no HW flow control, no SW flow control, try speeds 38400, 57600 and 115200 and see if you get anything on the terminal. But generally sticks should have EZSP firmware installed, meaning they should respond to the reset frame. Yours is not doing that. Otherwise contact Elelabs for support or RMA it.

Nixellion commented 4 years ago

@Adminiuga I'm not sure how to connect to the stick the way you describe, not familiar with it

Adminiuga commented 4 years ago

I meant to say "serial terminal", like mincom. But better in this case either contact Elelabs for support or just RMA it.

balloob commented 4 years ago

I suggest that we should at least catch this error and try to print a meaningful error message.

sam-ward commented 4 years ago

So I don't know if its related to a particular device, or zha in general on my instance, but shortly after rebooting last night (after updating home assitant core to 0.106.6), I noticed the following messages in the log.

2020-03-13 21:39:49 INFO (MainThread) [zigpy_deconz.zigbee.application] New device joined: 0xf4bb, 00:15:8d:00:02:b7:59:e9
2020-03-13 21:39:49 INFO (MainThread) [zigpy.application] Device 0xf4bb (00:15:8d:00:02:b7:59:e9) joined the network
2020-03-13 21:39:56 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 8 req id frame: 0xe9
2020-03-13 21:39:56 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 10 req id frame: 0xe9
2020-03-13 21:39:57 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 2 req id frame: 0xf0
2020-03-13 21:39:57 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 4 req id frame: 0xf0
2020-03-13 21:39:57 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 6 req id frame: 0xf0
2020-03-13 21:40:02 INFO (MainThread) [hacs.factory] Task processing of 12 tasks completed in 12 seconds
2020-03-13 21:40:23 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 12 req id frame: 0xe9
2020-03-13 21:40:23 WARNING (MainThread) [zigpy_deconz.zigbee.application] Error while sending 14 req id frame: 0xe9
2020-03-13 21:43:44 INFO (MainThread) [zigpy_deconz.zigbee.application] New device joined: 0x68f7, 84:18:26:00:00:e8:f2:27
2020-03-13 21:43:44 INFO (MainThread) [zigpy.application] Device 0x68f7 (84:18:26:00:00:e8:f2:27) joined the network

There are many other "error while sending" messages in the log subsiquent to that. As I said not sure if this is related to my original problem or something else, but I just thought id put it out there incase its relevant.

Nixellion commented 4 years ago

I emailed Elelabs both on their info email and email of their representative who curated my purchase and actually offered help if I had any problems. So far been about a day, no response. Maybe a weekend.

Adminiuga commented 4 years ago

@sam-ward those are not errors in zha, but errors reported by the network and are normal part of operations. It's normal to see those during restarts and is not related to original error. Do you still get the original error on restarts?

carlos-sarmiento commented 4 years ago

I'm seeing the same. I also have the conbee stick but I'm running on Docker. To me the issue started around 0.100 (I don't remember exactly, in the beginning I blamed batteries and such and didn't associate it with HA).

I'm running HA on Docker. I've made a setup were I try not to restart HA often, but will post my own logs when this happens again. Is there anything I can do to monitor when that happens?

Adminiuga commented 4 years ago

You have to be more specific about: "I'm seeing the same". The zigpy_deconz.zigbee.application] Error while sending 8 req id frame: 0xe9 are normal to be seen after a restart.

If you are getting:

019-11-08 23:05:04 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal write error on serial transport
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/serial/serialposix.py", line 505, in write
    n = os.write(self.fd, d)
OSError: [Errno 5] I/O error

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 120, in write
    n = self._serial.write(data)
  File "/usr/local/lib/python3.7/site-packages/serial/serialposix.py", line 537, in write
    raise SerialException('write failed: {}'.format(v))
serial.serialutil.SerialException: write failed: [Errno 5] I/O error

or

2020-03-10 21:21:32 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for zha_map which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-10 21:21:32 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-10 21:21:37 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.read_parameter' command
2020-03-10 21:21:37 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry /dev/cuaU0 for zha
Traceback (most recent call last):
File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/config_entries.py", line 215, in async_setup
hass, self
File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/zha/init.py", line 103, in async_setup_entry
await zha_gateway.async_initialize()
File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/zha/core/gateway.py", line 137, in async_initialize
await self.application_controller.startup(auto_form=True)
File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/zigbee/application.py", line 45, in startup
self.version = await self._api.version()
File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/api.py", line 310, in version
(self._proto_ver,) = await self[NetworkParameter.protocol_version]
File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/api.py", line 280, in read_parameter
r = await self._command(Command.read_parameter, 1 + len(data), param, data)
File "/srv/homeassistant/lib/python3.7/site-packages/zigpy_deconz/api.py", line 210, in _command
return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
File "/usr/local/lib/python3.7/asyncio/tasks.py", line 449, in wait_for
raise futures.TimeoutError()
concurrent.futures._base.TimeoutError

Which are two different issues and should have been tracked separately, then submit logs and details as per issue template

carlos-sarmiento commented 4 years ago

I'm sorry, you are absolutely right. I don't have logs that show the error right now (I'll post the logs as soon as a restart of my HA setup throws it again).

But I've read the logs and it is a similar I/O error when trying to read from the Conbee stick.

I'll try to restart my instance today and get the repro (I just don't like to do it because recovering from the Zigbee issue is a pain)

carlos-sarmiento commented 4 years ago

So I got the error here after restarting my server:

2020-03-18 00:02:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for fontawesome which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for nodered which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for garbage_collection which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:56 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:58 WARNING (MainThread) [homeassistant.components.group] The 'view' option (with value 'True') is deprecated, please remove it from your configuration. This option will become invalid in version 0.107.0
2020-03-18 00:02:58 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for attributes which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:59 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry /dev/zigbee for zha
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/serial/serialposix.py", line 244, in open
    self.fd = os.open(self.portstr, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK)
OSError: [Errno 6] No such device or address: '/dev/zigbee'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 215, in async_setup
    hass, self
  File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 103, in async_setup_entry
    await zha_gateway.async_initialize()
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 126, in async_initialize
    await radio.connect(usb_path, baudrate)
  File "/usr/local/lib/python3.7/site-packages/zigpy_deconz/api.py", line 198, in connect
    self._uart = await uart.connect(device, DECONZ_BAUDRATE, self)
  File "/usr/local/lib/python3.7/site-packages/zigpy_deconz/uart.py", line 120, in connect
    xonxoff=False,
  File "/usr/local/lib/python3.7/asyncio/coroutines.py", line 120, in coro
    res = func(*args, **kw)
  File "/usr/local/lib/python3.7/site-packages/serial_asyncio/__init__.py", line 410, in create_serial_connection
    ser = serial.serial_for_url(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/serial/__init__.py", line 88, in serial_for_url
    instance.open()
  File "/usr/local/lib/python3.7/site-packages/serial/serialposix.py", line 247, in open
    raise SerialException(msg.errno, "could not open port {}: {}".format(self._port, msg))
serial.serialutil.SerialException: [Errno 6] could not open port /dev/zigbee: [Errno 6] No such device or address: '/dev/zigbee'
2020-03-18 00:02:59 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for wyzesense which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:59 DEBUG (SyncWorker_13) [custom_components.wyzesense.wyzesense_custom] Start Inquiry...
2020-03-18 00:02:59 DEBUG (SyncWorker_13) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=4327, Payload=<None>
2020-03-18 00:02:59 DEBUG (SyncWorker_13) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa55430327016c'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa43042801016f'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa43042801016f'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=4328, Payload=b'01'
2020-03-18 00:02:59 DEBUG (SyncWorker_13) [custom_components.wyzesense.wyzesense_custom] Inquiry returns 1
2020-03-18 00:02:59 DEBUG (SyncWorker_13) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=5314, Payload=b'ff'
2020-03-18 00:02:59 DEBUG (SyncWorker_13) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa55530414ff0269'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa5314ff026555aa530e3500000170ec64c3cb0314ff05fa55aa530315016a'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa5314ff0265'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=53FF, Payload=ACK(5314)
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa530e3500000170ec64c3cb0314ff05fa55aa530315016a55aa530315016a'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa530e3500000170ec64c3cb0314ff05fa'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5335, Payload=b'00000170ec64c3cb0314ff'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5335)
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555335ff0286'
2020-03-18 00:02:59 INFO (Thread-2) [custom_components.wyzesense.wyzesense_custom] LOG: time=2020-03-17T23:46:31.627000, data=b'14ff'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa530315016a55aa530315016a'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa530315016a'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5315, Payload=<None>
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5315)
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555315ff0266'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa530315016a'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa530315016a'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5315, Payload=<None>
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5315)
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555315ff0266'
2020-03-18 00:02:59 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for accumulator which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa530332018755aa5303320187'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa5303320187'
2020-03-18 00:02:59 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5332, Payload=<None>
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5332)
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555332ff0283'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=5333, Payload=b'00000170ec73d8aa'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa55530b3300000170ec73d8aa04e2'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa5303320187'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa5303320187'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5332, Payload=<None>
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5332)
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555332ff0283'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=5333, Payload=b'00000170ec73d8b0'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa55530b3300000170ec73d8b004e8'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa5333ff028455aa5333ff0284'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa5333ff0284'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=53FF, Payload=ACK(5333)
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa5333ff0284'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa5333ff0284'
2020-03-18 00:03:00 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=53FF, Payload=ACK(5333)
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373837413241450200000170ec48c028a2003f40'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373837413241450200000170ec48c028a2003f40'
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:01 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.keggerator_co2_pressure. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.keggerator_flow_meter. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.whole_house_energy_mains_a_amps. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.whole_house_energy_mains_voltage. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.whole_house_energy_mains_watts. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.whole_house_energy_mains_b_amps. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.whole_house_energy_total_mains_amps. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 425, in _async_add_entity
    raise HomeAssistantError(msg)
homeassistant.exceptions.HomeAssistantError: Entity id already exists: sensor.whole_house_energy_tde. Platform esphome does not generate unique IDs
2020-03-18 00:03:02 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:02 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:02 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373837413241450200000170ec48c028a2003f40'
2020-03-18 00:03:02 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:02 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:03 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:03 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:03 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373837413241450200000170ec48c028a2003f40'
2020-03-18 00:03:03 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:03 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:04 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:04 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:04 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373837413241450200000170ec48c028a2003f40'
2020-03-18 00:03:04 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:04 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:05 ERROR (SyncWorker_19) [homeassistant.components.uvc.camera] Authorization failure while connecting to NVR
2020-03-18 00:03:05 ERROR (MainThread) [homeassistant.components.sensor] octoprint: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 312, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 476, in async_device_update
    await self.hass.async_add_executor_job(self.update)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/octoprint/sensor.py", line 130, in update
    self.sensor_type, self.api_endpoint, self.api_group, self.api_tool
  File "/usr/src/homeassistant/homeassistant/components/octoprint/__init__.py", line 255, in update
    return get_value_from_json(response, sensor_type, group, tool)
  File "/usr/src/homeassistant/homeassistant/components/octoprint/__init__.py", line 270, in get_value_from_json
    if sensor_type in json_dict[group][tool]:
KeyError: 'tool1'
2020-03-18 00:03:05 ERROR (MainThread) [homeassistant.components.sensor] octoprint: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 312, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 476, in async_device_update
    await self.hass.async_add_executor_job(self.update)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/octoprint/sensor.py", line 130, in update
    self.sensor_type, self.api_endpoint, self.api_group, self.api_tool
  File "/usr/src/homeassistant/homeassistant/components/octoprint/__init__.py", line 255, in update
    return get_value_from_json(response, sensor_type, group, tool)
  File "/usr/src/homeassistant/homeassistant/components/octoprint/__init__.py", line 270, in get_value_from_json
    if sensor_type in json_dict[group][tool]:
KeyError: 'tool1'
2020-03-18 00:03:05 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:05 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373837413241450200000170ec48c028a2003f4007ca'
2020-03-18 00:03:05 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373837413241450200000170ec48c028a2003f40'
2020-03-18 00:03:05 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:05 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:06 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373933463442460200000170ec426a21a2010a770770'
2020-03-18 00:03:06 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373933463442460200000170ec426a21a2010a770770'
2020-03-18 00:03:06 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373933463442460200000170ec426a21a2010a77'
2020-03-18 00:03:06 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:06 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:07 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373933463442460200000170ec43a51ea2000a7807a9'
2020-03-18 00:03:07 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373933463442460200000170ec43a51ea2000a7807a9'
2020-03-18 00:03:07 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373933463442460200000170ec43a51ea2000a78'
2020-03-18 00:03:07 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:07 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:08 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373933463442460200000170ec43a51ea2000a7807a9'
2020-03-18 00:03:08 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373933463442460200000170ec43a51ea2000a7807a9'
2020-03-18 00:03:08 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373933463442460200000170ec43a51ea2000a78'
2020-03-18 00:03:08 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:08 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373933463442460200000170ec43c5d5a2010a790882'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373933463442460200000170ec43c5d5a2010a790882'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373933463442460200000170ec43c5d5a2010a79'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Trying to parse: b'55aa531937a237373933463442460200000170ec43c5d5a2010a790882'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Received: b'55aa531937a237373933463442460200000170ec43c5d5a2010a790882'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] <=== Received: Packet: Cmd=5337, Payload=b'a237373933463442460200000170ec43c5d5a2010a79'
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] ===> Sending: Packet: Cmd=53FF, Payload=ACK(5337)
2020-03-18 00:03:09 DEBUG (Thread-2) [custom_components.wyzesense.wyzesense_custom] Sending: b'aa555337ff0288'
2020-03-18 00:03:10 ERROR (MainThread) [hass_nabucasa] Unexpected error in on_start <bound method RemoteUI.load_backend of <hass_nabucasa.remote.RemoteUI object at 0x7fb44ee51ed0>>
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/hass_nabucasa/remote.py", line 175, in load_backend
    snitun_port=443,
  File "/usr/local/lib/python3.7/site-packages/snitun/utils/aiohttp_client.py", line 36, in __init__
    self._site = SockSite(runner, self._socket, ssl_context=context)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_runner.py", line 168, in __init__
    ssl_context=ssl_context, backlog=backlog)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_runner.py", line 39, in __init__
    raise RuntimeError("Call runner.setup() before making a site")
RuntimeError: Call runner.setup() before making a site
Adminiuga commented 4 years ago

The serial port is not there. Why the device is /dev/zigbee ? are you running serial-over-ip?

2020-03-18 00:02:59 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry /dev/zigbee for zha
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/serial/serialposix.py", line 244, in open
    self.fd = os.open(self.portstr, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK)
OSError: [Errno 6] No such device or address: '/dev/zigbee'

We do need to catch those error, but other than that not much we could do without the device being present.

carlos-sarmiento commented 4 years ago

I have a udev rule that renames the device from /dev/ttyACM0 (or whatever, it is based on manufacturer) to /dev/zigbee. Yesterday I unplugged and replugged the conbee stick after that and restarted the docker container.

sam-ward commented 4 years ago

Please let me know if you would like me to open a new issue, but there is still something odd going on. I just upgraded from 107.3 to 107.5. After the upgrade i shutdown the rPi (from the supervisor -> system -> reboot) to shift some cables. Upon power up, the ZHA components were non-functional. No sensors were reading, no switches were working, and there were no messages in the logs about devices joining the zigbee network.

It took a subsequent restart (Configuration -> Server Control -> Restart) for the zigbee network to come back up.

Adminiuga commented 4 years ago

need new logs with debug level.

sam-ward commented 4 years ago

No problems, I’ll work to reproduce it. What components do you need the debug logs of? (Just so the logs are not too noisey).

Adminiuga commented 4 years ago

if you are using ConBee stick, configure logging: for the following components:

homeassistant.components.zha: debug
zigpy: debug
zigpy_deconz.zigbee.application: debug
zigpy_deconz.api: debug
sam-ward commented 4 years ago

Cheers. Yes I have a conbee 2.

I’ll set it up tomorrow (when it’s light as it has a habit of turning the lights off) and report back when I have some logs.

carlos-sarmiento commented 4 years ago

I ran the recommended logging from @Adminiuga and ran it until it had 3500 lines. I also have a conbee 2 and was running 0.107.5 on an x86 docker container

Here is the paste: https://pastebin.com/1BTSCW8g

Adminiuga commented 4 years ago

@carlos-sarmiento it's not bailing out ZHA setup properly. I'll need to run some tests why

carlos-sarmiento commented 4 years ago

@Adminiuga Anything I can do on my end to help?

carlos-sarmiento commented 4 years ago

Don't know if this is adding additional information, but reverted to 0.106.6 and Zigbee is working again

Adminiuga commented 4 years ago

0.107.7 should fix it

Nixellion commented 4 years ago

My issue still persists after the update. Elelabs is silent and not replying to my emails.

Adminiuga commented 4 years ago

Elelabs is crap for support. Get a different stick as it looks like your culprit is the stick itself and not the same issue as OP.

sam-ward commented 4 years ago

So i've managed to recreate the problem with the debug logging turned on.

I powered off the pi (from the Supervisor -> System -> Power off) and left it for 10 minutes. I powered it back on and let it boot. The zigbee network came up and was functional for for a few minutes (around 10 minutes based on the readings from the zigbee temp sensors), then stopped working. Log file home-assistant boot to failure.log

I then did a server restart (configuration -> server control -> restart), which did result in the zigbee network coming up. However I seem to be getting duplicate events firing. For instance I have 2 CentraLite 3130 zigbee switches, that will trigger an automation upon recieveing a button push event. You will see in the log "Toggle Dining Lights" executing twice, despite the physical button being pushed only once (the Toggle Kitchen Lights physical button was pressed twice, but four events were fired). Log file home-assistant restart duplicate events.log

I then did a reboot of the pi (Supervisor -> System -> Reboot), which seems to have brought everything back to a working state. Log file home-assistant working.log. The zigbee network is up, and events are only firing a single time.

I dont know if these two behaviours are related to the same problem, so I have included both logs. If they are different I can raise a separate issue if need be. Please let me know if you would like me to run any more tests.

cheers Sam

Nixellion commented 4 years ago

@Adminiuga That's a shame. It was one of the easiest to get to ship to Russia, any idea of some good option that could be available here?

Nixellion commented 4 years ago

Issue with Elelabs was solved. They finally contacted me and after a remote debugging session it turns out I missed the required baudrate:115200 config parameter, as required by their documentation:

https://elelabs.com/wp-content/uploads/2019/12/ELU012_UG_11_HomeAssistant.pdf

It would be good idea to add this information here too: https://www.home-assistant.io/integrations/zha

Adminiuga commented 4 years ago

Good to know. They must have changed it recently, because the elelabs dongle I have uses 57600 default baudrate. Essentially this change makes ZHA integration configuration UI unusable.

dmulcahey commented 4 years ago

that new baud means they switched to hardware flow control too I think... are there any ramifications to bellows for that? I think we had the baud in the UI when Damarco first did it and I think we were asked to remove it IIRC.

Adminiuga commented 4 years ago

Yeah, i'd like to hear official confirmation though. Potentially there are ramification for bellows, as it is using software flow control. In reality I don't think it is gonna affect it too much, but remains to be seen.