ESP32 Forum

开发板ESP32程序有BLE和Wifi两个模块，运行半天和一个晚上，第二天早上发现夜间程序被自动重启过，日志显示assert failed: get_cached_log_level log.c:220
Assert发生的时候只有Wifi在通信（BLE应该是待机中），Wifi它是每隔15秒会上传9个指节的心跳数据给AWS。

我上网搜寻一下这个问题，发现和之前https://esp32.com/viewtopic.php?t=19165提出的是一样的。
我也想知道为什么平时怎么测试都很难甚至不能复现，待机中却会发生的这个问题的原因是什么？
谢谢！

环境是ESP-IDF v4.4.3

大部分日志输出是INFO level，有一些个别或底层代码是DEBUG level（例如esp_ssl_tls.c：288里面的 ESP_LOGD(TAG, "fail, error=%d", -ret);
）.
在Component config → AWS OTA → Logging 有Error和Warning及Info被选中；
Component config → coreMQTT → Logging仅有Info被选中 ；
Component config → Bluetooth → NimBLE Options → NimBLE Host log verbosity仅有Info被选中

下面是串口输出的信息：
I (18602101) UART: recv uart start len 8.
I (18602421) MQTT_PAYLOAD: payload_pack cmd: 00 ,len:1,val:01
I (18602421) MQTT_TASK: mqtt publish topic daye/iot/device/pt22020000/083a8d2c2a30/response.
I (18619026) mcu_proc: sendHeartbeat sendHeartbeat start.
I (18619026) mcu_proc: sendHeartbeat sendHeartbeat end.
I (18619091) UART: recv uart start len 8.
I (18619281) MQTT_PAYLOAD: payload_pack cmd: 00 ,len:1,val:01
I (18619281) MQTT_TASK: mqtt publish topic daye/iot/device/pt22020000/083a8d2c2a30/response.
I (18636026) mcu_proc: sendHeartbeat sendHeartbeat start.
I (18636026) mcu_proc: sendHeartbeat sendHeartbeat end.
I (18636086) UART: recv uart start len 8.
I (18636131) MQTT_PAYLOAD: payload_pack cmd: 00 ,len:1,val:01
I (18636131) MQTT_TASK: mqtt publish topic daye/iot/device/pt22020000/083a8d2c2a30/response.

assert failed: get_cached_log_level log.c:220 (i == 0 || s_log_cache[(i - 1) / 2].generation < s_log_cache.generation)


Backtrace: 0x400823b9:0x3fffb0d0 0x40096275:0x3fffb0f0 0x4009d345:0x3fffb110 0x401afb86:0x3fffb230 0x401afdf2:0x3fffb250 0x4009d0bf:0x3fffb280 0x40145317:0x3fffb2d0 0x401410c3:0x3fffb330 0x4013b1d1:0x3fffb360 0x400e3c8b:0x3fffb380 0x400ed8bc:0x3fffb3a0 0x400ec4fe:0x3fffb3c0 0x400ec59f:0x3fffb3f0 0x400e1806:0x3fffb410 0x400e06a0:0x3fffb430 0x4009aaa1:0x3fffb460
0x400823b9: panic_abort at /home/niuyq/daye_dev/dayefw2/esp-idf/components/esp_system/panic.c:402

0x40096275: esp_system_abort at /home/niuyq/daye_dev/dayefw2/esp-idf/components/esp_system/esp_system.c:128

0x4009d345: __assert_func at /home/niuyq/daye_dev/dayefw2/esp-idf/components/newlib/assert.c:85

0x401afb86: get_cached_log_level at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:220
(inlined by) s_log_level_get_and_unlock at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:153

0x401afdf2: esp_log_writev at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:195

0x4009d0bf: esp_log_write at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:210

0x40145317: esp_mbedtls_add_rx_buffer at /home/niuyq/daye_dev/dayefw2/esp-idf/components/mbedtls/port/dynamic/esp_mbedtls_dynamic_impl.c:394 (discriminator 12)

0x401410c3: __wrap_mbedtls_ssl_read at /home/niuyq/daye_dev/dayefw2/esp-idf/components/mbedtls/port/dynamic/esp_ssl_tls.c:211

0x4013b1d1: esp_mbedtls_read at /home/niuyq/daye_dev/dayefw2/esp-idf/components/esp-tls/esp_tls_mbedtls.c:206

0x400e3c8b: esp_tls_conn_read at /home/niuyq/daye_dev/dayefw2/esp-idf/components/esp-tls/esp_tls.h:496
(inlined by) espTlsTransportRecv at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreHTTP/port/network_transport/network_transport.c:107

0x400ed8bc: MQTT_GetIncomingPacketTypeAndLength at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreMQTT/coreMQTT/source/core_mqtt_serializer.c:2359

0x400ec4fe: receiveSingleIteration at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreMQTT/coreMQTT/source/core_mqtt.c:1307

0x400ec59f: MQTT_ProcessLoop at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreMQTT/coreMQTT/source/core_mqtt.c:2195

0x400e1806: mqtt_impl_loop at /home/niuyq/daye_dev/dayefw2/Application/components/aws_iot/src/mqtt_impl.c:225

0x400e06a0: task at /home/niuyq/daye_dev/dayefw2/Application/components/aws_iot/src/mqtt_task.c:168

0x4009aaa1: vPortTaskWrapper at /home/niuyq/daye_dev/dayefw2/esp-idf/components/freertos/port/xtensa/port.c:131





ELF file SHA256: bd2795b2219fd188

Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:6660
load:0x40078000,len:14944

追加一下，我在发生Assert的地方打印了堆栈信息，发现堆栈空间够用。但是不清楚s_log_cache为什么不满足条件，好像有问题。不清楚怎么原因。
下面是我为添加输出信息修改了一下代码和结果：
Code:
static inline bool get_cached_log_level(const char *tag, esp_log_level_t *level)
{
// Look for `tag` in cache
uint32_t i;
for (i = 0; i < s_log_cache_entry_count; ++i) {
#ifdef LOG_BUILTIN_CHECKS
//assert(i == 0 || s_log_cache[(i - 1) / 2].generation < s_log_cache.generation);
if(i == 0 || s_log_cache[(i - 1) / 2].generation < s_log_cache.generation)
{
;
}
else
{
printf("*Task stack i : %d;s_log_cache.generation:%d ;--- %d\n", i, s_log_cache.generation, s_log_cache[(i - 1) / 2].generation);
esp_backtrace_print(100);
printf("*Task stack high water mark: %d\n", uxTaskGetStackHighWaterMark(NULL));

assert(0);
}
#endif

结果如下：
*Task stack i : 21;s_log_cache.generation:0 ;-- 170


Backtrace: 0x401A6AD5:0x3FFF8230 0x401A6D02:0x3FFF8250 0x4009A04D:0x3FFF8280 0x40138CF8:0x3FFF82D0 0x401334C9:0x3FFF8300 0x400DDD58:0x3FFF8320 0x400E6495:0x3FFF8340 0x400E52B6:0x3FFF8370 0x400E55CB:0x3FFF83D0 0x400DBC46:0x3FFF83F0 0x400DA870:0x3FFF8410
0x401a6ad5: get_cached_log_level at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:231
(inlined by) s_log_level_get_and_unlock at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:156

0x401a6d02: esp_log_writev at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:198

0x4009a04d: esp_log_write at /home/niuyq/daye_dev/dayefw2/esp-idf/components/log/log.c:213

0x40138cf8: __wrap_mbedtls_ssl_read at /home/niuyq/daye_dev/dayefw2/esp-idf/components/mbedtls/port/dynamic/esp_ssl_tls.c:210

0x401334c9: esp_mbedtls_read at /home/niuyq/daye_dev/dayefw2/esp-idf/components/esp-tls/esp_tls_mbedtls.c:206

0x400ddd58: esp_tls_conn_read at /home/niuyq/daye_dev/dayefw2/esp-idf/components/esp-tls/esp_tls.h:496
(inlined by) espTlsTransportRecv at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreHTTP/port/network_transport/network_transport.c:107

0x400e6495: MQTT_GetIncomingPacketTypeAndLength at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreMQTT/coreMQTT/source/core_mqtt_serializer.c:2359

0x400e52b6: receiveSingleIteration at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreMQTT/coreMQTT/source/core_mqtt.c:1307

0x400e55cb: MQTT_ProcessLoop at /home/niuyq/daye_dev/dayefw2/Application/libraries/coreMQTT/coreMQTT/source/core_mqtt.c:2195

0x400dbc46: mqtt_impl_loop at /home/niuyq/daye_dev/dayefw2/Application/components/aws_iot/src/mqtt_impl.c:225

0x400da870: task at /home/niuyq/daye_dev/dayefw2/Application/components/aws_iot/src/mqtt_task.c:168


*Task stack high water mark: 9556

assert failed: get_cached_log_level log.c:242 (0)

Hi，我们也碰到类似的问题，请问你这边找到原因了吗?