Impossible to add PiZigate with ZHA

GuillaumeDen commented 3 years ago

Error description

I am unable to configure/add ZHA integration. In the pop-up, my device is present in the dropdown

At this step, the PiZigate is glowing blue harder I am selecting zigate in the Radio Type screen after clicking submit. On the last screen, I leave a default (/dev/ttyAMA0 in my case) and click submit. And here comes the error

Technical details

fresh install, no additonal config or add-on

Home Assistant OS 0.118.4
HassOS 4.17
Integration causing this issue: Zigbee Home Automation
Device : Raspberry Pi 3B+
Using PiZigate (listed as compatible in ZHA documentation)

Traceback/Error logs

Additional informations

I tried a fresh install of raspbian lite, I then followed the steps to configure the PiZigate (including special commands for Raspberry Pi 3B) and the test script was succesful. That's why I am convinced my PiZigate is working.

Adminiuga commented 3 years ago

Did you modify boot config to enable the onboard serial port? IIRC by default Hass configures it for bluetooth.
Enable debug logging https://www.home-assistant.io/integrations/zha/ and post home-assistant.log when you are trying to configure the integration

Adminiuga commented 3 years ago

and the test script was succesful

What is the script? Check what the script is looking in the boot configuration file or get dev access to HASS console and run the script there

GuillaumeDen commented 3 years ago

First things first : thank you so much for your quick reply !

Did you modify boot config to enable the onboard serial port? IIRC by default Hass configures it for bluetooth.

I've just added these two lines in config.txt (on the hassos-boot partition)

dtoverlay=pi3-disable-bt
enable_uart=1

Since now I am able to add zha integration. So I am trying to pair a device (a simple aqara temperature sensor). But it's not showing... Here are the logs just after clicking "+" button bottom right in ZHA configuration screen

2020-12-01 21:49:15 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-01 21:49:15 ERROR (MainThread) [zigpy.application] Couldn't start application
2020-12-01 21:49:15 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry ttyAMA0, s/n: n/a for zha
Traceback (most recent call last):
File "/config/deps/lib/python3.8/site-packages/zigpy_zigate/api.py", line 133, in command
return await asyncio.wait_for(
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 236, in async_setup
result = await component.async_setup_entry(hass, self) # type: ignore
File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 100, in async_setup_entry
await zha_gateway.async_initialize()
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 147, in async_initialize
self.application_controller = await app_controller_cls.new(
File "/usr/local/lib/python3.8/site-packages/zigpy/application.py", line 68, in new
await app.startup(auto_form)
File "/config/deps/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 52, in startup
await self.form_network()
File "/config/deps/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 74, in form_network
network_formed, lqi = await self._api.start_network()
File "/config/deps/lib/python3.8/site-packages/zigpy_zigate/api.py", line 228, in start_network
return await self.command(0x0024, wait_response=0x8024)
File "/config/deps/lib/python3.8/site-packages/zigpy_zigate/api.py", line 142, in command
raise NoResponseError
zigpy_zigate.api.NoResponseError
2020-12-01 21:49:45 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [1843468608] Received invalid command: zha/devices/permit

Adminiuga commented 3 years ago

2020-12-01 21:49:15 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-01 21:49:15 ERROR (MainThread) [zigpy.application] Couldn't start application
2020-12-01 21:49:15 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry ttyAMA0, s/n: n/a for zha
Traceback (most recent call last):
File "/config/deps/lib/python3.8/site-packages/zigpy_zigate/api.py", line 133, in command
return await asyncio.wait_for(
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

It did not start. Make sure nothing else try to access that port, then fully reboot the host. Does the blue led shines on full brightness or half brighness?

Bredin76 commented 3 years ago

I have pretty same issue here

I'm running hass.io 0118.4 ( so HA supervised on docker) my PiZigate is fully functionnable with ZIgate integration ( thx @doudz ) using /dev/ttyS0 path in config.yaml BUT unable to connect it with ZHA Pizigate has been updated through ZIGATE to 3.1d

I tried to remove Zigate integration - reboot before installing ZHA one - Nothing Tried to use pizigate:/dev/ttyAMA0 or /dev/ttyS0 in serial device path popup => Nothing

I'm stick in using Zigate integration

GuillaumeDen commented 3 years ago

It did not start. Make sure nothing else try to access that port, then fully reboot the host. Does the blue led shines on full brightness or half brighness?

Ok so I just made a full fresh install following these steps :

Flashed my sd card with HassOs (32bit)
Edited config.txt on hassos-boot partition, to add the 2 lines needed ("dtoverlay=pi3-disable-bt" and "enable_uart=1")
Plugged ethernet cable
Booted my Raspberry pi (with PiZigate plugged on top)
Waited for install (as expected +-20min)
Configured Name/Password/Location
Added ZHA integration (with default settings) and succes message appeared => pizigate is blue onfull brightness, but same errors in logs

2020-12-01 22:56:07 WARNING (MainThread) [zigpy_znp.zigbee.application] Failed to probe ZNP radio with config {'path': '/dev/ttyAMA0', 'flow_control': None, 'baudrate': 115200}
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 142, in probe
await znp.connect()
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/api.py", line 236, in connect
version = await self.request(c.SYS.Version.Req())
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/api.py", line 520, in request
response = await response_future
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 142, in probe
await znp.connect()
File "/usr/local/lib/python3.8/site-packages/async_timeout/__init__.py", line 55, in __aexit__
self._do_exit(exc_type)
File "/usr/local/lib/python3.8/site-packages/async_timeout/__init__.py", line 92, in _do_exit
raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
2020-12-01 22:56:12 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.device_state' command with seq id '0x02'
2020-12-01 22:56:18 WARNING (MainThread) [zigpy_zigate.zigbee.application] Old ZiGate firmware detected, you should upgrade to 3.1d or newer
2020-12-01 22:56:19 WARNING (MainThread) [zigpy_cc.api] No response for: SRSP SYS version {}
2020-12-01 22:56:20 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-01 22:56:20 WARNING (MainThread) [zigpy_zigate.api] Retry command 0x0024
2020-12-01 22:56:20 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()
Traceback (most recent call last):
File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
self._protocol.data_received(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 76, in data_received
self._api.data_received(cmd, f_data, lqi)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 117, in data_received
data, rest = t.deserialize(data, RESPONSES[cmd])
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 8, in deserialize
value, data = type_.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 124, in deserialize
r, data = super().deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 480, in deserialize
item, data = cls._item_type.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 53, in deserialize
raise ValueError(f"Data is too short to contain {cls._size} bytes")
ValueError: Data is too short to contain 1 bytes
2020-12-01 22:56:20 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()
Traceback (most recent call last):
File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
self._protocol.data_received(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 76, in data_received
self._api.data_received(cmd, f_data, lqi)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 117, in data_received
data, rest = t.deserialize(data, RESPONSES[cmd])
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 8, in deserialize
value, data = type_.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 124, in deserialize
r, data = super().deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 480, in deserialize
item, data = cls._item_type.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 53, in deserialize
raise ValueError(f"Data is too short to contain {cls._size} bytes")
ValueError: Data is too short to contain 1 bytes
2020-12-01 22:56:21 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-01 22:56:21 ERROR (MainThread) [zigpy.application] Couldn't start application
2020-12-01 22:56:21 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry ttyAMA0, s/n: n/a for zha
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 133, in command
return await asyncio.wait_for(
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 236, in async_setup
result = await component.async_setup_entry(hass, self) # type: ignore
File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 100, in async_setup_entry
await zha_gateway.async_initialize()
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 147, in async_initialize
self.application_controller = await app_controller_cls.new(
File "/usr/local/lib/python3.8/site-packages/zigpy/application.py", line 68, in new
await app.startup(auto_form)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 52, in startup
await self.form_network()
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 74, in form_network
network_formed, lqi = await self._api.start_network()
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 228, in start_network
return await self.command(0x0024, wait_response=0x8024)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 142, in command
raise NoResponseError
zigpy_zigate.api.NoResponseError

t0mg commented 3 years ago

I have a similar issue, also with pizigate on a Pi 3 with HassOS. I'm using pizigate:/dev/ttyS0 in the setup as specified in the doc. Firmware was flashed to 3.1d. It was previously working fine with the now deprecated homeassistant-zigate. I uninstalled it and power cycled the Pi prior to adding ZHA.

2020-12-02 00:51:56 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-02 00:51:56 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-02 00:51:57 DEBUG (MainThread) [zigpy_zigate.api] Unsuccessful radio probe of 'pizigate:/dev/ttyS0' port
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/serial/serialposix.py", line 323, in _reconfigure_port
    orig_attr = termios.tcgetattr(self.fd)
termios.error: (5, 'I/O error')
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 258, in probe
    await asyncio.wait_for(api._probe(), timeout=PROBE_TIMEOUT)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 491, in wait_for
    return fut.result()
  File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 283, in _probe
    await self.connect()
  File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 101, in connect
    self._uart = await zigpy_zigate.uart.connect(self._config, self)
  File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 153, in connect
    _, protocol = await serial_asyncio.create_serial_connection(
  File "/usr/local/lib/python3.8/asyncio/coroutines.py", line 124, in coro
    res = func(*args, **kw)
  File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 410, in create_serial_connection
    ser = serial.serial_for_url(*args, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/serial/__init__.py", line 88, in serial_for_url
    instance.open()
  File "/usr/local/lib/python3.8/site-packages/serial/serialposix.py", line 272, in open
    self._reconfigure_port(force_update=True)
  File "/usr/local/lib/python3.8/site-packages/serial/serialposix.py", line 326, in _reconfigure_port
    raise SerialException("Could not configure port: {}".format(msg))
serial.serialutil.SerialException: Could not configure port: (5, 'I/O error')

Adminiuga commented 3 years ago

@GuillaumeDen please enable debug for

zigpy_zigate: debug
zigpy_zigate.uart: debug
zigpy_zigate.api: debug
zigpy_zigate.zigbee.application: debug

and post the log when it tries to start. What firmare version are you running?

@t0mg

 File "/usr/local/lib/python3.8/site-packages/serial/serialposix.py", line 326, in _reconfigure_port
    raise SerialException("Could not configure port: {}".format(msg))
serial.serialutil.SerialException: Could not configure port: (5, 'I/O error')

/dev/ttyS0 doesn't look like the correct port. What port the supervisor hardware tab reports?

Adminiuga commented 3 years ago

I can reproduce with freshly updated HA 0.118.4 with HassOS 4.17 on RPiB3+

2020-12-01 19:47:36 DEBUG (MainThread) [bellows.ezsp] Unsuccessful radio probe of '/dev/ttyAMA0' port
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/bellows/ezsp/__init__.py", line 54, in probe
    await asyncio.wait_for(ezsp._probe(), timeout=PROBE_TIMEOUT)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2020-12-01 19:47:36 DEBUG (MainThread) [zigpy_deconz.uart] Connection made
2020-12-01 19:47:36 DEBUG (MainThread) [zigpy_deconz.api] Command Command.device_state (0, 0, 0)
2020-12-01 19:47:36 DEBUG (MainThread) [zigpy_deconz.uart] Send: 0x0702000800000000
2020-12-01 19:47:38 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.device_state' command with seq id '0x02'
2020-12-01 19:47:38 DEBUG (MainThread) [zigpy_deconz.api] Unsuccessful radio probe of '/dev/ttyAMA0' port
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/zigpy_deconz/api.py", line 380, in probe
    await asyncio.wait_for(api._probe(), timeout=PROBE_TIMEOUT)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 491, in wait_for
    return fut.result()
  File "/usr/local/lib/python3.8/site-packages/zigpy_deconz/api.py", line 396, in _probe
    await self.device_state()
  File "/usr/local/lib/python3.8/site-packages/zigpy_deconz/api.py", line 305, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2020-12-01 19:47:38 DEBUG (MainThread) [zigpy_deconz.uart] Closed serial connection
2020-12-01 19:47:40 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-01 19:47:40 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-01 19:47:41 DEBUG (MainThread) [zigpy_zigate.uart] Connection made
2020-12-01 19:47:41 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0002 b'01'
2020-12-01 19:47:41 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x02\x00\x01\x02\x01'
2020-12-01 19:47:41 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x12\x02\x10\x02\x11\x02\x12\x02\x11'
2020-12-01 19:47:41 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078500000002000000
2020-12-01 19:47:41 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000020000' LQI:0
2020-12-01 19:47:43 DEBUG (MainThread) [zigpy.appdb] Loading application state from %s
2020-12-01 19:47:43 DEBUG (MainThread) [zigpy.ota.provider] OTA image directory '/home/lex/.homeassistant/zigpy_ota' does not exist
2020-12-01 19:47:43 INFO (MainThread) [zigpy.ota.provider] Trådfri: OTA provider enabled
2020-12-01 19:47:43 INFO (MainThread) [zigpy.ota.provider] Ledvance: OTA provider enabled
2020-12-01 19:47:44 DEBUG (MainThread) [zigpy.ota.provider] Ledvance: Finished downloading firmware update list
2020-12-01 19:47:45 WARNING (MainThread) [zigpy_cc.api] No response for: SRSP SYS version {}
2020-12-01 19:47:45 DEBUG (MainThread) [zigpy.ota.provider] Trådfri: Finished downloading firmware update list
2020-12-01 19:47:45 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-01 19:47:45 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Connection made
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0002 b'01'
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x02\x00\x01\x02\x01'
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x12\x02\x10\x02\x11\x02\x12\x02\x11'
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078500000002000000
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000020000' LQI:0
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 2, b'\x00\x00']
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0016 b'27595a62'
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b"\x00\x16\x00\x04T'YZb"
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b"\x02\x10\x16\x02\x10\x02\x14T'YZb"
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0010 b''
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x10\x00\x00\x10'
2020-12-01 19:47:46 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x10\x02\x10\x02\x10\x10'

Through automatic detection with correctly selected serial port. Will update to Zigate 3.1d tomorrow and will try again.

@GuillaumeDen post debug log. Update zigate firmware to 3.1d and try with it.

t0mg commented 3 years ago

@Adminiuga

/dev/ttyS0 doesn't look like the correct port. What port the supervisor hardware tab reports?

It reports this one as well as /dev/ttyAMA0 (and the ones from other USB devices). Neither work.

Adminiuga commented 3 years ago

@t0mg

did you change configuration to enable the serial port
debug logs for /dev/ttyAMA0

t0mg commented 3 years ago

@Adminiuga

Yes, enabled uart and disabled bluetooth, and it was working with the custom integration
It looked like yours above. I just retried with ttyAMA0 to get new ones and... It just worked this time 🤔 I'll try to provide more logs tomorrow.

Adminiuga commented 3 years ago

It looked like yours above

Well, mine above is the logs when it works as intended.

doudz commented 3 years ago

pizigate is working good on Rpi3 (I'm using it every days)

What you have to do is :

disable bluetooth according to doc (take care about the syntax dtoverlay=disable-bt != dtoverlay = disable-bt )
enable uart according to doc (not sure this is really needed)
Flash firmware 3.1d : :warning: not the pdmhost version !
Use path /dev/ttyAMA0

GuillaumeDen commented 3 years ago

@GuillaumeDen post debug log. Update zigate firmware to 3.1d and try with it.

pizigate is working good on Rpi3 (I'm using it every days)

What you have to do is :

disable bluetooth according to doc (take care about the syntax dtoverlay=disable-bt != dtoverlay = disable-bt )

enable uart according to doc (not sure this is really needed)

Flash firmware 3.1d : ⚠️ not the pdmhost version !

Use path /dev/ttyAMA0

I'll give it a try this week-end and I'll keep you updated. Thank you so much for being so fast to answer !

Adminiuga commented 3 years ago

I have just tested it with Firmware 3.1c and it still was detected fine. So follow the Sébastien's suggestions and post new logs if it still fails.

GuillaumeDen commented 3 years ago

Hello again !

So, I finally succeded to update my PiZigate, which is now running on 3.1d. To be 100% sure, I flashed another sd card. I added the 2 lines in boot/config.txt needed for RPI3 compatibilty. I waited the first install and did basic configuration wizard. I then enabled log debugging (using file editor add-on) as asked by @Adminiuga and restarted the server.

At this step : no errors in stack trace

So I added ZHA integration, specifying /dev/ttyAMA0 and zigate radio protocol. The integartion is added succesfully, and here come the errors (same as before 3.1d update) :

2020-12-07 21:13:32 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 17.49s
2020-12-07 21:13:32 INFO (MainThread) [homeassistant.core] Starting Home Assistant
2020-12-07 21:13:32 INFO (MainThread) [homeassistant.core] Timer:starting
2020-12-07 21:13:32 INFO (SyncWorker_5) [homeassistant.components.zeroconf] Starting Zeroconf broadcast
2020-12-07 21:14:28 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-07 21:14:28 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-07 21:14:29 DEBUG (MainThread) [zigpy_zigate.uart] Connection made
2020-12-07 21:14:29 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0002 b'01'
2020-12-07 21:14:29 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x02\x00\x01\x02\x01'
2020-12-07 21:14:29 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x12\x02\x10\x02\x11\x02\x12\x02\x11'
2020-12-07 21:14:29 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078500000002000000
2020-12-07 21:14:29 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000020000' LQI:0
2020-12-07 21:14:30 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-07 21:14:30 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Connection made
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0002 b'01'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x02\x00\x01\x02\x01'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x12\x02\x10\x02\x11\x02\x12\x02\x11'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078500000002000000
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000020000' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 2, b'\x00\x00']
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0016 b'276157b7'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b"\x00\x16\x00\x04\xb4'aW\xb7"
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b"\x02\x10\x16\x02\x10\x02\x14\xb4'aW\xb7"
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0010 b''
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x10\x00\x00\x10'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x10\x02\x10\x02\x10\x10'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000079100000016000000
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000160000' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 22, b'\x00\x00']
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000079700000010000000
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000100000' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 16, b'\x00\x00']
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80100005880003031d00
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8010 b'0003031d' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [3, 797]
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0009 b''
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\t\x00\x00\t'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x19\x02\x10\x02\x10\x02\x19'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078e00000009000000
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000090000' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 9, b'\x00\x00']
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80090016b2ffff00158d00021e2b9133639c1254b43dadea5c0b00
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8009 b'ffff00158d00021e2b9133639c1254b43dadea5c0b' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0xffff, 00:15:8d:00:02:1e:2b:91, 13155, 11246144352603204188, 11]
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0021 b'0718c800'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00!\x00\x04\xf2\x07\x18\xc8\x00'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10!\x02\x10\x02\x14\xf2\x02\x17\x18\xc8\x02\x10'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80000007a600000021000000
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000210000' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 33, b'\x00\x00']
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0024 b''
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00$\x00\x00$'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10$\x02\x10\x02\x10$'
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80000007a300000024000000
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000240000' LQI:0
2020-12-07 21:14:31 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 36, b'\x00\x00']
2020-12-07 21:14:33 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-07 21:14:33 WARNING (MainThread) [zigpy_zigate.api] Retry command 0x0024
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0024 b''
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00$\x00\x00$'
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10$\x02\x10\x02\x10$'
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80240002a00600
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8024 b'06' LQI:0
2020-12-07 21:14:33 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()
Traceback (most recent call last):
File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
self._protocol.data_received(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 76, in data_received
self._api.data_received(cmd, f_data, lqi)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 117, in data_received
data, rest = t.deserialize(data, RESPONSES[cmd])
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 8, in deserialize
value, data = type_.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 124, in deserialize
r, data = super().deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 480, in deserialize
item, data = cls._item_type.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 53, in deserialize
raise ValueError(f"Data is too short to contain {cls._size} bytes")
ValueError: Data is too short to contain 1 bytes
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80240002a00600
2020-12-07 21:14:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8024 b'06' LQI:0
2020-12-07 21:14:33 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()
Traceback (most recent call last):
File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
self._protocol.data_received(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 76, in data_received
self._api.data_received(cmd, f_data, lqi)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 117, in data_received
data, rest = t.deserialize(data, RESPONSES[cmd])
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 8, in deserialize
value, data = type_.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 124, in deserialize
r, data = super().deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 480, in deserialize
item, data = cls._item_type.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 53, in deserialize
raise ValueError(f"Data is too short to contain {cls._size} bytes")
ValueError: Data is too short to contain 1 bytes
2020-12-07 21:14:34 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-07 21:14:34 ERROR (MainThread) [zigpy.application] Couldn't start application
2020-12-07 21:14:34 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry pizigate:/dev/ttyAMA0 for zha
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 133, in command
return await asyncio.wait_for(
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 236, in async_setup
result = await component.async_setup_entry(hass, self) # type: ignore
File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 100, in async_setup_entry
await zha_gateway.async_initialize()
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 147, in async_initialize
self.application_controller = await app_controller_cls.new(
File "/usr/local/lib/python3.8/site-packages/zigpy/application.py", line 68, in new
await app.startup(auto_form)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 52, in startup
await self.form_network()
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 74, in form_network
network_formed, lqi = await self._api.start_network()
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 228, in start_network
return await self.command(0x0024, wait_response=0x8024)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 142, in command
raise NoResponseError
zigpy_zigate.api.NoResponseError
2020-12-07 21:16:22 WARNING (MainThread) [zigpy_znp.zigbee.application] Failed to probe ZNP radio with config {'path': '/dev/ttyAMA0', 'flow_control': None, 'baudrate': 115200}
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 142, in probe
await znp.connect()
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/api.py", line 236, in connect
version = await self.request(c.SYS.Version.Req())
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/api.py", line 520, in request
response = await response_future
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_znp/zigbee/application.py", line 142, in probe
await znp.connect()
File "/usr/local/lib/python3.8/site-packages/async_timeout/__init__.py", line 55, in __aexit__
self._do_exit(exc_type)
File "/usr/local/lib/python3.8/site-packages/async_timeout/__init__.py", line 92, in _do_exit
raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
2020-12-07 21:16:27 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.device_state' command with seq id '0x02'
2020-12-07 21:16:29 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-07 21:16:29 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.uart] Connection made
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0002 b'01'
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x02\x00\x01\x02\x01'
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x12\x02\x10\x02\x11\x02\x12\x02\x11'
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078500000002000000
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000020000' LQI:0
2020-12-07 21:16:31 DEBUG (MainThread) [zigpy_zigate.uart] PiZiGate detected
2020-12-07 21:16:31 INFO (MainThread) [zigpy_zigate.common] Put PiZiGate in running mode
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Connection made
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0002 b'01'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x02\x00\x01\x02\x01'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x12\x02\x10\x02\x11\x02\x12\x02\x11'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078500000002000000
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000020000' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 2, b'\x00\x00']
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0016 b'27615831'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b"\x00\x16\x00\x04='aX1"
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b"\x02\x10\x16\x02\x10\x02\x14='aX1"
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0010 b''
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\x10\x00\x00\x10'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x10\x02\x10\x02\x10\x10'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000079100000016000000
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000160000' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 22, b'\x00\x00']
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000079700000010000000
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000100000' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 16, b'\x00\x00']
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80100005880003031d00
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8010 b'0003031d' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [3, 797]
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0009 b''
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00\t\x00\x00\t'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10\x02\x19\x02\x10\x02\x10\x02\x19'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 800000078e00000009000000
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000090000' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 9, b'\x00\x00']
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80090016e2ffff00158d00021e2b919a9a9c1254b43dadea5c0b00
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8009 b'ffff00158d00021e2b919a9a9c1254b43dadea5c0b' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0xffff, 00:15:8d:00:02:1e:2b:91, 39578, 11246144352603204188, 11]
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0021 b'0718c800'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00!\x00\x04\xf2\x07\x18\xc8\x00'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10!\x02\x10\x02\x14\xf2\x02\x17\x18\xc8\x02\x10'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80000007a600000021000000
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000210000' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 33, b'\x00\x00']
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0024 b''
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00$\x00\x00$'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10$\x02\x10\x02\x10$'
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80000007a300000024000000
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8000 b'000000240000' LQI:0
2020-12-07 21:16:33 DEBUG (MainThread) [zigpy_zigate.zigbee.application] zigate_callback_handler [0, 0, 36, b'\x00\x00']
2020-12-07 21:16:34 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-07 21:16:34 WARNING (MainThread) [zigpy_zigate.api] Retry command 0x0024
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.uart] Send: 0x0024 b''
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.uart] Frame to send: b'\x00$\x00\x00$'
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.uart] Frame escaped: b'\x02\x10$\x02\x10\x02\x10$'
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80240002a00600
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8024 b'06' LQI:0
2020-12-07 21:16:34 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()
Traceback (most recent call last):
File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
self._protocol.data_received(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 76, in data_received
self._api.data_received(cmd, f_data, lqi)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 117, in data_received
data, rest = t.deserialize(data, RESPONSES[cmd])
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 8, in deserialize
value, data = type_.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 124, in deserialize
r, data = super().deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 480, in deserialize
item, data = cls._item_type.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 53, in deserialize
raise ValueError(f"Data is too short to contain {cls._size} bytes")
ValueError: Data is too short to contain 1 bytes
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.uart] Frame received: 80240002a00600
2020-12-07 21:16:34 DEBUG (MainThread) [zigpy_zigate.api] data received 0x8024 b'06' LQI:0
2020-12-07 21:16:34 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()
Traceback (most recent call last):
File "/usr/local/lib/python3.8/asyncio/events.py", line 81, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.8/site-packages/serial_asyncio/__init__.py", line 106, in _read_ready
self._protocol.data_received(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/uart.py", line 76, in data_received
self._api.data_received(cmd, f_data, lqi)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 117, in data_received
data, rest = t.deserialize(data, RESPONSES[cmd])
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 8, in deserialize
value, data = type_.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/types.py", line 124, in deserialize
r, data = super().deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 480, in deserialize
item, data = cls._item_type.deserialize(data)
File "/usr/local/lib/python3.8/site-packages/zigpy/types/basic.py", line 53, in deserialize
raise ValueError(f"Data is too short to contain {cls._size} bytes")
ValueError: Data is too short to contain 1 bytes
2020-12-07 21:16:34 WARNING (MainThread) [zigpy_cc.api] No response for: SRSP SYS version {}
2020-12-07 21:16:36 WARNING (MainThread) [zigpy_zigate.api] No response to command 0x0024
2020-12-07 21:16:36 ERROR (MainThread) [zigpy.application] Couldn't start application
2020-12-07 21:16:36 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry ttyAMA0, s/n: n/a for zha
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 133, in command
return await asyncio.wait_for(
File "/usr/local/lib/python3.8/asyncio/tasks.py", line 498, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 236, in async_setup
result = await component.async_setup_entry(hass, self) # type: ignore
File "/usr/src/homeassistant/homeassistant/components/zha/__init__.py", line 100, in async_setup_entry
await zha_gateway.async_initialize()
File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 147, in async_initialize
self.application_controller = await app_controller_cls.new(
File "/usr/local/lib/python3.8/site-packages/zigpy/application.py", line 68, in new
await app.startup(auto_form)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 52, in startup
await self.form_network()
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/zigbee/application.py", line 74, in form_network
network_formed, lqi = await self._api.start_network()
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 228, in start_network
return await self.command(0x0024, wait_response=0x8024)
File "/usr/local/lib/python3.8/site-packages/zigpy_zigate/api.py", line 142, in command
raise NoResponseError
zigpy_zigate.api.NoResponseError

doudz commented 3 years ago

we badly handle 0x8024 response in case of bad status but we can see that zigate fails to start network 0x8024 b'06' , status 0x06 I don't know what 0x06 means,but it should be 0 or 1

0 = Joined existing network 1 = Formed new network

I suggest erasing eeprom

GuillaumeDen commented 3 years ago

Any documentation or tutorial on how to do that ? Or could you give me some guidelines ?

doudz commented 3 years ago

You should be able to call the following command from shell python3 -m zigpy_zigate.tools.cli erase_persistent -p /dev/ttyAMA0

Adminiuga commented 3 years ago

was the last log after ZHA was configured and HA instance rebooted?

GuillaumeDen commented 3 years ago

You should be able to call the following command from shell python3 -m zigpy_zigate.tools.cli erase_persistent -p /dev/ttyAMA0

Ok, just did it (succes message : memory erased), tried to add ZHA integration, and same error data received 0x8024 b'06'

was the last log after ZHA was configured and HA instance rebooted?

It was after a reboot, and ZHA integration configuration (so the error happens while I add the integration)

doudz commented 3 years ago

Could you try to reset ? python3 -m zigpy_zigate.tools.cli reset -p /dev/ttyAMA0

doudz commented 3 years ago

I found what 0x06 means : Commissioning in progress https://github.com/fairecasoimeme/ZiGate/issues/225

So I have to fix support of message 0x8024, we just have to wait

Adminiuga commented 3 years ago

While commissioning, does the host need to do anything? If it just needs time for commissioning, then after a second reboot it should be ready?

GuillaumeDen commented 3 years ago

ALLELUIA !!

Resetting the PiZigate did the job, I successfully added the ZHA integration and added devices. Thank you so much for your quick replies, and I'll keep updated on this issue resolution.

Since this thread could be useful for someone else, I will update it's status to Solved 👍

t0mg commented 3 years ago

It looked like yours above

Well, mine above is the logs when it works as intended.

Indeed, sorry I misread your log. I meant up to the asyncio.exceptions.TimeoutError. But it works consistently now, I don't know what was going on. Thanks for the help!

home-assistant / core