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

Slae.sh USB stick not working on v0.6.3 #106

Closed davidbb closed 2 years ago

davidbb commented 2 years ago

After updating HA OS to 2021.12.0b2, ZHA fails to start up. Downgrading to 2021.11.5 allows ZHA to start up again. Enabling debug logging shows the logs below for 2021.12.0b2:

2021-12-07 10:08:07 DEBUG (MainThread) [zigpy_znp.uart] Connecting to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 at 115200 baud
2021-12-07 10:08:07 DEBUG (MainThread) [zigpy_znp.uart] Opened /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 serial port
2021-12-07 10:08:07 DEBUG (MainThread) [zigpy_znp.uart] Connected to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 at 115200 baud
2021-12-07 10:08:07 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2021-12-07 10:08:10 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2021-12-07 10:08:10 DEBUG (MainThread) [zigpy_znp.api] Toggling RTS/DTR pins to skip bootloader or reset chip
2021-12-07 10:08:10 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2021-12-07 10:08:10 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=True
2021-12-07 10:08:11 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2021-12-07 10:08:11 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2021-12-07 10:08:12 DEBUG (MainThread) [zigpy_znp.api] Connection to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 failed, cleaning up
2021-12-07 10:08:12 DEBUG (MainThread) [zigpy_znp.uart] Closing serial port
2021-12-07 10:08:12 ERROR (MainThread) [zigpy.application] Couldn't start application

And these are the equivalent logs for 2021.11.5:

2021-12-07 10:18:35 DEBUG (MainThread) [zigpy_znp.uart] Connecting to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 at 115200 baud
2021-12-07 10:18:35 DEBUG (MainThread) [zigpy_znp.uart] Opened /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 serial port
2021-12-07 10:18:35 DEBUG (MainThread) [zigpy_znp.uart] Toggling RTS/CTS to skip CC2652R bootloader
2021-12-07 10:18:36 DEBUG (MainThread) [zigpy_znp.uart] Connected to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 at 115200 baud
2021-12-07 10:18:36 DEBUG (MainThread) [zigpy_znp.api] Waiting 1s before sending anything
2021-12-07 10:18:42 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.ResetInd.Callback(Reason=<ResetReason.PowerUp: 0>, TransportRev=2, ProductId=1, MajorRel=2, MinorRel=7, MaintRel=1)
2021-12-07 10:18:42 WARNING (MainThread) [zigpy_znp.api] Received an unhandled command: SYS.ResetInd.Callback(Reason=<ResetReason.PowerUp: 0>, TransportRev=2, ProductId=1, MajorRel=2, MinorRel=7, MaintRel=1)
2021-12-07 10:18:43 DEBUG (MainThread) [zigpy_znp.api] Sending bootloader skip byte
2021-12-07 10:18:43 DEBUG (MainThread) [zigpy_znp.api] Waiting 1s or until a reset indication is received
2021-12-07 10:18:44 DEBUG (MainThread) [zigpy_znp.api] Testing connection to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0
2021-12-07 10:18:44 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2021-12-07 10:18:44 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.Ping.Rsp(Capabilities=<MTCapabilities.APP_CNF|GP|UTIL|ZDO|AF|SYS: 1625>)
2021-12-07 10:18:44 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVLength.Req(Id=<OsalNvIds.NWKKEY: 130>)
2021-12-07 10:18:44 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.OSALNVLength.Rsp(ItemLen=24)

It appears connection to the slaesh USB stick is failing. This seems related to the new connection logic introduced in PR #104. Happy to provide more info if necessary.

puddly commented 2 years ago

Interesting, it takes seven seconds for the stick to reset.

Could you try out this branch? You can use either the beta or the last stable. Instructions for setting up zigpy-znp with the custom deps deployment addon are here: https://github.com/zigpy/zigpy-znp#testing-dev-with-home-assistant-os

apk: []
pypi:
  - git+https://github.com/puddly/zigpy-znp.git@puddly/fix-slaesh-bootloader
  - zigpy==0.42.0
davidbb commented 2 years ago

Much better! Logs below on 2021.12.0b2 using zigpy 0.42.0 from your repo:

2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.uart] Connecting to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 at 115200 baud
2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.uart] Opened /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 serial port
2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.uart] Connected to /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_21_CC_45_F5-if00-port0 at 115200 baud
2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.api] Toggling RTS/DTR pins to skip bootloader or reset chip
2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=True
2021-12-07 13:59:48 DEBUG (MainThread) [zigpy_znp.uart] Setting serial pin states: DTR=False, RTS=False
2021-12-07 13:59:49 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.ResetInd.Callback(Reason=<ResetReason.PowerUp: 0>, TransportRev=2, ProductId=1, MajorRel=2, MinorRel=7, MaintRel=1)
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Radio is alive: SYS.ResetInd.Callback(Reason=<ResetReason.PowerUp: 0>, TransportRev=2, ProductId=1, MajorRel=2, MinorRel=7, MaintRel=1)
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Giving ping task 0.50s to finish
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.Ping.Rsp(Capabilities=<MTCapabilities.APP_CNF|GP|UTIL|ZDO|AF|SYS: 1625>)
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVLength.Req(Id=<OsalNvIds.NWKKEY: 130>)
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.OSALNVLength.Rsp(ItemLen=24)
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.OSALNVReadExt.Req(Id=<OsalNvIds.NWKKEY: 130>, Offset=0)
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.OSALNVReadExt.Rsp(Status=<Status.SUCCESS: 0>, Value=b'\x00\xFA\x6F\x91\x99\x94\x14\x8F\xC3\xE0\x22\x2F\xF5\x16\x8A\xED\x61\xEC\x01\x00\xCA\x86\x69\x00')
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.nvram] Read NVRAM["LEGACY"][0x0082] = b'\x00\xFA\x6F\x91\x99\x94\x14\x8F\xC3\xE0\x22\x2F\xF5\x16\x8A\xED\x61\xEC\x01\x00\xCA\x86\x69\x00'
2021-12-07 13:59:51 DEBUG (MainThread) [zigpy_znp.nvram] Detected struct alignment: True

Seems to work OK thanks for the quick fix!