Page 1 of 1

[in work to solve/pull] nvs_flash_init() let hang up the boot (pinnedToCore) process

Posted: Thu Feb 23, 2017 2:01 am
by rudi ;-)
[ no hurry! will look after a week here again]


hi

Stumble straight over a problem with
nvs_flash_init ();

It seems the code hangs at this point.
I use the hello world example
It has changed a little
Use on both cores freertos
And have a task pinned on each core.

Here the first part of the code is always the same:

Code: Select all

/* Hello World Example

   This example code is in the Public Domain (or CC0 licensed, at your option.)

   Unless required by applicable law or agreed to in writing, this
   software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR
   CONDITIONS OF ANY KIND, either express or implied.
*/
#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_system.h"
#include "nvs_flash.h"

#define core_0 0
#define core_1 1

void hello_task_core_1(void *pvParameter)
{
	
	while(1){
    printf("Hello world from core:%d!\n", xPortGetCoreID() );
    vTaskDelay(872 / portTICK_PERIOD_MS);
    fflush(stdout);
	} 
}

void hello_task_core_0(void *pvParameter)
{

	while(1) {
    printf("Hello world from core:%d!\n", xPortGetCoreID() );
	vTaskDelay(1323 / portTICK_PERIOD_MS);
    fflush(stdout);
	}
}
And the changed code in the app_main
Is listed in the 5 tests.

have make on each test

-> make erase_flash
-> make clean
-> make -j8 all
-> make flash monitor

uses the last esp-idf ( without the spi pull request )


please have a look:


Test 1: with nvs_flash_init
reboots..

Code: Select all

void app_main()
{
nvs_flash_init();
// printf("printf in app_main [before taskCreate]\n");
xTaskCreatePinnedToCore(&hello_task_core_1, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
xTaskCreatePinnedToCore(&hello_task_core_0, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
// printf("in app_main [after taskCreate]\n");
}
I (44) boot: ESP-IDF v2.0-rc1-73-g61c7bd3 2nd stage bootloader
I (44) boot: compile time 02:42:36
I (45) boot: Enabling RNG early entropy source...
I (65) boot: SPI Speed : 40MHz
I (77) boot: SPI Mode : DIO
I (90) boot: SPI Flash Size : 4MB
I (102) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (136) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (159) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (183) boot: 2 factory factory app 00 00 00010000 00100000
I (206) boot: End of partition table
I (219) boot: Disabling RNG early entropy source...
I (236) boot: Loading app partition at offset 00010000
I (518) boot: segment 0: paddr=0x00010018 vaddr=0x00000000 size=0x0ffe8 ( 65512)
I (519) boot: segment 1: paddr=0x00020008 vaddr=0x3f400010 size=0x02eb4 ( 11956) map
I (535) boot: segment 2: paddr=0x00022ec4 vaddr=0x3ffb0000 size=0x01af0 ( 6896) load
I (564) boot: segment 3: paddr=0x000249bc vaddr=0x40080000 size=0x00400 ( 1024) load
I (588) boot: segment 4: paddr=0x00024dc4 vaddr=0x40080400 size=0x08858 ( 34904) load
I (630) boot: segment 5: paddr=0x0002d624 vaddr=0x400c0000 size=0x00000 ( 0) load
I (640) boot: segment 6: paddr=0x0002d62c vaddr=0x00000000 size=0x029dc ( 10716)
I (665) boot: segment 7: paddr=0x00030010 vaddr=0x400d0018 size=0x0e004 ( 57348) map
I (691) heap_alloc_caps: Initializing. RAM available for dynamic allocation:
I (714) heap_alloc_caps: At 3FFB22F8 len 0002DD08 (183 KiB): DRAM
I (735) heap_alloc_caps: At 3FFE8000 len 00018000 (96 KiB): D/IRAM
I (756) heap_alloc_caps: At 40088C58 len 000173A8 (92 KiB): IRAM
I (777) cpu_start: Pro cpu up.
I (788) cpu_start: Starting app cpu, entry point is 0x40080a5c
I (0) cpu_start: App cpu up.
I (819) cpu_start: Pro cpu start user code
I (880) cpu_start: Starting scheduler on PRO CPU.
I (81) cpu_start: Starting scheduler on APP CPU.
Hello world from core:0!
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0)
Register dump:
PC : 0x400d1e58 PS : 0x00060634 A0 : 0x80082fd6 A1 : 0x3ffb9c10
A2 : 0x3ffba2a8 A3 : 0x00060623 A4 : 0x00060620 A5 : 0x00000019
A6 : 0x00000000 A7 : 0x00000000 A8 : 0xb33f0001 A9 : 0x00000001
A10 : 0x00060623 A11 : 0x00000000 A12 : 0x3ffb4648 A13 : 0x00000019
A14 : 0x3ffb2330 A15 : 0x00000000 SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xffffffff

Backtrace:
0x400d1e58:0x3ffb9c10 0x40082fd6:0x3ffb9c30 0x4008433c:0x3ffb9c50 0x40084490:0x3ffb9c90
0x40081902:0x3ffb9cb0 0x400819be:0x3ffb9ce0 0x400d9cad:0x3ffb9d00 0x400dc3d4:0x3ffba010
0x400db9b3:0x3ffba060

Rebooting...
ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x16 (SPI_FAST_FLASH_BOOT)




Test 2: without nvs_flash_init
run..

Code: Select all

void app_main()
{
// nvs_flash_init();
// printf("printf in app_main [before taskCreate]\n");
xTaskCreatePinnedToCore(&hello_task_core_1, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
xTaskCreatePinnedToCore(&hello_task_core_0, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
// printf("in app_main [after taskCreate]\n");
}
I (44) boot: ESP-IDF v2.0-rc1-73-g61c7bd3 2nd stage bootloader
I (44) boot: compile time 01:59:14
I (45) boot: Enabling RNG early entropy source...
I (65) boot: SPI Speed : 40MHz
I (77) boot: SPI Mode : DIO
I (90) boot: SPI Flash Size : 4MB
I (102) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (136) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (159) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (183) boot: 2 factory factory app 00 00 00010000 00100000
I (206) boot: End of partition table
I (219) boot: Disabling RNG early entropy source...
I (236) boot: Loading app partition at offset 00010000
I (510) boot: segment 0: paddr=0x00010018 vaddr=0x00000000 size=0x0ffe8 ( 65512)
I (510) boot: segment 1: paddr=0x00020008 vaddr=0x3f400010 size=0x025cc ( 9676) map
I (526) boot: segment 2: paddr=0x000225dc vaddr=0x3ffb0000 size=0x01aec ( 6892) load
I (555) boot: segment 3: paddr=0x000240d0 vaddr=0x40080000 size=0x00400 ( 1024) load
I (579) boot: segment 4: paddr=0x000244d8 vaddr=0x40080400 size=0x08858 ( 34904) load
I (622) boot: segment 5: paddr=0x0002cd38 vaddr=0x400c0000 size=0x00000 ( 0) load
I (631) boot: segment 6: paddr=0x0002cd40 vaddr=0x00000000 size=0x032c8 ( 13000)
I (656) boot: segment 7: paddr=0x00030010 vaddr=0x400d0018 size=0x0c854 ( 51284) map
I (683) heap_alloc_caps: Initializing. RAM available for dynamic allocation:
I (706) heap_alloc_caps: At 3FFB2280 len 0002DD80 (183 KiB): DRAM
I (726) heap_alloc_caps: At 3FFE8000 len 00018000 (96 KiB): D/IRAM
I (747) heap_alloc_caps: At 40088C58 len 000173A8 (92 KiB): IRAM
I (768) cpu_start: Pro cpu up.
I (780) cpu_start: Starting app cpu, entry point is 0x40080a5c
I (0) cpu_start: App cpu up.
I (811) cpu_start: Pro cpu start user code
I (871) cpu_start: Starting scheduler on PRO CPU.
Hello world from core:0!
I (80) cpu_start: Starting scheduler on APP CPU.
Hello world from core:1!
Hello world from core:1!
Hello world from core:0!
Hello world from core:1!
Hello world from core:1!
Hello world from core:0!
Hello world from core:1!
Hello world from core:0!
Hello world from core:1!
Hello world from core:1!
..



Test 3:
with nvs_flash_init
with printf after nvs_flash_init ( before xTaskCreate )
reboots..

Code: Select all

void app_main()
{
nvs_flash_init();
printf("printf in app_main [before taskCreate]\n");
xTaskCreatePinnedToCore(&hello_task_core_1, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
xTaskCreatePinnedToCore(&hello_task_core_0, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
// printf("in app_main [after taskCreate]\n");
}
I (44) boot: ESP-IDF v2.0-rc1-73-g61c7bd3 2nd stage bootloader
I (44) boot: compile time 02:09:46
I (45) boot: Enabling RNG early entropy source...
I (65) boot: SPI Speed : 40MHz
I (77) boot: SPI Mode : DIO
I (90) boot: SPI Flash Size : 4MB
I (102) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (136) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (159) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (183) boot: 2 factory factory app 00 00 00010000 00100000
I (206) boot: End of partition table
I (219) boot: Disabling RNG early entropy source...
I (236) boot: Loading app partition at offset 00010000
I (518) boot: segment 0: paddr=0x00010018 vaddr=0x00000000 size=0x0ffe8 ( 65512)
I (519) boot: segment 1: paddr=0x00020008 vaddr=0x3f400010 size=0x02edc ( 11996) map
I (535) boot: segment 2: paddr=0x00022eec vaddr=0x3ffb0000 size=0x01af0 ( 6896) load
I (564) boot: segment 3: paddr=0x000249e4 vaddr=0x40080000 size=0x00400 ( 1024) load
I (588) boot: segment 4: paddr=0x00024dec vaddr=0x40080400 size=0x08858 ( 34904) load
I (630) boot: segment 5: paddr=0x0002d64c vaddr=0x400c0000 size=0x00000 ( 0) load
I (640) boot: segment 6: paddr=0x0002d654 vaddr=0x00000000 size=0x029b4 ( 10676)
I (665) boot: segment 7: paddr=0x00030010 vaddr=0x400d0018 size=0x0e0c0 ( 57536) map
I (692) heap_alloc_caps: Initializing. RAM available for dynamic allocation:
I (714) heap_alloc_caps: At 3FFB22F8 len 0002DD08 (183 KiB): DRAM
I (735) heap_alloc_caps: At 3FFE8000 len 00018000 (96 KiB): D/IRAM
I (756) heap_alloc_caps: At 40088C58 len 000173A8 (92 KiB): IRAM
I (777) cpu_start: Pro cpu up.
I (788) cpu_start: Starting app cpu, entry point is 0x40080a5c
I (0) cpu_start: App cpu up.
I (819) cpu_start: Pro cpu start user code
I (880) cpu_start: Starting scheduler on PRO CPU.
I (81) cpu_start: Starting scheduler on APP CPU.
printf in app_main [before taskCreate]
Hello world from core:0!
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0)
Register dump:
PC : 0x400d1e60 PS : 0x00060234 A0 : 0x80082fd6 A1 : 0x3ffb9cc0
A2 : 0x3ffb5fc8 A3 : 0x00060223 A4 : 0x00060220 A5 : 0x00000019
A6 : 0x00000000 A7 : 0x00000000 A8 : 0xb33f0001 A9 : 0xb33fffff
A10 : 0x00060223 A11 : 0x00000000 A12 : 0x3ffb4648 A13 : 0x00000019
A14 : 0x3ffb2330 A15 : 0x00000000 SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xffffffff

Backtrace:
0x400d1e60:0x3ffb9cc0 0x40082fd6:0x3ffb9ce0 0x4008433c:0x3ffb9d00 0x40084490:0x3ffb9d40
0x40081902:0x3ffb9d60 0x400819be:0x3ffb9d90 0x400d9cb5:0x3ffb9db0 0x400dc3e4:0x3ffba0c0
0x400db9bb:0x3ffba110

Rebooting...
ets Jun 8 2016 00:22:57


Test 4:
without nvs_flash_init
with printf after nvs_flash_init ( before xTaskCreate )
runs..

Code: Select all

void app_main()
{
// nvs_flash_init();
printf("printf in app_main [before taskCreate]\n");
xTaskCreatePinnedToCore(&hello_task_core_1, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
xTaskCreatePinnedToCore(&hello_task_core_0, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
// printf("in app_main [after taskCreate]\n");
}

I (44) boot: ESP-IDF v2.0-rc1-73-g61c7bd3 2nd stage bootloader
I (45) boot: compile time 02:23:17
I (45) boot: Enabling RNG early entropy source...
I (65) boot: SPI Speed : 40MHz
I (77) boot: SPI Mode : DIO
I (90) boot: SPI Flash Size : 4MB
I (102) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (136) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (159) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (183) boot: 2 factory factory app 00 00 00010000 00100000
I (206) boot: End of partition table
I (219) boot: Disabling RNG early entropy source...
I (236) boot: Loading app partition at offset 00010000
I (510) boot: segment 0: paddr=0x00010018 vaddr=0x00000000 size=0x0ffe8 ( 65512)
I (510) boot: segment 1: paddr=0x00020008 vaddr=0x3f400010 size=0x025f4 ( 9716) map
I (526) boot: segment 2: paddr=0x00022604 vaddr=0x3ffb0000 size=0x01aec ( 6892) load
I (556) boot: segment 3: paddr=0x000240f8 vaddr=0x40080000 size=0x00400 ( 1024) load
I (580) boot: segment 4: paddr=0x00024500 vaddr=0x40080400 size=0x08858 ( 34904) load
I (622) boot: segment 5: paddr=0x0002cd60 vaddr=0x400c0000 size=0x00000 ( 0) load
I (631) boot: segment 6: paddr=0x0002cd68 vaddr=0x00000000 size=0x032a0 ( 12960)
I (656) boot: segment 7: paddr=0x00030010 vaddr=0x400d0018 size=0x0c90c ( 51468) map
I (683) heap_alloc_caps: Initializing. RAM available for dynamic allocation:
I (706) heap_alloc_caps: At 3FFB2280 len 0002DD80 (183 KiB): DRAM
I (727) heap_alloc_caps: At 3FFE8000 len 00018000 (96 KiB): D/IRAM
I (748) heap_alloc_caps: At 40088C58 len 000173A8 (92 KiB): IRAM
I (768) cpu_start: Pro cpu up.
I (780) cpu_start: Starting app cpu, entry point is 0x40080a5c
I (0) cpu_start: App cpu up.
I (811) cpu_start: Pro cpu start user code
I (872) cpu_start: Starting scheduler on PRO CPU.
printf in app_main [before taskCreate]
Hello world from core:0!
I (81) cpu_start: Starting scheduler on APP CPU.
Hello world from core:1!
Hello world from core:1!
Hello world from core:0!
Hello world from core:1!
..


Test 5:
without nvs_flash_init
with printf after xTaksCreates
runs..

Code: Select all

void app_main()
{
// nvs_flash_init();
// printf("printf in app_main [before taskCreate]\n");
xTaskCreatePinnedToCore(&hello_task_core_1, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
xTaskCreatePinnedToCore(&hello_task_core_0, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
printf("in app_main [after taskCreate]\n");
}
I (44) boot: ESP-IDF v2.0-rc1-73-g61c7bd3 2nd stage bootloader
I (44) boot: compile time 02:32:56
I (45) boot: Enabling RNG early entropy source...
I (65) boot: SPI Speed : 40MHz
I (77) boot: SPI Mode : DIO
I (90) boot: SPI Flash Size : 4MB
I (102) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (136) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (159) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (183) boot: 2 factory factory app 00 00 00010000 00100000
I (206) boot: End of partition table
I (219) boot: Disabling RNG early entropy source...
I (236) boot: Loading app partition at offset 00010000
I (510) boot: segment 0: paddr=0x00010018 vaddr=0x00000000 size=0x0ffe8 ( 65512)
I (511) boot: segment 1: paddr=0x00020008 vaddr=0x3f400010 size=0x025ec ( 9708) map
I (527) boot: segment 2: paddr=0x000225fc vaddr=0x3ffb0000 size=0x01aec ( 6892) load
I (556) boot: segment 3: paddr=0x000240f0 vaddr=0x40080000 size=0x00400 ( 1024) load
I (580) boot: segment 4: paddr=0x000244f8 vaddr=0x40080400 size=0x08858 ( 34904) load
I (622) boot: segment 5: paddr=0x0002cd58 vaddr=0x400c0000 size=0x00000 ( 0) load
I (632) boot: segment 6: paddr=0x0002cd60 vaddr=0x00000000 size=0x032a8 ( 12968)
I (656) boot: segment 7: paddr=0x00030010 vaddr=0x400d0018 size=0x0c90c ( 51468) map
I (683) heap_alloc_caps: Initializing. RAM available for dynamic allocation:
I (706) heap_alloc_caps: At 3FFB2280 len 0002DD80 (183 KiB): DRAM
I (727) heap_alloc_caps: At 3FFE8000 len 00018000 (96 KiB): D/IRAM
I (748) heap_alloc_caps: At 40088C58 len 000173A8 (92 KiB): IRAM
I (768) cpu_start: Pro cpu up.
I (780) cpu_start: Starting app cpu, entry point is 0x40080a5c
I (0) cpu_start: App cpu up.
I (811) cpu_start: Pro cpu start user code
I (872) cpu_start: Starting scheduler on PRO CPU.
Hello world from core:0!
in app_main [after taskCreate]
I (81) cpu_start: Starting scheduler on APP CPU.
Hello world from core:1!
Hello world from core:1!
Hello world from core:0!
Hello world from core:1!
Hello world from core:1!
Hello world from core:0!
..


best wishes
rudi ;-)

Re: nvs_flash_init() let hang up the boot (pinnedToCore) process

Posted: Thu Feb 23, 2017 2:19 am
by ESP_igrr
Hi rudi, thanks for sharing.
we have a fix for this, which should make it into master today.

Re: nvs_flash_init() let hang up the boot (pinnedToCore) process

Posted: Thu Feb 23, 2017 2:22 am
by rudi ;-)
Hi Ivan

thank you!
if you have small time, please, can you short tell, what happend / what was done?
can it bee that have to do with the dual core mode?
thank you!

best wishes
rudi ;-)

Re: nvs_flash_init() let hang up the boot (pinnedToCore) process

Posted: Thu Feb 23, 2017 2:25 am
by ESP_igrr
ESP_Sprite has found a couple of bugs in FreeRTOS scheduler which happen to cause this. I'm not sure why this issue didn't happen before, probably because nvs_flash_init (and the first flash operation) used to be called as part of esp_phy_init before freertos scheduler was started. Now nvs_flash_init happens after the scheduler has started, which is what possibly triggers the bug.
This does indeed only happen in dual core mode.

Re: nvs_flash_init() let hang up the boot (pinnedToCore) process

Posted: Thu Feb 23, 2017 2:31 am
by rudi ;-)
thank you Ivan, this sounds plausible.
have wounder me for next logical step to search in freertos scheduler too.
thank you jeroen for figure it out!
will change status to solved.

best wishes
rudi ;-)

Re: [in work to solve/pull] nvs_flash_init() let hang up the boot (pinnedToCore) process

Posted: Thu Feb 23, 2017 2:43 am
by rudi ;-)
hi ivan

please, if you get small time on it, can you reply on this? ( no hurry )

runs!

Code: Select all

	nvs_flash_init();
	printf("printf in app_main [before taskCreate]\n");
	xTaskCreatePinnedToCore(&hello_task_core_0, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
	xTaskCreatePinnedToCore(&hello_task_core_1, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
rebooting

Code: Select all

	nvs_flash_init();
	printf("printf in app_main [before taskCreate]\n");
	xTaskCreatePinnedToCore(&hello_task_core_1, "core1_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_1);
	xTaskCreatePinnedToCore(&hello_task_core_0, "core0_task", 1024*8, NULL, configMAX_PRIORITIES - 1, NULL, core_0);
it is important how we create the pinned to core task in enumeration
if we create core 1 at first, it hangs
if we create core 0 at first, it runs
I (44) boot: ESP-IDF v2.0-rc1-73-g61c7bd3 2nd stage bootloader
I (44) boot: compile time 03:37:31
I (45) boot: Enabling RNG early entropy source...
I (65) boot: SPI Speed : 40MHz
I (77) boot: SPI Mode : DIO
I (90) boot: SPI Flash Size : 4MB
I (102) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (136) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (159) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (183) boot: 2 factory factory app 00 00 00010000 00100000
I (206) boot: End of partition table
I (219) boot: Disabling RNG early entropy source...
I (236) boot: Loading app partition at offset 00010000
I (518) boot: segment 0: paddr=0x00010018 vaddr=0x00000000 size=0x0ffe8 ( 65512)
I (519) boot: segment 1: paddr=0x00020008 vaddr=0x3f400010 size=0x02edc ( 11996) map
I (535) boot: segment 2: paddr=0x00022eec vaddr=0x3ffb0000 size=0x01af0 ( 6896) load
I (564) boot: segment 3: paddr=0x000249e4 vaddr=0x40080000 size=0x00400 ( 1024) load
I (588) boot: segment 4: paddr=0x00024dec vaddr=0x40080400 size=0x08858 ( 34904) load
I (630) boot: segment 5: paddr=0x0002d64c vaddr=0x400c0000 size=0x00000 ( 0) load
I (640) boot: segment 6: paddr=0x0002d654 vaddr=0x00000000 size=0x029b4 ( 10676)
I (665) boot: segment 7: paddr=0x00030010 vaddr=0x400d0018 size=0x0e0c0 ( 57536) map
I (692) heap_alloc_caps: Initializing. RAM available for dynamic allocation:
I (714) heap_alloc_caps: At 3FFB22F8 len 0002DD08 (183 KiB): DRAM
I (735) heap_alloc_caps: At 3FFE8000 len 00018000 (96 KiB): D/IRAM
I (756) heap_alloc_caps: At 40088C58 len 000173A8 (92 KiB): IRAM
I (777) cpu_start: Pro cpu up.
I (788) cpu_start: Starting app cpu, entry point is 0x40080a5c
I (0) cpu_start: App cpu up.
I (819) cpu_start: Pro cpu start user code
I (880) cpu_start: Starting scheduler on PRO CPU.
I (81) cpu_start: Starting scheduler on APP CPU.
printf in app_main [before taskCreate]
Hello world from core:0!
Hello world from core:1!
Hello world from core:0!
Hello world from core:1!
Hello world from core:0!
Hello world from core:0!
Hello world from core:1!
best wishes
rudi ;-)