"unexpected spi flash error code:101"

[mzimmers]

Also, starting with 152KB seems wrong. You should be able to start at 200KB (ish) with Wifi. Did you forget to put const in front of some initialisation data? A lot of Linux/PC code will fail to do that.

At the top of app_main, before I do much of anything, I have about 167KB of internal RAM. When I'm done creating my objects (I'm using C++) I have about 152KB. As I mentioned before, each task takes about 8KB, except when my Wifi task (not to be confused with the system wifi task) starts making calls, it eats up a lot more.

I could look through my code for things that could be allocated const, but I don't think there are enough to make much difference. Your comment about the static/dynamic wifi buffers is interesting; I look forward to seeing what Angus (or anyone else) has to say about this.

As a side note, I wonder whether anyone has any numbers on how much more space v4.1 and NETIF take up than their predecessors.

[mzimmers]

So, here's where I am now:

• by changing the internal/external threshold from 16K to 4K, my app no longer crashes due to insufficient memory. I fear that I've just postponed the problem, however, as I'm under 4K of MALLOC_CAP_8BIT | MALLOC_CAP_INTERNAL, and I still have another task to add, which will break the bank.

• It's not clear to me that the SPI RAM is getting utilized nearly enough:

  Code: Select all

  I (2386) memreport: main(): start of main:
  I (2386) memreport: memReport(): there are 4175216 MALLOC_CAP_8BIT | MALLOC_CAP_SPIRAM bytes free.
  ...
  I (10196) memreport: memReport(): there are 4166720 MALLOC_CAP_8BIT | MALLOC_CAP_SPIRAM bytes free.
  

  So, I'm using less than 9K of this enormous pool of SPI RAM? It would seem clear that I need to better utilize it, though I'm not sure how to go about this.

• Now, I'm crashing with this error:

  Code: Select all

  E (10226) spi_flash: unexpected spi flash error code: 101

  The trace indicates this is happening in spi_flash_translate_rc(), but the error code is a bit of a mystery, given that ESP_ERR_FLASH_BASE is 0x6000. So, I'm not really sure where to go from here.

• when I disable the code that leads to the above crash, I then abort on a stack overflow for the wifi task:

  Code: Select all

  I (5506) wifi: new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
  I (5506) wifi: state: init -> auth (b0)
  ***ERROR*** A stack overflow in task wifi has been detected.
  abort() was called at PC 0x4008bf8c on core 0

  I hope everyone reading this is having as much fun with it as I am...

• though the trace doesn't indicate it, the stack overflow is caused by my call to esp_wifi_start(). When I comment out this line, it doesn't abort (of course, it doesn't work, either).

[ESP_Angus]

Hi mzimmers,

I think I understand what's happening enough here. Can hopefully give some general pointers and with these you can get things working again:

• Task stack memory has to be internal memory*. So if you're allocating ~88KB of task stacks, this is a lot. If you can multiplex some functions into a single task which calls multiple functions in a sequence (or blocks on multiple queues/semaphores at once and then calls a handler function), or reduce the total stack sizes, then this is probably an easy fix.
• Initializing Wi-Fi with default settings using around 50KB of heap sounds plausible to me.
• As PeterR mentioned, there are some config items you can use to push as much Wi-Fi & TCP/IP stack memory as possible into PSRAM. The tradeoff here is Wi-Fi performance vs free internal memory. Try enabling CONFIG_SPIRAM_ALLOW_BSS_SEG_EXTERNAL_MEMORY and CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP, you should find you get some extra headroom
• The stack overflow when initializing wifi suggests that the task which call esp_wifi_init() doesn't have a large enough associated stack size. Can you bump it up somehow (if the task is app_main() then there's a config option which will bump up app_main()'s stack size). Or move the call higher in the task call stack, if that's possible. If that doesn't fix the problem, can you try decoding the "backtrace" that comes after the abort line (using the "make monitor"/"idf.py monitor" feature will do this automatically).

[*] there is a way to force some stacks to allocate in PSRAM but it's marked as "be extremely careful" and will probably lead to very hard to debug problems, significantly worse than even the confusing problems you have now! So suggest ignoring that tempting option.

[mzimmers]

Hi Angus -

I'll look into reducing the stack spaces I'm allocating to each of the tasks I start, as well as the configuration parameters you mention above.

I'm curious though -- the error message says that the stack overflow is occurring in task "wifi" which is not the same as my task "Wifi." I'd assumed this was another task, within the system. Is this correct, and if so, is there a way to increase the stack size of "wifi?"

[ESP_Angus]

I'm curious though -- the error message says that the stack overflow is occurring in task "wifi" which is not the same as my task "Wifi." I'd assumed this was another task, within the system. Is this correct, and if so, is there a way to increase the stack size of "wifi?"

No, I missed that - this is probably a bug. Can you please give us the exact IDF version you have ("git describe --tags", or it's in the boot log), and any information about the params you're passing in to esp_wifi_init() to cause it to crash?

[mzimmers]

Code: Select all

C:\esp-idf>git describe --tags
v4.1-dev-1986-gca735340f

C:\esp-idf>

from esp_wifi.h:

Code: Select all

#define WIFI_INIT_CONFIG_DEFAULT() { \
    .event_handler = &esp_event_send_internal, \
    .osi_funcs = &g_wifi_osi_funcs, \
    .wpa_crypto_funcs = g_wifi_default_wpa_crypto_funcs, \
    .static_rx_buf_num = CONFIG_ESP32_WIFI_STATIC_RX_BUFFER_NUM,\
    .dynamic_rx_buf_num = CONFIG_ESP32_WIFI_DYNAMIC_RX_BUFFER_NUM,\
    .tx_buf_type = CONFIG_ESP32_WIFI_TX_BUFFER_TYPE,\
    .static_tx_buf_num = WIFI_STATIC_TX_BUFFER_NUM,\
    .dynamic_tx_buf_num = WIFI_DYNAMIC_TX_BUFFER_NUM,\
    .csi_enable = WIFI_CSI_ENABLED,\
    .ampdu_rx_enable = WIFI_AMPDU_RX_ENABLED,\
    .ampdu_tx_enable = WIFI_AMPDU_TX_ENABLED,\
    .nvs_enable = WIFI_NVS_ENABLED,\
    .nano_enable = WIFI_NANO_FORMAT_ENABLED,\
    .tx_ba_win = WIFI_DEFAULT_TX_BA_WIN,\
    .rx_ba_win = WIFI_DEFAULT_RX_BA_WIN,\
    .wifi_task_core_id = WIFI_TASK_CORE_ID,\
    .beacon_max_len = WIFI_SOFTAP_BEACON_MAX_LEN, \
    .mgmt_sbuf_num = WIFI_MGMT_SBUF_NUM, \
    .feature_caps = g_wifi_feature_caps, \
    .magic = WIFI_INIT_CONFIG_MAGIC\
};

My code:

Code: Select all

    wifi_init_config_t wifiInitConfig;
    ESP_ERROR_CHECK(esp_netif_init()); 
    ESP_ERROR_CHECK(esp_event_loop_create_default());
    esp_netif_create_default_wifi_sta();
    wifiInitConfig = WIFI_INIT_CONFIG_DEFAULT();
    err = esp_wifi_init(&wifiInitConfig);

Thanks...

[mzimmers]

Progress report: my app is now functional (though needs more testing). I think the following changes are what made the difference:

• enabling the parameters CONFIG_SPIRAM_ALLOW_BSS_SEG_EXTERNAL_MEMORY and CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP as Angus suggested

• setting the option to allow malloc() to use SPI RAM

• reducing the maximum malloc() size to be forced into internal memory to 1024 bytes (I think this was a major help)

• reducing the stack sizes on several of my tasks

I don't really have to worry about taking a minor hit on Wifi performance, as this app doesn't make heavy use of communications.

I think the nvs problem I'm seeing is unrelated, or at least differently enough related, that I'm going to open a separate thread on it.

Thanks to EVERYONE who helped with this.

[mzimmers]

I said above I was going to open a new thread, but then I realized that the original problem is exactly what I'm facing now, so I'll continue here.

This code:

Code: Select all

const char NVS_PARTITION_SYSLOG[] = "nvs_syslog";
esp_err_t Syslog::openNvs()
{
    esp_err_t err;

    ESP_LOGI(TAG, "openNvs(): about to initialize %s.", NVS_PARTITION_SYSLOG);
    err = nvs_flash_init_partition(NVS_PARTITION_SYSLOG);

produces this error message:

Code: Select all

unexpected spi flash error code:101"

And then the processor resets.

Here's my partition table:

Code: Select all

otadata,data,ota,0x9000,0x2000,
phy_init,data,phy,0xb000,0x1000,
nvs,data,nvs,0xc000,0x4000,
nvs_config,data,nvs,0x10000,0x4000,
nvs_syslog,data,nvs,0x14000,0x6c000,
ota_0,app,ota_0,0x80000,0x1c0000,
ota_1,app,ota_1,0x240000,0x1c0000,

And everything shows up in the boot log to corroborate these entries.

Any idea what I'm doing wrong? An error 101 seems especially odd given that the base for errors is 0x6000.

Thanks...

[mzimmers]

BTT: anyone?

Could this somehow be related to my use of the SPI RAM?

Thanks...I'm eager to get this resolved.

[ESP_Angus]

Hi mzimmers,

EDIT: I took a look and there are two bugs in ESP-IDF, will fix:

1) If PSRAM is enabled at least 16KB of contiguous free memory needs to be enabled in order to use SPIRAM APIs to read into a buffer stored in PSRAM even if the read is for much less than 16KB of data. NVS initialization is almost certainly doing this and then it's crashing because 16KB isn't free.
2) The SPI flash APIs don't correctly handle the out of memory case and print "unexpected spi flash error code: 101" error that you're getting before abort()-ing, instead of returning to the caller.

Will fix both ASAP.

If you think there should be enough free heap to allocate 16KB, you can confirm by calling heap_caps_print_heap_info(MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); and check the largest free block is a reasonable size. (The simple free memory number can be misleading, because of fragmentation.)