ESP32 Forum

Posted: **Fri Jan 11, 2019 10:59 am**

Hi,

In my sdkconfig file I have the following settings for LOG management

CONFIG_LOG_BOOTLOADER_LEVEL_NONE=y
CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y

Bootloader LOG is disabled and LOG level for application is set to DEBUG.

The very first operation I do on my "app_main" is

Code: Select all

esp_log_level_set("*", ESP_LOG_NONE);

in order to disable all the log (I could enable later via a command on uart if needed for debugging on field). However at start-up

Code: Select all

ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x1b (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:0x3fff0018,len:4
load:0x3fff001c,len:824
load:0x40078000,len:8304
ho 0 tail 12 room 4
load:0x40080000,len:5188
entry 0x40080270
I (448) cpu_start: Pro cpu up.
I (448) cpu_start: Starting app cpu, entry point is 0x4008129c
I (433) cpu_start: App cpu up.
I (449) heap_init: Initializing. RAM available for dynamic allocation:
D (454) heap_init: New heap initialised at 0x3ffaff10
I (459) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
D (465) heap_init: New heap initialised at 0x3ffcd9c0
I (469) heap_init: At 3FFCD9C0 len 00012640 (73 KiB): DRAM
I (474) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (480) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (486) heap_init: New heap initialised at 0x4009802c
I (490) heap_init: At 4009802C len 00007FD4 (31 KiB): IRAM
I (495) cpu_start: Pro cpu start user code
D (506) clk: RTC_SLOW_CLK calibration value: 3372518
D (68) intr_alloc: Connected src 46 to int 2 (cpu 0)
D (69) intr_alloc: Connected src 57 to int 3 (cpu 0)
D (69) intr_alloc: Connected src 24 to int 9 (cpu 0)
I (73) esp_core_dump: Init core dump to UART
I (77) cpu_start: Starting scheduler on PRO CPU.
D (0) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (4) cpu_start: Starting scheduler on APP CPU.
D (98) heap_init: New heap initialised at 0x3ffe0440
D (103) heap_init: New heap initialised at 0x3ffe4350
D (107) intr_alloc: Connected src 16 to int 12 (cpu 0)
D (207) intr_alloc: Connected src 34 to int 13 (cpu 0)
D (209) intr_alloc: Connected src 37 to int 17 (cpu 0)

The very first part is from ROM code and I know it is managed by strapping fine..The second part from "cpu_start: Pro cpu up" is generated by ESP_EARLY_LOGx instruction which seems to assume CONFIG_LOG_DEFAULT_LEVEL_DEBUG level and not CONFIG_LOG_BOOTLOADER_LEVEL_NONE configuration.

I'm using ESP-IDF v3.1.2 ed13041.

How can I avoid this initial logs (obviously mantaining CONFIG_LOG_DEFAULT_LEVEL_DEBUG =y)?

Thanks

Posted: **Tue Jan 29, 2019 6:39 am**

Its totally correct that ESP_EARLY_LOGx uses CONFIG_LOG_DEFAULT_LEVEL_DEBUG and not CONFIG_LOG_BOOTLOADER_LEVEL_NONE in that case, because "cpu_start" is handled after 2nd stage bootloader.

Compare with the docs:
https://docs.espressif.com/projects/esp ... notes.html

First-stage bootloader in ROM loads second-stage bootloader image to RAM (IRAM & DRAM) from flash offset 0x1000.

Second-stage bootloader loads partition table and main app image from flash. Main app incorporates both RAM segments and read-only segments mapped via flash cache.

Main app image executes. At this point the second CPU and RTOS scheduler can be started.

ESP-IDF application entry point is call_start_cpu0 function found in components/esp32/cpu_start.c.

So you can try the "Arduino-Style" for custom logging setting log-level (very) low and using log_printf from lib_printf.c (compare: https://github.com/espressif/arduino-es ... -hal-log.h)

-- edit

Another approach I'm currently trying is swapping UART0 with UART2 via sdkconfig and bringing application-logs back in app_main by something like:

Code: Select all

stdin = fopen("/dev/uart/0", "r");
stdout = fopen("/dev/uart/0", "w");
stderr = fopen("/dev/uart/0", "w");

but unfortunately it's not very successful until now ...

Posted: **Tue Jan 29, 2019 9:34 pm**

I'm happy to let you know I came up with a solution for our issue

To avoid early logging and redirect it to UART1 (to some debug-uart pins) but also having the ability to printf to UART0 I did the following:

In sdkconfig, I defined:

Code: Select all

CONFIG_CONSOLE_UART_CUSTOM=y
CONFIG_CONSOLE_UART_NUM=1
CONFIG_CONSOLE_UART_TX_GPIO=17
CONFIG_CONSOLE_UART_RX_GPIO=16

(routing "all output" to GPIO_16 / GPIO_17)

while keeping Log-Level "Info" with:

Code: Select all

CONFIG_LOG_DEFAULT_LEVEL_INFO=y
CONFIG_LOG_DEFAULT_LEVEL=3

Now everything get's printed on defined UART - but thats not what I wanted.

I wanted a dedicated debug-uart for LOG-Messages and Primary-UART (USB for my DevBoard) for application messages.

But redirecting std-streams also redirected LOG-Messages back to UART0.

So here is my code-snippet for separated application logging via std-streams and debug logging via ESP_LOGx on separate UARTs (mention the sdkconfig!):

Code: Select all

#include <stdio.h>
#include <freertos/FreeRTOS.h>
#include <freertos/task.h>
#include <esp_log.h>
#include <driver/uart.h>

#define APP_LOG_BUF_SIZE	(1024)
#define APP_LOG_UART		(UART_NUM_0)
#define APP_LOG_UART_TXD	(GPIO_NUM_1)
#define APP_LOG_UART_RXD	(GPIO_NUM_3)
#define APP_LOG_UART_RTS	(UART_PIN_NO_CHANGE)
#define APP_LOG_UART_CTS	(UART_PIN_NO_CHANGE)

static const char* LOG_TAG = "SEPLOG";

FILE* log_out;

int logging_vprintf(const char *format, va_list arg) {
	return vfprintf(log_out, format, arg);
}

static void setupIOStreams() {
	ESP_LOGI(LOG_TAG, "Redirecting log-streams to UART1");
	
	// no need to open serial port here because already opened by startup, because UART1 is std. console out
	log_out = fopen("/dev/uart/1", "w");
	esp_log_set_vprintf(logging_vprintf);

	ESP_LOGI(LOG_TAG, "Redirecting std-streams to UART0");
	
	uart_config_t uart_config = {
		.baud_rate = 115200,
		.data_bits = UART_DATA_8_BITS,
		.parity    = UART_PARITY_DISABLE,
		.stop_bits = UART_STOP_BITS_1,
		.flow_ctrl = UART_HW_FLOWCTRL_DISABLE,
		.rx_flow_ctrl_thresh = 122,
		.use_ref_tick = true
	};

	uart_param_config(APP_LOG_UART, &uart_config);
	uart_set_pin(APP_LOG_UART, APP_LOG_UART_TXD, APP_LOG_UART_RXD, APP_LOG_UART_RTS, APP_LOG_UART_CTS);
	uart_driver_install(APP_LOG_UART, APP_LOG_BUF_SIZE * 2, 0, 0, NULL, 0);

	_GLOBAL_REENT->_stderr = stderr = fopen("/dev/uart/0", "w");
	_GLOBAL_REENT->_stdout = stdout = fopen("/dev/uart/0", "w");
	_GLOBAL_REENT->_stdin = stdin = fopen("/dev/uart/0", "r");
}

static void task(void *pvParameters) {
	printf("new task printf\n");
	ESP_LOGW(LOG_TAG, "new task warn log");

	for(;;) {
		vTaskDelay(5000 / portTICK_PERIOD_MS);
	}

	vTaskDelete(NULL);
}

void app_main(void) {
	setupIOStreams();

	printf("printf!\n");
	ESP_LOGI(LOG_TAG, "ESP_LOGI!");

	xTaskCreate(task, "task", 1024, NULL, 10, NULL);
}

I'm sure you are able to modify my implementation to fit your needs

And I'm always interested in fixes for my code - if you spot any bug (not sure about "perfect" logging_vprintf for example ... maybe there is a more efficient solution?)

ESP32 Forum

Avoiding ESP_EARLY_LOG after code startup

Avoiding ESP_EARLY_LOG after code startup

Re: Avoiding ESP_EARLY_LOG after code startup

Re: Avoiding ESP_EARLY_LOG after code startup