ESP32S3 FOTA using GSM Module

[snehapawar#]

Hello All,

I am using esp32s-esp-idf for my project, and in our application, have successfully implemented wifi-OTA.

Now, as a feature, am trying to do fota using questel's gsm module.



-ESP32S
-ESP-IDF v1.5.1
-Quectel's BG95
-partition table
nvs, 0x01, nvs, 0x11000, 0x8000,
otadata, 0x01, ota, 0x19000, 0x2000,
phy_init, 0x01, phy, 0x21000, 0x3000,
ota_0, 0x00, ota_0, 0x110000, 0x140000,
ota_1, 0x00, ota_1, 0x250000, 0x140000,
fatfs_storage, 0x01, fat, , 4M,



Please find my flow of code.
-http get request using gsm modem
-download .bin file from aws s3 server(successfully)
-this file is saved in Quectel's file system
-read file data of 1kb at a time and flash into esp(got no error while writing to flash)
-when esp_ota_end(update_handle) is been called, got error as 'ESP_ERR_OTA_VALIDATE_FAILED' i.e. 'Image validation failed, image is corrupted'





fota failure reply for BIN FILE(1)
I (424428) esp_image: segment 0: paddr=00250020 vaddr=3c0e0020 size=31960h (203104) map
I (424508) esp_image: segment 1: paddr=00281988 vaddr=3fc988f0 size=03d2ch ( 15660)
I (424518) esp_image: segment 2: paddr=002856bc vaddr=40374000 size=0a95ch ( 43356)
I (424538) esp_image: segment 3: paddr=00290020 vaddr=42000020 size=da4c0h (894144) map
I (424868) esp_image: segment 4: paddr=0036a4e8 vaddr=4037e95c size=09f88h ( 40840)
I (424888) esp_image: segment 5: paddr=00374478 vaddr=50000000 size=011fch ( 4604)
I (424888) esp_image: segment 6: paddr=0037567c vaddr=50001200 size=007c8h ( 1992)
I (424888) esp_image: segment 7: paddr=00375e4c vaddr=600fe000 size=00150h ( 336)
E (424898) esp_image: Checksum failed. Calculated 0xc7 read 0x61
Image validation failed, image is corrupted
Exiting task due to fatal error...
ERROR - FOTA ... failed!


fota failure reply for BIN FILE(2)
I (2262510) esp_image: segment 0: paddr=00250020 vaddr=3c0e0020 size=317f8h (202744) map
I (2262590) esp_image: segment 1: paddr=00281820 vaddr=3fc988d0 size=03d2ch ( 15660)
I (2262600) esp_image: segment 2: paddr=00285554 vaddr=40374000 size=0aac4h ( 43716)
I (2262620) esp_image: segment 3: paddr=00290020 vaddr=42000020 size=d9b50h (891728) map
I (2262950) esp_image: segment 4: paddr=00369b78 vaddr=4037eac4 size=09e08h ( 40456)
I (2262970) esp_image: segment 5: paddr=00373988 vaddr=50000000 size=011fch ( 4604)
I (2262970) esp_image: segment 6: paddr=00374b8c vaddr=50001200 size=00788h ( 1928)
I (2262970) esp_image: segment 7: paddr=0037531c vaddr=600fe000 size=00150h ( 336)
E (2262980) esp_image: Checksum failed. Calculated 0x39 read 0x1c
Image validation failed, image is corrupted
Exiting task due to fatal error...
ERROR - FOTA ... failed!




does anyone has got such type of issue while doing fota???
Can anyone help me to resolve this issue??



-Sneha

[ESP_Sprite]

Suggest you use esptool.py to dump the OTA partition the OTA image was downloaded in and compare it to the actual OTA image. Most issues like this tend to be caused with the OTA server actually serving something else (error page, redirect page, ...) than the OTA image. (Although in your case, it seems to have downloaded at least the header of the image. Comparing still may give insights in what went wrong.)

[snehapawar#]

Hello,

@ESP_Sprite Thank you so much for the suggestion. Will check the comparison as you have suggested.
Will share what I get.



-Sneha

[snehapawar#]

Hello,

@ESP_Sprite As you suggested, i have used esptool and read OTA partition, in my case I wrote new .bin from 0x250000.

You are perfectly right. Even though i have received correct number of bytes from server with header(which am bypassing while actual writing in a ota partition), some of the data is been corrupted.
For example,
original .bin file has this:
3636 3138 2c35 3831 2e30 3130 3334 2c35
3432 2e38 3934 3437 2c30 2c33 3139 2e35
3430 3838 2d32 3333 2e39 3535 2c35 3432

But am getting(so writing) this:
3100 0000 4361 6368 6520 6469 7361 6200
0000 0000 0000 0000 0000 0000 0000 0000
0000 0000 0000 0000 0000 0000 0000 0000

likewise,
right one is this:
2e39 3037 3036 2d35 3831 2e30 3130 3334
2c35 3432 2e39 3037 3036 4833 3433 392e
3332 3335 5a6d 3433 352e 3337 3530 382c

and getting this:
7666 732f 7666 732e 6300 0000 7472 6100
0000 0000 0000 0000 0000 0000 0000 0000
0000 0000 0000 0000 0000 0000 0000 0000


As you can see, corrupted data always has first line of data wrong, and next two line of data as zero.



What and why is this??

How to resolve this issue.


Please guide me on this.

-Sneha

[ESP_Sprite]

Those responses in ASCII read 'vfs/vfc', 'tra' and 'Cache disab'. Those could be part of the OTA image, that can't be ruled out, but an alternative explanation is that you're getting some log messages from somewhere that you then interpret as data. Suggest looking closely at what goes over the serial line from/to the GSM modem.

[snehapawar#]

Hi
@ESP_Sprite

I compared both the files i.e. original .bin and 'ota partition read' .bin file in ascii.
Missing part is something like below, but why I don't get it..

I got this :
" rtc_clk_xtal_freq_get() == RTC_XTAL_FREQ_40M soc/esp32s3/clk.c res d'esp_clk_init vfs_err == ESP_OK && "Failed to register vfs console" /IDF/components/esp_system/startup.c /dev/console/ err == ESP_OK && "Failed to init pthread module!" flash_ret == ESP_OK [0;32mI (%u) %s: Pro cpu start user code[0m"

But expected was :
" rtc_clk_xtal_freq_get() == RTC_XTAL_FREQ_40M /IDF/components/esp_system/port/soc/esp32s3/clk.c res d'esp_clk_init vfs_err == ESP_OK && "Failed to register vfs console" /IDF/components/esp_system/startup.c /dev/console/ err == ESP_OK && "Failed to init pthread module!" flash_ret == ESP_OK [0;32mI (%u) %s: Pro cpu start user code[0m"

and got this :
" rtc_clk_xtal_freq_get() == RTC_XTAL_FREQ_40M /IDF/components/esp_system/port/soc/esp32s3/clk.c res d'esp_clk_init vfs_err == ESP_OK && "Failed to register vfs console" /IDF/components/esp_system/startup.c /dev/console/ err == ESP_OK && "Failed to init pthread module!" flash_ret == ESP_OK [0;32mI (%u) %s: Pro cpu start user code[0m"

and expected was :
" Icache preload parameter configuration error, the error address and size is 0x Dcache sync parameter configuration error, the error address and size is 0x Dcache preload parameter configuration error, the error address and size is 0x Write back error occurred while dcache tries to write back to flash"


As a flow, am transfering whole data at once using http-gsm modem to file of modem's file system, AT ONCE.
I am also thinking i might be the issue because of whole data saving to file at once, this process is command based, and handled by quectel(http and it's own file system) which i don't have a control of.

Experiment point of view, i would try to take chunk of data at a time from server and write directly to flash at a time.
Let's see, that way this problem will be resolved or not.


Let me know, if you have any idea to give it a try.

-Sneha

[snehapawar#]

Hi @ESP_Sprite,

Sorry for late reply.

below are the fota logs which is taken when fota is done using wifi and gsm modem.

-> Flash write log when WIFI:

Total Write binary data length: 1201296
I (56101) esp_image: segment 0: paddr=00250020 vaddr=3c0e0020 size=317f8h (202744) map
I (56181) esp_image: segment 1: paddr=00281820 vaddr=3fc988d0 size=03d2ch ( 15660)
I (56181) esp_image: segment 2: paddr=00285554 vaddr=40374000 size=0aac4h ( 43716)
I (56201) esp_image: segment 3: paddr=00290020 vaddr=42000020 size=d9b50h (891728) map
I (56531) esp_image: segment 4: paddr=00369b78 vaddr=4037eac4 size=09e08h ( 40456)
I (56551) esp_image: segment 5: paddr=00373988 vaddr=50000000 size=011fch ( 4604)
I (56551) esp_image: segment 6: paddr=00374b8c vaddr=50001200 size=00788h ( 1928)
I (56561) esp_image: segment 7: paddr=0037531c vaddr=600fe000 size=00150h ( 336)


-> Flash write log when GSM-Modem:

Total Write binary data length: 1201296
I (451949) esp_image: segment 0: paddr=00250020 vaddr=3c0e0020 size=317f8h (202744) map
I (452029) esp_image: segment 1: paddr=00281820 vaddr=3fc988d0 size=03d2ch ( 15660)
I (452039) esp_image: segment 2: paddr=00285554 vaddr=40374000 size=0aac4h ( 43716)
I (452059) esp_image: segment 3: paddr=00290020 vaddr=42000020 size=d9b50h (891728) map
I (452389) esp_image: segment 4: paddr=00369b78 vaddr=4037eac4 size=09e08h ( 40456)
I (452409) esp_image: segment 5: paddr=00373988 vaddr=50000000 size=011fch ( 4604)
I (452409) esp_image: segment 6: paddr=00374b8c vaddr=50001200 size=00788h ( 1928)
I (452409) esp_image: segment 7: paddr=0037531c vaddr=600fe000 size=00150h ( 336)
E (452419) esp_image: Checksum failed. Calculated 0x39 read 0x1c
Image validation failed, image is corrupted




As we can see, partition is been written correctly(number of data wise) in both ways, but checksum is failed in gsm-modem's case, In a wifi case, fota is done successfully.

As you have suggested, some data becomes corrupted while in a process( either when am writing into the file or am writing flash from file data, but as we can see checksum of original data is already been known for comparison, that means flash writing is getting corrupted while writing(????) )

How can I resolve this issue of corruption of data??

It's been a very long time, am stucked into this.

Any help would be appreciated.

Thanks in advance

[ESP_Sprite]

Given it's your code and I'm not familiar with that GSM modem, I can't give you any detailed pointers. What I'd do is try a divide-and-conquer approach. You know (presumably) the firmware is good when it is compiled on your machine. You also know it's bad when it is in the ESP32 partition. The processes in between are your machine -> server -> GSM modem -> ESP32 -> flash. So try to see if you can get a dump of the firmware at each of those steps and see if it's is corrupted at that point or not.

[snehapawar#]

Hi ESP_Sprite,

Thank you for your reply.
Will definitely try the approach you suggested, will share the results.

[snehapawar#]

Hello ESP_Sprite,

I changed data fetching routine from quectel BG95-M5 file to esp-flash. Now I am getting below error when writing is completed.

Total Write binary data length: 1201296
E (372229) boot_comm: mismatch chip ID, expected 9, found 0
Image validation failed, image is corrupted
Exiting task due to fatal error...


What is happening now??

How can I resolve this issue??


Please help.