Closed f-hoepfinger-hr-agrartechnik closed 2 years ago
all Debug Log:
Executing action: monitor
Running idf_monitor in directory /home/franz/git/hr/2/Sample/bleprph_wifi_coex
Executing "/home/franz/.espressif/python_env/idf4.4_py3.8_env/bin/python /home/franz/esp-idf-v4.4/tools/idf_monitor.py -p /dev/ttyUSB0 -b 115200 --toolchain-prefix xtensa-esp32-elf- --target esp32 --revision 3 --print_filter /home/franz/git/hr/2/Sample/bleprph_wifi_coex/build/bleprph_wifi_coex.elf -m '/home/franz/.espressif/python_env/idf4.4_py3.8_env/bin/python' '/home/franz/esp-idf-v4.4/tools/idf.py'"...
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jul 29 2019 12:21:46
rst:0x1 (POWERON_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:6612
load:0x40078000,len:14780
load:0x40080400,len:3792
0x40080400: _init at ??:?
entry 0x40080694
I (27) boot: ESP-IDF v4.4-dirty 2nd stage bootloader
I (27) boot: compile time 15:01:49
I (27) boot: chip revision: 3
I (30) boot.esp32: SPI Speed : 40MHz
I (35) boot.esp32: SPI Mode : DIO
I (40) boot.esp32: SPI Flash Size : 2MB
I (44) boot: Enabling RNG early entropy source...
I (50) boot: Partition Table:
I (53) boot: ## Label Usage Type ST Offset Length
I (60) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (68) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (75) boot: 2 factory factory app 00 00 00010000 00177000
I (83) boot: End of partition table
I (87) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=18440h ( 99392) map
I (132) esp_image: segment 1: paddr=00028468 vaddr=3ffbdb60 size=05644h ( 22084) load
I (140) esp_image: segment 2: paddr=0002dab4 vaddr=40080000 size=02564h ( 9572) load
I (145) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=9a42ch (631852) map
I (377) esp_image: segment 4: paddr=000ca454 vaddr=40082564 size=1bc38h (113720) load
I (424) esp_image: segment 5: paddr=000e6094 vaddr=50000000 size=00010h ( 16) load
I (439) boot: Loaded app from partition at offset 0x10000
I (439) boot: Disabling RNG early entropy source...
I (450) psram: This chip is ESP32-D0WD
I (451) spiram: Found 64MBit SPI RAM device
I (451) spiram: SPI RAM mode: flash 40m sram 40m
I (456) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (463) cpu_start: Pro cpu up.
I (467) cpu_start: Starting app cpu, entry point is 0x40081348
0x40081348: call_start_cpu1 at /home/franz/esp-idf-v4.4/components/esp_system/port/cpu_start.c:156
I (0) cpu_start: App cpu up.
I (1360) spiram: SPI SRAM memory test OK
I (1368) cpu_start: Pro cpu start user code
I (1369) cpu_start: cpu freq: 160000000
I (1369) cpu_start: Application information:
I (1372) cpu_start: Project name: bleprph_wifi_coex
I (1377) cpu_start: App version: a51a1fc-dirty
I (1383) cpu_start: Compile time: May 26 2022 16:42:56
I (1389) cpu_start: ELF file SHA256: 52d248c444207d76...
I (1395) cpu_start: ESP-IDF: v4.4-dirty
I (1401) heap_init: Initializing. RAM available for dynamic allocation:
I (1408) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1414) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1420) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1426) heap_init: At 3FFC8F78 len 00017088 (92 KiB): DRAM
I (1433) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1439) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1446) heap_init: At 4009E19C len 00001E64 (7 KiB): IRAM
I (1452) spiram: Adding pool of 4095K of external SPI memory to heap allocator
I (1461) spi_flash: detected chip: generic
I (1465) spi_flash: flash io: dio
W (1469) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (1484) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1492) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1612) wifi_prph_coex: ESP_WIFI_MODE_STA
I (1622) wifi:wifi driver task: 3ffb7444, prio:23, stack:6656, core=0
I (1622) system_api: Base MAC address is not set
I (1622) system_api: read default base MAC address from EFUSE
I (1642) wifi:wifi firmware version: 7679c42
I (1642) wifi:wifi certification version: v7.0
I (1642) wifi:config NVS flash: enabled
I (1642) wifi:config nano formating: disabled
I (1652) wifi:Init data frame dynamic rx buffer num: 32
I (1652) wifi:Init management frame dynamic rx buffer num: 32
I (1662) wifi:Init management short buffer num: 32
I (1662) wifi:Init static tx buffer num: 16
I (1662) wifi:Init tx cache buffer num: 32
I (1672) wifi:Init static rx buffer size: 1600
I (1672) wifi:Init static rx buffer num: 10
I (1682) wifi:Init dynamic rx buffer num: 32
I (1682) wifi_init: rx ba win: 6
I (1682) wifi_init: tcpip mbox: 32
I (1692) wifi_init: udp mbox: 6
I (1692) wifi_init: tcp mbox: 6
I (1702) wifi_init: tcp tx win: 5744
I (1702) wifi_init: tcp rx win: 5744
I (1702) wifi_init: tcp mss: 1440
I (1712) wifi_init: WiFi/LWIP prefer SPIRAM
I (1712) wifi_init: WiFi IRAM OP enabled
I (1722) wifi_init: WiFi RX IRAM OP enabled
I (1732) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1822) wifi:mode : sta (58:bf:25:e0:71:30)
I (1822) wifi:enable tsf
I (1832) wifi_prph_coex: wifi_init_sta finished.
I (1842) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1
I (1842) wifi:state: init -> auth (b0)
I (3722) wifi:state: auth -> assoc (0)
I (3732) wifi:state: assoc -> run (10)
I (3762) wifi:connected with devolo-644, aid = 4, channel 11, BW20, bssid = b8:be:f4:a6:be:f4
I (3762) wifi:security: WPA3-SAE, phy: bgn, rssi: -47
I (3772) wifi:pm start, type: 1
W (3782) wifi:<ba-add>idx:0 (ifx:0, b8:be:f4:a6:be:f4), tid:6, ssn:2, winSize:64
I (3792) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (4612) esp_netif_handlers: sta ip: 192.168.178.98, mask: 255.255.255.0, gw: 192.168.178.1
I (4612) wifi_prph_coex: got ip:192.168.178.98
I (4612) wifi_prph_coex: connected to ap SSID:devolo-644 password:XXIEZHILYDDIXIJN
I (4632) BTDM_INIT: BT controller compile version [6a07b06]
W (4742) wifi:<ba-add>idx:1 (ifx:0, b8:be:f4:a6:be:f4), tid:0, ssn:0, winSize:64
64 bytes from 93.184.216.34 icmp_seq=1 ttl=58 time=131 ms
I (4882) wifi_prph_coex: BLE Host Task Started
Opening Non-Volatile Storage (NVS) handle... Done
Reading restart counter from NVS ... Done
Restart counter = 1463
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1464
Updating restart counter in NVS ... I (4922) wifi_prph_coex: Device Address:58:bf:25:e0:71:32
I (4932) NimBLE: GAP procedure initiated: advertise;
I (4932) NimBLE: disc_mode=2
I (4932) NimBLE: adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
I (4942) NimBLE:
Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1465
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1466
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1467
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1468
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1469
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1470
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1471
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1472
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1473
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1474
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1475
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1476
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1477
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1478
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1479
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1480
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1481
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1482
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1483
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1484
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1485
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1486
Updating restart counter in NVS ... Done
Committing updates in NVS ... Done
Done
Reading restart counter from NVS ... Done
Restart counter = 1487
Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed).
Core 0 register dump:
PC : 0x40092bc2 PS : 0x00060835 A0 : 0x80082058 A1 : 0x3ffbe6c0
0x40092bc2: xQueueReceiveFromISR at /home/franz/esp-idf-v4.4/components/freertos/queue.c:1946 (discriminator 1)
A2 : 0x3f8010a8 A3 : 0x00000000 A4 : 0x00000001 A5 : 0xbad00bad
A6 : 0x00000000 A7 : 0x00000001 A8 : 0x40084530 A9 : 0x3ffbe7d0
0x40084530: _xt_medint3 at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/xtensa_vectors.S:1280
A10 : 0x00000000 A11 : 0x003fffff A12 : 0xa60003cd A13 : 0x40091864
0x40091864: _frxt_int_enter at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/portasm.S:119
A14 : 0x00ff0000 A15 : 0xff000000 SAR : 0x00000018 EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000
Backtrace:0x40092bbf:0x3ffbe6c00x40082055:0x3ffbe6f0 0x4008d717:0x3ffbe710 0x4008d9d3:0x3ffbe740 0x4008d6c1:0x3ffbe770 0x40084c91:0x3ffbe790 0x40090801:0x3ffbe7b0 0x40084a2a:0x3ffbe7d0 0x4008452d:0x3ffbe800 0x4000bfed:0x3ffbe8c0 0x40094f76:0x3ffbe8d0 0x40082006:0x3ffbe8f0 0x4008da9b:0x3ffbe910 0x4008d6dd:0x3ffbe930 0x40084c79:0x3ffbe950 0x4008bc0d:0x3ffbe970 0x400843dd:0x3ffbe990 0x4000bfed:0x3ffbc5b0 0x40093fcd:0x3ffbc5c0 0x4008c3d8:0x3ffbc5e0 0x4008d2fd:0x3ffbc600 0x4008d3a2:0x3ffbc620 0x400908e9:0x3ffbc640 0x4008cfcb:0x3ffbc660 0x400fcdf1:0x3ffbc6a0 0x400fe767:0x3ffbc6d0 0x400ff382:0x3ffbc6f0 0x400ff73d:0x3ffbc710 0x400ff8b9:0x3ffbc770 0x400fe198:0x3ffbc800 0x400fe58e:0x3ffbc870 0x401659c7:0x3ffbc890 0x400fd40b:0x3ffbc8c0 0x400fd431:0x3ffbc8f0 0x400d822d:0x3ffbc910 0x40168c1f:0x3ffbc940 0x40094c8d:0x3ffbc960
0x40092bbf: xQueueReceiveFromISR at /home/franz/esp-idf-v4.4/components/freertos/queue.c:1946 (discriminator 1)
0x40082055: semphr_take_from_isr_wrapper at /home/franz/esp-idf-v4.4/components/esp_wifi/esp32/esp_adapter.c:294
0x4008d717: coex_bb_reset_unlock at ??:?
0x4008d9d3: coex_core_release at ??:?
0x4008d6c1: coex_bt_release at ??:?
0x40084c91: coex_bt_release_wrapper at /home/franz/esp-idf-v4.4/components/bt/controller/esp32/bt.c:1273
0x40090801: customer_swisr_handle at /home/franz/esp-idf-v4.4/components/bt/controller/esp32/hli_api.c:56
0x40084a2a: queue_isr_handler at /home/franz/esp-idf-v4.4/components/bt/controller/esp32/hli_api.c:156
0x4008452d: _xt_medint3 at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/xtensa_vectors.S:1280
0x40094f76: vPortClearInterruptMaskFromISR at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/include/freertos/portmacro.h:571
(inlined by) vPortExitCritical at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/port.c:319
0x40082006: wifi_int_restore_wrapper at /home/franz/esp-idf-v4.4/components/esp_wifi/esp32/esp_adapter.c:231
0x4008da9b: coex_core_bb_reset_unlock at ??:?
0x4008d6dd: coex_bb_reset_unlock at ??:?
0x40084c79: coex_bb_reset_unlock_wrapper at /home/franz/esp-idf-v4.4/components/bt/controller/esp32/bt.c:1300
0x4008bc0d: btdm_bb_isr at intc.c:?
0x400843dd: _xt_lowint1 at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/xtensa_vectors.S:1111
0x40093fcd: vPortClearInterruptMaskFromISR at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/include/freertos/portmacro.h:571
(inlined by) xTaskGetSchedulerState at /home/franz/esp-idf-v4.4/components/freertos/tasks.c:4686
0x4008c3d8: spi_flash_enable_interrupts_caches_and_other_cpu at /home/franz/esp-idf-v4.4/components/spi_flash/cache_utils.c:195
0x4008d2fd: cache_enable at /home/franz/esp-idf-v4.4/components/spi_flash/spi_flash_os_func_app.c:63
0x4008d3a2: spi1_end at /home/franz/esp-idf-v4.4/components/spi_flash/spi_flash_os_func_app.c:111
0x400908e9: spiflash_end_default at /home/franz/esp-idf-v4.4/components/spi_flash/esp_flash_api.c:143
0x4008cfcb: esp_flash_read at /home/franz/esp-idf-v4.4/components/spi_flash/esp_flash_api.c:839
0x400fcdf1: esp_partition_read at /home/franz/esp-idf-v4.4/components/spi_flash/partition.c:424
0x400fe767: nvs::NVSPartition::read(unsigned int, void*, unsigned int) at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_partition.cpp:45
0x400ff382: nvs::Page::readEntry(unsigned int, nvs::Item&) const at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_page.cpp:804
0x400ff73d: nvs::Page::findItem(unsigned char, nvs::ItemType, char const*, unsigned int&, nvs::Item&, unsigned char, nvs::VerOffset) at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_page.cpp:848
0x400ff8b9: nvs::Page::cmpItem(unsigned char, nvs::ItemType, char const*, void const*, unsigned int, unsigned char, nvs::VerOffset) at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_page.cpp:329
0x400fe198: nvs::Storage::writeItem(unsigned char, nvs::ItemType, char const*, void const*, unsigned int) at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_storage.cpp:349 (discriminator 1)
0x400fe58e: nvs::NVSHandleSimple::set_typed_item(nvs::ItemType, char const*, void const*, unsigned int) at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_handle_simple.cpp:29
0x401659c7: int nvs::NVSHandle::set_item<int>(char const*, int) at /home/franz/esp-idf-v4.4/components/nvs_flash/include/nvs_handle.hpp:270
0x400fd40b: int nvs_set<int>(unsigned int, char const*, int) at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_api.cpp:356
0x400fd431: nvs_set_i32 at /home/franz/esp-idf-v4.4/components/nvs_flash/src/nvs_api.cpp:381
0x400d822d: app_main at /home/franz/git/hr/2/Sample/bleprph_wifi_coex/build/../main/main.c:613
0x40168c1f: main_task at /home/franz/esp-idf-v4.4/components/freertos/port/port_common.c:129 (discriminator 2)
0x40094c8d: vPortTaskWrapper at /home/franz/esp-idf-v4.4/components/freertos/port/xtensa/port.c:131
ELF file SHA256: 52d248c444207d76
Rebooting...
ets Jul 29 2019 12:21:46
rst:0x3 (SW_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:6612
load:0x40078000,len:14780
load:0x40080400,len:3792
0x40080400: _init at ??:?
entry 0x40080694
I (26) boot: ESP-IDF v4.4-dirty 2nd stage bootloader
I (27) boot: compile time 15:01:49
I (27) boot: chip revision: 3
I (30) boot.esp32: SPI Speed : 40MHz
I (35) boot.esp32: SPI Mode : DIO
I (39) boot.esp32: SPI Flash Size : 2MB
I (44) boot: Enabling RNG early entropy source...
I (49) boot: Partition Table:
I (53) boot: ## Label Usage Type ST Offset Length
I (60) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (67) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (75) boot: 2 factory factory app 00 00 00010000 00177000
I (82) boot: End of partition table
I (87) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=18440h ( 99392) map
I (131) esp_image: segment 1: paddr=00028468 vaddr=3ffbdb60 size=05644h ( 22084) load
I (140) esp_image: segment 2: paddr=0002dab4 vaddr=40080000 size=02564h ( 9572) load
I (144) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=9a42ch (631852) map
I (376) esp_image: segment 4: paddr=000ca454 vaddr=40082564 size=1bc38h (113720) load
I (423) esp_image: segment 5: paddr=000e6094 vaddr=50000000 size=00010h ( 16) load
I (438) boot: Loaded app from partition at offset 0x10000
I (438) boot: Disabling RNG early entropy source...
I (450) psram: This chip is ESP32-D0WD
I (451) spiram: Found 64MBit SPI RAM device
I (451) spiram: SPI RAM mode: flash 40m sram 40m
I (455) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (463) cpu_start: Pro cpu up.
I (466) cpu_start: Starting app cpu, entry point is 0x40081348
0x40081348: call_start_cpu1 at /home/franz/esp-idf-v4.4/components/esp_system/port/cpu_start.c:156
I (0) cpu_start: App cpu up.
@f-hoepfinger-hr-agrartechnik
Could you please check by increasing CONFIG_SPIRAM_MALLOC_ALWAYSINTERNAL
to say 256? Default value for this config is 16384. If you keep value as 0 then it shall redirect all potential allocations with default capabilities to external SPIRAM and that can result in this issue. Of-course, relevant software layers should ensure that allocations that require internal memory must ensure appropriate capabilities while allocating the resource, but we can fix that once you confirm the problem.
After setting CONFIG_SPIRAM_MALLOC_ALWAYSINTERNAL
to 256, it seems to work normally as expected.
We will take a closer look in our continues process.
Kind regards Jannes
Environment
git describe --tags
to find it): // git describe --tagsxtensa-esp32-elf-gcc --version
to find it): // xtensa-esp32-elf-gcc (crosstool-NG esp-2021r2) 8.4.0Problem Description
//Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed).
Expected Behavior
not crahing.
Actual Behavior
crashing
Steps to reproduce
Code to reproduce this issue
https://github.com/hr-agrartechnik/Sample
Debug Logs
Other items if possible