nrfutil BLE DFU fails with Timeout: operation - Execute

This is with the nRF 5 SDK (17.0.2) and the S113 softdevice. 

We have another microcontroller connected to the nRF52833 over UART and external flash. We modified the bootloader on the nRF52 to store an external app on the external flash and then update the other micro.  We're inconsistently getting getting a timeout excepting when testing the OTA process when using nrfutil.exe.  And this problem (best we can tell) only exists with nrfutil.  nRF Connect (mobile app and desktop) work very reliably. 

The log output from nrfutil also shows that the binary for the external microcontroller is getting fully sent out.  The timeout exception is happening when the nRF52833 is transfering the firmware from external flash to the external microcontroller. 

Here's the log output from nrfutil, starting with the last BLE transfer of the binary.

2022-06-20T14:07:26.4625373Z 2022-06-20 10:07:06,123 Call ble_gattc_write: response(None) write_params(Write Params write_op(BLEGattWriteOperation.write_cmd) flags(BLEGattExecWriteFlag.prepared_cancel) handle(13) offset(0) data([0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 69, 65, 0, 0, 33, 65, 0, 0]))
2022-06-20T14:07:26.4625935Z 2022-06-20 10:07:06,151 evt> gattc_evt_write_cmd_tx_complete conn(0)
2022-06-20T14:07:26.4626126Z  count(1)
2022-06-20T14:07:26.4626326Z 2022-06-20 10:07:06,180 evt> gattc_evt_write_cmd_tx_complete conn(0)
2022-06-20T14:07:26.4626517Z  count(1)
2022-06-20T14:07:26.4626715Z 2022-06-20 10:07:06,209 evt> gattc_evt_write_cmd_tx_complete conn(0)
2022-06-20T14:07:26.4626908Z  count(1)
2022-06-20T14:07:26.4627096Z 2022-06-20 10:07:06,270 evt> on_gattc_evt_write_rsp conn(0)
2022-06-20T14:07:26.4627311Z  status(BLEGattStatusCode.success)
2022-06-20T14:07:26.4627469Z  error_handle(0)
2022-06-20T14:07:26.4627605Z  attr_handle(15)
2022-06-20T14:07:26.4627777Z  write_op(BLEGattWriteOperation.write_req)
2022-06-20T14:07:26.4627937Z  offset(0)
2022-06-20T14:07:26.4628062Z  data([])
2022-06-20T14:07:26.4628280Z 2022-06-20 10:07:06,272 evt> on_gattc_evt_hvx status(BLEGattStatusCode.success) conn(0)
2022-06-20T14:07:26.4628501Z  error_handle(0)
2022-06-20T14:07:26.4628642Z  attr_handle(15)
2022-06-20T14:07:26.4628805Z  hvx_type(BLEGattHVXType.notification)
2022-06-20T14:07:26.4628998Z  data([96, 3, 1, 152, 140, 0, 0, 12, 57, 6, 8])
2022-06-20T14:07:26.4629219Z 2022-06-20 10:07:06,330 evt> on_gattc_evt_write_rsp conn(0)
2022-06-20T14:07:26.4629433Z  status(BLEGattStatusCode.success)
2022-06-20T14:07:26.4629715Z  error_handle(0)
2022-06-20T14:07:26.4629855Z  attr_handle(15)
2022-06-20T14:07:26.4630027Z  write_op(BLEGattWriteOperation.write_req)
2022-06-20T14:07:26.4630187Z  offset(0)
2022-06-20T14:07:26.4630305Z  data([])
2022-06-20T14:07:26.4630454Z Traceback (most recent call last):
2022-06-20T14:07:26.4630673Z   File "nordicsemi\dfu\dfu_transport_ble.py", line 662, in __get_response
2022-06-20T14:07:26.4630890Z   File "queue.py", line 179, in get
2022-06-20T14:07:26.4631154Z _queue.Empty
2022-06-20T14:07:26.4631217Z
2022-06-20T14:07:26.4631399Z During handling of the above exception, another exception occurred:
2022-06-20T14:07:26.4631519Z
2022-06-20T14:07:26.4631657Z Traceback (most recent call last):
2022-06-20T14:07:26.4631857Z   File "nordicsemi\__main__.py", line 1545, in <module>
2022-06-20T14:07:26.4632064Z   File "click\core.py", line 1137, in __call__
2022-06-20T14:07:26.4632255Z   File "click\core.py", line 1062, in main
2022-06-20T14:07:26.4632447Z   File "click\core.py", line 1668, in invoke
2022-06-20T14:07:26.4632646Z   File "click\core.py", line 1668, in invoke
2022-06-20T14:07:26.4632839Z   File "click\core.py", line 1404, in invoke
2022-06-20T14:07:26.4633029Z   File "click\core.py", line 763, in invoke
2022-06-20T14:07:26.4633224Z   File "nordicsemi\__main__.py", line 1207, in ble
2022-06-20T14:07:26.4633444Z   File "nordicsemi\dfu\dfu.py", line 127, in dfu_send_images
2022-06-20T14:07:26.4633675Z   File "nordicsemi\dfu\dfu.py", line 100, in _dfu_send_image
2022-06-20T14:07:26.4633919Z   File "nordicsemi\dfu\dfu_transport_ble.py", line 574, in send_firmware
2022-06-20T14:07:26.4634169Z   File "nordicsemi\dfu\dfu_transport_ble.py", line 607, in __execute
2022-06-20T14:07:26.4634423Z   File "nordicsemi\dfu\dfu_transport_ble.py", line 664, in __get_response
2022-06-20T14:07:26.4634696Z pc_ble_driver_py.exceptions.NordicSemiException: Timeout: operation - Execute
2022-06-20T14:07:26.4634962Z [9840] Failed to execute script '__main__' due to unhandled exception!

Parents Reply Children
Related