search

zigpy / zigpy-znp

TI CC2531, CC13x2, CC26x2 radio support for Zigpy and ZHA
GNU General Public License v3.0
145 stars 40 forks source link

Connection to /dev/ttyUSBx failed when trying to restore config #118

Closed bvlaicu closed 2 years ago

bvlaicu commented 2 years ago

Hi. I'm trying to backup and restore my zigbee config between two identical HUSBZB-1 sticks. The backup went fine, but when I try to restore to the second stick, I get a connection error. I'm doing all this from the homeassistant docker container, while the ZHA integration is disabled. Here are some relevant logs. Any help is appreciated. Thanks in advance.

bash-5.1# ls -la /dev/serial/by-id/
total 0
drwxr-xr-x    2 root     root            80 Dec 20 15:51 .
drwxr-xr-x    4 root     root            80 Dec 20 15:51 ..
lrwxrwxrwx    1 root     root            13 Dec 20 15:51 usb-Silicon_Labs_HubZ_Smart_Home_Controller_C13023A6-if00-port0 -> ../../ttyUSB1
lrwxrwxrwx    1 root     root            13 Dec 20 15:51 usb-Silicon_Labs_HubZ_Smart_Home_Controller_C13023A6-if01-port0 -> ../../ttyUSB2

bash-5.1# bellows -d /dev/ttyUSB2 info
[00:0d:6f:00:15:45:22:d9]
[0x0000]
[<EmberNetworkStatus.JOINED_NETWORK: 2>]
[<EmberStatus.SUCCESS: 0>, <EmberNodeType.COORDINATOR: 1>, EmberNetworkParameters(extendedPanId=85:08:f9:f5:7a:2f:9e:4e, panId=0xae24, radioTxPower=8, radioChannel=15, joinMethod=<EmberJoinMethod.USE_MAC_ASSOCIATION: 0>, nwkManagerId=0x0000, nwkUpdateId=0, channels=<Channels.ALL_CHANNELS: 134215680>)]
[<EmberStatus.SUCCESS: 0>, EmberCurrentSecurityState(bitmask=<EmberCurrentSecurityBitmask.64|32|HAVE_TRUST_CENTER_LINK_KEY|GLOBAL_LINK_KEY: 116>, trustCenterLongAddress=00:0d:6f:00:15:45:22:d9)]
Manufacturer: HubZ ZigBee
Board name: HUSBZB-1
EmberZNet version: 5.4.1.0 build 962

bash-5.1# python -m zigpy_znp.tools.network_restore -vv /dev/ttyUSB2 -i /config/zigbee-backup.json
2021-12-20 16:00:49.865 homeassistant zigpy_znp.uart DEBUG Connecting to /dev/ttyUSB2 at 115200 baud
2021-12-20 16:00:49.872 homeassistant zigpy_znp.uart DEBUG Opened /dev/ttyUSB2 serial port
2021-12-20 16:00:49.873 homeassistant zigpy_znp.uart DEBUG Connected to /dev/ttyUSB2 at 115200 baud
2021-12-20 16:00:49.874 homeassistant zigpy_znp.api TRACE Creating callback CallbackResponseListener(matching_commands=(<zigpy_znp.utils.CatchAllResponse object at 0x7fbe41b945b0>,), callback=<bound method Queue.put_nowait of <Queue at 0x7fbe41b45190 maxsize=0>>)
2021-12-20 16:00:49.875 homeassistant zigpy_znp.api DEBUG Toggling RTS/DTR pins to skip bootloader or reset chip
2021-12-20 16:00:49.875 homeassistant zigpy_znp.uart DEBUG Setting serial pin states: DTR=False, RTS=False
2021-12-20 16:00:50.028 homeassistant zigpy_znp.uart DEBUG Setting serial pin states: DTR=False, RTS=True
2021-12-20 16:00:50.179 homeassistant zigpy_znp.uart DEBUG Setting serial pin states: DTR=False, RTS=False
2021-12-20 16:00:50.331 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:50.333 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:50.334 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:50.832 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:50.834 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:50.835 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:50.836 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:50.836 homeassistant zigpy_znp.api DEBUG Sending CC253x bootloader skip bytes
2021-12-20 16:00:50.838 homeassistant zigpy_znp.uart TRACE Sending data: b'\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF\xEF'
2021-12-20 16:00:53.340 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:53.341 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:53.342 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:54.341 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:54.342 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:54.342 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:54.343 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:54.344 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:54.344 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:54.345 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:55.344 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:55.345 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:55.346 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:55.347 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:55.347 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:55.348 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:55.348 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:56.348 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:56.349 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:56.349 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:56.349 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:56.350 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:56.350 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:56.350 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:57.351 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:57.351 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:57.352 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:57.352 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:57.352 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:57.353 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:57.353 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:58.354 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:58.354 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:58.355 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:58.356 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:58.357 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:58.358 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:58.359 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:59.358 homeassistant zigpy_znp.api TRACE Removing listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
2021-12-20 16:00:59.359 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
2021-12-20 16:00:59.359 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SRSP)
2021-12-20 16:00:59.359 homeassistant zigpy_znp.api TRACE There are 1 callbacks and 0 one-shot listeners remaining
2021-12-20 16:00:59.360 homeassistant zigpy_znp.api DEBUG Sending request: SYS.Ping.Req()
2021-12-20 16:00:59.361 homeassistant zigpy_znp.api TRACE Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Ping.Rsp(Capabilities=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x01, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
2021-12-20 16:00:59.361 homeassistant zigpy_znp.uart TRACE Sending data: b'\xFE\x00\x21\x01\x20'
2021-12-20 16:00:59.876 homeassistant zigpy_znp.api TRACE Removing listener CallbackResponseListener(matching_commands=(<zigpy_znp.utils.CatchAllResponse object at 0x7fbe41b945b0>,), callback=<bound method Queue.put_nowait of <Queue at 0x7fbe41b45190 maxsize=0>>)
2021-12-20 16:00:59.877 homeassistant zigpy_znp.api TRACE Cleaning up empty listener list for header <object object at 0x7fbe4255a770>
2021-12-20 16:00:59.877 homeassistant zigpy_znp.api TRACE There are 0 callbacks and 2 one-shot listeners remaining
2021-12-20 16:00:59.877 homeassistant zigpy_znp.api DEBUG Connection to /dev/ttyUSB2 failed, cleaning up
2021-12-20 16:00:59.878 homeassistant zigpy_znp.uart DEBUG Closing serial port
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/api.py", line 509, 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 "/usr/local/lib/python3.9/runpy.py", line 197, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/local/lib/python3.9/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/tools/network_restore.py", line 131, in <module>
    asyncio.run(main(sys.argv[1:]))  # pragma: no cover
  File "/usr/local/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/tools/network_restore.py", line 123, in main
    await restore_network(
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/tools/network_restore.py", line 98, in restore_network
    await app.startup(force_form=True)
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 175, in startup
    return await self._startup(
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/zigbee/application.py", line 188, in _startup
    await znp.connect()
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/api.py", line 551, in connect
    self.capabilities = (await self._skip_bootloader()).Capabilities
  File "/usr/local/lib/python3.9/site-packages/zigpy_znp/api.py", line 509, in _skip_bootloader
    result = await responses.get()
  File "/usr/local/lib/python3.9/site-packages/async_timeout/__init__.py", line 128, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.9/site-packages/async_timeout/__init__.py", line 203, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
puddly commented 2 years ago

zigpy-znp cannot communicate with HUSBZB-1 radios, it's only for Texas Instruments radios.

bellows is the library that deals with Silicon Labs chips (like the one used in your HUSBZB-1) and has its own backup and restore code:

$ bellows -d /dev/ttyUSB2 backup
$ bellows -d /dev/ttyUSB3 restore --help  # read this carefully