intercreate / smpclient

Simple Management Protocol (SMP) Client for remotely managing MCU firmware
Apache License 2.0
9 stars 6 forks source link

SMP Nrf52832 Error #41

Closed onurcoskun14 closed 2 months ago

onurcoskun14 commented 3 months ago

Hello, I am trying to update my Nrf52832 via ble with my rpi4 but I get this error and I don't understand what it is.

Connecting to SMP server at D4:D1:86:BA:11:3A...2024-08-29 09:00:22.142 INFO smp_characteristic.max_write_without_response_size=249 2024-08-29 09:00:22.144 INFO self._max_write_without_response_size=249 2024-08-29 09:00:22.703 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. 2024-08-29 09:00:22.703 WARNING Error reading MCUMgr parameters: header=Header(op=<OP.READ_RSP: 1>, version=<Version.V1: 0>, flags=<Flag: 0>, length=6, group_id=0, sequence=0, command_id=6) version=<Version.V1: 0> sequence=0 smp_data=b'\x01\x00\x00\x06\x00\x00\x00\x06\xbfbrc\x08\xff' rc=<MGMT_ERR.ENOTSUP: 8> rsn=None OK Sending request...2024-08-29 09:00:22.849 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. OK Received response: <bound method make_hash_func..hash_func of ImageStatesReadResponse(header=Header(op=<OP.READ_RSP: 1>, version=<Version.V1: 0>, flags=<Flag: 0>, length=134, group_id=1, sequence=1, command_id=0), version=<Version.V1: 0>, sequence=1, smp_data=b'\x01\x00\x00\x86\x00\x01\x01\x00\xbffimages\x9f\xbfdslot\x00gversione0.0.0dhashX \x01\xf6"\x86DU\x0f\x19{\x10\xe0\x99|<\x00\xc1\xc6\xfb\xa9\xf6*V\xe9\x1b\':y,\xe9\xdd\x10hbootable\xf5gpending\xf4iconfirmed\xf5factive\xf5ipermanent\xf4\xff\xffksplitStatus\x00\xff', images=[ImageState(slot=0, version='0.0.0', image=None, hash=b'\x01\xf6"\x86DU\x0f\x19{\x10\xe0\x99|<\x00\xc1\xc6\xfb\xa9\xf6*V\xe9\x1b\':y,\xe9\xdd\x10', bootable=True, pending=False, confirmed=True, active=True, permanent=False)], splitStatus=0)>

2024-08-29 09:00:23.045 ERROR Response could not by parsed as one of <class 'smp.image_management.ImageUploadWriteResponse'>, <class 'smp.image_management.ImageManagementErrorV1'>, or <class 'smp.image_management.ImageManagementErrorV2'>. header=Header(op=<OP.WRITE_RSP: 3>, version=<Version.V1: 0>, flags=<Flag: 0>, length=12, group_id=1, sequence=2, command_id=1) frame=b'\x03\x00\x00\x0c\x00\x01\x02\x01\xbfbrc\x00coff\x18\xa5\xff' 2024-08-29 09:00:23.045 ERROR Exception in SMPClient: exc_type=<class 'TypeError'>, exc_value=TypeError('No constructor defined'), traceback=<traceback object at 0x7fa16af4c0> 2024-08-29 09:00:25.288 WARNING Disconnected from D4:D1:86:BA:11:3A

onurcoskun14 commented 3 months ago

Additionally i can update the device wtih same binary file via nrf Connect app. Update

Connecting to SMP server at D4:D1:86:BA:11:3A...OK Sending request...OK Received response: header=Header(op=<OP.READ_RSP: 1>, version=<Version.V0: 0>, flags=<Flag: 0>, length=134, group_id=1, sequence=0, command_id=0) sequence=0 images=[ImageState(slot=0, version='0.0.0', image=None, hash=b'\x01\xf6"\x86DU\x0f\x19{\x10\xe0\x99|<\x00\xc1\xc6\xfb\xa9\xf6`*V\xe9\x1b\':y,\xe9\xdd\x10', bootable=True, pending=False, confirmed=True, active=True, permanent=False)] splitStatus=0

Uploaded 200,675 / 200,675 Bytes | 1.04 KB/s
Sending request...OK Received response: header=Header(op=<OP.READ_RSP: 1>, version=<Version.V0: 0>, flags=<Flag: 0>, length=244, group_id=1, sequence=130, command_id=0) sequence=0 images=[ImageState(slot=0, version='0.0.0', image=None, hash=b'\x01\xf6"\x86DU\x0f\x19{\x10\xe0\x99|<\x00\xc1\xc6\xfb\xa9\xf6`*V\xe9\x1b\':y,\xe9\xdd\x10', bootable=True, pending=False, confirmed=True, active=True, permanent=False), ImageState(slot=1, version='0.0.0', image=None, hash=b'\x7fL\xd0AG\x02\xb7\x9e\x9cB\x18\x12\x86e\xec\xdd\xd1\xe1\xaf\xc2p[\x9c\x0b\xf7[\xea\x1a9\x83\xd7l', bootable=True, pending=False, confirmed=False, active=False, permanent=False)] splitStatus=0 Traceback (most recent call last): File "/home/Cblt-Gw/smptest.py", line 73, in asyncio.run(main()) File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run return runner.run(main) ^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run return self._loop.run_until_complete(task) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete return future.result() ^^^^^^^^^^^^^^^ File "/home/Cblt-Gw/smptest.py", line 33, in main async with SMPClient( TypeError: SMPClient.aexit() takes 1 positional argument but 4 were given

This is new Error I got.

JPHutchins commented 3 months ago

TypeError: SMPClient.aexit() takes 1 positional argument but 4 were given

It looks like __aexit__ is defined with only 1 argument instead of 4.

Did this test work? It reports 1kBps which is very slow, 15kBps - 25kBps is possible.

Update. This is the async context manage def, so now I'm not sure! 🤔

https://github.com/intercreate/smpclient/blob/main/smpclient/__init__.py#L245C5-L250C15

JPHutchins commented 3 months ago

2024-08-29 09:00:23.045 ERROR Response could not by parsed as one of <class 'smp.image_management.ImageUploadWriteResponse'>, <class 'smp.image_management.ImageManagementErrorV1'>, or <class 'smp.image_management.ImageManagementErrorV2'>. header=Header(op=<OP.WRITE_RSP: 3>, version=<Version.V1: 0>, flags=<Flag: 0>, length=12, group_id=1, sequence=2, command_id=1) frame=b'\x03\x00\x00\x0c\x00\x01\x02\x01\xbfbrc\x00coff\x18\xa5\xff'

This is interesting. I believe that this response is out of spec. It appears be sending "rc=0" along with the offset. This is the CBOR: \xbfbrc\x00coff\x18\xa5\xff

I believe that it's a regression introduced by this commit: https://github.com/JPHutchins/smp/commit/60f7a29c485959a597af23a3c61d7918ea8576b9

JPHutchins commented 3 months ago

OK, can confirm

import cbor2
print(cbor2.loads(b"\xbfbrc\x00coff\x18\xa5\xff"))

output:

{'rc': 0, 'off': 165}

No form of an Image Upload Response should include rc and off: https://docs.zephyrproject.org/latest/services/device_mgmt/smp_groups/smp_group_1.html#image-upload-response

What version of Zephyr / NCS are you using?

I see that it will do this on latest if CONFIG_MCUMGR_SMP_LEGACY_RC_BEHAVIOUR is enabled: https://github.com/zephyrproject-rtos/zephyr/blob/91a1e706535b2f99433280513c5bc66dfb918506/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt.c#L397-L400

Since this problem may exist in the wild I will update smp and smpclient to allow this incorrect response.

onurcoskun14 commented 3 months ago

Thank you for answer. I have another question. After uploading image should I do anything else to nrf52832 run the new image cuz I can confirm that image is uploaded via nrfConnect hash code but can't make it run the uploaded image.

JPHutchins commented 3 months ago

Thank you for answer. I have another question. After uploading image should I do anything else to nrf52832 run the new image cuz I can confirm that image is uploaded via nrfConnect hash code but can't make it run the uploaded image.

Yes, you would need to mark the image for swap and then reset the device allowing MCUBoot to do the swap. Take a look at the example script: https://github.com/intercreate/smpclient/blob/main/examples/ble/upgrade.py. You could also run the example script if you have a compatible board.

You could also look at smpmgr's upgrade abstraction: https://github.com/intercreate/smpmgr/blob/41683521f850e39f2ce838250483699b16507f76/smpmgr/main.py#L83-L145

If you have time, I'd love to troublshoot why the speeds are so slow!

Note: I think I saw that you are marking the image confirmed before uploading - this is dangerous and can brick your device if the image is bad.

Re: confirm, it's called "upgrade" in the API: https://github.com/intercreate/smpclient/blob/0185b53a6ac35f662b2aad60c2e90e9fd981bc4d/smpclient/__init__.py#L97-L102

onurcoskun14 commented 3 months ago

If you have time, I'd love to troublshoot why the speeds are so slow!

I'd love that but my setup is in my office i won't be there until monday.

Yes, you would need to mark the image for swap and then reset the device allowing MCUBoot to do the swap. Take a look at the example script: https://github.com/intercreate/smpclient/blob/main/examples/ble/upgrade.py. You could also run the example script if you have a compatible board.

I'll try this first thing. Actually what I'm trying is to understand this python code and convert it to C# then implement into my project to scan ble devices around get advertisement etc.

onurcoskun14 commented 2 months ago

I installed version 4.1.1 I updated my Nrf successfully but i am getting warnings constantly and upload speed is really low. Uploaded 200,778 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:05.917 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 201,002 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:06.112 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 201,226 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:06.307 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 201,450 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:06.502 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 201,674 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:06.794 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 201,898 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:06.989 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 202,122 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:07.184 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 202,346 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:07.379 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 202,570 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:07.623 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 202,794 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:07.818 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 203,018 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:08.013 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 203,242 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:08.208 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 203,466 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:08.403 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 203,690 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:08.598 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 203,914 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:08.793 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 204,138 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:08.988 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 204,362 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:09.183 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 204,586 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:09.378 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 204,810 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:09.573 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 205,034 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:09.769 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 205,258 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:09.865 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. Uploaded 205,351 / 205,351 Bytes | 1.12 KB/s 2024-09-02 08:07:09.865 INFO Upload complete

JPHutchins commented 2 months ago

It seems like options to use V1 of SMP should get exposed on the convenience methods, like upload. Right now it defaults to V2 and then complains when it receives a V1 response. The differences between V1 and V2 are limited to how error messages are formatted. If possible, it would be best to update the FW to a newer version of Zephyr that will use V2 by default.

Regarding speed, it mostly is determined by the BLE MTU and configuration of the SMP buffers. An example, based on Nordic's examples for "fast DFU", is included in the dutfirmware folder of this repository. The MTU allows for packets of 495 bytes. The receiving buffer of 2475 bytes will reassemble an SMP frame from 5 packets received in sequence.

Further, smpclient will query for these parameters when connected and if that request is not supported, it will default back to sending an SMP frame that will fit in MTU.

If you have a dev kit then you can try the scripts in the examples folder, but keep in mind that they will overwrite the FW on your dev kit with the FW for the script.

JPHutchins commented 2 months ago

smp_characteristic.max_write_without_response_size=249 2024-08-29 09:00:22.144 INFO self._max_write_without_response_size=249 2024-08-29 09:00:22.703 WARNING Overriding self.version=<Version.V2: 1> with self.header.version=<Version.V1: 0> from the provided header. 2024-08-29 09:00:22.703 WARNING Error reading MCUMgr parameters: header=Header(op=<OP.READ_RSP: 1>, version=<Version.V1: 0>, flags=<Flag: 0>, length=6, group_id=0, sequence=0, command_id=6) version=<Version.V1: 0> sequence=0 smp_data=b'\x01\x00\x00\x06\x00\x00\x00\x06\xbfbrc\x08\xff' rc=<MGMT_ERR.ENOTSUP: 8> rsn=None

I do see from the initial logs that MTU is 252 and the SMP parameters request failed as not supported. This means that 249 byte packets will be sent without any SMP frame reassembly.

JPHutchins commented 2 months ago

I think that the standard overlay-bt.conf from the Zephyr SMP server examples folder has the KConfigs for fast BLE uploads.

Update: found it!

https://github.com/nrfconnect/sdk-zephyr/blob/main/samples/subsys/mgmt/mcumgr/smp_svr/overlay-bt.conf

onurcoskun14 commented 2 months ago

Yeah I guess it's about that rpi4 mtu size is small that is what causing slow upload.

JPHutchins commented 2 months ago

Yeah I guess it's about that rpi4 mtu size is small that is what causing slow upload.

Perhaps! But it is the FW that's controlling the MTU.

I'm curious about this since I have not tested on an RPi and I wonder if there's something making it significantly slower than BLE on Windows, Linux or Mac.

But first thing is to update the FW with Nordic's fast DFU config.

onurcoskun14 commented 2 months ago

I have noticed something when i upload the same image with mynewt-mcumgr it uploads almost twice as fast using same bluetooth adapter.