ESP32 Forum

ESP32 Official Forum
http://esp32.io/

OTA failed : "image at 0x180000 has invalid magic byte error" in Secure boot Flash encryption

http://esp32.io/viewtopic.php?f=13&t=21314

Page 1 of 1

OTA failed : "image at 0x180000 has invalid magic byte error" in Secure boot Flash encryption

Posted: Mon Jun 07, 2021 6:17 am
by Raghav Jha
Hello,
I implemented the secure boot and flash encryption on the device. When I was performing the OTA I got at
image at 0x180000 has invalid magic byte error
. I was using the encrypted .bin file for OTA.

Here is my partition table:

Code: Select all

# Name,   Type, SubType, Offset,  Size, Flags
# Note: if you change the phy_init or app partition offset, make sure to change the offset in Kconfig.projbuild,,,,
nvs,      data, nvs,     0x14000,  0x6000,
otadata,  data, ota, ,  0x2000,
phy_init, data, phy,  ,  0x1000,
factory,0,    factory,,  1400K,
ota_0,0,    ota_0,   ,         1400K,
ota_1,0,    ota_1,   ,         200K,
file,  data,spiffs,     ,0x6000,
Error Log:

Code: Select all

1172 23222 [OTA Agent Task] [INFO ][MQTT][232220] (MQTT connection 0x3ffb5f30) MQTT PUBLISH operation queued.
1173 23222 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/FW_246F2824E888/streams/AFR_OTA-042eecf3-3b72-49ed-b19e-e3b374752a1e/get/cbor
1174 23222 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock] 
1175 23253 [OTA Agent Task] [prvIngestDataBlock] Received file block 248, size 4096
1176 23254 [OTA Agent Task] [prvIngestDataBlock] Remaining: 5
1177 23254 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
1178 23265 [OTA Agent Task] [prvIngestDataBlock] Received file block 250, size 4096
1179 23266 [OTA Agent Task] [prvIngestDataBlock] Remaining: 4
1180 23266 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
1181 23273 [iot_thread] State: WaitingForFileBlock  Received: 252   Queued: 0   Processed: 0   Dropped: 0
1182 23277 [OTA Agent Task] [prvIngestDataBlock] Received file block 249, size 4096
1183 23278 [OTA Agent Task] [prvIngestDataBlock] Remaining: 3
1184 23278 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
1185 23289 [OTA Agent Task] [prvIngestDataBlock] Received file block 251, size 4096
1186 23290 [OTA Agent Task] [prvIngestDataBlock] Remaining: 2
1187 23290 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
Current Epoch Time: [ 1622486890 ]
Epoch Start Time: [ 1622486668 ]
Value of config bootloader num pin factory reset 0
1188 23303 [OTA Agent Task] [prvIngestDataBlock] Received file block 252, size 4096
1189 23304 [OTA Agent Task] [prvIngestDataBlock] Remaining: 1
1190 23304 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
1191 23312 [OTA Agent Task] [prvIngestDataBlock] Received file block 253, size 2352
I (233290) ota_pal: No such certificate file: certs/device. Using aws_ota_codesigner_certificate.h.

1192 23313 [OTA Agent Task] [prvIngestDataBlock] Received final expected block of file.
1193 23313 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer.
1194 23383 [iot_thread] State: WaitingForFileBlock  Received: 256   Queued: 0   Processed: 0   Dropped: 0
Current Epoch Time: [ 1622486891 ]
Epoch Start Time: [ 1622486668 ]
Value of config bootloader num pin factory reset 0
1195 23416 [OTA Agent Task] [prvIngestDataBlock] File receive complete and signature is valid.
1196 23416 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer.
1197 23416 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] Msg: {"status":"IN_PROGRESS","statusDetails":{"self_test":"ready","updatedBy":"0x1020024"}}
1198 23416 [OTA Agent Task] [INFO ][MQTT][234160] (MQTT connection 0x3ffb5f30) MQTT PUBLISH operation queued.
1199 23416 [OTA Agent Task] [INFO ][MQTT][234160] (MQTT connection 0x3ffb5f30, PUBLISH operation 0x3ffd8028) Waiting for operation completion.
E (234600) esp_image: image at 0x180000 has invalid magic byte
E (234600) boot_comm: mismatch chip ID, expected 0, found 32025
E (234600) boot_comm: can't run on lower chip revision, expected 1, found 37
W (234610) esp_image: image at 0x180000 has invalid SPI mode 103
W (234620) esp_image: image at 0x180000 has invalid SPI size 6
E (234630) ota_pal: aws_esp_ota_end failed!
1200 23444 [OTA Agent Task] [INFO ][MQTT][234440] (MQTT connection 0x3ffb5f30, PUBLISH operation 0x3ffd8028) Wait complete with result SUCCESS.
1201 23444 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] 'IN_PROGRESS' to $aws/things/FW_246F2824E888/jobs/AFR_OTA-OTA-SecureBoot2/update
Current Epoch Time: [ 1622486892 ]ed eOTA_JobEvent_Activate callback from OTA Agent.
Epoch Start Time: [ 1622486668 ]
Value of config bootloader num pin factory reset 0
1203 23501 [iot_thread] State: WaitingForFileBlock  Received: 256   Queued: 0   Processed: 0   Dropped: 0
Current Epoch Time: [ 1622486893 ]
Epoch Start Time: [ 1622486668 ]
Value of config bootloader num pin factory reset 0
1204 23630 [iot_thread] State: WaitingForFileBlock  Received: 256   Queued: 0   Processed: 0   Dropped: 0
Current Epoch Time: [ 1622486894 ]
Epoch Start Time: [ 1622486668 ]
Value of config bootloader num pin factory reset 0
1205 23750 [iot_thread] State: WaitingForFileBlock  Received: 256   Queued: 0   Processed: 0   Dropped: 0
Current Epoch Time: [ 1622486895 ]
Epoch Start Time: [ 1622486668 ]
Value of config bootloader num pin factory reset 0
1206 23866 [iot_thread] State: WaitingForFileBlock  Received: 256   Queued: 0   Processed: 0   Dropped: 0
I (238900) wifi: state: run -> init (0)
I (238900) wifi: pm stop, total sleep time: 184187776 us / 234073527 us

I (238900) wifi: new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1
iot_wifi 95-event handler
I (238900) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8
iot_wifi 95-event handler
I (238910) BTDM_INIT: BT controller compile version [9891bc6]
I (238920) wifi: flush txq
I (238920) wifi: stop sw txq
What does this error mean? How can solve this?

Re: OTA failed : "image at 0x180000 has invalid magic byte error" in Secure boot Flash encryption

Posted: Tue Jun 08, 2021 12:39 am
by ESP_Angus
Hi Raghav,

The ESP-IDF OTA mechanism relies on receiving the plaintext image via OTA, and it's then encrypted using the internal flash encryption hardware as it it is written to flash. This is why you see these errors, the firmware doesn't recognize the .bin file as a valid format.

We don't currently have a supported way to distribute a pre-encrypted image via OTA, we're working on such an approach but at the moment we recommend the server authenticates the device and then uses a secure channel (like TLS) to send the firmware.

Angus

Re: OTA failed : "image at 0x180000 has invalid magic byte error" in Secure boot Flash encryption

Posted: Tue Jun 08, 2021 6:05 pm
by Raghav Jha
Hello @ESP_Angus

I tried with plain-text .bin file to do OTA but some error I got.
In the log, you can see some flash offset problem.

Code: Select all

E (552870) esp_ota_ops: size should be 16byte aligned for flash encryption case
What does this mean?

Code: Select all

1361 55181 [OTA Agent Task] [prvIngestDataBlock] Received file block 312, size 4096
1362 55182 [OTA Agent Task] [prvIngestDataBlock] Remaining: 2
1363 55182 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
1364 55242 [OTA Agent Task] [prvIngestDataBlock] Received file block 313, size 4096
1365 55243 [OTA Agent Task] [prvIngestDataBlock] Remaining: 1
1366 55243 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
E (552870) esp_ota_ops: size should be 16byte aligned for flash encryption case
E (552870) ota_pal: Couldn't flash at the offset 1286144
I (552880) ota_pal: prvPAL_SetPlatformImageState, 3
W (552880) ota_pal: Set image as invalid!
I (552890) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
W (552890) esp_ota_ops: otadata partition is invalid, factory/ota_0 is boot partition
E (552900) ota_pal: currently executing firmware not marked as valid, abort
1367 55283 [OTA Agent Task] [prvIngestDataBlock] Received file block 314, size 3364
1368 55284 [OTA Agent Task] [prvIngestDataBlock] Error (-1) writing file block
1369 55284 [OTA Agent Task] [prvIngestDataBlock] Remaining: 1
1370 55284 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer.
1371 55284 [OTA Agent Task] [prvProcessDataMessage] Aborting due to IngestResult_t error -9
1372 55287 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] Msg: {"status":"FAILED","statusDetails":{"reason":"0x27000000: 0xfffffff7"}}
1373 55287 [OTA Agent Task] [INFO ][MQTT][552870] (MQTT connection 0x3ffb40ec) MQTT PUBLISH operation queued.
1374 55287 [OTA Agent Task] [INFO ][MQTT][552870] (MQTT connection 0x3ffb40ec, PUBLISH operation 0x3ffdbd98) Waiting for operation completion.
1375 55303 [OTA Agent Task] [INFO ][MQTT][553030] (MQTT connection 0x3ffb40ec, PUBLISH operation 0x3ffdbd98) Wait complete with result SUCCESS.
1376 55303 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] 'FAILED' to $aws/things/FW_246F2824E888/jobs/AFR_OTA-SecureBoot-7/update
1377 55303 [OTA Agent Task] Received eOTA_JobEvent_Fail callback from OTA Agent.
1378 55303 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 
1379 55303 [OTA Agent Task] [prvOTA_Close] Context->0x0x3ffbf850
1380 55303 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [CloseFile] New state [WaitingForJob] 
I (553690) ota_pal: prvPAL_SetPlatformImageState, 4
W (553690) ota_pal: Set image as aborted!
I (553690) esp_ota_ops: aws_esp_ota_get_boot_flags: 1
W (553700) esp_ota_ops: otadata partition is invalid, factory/ota_0 is boot partition
E (553700) ota_pal: currently executing firmware not marked as valid, abort
1381 55365 [OTA Agent Task] [prvParseJobDoc] Size of OTA_FileContext_t [64]
1382 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: execution
1383 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: jobId
1384 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: jobDocument
1385 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: afr_ota
1386 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: protocols
1387 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: files
1388 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: filepath
1389 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: filesize
1390 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: fileid
1391 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: certfile
1392 55365 [OTA Agent Task] [prvParseJSONbyModel] parameter not present: sig-sha256-ecdsa
1393 55365 [OTA Agent Task] [prvDefaultCustomJobCallback] Received Custom Job inside OTA Agent which is not supported.
1394 55365 [OTA Agent Task] [prvParseJobDoc] Ignoring job without ID.
1395 55365 [OTA Agent Task] [prvOTA_Close] Context->0x0x3fff6da0
1396 55367 [OTA Agent Task] [prvOTAAgentTask] Handler failed. Current State [WaitingForJob] Event  [ReceivedJobDocument] Error Code [603979776] 
1397 55402 [iot_thread] State: WaitingForFileBlock  Received: 318   Queued: 0   Processed: 0   Dropped: 0

Re: OTA failed : "image at 0x180000 has invalid magic byte error" in Secure boot Flash encryption

Posted: Tue Jun 08, 2021 6:29 pm
by chegewara
You have few not related issues here:
1) partition ota1 is only 200kB is size, i doubt you have any app that will fit it, especially AWSFreeRTOS app
2) for some reason your app is trying to flash at offset 1286144, which is incorrect (not 4 bytes aligned) and you should ask on AWS github repo

Code: Select all

E (552870) ota_pal: Couldn't flash at the offset 1286144
3) 1393 55365 [OTA Agent Task] [prvDefaultCustomJobCallback] Received Custom Job inside OTA Agent which is not supported.

Re: OTA failed : "image at 0x180000 has invalid magic byte error" in Secure boot Flash encryption

Posted: Sat Jul 31, 2021 1:52 pm
by Raghav Jha
hello developers,

I have created the issue ticked on this issue at the amazon-freertos repository,

Here is the link https://github.com/aws/amazon-freertos/issues/3215

Theys says I need to check the tools that generate the OTA image or check the linker to do the padding, so the .bin size will be 16bit align.

So, can you tell me which tool generate the OTA image or which linked do the padding so the image size will be 16bit aligned?

Thanks!
All times are UTC
Page 1 of 1
Powered by phpBB® Forum Software © phpBB Limited
https://www.phpbb.com/