triggering WDT in OTA

[mzimmers]

Hi all -

Using a WROVER, IDF release/v4.0.

I have an OTA task with this in it (inside a do loop; hence the continue):

Code: Select all

                ESP_LOGI(TAG, "otaTask(): next update partition is %s.", m_partInfo->label);

                rc = esp_ota_begin(m_partInfo, binSize, &m_handle);
                if (rc != ESP_OK)
                {
                    ESP_LOGE(TAG, "otaTask(): esp_ota_begin() returned: %x.", rc);
                    continue;
                }
                ESP_LOGI(TAG, "otaTask(): esp_ota_begin() successful.");

It usually (though not always) yields this error:

Code: Select all

I (44943) Ota: otaTask(): next update partition is ota_1.
E (49923) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (50063) task_wdt:  - IDLE0 (CPU 0)
E (50063) task_wdt: Tasks currently running:
E (50063) task_wdt: CPU 0: ipc0
E (50063) task_wdt: CPU 1: IDLE1
I (51903) Ota: otaTask(): esp_ota_begin() successful.

Any ideas what might be going on?

[username]

If its inside a do loop then you need to stick a delay in there. Otherwise your starving the WDT.

[mzimmers]

The do loop only executes once:

Code: Select all

do
{

	// initialize the socket.
	rc = setupSocket();
	if (rc != 0)
	{
		ESP_LOGE(TAG, "otaTask(): listening socket setup failed.");
		closeSocket();
		continue;
	}
	//ESP_LOGI(TAG, "otaTask(): listening socket setup successfully.");
	
	// we're ready to rock and roll.
	m_partInfo = const_cast<esp_partition_t *>(esp_ota_get_next_update_partition(m_partInfo));
	ESP_LOGI(TAG, "otaTask(): target partition is %s", m_partInfo->label);
	if (m_partInfo == nullptr)
	{
		ESP_LOGE(TAG, "otaTask(): esp_ota_get_next_update_partition() returned null pointer.");
		closeSocket();
		continue;
	}
	ESP_LOGI(TAG, "otaTask(): next update partition is %s.", m_partInfo->label);

	rc = esp_ota_begin(m_partInfo, binSize, &m_handle);
	if (rc != ESP_OK)
	{
		ESP_LOGE(TAG, "otaTask(): esp_ota_begin() returned: %x.", rc);
		closeSocket();
		continue;
	}
	ESP_LOGI(TAG, "otaTask(): esp_ota_begin() successful.");

	rc = receive(binSize);
	if (rc != 0)
	{
		ESP_LOGE(TAG, "otaTask(): receive failed.");
		closeSocket();
		continue;
	}

	rc = esp_ota_end(m_handle); // do this to free memory used by OTA.
	if (rc != ESP_OK)
	{
		ESP_LOGE(TAG, "otaTask(): esp_ota_end returned %x %s", rc, strerror(rc));
		closeSocket();
		continue;
	}

	rc = esp_ota_set_boot_partition(m_partInfo);
	if (rc != ESP_OK)
	{
		ESP_LOGE(TAG, "otaTask(): esp_ota_set_boot_partition() returned %x %s.", rc, strerror(rc));
	}
	closeSocket();
}
while (false);

(This is a coding style which eliminates the need for nested if statements; it makes for more readable code IMO.)

So the loop isn't the problem here.

[boarchuz]

It will be the partition erase. It can take a long time.

Try increasing the priority of the task calling esp_ota_begin.

[mzimmers]

Hi Boarchuz - thanks for the suggestion. I increased the priority from 5 to 6, and got the same result.

What if I explicitly erased the partition myself, a little at a time? Would a pre-erased partition speed up esp_ota_begin()?

[boarchuz]

For the sake of debugging, try increasing it a lot more (eg. to max).

Manually erasing might be tricky- I don't think there's a way to instruct the OTA component to skip the erase so it will likely do it again anyway. I might be wrong.

Here I broke the erase into chunks with a yield in between to keep FreeRTOS happy:
viewtopic.php?f=13&t=10801#p44310
If the priority thing doesn't work, give that a try. If that doesn't work, then it must be something else.

[mzimmers]

I tried increasing the priority to 9 (I believe I remember reading somewhere that's the maximum)...same result.

Your workaround is great, but I don't want to modify the idf. Did you ever submit this as a bug?

[boarchuz]

Nope, I actually haven't touched OTA for a long time and I'm still not sure if it's a bug or if we're missing something simple.

Out of curiosity, could you try (configMAX_PRIORITIES – 1 )?

I've just had a quick look and it seems the image_size parameter isn't really checked in any significant way, so a hacky solution for now that doesn't touch the IDF might be to erase the partition manually, then you could give esp_ota_begin image_size == 1 and it will only do the smallest possible erase.

I suppose you could always simply ignore the warning.

[mzimmers]

Tried the utmost priority; same thing.

I then tried your fix, and the problem went away.

If you don't object, I'd like to submit this as a bug, with your workaround cited.

[jhnlmn]

I found another cause for this persistent problem: CPU1 started DMA/SPI transfer (screen refresh) while CPU0 was calling esp_ota_begin. Apparently, esp_ota_begin was blocked waiting for screen update to finish. Raising task priority did not help.
The fix is to delay screen refresh until esp_ota_begin finished.
(I had this problem with IDF 4.4, CONFIG_SPI_FLASH_YIELD_DURING_ERASE=y is already set, but it did not help in my case).