Problem doing full modem update on nrf9160 over the air

Hi

I am trying to perform a full modem update on my nrf9160 DK board.

I started at v1.3.4 and successfully used the partial update method to go to 1.3.5

I then used partial update again to go to 1.3.6

I then tried to do a full update to 1.3.7 and this failed.

I loaded file firmware.update.image.cbor from the 1.3.7 download archive

I loaded it onto my server and triggered the download.

The download started and recognised a full firmware update

The download completed but failed with the following errors

[00:20:43.351,623] <inf> app_lwm2m_fsm: FOTA Update request for instance 0
[00:20:43.351,654] <inf> fota_download_full_modem: Applying full modem firmware update from external flash
[00:20:43.384,582] <err> net_echo_server_sample: UDP: Connection error 110
[00:20:43.384,613] <inf> net_echo_server_sample: process_udp ret=-110
[00:20:43.384,735] <err> lte_lc: Failed to enable eDRX, reported error: -12
[00:20:43.387,725] <err> fmfu_fdev: Unable to decode wrapper
[00:20:43.387,756] <err> fota_download_full_modem: fmfu_fdev_load failed: -22

I've attached the full log showing current HW and FW versions of the modem, the start of the transfer and the end of the transfer.

Any ideas

*** Using Zephyr OS v3.6.99-100befc70c74 ***
[00:00:01.147,827] <inf> operations: operations_init
[00:00:01.150,329] <inf> app_lwm2m_client: Run LWM2M client
[00:00:01.150,390] <inf> littlefs_handler: Area 0 at 0x0 on mx25r6435f@1 for 1048576 bytes
[00:00:01.150,421] <inf> littlefs_handler: /lfs1 automounted
[00:00:06.887,725] <inf> littlefs_handler: /lfs1: bsize = 16 ; frsize = 4096 ; blocks = 256 ; bfree = 59
[00:00:07.130,371] <inf> app_modem_mgmt: Initialised modem library
[00:00:07.130,401] <inf> app_modem_mgmt: Initialised modem info
[00:00:07.130,950] <inf> app_modem_mgmt: AT%HWVERSION ret=0 response=%HWVERSION: nRF9160 SICA B1A
OK

[00:00:07.131,652] <inf> app_modem_mgmt: AT%SHORTSWVER ret=0 response=%SHORTSWVER: nrf9160_1.3.6
OK

[00:00:07.132,324] <inf> app_modem_mgmt: AT%XMODEMUUID ret=0 response=%XMODEMUUID: 3e926f75-d31b-4852-b394-8c13f5a8bb6e
OK

[00:00:07.133,026] <inf> app_modem_mgmt: endpoint: urn:imei:351901930692193
[00:00:07.133,056] <inf> app_modem_mgmt: subscribing to signal quality metrics
[00:00:07.139,678] <inf> app_modem_mgmt: AT%CESQ=1 ret=0 response=OK

[00:00:07.140,319] <inf> app_modem_mgmt: AT%XSNRSQ=1 ret=0 response=OK

[00:00:07.352,203] <inf> lwm2m_lte_notification: Registering ncell notification handler
[00:00:07.352,325] <inf> lwm2m_firmware: Image is confirmed OK
[00:00:07.358,886] <err> pdn: Failed to read PDP contexts, err -77
[00:00:07.358,947] <inf> app_lwm2m_client: APN: (-77) ""
[00:00:07.358,947] <inf> app_comms_mgmt: comms_link_connect_startup: starting connection
[00:00:07.359,405] <wrn> app_lwm2m_fsm: PSM mode requested
[00:00:07.359,436] <inf> app_lwm2m_fsm: Connecting to network using async
[00:00:07.398,681] <inf> modbus_serial: RTU timeout 1002 us
[00:00:07.398,712] <inf> app_comms_mgmt: comms_link_start_udp: starting UDP
[00:00:07.398,712] <inf> net_echo_server_sample: Starting UDP
[00:00:07.398,773] <inf> net_echo_server_sample: start_udp_proto
[00:00:07.399,414] <inf> net_echo_server_sample: Waiting for UDP packets on port 4242...
[00:00:07.400,512] <inf> operations_sms: sms_register_listener returns 0
[00:00:07.400,543] <inf> app_gl_engine: GL Engine Init
[00:00:07.414,520] <err> fs: failed to create directory (-17)
[00:00:07.892,669] <err> fs: failed to create directory (-17)
[00:00:10.784,057] <inf> app_modem_mgmt: MON: rsrp=-109 dBm rsrq=-130 dB %CESQ: 31,1,13,1

[00:00:10.884,216] <inf> app_modem_mgmt: MON: snr=3 dB srx=15 cd=0 %XSNRSQ: 27,2,142,0

[00:00:10.984,497] <dbg> app_lwm2m_fsm: lwm2m_lte_reg_handler_notify: LTE NW status: 2
[00:00:11.451,873] <inf> app_modem_mgmt: MON: rsrp=-109 dBm rsrq=-155 dB %CESQ: 31,1,8,1

[00:00:12.729,614] <inf> app_modem_mgmt: MON: Received +CGEV notification: +CGEV: ME PDN ACT 0,0

[00:00:12.729,644] <inf> app_modem_mgmt: MON: Default PDP context activated
[00:00:12.930,755] <inf> app_modem_mgmt: Modem response:+CGDCONT: 0,"IP","eseye1","10.178.88.128",0,0
OK


----

00:05:53.677,246] <inf> fota_download_util: Download Path 0164228b host coap://lwm2m.cumulocity.com:5783
[00:05:53.678,619] <inf> download_client: Downloading: 0164228b [0]
[00:05:54.015,625] <inf> download_client: Connecting to 3.123.199.199
[00:05:54.420,135] <inf> download_client: Downloaded 512/2089453 bytes (0%)
[00:05:54.421,142] <inf> lwm2m_firmware: FOTA download started, target 4
[00:05:54.767,150] <inf> download_client: Downloaded 1024/2089453 bytes (0%)
[00:05:54.926,116] <inf> download_client: Downloaded 1536/2089453 bytes (0%)
[00:05:55.090,209] <inf> download_client: Downloaded 2048/2089453 bytes (0%)
[00:05:55.235,198] <inf> download_client: Downloaded 2560/2089453 bytes (0%)
[00:05:55.438,293] <inf> download_client: Downloaded 3072/2089453 bytes (0%)
[00:05:55.635,375] <inf> download_client: Downloaded 3584/2089453 bytes (0%)
[00:05:55.795,227] <inf> download_client: Downloaded 4096/2089453 bytes (0%)
[00:05:56.115,386] <inf> download_client: Downloaded 4608/2089453 bytes (0%)
[00:05:56.275,207] <inf> download_client: Downloaded 5120/2089453 bytes (0%)
[00:05:56.766,235] <inf> download_client: Downloaded 5632/2089453 bytes (0%)
[00:05:56.967,437] <inf> download_client: Downloaded 6144/2089453 bytes (0%)
[00:05:57.175,445] <inf> download_client: Downloaded 6656/2089453 bytes (0%)
[00:05:57.333,282] <inf> download_client: Downloaded 7168/2089453 bytes (0%)
[00:05:57.481,262] <inf> download_client: Downloaded 7680/2089453 bytes (0%)
[00:05:57.641,448] <inf> download_client: Downloaded 8192/2089453 bytes (0%)
[00:05:57.961,456] <inf> download_client: Downloaded 8704/2089453 bytes (0%)
[00:05:58.163,452] <inf> download_client: Downloaded 9216/2089453 bytes (0%)
[00:05:58.379,455] <inf> download_client: Downloaded 9728/2089453 bytes (0%)
[00:05:58.542,449] <inf> download_client: Downloaded 10240/2089453 bytes (0%)
[00:05:58.708,282] <inf> download_client: Downloaded 10752/2089453 bytes (0%)
[00:05:58.854,919] <inf> download_client: Downloaded 11264/2089453 bytes (0%)
[00:05:58.996,276] <inf> download_client: Downloaded 11776/2089453 bytes (0%)
[00:05:59.155,303] <inf> download_client: Downloaded 12288/2089453 bytes (0%)
[00:05:59.476,287] <inf> download_client: Downloaded 12800/2089453 bytes (0%)
[00:05:59.678,497] <inf> download_client: Downloaded 13312/2089453 bytes (0%)
[00:05:59.885,406] <inf> download_client: Downloaded 13824/2089453 bytes (0%)
[00:06:00.056,304] <inf> download_client: Downloaded 14336/2089453 bytes (0%)
[00:06:00.212,310] <inf> download_client: Downloaded 14848/2089453 bytes (0%)
[00:06:00.356,292] <inf> download_client: Downloaded 15360/2089453 bytes (0%)
[00:06:00.526,367] <inf> download_client: Downloaded 15872/2089453 bytes (0%)
[00:06:00.691,589] <inf> download_client: Downloaded 16384/2089453 bytes (0%)
[00:06:01.005,523] <inf> download_client: Downloaded 16896/2089453 bytes (0%)
[00:06:01.183,532] <inf> download_client: Downloaded 17408/2089453 bytes (0%)
[00:06:01.395,385] <inf> download_client: Downloaded 17920/2089453 bytes (0%)
[00:06:01.555,389] <inf> download_client: Downloaded 18432/2089453 bytes (0%)
[00:06:01.715,545] <inf> download_client: Downloaded 18944/2089453 bytes (0%)
[00:06:01.907,562] <inf> download_client: Downloaded 19456/2089453 bytes (0%)
[00:06:02.130,401] <inf> download_client: Downloaded 19968/2089453 bytes (0%)
[00:06:02.297,454] <inf> download_client: Downloaded 20480/2089453 bytes (0%)
[00:06:02.606,994] <inf> download_client: Downloaded 20992/2089453 bytes (1%)
[00:06:02.787,384] <inf> download_client: Downloaded 21504/2089453 bytes (1%)
[00:06:02.915,588] <inf> download_client: Downloaded 22016/2089453 bytes (1%)
[00:06:03.075,592] <inf> download_client: Downloaded 22528/2089453 bytes (1%)
[00:06:03.278,564] <inf> download_client: Downloaded 23040/2089453 bytes (1%)
[00:06:03.475,463] <inf> download_client: Downloaded 23552/2089453 bytes (1%)
[00:06:03.647,460] <inf> download_client: Downloaded 24064/2089453 bytes (1%)
[00:06:03.796,447] <inf> download_client: Downloaded 24576/2089453 bytes (1%)
[00:06:


[00:20:36.631,530] <inf> download_client: Downloaded 2085888/2089453 bytes (99%)
[00:20:36.791,656] <inf> download_client: Downloaded 2086400/2089453 bytes (99%)
[00:20:36.967,559] <inf> download_client: Downloaded 2086912/2089453 bytes (99%)
[00:20:37.134,246] <inf> download_client: Downloaded 2087424/2089453 bytes (99%)
[00:20:37.362,762] <inf> download_client: Downloaded 2087936/2089453 bytes (99%)
[00:20:37.523,223] <inf> download_client: Downloaded 2088448/2089453 bytes (99%)
[00:20:37.672,210] <inf> download_client: Downloaded 2088960/2089453 bytes (99%)
[00:20:37.991,760] <inf> download_client: Downloaded 2089453/2089453 bytes (100%)
[00:20:37.991,851] <inf> download_client: Download complete
[00:20:37.991,851] <inf> dfu_target_full_modem: Modem firmware downloaded to flash device
[00:20:38.099,975] <inf> lwm2m_firmware: FOTA download finished
[00:20:38.299,194] <inf> app_lwm2m_fsm: FOTA download ready for instance 0, dfu_type 4
[00:20:38.391,418] <dbg> app_lwm2m_fsm: rd_client_event: Registration update started
[00:20:39.033,905] <inf> net_lwm2m_engine: Connected, sock id 2
[00:20:39.325,500] <inf> net_lwm2m_rd_client: Update callback (code:2.4)
[00:20:39.325,561] <dbg> app_lwm2m_fsm: rd_client_event: Registration update complete
[00:20:39.325,592] <inf> net_lwm2m_rd_client: Update Done
[00:20:41.351,470] <inf> app_lwm2m_fsm: FOTA Update request for instance 0
[00:20:41.351,501] <inf> lwm2m_firmware: Delay 2 s Update instance 0 
[00:20:41.351,776] <inf> app_lwm2m_fsm: lwm2m: client state UPDATE_FIRMWARE
[00:20:41.351,837] <inf> net_lwm2m_rd_client: Stop LWM2M Client: urn:imei:351901930692193
[00:20:41.551,452] <err> net_echo_server_sample: UDP: Connection error 115
[00:20:41.551,483] <inf> net_echo_server_sample: process_udp ret=-115
[00:20:41.552,368] <inf> app_modem_mgmt: MON: Received +CGEV notification: +CGEV: ME PDN DEACT 0

[00:20:41.552,429] <inf> app_lwm2m_client: PDN: cid=0 event=2 reason=0
[00:20:41.652,618] <dbg> app_lwm2m_fsm: lwm2m_lte_reg_handler_notify: LTE NW status: 0
[00:20:41.752,593] <inf> app_modem_mgmt: MON: Received +CGEV notification: +CGEV: ME DETACH

[00:20:41.752,655] <inf> app_lwm2m_client: PDN: cid=0 event=5 reason=0
[00:20:42.551,544] <inf> net_echo_server_sample: start_udp_proto
[00:20:42.560,943] <inf> net_echo_server_sample: Waiting for UDP packets on port 4242...
[00:20:42.984,008] <inf> app_modem_mgmt: MON: rsrp=115 dBm rsrq=1080 dB %CESQ: 255,0,255,0

[00:20:43.084,014] <inf> app_modem_mgmt: MON: snr=103 dB srx=32640 cd=255 %XSNRSQ: 127,0,32767,255

[00:20:43.351,623] <inf> app_lwm2m_fsm: FOTA Update request for instance 0
[00:20:43.351,654] <inf> fota_download_full_modem: Applying full modem firmware update from external flash
[00:20:43.384,582] <err> net_echo_server_sample: UDP: Connection error 110
[00:20:43.384,613] <inf> net_echo_server_sample: process_udp ret=-110
[00:20:43.384,735] <err> lte_lc: Failed to enable eDRX, reported error: -12
[00:20:43.387,725] <err> fmfu_fdev: Unable to decode wrapper
[00:20:43.387,756] <err> fota_download_full_modem: fmfu_fdev_load failed: -22
[00:20:43.707,214] <inf> app_lwm2m_fsm: FOTA failure 0 by status 8
[00:20:43.707,244] <wrn> app_lwm2m_fsm: FOTA unexpected new event type MODEM_RECONNECT
[00:20:44.384,674] <inf> net_echo_server_sample: start_udp_proto
[00:20:44.384,735] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:44.384,765] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:45.384,826] <inf> net_echo_server_sample: start_udp_proto
[00:20:45.384,918] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:45.384,918] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:46.385,009] <inf> net_echo_server_sample: start_udp_proto
[00:20:46.385,070] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:46.385,070] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:47.385,162] <inf> net_echo_server_sample: start_udp_proto
[00:20:47.385,223] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:47.385,253] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:48.385,345] <inf> net_echo_server_sample: start_udp_proto
[00:20:48.385,406] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:48.385,406] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:49.385,498] <inf> net_echo_server_sample: start_udp_proto
[00:20:49.385,559] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:49.385,589] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:50.385,681] <inf> net_echo_server_sample: start_udp_proto
[00:20:50.385,742] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:50.385,742] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:51.385,833] <inf> net_echo_server_sample: start_udp_proto
[00:20:51.385,894] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:51.385,925] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:52.386,016] <inf> net_echo_server_sample: start_udp_proto
[00:20:52.386,077] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:52.386,077] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:53.386,169] <inf> net_echo_server_sample: start_udp_proto
[00:20:53.386,260] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:53.386,260] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
[00:20:54.386,352] <inf> net_echo_server_sample: start_udp_proto
[00:20:54.386,413] <err> net_echo_server_sample: Failed to create UDP socket: 105
[00:20:54.386,413] <wrn> net_echo_server_sample: start_udp_proto waiting 1s
uart:~$

Parents Reply Children
No Data
Related