SmingHub / Sming

Sming - powerful open source framework simplifying the creation of embedded C++ applications.
https://sming.readthedocs.io
GNU Lesser General Public License v3.0
1.47k stars 347 forks source link

vPortFree 517 line assert fail #2720

Closed pljakobs closed 6 months ago

pljakobs commented 6 months ago

I'm experiencing the above error when running an OTA on my firware. The OTA seems to not update the spiffs partition, but I'm not sure if this is a result of the above Error. What I could find about the error is a very old issue on NONOS 3.0.0 here: https://github.com/espressif/ESP8266_NONOS_SDK/issues/243

Is that a patch that needs to be cherry-picked into Sming, is it something unavoidable like I'm using too much heap or is it something else?

I know I have some memory pressure, running with a free heap of about 16kB, I could terminate all tcp connections before attempting the OTA but I'm wondering if that's really the only way.

pj

mikee47 commented 6 months ago

The SDK issue you mention should not affect Sming code. It seems to boil down to whether IRAM can be used by the allocator. According to the SDK documentation this feature was added in version 3.0 but requires applications to define a function user_iram_memory_is_enabled() which returns 1. This function isn't defined in Sming so allocations should always come from regular DRAM.

The OsMessageInterceptor class was added to deal with this sort of problem by catching the relevant SDK messages and breaking into the debugger or printing a stack dump. Its use is demonstrated in the LiveDebug sample.

Below are the bits you'd need to add to your application.

#include <Platform/OsMessageInterceptor.h>

static OsMessageInterceptor osMessageInterceptor;

/**
 * @brief See if the OS debug message is something we're interested in.
 * @param msg
 * @retval bool true if we want to report this
 */
static bool __noinline parseOsMessage(OsMessage& msg)
{
    m_printf(_F("[OS] %s\r\n"), msg.getBuffer());
    if(msg.startsWith(_F("E:M "))) {
        Serial.println(_F("** OS Memory Error **"));
        return true;
    }
    if(msg.contains(_F(" assert "))) {
        Serial.println(_F("** OS Assert **"));
        return true;
    }
    if(msg.contains(_F("vPortFree"))) {
        Serial.println(_F("** vPortFree **"));
        return true;
    }
    return false;
}

/**
 * @brief Called when the OS outputs a debug message using os_printf, etc.
 * @param msg The message
 */
static void onOsMessage(OsMessage& msg)
{
    // Note: We do the check in a separate function to avoid messing up the stack pointer
    if(parseOsMessage(msg)) {
        if(gdb_present() == eGDB_Attached) {
            gdb_do_break();
        } else {
#ifdef ARCH_ESP8266
            register uint32_t sp __asm__("a1");
            debug_print_stack(sp + 0x10, 0x3fffffb0);
#endif
        }
    }
}

void init()
{
   ...
    osMessageInterceptor.begin(onOsMessage);
}
pljakobs commented 6 months ago

as usual, I'm impressed by the quality of answers here, thanks @mikee47 I assume this is Esp8266 only since nonos is Esp8266 only, right? So no reason to have it in the code for all architectures?

mikee47 commented 6 months ago

... Esp8266 only since nonos is Esp8266 only, right? So no reason to have it in the code for all architectures?

It'll build for Esp32 also, though never had occasion to use it.

pljakobs commented 6 months ago

I can't say that I'm making progress here... so, now I get a stack dump

[OS] vPortFree 517 line assert fail
** OS Assert **

Stack dump:

that decodes to


0x40251490: OsMessageInterceptor::static_putc(char) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Platform/OsMessageInterceptor.h:93
0x40001da0: ?? ??:0
0x40001db4: ?? ??:0
0x40001f46: ?? ??:0
0x4000050c: ?? ??:0
0x4026b204: operator delete(void*, unsigned int) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/heap/alloc.cpp:47
0x4000050c: ?? ??:0
0x40265984: TcpConnection::flush() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpConnection.cpp:383
0x40002514: ?? ??:0
0x40101282: vPortFree at ??:?
0x401013c7: free at ??:?
0x4026fac0: Ota::UpgradeOutputStream::close() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Libraries/Ota/src/UpgradeOutputStream.cpp:59
0x4026b204: operator delete(void*, unsigned int) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/heap/alloc.cpp:47
0x4026fad7: Ota::UpgradeOutputStream::~UpgradeOutputStream() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Libraries/Ota/src/include/Ota/UpgradeOutputStream.h:40
0x4026b1c8: operator new(unsigned int) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/heap/alloc.cpp:17
0x4026fbce: Ota::UpgradeOutputStream::~UpgradeOutputStream() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Libraries/Ota/src/include/Ota/UpgradeOutputStream.h:40
0x4026b1c8: operator new(unsigned int) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/heap/alloc.cpp:17
0x4026391c: HttpResponse::freeStreams() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:161
0x401013c7: free at ??:?
0x40265635: TcpConnection::trySend(TcpConnectionEvent) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpConnection.h:196
0x40269af4: std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_manager(std::_Any_data&, std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}> const&, std::_Manager_operation) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:268
0x40272b84: std::_Function_base::_Base_manager<Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_get_pointer(std::_Any_data const&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:144
 (inlined by) std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_invoke(std::_Any_data const&, TcpClient&, char*&&, int&&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:291
0x401013c7: free at ??:?
0x402656c1: TcpConnection::onConnected(signed char) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpConnection.cpp:179
0x4024f0a8: String::invalidate() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Wiring/WString.cpp:147
0x402663a2: TcpClient::onConnected(signed char) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpClient.cpp:131
0x401013c7: free at ??:?
0x4024f61b: String::operator=(char const*) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Wiring/WString.cpp:338
0x401013c7: free at ??:?
0x4026ac1a: HttpClientConnection::onMessageComplete(http_parser*) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:159
0x4026398a: HttpResponse::reset() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:129
0x40263998: HttpResponse::reset() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:130
0x40269ed0: HttpConnection::reset() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpConnection.h:42
 (inlined by) HttpClientConnection::reset() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:61
0x40272b74: HttpConnection::staticOnMessageComplete(http_parser*) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:164
0x4026daf0: http_parser_execute at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/http-parser/http_parser.c:1971 (discriminator 3)
0x402382a0: chip_v6_unset_chanfreq at ??:?
0x40235ed0: chip_v6_unset_chanfreq at ??:?
0x40101302: pvPortCalloc at ??:?
0x40208b6b: ieee80211_parse_htcap at ??:?
0x40269aa1: HttpConnection::onTcpReceive(TcpClient&, char*, int) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:180
 (inlined by) HttpConnection::onTcpReceive(TcpClient&, char*, int) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:172
0x40233b3b: pwm_start at D:\VM\Share\v1.1.0\LIGHT_RELEASE\esp_iot_sdk_v1.0.1_b3_light_source_xcc\app\pwm/D:\VM\Share\v1.1.0\LIGHT_RELEASE\esp_iot_sdk_v1.0.1_b3_light_source_xcc\app\pwm/pwm.c:189
0x40272ba8: std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_invoke(std::_Any_data const&, TcpClient&, char*&&, int&&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:293
0x40233cf6: pwm_start at D:\VM\Share\v1.1.0\LIGHT_RELEASE\esp_iot_sdk_v1.0.1_b3_light_source_xcc\app\pwm/D:\VM\Share\v1.1.0\LIGHT_RELEASE\esp_iot_sdk_v1.0.1_b3_light_source_xcc\app\pwm/pwm.c:275
0x40266402: TcpClient::onReceive(pbuf*) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpClient.cpp:149
0x40265d64: TcpConnection::internalOnReceive(pbuf*, signed char) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpConnection.cpp:484
0x402548bc: RGBWWLed::setOutput(ChannelOutput&) at /home/pjakobs/devel/esp_rgbww_firmware/Components/RGBWWLed/RGBWWLed.cpp:139
0x40265dd4: operator() at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpConnection.cpp:329
 (inlined by) _FUN at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpConnection.cpp:331
0x40220a24: tcp_input at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_in.c:394 (discriminator 1)
0x4021e149: ip_input at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:559
0x4023944c: igmp_timer at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/timers.c:217
0x4021dca9: ethernet_input at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/netif/etharp.c:1379
0x40100e1a: wdt_feed at ??:?
0x40100d6d: wdt_feed at ??:?
0x40217eac: ets_timer_handler_isr at ??:?
0x40217ed2: ets_timer_handler_isr at ??:?
0x4021c857: ets_snprintf at ??:?

I can't really say much about the circumstance apart from the fact that it's reliably triggered at the end of an OTA, before rebooting into the new ROM.

I've also seen it happen in a few other circumstances, when the software was writing to flash. Since that is code, I have not touched a whole lot yet, it might just be memory pressure triggering this. It's very odd at any rate.

pljakobs commented 6 months ago

I have now rewritten the OTA component to use the same code as the SimpleOTA example (which, iirc, is the newer, Esp32 compatible OTA code?) but the result is still the same. I was able to track it down a bit further, though. The rom file is successfully downloaded and written to flash but right after completed, the error occurs:

[Components/Network/src/Network/Http/HttpClientConnection.cpp:115] HCC::onMessageComplete: executionQueue: 1, http://192.168.29.10:8080/Esp8266/v1/rom0.bin
[Libraries/OtaNetwork/src/HttpUpgrader.cpp:61] Finished: URL: http://192.168.29.10:8080/Esp8266/v1/rom0.bin, Offset: 0x2000, Length: 537872
[Components/Network/src/Network/TcpConnection.cpp:174] TCP 3fff7ff8 connected
[Components/Network/src/Network/Http/HttpClientConnection.cpp:237] HCC::onReadyToSendData: State: 0, executionQueue: 0, waitingQueue: 1
[Core/Data/Stream/MemoryDataStream.cpp:34] MemoryDataStream::realloc 0 -> 40
[Components/Network/src/Network/TcpClient.cpp:112] Sending stream. Bytes to send: 40
[Core/Data/Stream/MemoryDataStream.cpp:34] MemoryDataStream::realloc 40 -> 194
[Components/Network/src/Network/TcpClient.cpp:112] Sending stream. Bytes to send: 66
[Components/Network/src/Network/TcpClient.cpp:112] Sending stream. Bytes to send: 85
[Components/Network/src/Network/TcpClient.cpp:112] Sending stream. Bytes to send: 87
[Components/Network/src/Network/TcpConnection.cpp:198] TCP 3fff7ff8 onReadyToSendData: 0
[Components/Network/src/Network/TcpConnection.cpp:256] TCP 3fff7ff8 Written: 87, Available: 2780, isFinished: 0, PushCount: 1
[Components/Network/src/Network/TcpClient.cpp:198] TcpClient stream finished
[Components/Network/src/Network/Http/HttpClientConnection.cpp:237] HCC::onReadyToSendData: State: 2, executionQueue: 1, waitingQueue: 0
[Components/Network/src/Network/Http/HttpClientConnection.cpp:245] HCC::onReadyToSendData: Nothing in the waiting queue
[OS] vPortFree 517 line assert fail
** OS Assert **

Stack dump:

the configuration of the otaUpdater is this:

[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:47] ApplicationOTA::start spiffspart: spiffs0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:99] ApplicationOTA::beforeOTA
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:58] Free heap before OTA: 17720
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:60] configured OTA item list
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:61] ========================
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:64]   URL: http://192.168.29.10:8080/Esp8266/v1/rom0.bin
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:65]   Partition: rom0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:66]   Size: 0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:67]   ---------
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:64]   URL: http://192.168.29.10:8080/Esp8266/v1/spiff_rom.bin
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:65]   Partition: spiffs0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:66]   Size: 0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:67]   ---------
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:71] Starting OTA ...

and this is the flash layout:

Partition map: hwconfig
options: 4m, spiffs
Device            Start       End         Size        Type      SubType   Name              Filename
----------------  ----------  ----------  ----------  --------  --------  ----------------  ------------
spiFlash          0x00000000  0x00001fff          8K                      Boot Sector       
spiFlash          0x00002000  0x000f9fff        992K  app       ota_0     rom0              $(RBOOT_ROM_0_BIN)
spiFlash          0x000fa000  0x00101fff         32K                      (unused)          
spiFlash          0x00102000  0x001f9fff        992K  app       ota_1     rom1              $(RBOOT_ROM_0_BIN)
spiFlash          0x001fa000  0x001fffff         24K                      (unused)          
spiFlash          0x00200000  0x002bffff        768K  data      spiffs    spiffs0           $(SPIFF_BIN_OUT)
spiFlash          0x002c0000  0x0037ffff        768K  data      spiffs    spiffs1           $(SPIFF_BIN_OUT)
spiFlash          0x00380000  0x003f9fff        488K                      (unused)          
spiFlash          0x003fa000  0x003fafff          4K                      Partition Table   
spiFlash          0x003fb000  0x003fbfff          4K  data      rfcal     rf_cal            
spiFlash          0x003fc000  0x003fcfff          4K  data      phy       phy_init          $(FLASH_INIT_DATA)
spiFlash          0x003fd000  0x003fffff         12K  data      sysparam  sys_param   

so, clearly something reproducibly triggers this vPortFree assert - but I can't say why. It might be this mix of older and newer ota code in my codebase (although I think I've now fully switched to the new model) or something else. Not sure where to go with this now.

pljakobs commented 6 months ago

some more analysis. For simplicity, I'm only updating the rom partition, ignoring spiffs for now, so the ota config is like this:

[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:60] Free heap before OTA: 14736
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:62] Current running partition: rom0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:63] OTA target partition: rom1
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:64] configured OTA item list
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:65] ========================
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:68]   URL: http://192.168.29.10:8080/Esp8266/v1/rom0.bin
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:69]   Partition: rom1
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:70]   Size: 0
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:71]   ---------
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:75] Starting OTA ...
[Libraries/OtaNetwork/src/HttpUpgrader.cpp:23] Download file:
    (0) http://192.168.29.10:8080/Esp8266/v1/rom0.bin -> rom1 @ 0x102000

The result is much the same, though.

[Libraries/Spiffs/src/FileSystem.cpp:443] Flushing Metadata to disk
[/home/pjakobs/devel/esp_rgbww_firmware/app/otaupdate.cpp:155] OTA callback done, rebooting

this message is output at the end of the otaupdate callback

debug_i("OTA callback done, rebooting");
System.restart();

I'm not sure if the messages after this are due to the restart of if there are parallel operations ongoing.

[Libraries/OtaNetwork/src/HttpUpgrader.cpp:112] Firmware updated.
[Components/Network/src/Network/TcpConnection.cpp:174] TCP 3fff86a0 connected
[Components/Network/src/Network/Http/HttpClientConnection.cpp:237] HCC::onReadyToSendData: State: 0, executionQueue: 0, waitingQueue: 0
[Components/Network/src/Network/Http/HttpClientConnection.cpp:245] HCC::onReadyToSendData: Nothing in the waiting queue
[Components/Network/src/Network/TcpConnection.cpp:198] TCP 3fff86a0 onReadyToSendData: 0
[OS] vPortFree 517 line assert fail
** OS Assert **

The vPortFree 517 line assert fail reliably comes after the TCP onReadyToSendData message

void TcpConnection::onReadyToSendData(TcpConnectionEvent sourceEvent)
{
    if(sourceEvent != eTCE_Poll) {
        debug_tcp_d("onReadyToSendData: %d", sourceEvent);
    }
}

but I'm not sure if it's at all connected.

pljakobs commented 6 months ago

this is where the stack dump seems to match up with the output:

0x40101282: vPortFree at ??:?
0x40257fc9: std::_Function_handler<int (HttpConnection&, bool), Delegate<int (HttpConnection&, bool)>::Delegate<Ota::Network::HttpUpgrader>(int (Ota::Network::HttpUpgrader::*)(HttpConnection&, bool), Ota::Network::HttpUpgrader*)::{lambda(HttpConnection&, bool)#1}>::_M_manager(std::_Any_data&, std::_Function_handler<int (HttpConnection&, bool), Delegate<int (HttpConnection&, bool)>::Delegate<Ota::Network::HttpUpgrader>(int (Ota::Network::HttpUpgrader::*)(HttpConnection&, bool), Ota::Network::HttpUpgrader*)::{lambda(HttpConnection&, bool)#1}> const&, std::_Manager_operation) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:286
0x401013c7: free at ??:?
0x40267c96: TcpClient::onConnected(signed char) at /home/pjakobs/devel/esp_rgbww_firmware/Sming/Sming/Components/Network/src/Network/TcpClient.cpp:131

I have a hard time breaking down the code at 0x40257fc9

mikee47 commented 6 months ago

Can you get the code running in GDB? The backtrace might be easier to follow. See https://sming.readthedocs.io/en/latest/arch/esp8266/debugging.

If you can provide an example application which demonstrates the fault I could assist further?

pljakobs commented 6 months ago

I have just tested it with the BasicOta example with the following changes:

I can reproduce the error with this.

Note: since I'm only using one ROM file, I have removed the RBOOT_USE_TWO_ROMS #ifdefs

my experiments with gdb and remote development haven't been really successful so far, but I'll try again.

here's the decoded stack:

0x40237660: OsMessageInterceptor::static_putc(char) at /opt/sming/Sming/Platform/OsMessageInterceptor.h:93
0x40001da0: ?? ??:0
0x40001db4: ?? ??:0
0x40001f46: ?? ??:0
0x402482d9: flashmem_write at /opt/sming/Sming/Arch/Esp8266/Components/spi_flash/flashmem.c:60
0x40248168: operator delete(void*, unsigned int) at /opt/sming/Sming/Arch/Esp8266/Components/heap/alloc.cpp:47
0x40245020: TcpConnection::flush() at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:383
0x40002514: ?? ??:0
0x40101d44: spi_flash_erase_sector at ??:?
0x401010ca: vPortFree at ??:?
0x401011f6: malloc at ??:?
0x4024c254: std::_Function_base::~_Function_base() at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:246
0x4010120f: free at ??:?
0x4024b514: Ota::UpgradeOutputStream::close() at /opt/sming/Sming/Libraries/Ota/src/UpgradeOutputStream.cpp:59
0x40248168: operator delete(void*, unsigned int) at /opt/sming/Sming/Arch/Esp8266/Components/heap/alloc.cpp:47
0x4024b52b: Ota::UpgradeOutputStream::~UpgradeOutputStream() at /opt/sming/Sming/Libraries/Ota/src/include/Ota/UpgradeOutputStream.h:40
0x402466dc: std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_manager(std::_Any_data&, std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}> const&, std::_Manager_operation) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:268
0x4024b626: Ota::UpgradeOutputStream::~UpgradeOutputStream() at /opt/sming/Sming/Libraries/Ota/src/include/Ota/UpgradeOutputStream.h:40
0x4010120f: free at ??:?
0x40248030: HttpResponse::freeStreams() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:161
0x40235be4: String::invalidate() at /opt/sming/Sming/Wiring/WString.cpp:147
0x40245a3e: TcpClient::onConnected(signed char) at /opt/sming/Sming/Components/Network/src/Network/TcpClient.cpp:131
0x4010120f: free at ??:?
0x4023615b: String::operator=(char const*) at /opt/sming/Sming/Wiring/WString.cpp:338
0x4010120f: free at ??:?
0x40247a4a: HttpClientConnection::onMessageComplete(http_parser*) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:159
0x4024809a: HttpResponse::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:129
0x402480a8: HttpResponse::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:130
0x40246c80: HttpConnection::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.h:42
 (inlined by) HttpClientConnection::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:61
0x4024cca8: HttpConnection::staticOnMessageComplete(http_parser*) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:164
0x4024a8e4: http_parser_execute at /opt/sming/Sming/Components/http-parser/http_parser.c:1971 (discriminator 3)
0x40232eec: chip_v6_unset_chanfreq at ??:?
0x40231800: chip_v6_unset_chanfreq at ??:?
0x4010114a: pvPortCalloc at ??:?
0x402058e7: ieee80211_parse_htcap at ??:?
0x40246689: HttpConnection::onTcpReceive(TcpClient&, char*, int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:180
 (inlined by) HttpConnection::onTcpReceive(TcpClient&, char*, int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:172
0x4024ccdc: std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_invoke(std::_Any_data const&, TcpClient&, char*&&, int&&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:293
0x4020a63b: scan_parse_beacon at ??:?
0x40245a9e: TcpClient::onReceive(pbuf*) at /opt/sming/Sming/Components/Network/src/Network/TcpClient.cpp:149
0x402453f8: TcpConnection::internalOnReceive(pbuf*, signed char) at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:484
0x40100e43: ets_timer_arm_new at ??:?
0x4020b287: sta_input at ??:?
0x4020b2f2: sta_input at ??:?
0x40245468: operator() at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:329
 (inlined by) _FUN at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:331
0x4021cfa0: tcp_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_in.c:394 (discriminator 1)
0x4021a871: ip_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:559
0x40234258: igmp_timer at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/timers.c:217
0x4021a3d1: ethernet_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/netif/etharp.c:1379
0x40100c62: wdt_feed at ??:?
0x40100bb5: wdt_feed at ??:?
0x402145d4: ets_timer_handler_isr at ??:?
0x402145fa: ets_timer_handler_isr at ??:?
0x40218f7f: ets_snprintf at ??:?
0x40000f49: ?? ??:0
0x40000f49: ?? ??:0

I am a little bit confused, I tried to find the offending code but the only reference I found was somewhere in the nonos tree in mem.h - is that part not open source? I guess I've never looked at it.

mikee47 commented 6 months ago

One thought: have you tried the 'new' memory allocator? Build with ENABLE_CUSTOM_HEAP=1. https://sming.readthedocs.io/en/latest/_inc/Sming/Arch/Esp8266/Components/heap/index.html

pljakobs commented 6 months ago

umm... what I can say is: it does make a difference

wonder if the "unaligned" is the problem in the first case.

***** Fatal exception 9 (UNALIGNED)
pc=0x40247ccf sp=0x3ffffd30 excvaddr=0x02d0049b
ps=0x00000030 sar=0x00000010 vpri=0x40247e0c
r00: 0x40247d4c=1076133196 r01: 0x3ffffd30=1073741104 r02: 0x3fff0fdc=1073680348 
r03: 0x02d00497=  47187095 r04: 0xffff8000=-     32768 r05: 0x00000087=       135 
r06: 0x3fff18d8=1073682648 r07: 0x000000fe=       254 r08: 0x0000007b=       123 
r09: 0x00000400=      1024 r10: 0x00000000=         0 r11: 0x3fff19a4=1073682852 
r12: 0x3fff1110=1073680656 r13: 0x00000000=         0 r14: 0x00000000=         0 
r15: 0x3ffec728=1073661736 
0x40100348: umm_free at /opt/sming/Sming/Arch/Esp8266/Components/heap/umm_malloc/src/umm_malloc.c:294
0x40100348: umm_free at /opt/sming/Sming/Arch/Esp8266/Components/heap/umm_malloc/src/umm_malloc.c:294
0x40100150: free at /opt/sming/Sming/Arch/Esp8266/Components/heap/custom_heap.c:49
0x40247d4c: HttpResponse::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpResponse.cpp:130
0x40246924: HttpConnection::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.h:42
 (inlined by) HttpClientConnection::reset() at /opt/sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:61
0x4024c938: HttpConnection::staticOnMessageComplete(http_parser*) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:164
0x40105ba3: wDev_ProcessFiq at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/wdev.c:1243
0x4024a588: http_parser_execute at /opt/sming/Sming/Components/http-parser/http_parser.c:1971 (discriminator 3)
0x40232ddc: chip_v6_unset_chanfreq at ??:?
0x4021aa14: ip_output_if_opt at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:780
0x4024632d: HttpConnection::onTcpReceive(TcpClient&, char*, int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:180
 (inlined by) HttpConnection::onTcpReceive(TcpClient&, char*, int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:172
0x4024c96c: std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_invoke(std::_Any_data const&, TcpClient&, char*&&, int&&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:293
0x40245742: TcpClient::onReceive(pbuf*) at /opt/sming/Sming/Components/Network/src/Network/TcpClient.cpp:149
0x4021da62: pbuf_free at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/pbuf.c:758
0x4024509c: TcpConnection::internalOnReceive(pbuf*, signed char) at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:484
0x4021fe06: tcp_send_empty_ack at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_out.c:886
0x402203a6: tcp_output at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_out.c:925
0x4024510c: operator() at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:329
 (inlined by) _FUN at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:331
0x4021cf04: tcp_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_in.c:394 (discriminator 1)
0x4021a7d5: ip_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:559
0x4022c0bb: pp_enable_noise_timer at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/pp.c:323
0x4021a335: ethernet_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/netif/etharp.c:1379
0x40101276: wdt_feed at ??:?
0x401011c9: wdt_feed at ??:?
0x40214538: ets_timer_handler_isr at ??:?
0x4021455e: ets_timer_handler_isr at ??:?
0x40218ee3: ets_snprintf at ??:?
pljakobs commented 6 months ago

so I can 100% reproduce this now flashing this code: https://github.com/pljakobs/SMING_OTA_TEST

mikee47 commented 6 months ago

OK, so problem is the UpgradeOutputStream is being destroyed twice. I think the problem is within HttpUpgrader as when items.clear() is called the HttpResponse object still retains a reference to the corresponding stream.

Updating...
5178252 CREATE UpgradeOutputStream 3fff0fb8
5197719 [HR]::setBuffer(3fff0fb8), existing 0
5197983 [HR]::setStream(3fff0fb8)
10131785 DESTROY UpgradeOutputStream 3fff0fb8 ///<<<<< When HttpUpgrader calls `items.clear()`
In callback...
Firmware updated, rebooting to rom1 @ ...
10174737 [HR]::freeStreams(), buffer 3fff0fb8, stream 3fff0fb8
10175140 DESTROY UpgradeOutputStream 3fff0fb8 ///<<<<<< HttpResponse::freeStreams()
[OS] vPortFree 517 line assert fail
** OS Assert **

(Found by judicious application of debug_i(...) statements.)

mikee47 commented 6 months ago

@pljakobs I've raised a PR which should fix this issue. Would you give this a test?

mikee47 commented 6 months ago

umm... what I can say is: it does make a difference

wonder if the "unaligned" is the problem in the first case.

I've learned that you cannot take some of this debug output too literally! I took this to mean that both memory allocators get 'messed up' so first place to look is something getting de-allocated twice.

mikee47 commented 6 months ago

Something else I should have thought about earlier is using the malloc_count component https://sming.readthedocs.io/en/latest/_inc/Sming/Components/malloc_count/.

Enabling it produces the following output:

Updating...
5625023 MC## malloc(312) = 3fff1208 (cur 6155)
5625476 CREATE UpgradeOutputStream 3fff0c40
5625860 MC## malloc(512) = 3fff1360 (cur 6801)
5639548 MC## malloc(1504) = 3fff19d0 (cur 8816)
5643588 MC## free(3fff19d0) -> 1504 (cur 7123)
5646813 [HR]::setBuffer(3fff0c40), existing 0
5646998 [HR]::setStream(3fff0c40)
5652689 MC## malloc(335) = 3fff18b8 (cur 7621)
5698119 MC## free(3fff18b8) -> 335 (cur 7286)
5698627 
Firmware download failed..
In callback...
Firmware update failed!
5698852 DESTROY UpgradeOutputStream 3fff0c40
5704989 MC## free(3fff1208) -> 312 (cur 6681)
5710817 [HR]::freeStreams(), buffer 3fff0c40, stream 3fff0c40
5719009 DESTROY UpgradeOutputStream 3fff0c40
5725454 MC## free(3fff0c40) has no sentinel !!! memory corruption?
[OS] 3fff0c40 already freed
5738291 HTTP parser error: HPE_CB_message_complete
[OS] pm open,type:2 0

Curiously we also get an 'already freed' message from the OS. Either way it can help.

For completeness, enable the above functionality thus:

  1. Add COMPONENT_DEPENDS += malloc_count to the project's component.mk
  2. Add #include <malloc_count.h> and a call to MallocCount::enableLogging(true) to the project's init() function.
pljakobs commented 6 months ago

@pljakobs I've raised a PR which should fix this issue. Would you give this a test?

I'm getting a compile error

/opt/sming/Sming/Libraries/OtaNetwork/src/HttpUpgrader.cpp: In member function 'void Ota::Network::HttpUpgrader::start()':
/opt/sming/Sming/Libraries/OtaNetwork/src/HttpUpgrader.cpp:35:33: error: 'struct Ota::Network::HttpUpgrader::Item' has no member named 'releaseStream'
   35 |   request->setResponseStream(it.releaseStream());

I looked at the documentation and couldn't find that on item - am I missing something? Is there more to the patch than the HttpUpgrader.h and .cpp files?

mikee47 commented 6 months ago

The getStream method has been renamed to releaseStream - it's in there!

pljakobs commented 6 months ago

my fault entirely bangshead

pljakobs commented 6 months ago

so for now, all I can really say is that the error has changed a bit.

40082116 TCP 3fff13f4 onReadyToSendData: 1
40084918 MC## malloc(984) = 3fff2174 (cur 9208)
40087538 MC## free(3fff2174) -> 984 (cur 8224)
40087933 ota_write_flash: item.size: 343936
40088154 HCC::onMessageComplete: executionQueue: 1, http://192.168.29.10:8080/test/rom0.bin

***** Fatal exception 28 (LOAD_PROHIBITED)
pc=0x40239cd9 sp=0x3ffffc40 excvaddr=0x00000000
ps=0x00000030 sar=0x00000010 vpri=0x3fff146c
r00: 0x40239cd5=1076075733 r01: 0x3ffffc40=1073740864 r02: 0x00000000=         0 
r03: 0x3ffef5ac=1073673644 r04: 0x00000000=         0 r05: 0x00102000=   1056768 
r06: 0x00000000=         0 r07: 0x0a0d7525= 168654117 r08: 0x4024e5a8=1076159912 
r09: 0x00000120=       288 r10: 0x0000007e=       126 r11: 0x0000006c=       108 
r12: 0x3fff0e94=1073680020 r13: 0x3fff0d8c=1073679756 r14: 0x0263b645=  40089157 
r15: 0x3fff10d4=1073680596 
0x40233b3d: m_printf at /opt/sming/Sming/System/m_printf.cpp:113
0x40244a65: Url::toString() const at /opt/sming/Sming/Components/Network/src/Network/Url.cpp:94
0x4024ce30: std::_Function_handler<int (HttpConnection&, bool), Delegate<int (HttpConnection&, bool)>::Delegate<Ota::Network::HttpUpgrader>(int (Ota::Network::HttpUpgrader::*)(HttpConnection&, bool), Ota::Network::HttpUpgrader*)::{lambda(HttpConnection&, bool)#1}>::_M_invoke(std::_Any_data const&, HttpConnection&, bool&&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:293
0x4024803a: std::function<int (HttpConnection&, bool)>::operator()(HttpConnection&, bool) const at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:622
 (inlined by) HttpClientConnection::onMessageComplete(http_parser*) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:123
0x402473bb: HttpClientConnection::onBody(char const*, unsigned int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:225
 (inlined by) HttpClientConnection::onBody(char const*, unsigned int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpClientConnection.cpp:212
0x4020731f: ieee80211_output_pbuf at ??:?
0x4024d4a8: HttpConnection::staticOnMessageComplete(http_parser*) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:160
0x4024b0dc: http_parser_execute at /opt/sming/Sming/Components/http-parser/http_parser.c:1971 (discriminator 3)
0x40232cfc: chip_v6_unset_chanfreq at ??:?
0x40219eca: etharp_output_to_arp_index at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/netif/etharp.c:890
0x40246b9d: HttpConnection::onTcpReceive(TcpClient&, char*, int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:180
 (inlined by) HttpConnection::onTcpReceive(TcpClient&, char*, int) at /opt/sming/Sming/Components/Network/src/Network/Http/HttpConnection.cpp:172
0x40105868: wDev_ProcessFiq at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/wdev.c:1072
0x40244d54: TcpConnection::onReceive(pbuf*) at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:141
0x4024d4e8: std::_Function_handler<bool (TcpClient&, char*, int), Delegate<bool (TcpClient&, char*, int)>::Delegate<HttpConnection>(bool (HttpConnection::*)(TcpClient&, char*, int), HttpConnection*)::{lambda(TcpClient&, char*, int)#1}>::_M_invoke(std::_Any_data const&, TcpClient&, char*&&, int&&) at /opt/sming/Sming/esp-quick-toolchain/xtensa-lx106-elf/xtensa-lx106-elf/include/c++/10.2.0/bits/std_function.h:293
0x40245ee6: TcpClient::onReceive(pbuf*) at /opt/sming/Sming/Components/Network/src/Network/TcpClient.cpp:149
0x4022f106: esf_buf_recycle at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/esf_buf.c:582
0x4021a912: ip_output_if at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:631
0x4021a955: ip_output at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:817
0x40245764: TcpConnection::internalOnReceive(pbuf*, signed char) at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:484
0x4021fc96: tcp_send_empty_ack at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_out.c:886
0x40220236: tcp_output at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_out.c:925
0x402457d4: operator() at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:329
 (inlined by) _FUN at /opt/sming/Sming/Components/Network/src/Network/TcpConnection.cpp:331
0x4021cdb8: tcp_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/tcp_in.c:394 (discriminator 1)
0x401000a8: vPortFree at /opt/sming/Sming/Arch/Esp8266/Components/heap/custom_heap.c:29
0x4021a69d: ip_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/core/ipv4/ip.c:559
0x4021a201: ethernet_input at /opt/sming/Sming/Arch/Esp8266/Components/esp-open-lwip/esp-open-lwip/lwip/netif/etharp.c:1379
0x401040fd: lmacTxFrame at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/lmac.c:1611
0x401044f2: ppSearchTxframe at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/pp.c:2844
0x40104284: ppProcessTxQ at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/pp.c:1015
0x401042c0: ppProcessTxQ at /home/xcg/workspace/debug/esp8266_nonos_sdk_core_20180510/app/pp/pp.c:1072
0x40218def: ets_snprintf at ??:?
mikee47 commented 6 months ago

Right, so HttpUpgrader::itemComplete needs access to the stream! I've reverted first attempt and pushed this instead:

diff --git a/Sming/Libraries/OtaNetwork/src/HttpUpgrader.cpp b/Sming/Libraries/OtaNetwork/src/HttpUpgrader.cpp
index 90b89339..a263619c 100644
--- a/Sming/Libraries/OtaNetwork/src/HttpUpgrader.cpp
+++ b/Sming/Libraries/OtaNetwork/src/HttpUpgrader.cpp
@@ -49,17 +49,19 @@ void HttpUpgrader::start()

 int HttpUpgrader::itemComplete(HttpConnection& client, bool success)
 {
+   auto& it = items[currentItem];
+
    if(!success) {
+       it.stream.release(); // Owned by HttpRequest
        updateFailed();
        return -1;
    }

-   auto& it = items[currentItem];
    debug_d("Finished: URL: %s, Offset: 0x%X, Length: %u", it.url.c_str(), it.partition.address(),
            it.stream->available());

    it.size = it.stream->available();
-   it.stream = nullptr; // the actual deletion will happen outside of this class
+   it.stream.release(); // the actual deletion will happen outside of this class
    currentItem++;

    return 0;

Done a quick test (success and failure) and both seem OK.

pljakobs commented 6 months ago

I think I can confirm this fixed, at least from first tries with the Basic OTA code. Will try with my project. Dang this was an annoying one. Thanks for your help!

edit: confirmed for my larger project, too! This is great!