mfw_update sample app fails

rabarar · Nov 24, 2024

Anyone successfully update the feather to the 1.3.7 firmware? When I attempt to do so, I get the following error:

% python3 update_modem.py ~/Downloads/mfw_nrf9160_1.3.7.zip /dev/tty.usbserial-510 1000000
# modem firmware upgrade over serial port example started.
[HighLevel] Creating new probe
[HighLevel] Initialize new probe.
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Dll directory is /Users/robert/.virtualenvs/zephyr/lib/python3.11/site-packages/pynrfjprog/lib_x64.
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Find and connect to dfu dll
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Using DFU dll at /Users/robert/.virtualenvs/zephyr/lib/python3.11/site-packages/pynrfjprog/lib_x64/libnrfdfu.dylib.
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Load library at /Users/robert/.virtualenvs/zephyr/lib/python3.11/site-packages/pynrfjprog/lib_x64/libnrfdfu.dylib.
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Library loaded, loading member functions.
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Member functions succesfully loaded.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Initialize new probe.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Successfully opened port: /dev/tty.usbserial-510@1000000,flow_control:none,parity:none.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Error caught in parse_stat_response: Key not found: 'rc'
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 569, 
    "error_code": "Ok", 
    "operation": "open_uart", 
    "outcome": "success", 
    "progress_percentage": 100
}
[HighLevel] Probe initialization complete!
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Check if provided file exists
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Check if provided file can be read
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":4,"description":"Finding image components","duration":0,"message":"Detecting package components","operation":"confirm_image","progressPercentage":25,"step":1}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":4,"description":"Finding image components","duration":0,"message":"Verifying that package is complete","operation":"confirm_image","progressPercentage":50,"step":2}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":4,"description":"Finding image components","duration":0,"message":"Detecting bootloader version","operation":"confirm_image","progressPercentage":75,"step":3}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":4,"description":"Finding image components","duration":0,"message":"Finished","operation":"confirm_image","progressPercentage":100,"result":"success","step":4}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":7,"description":"Upload segments","duration":0,"message":"Prepare modem for upload","operation":"enter_programming_state","progressPercentage":14,"step":1}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":7,"description":"Upload segments","duration":0,"message":"Upload bootloader","operation":"enter_programming_state","progressPercentage":28,"step":2}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":2,"description":"Starting modem boot loader","duration":0,"message":"mfw_nrf9160_1.3.7/72B3D7C.ipc_dfu.signed_1.2.0.ihex","operation":"enter_programming_state","progressPercentage":50,"step":1}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Extracting 16791 bytes from mfw_nrf9160_1.3.7/72B3D7C.ipc_dfu.signed_1.2.0.ihex.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 0, 
    "message": "Calculating image size", 
    "operation": "upload_image", 
    "progress_percentage": 5
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 0, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 10
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 8, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 14
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 16, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 19
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 25, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 24
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 33, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 28
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 42, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 33
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 50, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 38
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 59, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 43
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 67, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 48
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 76, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 53
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 84, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 58
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 93, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 63
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 101, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 68
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 110, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 73
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 118, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 78
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 127, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 83
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 135, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 88
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 144, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 93
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 152, 
    "message": "Uploading image to device", 
    "operation": "upload_image", 
    "progress_percentage": 98
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 212, 
    "operation": "upload_image", 
    "outcome": "success", 
    "progress_percentage": 100
}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":2,"description":"Starting modem boot loader","duration":213,"message":"Finished","operation":"enter_programming_state","progressPercentage":100,"result":"success","step":2}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":7,"description":"Upload segments","duration":213,"message":"Modem ready for upload","operation":"enter_programming_state","progressPercentage":42,"step":3}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {"amountOfSteps":7,"description":"Upload segments","duration":0,"message":"segment 1 of 4","operation":"upload_image","progressPercentage":57,"step":4}
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Extracting 212 bytes from __MACOSX/mfw_nrf9160_1.3.7/._firmware.update.image.segments.0.hex.
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Unknown runtime error: Found end of content before end of string.
[HighLevel] Failed programming the device.
[Probes./dev/tty.usbserial-510] b"An error was reported by NRFJPROG DLL: -254 INTERNAL_ERROR. \n[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Error caught in parse_stat_response: Key not found: 'rc'\n\textra: [Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Unknown runtime error: Found end of content before end of string.\n\textra: [HighLevel] Failed programming the device."
[Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Uninitializing ModemUARTDFU probe at serial port /dev/tty.usbserial-510.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Sending device reset request
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Sending reset request to device.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Closing connection to mcuboot device
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] serial port /dev/tty.usbserial-510 closed.
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] {
    "duration": 74, 
    "error_code": "Ok", 
    "operation": "close_uart", 
    "outcome": "success", 
    "progress_percentage": 100
}
[HighLevel] Done.
[HighLevel] Closing and freeing sub dlls.
Traceback (most recent call last):
  File "/Users/robert/src/zephyr/circuitdojo/proj2/nfed/samples/mfw_update/update_modem.py", line 43, in <module>
    run(args.uart, args.firmware, args.baudrate)
  File "/Users/robert/src/zephyr/circuitdojo/proj2/nfed/samples/mfw_update/update_modem.py", line 26, in run
    modem_dfu_probe.program(modem_firmware_zip)
  File "/Users/robert/.virtualenvs/zephyr/lib/python3.11/site-packages/pynrfjprog/HighLevel.py", line 409, in program
    raise APIError(result, error_data=self.get_errors(), log=self._logger.error)
pynrfjprog.APIError.APIError: An error was reported by NRFJPROG DLL: -254 INTERNAL_ERROR. 
[Probes./dev/tty.usbserial-510] [ModemUARTDFU-/dev/tty.usbserial-510] Error caught in parse_stat_response: Key not found: 'rc'
	extra: [Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Unknown runtime error: Found end of content before end of string.
	extra: [HighLevel] Failed programming the device.

rabarar · Nov 24, 2024

Taking a closer look at the python docs for pynrfjprog this looks to be a WINDOZE only app… grrr

jaredwolff · Nov 24, 2024

@rabarar this should work on all platforms. It only uses the serial interface. The other dependencies are for jlink

https://github.com/NordicSemiconductor/pynrfjprog

jaredwolff · Nov 24, 2024

What version of python3 do you have installed? What about the pynrfjprog library?

rabarar · Nov 24, 2024

so python version on OSX with homebrew is Python 3.11.10 (main, Sep 7 2024, 01:03:31) [Clang 15.0.0 (clang-1500.3.9.4)] on darwin and pynrfjprog is 10.24.2

rabarar · Nov 24, 2024

@jaredwolff I’m sure you saw it in the log, the error specifically is: Error caught in parse_stat_response: Key not found: 'rc'\n\textra: [Probes./dev/tty.usbserial-510] [ModemUARTDFUProbe] Unknown runtime error: Found end of content before end of string.\n\textra: [HighLevel] Failed programming the device."

jaredwolff · Nov 24, 2024

I did see the errors yes.

Usually on Mac the device shows up as /dev/tty.SLAB_USBtoUART are you sure you’re using the right port? I assume you loaded the mfw update firmware without an issue? Make sure you close all open console sessions (serial port logging etc) as it will interfere.

rabarar · Nov 25, 2024

@jaredwolff - okay I found the issue. If you download the firmware link from the nordic page, it will automatically uncompressed and leave a folder of the items in your download directory. Typically, one just recompresses the folder to restore a zip archive. But that is what created an issue as it likely added an OSX-Specification artifact to the zip file. On a hunch, I thought I’d try grabbing the zip file with wget and see if that made a difference. And indeed it did and everything worked as expected … may be worth adding a caveat to the docs for MacOS … btw - the device on OSX is /dev/tty.usbserial-510

After updating the firmware, reloading the at_client app, I can confirm that the new firmware is installed:

at
OK
AT+CGMR
mfw_nrf9160_1.3.7
OK

jaredwolff · Nov 25, 2024

Ahh yea tricky! Glad you got it straightened out