NRF_CLOUD_FOTA_REJECTED not handled

[govert-overgaauw-ampel]

I am testing if the firmware correctly rejects incorrectly signed images and noticed the following things. I don't think it is related to the images, as I cannot reproduce it every time with an incorrect image (most of the times it downloads the update and MCUboot invalidates the update and the cloud sees update completed). I have seen in my fleet with an update that 2 out of 25 modules where stuck in firmware update mode over a long time, so I think it is a stability thing.

1. NRF_CLOUD_FOTA_REJECTED event is not handled causing the FOTA module state machine to get stuck.
2. I managed to get the following error once:

[00:10:18.439,788] fota: state_polling_for_update_entry: Job available, FOTA processing started
[00:10:18.439,880] fota: state_downloading_update_entry: state_downloading_update_entry
[00:10:18.765,472] downloader: Setting up TLS credentials, sec tag count 1
[00:10:18.766,357] downloader: Connecting to 2600:1f18:56ff:3d02::ffc5 [00:10:18.766,845] downloader: Failed to connect on IPv6 (err -118), attempting IPv4
[00:10:19.045,776] downloader: Setting up TLS credentials, sec tag count 1
[00:10:19.046,081] downloader: Connecting to 54.145.71.75
[00:10:22.754,241] downloader: Downloaded 1024/44636 bytes (2%)
[00:10:22.754,333] fota_download: Refuse fragment, restart with offset
[00:10:22.768,005] cloud: handle_metrics_msg: Wake up reason: 1
[00:10:23.754,608] fota_download: Downloading from offset: 0x5b400
[00:10:23.770,965] downloader: Setting up TLS credentials, sec tag count 1
[00:10:23.777,770] downloader: Connecting to 2600:1f18:56ff:3d02::ffc5
[00:10:23.784,759] downloader: Failed to connect on IPv6 (err -118), attempting IPv4
[00:10:23.798,004] downloader: Setting up TLS credentials, sec tag count 1
[00:10:23.804,718] downloader: Connecting to 54.145.71.75
[00:10:27.526,947] downloader: Server responded with code 0x80
[00:10:27.528,594] downloader: Setting up TLS credentials, sec tag count 1
[00:10:27.528,930] downloader: Connecting to 54.145.71.75
[00:10:30.941,650] downloader: Server responded with code 0x80
[00:10:30.943,603] downloader: Setting up TLS credentials, sec tag count 1
[00:10:30.943,908] downloader: Connecting to 54.145.71.75
[00:10:34.327,270] downloader: Server responded with code 0x80
[00:10:34.329,010] downloader: Setting up TLS credentials, sec tag count 1
[00:10:34.329,528] downloader: Connecting to 54.145.71.75
[00:10:37.833,831] downloader: Server responded with code 0x80
[00:10:37.835,815] downloader: Setting up TLS credentials, sec tag count 1
[00:10:37.836,120] downloader: Connecting to 54.145.71.75
[00:10:41.426,086] downloader: Server responded with code 0x80
[00:10:41.427,856] downloader: Setting up TLS credentials, sec tag count 1

[00:10:22.754,333] fota_download: Refuse fragment, restart with offset
causes the downloader to go into an endless cycle connecting and failing (seems a bug in the NRF SDK?).

[simensrostad]

Thanks, PR for handling the rejection event:
#486

@govert-overgaauw-ampel It would be much appreciated if you could verify it.

Looking into the endless cycle scenario.

[simensrostad]

Regarding the endless cycle scenario, I'm patching in @SyverHaraldsen as he has worked on the retry-mechanism during FOTA in NCS just recently.

[SyverHaraldsen]

Hey @govert-overgaauw-ampel, thanks for pointing this out.
I see from your logs that you try to resume from offset 0x5b400, which is larger than the requested FOTA file size of 44636.
The DFU target is only reset if the requested FOTA URI differs from the cached URI, so could you check whether those URIs are identical in the failing case?

It also appears we may be lacking proper handling of situations where the cached offset is larger than the requested FOTA, which could lead to the server responding with COAP_RESPONSE_CODE_BAD_REQUEST, followed by the client repeatedly reconnecting and retrying.