How to run microTVM on brd4180a (efr32)

microTVM
#1

I am trying out the example provided here: 1. microTVM CLI Tool — tvm 0.12.dev0 documentation and trying to run the example on the EFR32MG21A020F1024 board and I get the following error when I try to run the model on target: Error: Could not open a session with the micro target.

My environment:

Jlink: 11.0.17
tvmc: 0.12.dev0
Homebrew clang version 16.0.0
Target: arm64-apple-darwin22.4.0
Thread model: posix
InstalledDir: /opt/homebrew/opt/llvm/bin
Zephyr: v3.2-branch (last commit hash: 17238d2e0ed589471919e5bec57e38cbe3132a12)
VID:PID from lsusb: Bus 000 Device 003: ID 1366:0105 1366 J-Link Pro OB  Serial: 000440120555

To begin with, I added my board to boards.json as follows:

"efr32_radio_brd4180a": {
    "board": "efr32_radio_brd4180a",
    "model": "EFR32MG21A020F1024",
    "is_qemu": false,
    "fpu": true,
    "vid_hex": "1366",
    "pid_hex": "0105"
}

And then, basically followed the commands provided

wget https://github.com/tensorflow/tflite-micro/raw/a56087ffa2703b4d5632f024a8a4c899815c31bb/tensorflow/lite/micro/examples/micro_speech/micro_speech.tflite
tvmc compile micro_speech.tflite --target="c -keys=cpu -model=efr32_radio_brd4180a" --runtime=crt --runtime-crt-system-lib 1 --executor="aot" --output model.tar --output-format mlf --pass-config tir.disable_vectorize=1
tvmc micro create project model.tar zephyr --project-option project_type=host_driven board=efr32_radio_brd4180a
tvmc micro build project zephyr
tvmc micro flash project zephyr

No explicit errors here

tvmc run --device micro project --fill-mode ones --print-top 3

This command resulted in Error: Could not open a session with the micro target.. Given that it doesn’t provide enough debug info, I raised it through the pythonic interface

python3 -c 'import logging; import tvm.driver.tvmc.main; logging.getLogger().setLevel(logging.DEBUG); tvm.driver.tvmc.main.main()' run --device micro project --print-top 3 Here is the output:

DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "server_info_query", "params": {"tvm_version": "0.12.dev0"}, "id": 1}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 1, "result": {"platform_name": "zephyr", "is_template": false, "model_library_format_path": "/Users/workspace//project/model.tar", "project_options": [{"name": "verbose", "choices": null, "default": false, "type": "bool", "required": null, "optional": ["generate_project"], "help": "Run build with verbose output."}, {"name": "project_type", "choices": [], "default": null, "type": "str", "required": ["generate_project"], "optional": null, "help": "Type of project to generate."}, {"name": "board", "choices": ["b_u585i_iot02a", "mimxrt1050_evk", "mps2_an521", "mps3_an547", "nrf5340dk_nrf5340_cpuapp", "nucleo_f746zg", "nucleo_l4r5zi", "qemu_cortex_r5", "qemu_riscv32", "qemu_riscv64", "qemu_x86", "stm32f746g_disco", "efr32_radio_brd4180a", "efr32_radio_brd4187a"], "default": null, "type": "str", "required": ["generate_project"], "optional": null, "help": "Name of the board to build for."}, {"name": "cmsis_path", "choices": null, "default": null, "type": "str", "required": null, "optional": ["generate_project"], "help": "Path to the CMSIS directory."}, {"name": "warning_as_error", "choices": null, "default": false, "type": "bool", "required": null, "optional": ["generate_project"], "help": "Treat warnings as errors and raise an Exception."}, {"name": "compile_definitions", "choices": null, "default": null, "type": "str", "required": null, "optional": ["generate_project"], "help": "Extra definitions added project compile."}, {"name": "extra_files_tar", "choices": null, "default": null, "type": "str", "required": null, "optional": ["generate_project"], "help": "If given, during generate_project, uncompress the tarball at this path into the project dir."}, {"name": "gdbserver_port", "choices": null, "default": null, "type": "int", "required": null, "optional": ["open_transport"], "help": "If given, port number to use when running the local gdbserver."}, {"name": "serial_number", "choices": null, "default": null, "type": "str", "required": null, "optional": ["open_transport", "flash"], "help": "Board serial number."}, {"name": "west_cmd", "choices": null, "default": "/Users/user/.pyenv/versions/3.9.15/bin/python -m west", "type": "str", "required": null, "optional": ["generate_project", "build", "flash", "open_transport"], "help": "Path to the west tool. If given, supersedes both the zephyr_base option and ZEPHYR_BASE environment variable."}, {"name": "zephyr_base", "choices": null, "default": "/Users/user/toolchains/zephyrproject/zephyr", "type": "str", "required": null, "optional": ["generate_project", "open_transport"], "help": "Path to the zephyr base directory."}, {"name": "config_main_stack_size", "choices": null, "default": null, "type": "int", "required": null, "optional": ["generate_project"], "help": "Sets CONFIG_MAIN_STACK_SIZE for Zephyr board."}, {"name": "arm_fvp_path", "choices": null, "default": null, "type": "str", "required": null, "optional": ["generate_project", "open_transport"], "help": "Path to the FVP binary to invoke."}, {"name": "use_fvp", "choices": null, "default": false, "type": "bool", "required": null, "optional": ["generate_project"], "help": "Run on the FVP emulator instead of hardware."}, {"name": "workspace_size_bytes", "choices": null, "default": null, "type": "int", "required": null, "optional": ["generate_project"], "help": "Sets the value for TVM_WORKSPACE_SIZE_BYTES passed to K_HEAP_DEFINE() to service TVM memory allocation requests."}], "protocol_version": 1}}

DEBUG:tvm.micro.transport:micro-rpc: opening transport
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "open_transport", "params": {"options": {"verbose": false, "project_type": null, "board": null, "cmsis_path": null, "warning_as_error": false, "compile_definitions": null, "extra_files_tar": null, "gdbserver_port": null, "serial_number": null, "west_cmd": "/Users/user/.pyenv/versions/3.9.15/bin/python -m west", "zephyr_base": "/Users/user/toolchains/zephyrproject/zephyr", "config_main_stack_size": null, "arm_fvp_path": null, "use_fvp": false, "workspace_size_bytes": null}}, "id": 2}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 2, "result": {"timeouts": {"session_start_retry_timeout_sec": 2.0, "session_start_timeout_sec": 5.0, "session_established_timeout_sec": 5.0}}}

DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "{r", "timeout_sec": 5.0}, "id": 3}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 3, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  1 B]: fe                                               .
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "|NQ", "timeout_sec": 5.0}, "id": 4}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 4, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: ff fd                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0{{R3", "timeout_sec": 5.0}, "id": 5}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 5, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  4 B]: 03 00 00 00                                      ....
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0006", "timeout_sec": 5.0}, "id": 6}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 6, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  3 B]: 00 00 02                                         ...
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "W_J", "timeout_sec": 5.0}, "id": 7}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 7, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: 66 77                                            fw
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "|NQ", "timeout_sec": 5.0}, "id": 8}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 8, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: ff fd                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "1ONa4", "timeout_sec": 5.0}, "id": 9}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 9, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  4 B]: 04 00 00 00                                      ....
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "1^@s", "timeout_sec": 5.0}, "id": 10}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 10, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  3 B]: 06 00 00                                         ...
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0R", "timeout_sec": 5.0}, "id": 11}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 11, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  1 B]: 01                                               .
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "vi<", "timeout_sec": 5.0}, "id": 12}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 12, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: b2 fe                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "read_transport", "params": {"n": 1, "timeout_sec": 1.998125}, "id": 13}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 13, "error": {"code": -32000, "message": "IoTimeoutError", "data": {"traceback": "Traceback (most recent call last):\n  File \"/Users/workspace//project/server.py\", line 486, in serve_one_request  # <--- Outermost server-side stack frame\n    self._dispatch_request(request)\n  File \"/Users/workspace//project/server.py\", line 598, in _dispatch_request\n    return_value = dispatch_method(**params)\n  File \"/Users/workspace//project/server.py\", line 647, in _dispatch_read_transport\n    reply_data = self._handler.read_transport(n, timeout_sec)\n  File \"/Users/workspace//project/microtvm_api_server.py\", line 855, in read_transport\n    return self._transport.read(n, timeout_sec)\n  File \"/Users/workspace//project/microtvm_api_server.py\", line 984, in read\n    raise server.IoTimeoutError()\nserver.IoTimeoutError: JSON-RPC error # -32000: IoTimeoutError\n"}}}

DEBUG:tvm.micro.transport:micro-rpc: read { 2.00s}    1 B -> [IoTimeoutError  2.00s]
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "|NQ", "timeout_sec": 5.0}, "id": 14}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 14, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: ff fd                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0{{R3", "timeout_sec": 5.0}, "id": 15}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 15, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  4 B]: 03 00 00 00                                      ....
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0006", "timeout_sec": 5.0}, "id": 16}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 16, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  3 B]: 00 00 02                                         ...
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "W_J", "timeout_sec": 5.0}, "id": 17}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 17, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: 66 77                                            fw
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "|NQ", "timeout_sec": 5.0}, "id": 18}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 18, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: ff fd                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "1ONa4", "timeout_sec": 5.0}, "id": 19}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 19, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  4 B]: 04 00 00 00                                      ....
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "ga7~", "timeout_sec": 5.0}, "id": 20}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 20, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  3 B]: 84 00 00                                         ...
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0R", "timeout_sec": 5.0}, "id": 21}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 21, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  1 B]: 01                                               .
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": ";?4", "timeout_sec": 5.0}, "id": 22}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 22, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: e2 ce                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "read_transport", "params": {"n": 1, "timeout_sec": 1.979362}, "id": 23}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 23, "error": {"code": -32000, "message": "IoTimeoutError", "data": {"traceback": "Traceback (most recent call last):\n  File \"/Users/workspace//project/server.py\", line 486, in serve_one_request  # <--- Outermost server-side stack frame\n    self._dispatch_request(request)\n  File \"/Users/workspace//project/server.py\", line 598, in _dispatch_request\n    return_value = dispatch_method(**params)\n  File \"/Users/workspace//project/server.py\", line 647, in _dispatch_read_transport\n    reply_data = self._handler.read_transport(n, timeout_sec)\n  File \"/Users/workspace//project/microtvm_api_server.py\", line 855, in read_transport\n    return self._transport.read(n, timeout_sec)\n  File \"/Users/workspace//project/microtvm_api_server.py\", line 984, in read\n    raise server.IoTimeoutError()\nserver.IoTimeoutError: JSON-RPC error # -32000: IoTimeoutError\n"}}}

DEBUG:tvm.micro.transport:micro-rpc: read { 1.98s}    1 B -> [IoTimeoutError  1.98s]
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "|NQ", "timeout_sec": 5.0}, "id": 24}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 24, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: ff fd                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0{{R3", "timeout_sec": 5.0}, "id": 25}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 25, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  4 B]: 03 00 00 00                                      ....
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0006", "timeout_sec": 5.0}, "id": 26}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 26, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  3 B]: 00 00 02                                         ...
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "W_J", "timeout_sec": 5.0}, "id": 27}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 27, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: 66 77                                            fw
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "|NQ", "timeout_sec": 5.0}, "id": 28}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 28, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: ff fd                                            ..
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "1ONa4", "timeout_sec": 5.0}, "id": 29}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 29, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  4 B]: 04 00 00 00                                      ....
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "#sB~", "timeout_sec": 5.0}, "id": 30}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 30, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  3 B]: c6 00 00                                         ...
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "0R", "timeout_sec": 5.0}, "id": 31}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 31, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  1 B]: 01                                               .
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "write_transport", "params": {"data": "7EJ", "timeout_sec": 5.0}, "id": 32}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 32, "result": null}

DEBUG:tvm.micro.transport:micro-rpc: write { 5.00s}        <- [  2 B]: 16 4d                                            .M
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "read_transport", "params": {"n": 1, "timeout_sec": 1.986024}, "id": 33}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 33, "error": {"code": -32000, "message": "IoTimeoutError", "data": {"traceback": "Traceback (most recent call last):\n  File \"/Users/workspace//project/server.py\", line 486, in serve_one_request  # <--- Outermost server-side stack frame\n    self._dispatch_request(request)\n  File \"/Users/workspace//project/server.py\", line 598, in _dispatch_request\n    return_value = dispatch_method(**params)\n  File \"/Users/workspace//project/server.py\", line 647, in _dispatch_read_transport\n    reply_data = self._handler.read_transport(n, timeout_sec)\n  File \"/Users/workspace//project/microtvm_api_server.py\", line 855, in read_transport\n    return self._transport.read(n, timeout_sec)\n  File \"/Users/workspace//project/microtvm_api_server.py\", line 984, in read\n    raise server.IoTimeoutError()\nserver.IoTimeoutError: JSON-RPC error # -32000: IoTimeoutError\n"}}}

DEBUG:tvm.micro.transport:micro-rpc: read { 1.99s}    1 B -> [IoTimeoutError  1.99s]
DEBUG:tvm.micro.transport:micro-rpc: closing transport
DEBUG:tvm.micro.project_api.client:send -> {"jsonrpc": "2.0", "method": "close_transport", "params": {}, "id": 34}
DEBUG:tvm.micro.project_api.client:recv <- {"jsonrpc": "2.0", "id": 34, "result": null}

Any help in this would be appreciated

#2

Notifying @areusch @gromero

#3

@nishtala it looks to me like the device isn’t responding over the serial port. could you confirm which serial port you’re using and ensure it’s working through e.g. minicom or python3 -mserial.tools.miniterm first? you may then need to modify _find_serial_port in microtvm_api_server.py to ensure tvmc run is talking to the correct port.

#4

python3 -mserial.tools.miniterm yields /dev/cu.usbmodem0004401205551 'J-Link Pro OB' and I have already changed this generic_find_serial_port to take the correct device.

#5

You should see some traffic on this port when you reset the board. I would start by confirming that you can see the traffic in some console program, then move on to debugging the connection. It’s possible (though, admittedly seems unlikely) that Zephyr requires additional configuration on your platform. It might also use a different baud rate. Knowing all of these parameters should help in fixing microtvm_api_server.py to point at the correct port.

#6

Everytime I reset the board I do see traffic and that’s OK. So, I’m sure that baudrate and port path are correct.

Don’t think it’s a problem in Zephyr, either. I could flash the example applications and view them on the console via minicom/screen.

#7

@nishtala Hi. Pardon the delay in replying. It seems you’re running into a stack overflow while executing the model in the target board, hence the timeout after you see some traffic in the serial line — experiment with setting CONFIG_MAIN_STACK_SIZE=4096 in prj.conf inside your project dir after tvmc create. Then build and flash.

Here is an example of output for the same tvmc commands you provided but on a ST disco board:

gromero@amd:/tmp/micro_speech_aot$ tvmc run --device micro /tmp/micro_speech_aot  --print-top 6 --fill-mode random
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: microTVM Zephyr runtime - running
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: DumpMetadata:
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	mod_name=tvmgen_default
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	version=1
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	num_inputs=1
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	num_outputs=1
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	num_workspace_pools=1
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	num_constant_pools=7
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	input[0]: Reshape_1
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	output[0]: output0
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	workspace_pools[0]: global_workspace_1_var
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[0]: fused_constant_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[1]: fused_nn_conv2d_constant_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[2]: fused_nn_conv2d_add_constant_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[3]: fused_nn_conv2d_add_constant_1_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[4]: fused_nn_conv2d_add_constant_2_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[5]: fused_constant_1_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: 	constant_pools[6]: fused_nn_contrib_dense_pack_constant_let
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: input allocate[0]: Reshape_1
[22:53:48] /home/gromero/git/tvm/src/runtime/micro/micro_session.cc:377: remote: output allocate[0]: output0
[[   3    2    1    0]
 [  71  -93 -106 -128]]
gromero@amd:/tmp/micro_speech_aot$

HTH

#8

…or better, instead of editing the prj.conf file manually, pass config_main_stack_size=4096 to tvmc micro create [...], for instance:

$ tvmc micro create -f /tmp/micro_speech_aot micro_speech_aot.tar zephyr --project-option project_type=host_driven board=stm32f746g_disco config_main_stack_size=4096
#9

@gromero thanks for the reply. Even after passing the parameter config_main_stack_size=4096 it’s still the same log we see above… here are a few things I verified: a) verified that the device is communicable (b) checked that the port_path and baudrate are captured correctly (I even hardcorded it for now) (c) examples from zephyr run on the device.

could it be any other parameter in tvm that I might be missing?

#10

@nishtala do you see any serial output from the device with this particular application flashed? the logs you’ve posted up here don’t show any, so that’s why i’ve been asking about that. you should at minimum see some gibberish including the string microTVM Zephyr runtime - running on the serial console when you reset the board.

#11

@nishtala Double check the string as Andrew mentioned above, you can check it using a term prog, like minicom too. After reset (or a flash) you must see the microTVM welcoming output, or something is really wrong with the serial or with the firmware flashed to the target.

If you do see the welcoming string you can check if your target is crashing after you ask the model to run by going into [...]/project/build and running GDB with west debug, then hitting c to continue. If you’re with minicom opened after you hit ‘c’ you must see the welcoming string. Then close minicom and execute the tvmc run (keeping the term you ran west debug open). After the time out, hit ctrl-c in GDB and then type bt to get a backtrace so you can have a clue what exactly the target is executing after the timeout. If the stack is spoiled (corrupted) or in a fault function, it’s something wrong when executing the model in the target.

#12

I don’t think any parameter is missing. You need to debug why the timeout is happening exactly with this board. Check the string as Andrew mentioned and if that’s the case, try to see what happens on the target when the model runs (using west debug).

#13

@areusch @gromero I configured the memory size incorrectly in Zephyr. I can now see the welcome message and some garbage, and this is the backtrace. I’ll start checking through the trace now and see what’s going on now

  [bt] (8) 9   _ctypes.cpython-39-darwin.so        0x0000000101647b4c _ctypes_callproc + 1392
  [bt] (7) 8   libffi.dylib                        0x000000019a9cfaf8 ffi_call_int + 1208
  [bt] (6) 7   libffi.dylib                        0x000000019a9c7050 ffi_call_SYSV + 80
  [bt] (5) 6   libtvm.dylib                        0x0000000129a1de14 TVMFuncCall + 60
  [bt] (4) 5   libtvm.dylib                        0x0000000129afa068 tvm::runtime::PackedFuncObj::Extractor<tvm::runtime::PackedFuncSubObj<tvm::runtime::micro_rpc::$_0>>::Call(tvm::runtime::PackedFuncObj const*, tvm::runtime::TVMArgs, tvm::runtime::TVMRetValue*) + 572
  [bt] (3) 4   libtvm.dylib                        0x0000000129afa920 tvm::runtime::micro_rpc::MicroTransportChannel::StartSession() + 184
  [bt] (2) 3   libtvm.dylib                        0x00000001280054e0 __clang_call_terminate + 0
  [bt] (1) 2   libtvm.dylib                        0x0000000128006820 tvm::runtime::detail::LogFatal::Entry::Finalize() + 0
  [bt] (0) 1   libtvm.dylib                        0x0000000128006874 tvm::runtime::detail::LogFatal::Entry::Finalize() + 84
  File "/Users/workspace/tvm/src/runtime/micro/micro_session.cc", line 245```

TVMError:
---------------------------------------------------------------
An error occurred during the execution of TVM.
For more information, please see: https://tvm.apache.org/docs/errors.html
---------------------------------------------------------------
  Check failed: (state_ == State::kReset) is false: MicroSession: state_: expected kReset, got
#14

@nishtala Cool.

Another hint is to check what’s being executed in the target by running west debug in ./build dir, adding a break at some of the interesting “entry points”, for instance: tvmgen_default_run (when the model starts running) or before, in TVMAotExecutor_Run, by adding a break in GDB with b (like b tvmgen_default_run), then hit ‘c’ to continue execution and on another terminal run the tvmc run ... command and check if it hits the break.

A typical working backtrace looks like the following:

(gdb) bt
#0  tvmgen_default___tvm_main__ (args=args@entry=0x20014d40 <z_main_stack+2752>, arg_type_ids=0x20015038 <z_main_stack+3512>, num_args=num_args@entry=3, out_ret_value=out_ret_value@entry=0x20015068 <z_main_stack+3560>, 
    out_ret_tcode=out_ret_tcode@entry=0x200150b8 <z_main_stack+3640>, resource_handle=resource_handle@entry=0x8020260 <_tvm_func_registry>) at /tmp/micro_speech_aot/model/codegen/host/src/default_lib2.c:249
#1  0x0800c416 in tvmgen_default_run (args=<optimized out>, type_code=<optimized out>, num_args=3, out_value=0x20015068 <z_main_stack+3560>, out_type_code=0x200150b8 <z_main_stack+3640>, resource_handle=0x8020260 <_tvm_func_registry>)
    at /tmp/micro_speech_aot/model/codegen/host/src/default_lib0.c:2189
#2  0x0800beee in TVMFuncCall (func_handle=<optimized out>, arg_values=arg_values@entry=0x20014fe8 <z_main_stack+3432>, type_codes=type_codes@entry=0x20015038 <z_main_stack+3512>, num_args=3, ret_val=ret_val@entry=0x20015068 <z_main_stack+3560>, 
    ret_type_code=ret_type_code@entry=0x200150b8 <z_main_stack+3640>) at /tmp/micro_speech_aot/crt/src/runtime/crt/common/crt_runtime_api.c:303
#3  0x0800c2c8 in TVMPackedFunc_Call (pf=0x20014f18 <z_main_stack+3224>) at /tmp/micro_speech_aot/crt/src/runtime/crt/common/packed_func.c:129
#4  0x0800b4f8 in TVMAotExecutor_Run (executor=0x20016044 <kheap_tvm_heap+3460>) at /tmp/micro_speech_aot/crt/src/runtime/crt/aot_executor/aot_executor.c:126
#5  0x0800beee in TVMFuncCall (func_handle=<optimized out>, arg_values=0x0, type_codes=0x0, num_args=0, ret_val=0x20015188 <z_main_stack+3848>, ret_type_code=0x20015174 <z_main_stack+3828>) at /tmp/micro_speech_aot/crt/src/runtime/crt/common/crt_runtime_api.c:303
#6  0x0800a254 in tvm::runtime::MinRPCExecute<tvm::runtime::micro_rpc::MicroIOHandler>::NormalCallFunc (this=0x2004bc68, call_handle=<optimized out>, values=0x0, tcodes=0x0, num_args=0)
    at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/../../minrpc/minrpc_server.h:186
#7  0x08008d5e in tvm::runtime::MinRPCServer<tvm::runtime::micro_rpc::MicroIOHandler, tvm::runtime::detail::PageAllocator>::HandleNormalCallFunc (this=<optimized out>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/../../minrpc/minrpc_server.h:653
#8  tvm::runtime::MinRPCServer<tvm::runtime::micro_rpc::MicroIOHandler, tvm::runtime::detail::PageAllocator>::ProcessOnePacket (this=0x20015814 <kheap_tvm_heap+1364>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/../../minrpc/minrpc_server.h:599
#9  tvm::runtime::micro_rpc::MicroRPCServer::HandleCompleteMessage (message_type=tvm::runtime::micro_rpc::MessageType::kNormal, buf=<optimized out>, this=0x20015724 <kheap_tvm_heap+1124>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/rpc_server.cc:182
#10 tvm::runtime::micro_rpc::MicroRPCServer::HandleCompleteMessage (buf=<optimized out>, message_type=<optimized out>, this=0x20015724 <kheap_tvm_heap+1124>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/rpc_server.cc:177
#11 tvm::runtime::micro_rpc::MicroRPCServer::HandleCompleteMessageCb (context=0x20015724 <kheap_tvm_heap+1124>, message_type=<optimized out>, buf=<optimized out>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/rpc_server.cc:187
#12 0x0800b10a in tvm::runtime::micro_rpc::Session::SessionReceiver::PacketDone (this=<optimized out>, is_valid=<optimized out>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_common/session.cc:170
#13 0x0800ab38 in tvm::runtime::micro_rpc::Unframer::FindCrcEnd (this=0x20015774 <kheap_tvm_heap+1204>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_common/framing.cc:298
#14 tvm::runtime::micro_rpc::Unframer::FindCrcEnd (this=0x20015774 <kheap_tvm_heap+1204>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_common/framing.cc:287
#15 0x0800ab6c in tvm::runtime::micro_rpc::Unframer::Write (this=this@entry=0x20015774 <kheap_tvm_heap+1204>, data=<optimized out>, data_size_bytes=1, bytes_consumed=bytes_consumed@entry=0x2001526c <z_main_stack+4076>)
    at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_common/framing.cc:108
#16 0x080073a0 in tvm::runtime::micro_rpc::MicroRPCServer::Loop (new_data_size_bytes=0x2001528c <z_main_stack+4108>, new_data_size_bytes@entry=0x2001525c <z_main_stack+4060>, new_data=0x20015288 <z_main_stack+4104>, new_data@entry=0x20015258 <z_main_stack+4056>, 
    this=this@entry=0x20015724 <kheap_tvm_heap+1124>) at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/rpc_server.cc:146
#17 MicroTVMRpcServerLoop (server_ptr=server_ptr@entry=0x20015724 <kheap_tvm_heap+1124>, new_data=new_data@entry=0x20015288 <z_main_stack+4104>, new_data_size_bytes=new_data_size_bytes@entry=0x2001528c <z_main_stack+4108>)
    at /tmp/micro_speech_aot/crt/src/runtime/crt/microtvm_rpc_server/rpc_server.cc:268
#18 0x08001ede in main () at /tmp/micro_speech_aot/src/main.c:153
(gdb)

HTH

#15

@nishtala glad to hear you made some progress. i think you might need to give it a bit more memory, that state issue smells of memory corruption.