Closed JPHutchins closed 2 weeks ago
Confirmed that the request, with the same MTU, does work via the MCUBoot Serial SMP Server.
ImageState(
slot=0,
version='1.0.0.41459195',
image=None,
hash=HashBytes('760D3F6EF885CA8A66580106425DC94B8DF46E41531A9930ECAA9A80013BF8C2'),
bootable=True,
pending=None,
confirmed=True,
active=True,
permanent=None
)
ImageState(
slot=1,
version='1.0.0.41459195',
image=None,
hash=HashBytes('760D3F6EF885CA8A66580106425DC94B8DF46E41531A9930ECAA9A80013BF8C2'),
bootable=True,
pending=None,
confirmed=None,
active=None,
permanent=None
)
Here's a Zephyr call stack from the echo command:
os_mgmt_echo@0x0005eaec (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\grp\os_mgmt\src\os_mgmt.c:101)
smp_handle_single_payload@0x000a64c8 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\smp\src\smp.c:229)
smp_handle_single_req@0x000a652a (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\smp\src\smp.c:282)
smp_process_request_packet@0x000a6606 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\smp\src\smp.c:414)
smp_process_packet@0x000a6b08 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\transport\src\smp.c:123)
smp_handle_reqs@0x000a6b1a (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\transport\src\smp.c:140)
work_queue_main@0x00092310 (\home\jp\ncs\v2.5.0\zephyr\kernel\work.c:668)
z_thread_entry@0x000a1c00 (\home\jp\ncs\v2.5.0\zephyr\lib\os\thread_entry.c:48)
??@0xaaaaaaaa (Unknown Source:0)
Interesting, I cannot hit a break, even at smp_handle_reqs
when sending the upload request. So, it's like it's not even treating it as SMP.
OK, finally got a break point on the upload request @
nb = mcumgr_serial_process_frag(&smp_shell_rx_ctxt,
buf->data,
buf->len);
in smp_shell.c
smp_shell_process@0x0005f89e (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\transport\src\smp_shell.c:198)
update@0x000a4678 (\home\jp\ncs\v2.5.0\zephyr\subsys\shell\backends\shell_uart.c:326)
shell_thread@0x000596f8 (\home\jp\ncs\v2.5.0\zephyr\subsys\shell\shell.c:1362)
z_thread_entry@0x000a1c00 (\home\jp\ncs\v2.5.0\zephyr\lib\os\thread_entry.c:48)
??@0xaaaaaaaa (Unknown Source:0)
OK, the data is in the buf.data member
0x200301b8 <net_buf_data_smp_shell_rx_pool> "\006\tALUCAACrAAEAAaZjb2ZmAGRkYXRhWF89uPOWAAAAAAACAADAGQ0ABAAAAAEAAAD7nXgCAAAAAP", '/' <repeats 51 times>, "\324\023\334\036\022<v\364\035\345\241ҕ\023\215\224&\005\354K\231ºY\214fi\317<\a\261am4\215\020\203\034\037\301\024\255\377\262\004'\257y\321~U\302\370٭d6y\232\365^\023Q\026\222\364\201\202\313\070\235\345\b"...
But, plot twist, the size is set to 127 which is the legacy mcumgr transport size. I'll try setting MTU to 127 and see if that fixes it.
OK, a LITTLE progress,
│ │ response = ImageUploadProgressWriteResponse( │ │
│ │ │ header=Header( │ │
│ │ │ │ op=<OP.WRITE_RSP: 3>, │ │
│ │ │ │ version=<Version.V0: 0>, │ │
│ │ │ │ flags=<Flag.0: 0>, │ │
│ │ │ │ length=6, │ │
│ │ │ │ group_id=<GroupId.IMAGE_MANAGEMENT: 1>, │ │
│ │ │ │ sequence=0, │ │
│ │ │ │ command_id=<ImageManagement.UPLOAD: 1> │ │
│ │ │ ), │ │
│ │ │ sequence=0, │ │
│ │ │ rc=3, │ │
│ │ │ off=None │ │
│ │ )
We want offset = the size of data written and rc=0. What is rc=3?
Cool we can stop on the request now!
img_mgmt_upload@0x0005e6d6 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\grp\img_mgmt\src\img_mgmt.c:461)
smp_handle_single_payload@0x000a64c8 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\smp\src\smp.c:229)
smp_handle_single_req@0x000a652a (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\smp\src\smp.c:282)
smp_process_request_packet@0x000a6606 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\smp\src\smp.c:414)
smp_process_packet@0x000a6b08 (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\transport\src\smp.c:123)
smp_handle_reqs@0x000a6b1a (\home\jp\ncs\v2.5.0\zephyr\subsys\mgmt\mcumgr\transport\src\smp.c:140)
work_queue_main@0x00092310 (\home\jp\ncs\v2.5.0\zephyr\kernel\work.c:668)
z_thread_entry@0x000a1c00 (\home\jp\ncs\v2.5.0\zephyr\lib\os\thread_entry.c:48)
??@0xaaaaaaaa (Unknown Source:0)
OK, looks like img_mgmt_upload_inspect is failing with rc=22.
/* Determine what actions to take as a result of this request. */
rc = img_mgmt_upload_inspect(&req, &action);
if (rc != 0) {
#if defined(CONFIG_MCUMGR_GRP_IMG_STATUS_HOOKS)
(void)mgmt_callback_notify(MGMT_EVT_OP_IMG_MGMT_DFU_STOPPED, NULL, 0, &err_rc,
&err_group);
#endif
MGMT_CTXT_SET_RC_RSN(ctxt, IMG_MGMT_UPLOAD_ACTION_RC_RSN(&action));
LOG_ERR("Image upload inspect failed: %d", rc);
ok = smp_add_cmd_err(zse, MGMT_GROUP_ID_IMAGE, rc);
goto end;
}
Hmm, req->img_data.len here is 0,
if (req->img_data.len < sizeof(struct image_header)) {
/* Image header is the first thing in the image */
IMG_MGMT_UPLOAD_ACTION_SET_RC_RSN(action, img_mgmt_err_str_hdr_malformed);
return IMG_MGMT_ERR_INVALID_IMAGE_HEADER;
}
I THINK that the problem is there not being enough room in the packet for the SHA and initial image data, while the routine there wants to see at least 32 bytes in the initial upload request (the MCUBoot header).
Alright, this requires an upstream "fix" in smpclient. The fix is to not include the the SHA in the initial request to make sure that there is room for at least 32 bytes of data. Still feels like a bug in the _maximize_packet function wherein it's not calculating the packet size correctly.
IDK, seems like there should be enough room in the CBOR for 32 byte sha and 32 bytes of the image.
def _maximize_packet(self, request: ImageUploadWrite, image: bytes) -> ImageUploadWrite:
"""Given an `ImageUploadWrite` with empty `data`, return the largest packet possible."""
def cbor_integer_size(integer: int) -> int:
"""CBOR integers are packed as small as possible."""
return 0 if integer < 24 else 1 if integer < 0xFF else 2 if integer < 0xFFFF else 4
_h = cast(smpheader.Header, request.header)
chunk_size = self._transport.max_unencoded_size - len(bytes(request))
chunk_size -= cbor_integer_size(chunk_size)
chunk_size = max(0, chunk_size)
cbor_size = _h.length + chunk_size + cbor_integer_size(chunk_size)
return ImageUploadWrite(
header=smpheader.Header(
op=_h.op,
version=_h.version,
flags=_h.flags,
length=cbor_size,
group_id=_h.group_id,
sequence=_h.sequence,
command_id=_h.command_id,
),
off=request.off,
data=image[request.off : request.off + chunk_size],
image=request.image,
len=request.len,
sha=request.sha,
upgrade=request.upgrade,
)
Summary
To support image uploads using the Zephyr SMP Server "shell" transport:
--mtu 127
for the Zephyr SMP Server shell transport
Confirmed a successful upload to the secondary slot.
Hi! I'm having still problems doing this. I was trying to get this to work with mtu=127 (which btw should be the fixed line size for the serial transport according to the original implementation) however with the current verson, the first payload is produced empty. I have not yet regressed to previous commits of this repo so couldn't really see when/if this was introduced by any changes.
Hi! I'm having still problems doing this. I was trying to get this to work with mtu=127 (which btw should be the fixed line size for the serial transport according to the original implementation) however with the current verson, the first payload is produced empty. I have not yet regressed to previous commits of this repo so couldn't really see when/if this was introduced by any changes.
This is not fixed in smpmgr. The upload method of smpclient now has an option to not include the image SHA, so it's a matter of upgrading smpclient and then exposing that option to the CLI.
There is probably something that needs to be fixed in Zephyr to make this work with slightly larger packets so that the SHA can be used.
@JPHutchins Thanks for the feedack, I will test this later today. I'm happy to help on both sides. We at AssistMe are definitely looking forward to using both smpmgr and the two libs, so we are also eager to contribute with features and bugfixes. I am contact with some of the other people who did the original implementation of the protocol and it would be cool to also see this working with zephyr/mynewt/mcuboot.
Looking forward to it! The example scripts in smpclient provide some integration tests. Shell transport is not covered yet. The upload examples use a programmer to flash FW, then use smpclient to do upload and swap, then verify success. There are only nordic example boards but we're working on adding ST examples right now.
I believe this is also an issue for non-shell transports.
/ {
chosen {
zephyr,console = &lpuart1;
zephyr,shell-uart = &cdc_acm_uart0;
zephyr,uart-mcumgr = &cdc_acm_uart1;
};
};
&zephyr_udc0 {
cdc_acm_uart0: cdc_acm_uart0 {
compatible = "zephyr,cdc-acm-uart";
};
cdc_acm_uart1: cdc_acm_uart1 {
compatible = "zephyr,cdc-acm-uart";
};
};
#
# Transports and Transport Related Configuration Options
#
CONFIG_MCUMGR_TRANSPORT_WORKQUEUE_STACK_SIZE=2048
CONFIG_MCUMGR_TRANSPORT_WORKQUEUE_THREAD_PRIO=3
CONFIG_MCUMGR_TRANSPORT_NETBUF_COUNT=4
CONFIG_MCUMGR_TRANSPORT_NETBUF_SIZE=384
CONFIG_MCUMGR_TRANSPORT_NETBUF_MIN_USER_DATA_SIZE=4
CONFIG_MCUMGR_TRANSPORT_NETBUF_USER_DATA_SIZE=4
# CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL_OFF is not set
# CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL_ERR is not set
# CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL_WRN is not set
# CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL_INF is not set
# CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL_DBG is not set
CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL_DEFAULT=y
CONFIG_MCUMGR_TRANSPORT_LOG_LEVEL=3
# CONFIG_MCUMGR_TRANSPORT_DUMMY is not set
# CONFIG_MCUMGR_TRANSPORT_SHELL is not set
CONFIG_MCUMGR_TRANSPORT_UART=y
CONFIG_MCUMGR_TRANSPORT_UART_MTU=256
# end of Transports and Transport Related Configuration Options
I will try as well with the sha omit option.
In the mean time...
DEBUG Sending 179 bytes - d:\GitHub\x\.venv\Lib\site-packages\smpclient\transport\serial.py:106 serial.py:106
DEBUG Serializing packet.py:30
request=b'\x02\x00\x00\xab\x00\x01\x00\x01\xa6coff\x00ddataX_=\xb8\xf3\x96\x00\x00\x00\x00\x00\x04\x00\x00\xf0\xbf\x01\x00\x00\x00\x00\x00\x00\
x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0
0\x00\x00eimage\x00clen\x1a\x00\x01\xc4\x80cshaX
d8\xe5r\x0e8\x1c\xd6p\xb2\xc5\xf8\xfd\x8d\x8e\xd4\xb9\x90}\x8e\xaf\x84\xcet\x86Y\x0c?\xea\xb0,Xgupgrade\xf4' -
d:\GitHub\x\.venv\Lib\site-packages\smp\packet.py:30
DEBUG Total size of request is 183B - d:\GitHub\x\.venv\Lib\site-packages\smp\packet.py:36 packet.py:36
DEBUG Total size of b64 encoded request is 244B - d:\GitHub\x\.venv\Lib\site-packages\smp\packet.py:41 packet.py:41
DEBUG Writing encoded packet of size 247B; self.mtu=256 - d:\GitHub\x\.venv\Lib\site-packages\smpclient\transport\serial.py:113 serial.py:113
DEBUG Sent 179 bytes - d:\GitHub\x\.venv\Lib\site-packages\smpclient\transport\serial.py:119 serial.py:119
DEBUG Waiting for response - d:\GitHub\x\.venv\Lib\site-packages\smpclient\transport\serial.py:125 serial.py:125
Hope this helps. Will continue to dig.
Hi @sgfeniex! We're maintaining some hardware integration tests over at smpclient:
https://github.com/intercreate/smpclient/tree/main/examples
Ideally we can add the regression test there. Is a regular echo like smpmgr --port /mydevice --mtu 256 --log-level DEBUG os echo hello
working? Larger MTUs shouldn't be impacted by the bug discussed here.
@sgfeniex Also take a look here, I've had mixed results with what Kconfigs are actually being used: https://github.com/intercreate/smpclient/pull/25#issuecomment-2132040998
I "discovered" those config settings shortly before coming across your findings.
Generally speaking, 'shorter' requests echo and image state work fine all the time. I am using i.MXRT1062 hardware. When I get set up with Zephyr debugging I will find out what is going on on the embedded side causing it to not respond.
I will also try the echo as you suggested and report back.
@sgfeniex Do you recommend this dev kit? https://www.nxp.com/design/design-center/development-boards-and-designs/i-mx-evaluation-and-development-boards/i-mx-rt1060-evaluation-kit:MIMXRT1060-EVKB
Another upside is that it looks like I could use it for the UDP transport implementation as well.
Feel free to attach your build/zephyr/.config
as well if you have a chance.
Yes, I do recommend that dev kit. It is great for some of the most common i.MXRT processors.
I've given up on shell transport for the time being since it was so easy to spin up another CDC ACM port.
/ {
chosen {
zephyr,console = &cdc_acm_uart0;
zephyr,shell-uart = &cdc_acm_uart0;
zephyr,uart-mcumgr = &cdc_acm_uart1;
};
};
&zephyr_udc0 {
cdc_acm_uart0: cdc_acm_uart0 {
compatible = "zephyr,cdc-acm-uart";
};
cdc_acm_uart1: cdc_acm_uart1 {
compatible = "zephyr,cdc-acm-uart";
};
};
Note: CONFIG_MCUMGR_TRANSPORT_UART_MTU
ends up as 256
The result of all this is:
smpmgr --port COM22 upgrade D:\GitHub\x\build\app\zephyr\zephyr.signed.bin
smpmgr --port COM22 --mtu 256 upgrade D:\GitHub\x\build\app\zephyr\zephyr.signed.bin
smpmgr --port COM22 --mtu 128 upgrade D:\GitHub\x\build\app\zephyr\zephyr.signed.bin
smpmgr --port COM22 os echo "https://github.com/intercreate/smpmgr/issues/8"
smpmgr --port COM22 --mtu 256 os echo "https://github.com/intercreate/smpmgr/issues/8"
smpmgr --port COM22 --mtu 128 os echo "https://github.com/intercreate/smpmgr/issues/8"
smpmgr --port COM22 --mtu 32 os echo "https://github.com/intercreate/smpmgr/issues/8"
After removing the SHA transmit in upload->request->_maximize_packet->ImageUploadWrite
smpmgr --port COM22 --mtu 128 upgrade D:\GitHub\x\build\app\zephyr\zephyr.signed.bin
Note:
CONFIG_MCUMGR_TRANSPORT_UART_MTU
ends up as 256
In your .config, we see the following:
CONFIG_UART_MCUMGR=y
CONFIG_UART_MCUMGR_RX_BUF_SIZE=128
CONFIG_UART_MCUMGR_RX_BUF_COUNT=2
Try updating CONFIG_UART_MCUMGR_RX_BUF_SIZE to 256. Likely this needs to be fixed in Zephyr source and/or docs.
If you set RX_BUF_COUNT to 2, then I think you need to increase
CONFIG_MCUMGR_TRANSPORT_NETBUF_SIZE=512
I recommend larger settings when you can spare the RAM. Typically this is easy if you are upgrading FW from within the bootloader maybe not so much if you are upgrading from within the application. See integration tested configs here, for example: https://github.com/intercreate/smpclient/blob/main/dutfirmware/usb_smp_dut_8192_1_8192.conf
Update:
The netbuf size one does get used: https://github.com/zephyrproject-rtos/zephyr/blob/cb17f5f5a4af168d535227a14923bd28a8c17ee6/tests/subsys/mgmt/mcumgr/smp_reassembly/src/main.c#L16-L19
As does the RX_BUF_SIZE: https://github.com/zephyrproject-rtos/zephyr/blob/cb17f5f5a4af168d535227a14923bd28a8c17ee6/include/zephyr/drivers/console/uart_mcumgr.h#L26-L30
This is fixed by this: https://github.com/intercreate/smpclient/blob/1c940d9ce7d8dfefd2abda9cb59365868ad04882/smpclient/__init__.py#L257-L259
But feel free to comment if it is sighted again, either on shell transport or with any small buffers.
Adding
Allows coexistence of the Zephyr shell/console with the SMP servers on the same transport (UART/USB CDC ACM).
A simple echo request works:
But upload requests hang or return characters not belonging to an SMP response.
The response,
b'\x1b[m\r\n'
, looks a lot like Zephyr is accidentally sending some log or terminal stuff over the wire instead of SMP.