Heap memory issues

I am facing heap memory issues in my code. I am using dynamic memory allocation for saving microphone data into sd card. Along with this I am using wifi also.

CONFIG_HEAP_MEM_POOL_SIZE=153600 this configuration is already large.
I am attaching my code for reference.

Updated_home_with_wifi.zip
Parents
  • Before we dive into your code, Can you please describe what the issues are exactly using the heap? Are you getting heap memory corruption?

    Which companion chip with RAM are you using to control the nRF7002? seems like 153600 is huge chunk of allocation for heap. Have you checked in the memory map if you had that much free space in RAM?

  • So I am using MS12SF1 module (nrf5340+nrf7002). In my application I need to enable wifi as well as collect audio data through pdm microphone and save it into the sd card. When the wifi was not enabled the application was working smoothly but as the wifi configurations was enabled the memory was not getting allocated for microphone.
    Also I am using dynamic allocation because when I tried using static memory I need to take it large enough as the microphone data is coming with speed and is also very large. With small static array it was either facing loses or the generated audio was fast forwarded. Also on using static memory my ram gets increased to 88% but if I use dynamic it stays till 57% around but the issue is in allocation of memory during runtime

    Also I changed something in my code, previously I was allocating memory using k_malloc inside the audio_callback(), but later on I created a separate function for allocating memory by calling the function in main() but nothing changed

  • After checking the heap stats, the below logs were printed before network got connected

    [00:00:00.186,523] <inf> home_demo: INFO: Allocated Heap = 88452

    [00:00:00.186,523] <inf> home_demo: INFO: Free Heap = 64368

    [00:00:00.186,553] <inf> home_demo: INFO: Max Allocated Heap = 88452

    But when I called the heap stats after network got connected, I got

    [00:00:26.442,382] <inf> home_demo: INFO: Allocated Heap = 122120

    [00:00:26.442,382] <inf> home_demo: INFO: Free Heap = 30652

    [00:00:26.442,382] <inf> home_demo: INFO: Max Allocated Heap = 127404

  • There seems to be some additional heap allocated somehwhere after the connection. Try to enable CONFIG_SYS_HEAP_RUNTIME_STATS=in your prj.conf to get some dynamic heap stats to see if we get to understand where the difference in memory after connection is happening.

    Also is that the memory issue you are talking about, the difference in max allocated heap and allocated heap or are you seeing any other side effects of this in the functioning of your app?

Reply
  • There seems to be some additional heap allocated somehwhere after the connection. Try to enable CONFIG_SYS_HEAP_RUNTIME_STATS=in your prj.conf to get some dynamic heap stats to see if we get to understand where the difference in memory after connection is happening.

    Also is that the memory issue you are talking about, the difference in max allocated heap and allocated heap or are you seeing any other side effects of this in the functioning of your app?

Children
  • After enabling the above configuration you mentioned and adding 

    void rtos_hal_print_heap_info(void)
    {
    sys_heap_runtime_stats_get(&_system_heap.heap, &stats);

    LOG_INF("\n");
    LOG_INF("INFO: Allocated Heap = %zu\n", stats.allocated_bytes);
    LOG_INF("INFO: Free Heap = %zu\n", stats.free_bytes);
    LOG_INF("INFO: Max Allocated Heap = %zu\n", stats.max_allocated_bytes);
    LOG_INF("\n");

    return;
    } in my code only I got the allocated heap and free heap 

    On running the code I used to get 
    LOG_ERR("Memory allocation for circular buffer failed\n"); this continuously and if I try to reduce the size of the k_malloc it executes for hardly 1sec and after that I get fault (have set 
    CONFIG_RESET_ON_FATAL_ERROR=n) otherwise before it was getting reset
  • When I don't place the breakpoint in the faults.c, I get 

    [00:00:37.674,804] <err> os: ***** USAGE FAULT *****
    [00:00:37.674,804] <err> os: Illegal load of EXC_RETURN into PC
    [00:00:37.674,835] <err> os: r0/a1: 0x0cdb1640 r1/a2: 0x0cd4162e r2/a3: 0x0cca162c
    [00:00:37.674,835] <err> os: r3/a4: 0x0cc11630 r12/ip: 0x0cbc162a r14/lr: 0x0cc21630
    [00:00:37.674,865] <err> os: xpsr: 0x0ce01600
    [00:00:37.674,865] <err> os: Faulting instruction address (r15/pc): 0x0ccd1635
    [00:00:37.674,896] <err> os: >>> ZEPHYR FATAL ERROR 34: Unknown error on CPU 0
    [00:00:37.674,926] <err> os: Current thread: 0x2000a720 (unknown)
    [00:00:38.072,448] <err> os: Halting system

    So I already made a addr2line.sh file in which I am executing arm-none-eabi-addr2line -e build/zephyr/zephyr.elf pc address 

    So I run ./addr2line.sh 0x0ccd1635 but I get ??:0

  • It is unclear why this fault happens based on the limited logs that is generated. We can improve the information of the fault logs if you add these below in your prj.conf, recompile, flash and run the new binary.

    CONFIG_REBOOT=y
    # CONFIG_RESET_ON_FATAL_ERROR=y
    CONFIG_FATAL_ERROR_LOG_LEVEL_DBG=y
    CONFIG_BT_HCI_VS_FATAL_ERROR=y
    
    
    CONFIG_EXTRA_EXCEPTION_INFO=y
    
    CONFIG_THREAD_NAME=y
    CONFIG_THREAD_ANALYZER=y
    CONFIG_THREAD_STACK_INFO=y
    CONFIG_THREAD_MONITOR=y
    CONFIG_THREAD_ANALYZER_ISR_STACK_USAGE=y
    CONFIG_THREAD_ANALYZER_AUTO_INTERVAL=5
    # CONFIG_THREAD_ANALYZER_USE_PRINTK=n
    CONFIG_THREAD_ANALYZER_AUTO=y
    CONFIG_THREAD_ANALYZER_USE_LOG=y
    
    
    CONFIG_INIT_STACKS=y
    CONFIG_STACK_USAGE=y
    
    #CONFIG_MPU_STACK_GUARD=y
    #CONFIG_STACK_SENTINEL=y
    
    
    
    CONFIG_IDLE_STACK_SIZE=4096
    CONFIG_MAIN_STACK_SIZE=8196
    CONFIG_ISR_STACK_SIZE=8196
    CONFIG_MPSL_WORK_STACK_SIZE=8196
    CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=8196

    With this, we hopefully get more context to see if there is a stack overflow in any thread and which thread executed a instruction that caused a fault.

  • After enabling the above configurations you mentioned, I got the below logs

    [00:00:00.188,476] <inf> fs_nvs: 2 Sectors of 4096 bytes
    [00:00:00.188,476] <inf> fs_nvs: alloc wra: 0, fe8
    [00:00:00.188,507] <inf> fs_nvs: data wra: 0, 0
    *** Booting nRF Connect SDK v2.5.2 ***
    [00:00:00.188,903] <inf> home_demo: UART_RX_BUF_REQUEST
    [00:00:00.188,934] <inf> home_demo: New buffer set successfully
    [00:00:00.188,964] <inf> home_demo: UART initialised
    [00:00:00.191,192] <inf> thread_analyzer: Thread analyze:
    [00:00:00.191,558] <inf> thread_analyzer:  0x2000a3f8          : STACK: unused 1360 usage 2736 / 4096 (66 %); CPU: 0 %
    [00:00:00.191,558] <inf> thread_analyzer:       : Total CPU cycles used: 11
    [00:00:00.191,711] <inf> thread_analyzer:  thread_analyzer     : STACK: unused 536 usage 488 / 1024 (47 %); CPU: 0 %
    [00:00:00.191,711] <inf> thread_analyzer:       : Total CPU cycles used: 16
    [00:00:00.203,918] <inf> thread_analyzer:  pcm_thread_id       : STACK: unused 3912 usage 18--- 45[00:00:02.782,440] <inf> wifi_mgmt_ext: Connection requested
    [00:00:03.570,129] <inf> home_demo: UART_RX_RDY
    [00:00:03.572,692] <inf> home_demo: The data from prodo is: 00:00:03 {"Hcho-mg/m3": 0.00,"Co-PPM": 0,"Co2-PPM": 1048,"Pm1.0-µg/m3": 8,"Pm10-µg/m3": 9,"Pm25-µg/m3": 8,"Voc-mg/m3": 0,"Temp-°C": 71,"Hum-": 70,"Noi-DB": 47,"UVA-mw/cm2": 0.07,"UVB-mw/cm2": 0.00,"UVC-mw/cm2": 0.00,"RED": 4,"GREEN": 422,"BLUE": 319,"IR": 10}
    
    [00:00:03.578,613] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:03.578,643] <inf> home_demo: Buffer is released
    [00:00:03.578,643] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:03.578,674] <inf> home_demo: Buffer is released
    [00:00:03.578,674] <inf> home_demo: UART_RX_DISABLED
    [00:00:03.578,704] <inf> home_demo: UART_RX_BUF_REQUEST
    [00:00:03.578,735] <inf> home_demo: New buffer set successfully
    [00:00:05.222,625] <inf> thread_analyzer: Thread analyze:
    [00:00:05.223,419] <inf> thread_analyzer:  0x2000a2f8          : STACK: unused 5968 usage 176 / 6144 (2 %); CPU: 0 %
    [00:00:05.223,449] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:05.223,663] <inf> thread_analyzer:  0x2000a3f8          : STACK: unused 1208 usage 2888 / 4096 (70 %); CPU: 0 %
    [00:00:05.223,663] <inf> thread_analyzer:       : Total CPU cycles used: 72
    [00:00:05.223,754] <inf> thread_analyzer:  thread_analyzer     : STACK: unused 504 usage 520 / 1024 (50 %); CPU: 0 %
    [00:00:05.223,785] <inf> thread_analyzer:       : Total CPU cycles used: 421
    [00:00:05.224,273] <inf> thread_analyzer:  pcm_thread_id       : STACK: unused 3912 usage 184 / 4096 (4 %); CPU: 0 %
    [00:00:05.224,304] <inf> thread_analyzer:       : Total CPU cycles used: 65
    [00:00:05.225,006] <inf> thread_analyzer:  0x2000a1e8          : STACK: unused 5216 usage 2976 / 8192 (36 %); CPU: 0 %
    [00:00:05.225,006] <inf> thread_analyzer:       : Total CPU cycles used: 501
    [00:00:05.225,830] <inf> thread_analyzer:  0x2000a4f8          : STACK: unused 6224 usage 1968 / 8192 (24 %); CPU: 84 %
    [00:00:05.225,860] <inf> thread_analyzer:       : Total CPU cycles used: 143660
    [00:00:05.226,348] <inf> thread_analyzer:  rx_q[0]             : STACK: unused 3968 usage 128 / 4096 (3 %); CPU: 0 %
    [00:00:05.226,379] <inf> thread_analyzer:       : Total CPU cycles used: 1
    [00:00:05.226,867] <inf> thread_analyzer:  net_mgmt            : STACK: unused 3840 usage 256 / 4096 (6 %); CPU: 0 %
    [00:00:05.226,867] <inf> thread_analyzer:       : Total CPU cycles used: 2
    [00:00:05.227,203] <inf> thread_analyzer:  tcp_work            : STACK: unused 1872 usage 176 / 2048 (8 %); CPU: 0 %
    [00:00:05.227,203] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:05.228,454] <inf> thread_analyzer:  sysworkq            : STACK: unused 7944 usage 256 / 8200 (3 %); CPU: 0 %
    [00:00:05.228,454] <inf> thread_analyzer:       : Total CPU cycles used: 52
    [00:00:05.228,698] <inf> thread_analyzer:  0x2000a5d8          : STACK: unused 1448 usage 600 / 2048 (29 %); CPU: 0 %
    [00:00:05.228,729] <inf> thread_analyzer:       : Total CPU cycles used: 378
    [00:00:05.228,912] <inf> thread_analyzer:  0x2000a6d8          : STACK: unused 1072 usage 976 / 2048 (47 %); CPU: 0 %
    [00:00:05.228,912] <inf> thread_analyzer:       : Total CPU cycles used: 144
    [00:00:05.228,973] <inf> thread_analyzer:  logging             : STACK: unused 216 usage 552 / 768 (71 %); CPU: 0 %
    [00:00:05.229,003] <inf> thread_analyzer:       : Total CPU cycles used: 491
    [00:00:05.229,522] <inf> thread_analyzer:  idle                : STACK: unused 4048 usage 48 / 4096 (1 %); CPU: 13 %
    [00:00:05.229,522] <inf> thread_analyzer:       : Total CPU cycles used: 23493
    [00:00:05.230,224] <inf> thread_analyzer:  main                : STACK: unused 5456 usage 2744 / 8200 (33 %); CPU: 0 %
    [00:00:05.230,224] <inf> thread_analyzer:       : Total CPU cycles used: 1462
    [00:00:05.231,140] <inf> thread_analyzer:  ISR0                : STACK: unused 6960 usage 1240 / 8200 (15 %)
    [00:00:09.384,429] <inf> home_demo: UART_RX_RDY
    [00:00:09.387,054] <inf> home_demo: The data from prodo is: 00:00:09 {"Hcho-mg/m3": 0.00,"Co-PPM": 0,"Co2-PPM": 1012,"Pm1.0-µg/m3": 8,"Pm10-µg/m3": 9,"Pm25-µg/m3": 8,"Voc-mg/m3": 0,"Temp-°C": 71,"Hum-": 69,"Noi-DB": 40,"UVA-mw/cm2": 0.07,"UVB-mw/cm2": 0.00,"UVC-mw/cm2": 0.00,"RED": 4,"GREEN": 423,"BLUE": 320,"IR": 10}
    
    [00:00:09.393,066] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:09.393,096] <inf> home_demo: Buffer is released
    [00:00:09.393,096] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:09.393,127] <inf> home_demo: Buffer is released
    [00:00:09.393,127] <inf> home_demo: UART_RX_DISABLED
    [00:00:09.393,188] <inf> home_demo: UART_RX_BUF_REQUEST
    [00:00:09.393,188] <inf> home_demo: New buffer set successfully
    [00:00:10.231,201] <inf> thread_analyzer: Thread analyze:
    [00:00:10.231,994] <inf> thread_analyzer:  0x2000a2f8          : STACK: unused 5968 usage 176 / 6144 (2 %); CPU: 0 %
    [00:00:10.232,025] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:10.232,238] <inf> thread_analyzer:  0x2000a3f8          : STACK: unused 1208 usage 2888 / 4096 (70 %); CPU: 0 %
    [00:00:10.232,238] <inf> thread_analyzer:       : Total CPU cycles used: 81
    [00:00:10.232,330] <inf> thread_analyzer:  thread_analyzer     : STACK: unused 504 usage 520 / 1024 (50 %); CPU: 0 %
    [00:00:10.232,360] <inf> thread_analyzer:       : Total CPU cycles used: 700
    [00:00:10.232,849] <inf> thread_analyzer:  pcm_thread_id       : STACK: unused 3832 usage 264 / 4096 (6 %); CPU: 0 %
    [00:00:10.232,849] <inf> thread_analyzer:       : Total CPU cycles used: 534
    [00:00:10.233,551] <inf> thread_analyzer:  0x2000a1e8          : STACK: unused 5216 usage 2976 / 8192 (36 %); CPU: 0 %
    [00:00:10.233,581] <inf> thread_analyzer:       : Total CPU cycles used: 501
    [00:00:10.234,344] <inf> thread_analyzer:  0x2000a4f8          : STACK: unused 5648 usage 2544 / 8192 (31 %); CPU: 42 %
    [00:00:10.234,375] <inf> thread_analyzer:       : Total CPU cycles used: 143878
    [00:00:10.234,954] <inf> thread_analyzer:  rx_q[0]             : STACK: unused 3968 usage 128 / 4096 (3 %); CPU: 0 %
    [00:00:10.234,954] <inf> thread_analyzer:       : Total CPU cycles used: 1
    [00:00:10.235,443] <inf> thread_analyzer:  net_mgmt            : STACK: unused 3840 usage 256 / 4096 (6 %); CPU: 0 %
    [00:00:10.235,473] <inf> thread_analyzer:       : Total CPU cycles used: 2
    [00:00:10.235,717] <inf> thread_analyzer:  tcp_work            : STACK: unused 1872 usage 176 / 2048 (8 %); CPU: 0 %
    [00:00:10.235,748] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:10.236,968] <inf> thread_analyzer:  sysworkq            : STACK: unused 7944 usage 256 / 8200 (3 %); CPU: 0 %
    [00:00:10.236,968] <inf> thread_analyzer:       : Total CPU cycles used: 155
    [00:00:10.237,213] <inf> thread_analyzer:  0x2000a5d8          : STACK: unused 1448 usage 600 / 2048 (29 %); CPU: 0 %
    [00:00:10.237,243] <inf> thread_analyzer:       : Total CPU cycles used: 1062
    [00:00:10.237,426] <inf> thread_analyzer:  0x2000a6d8          : STACK: unused 1072 usage 976 / 2048 (47 %); CPU: 0 %
    [00:00:10.237,457] <inf> thread_analyzer:       : Total CPU cycles used: 997
    [00:00:10.237,487] <inf> thread_analyzer:  logging             : STACK: unused 160 usage 608 / 768 (79 %); CPU: 0 %
    [00:00:10.237,518] <inf> thread_analyzer:       : Total CPU cycles used: 779
    [00:00:10.238,037] <inf> thread_analyzer:  idle                : STACK: unused 4048 usage 48 / 4096 (1 %); CPU: 55 %
    [00:00:10.238,037] <inf> thread_analyzer:       : Total CPU cycles used: 184460
    [00:00:10.238,739] <inf> thread_analyzer:  main                : STACK: unused 5456 usage 2744 / 8200 (33 %); CPU: 0 %
    [00:00:10.238,739] <inf> thread_analyzer:       : Total CPU cycles used: 1462
    [00:00:10.239,624] <inf> thread_analyzer:  ISR0                : STACK: unused 6960 usage 1240 / 8200 (15 %)
    [00:00:15.188,873] <inf> home_demo: UART_RX_RDY
    [00:00:15.191,497] <inf> home_demo: The data from prodo is: 00:00:15 {"Hcho-mg/m3": 0.00,"Co-PPM": 0,"Co2-PPM": 975,"Pm1.0-µg/m3": 8,"Pm10-µg/m3": 9,"Pm25-µg/m3": 8,"Voc-mg/m3": 0,"Temp-°C": 71,"Hum-": 69,"Noi-DB": 39,"UVA-mw/cm2": 0.07,"UVB-mw/cm2": 0.00,"UVC-mw/cm2": 0.00,"RED": 4,"GREEN": 423,"BLUE": 320,"IR": 10}
    
    [00:00:15.197,509] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:15.197,540] <inf> home_demo: Buffer is released
    [00:00:15.197,540] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:15.197,570] <inf> home_demo: Buffer is released
    [00:00:15.197,570] <inf> home_demo: UART_RX_DISABLED
    [00:00:15.197,601] <inf> home_demo: UART_RX_BUF_REQUEST
    [00:00:15.197,631] <inf> home_demo: New buffer set successfully
    [00:00:15.239,685] <inf> thread_analyzer: Thread analyze:
    [00:00:15.240,478] <inf> thread_analyzer:  0x2000a2f8          : STACK: unused 5968 usage 176 / 6144 (2 %); CPU: 0 %
    [00:00:15.240,509] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:15.240,722] <inf> thread_analyzer:  0x2000a3f8          : STACK: unused 1208 usage 2888 / 4096 (70 %); CPU: 0 %
    [00:00:15.240,722] <inf> thread_analyzer:       : Total CPU cycles used: 90
    [00:00:15.240,814] <inf> thread_analyzer:  thread_analyzer     : STACK: unused 504 usage 520 / 1024 (50 %); CPU: 0 %
    [00:00:15.240,814] <inf> thread_analyzer:       : Total CPU cycles used: 976
    [00:00:15.241,333] <inf> thread_analyzer:  pcm_thread_id       : STACK: unused 3832 usage 264 / 4096 (6 %); CPU: 0 %
    [00:00:15.241,333] <inf> thread_analyzer:       : Total CPU cycles used: 1018
    [00:00:15.242,095] <inf> thread_analyzer:  0x2000a1e8          : STACK: unused 5216 usage 2976 / 8192 (36 %); CPU: 0 %
    [00:00:15.242,095] <inf> thread_analyzer:       : Total CPU cycles used: 501
    [00:00:15.242,858] <inf> thread_analyzer:  0x2000a4f8          : STACK: unused 5648 usage 2544 / 8192 (31 %); CPU: 28 %
    [00:00:15.242,858] <inf> thread_analyzer:       : Total CPU cycles used: 144209
    [00:00:15.243,377] <inf> thread_analyzer:  rx_q[0]             : STACK: unused 3968 usage 128 / 4096 (3 %); CPU: 0 %
    [00:00:15.243,408] <inf> thread_analyzer:       : Total CPU cycles used: 1
    [00:00:15.243,896] <inf> thread_analyzer:  net_mgmt            : STACK: unused 3840 usage 256 / 4096 (6 %); CPU: 0 %
    [00:00:15.243,896] <inf> thread_analyzer:       : Total CPU cycles used: 2
    [00:00:15.244,171] <inf> thread_analyzer:  tcp_work            : STACK: unused 1872 usage 176 / 2048 (8 %); CPU: 0 %
    [00:00:15.244,171] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:15.245,422] <inf> thread_analyzer:  sysworkq            : STACK: unused 7944 usage 256 / 8200 (3 %); CPU: 0 %
    [00:00:15.245,422] <inf> thread_analyzer:       : Total CPU cycles used: 199
    [00:00:15.245,666] <inf> thread_analyzer:  0x2000a5d8          : STACK: unused 1448 usage 600 / 2048 (29 %); CPU: 0 %
    [00:00:15.245,697] <inf> thread_analyzer:       : Total CPU cycles used: 1444
    [00:00:15.245,880] <inf> thread_analyzer:  0x2000a6d8          : STACK: unused 1072 usage 976 / 2048 (47 %); CPU: 0 %
    [00:00:15.245,880] <inf> thread_analyzer:       : Total CPU cycles used: 1330
    [00:00:15.245,941] <inf> thread_analyzer:  logging             : STACK: unused 160 usage 608 / 768 (79 %); CPU: 0 %
    [00:00:15.245,941] <inf> thread_analyzer:       : Total CPU cycles used: 1138
    [00:00:15.246,490] <inf> thread_analyzer:  idle                : STACK: unused 4048 usage 48 / 4096 (1 %); CPU: 69 %
    [00:00:15.246,490] <inf> thread_analyzer:       : Total CPU cycles used: 346225
    [00:00:15.247,192] <inf> thread_analyzer:  main                : STACK: unused 5456 usage 2744 / 8200 (33 %); CPU: 0 %
    [00:00:15.247,192] <inf> thread_analyzer:       : Total CPU cycles used: 1462
    [00:00:15.248,077] <inf> thread_analyzer:  ISR0                : STACK: unused 6960 usage 1240 / 8200 (15 %)
    [00:00:20.248,168] <inf> thread_analyzer: Thread analyze:
    [00:00:20.248,992] <inf> thread_analyzer:  0x2000a2f8          : STACK: unused 5968 usage 176 / 6144 (2 %); CPU: 0 %
    [00:00:20.248,992] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:20.249,206] <inf> thread_analyzer:  0x2000a3f8          : STACK: unused 1208 usage 2888 / 4096 (70 %); CPU: 0 %
    [00:00:20.249,206] <inf> thread_analyzer:       : Total CPU cycles used: 99
    [00:00:20.249,298] <inf> thread_analyzer:  thread_analyzer     : STACK: unused 504 usage 520 / 1024 (50 %); CPU: 0 %
    [00:00:20.249,328] <inf> thread_analyzer:       : Total CPU cycles used: 1252
    [00:00:20.249,816] <inf> thread_analyzer:  pcm_thread_id       : STACK: unused 3832 usage 264 / 4096 (6 %); CPU: 0 %
    [00:00:20.249,816] <inf> thread_analyzer:       : Total CPU cycles used: 1510
    [00:00:20.250,518] <inf> thread_analyzer:  0x2000a1e8          : STACK: unused 5216 usage 2976 / 8192 (36 %); CPU: 0 %
    [00:00:20.250,549] <inf> thread_analyzer:       : Total CPU cycles used: 501
    [00:00:20.251,312] <inf> thread_analyzer:  0x2000a4f8          : STACK: unused 5648 usage 2544 / 8192 (31 %); CPU: 21 %
    [00:00:20.251,312] <inf> thread_analyzer:       : Total CPU cycles used: 144708
    [00:00:20.251,831] <inf> thread_analyzer:  rx_q[0]             : STACK: unused 3968 usage 128 / 4096 (3 %); CPU: 0 %
    [00:00:20.251,831] <inf> thread_analyzer:       : Total CPU cycles used: 1
    [00:00:20.252,349] <inf> thread_analyzer:  net_mgmt            : STACK: unused 3840 usage 256 / 4096 (6 %); CPU: 0 %
    [00:00:20.252,349] <inf> thread_analyzer:       : Total CPU cycles used: 2
    [00:00:20.252,655] <inf> thread_analyzer:  tcp_work            : STACK: unused 1872 usage 176 / 2048 (8 %); CPU: 0 %
    [00:00:20.252,655] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:20.253,906] <inf> thread_analyzer:  sysworkq            : STACK: unused 7944 usage 256 / 8200 (3 %); CPU: 0 %
    [00:00:20.253,906] <inf> thread_analyzer:       : Total CPU cycles used: 221
    [00:00:20.254,150] <inf> thread_analyzer:  0x2000a5d8          : STACK: unused 1448 usage 600 / 2048 (29 %); CPU: 0 %
    [00:00:20.254,180] <inf> thread_analyzer:       : Total CPU cycles used: 1777
    [00:00:20.254,364] <inf> thread_analyzer:  0x2000a6d8          : STACK: unused 1072 usage 976 / 2048 (47 %); CPU: 0 %
    [00:00:20.254,364] <inf> thread_analyzer:       : Total CPU cycles used: 1521
    [00:00:20.254,425] <inf> thread_analyzer:  logging             : STACK: unused 160 usage 608 / 768 (79 %); CPU: 0 %
    [00:00:20.254,425] <inf> thread_analyzer:       : Total CPU cycles used: 1492
    [00:00:20.254,974] <inf> thread_analyzer:  idle                : STACK: unused 4048 usage 48 / 4096 (1 %); CPU: 76 %
    [00:00:20.254,974] <inf> thread_analyzer:       : Total CPU cycles used: 508022
    [00:00:20.255,737] <inf> thread_analyzer:  main                : STACK: unused 5456 usage 2744 / 8200 (33 %); CPU: 0 %
    [00:00:20.255,737] <inf> thread_analyzer:       : Total CPU cycles used: 1462
    [00:00:20.256,622] <inf> thread_analyzer:  ISR0                : STACK: unused 6960 usage 1240 / 8200 (15 %)
    [00:00:20.993,286] <inf> home_demo: UART_RX_RDY
    [00:00:20.995,910] <inf> home_demo: The data from prodo is: 00:00:20 {"Hcho-mg/m3": 0.00,"Co-PPM": 0,"Co2-PPM": 938,"Pm1.0-µg/m3": 8,"Pm10-µg/m3": 9,"Pm25-µg/m3": 8,"Voc-mg/m3": 0,"Temp-°C": 71,"Hum-": 69,"Noi-DB": 39,"UVA-mw/cm2": 0.07,"UVB-mw/cm2": 0.00,"UVC-mw/cm2": 0.00,"RED": 4,"GREEN": 423,"BLUE": 320,"IR": 10}
    
    [00:00:21.001,892] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:21.001,892] <inf> home_demo: Buffer is released
    [00:00:21.001,922] <inf> home_demo: UART_RX_BUF_RELEASED
    
    [00:00:21.001,953] <inf> home_demo: Buffer is released
    [00:00:21.001,953] <inf> home_demo: UART_RX_DISABLED
    [00:00:21.001,983] <inf> home_demo: UART_RX_BUF_REQUEST
    [00:00:21.002,014] <inf> home_demo: New buffer set successfully
    [00:00:25.256,683] <inf> thread_analyzer: Thread analyze:
    [00:00:25.257,476] <inf> thread_analyzer:  0x2000a2f8          : STACK: unused 5968 usage 176 / 6144 (2 %); CPU: 0 %
    [00:00:25.257,507] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:25.257,720] <inf> thread_analyzer:  0x2000a3f8          : STACK: unused 1208 usage 2888 / 4096 (70 %); CPU: 0 %
    [00:00:25.257,720] <inf> thread_analyzer:       : Total CPU cycles used: 106
    [00:00:25.257,812] <inf> thread_analyzer:  thread_analyzer     : STACK: unused 504 usage 520 / 1024 (50 %); CPU: 0 %
    [00:00:25.257,843] <inf> thread_analyzer:       : Total CPU cycles used: 1529
    [00:00:25.258,331] <inf> thread_analyzer:  pcm_thread_id       : STACK: unused 3832 usage 264 / 4096 (6 %); CPU: 0 %
    [00:00:25.258,331] <inf> thread_analyzer:       : Total CPU cycles used: 1990
    [00:00:25.259,033] <inf> thread_analyzer:  0x2000a1e8          : STACK: unused 5216 usage 2976 / 8192 (36 %); CPU: 0 %
    [00:00:25.259,063] <inf> thread_analyzer:       : Total CPU cycles used: 501
    [00:00:25.259,796] <inf> thread_analyzer:  0x2000a4f8          : STACK: unused 5648 usage 2544 / 8192 (31 %); CPU: 17 %
    [00:00:25.259,826] <inf> thread_analyzer:       : Total CPU cycles used: 144880
    [00:00:25.260,345] <inf> thread_analyzer:  rx_q[0]             : STACK: unused 3968 usage 128 / 4096 (3 %); CPU: 0 %
    [00:00:25.260,345] <inf> thread_analyzer:       : Total CPU cycles used: 1
    [00:00:25.260,833] <inf> thread_analyzer:  net_mgmt            : STACK: unused 3840 usage 256 / 4096 (6 %); CPU: 0 %
    [00:00:25.260,864] <inf> thread_analyzer:       : Total CPU cycles used: 2
    [00:00:25.261,108] <inf> thread_analyzer:  tcp_work            : STACK: unused 1872 usage 176 / 2048 (8 %); CPU: 0 %
    [00:00:25.261,138] <inf> thread_analyzer:       : Total CPU cycles used: 0
    [00:00:25.262,359] <inf> thread_analyzer:  sysworkq            : STACK: unused 7944 usage 256 / 8200 (3 %); CPU: 0 %
    [00:00:25.262,359] <inf> thread_analyzer:       : Total CPU cycles used: 295
    [00:00:25.262,664] <inf> thread_analyzer:  0x2000a5d8          : STACK: unused 1448 usage 600 / 2048 (29 %); CPU: 0 %
    [00:00:25.262,695] <inf> thread_analyzer:       : Total CPU cycles used: 2245
    [00:00:25.262,878] <inf> thread_analyzer:  0x2000a6d8          : STACK: unused 1072 usage 976 / 2048 (47 %); CPU: 0 %
    [00:00:25.262,908] <inf> thread_analyzer:       : Total CPU cycles used: 2129
    [00:00:25.262,939] <inf> thread_analyzer:  logging             : STACK: unused 160 usage 608 / 768 (79 %); CPU: 0 %
    [00:00:25.262,969] <inf> thread_analyzer:       : Total CPU cycles used: 1845
    [00:00:25.263,488] <inf> thread_analyzer:  idle                : STACK: unused 4048 usage 48 / 4096 (1 %); CPU: 80 %
    [00:00:25.263,488] <inf> thread_analyzer:       : Total CPU cycles used: 669534
    [00:00:25.264,190] <inf> thread_analyzer:  main                : STACK: unused 5456 usage 2744 / 8200 (33 %); CPU: 0 %
    [00:00:25.264,190] <inf> thread_analyzer:       : Total CPU cycles used: 1462
    [00:00:25.265,075] <inf> thread_analyzer:  ISR0                : STACK: unused 6960 usage 1240 / 8200 (15 %)
    [00:00:26.238,189] <inf> home_demo: Network connected
    [00:00:26.238,586] <inf> home_demo: ################
    [00:00:26.391,326] <inf> home_demo: Block count 31116288
    Sector size 512
    Memory Size(MB) 15193
    Disk mounted.
    
    Listing dir /SD: ...
    [FILE] RIFF$ (size = 0)
    [FILE]  (size = 0)
    [FILE] MIC.WAV (size = 68724736)
    [FILE] TESTFILE.TXT (size = 68444)
    [DIR ] SPOTLI~4
    [DIR ] FSEVEN~7
    [FILE] _TESTF~9.TXT (size = 4096)
    [DIR ] TEMPO~12
    [FILE] _MI~15.WAV (size = 4096)
    [FILE] MICRO.WAV (size = 20598828)
    [FILE] _MICR~18.WAV (size = 4096)
    [00:00:26.400,848] <inf> home_demo: 
    
    [00:00:26.400,848] <inf> home_demo: INFO: Allocated Heap = 122060
    
    [00:00:26.400,848] <inf> home_demo: INFO: Free Heap = 30708
    
    [00:00:26.400,878] <inf> home_demo: INFO: Max Allocated Heap = 127404
    
    [00:00:26.400,878] <inf> home_demo: 
    
    [00:00:26.409,698] <inf> home_demo: Mic switch is on at startup
    [00:00:26.409,729] <inf> home_demo: PDM start was successful at startup
    [00:00:26.416,656] <inf> home_demo: Wrote 262 bytes to file /SD:/testfile.txt
    
    [00:00:26.440,887] <err> home_demo: Memory allocation for circular buffer failed
    
    [00:00:26.472,015] <err> home_demo: Memory allocation for circular buffer failed
    
    [00:00:26.503,143] <err> home_demo: Memory allocation for circular buffer failed
    

Related