Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Connection failure to CC2530 after upgrade to 0.7.0 #132

Open
reef-actor opened this issue Feb 3, 2022 · 10 comments
Open

Connection failure to CC2530 after upgrade to 0.7.0 #132

reef-actor opened this issue Feb 3, 2022 · 10 comments

Comments

@reef-actor
Copy link

I have upgraded HomeAssistant from 2021.11.3 to 2022.2 and my ZHA integration is failing.
My hardware is CC2530 + CC2591, serial over TCP with tasmota. It has been reliable until the upgrade.

It appears to be blowing up during initialisation shortly after connection.
Seems to have similarities to #106

2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.uart] Connecting to socket://zigbeebridge:8888 at 115200 baud
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.uart] Opened socket://zigbeebridge:8888 serial port
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.uart] Connected to socket://zigbeebridge:8888 at 115200 baud
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.api] Toggling RTS/DTR pins to skip bootloader or reset chip
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=True
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2022-02-03 20:19:01 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:02 DEBUG (MainThread) [zigpy_znp.api] Sending CC253x bootloader skip bytes
2022-02-03 20:19:04 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:05 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:06 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:07 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:09 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:10 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-03 20:19:11 DEBUG (MainThread) [zigpy_znp.api] Connection to socket://zigbeebridge:8888 failed, cleaning up
2022-02-03 20:19:11 DEBUG (MainThread) [zigpy_znp.uart] Closing serial port
2022-02-03 20:19:11 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-02-03 20:19:11 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/home/home/hass_venv/lib/python3.9/site-packages/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/home/home/hass_venv/lib/python3.9/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/home/home/hass_venv/lib/python3.9/site-packages/homeassistant/util/async_.py", line 166, in protected_loop_func
    check_loop(func, strict=strict)
  File "/home/home/hass_venv/lib/python3.9/site-packages/homeassistant/util/async_.py", line 129, in check_loop
    raise RuntimeError(
RuntimeError: Detected blocking call inside the event loop. This is causing stability issues. Please report issue
2022-02-03 20:19:11 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start ZNP = Texas Instruments Z-Stack ZNP protocol: CC253x, CC26x2, CC13x2 coordinator
Traceback (most recent call last):
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/api.py", line 530, in _skip_bootloader
    result = await responses.get()
  File "/usr/local/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/home/hass_venv/lib/python3.9/site-packages/homeassistant/components/zha/core/gateway.py", line 152, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 152, in startup
    return await self._startup(
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 165, in _startup
    await znp.connect()
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/api.py", line 572, in connect
    self.capabilities = (await self._skip_bootloader()).Capabilities
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/api.py", line 530, in _skip_bootloader
    result = await responses.get()
  File "/home/home/hass_venv/lib/python3.9/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/home/home/hass_venv/lib/python3.9/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
2022-02-03 20:19:11 DEBUG (MainThread) [homeassistant.config_entries] Config entry 'socket://zigbeebridge:8888' for zha integration not ready yet; Retrying in 80 seconds
@puddly
Copy link
Collaborator

puddly commented Feb 3, 2022

Try cutting power to your coordinator for a few seconds and plugging it back in.

Does it start working again if you downgrade to 2021.11.3?

Serial over TCP doesn't have a way to toggle RTS and DTR pins so while the linked issue also mentioned a coordinator failing to start up, that problem was different.

@reef-actor
Copy link
Author

I downgraded and the behaviour persisted, but a power cycle brought it back. Hopefully the same will work for 2022.2. I don't remember upgrades being anything but seamless before, but I am glad to be back online.
Thanks for your help. I will close this when I have confirmed 2022.2 is working too.

@reef-actor
Copy link
Author

Back on 2022.2 and unfortunately pulling the power isn't allowing the connection to return. The log does contain something a little different though, is it failing to migrate data?

2022-02-04 09:31:51 DEBUG (MainThread) [zigpy_znp.uart] Connecting to socket://zigbeebridge:8888 at 115200 baud
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.uart] Opened socket://zigbeebridge:8888 serial port
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.uart] Connected to socket://zigbeebridge:8888 at 115200 baud
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Toggling RTS/DTR pins to skip bootloader or reset chip
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=True
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.Ping.Rsp(Capabilities=<MTCapabilities.APP|UTIL|SAPI|ZDO|AF|SYS: 377>)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Radio is alive: SYS.Ping.Rsp(Capabilities=<MTCapabilities.APP|UTIL|SAPI|ZDO|AF|SYS: 377>)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.nvram] Detecting struct alignment
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Sending request: UTIL.AssocFindDevice.Req(Index=0)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Received command: UTIL.AssocFindDevice.Rsp(Device=b'\x9E\x0A\x00\x00\x04\x0B\x00\xE6\x02\x01\xAA\x00\x00\x00\x00\x00\xDF\x00\x46\xE6\x05\xD5\x91\xDB\x00\x0E\xD3\xE6')
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.nvram] Detected struct alignment: False
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Detected Z-Stack 1.2
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Connected to socket://zigbeebridge:8888 at 115200 baud
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVLength.Req(Id=<OsalNvIds.ZIGPY_ZNP_MIGRATION_ID: 95>)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.OSALNVLength.Rsp(ItemLen=0)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVLength.Req(Id=<OsalNvIds.ADDRMGR: 35>)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.OSALNVLength.Rsp(ItemLen=209)
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVReadExt.Req(Id=<OsalNvIds.ADDRMGR: 35>, Offset=0)
2022-02-04 09:32:07 DEBUG (MainThread) [zigpy_znp.uart] Closing serial port
2022-02-04 09:32:07 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-02-04 09:32:07 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/home/home/hass_venv/lib/python3.9/site-packages/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/home/home/hass_venv/lib/python3.9/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/home/home/hass_venv/lib/python3.9/site-packages/homeassistant/util/async_.py", line 166, in protected_loop_func
    check_loop(func, strict=strict)
  File "/home/home/hass_venv/lib/python3.9/site-packages/homeassistant/util/async_.py", line 129, in check_loop
    raise RuntimeError(
RuntimeError: Detected blocking call inside the event loop. This is causing stability issues. Please report issue
2022-02-04 09:32:07 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start ZNP = Texas Instruments Z-Stack ZNP protocol: CC253x, CC26x2, CC13x2 coordinator
Traceback (most recent call last):
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/api.py", line 847, in request
    response = await response_future
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/home/hass_venv/lib/python3.9/site-packages/homeassistant/components/zha/core/gateway.py", line 152, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 152, in startup
    return await self._startup(
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 172, in _startup
    await self._migrate_nvram()
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 953, in _migrate_nvram
    entries = await security.read_addr_manager_entries(self._znp)
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/znp/security.py", line 167, in read_addr_manager_entries
    await znp.nvram.osal_read(
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/nvram.py", line 177, in osal_read
    read_rsp = await self.znp.request(
  File "/home/home/hass_venv/lib/python3.9/site-packages/zigpy_znp/api.py", line 847, in request
    response = await response_future
  File "/home/home/hass_venv/lib/python3.9/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/home/home/hass_venv/lib/python3.9/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
2022-02-04 09:32:07 DEBUG (MainThread) [homeassistant.config_entries] Config entry 'socket://zigbeebridge:8888' for zha integration not ready yet; Retrying in 80 seconds

@puddly
Copy link
Collaborator

puddly commented Feb 8, 2022

It connected this time and zigpy-znp is trying reading some entries from NVRAM. The problem is that your coordinator just stops responding:

# Reading the ADDRMGR NVRAM entry
2022-02-04 09:31:52 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVReadExt.Req(Id=<OsalNvIds.ADDRMGR: 35>, Offset=0)

# No response after 15 seconds, connection is assumed dead and closed
2022-02-04 09:32:07 DEBUG (MainThread) [zigpy_znp.uart] Closing serial port

Are you able to connect if you downgrade back to 2021.11.3?

@puddly
Copy link
Collaborator

puddly commented Feb 8, 2022 •
edited
Loading

The CC2530 has been notoriously finicky with serial connections when I last tried using it. Can you post your exact hardware and firmware configuration so that I can try replicating this setup myself?

@Adminiuga
Copy link
Contributor

And having a serial over TCP connection does not help.

@reef-actor
Copy link
Author

Are you able to connect if you downgrade back to 2021.11.3?

Back on 11.3 it is connected and stable again.

My hardware setup is CC2530 + CC2591 connected to sonoff basic via hardware serial (pins 1&3). Sonoff is running tasmota 9.2.0.3. I will find out what firmware the radio is running.
I have <10 connected devices.

@reef-actor
Copy link
Author

reef-actor commented Feb 9, 2022 •
edited
Loading

Firmware is build 20190608, should I go ahead and update to the latest Z-Stack_Home_3.x.0_20211217?

@puddly
Copy link
Collaborator

puddly commented Feb 9, 2022

Sure, give it a try. Make sure to make a network backup first and restore after, upgrading will erase your network settings.

@puddly
Copy link
Collaborator

puddly commented Feb 9, 2022

Your stick is only compatible with the Z-Stack Home 1.2 firmware, it won't work with anything 3.x.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Adminiuga @puddly @reef-actor