gzUpdater fails - Githubissues

scubachristopher commented 3 years ago

Hi,

I'm provisioning new firmware updates via https server, downloading the gz to SPIFFS and (hopefully) using your library to update. It's failing, so went to your example and that fails. Here's the sketch:


void setup() {
  Serial.begin( 115200 );    
  Serial.printf("Initializing SPIFFS...\n");

  if (!SPIFFS.begin(false)) {
     Serial.printf("SPIFFS Mount Failed\n");
  }
  else {
    Serial.printf("SPIFFS Mount Successful\n");
  }
}

void loop() {
  bool done = false;

  while (!done) {
    delay(1000);
    if (SPIFFS.exists("/firmware.bin.gz")) {
      Serial.printf("Found file, about to update...\n");
      delay(1000);
      // flash the ESP with gz's contents (gzip the bin yourself and use the spiffs uploader)
      gzUpdater(SPIFFS, "/firmware.bin.gz");
      done = true;
    }
    else {
      Serial.printf("/firmware.bin.gz not found\n");
      break;
    }
  }
}

The binary I'm using is the output from this sketch. I use:

gzip --keep --best --force firmware.bin

Host OS doing the gzipping and serving, and gzip version:

$ cat /etc/os-release
NAME="Ubuntu"
VERSION="18.04.3 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.3 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
$ gzip --version
gzip 1.6

To prove the error, I gzip the firmware of this sketch, then build and upload a SPIFFS partition (also contains my certs / keys, so this is proven functional).

ls -al data/firmware.bin.gz ~/fw.bin 
-rw-r--r--  1 chris  staff  322144 Nov  8 10:56 /Users/chris/fw.bin
-rw-r--r--  1 chris  staff  146768 Nov  8 11:01 data/firmware.bin.gz

Here's the output of the run, which is the same as what I get with my program:

11:16:48.707 -> ⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮ets Jun  8 2016 00:22:57
11:16:48.707 -> 
11:16:48.707 -> rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
11:16:48.707 -> configsip: 0, SPIWP:0xee
11:16:48.707 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
11:16:48.707 -> mode:DIO, clock div:1
11:16:48.707 -> load:0x3fff0018,len:4
11:16:48.707 -> load:0x3fff001c,len:1216
11:16:48.707 -> ho 0 tail 12 room 4
11:16:48.707 -> load:0x40078000,len:9720
11:16:48.744 -> ho 0 tail 12 room 4
11:16:48.744 -> load:0x40080400,len:6352
11:16:48.744 -> entry 0x400806b8
11:16:48.883 -> Initializing SPIFFS...
11:16:48.983 -> SPIFFS Mount Successful
11:16:50.000 -> Found file, about to update...
11:16:50.999 -> uzLib SPIFFS Updater start!
11:16:51.033 -> gzip file detected ! gz size: 146768 bytes, expanded size:322144 bytes
11:16:51.071 -> Guru Meditation Error: Core  1 panic'ed (InstrFetchProhibited). Exception was unhandled.
11:16:51.071 -> Core 1 register dump:
11:16:51.071 -> PC      : 0x00000000  PS      : 0x00060530  A0      : 0x800d14ba  A1      : 0x3ffb1f10  
11:16:51.071 -> A2      : 0x3ffc00c8  A3      : 0x00000000  A4      : 0x3ffc15e4  A5      : 0x00008000  
11:16:51.071 -> A6      : 0x400d1208  A7      : 0x00000000  A8      : 0x800d140c  A9      : 0x3ffb1ef0  
11:16:51.071 -> A10     : 0x00000000  A11     : 0xffffffff  A12     : 0x00008000  A13     : 0x3ffbd4d4  
11:16:51.108 -> A14     : 0x3f400f10  A15     : 0x00000000  SAR     : 0x00000008  EXCCAUSE: 0x00000014  
11:16:51.108 -> EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000  
11:16:51.108 -> 
11:16:51.108 -> Backtrace: 0x00000000:0x3ffb1f10 0x400d14b7:0x3ffb1f30 0x400d11dd:0x3ffb1f90 0x400d39a9:0x3ffb1fb0 0x40088215:0x3ffb1fd0
11:16:51.108 -> 
11:16:51.108 -> Rebooting...
11:16:51.108 -> ets Jun  8 2016 00:22:57

Any support would be greatly appreciated.

tobozo commented 3 years ago

Thanks for your feedback.

There are some more information I'll need to get a better understanding of the situation:

SPIFFS partition size
Serial output when the application is flashed with "Core Debug Level" set to "Debug"
Decoded Exception using the ESP Exception decoder from the tools menu

Meanwhile I will try to reproduce the issue.

scubachristopher commented 3 years ago

@tobozo -- thanks for the rapid response!

I don't see an option for ESP Exception decoder. I'm using Arduino 2 on a Mac.

Board is a Heltec ESP LORA V2 (8MB). I use these two lines to build the spiffs bin and flash when manually uploading the firmware bin, as I did for this test:

/Users/chris/.platformio/packages/tool-mkspiffs/mkspiffs_espressif32_arduino -c ./data -p 256 -b 4096 -s 1638400 ./.pio/build/esp32dev/spiffs.bin
/Users/chris/.platformio/packages/tool-esptoolpy/esptool.py --chip esp32 --port /dev/cu.Repleo-CP2102-0001 --baud 460800 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_size detect 6750208 ./.pio/build/esp32dev/spiffs.bin

Partition map:

# Name,   Type, SubType, Offset,  Size, Flags
nvs,      data, nvs,     0x9000,  0x5000,
otadata,  data, ota,     0xe000,  0x2000,
app0,     app,  ota_0,   0x10000, 0x330000,
app1,     app,  ota_1,   0x340000,0x330000,
spiffs,   data, spiffs,  0x670000,0x190000,

Apologies, should have turned on debug logging:

12:19:46.738 -> ⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮⸮ets Jun  8 2016 00:22:57
12:19:46.738 -> 
12:19:46.738 -> rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
12:19:46.738 -> configsip: 0, SPIWP:0xee
12:19:46.738 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
12:19:46.738 -> mode:DIO, clock div:1
12:19:46.738 -> load:0x3fff0018,len:4
12:19:46.738 -> load:0x3fff001c,len:1216
12:19:46.738 -> ho 0 tail 12 room 4
12:19:46.738 -> load:0x40078000,len:9720
12:19:46.738 -> ho 0 tail 12 room 4
12:19:46.738 -> load:0x40080400,len:6352
12:19:46.738 -> entry 0x400806b8
12:19:46.913 -> Initializing SPIFFS...
12:19:47.014 -> SPIFFS Mount Successful
12:19:48.046 -> Found file, about to update...
12:19:49.010 -> uzLib SPIFFS Updater start!
12:19:49.080 -> gzip file detected ! gz size: 146768 bytes, expanded size:322144 bytes
12:19:49.080 -> [D][Updater.cpp:136] begin(): OTA Partition: app1
12:19:49.080 -> Guru Meditation Error: Core  1 panic'ed (InstrFetchProhibited). Exception was unhandled.
12:19:49.080 -> Core 1 register dump:
12:19:49.080 -> PC      : 0x00000000  PS      : 0x00060530  A0      : 0x800d1632  A1      : 0x3ffb1f10  
12:19:49.114 -> A2      : 0x3ffc00c8  A3      : 0x00000000  A4      : 0x3ffc15e4  A5      : 0x00008000  
12:19:49.114 -> A6      : 0x3ffbd50c  A7      : 0x3ffb2068  A8      : 0x800d156c  A9      : 0x3ffb1ef0  
12:19:49.114 -> A10     : 0x00000000  A11     : 0xffffffff  A12     : 0x00008000  A13     : 0x3ffbebe8  
12:19:49.114 -> A14     : 0x3ffc1950  A15     : 0x00000000  SAR     : 0x00000008  EXCCAUSE: 0x00000014  
12:19:49.114 -> EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000  
12:19:49.149 -> 
12:19:49.149 -> Backtrace: 0x00000000:0x3ffb1f10 0x400d162f:0x3ffb1f30 0x400d12fd:0x3ffb1f90 0x400d4889:0x3ffb1fb0 0x40088215:0x3ffb1fd0
12:19:49.149 -> 
12:19:49.149 -> Rebooting...
12:19:49.149 -> ets Jun  8 2016 00:22:57

The [D][Updater.cpp:136] begin(): OTA Partition: app1 is what I see on my program as well.

tobozo commented 3 years ago

thanks to your feedback I found a couple of bugs and (hopefully) fixed them

your example code now produces the expected behaviour when used with the latest commit on the master branch

please let me know if things have improved for you and I'll produce a new release

scubachristopher commented 3 years ago

@tobozo -- that worked!

I was able to verify with my application (yay!) but not Arduino IDE, because you didn't bump the version tag. I suspect you will now that I've validated it works. Please do ;)

THANK YOU VERY MUCH FOR YOUR FAST TURN-AROUND!!!

scubachristopher commented 3 years ago

@tobozo -- one last comment.

The update process Serial.print's a progress bar. Some applications need to control Serial. If possible, would you be willing to support a silent version of gzUpdate and eliminate the output?

uzLib SPIFFS Updater start!
gzip file detected ! gz size: 654221 bytes, expanded size:1166192 bytes
Progress:
[0%ZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZ100%]

If not, it's cool, I'll fork and eliminate it.

Thanks!

tobozo commented 3 years ago

Good suggestion

I've pushed some changes, now exposing the setProgressCallback() function so you can shut down the progress bar. Also created setLoggerCallback() for the serial output.

void myNullProgressCallback( uint8_t progress ) {
  // printf("Progress: %d", progress );
}
void myNullLogger(const char* format, ...) {
  //va_list args;
  //va_start(args, format);
  //vprintf(format, args);
  //va_end(args);
}

void setup() {
    Serial.begin( 115200 );
    setProgressCallback( myNullProgressCallback );
    setLoggerCallback( myNullLogger );
}

scubachristopher commented 3 years ago

@tobozo -- perfect!

Again, thanks so much for the rapid turn-around and being open to changes.

tobozo / ESP32-targz

gzUpdater fails #8