Unable to use zigpy-znp library with Z-Stack 3.0.x on CC2531 USB dongle

[lucasdietrich]

Hi,

I followed the zigpy-znp readme and I'm using a CC2531 based USB dongle with Z Stack 3.0.x coordinator firmware that I successfully flashed with TI SmartRF Flash Programmer. When I'm running the following script, I'm getting a TimeoutError exception.

• The dongle seems to not answers to the SYS_PING request sent by the library.

import asyncio

import logging

logging.basicConfig()
logging.root.setLevel(logging.DEBUG)


from zigpy_znp import config
from zigpy_znp.zigbee.application import ControllerApplication

APP_CONFIG = {
    config.CONF_DEVICE: {
        config.CONF_DEVICE_PATH: "COM6",
        config.CONF_DEVICE_BAUDRATE: 115200,
    },
}

async def main():
    app = ControllerApplication(APP_CONFIG)

    await app.startup(auto_form=True)

    await app.permit(60)
    await asyncio.sleep(60)

    await asyncio.get_running_loop().create_future()

if __name__ == "__main__":
    asyncio.run(main())

Python Console Log

DEBUG:asyncio:Using proactor: IocpProactor
DEBUG:zigpy_znp.uart:Connecting to COM6 at 115200 baud
DEBUG:zigpy_znp.uart:Opened COM6 serial port
DEBUG:zigpy_znp.uart:Toggling RTS/CTS to skip CC2652R bootloader
DEBUG:zigpy_znp.uart:Connected to COM6 at 115200 baud
DEBUG:zigpy_znp.api:Waiting 1s before sending anything
DEBUG:zigpy_znp.api:Sending bootloader skip byte
DEBUG:zigpy_znp.uart: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'
DEBUG:zigpy_znp.api:Waiting 1s or until a reset indication is received
DEBUG:zigpy_znp.api:Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.ResetInd.Callback(Reason=None, TransportRev=None, ProductId=None, MajorRel=None, MinorRel=None, MaintRel=None),), future=<Future pending>)
DEBUG:zigpy_znp.api:Removing listener OneShotResponseListener(matching_commands=(SYS.ResetInd.Callback(Reason=None, TransportRev=None, ProductId=None, MajorRel=None, MinorRel=None, MaintRel=None),), future=<Future cancelled>)
DEBUG:zigpy_znp.api:Cleaning up empty listener list for header CommandHeader(id=0x80, subsystem=Subsystem.SYS, type=CommandType.AREQ)
DEBUG:zigpy_znp.api:There are 0 callbacks and 0 one-shot listeners remaining
DEBUG:zigpy_znp.api:Testing connection to COM6
DEBUG:zigpy_znp.api:Sending request: SYS.Version.Req()
DEBUG:zigpy_znp.api:Creating one-shot listener OneShotResponseListener(matching_commands=(SYS.Version.Rsp(TransportRev=None, ProductId=None, MajorRel=None, MinorRel=None, MaintRel=None, CodeRevision=None, BootloaderBuildType=None, BootloaderRevision=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x02, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future pending>)
DEBUG:zigpy_znp.uart:Sending data: b'\xFE\x00\x21\x02\x23'
DEBUG:zigpy_znp.api:Removing listener OneShotResponseListener(matching_commands=(SYS.Version.Rsp(TransportRev=None, ProductId=None, MajorRel=None, MinorRel=None, MaintRel=None, CodeRevision=None, BootloaderBuildType=None, BootloaderRevision=None), RPCError.CommandNotRecognized.Rsp(ErrorCode=None, RequestHeader=CommandHeader(id=0x02, subsystem=Subsystem.SYS, type=CommandType.SREQ))), future=<Future cancelled>)
DEBUG:zigpy_znp.api:Cleaning up empty listener list for header CommandHeader(id=0x00, subsystem=Subsystem.RPCError, type=CommandType.SRSP)
DEBUG:zigpy_znp.api:Cleaning up empty listener list for header CommandHeader(id=0x02, subsystem=Subsystem.SYS, type=CommandType.SRSP)
DEBUG:zigpy_znp.api:There are 0 callbacks and 0 one-shot listeners remaining
DEBUG:zigpy_znp.api:Connection to COM6 failed, cleaning up
Traceback (most recent call last):
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\zigpy_znp\api.py", line 507, in request
    response = await response_future
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "<input>", line 1, in <module>
  File "C:\Program Files\JetBrains\PyCharm Community Edition 2020.3\plugins\python-ce\helpers\pydev\_pydev_bundle\pydev_umd.py", line 197, in runfile
    pydev_imports.execfile(filename, global_vars, local_vars)  # execute the script
  File "C:\Program Files\JetBrains\PyCharm Community Edition 2020.3\plugins\python-ce\helpers\pydev\_pydev_imps\_pydev_execfile.py", line 18, in execfile
    exec(compile(contents+"\n", file, 'exec'), glob, loc)
  File "C:/Users/ldietrich/Documents/zigbee.wiki/lucas/12_CC2531_Antenna/github_znp_issue.py", line 30, in <module>
    asyncio.run(main())
  File "C:\Python38\lib\asyncio\runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "C:\Python38\lib\asyncio\base_events.py", line 616, in run_until_complete
    return future.result()
  File "C:/Users/ldietrich/Documents/zigbee.wiki/lucas/12_CC2531_Antenna/github_znp_issue.py", line 22, in main
    await app.startup(auto_form=True)
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\zigpy_znp\zigbee\application.py", line 206, in startup
    return await self._startup(auto_form=auto_form)
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\zigpy_znp\zigbee\application.py", line 215, in _startup
    await znp.connect()
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\zigpy_znp\api.py", line 234, in connect
    self._version = await self.request(c.SYS.Version.Req())
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\zigpy_znp\api.py", line 507, in request
    response = await response_future
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\async_timeout\__init__.py", line 55, in __aexit__
    self._do_exit(exc_type)
  File "C:\Users\ldietrich\Documents\zigbee.wiki\lucas\12_CC2531_Antenna\venv\lib\site-packages\async_timeout\__init__.py", line 92, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError

I tried the following script to send the SYS_PING request over serial manually using the "Monitor and Test API" document, to be sure that the firmware works over the correct COM port.

import serial
from time import sleep
import threading

s = serial.Serial(port="COM6", baudrate=115200)

def listener():
    while True:
        r = s.read()

        if r:
            print(r, end="")

thread = threading.Thread(target=listener)
thread.start()

# TI Z Stack Monitor and Test API
# frames specifications on page 3
# SYS_PING request and response on page 6
cmd = b"\xFE\x00\x21\x01\x20" # START BYTE, LEN, CMD 1, CMD 2, [0 data bytes here], CHECKSUM

print("sending", cmd, "\nreponse ", end="")

s.write(cmd)

sleep(1.0)

thread.join()

s.close()

And I'm getting a response from the dongle.

sending b'\xfe\x00!\x01 ' 
reponse b'\xfe'b'\x02'b'a'b'\x01'b'y'b'\x07'b'\x1c'

I'm a beginner and I have some difficulties to identify the reasons. I expect a misconfiguration or the misuse of the python library in my script.

What are the things that I could have missed ? Or am I totally wrong with the use of the library in my script.

I also specify that I have the same problem with the zigpy-cc library but with the Z Stack 1.2 firmware, which could highlight my misunderstanding of library...

In addition, are there examples of use of this library (or more precise documentation) ?

Thank you

Lucas

PS: I'm not sure if my question is relevent in this category, I'm not completely comfortable with github yet...

[puddly]

Hi Lucas,

I have tested zigpy-znp on Windows only a handful of times but it has worked in the past and I still expect it to, since PySerial is cross-platform. The debug log shows the exact bytes sent/received by zigpy-znp over serial and it does look like your CC2531 does not respond to the SYS.Version.Req().

Functionally, the only difference between your two scripts is the use of asyncio on Windows, perhaps there is some bug? Your script works fine for me with a CC2531 running Z-Stack 3.0.2 on macOS.

Some suggestions:

• Try switching the event loop implementation back to the selector event loop? Python 3.8 switched to the proactor event loop.

  import asyncio
  # Immediately after: 
  asyncio.set_event_loop_policy(asyncio.WindowsSelectorEventLoopPolicy())

• Try this script under the Windows Subsystem for Linux with /dev/ttyS6 (COM6 maps to this).

[Adminiuga]

try downgrading pyserial to previsous version on windows

[puddly]

Also, the ControllerApplication class is mainly for use with the zigpy library. It's totally usable for external scripts but the lower-level ZNP class may be a better fit for your use case, as it's only a thin wrapper around the Z-Stack Management and Testing API and just lets you send/receive requests and subscribe to callbacks without doing anything else (you can look at the various ones in the tools/ subdirectory for examples of both).

For example, setting CONF_SKIP_BOOTLOADER to False and calling znp.connect(test_port=False) will not send a single byte over the UART until you call znp.request or znp.request_callback_rsp.

[lucasdietrich]

Hi puddly, with Python 3.8, I tried the following command that reads firmware version on :

• Windows (with the event loop policy set to SelectorEventLoopPolicy) python -m zigpy_znp.tools.flash_read COM6 -o:out.txt
• Ubuntu VM python -m zigpy_znp.tools.flash_read /dev/ttyACM0 -o:out.txt
• Windows Ubuntu Subsystem python -m zigpy_znp.tools.flash_read /dev/ttyS6-o:out.txt

In all the situations, the serial connection is successfully established, but I still have the TimeoutError.

Using pyserial library to send the SYS_VERSION command manually works fine in all these 3 situations (I get an answer from the USB dongle).

I searched a little more in the library and I noticed that it uses pyserial-asyncio library. I first thought it wasn't working on windows because this library seems to not work for Windows as written in the readme.md file on github. But I have the same TimeoutError problem also on UNIX OS.

Same TimeoutError with the following script using ZNP object and not whole ControllerApplication.

import asyncio
asyncio.set_event_loop_policy(asyncio.WindowsSelectorEventLoopPolicy())

import logging

logging.basicConfig()
logging.root.setLevel(logging.DEBUG)

from zigpy_znp.api import ZNP
from zigpy_znp import config

import zigpy_znp.commands as cmd

CFG = config.CONFIG_SCHEMA(
    {"znp_config": {"skip_bootloader": True}, "device": {"path": "COM6", "baudrate": 115200}}
)

znp = ZNP(CFG)

async def main():
    await znp.connect(test_port=False)

    await znp.request_callback_rsp(
        request=cmd.UBL.HandshakeReq.Req(),
        callback=cmd.UBL.HandshakeRsp.Callback(partial=True),
    )


if __name__ == "__main__":
    asyncio.run(main())

As Adminiuga suggested, I also tried other versions of pyserial-asyncio or zigpy-znp, same TimeoutError.

I will spend more time on monday, I'll keep you informed.

Thanks

[Adminiuga]

check if you can get zigbee2mqtt running with your adapter on an Ubuntu VM. Just to confirm the adapter is working.

[lucasdietrich]

It works well with zigbee2mqtt on Windows

[puddly]

It's not just you, I can confirm this bug on Windows 10. Same symptoms with a fresh installation of Python 3.9.1 after creating a virtualenv and installing just zigpy-znp from PyPI. Interestingly the bootloader skip bytes being sent don't cause the green LED to turn off (indicating that the bootloader is inactive), meaning that nothing is being sent by pyserial-asyncio.

You can fix this by downgrading pyserial-asyncio:

$ pip install zigpy-znp
$ python -m zigpy_znp.tools.energy_scan -vv COM4  # fails to receive a response to the Version req
$ pip install pyserial-asyncio==0.4
$ python -m zigpy_znp.tools.energy_scan -vv COM4  # works

[puddly]

For reference, this has been reported as pyserial/pyserial-asyncio#69 and was fixed by pyserial/pyserial-asyncio#70. There however hasn't been a 0.5.1 release yet of pyserial-asyncio.

[puddly]

As for your timeout issue on non-Windows platforms, this may be because you're configuring ZNP with "skip_bootloader": True but also sending serial bootloader commands. I don't recall if the default behavior of Z-Stack is to silently ignore them (causing your TimeoutError) or to cause a CommandNotRecognized exception but I suggest you modify your testing code to test using a different subsystem. This runs fine on Windows for me after downgrading pyserial-asyncio:

import asyncio
import logging

logging.basicConfig()
logging.root.setLevel(logging.DEBUG)

from zigpy_znp.api import ZNP
from zigpy_znp import config

import zigpy_znp.commands as cmd

znp = ZNP(config.CONFIG_SCHEMA({
    "znp_config": {
        "skip_bootloader": True
    },
    "device": {
        "path": "COM6",
        "baudrate": 115200
    }
}))

async def main():
    await znp.connect(test_port=False)

    version = await znp.request(cmd.SYS.Version.Req())

    print('Reported version is', version)


if __name__ == "__main__":
    asyncio.run(main())

The flash_* tools can only be used within 60s of plugging in the stick due to the bootloader auto timeout so make sure to only run it if the green LED is lit.

[lucasdietrich]

Hi,

You are right. Problem solved by downgrading pyserial-asyncio to version 0.4.

Thank you !

PS : I missclicked on button "close"