Crash_Override/OVMS3-idf
1
0
Fork 0
Code Issues Pull requests Projects Releases Wiki Activity

Merge branch 'feature/logging' into 'master'

Browse source 
Add logging library

Logging library, intended to be used across other components.
Uses design similar to Android NDK logging APIs and allows for both compile time and run time filters, similar to logcat.

Also includes cleanup of cpu_startup.c — i was changing some logging output in this file so decided to re-format it and reduce code duplication.

Ref TW6703

See merge request !68
This commit is contained in:
Ivan Grokhotkov 2016-09-20 17:16:41 +08:00
commit 6e35c0a91a
15 changed files with 829 additions and 422 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

38
components/bootloader/Kconfig.projbuild
View file

@ -1,33 +1,31 @@
menu "Bootloader config" menu "Bootloader config"
choice LOG_BOOTLOADER_LEVEL
choice BOOTLOADER_LOG_LEVEL
bool "Bootloader log verbosity" bool "Bootloader log verbosity"
default BOOTLOADER_LOG_LEVEL_NOTICE default LOG_BOOTLOADER_LEVEL_WARN
help help
Specify how much output to see in the bootloader logs. Specify how much output to see in bootloader logs.
Note that if MTDO is HIGH on reset, all early boot output config LOG_BOOTLOADER_LEVEL_NONE
(including bootloader logs) are suppressed.
config BOOTLOADER_LOG_LEVEL_NONE
bool "No output" bool "No output"
config BOOTLOADER_LOG_LEVEL_ERROR config LOG_BOOTLOADER_LEVEL_ERROR
bool "Error" bool "Error"
config BOOTLOADER_LOG_LEVEL_WARN config LOG_BOOTLOADER_LEVEL_WARN
bool "Warning" bool "Warning"
config BOOTLOADER_LOG_LEVEL_INFO config LOG_BOOTLOADER_LEVEL_INFO
bool "Info" bool "Info"
config BOOTLOADER_LOG_LEVEL_NOTICE config LOG_BOOTLOADER_LEVEL_DEBUG
bool "Notice"
config BOOTLOADER_LOG_LEVEL_DEBUG
bool "Debug" bool "Debug"
config LOG_BOOTLOADER_LEVEL_VERBOSE
bool "Verbose"
endchoice endchoice
config BOOTLOADER_LOG_COLORS config LOG_BOOTLOADER_LEVEL
bool "Use ANSI terminal colors in bootloader log output" int
default "y" default 0 if LOG_BOOTLOADER_LEVEL_NONE
help default 1 if LOG_BOOTLOADER_LEVEL_ERROR
Enable ANSI terminal color codes in bootloader output. default 2 if LOG_BOOTLOADER_LEVEL_WARN
default 3 if LOG_BOOTLOADER_LEVEL_INFO
In order to view these, your terminal program must support ANSI color codes. default 4 if LOG_BOOTLOADER_LEVEL_DEBUG
default 5 if LOG_BOOTLOADER_LEVEL_VERBOSE
endmenu endmenu

3
components/bootloader/Makefile.projbuild
View file

@ -45,4 +45,7 @@ $(COMPONENT_PATH)/src/sdkconfig: $(PROJECT_PATH)/sdkconfig
bootloader-flash: $(BOOTLOADER_BIN) bootloader-flash: $(BOOTLOADER_BIN)
$(MAKE) -C $(BOOTLOADER_COMPONENT_PATH)/src flash MAKEFLAGS= V=$(V) $(MAKE) -C $(BOOTLOADER_COMPONENT_PATH)/src flash MAKEFLAGS= V=$(V)
else
CFLAGS += -D BOOTLOADER_BUILD=1 -I $(IDF_PATH)/components/esp32/include
endif endif

6
components/bootloader/src/Makefile
View file

@ -4,14 +4,14 @@
# #
PROJECT_NAME := bootloader PROJECT_NAME := bootloader
COMPONENTS := esptool_py bootloader COMPONENTS := esptool_py bootloader log
# The bootloader pseudo-component is also included in this build, for its Kconfig.projbuild to be included. # The bootloader pseudo-component is also included in this build, for its Kconfig.projbuild to be included.
# #
# IS_BOOTLOADER_BUILD tells the component Makefile.projbuild to be a no-op # IS_BOOTLOADER_BUILD tells the component Makefile.projbuild to be a no-op
IS_BOOTLOADER_BUILD := 1 IS_BOOTLOADER_BUILD := 1
#We cannot include the esp32 component directly but we need its includes. This is fixed by #We cannot include the esp32 component directly but we need its includes.
#adding it in the main/Makefile directory. #This is fixed by adding CFLAGS from Makefile.projbuild
include $(IDF_PATH)/make/project.mk include $(IDF_PATH)/make/project.mk

114
components/bootloader/src/main/bootloader_log.h
View file

@ -1,114 +0,0 @@
// Copyright 2015-2016 Espressif Systems (Shanghai) PTE LTD
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
#ifndef __BOOT_LOG_H__
#define __BOOT_LOG_H__
#ifdef __cplusplus
extern "C"
{
#endif
#include "sdkconfig.h"
#define BOOT_LOG_LEVEL_NONE (0)
#define BOOT_LOG_LEVEL_ERROR (1)
#define BOOT_LOG_LEVEL_WARN (2)
#define BOOT_LOG_LEVEL_INFO (3)
#define BOOT_LOG_LEVEL_NOTICE (4)
#define BOOT_LOG_LEVEL_DEBUG (5)
#define Black "30"
#define Red "31"
#define Green "32"
#define Brown "33"
#define Blue "34"
#define Purple "35"
#define Cyan "36"
#if CONFIG_BOOTLOADER_LOG_COLORS
#define LOG_COLOR(COLOR) "\033[0;"COLOR"m"
#define LOG_BOLD(COLOR) "\033[1;"COLOR"m"
#define LOG_RESET_COLOR "\033[0m"
#else
#define LOG_COLOR(...)
#define LOG_BOLD(...)
#define LOG_RESET_COLOR ""
#endif
// BOOT_LOG_LEVEL defined by make menuconfig
#if CONFIG_BOOTLOADER_LOG_LEVEL_NONE
#define BOOT_LOG_LEVEL BOOT_LOG_LEVEL_NONE
#elif CONFIG_BOOTLOADER_LOG_LEVEL_ERROR
#define BOOT_LOG_LEVEL BOOT_LOG_LEVEL_ERROR
#elif CONFIG_BOOTLOADER_LOG_LEVEL_WARN
#define BOOT_LOG_LEVEL BOOT_LOG_LEVEL_WARN
#elif CONFIG_BOOTLOADER_LOG_LEVEL_INFO
#define BOOT_LOG_LEVEL BOOT_LOG_LEVEL_INFO
#elif CONFIG_BOOTLOADER_LOG_LEVEL_NOTICE
#define BOOT_LOG_LEVEL BOOT_LOG_LEVEL_NOTICE
#elif CONFIG_BOOTLOADER_LOG_LEVEL_DEBUG
#define BOOT_LOG_LEVEL BOOT_LOG_LEVEL_DEBUG
#else
#error "No bootloader log level set in menuconfig!"
#endif
//printf("\033[0;36m[NOTICE][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__);
#define log_notice(format, ...) \
do{\
if(BOOT_LOG_LEVEL >= BOOT_LOG_LEVEL_NOTICE){\
ets_printf(LOG_COLOR(Cyan) format "\r\n", ##__VA_ARGS__); \
ets_printf(LOG_RESET_COLOR); \
}\
}while(0)
#define log_info(format, ...) \
do{\
if(BOOT_LOG_LEVEL >= BOOT_LOG_LEVEL_INFO){\
ets_printf(LOG_BOLD(Cyan) format "\r\n", ##__VA_ARGS__); \
ets_printf(LOG_RESET_COLOR); \
}\
}while(0)
//printf("\033[0;31m[ERROR][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__);
#define log_error(format, ...) \
do{\
if(BOOT_LOG_LEVEL >= BOOT_LOG_LEVEL_ERROR){\
ets_printf(LOG_COLOR(Red) "[ERROR][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__); \
ets_printf(LOG_RESET_COLOR); \
}\
}while(0)
//printf("\033[1;33m[WARN][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__);
#define log_warn(format, ...) \
do{\
if(BOOT_LOG_LEVEL >= BOOT_LOG_LEVEL_WARN){\
ets_printf(LOG_BOLD(Brown) "[WARN][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__); \
ets_printf(LOG_RESET_COLOR); \
}\
}while(0)
//printf("\033[1;32m[DEBUG][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__);
#define log_debug(format, ...) \
do{\
if(BOOT_LOG_LEVEL >= BOOT_LOG_LEVEL_DEBUG){\
ets_printf(LOG_BOLD(Green) "[DEBUG][%s][%s][%d]\n" format "\r\n", __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__); \
ets_printf(LOG_RESET_COLOR); \
}\
}while(0)
#ifdef __cplusplus
}
#endif
#endif /* __BOOT_LOGGING_H__ */

123
components/bootloader/src/main/bootloader_start.c
View file

@ -16,6 +16,7 @@
#include <limits.h> #include <limits.h>
#include "esp_attr.h" #include "esp_attr.h"
#include "esp_log.h"
#include "rom/cache.h" #include "rom/cache.h"
#include "rom/ets_sys.h" #include "rom/ets_sys.h"
@ -23,6 +24,7 @@
#include "rom/crc.h" #include "rom/crc.h"
#include "soc/soc.h" #include "soc/soc.h"
#include "soc/cpu.h"
#include "soc/dport_reg.h" #include "soc/dport_reg.h"
#include "soc/io_mux_reg.h" #include "soc/io_mux_reg.h"
#include "soc/efuse_reg.h" #include "soc/efuse_reg.h"
@ -31,11 +33,12 @@
#include "sdkconfig.h" #include "sdkconfig.h"
#include "bootloader_log.h"
#include "bootloader_config.h" #include "bootloader_config.h"
extern int _bss_start; extern int _bss_start;
extern int _bss_end; extern int _bss_end;
static const char* TAG = "boot";
/* /*
We arrive here after the bootloader finished loading the program from flash. The hardware is mostly uninitialized, We arrive here after the bootloader finished loading the program from flash. The hardware is mostly uninitialized,
flash cache is down and the app CPU is in reset. We do have a stack, so we can do the initialization in C. flash cache is down and the app CPU is in reset. We do have a stack, so we can do the initialization in C.
@ -58,36 +61,7 @@ void IRAM_ATTR set_cache_and_start_app(uint32_t drom_addr,
void IRAM_ATTR call_start_cpu0() void IRAM_ATTR call_start_cpu0()
{ {
//Make page 0 access raise an exception cpu_configure_region_protection();
//Also some other unused pages so we can catch weirdness
//ToDo: this but nicer.
asm volatile (\
"movi a4,0x00000000\n" \
"movi a5,0xf\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x80000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xa0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xc0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xe0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x20000000\n" \
"movi a5,0x0\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x40000000\n" \
"movi a5,0x2\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"isync\n" \
:::"a4","a5");
//Clear bss //Clear bss
memset(&_bss_start, 0, (&_bss_end - &_bss_start) * sizeof(_bss_start)); memset(&_bss_start, 0, (&_bss_end - &_bss_start) * sizeof(_bss_start));
@ -130,7 +104,7 @@ uint32_t get_bin_len(uint32_t pos)
{ {
uint32_t len = 8 + 16; uint32_t len = 8 + 16;
uint8_t i; uint8_t i;
log_debug("pos %d %x\n",pos,*(uint8_t *)pos); ESP_LOGD(TAG, "pos %d %x",pos,*(uint8_t *)pos);
if(0xE9 != *(uint8_t *)pos) { if(0xE9 != *(uint8_t *)pos) {
return 0; return 0;
} }
@ -142,7 +116,7 @@ uint32_t get_bin_len(uint32_t pos)
} else { } else {
len += 16; len += 16;
} }
log_debug("bin length = %d\n", len); ESP_LOGD(TAG, "bin length = %d", len);
return len; return len;
} }
@ -161,7 +135,7 @@ void boot_cache_redirect( uint32_t pos, size_t size )
uint32_t count = (size + 0xffff) / 0x10000; uint32_t count = (size + 0xffff) / 0x10000;
Cache_Read_Disable( 0 ); Cache_Read_Disable( 0 );
Cache_Flush( 0 ); Cache_Flush( 0 );
log_debug( "mmu set paddr=%08x count=%d", pos_aligned, count ); ESP_LOGD(TAG, "mmu set paddr=%08x count=%d", pos_aligned, count );
cache_flash_mmu_set( 0, 0, 0x3f400000, pos_aligned, 64, count ); cache_flash_mmu_set( 0, 0, 0x3f400000, pos_aligned, 64, count );
Cache_Read_Enable( 0 ); Cache_Read_Enable( 0 );
} }
@ -183,13 +157,13 @@ bool load_partition_table(bootloader_state_t* bs, uint32_t addr)
int index = 0; int index = 0;
char *partition_usage; char *partition_usage;
log_info("Partition Table:"); ESP_LOGI(TAG, "Partition Table:");
log_info("## Label Usage Type ST Offset Length"); ESP_LOGI(TAG, "## Label Usage Type ST Offset Length");
while (addr < end) { while (addr < end) {
log_debug("load partition table entry from %x(%08x)", addr, MEM_CACHE(addr)); ESP_LOGD(TAG, "load partition table entry from %x(%08x)", addr, MEM_CACHE(addr));
memcpy(&partition, MEM_CACHE(addr), sizeof(partition)); memcpy(&partition, MEM_CACHE(addr), sizeof(partition));
log_debug("type=%x subtype=%x", partition.type, partition.subtype); ESP_LOGD(TAG, "type=%x subtype=%x", partition.type, partition.subtype);
partition_usage = "unknown"; partition_usage = "unknown";
if (partition.magic == PARTITION_MAGIC) { /* valid partition definition */ if (partition.magic == PARTITION_MAGIC) { /* valid partition definition */
@ -244,14 +218,14 @@ bool load_partition_table(bootloader_state_t* bs, uint32_t addr)
} }
/* print partition type info */ /* print partition type info */
log_info("%2d %-16s %-16s %02x %02x %08x %08x", index, partition.label, partition_usage, ESP_LOGI(TAG, "%2d %-16s %-16s %02x %02x %08x %08x", index, partition.label, partition_usage,
partition.type, partition.subtype, partition.type, partition.subtype,
partition.pos.offset, partition.pos.size); partition.pos.offset, partition.pos.size);
index++; index++;
addr += sizeof(partition); addr += sizeof(partition);
} }
log_info("End of partition table"); ESP_LOGI(TAG,"End of partition table");
return true; return true;
} }
@ -274,14 +248,7 @@ static bool ota_select_valid(const ota_select *s)
void bootloader_main() void bootloader_main()
{ {
//Run start routine. ESP_LOGI(TAG, "Espressif ESP32 2nd stage bootloader v. %s", BOOT_VERSION);
/*ESP32 2ND bootload start here*/
log_info( "\n" );
log_info( "**************************************" );
log_info( "* hello espressif ESP32! *" );
log_info( "* 2nd boot is running! *" );
log_info( "* version (%s) *", BOOT_VERSION);
log_info( "**************************************");
struct flash_hdr fhdr; struct flash_hdr fhdr;
bootloader_state_t bs; bootloader_state_t bs;
@ -289,7 +256,7 @@ void bootloader_main()
ota_select sa,sb; ota_select sa,sb;
memset(&bs, 0, sizeof(bs)); memset(&bs, 0, sizeof(bs));
log_notice( "compile time %s\n", __TIME__ ); ESP_LOGI(TAG, "compile time " __TIME__ );
/* close watch dog here */ /* close watch dog here */
REG_CLR_BIT( RTC_CNTL_WDTCONFIG0_REG, RTC_CNTL_WDT_FLASHBOOT_MOD_EN ); REG_CLR_BIT( RTC_CNTL_WDTCONFIG0_REG, RTC_CNTL_WDT_FLASHBOOT_MOD_EN );
REG_CLR_BIT( TIMG_WDTCONFIG0_REG(0), TIMG_WDT_FLASHBOOT_MOD_EN ); REG_CLR_BIT( TIMG_WDTCONFIG0_REG(0), TIMG_WDT_FLASHBOOT_MOD_EN );
@ -302,14 +269,14 @@ void bootloader_main()
print_flash_info(&fhdr); print_flash_info(&fhdr);
if (!load_partition_table(&bs, PARTITION_ADD)) { if (!load_partition_table(&bs, PARTITION_ADD)) {
log_error("load partition table error!"); ESP_LOGE(TAG, "load partition table error!");
return; return;
} }
partition_pos_t load_part_pos; partition_pos_t load_part_pos;
if (bs.ota_info.offset != 0) { // check if partition table has OTA info partition if (bs.ota_info.offset != 0) { // check if partition table has OTA info partition
//log_error("OTA info sector handling is not implemented"); //ESP_LOGE("OTA info sector handling is not implemented");
boot_cache_redirect(bs.ota_info.offset, bs.ota_info.size ); boot_cache_redirect(bs.ota_info.offset, bs.ota_info.size );
memcpy(&sa,MEM_CACHE(bs.ota_info.offset & 0x0000ffff),sizeof(sa)); memcpy(&sa,MEM_CACHE(bs.ota_info.offset & 0x0000ffff),sizeof(sa));
memcpy(&sb,MEM_CACHE((bs.ota_info.offset + 0x1000)&0x0000ffff) ,sizeof(sb)); memcpy(&sb,MEM_CACHE((bs.ota_info.offset + 0x1000)&0x0000ffff) ,sizeof(sb));
@ -325,13 +292,13 @@ void bootloader_main()
spiRet1 = SPIEraseSector(bs.ota_info.offset/0x1000); spiRet1 = SPIEraseSector(bs.ota_info.offset/0x1000);
spiRet2 = SPIEraseSector(bs.ota_info.offset/0x1000+1); spiRet2 = SPIEraseSector(bs.ota_info.offset/0x1000+1);
if (spiRet1 != SPI_FLASH_RESULT_OK || spiRet2 != SPI_FLASH_RESULT_OK ) { if (spiRet1 != SPI_FLASH_RESULT_OK || spiRet2 != SPI_FLASH_RESULT_OK ) {
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return; return;
} }
spiRet1 = SPIWrite(bs.ota_info.offset,(uint32_t *)&sa,sizeof(ota_select)); spiRet1 = SPIWrite(bs.ota_info.offset,(uint32_t *)&sa,sizeof(ota_select));
spiRet2 = SPIWrite(bs.ota_info.offset + 0x1000,(uint32_t *)&sb,sizeof(ota_select)); spiRet2 = SPIWrite(bs.ota_info.offset + 0x1000,(uint32_t *)&sb,sizeof(ota_select));
if (spiRet1 != SPI_FLASH_RESULT_OK || spiRet2 != SPI_FLASH_RESULT_OK ) { if (spiRet1 != SPI_FLASH_RESULT_OK || spiRet2 != SPI_FLASH_RESULT_OK ) {
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return; return;
} }
Cache_Read_Enable(0); Cache_Read_Enable(0);
@ -344,7 +311,7 @@ void bootloader_main()
}else if(ota_select_valid(&sb)) { }else if(ota_select_valid(&sb)) {
load_part_pos = bs.ota[(sb.ota_seq - 1) % bs.app_count]; load_part_pos = bs.ota[(sb.ota_seq - 1) % bs.app_count];
}else { }else {
log_error("ota data partition info error"); ESP_LOGE(TAG, "ota data partition info error");
return; return;
} }
} }
@ -353,15 +320,15 @@ void bootloader_main()
} else if (bs.test.offset != 0) { // otherwise, look for test app parition } else if (bs.test.offset != 0) { // otherwise, look for test app parition
load_part_pos = bs.test; load_part_pos = bs.test;
} else { // nothing to load, bail out } else { // nothing to load, bail out
log_error("nothing to load"); ESP_LOGE(TAG, "nothing to load");
return; return;
} }
log_info("Loading app partition at offset %08x", load_part_pos); ESP_LOGI(TAG, "Loading app partition at offset %08x", load_part_pos);
if(fhdr.secury_boot_flag == 0x01) { if(fhdr.secury_boot_flag == 0x01) {
/* protect the 2nd_boot */ /* protect the 2nd_boot */
if(false == secure_boot()){ if(false == secure_boot()){
log_error("secure boot failed"); ESP_LOGE(TAG, "secure boot failed");
return; return;
} }
} }
@ -369,7 +336,7 @@ void bootloader_main()
if(fhdr.encrypt_flag == 0x01) { if(fhdr.encrypt_flag == 0x01) {
/* encrypt flash */ /* encrypt flash */
if (false == flash_encrypt(&bs)) { if (false == flash_encrypt(&bs)) {
log_error("flash encrypt failed"); ESP_LOGE(TAG, "flash encrypt failed");
return; return;
} }
} }
@ -395,7 +362,7 @@ void unpack_load_app(const partition_pos_t* partition)
uint32_t irom_load_addr = 0; uint32_t irom_load_addr = 0;
uint32_t irom_size = 0; uint32_t irom_size = 0;
log_debug("bin_header: %u %u %u %u %08x\n", image_header.magic, ESP_LOGD(TAG, "bin_header: %u %u %u %u %08x", image_header.magic,
image_header.blocks, image_header.blocks,
image_header.spi_mode, image_header.spi_mode,
image_header.spi_size, image_header.spi_size,
@ -420,7 +387,7 @@ void unpack_load_app(const partition_pos_t* partition)
} }
if (address >= DROM_LOW && address < DROM_HIGH) { if (address >= DROM_LOW && address < DROM_HIGH) {
log_debug("found drom section, map from %08x to %08x\n", pos, ESP_LOGD(TAG, "found drom section, map from %08x to %08x", pos,
section_header.load_addr); section_header.load_addr);
drom_addr = partition->offset + pos - sizeof(section_header); drom_addr = partition->offset + pos - sizeof(section_header);
drom_load_addr = section_header.load_addr; drom_load_addr = section_header.load_addr;
@ -430,7 +397,7 @@ void unpack_load_app(const partition_pos_t* partition)
} }
if (address >= IROM_LOW && address < IROM_HIGH) { if (address >= IROM_LOW && address < IROM_HIGH) {
log_debug("found irom section, map from %08x to %08x\n", pos, ESP_LOGD(TAG, "found irom section, map from %08x to %08x", pos,
section_header.load_addr); section_header.load_addr);
irom_addr = partition->offset + pos - sizeof(section_header); irom_addr = partition->offset + pos - sizeof(section_header);
irom_load_addr = section_header.load_addr; irom_load_addr = section_header.load_addr;
@ -439,7 +406,7 @@ void unpack_load_app(const partition_pos_t* partition)
map = true; map = true;
} }
log_notice("section %d: paddr=0x%08x vaddr=0x%08x size=0x%05x (%6d) %s", section_index, pos, section_header.load_addr, section_header.data_len, section_header.data_len, (load)?"load":(map)?"map":""); ESP_LOGI(TAG, "section %d: paddr=0x%08x vaddr=0x%08x size=0x%05x (%6d) %s", section_index, pos, section_header.load_addr, section_header.data_len, section_header.data_len, (load)?"load":(map)?"map":"");
if (!load) { if (!load) {
pos += section_header.data_len; pos += section_header.data_len;
@ -468,29 +435,29 @@ void IRAM_ATTR set_cache_and_start_app(
uint32_t irom_size, uint32_t irom_size,
uint32_t entry_addr) uint32_t entry_addr)
{ {
log_debug("configure drom and irom and start\n"); ESP_LOGD(TAG, "configure drom and irom and start");
Cache_Read_Disable( 0 ); Cache_Read_Disable( 0 );
Cache_Read_Disable( 1 ); Cache_Read_Disable( 1 );
Cache_Flush( 0 ); Cache_Flush( 0 );
Cache_Flush( 1 ); Cache_Flush( 1 );
uint32_t drom_page_count = (drom_size + 64*1024 - 1) / (64*1024); // round up to 64k uint32_t drom_page_count = (drom_size + 64*1024 - 1) / (64*1024); // round up to 64k
log_debug( "d mmu set paddr=%08x vaddr=%08x size=%d n=%d \n", drom_addr & 0xffff0000, drom_load_addr & 0xffff0000, drom_size, drom_page_count ); ESP_LOGV(TAG, "d mmu set paddr=%08x vaddr=%08x size=%d n=%d", drom_addr & 0xffff0000, drom_load_addr & 0xffff0000, drom_size, drom_page_count );
int rc = cache_flash_mmu_set( 0, 0, drom_load_addr & 0xffff0000, drom_addr & 0xffff0000, 64, drom_page_count ); int rc = cache_flash_mmu_set( 0, 0, drom_load_addr & 0xffff0000, drom_addr & 0xffff0000, 64, drom_page_count );
log_debug( "rc=%d", rc ); ESP_LOGV(TAG, "rc=%d", rc );
rc = cache_flash_mmu_set( 1, 0, drom_load_addr & 0xffff0000, drom_addr & 0xffff0000, 64, drom_page_count ); rc = cache_flash_mmu_set( 1, 0, drom_load_addr & 0xffff0000, drom_addr & 0xffff0000, 64, drom_page_count );
log_debug( "rc=%d", rc ); ESP_LOGV(TAG, "rc=%d", rc );
uint32_t irom_page_count = (irom_size + 64*1024 - 1) / (64*1024); // round up to 64k uint32_t irom_page_count = (irom_size + 64*1024 - 1) / (64*1024); // round up to 64k
log_debug( "i mmu set paddr=%08x vaddr=%08x size=%d n=%d\n", irom_addr & 0xffff0000, irom_load_addr & 0xffff0000, irom_size, irom_page_count ); ESP_LOGV(TAG, "i mmu set paddr=%08x vaddr=%08x size=%d n=%d", irom_addr & 0xffff0000, irom_load_addr & 0xffff0000, irom_size, irom_page_count );
rc = cache_flash_mmu_set( 0, 0, irom_load_addr & 0xffff0000, irom_addr & 0xffff0000, 64, irom_page_count ); rc = cache_flash_mmu_set( 0, 0, irom_load_addr & 0xffff0000, irom_addr & 0xffff0000, 64, irom_page_count );
log_debug( "rc=%d", rc ); ESP_LOGV(TAG, "rc=%d", rc );
rc = cache_flash_mmu_set( 1, 0, irom_load_addr & 0xffff0000, irom_addr & 0xffff0000, 64, irom_page_count ); rc = cache_flash_mmu_set( 1, 0, irom_load_addr & 0xffff0000, irom_addr & 0xffff0000, 64, irom_page_count );
log_debug( "rc=%d", rc ); ESP_LOGV(TAG, "rc=%d", rc );
REG_CLR_BIT( DPORT_PRO_CACHE_CTRL1_REG, (DPORT_PRO_CACHE_MASK_IRAM0) | (DPORT_PRO_CACHE_MASK_IRAM1 & 0) | (DPORT_PRO_CACHE_MASK_IROM0 & 0) | DPORT_PRO_CACHE_MASK_DROM0 | DPORT_PRO_CACHE_MASK_DRAM1 ); REG_CLR_BIT( DPORT_PRO_CACHE_CTRL1_REG, (DPORT_PRO_CACHE_MASK_IRAM0) | (DPORT_PRO_CACHE_MASK_IRAM1 & 0) | (DPORT_PRO_CACHE_MASK_IROM0 & 0) | DPORT_PRO_CACHE_MASK_DROM0 | DPORT_PRO_CACHE_MASK_DRAM1 );
REG_CLR_BIT( DPORT_APP_CACHE_CTRL1_REG, (DPORT_APP_CACHE_MASK_IRAM0) | (DPORT_APP_CACHE_MASK_IRAM1 & 0) | (DPORT_APP_CACHE_MASK_IROM0 & 0) | DPORT_APP_CACHE_MASK_DROM0 | DPORT_APP_CACHE_MASK_DRAM1 ); REG_CLR_BIT( DPORT_APP_CACHE_CTRL1_REG, (DPORT_APP_CACHE_MASK_IRAM0) | (DPORT_APP_CACHE_MASK_IRAM1 & 0) | (DPORT_APP_CACHE_MASK_IROM0 & 0) | DPORT_APP_CACHE_MASK_DROM0 | DPORT_APP_CACHE_MASK_DRAM1 );
Cache_Read_Enable( 0 ); Cache_Read_Enable( 0 );
Cache_Read_Enable( 1 ); Cache_Read_Enable( 1 );
log_notice("start: 0x%08x\n", entry_addr); ESP_LOGD(TAG, "start: 0x%08x", entry_addr);
typedef void (*entry_t)(void); typedef void (*entry_t)(void);
entry_t entry = ((entry_t) entry_addr); entry_t entry = ((entry_t) entry_addr);
@ -506,11 +473,11 @@ void print_flash_info(struct flash_hdr* pfhdr)
struct flash_hdr fhdr = *pfhdr; struct flash_hdr fhdr = *pfhdr;
log_debug( "[D]: magic %02x\n", fhdr.magic ); ESP_LOGD(TAG, "magic %02x", fhdr.magic );
log_debug( "[D]: blocks %02x\n", fhdr.blocks ); ESP_LOGD(TAG, "blocks %02x", fhdr.blocks );
log_debug( "[D]: spi_mode %02x\n", fhdr.spi_mode ); ESP_LOGD(TAG, "spi_mode %02x", fhdr.spi_mode );
log_debug( "[D]: spi_speed %02x\n", fhdr.spi_speed ); ESP_LOGD(TAG, "spi_speed %02x", fhdr.spi_speed );
log_debug( "[D]: spi_size %02x\n", fhdr.spi_size ); ESP_LOGD(TAG, "spi_size %02x", fhdr.spi_size );
const char* str; const char* str;
switch ( fhdr.spi_speed ) { switch ( fhdr.spi_speed ) {
@ -534,7 +501,7 @@ void print_flash_info(struct flash_hdr* pfhdr)
str = "20MHz"; str = "20MHz";
break; break;
} }
log_notice( " SPI Speed : %s", str ); ESP_LOGI(TAG, "SPI Speed : %s", str );
@ -566,7 +533,7 @@ void print_flash_info(struct flash_hdr* pfhdr)
str = "DIO"; str = "DIO";
break; break;
} }
log_notice( " SPI Mode : %s", str ); ESP_LOGI(TAG, "SPI Mode : %s", str );
@ -595,6 +562,6 @@ void print_flash_info(struct flash_hdr* pfhdr)
str = "1MB"; str = "1MB";
break; break;
} }
log_notice( " SPI Flash Size : %s", str ); ESP_LOGI(TAG, "SPI Flash Size : %s", str );
#endif #endif
} }

1
components/bootloader/src/main/component.mk
View file

@ -8,6 +8,5 @@
# #
COMPONENT_ADD_LDFLAGS := -L $(abspath .) -lmain -T esp32.bootloader.ld -T $(IDF_PATH)/components/esp32/ld/esp32.rom.ld COMPONENT_ADD_LDFLAGS := -L $(abspath .) -lmain -T esp32.bootloader.ld -T $(IDF_PATH)/components/esp32/ld/esp32.rom.ld
COMPONENT_EXTRA_INCLUDES := $(IDF_PATH)/components/esp32/include
include $(IDF_PATH)/make/component_common.mk include $(IDF_PATH)/make/component_common.mk

62
components/bootloader/src/main/flash_encrypt.c
View file

@ -16,6 +16,7 @@
#include "esp_types.h" #include "esp_types.h"
#include "esp_attr.h" #include "esp_attr.h"
#include "esp_log.h"
#include "rom/cache.h" #include "rom/cache.h"
#include "rom/ets_sys.h" #include "rom/ets_sys.h"
@ -28,13 +29,14 @@
#include "sdkconfig.h" #include "sdkconfig.h"
#include "bootloader_log.h"
#include "bootloader_config.h" #include "bootloader_config.h"
static const char* TAG = "flash_encrypt";
/** /**
* @function : bitcount * @function : bitcount
* @description: caculate bit 1 in flash_crypt_cnt * @description: calculate bit 1 in flash_crypt_cnt
* if it's even number ,need encrypt flash data,and burn efuse * if it's even number, need encrypt flash data, and burn efuse
* *
* @inputs: n flash_crypt_cnt * @inputs: n flash_crypt_cnt
* @return: number of 1 in flash_crypt_cnt * @return: number of 1 in flash_crypt_cnt
@ -68,19 +70,19 @@ bool flash_encrypt_write(uint32_t pos, uint32_t len)
spiRet = SPIRead(pos, buf, SPI_SEC_SIZE); spiRet = SPIRead(pos, buf, SPI_SEC_SIZE);
if (spiRet != SPI_FLASH_RESULT_OK) { if (spiRet != SPI_FLASH_RESULT_OK) {
Cache_Read_Enable(0); Cache_Read_Enable(0);
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return false; return false;
} }
spiRet = SPIEraseSector(pos/SPI_SEC_SIZE); spiRet = SPIEraseSector(pos/SPI_SEC_SIZE);
if (spiRet != SPI_FLASH_RESULT_OK) { if (spiRet != SPI_FLASH_RESULT_OK) {
Cache_Read_Enable(0); Cache_Read_Enable(0);
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return false; return false;
} }
spiRet = SPI_Encrypt_Write(pos, buf, SPI_SEC_SIZE); spiRet = SPI_Encrypt_Write(pos, buf, SPI_SEC_SIZE);
if (spiRet != SPI_FLASH_RESULT_OK) { if (spiRet != SPI_FLASH_RESULT_OK) {
Cache_Read_Enable(0); Cache_Read_Enable(0);
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return false; return false;
} }
pos += SPI_SEC_SIZE; pos += SPI_SEC_SIZE;
@ -104,53 +106,53 @@ bool flash_encrypt(bootloader_state_t *bs)
uint32_t flash_crypt_cnt = REG_GET_FIELD(EFUSE_BLK0_RDATA0_REG, EFUSE_FLASH_CRYPT_CNT); uint32_t flash_crypt_cnt = REG_GET_FIELD(EFUSE_BLK0_RDATA0_REG, EFUSE_FLASH_CRYPT_CNT);
uint8_t count = bitcount(flash_crypt_cnt); uint8_t count = bitcount(flash_crypt_cnt);
int i = 0; int i = 0;
log_debug("flash crypt cnt %x, count %d\n", flash_crypt_cnt, count); ESP_LOGD(TAG, "flash encrypt cnt %x, bitcount %d", flash_crypt_cnt, count);
if ((count % 2) == 0) { if ((count % 2) == 0) {
boot_cache_redirect( 0, 64*1024); boot_cache_redirect( 0, 64*1024);
/* encrypt iv and abstruct */ /* encrypt iv and abstruct */
if (false == flash_encrypt_write(0,SPI_SEC_SIZE)) { if (false == flash_encrypt_write(0, SPI_SEC_SIZE)) {
log_error("encrypt iv and abstruct error"); ESP_LOGE(TAG, "encrypt iv and abstract error");
return false; return false;
} }
/* encrypt write boot bin*/ /* encrypt write boot bin*/
bin_len = get_bin_len((uint32_t)MEM_CACHE(0x1000)); bin_len = get_bin_len((uint32_t)MEM_CACHE(0x1000));
if(bin_len != 0) { if(bin_len != 0) {
if (false == flash_encrypt_write(0x1000,bin_len)) { if (false == flash_encrypt_write(0x1000, bin_len)) {
log_error("encrypt 2nd boot error"); ESP_LOGE(TAG, "encrypt 2nd boot error");
return false; return false;
} }
} else { } else {
log_error("2nd boot len error"); ESP_LOGE(TAG, "2nd boot len error");
return false; return false;
} }
/* encrypt partition table */ /* encrypt partition table */
if (false == flash_encrypt_write(PARTITION_ADD,SPI_SEC_SIZE)) { if (false == flash_encrypt_write(PARTITION_ADD, SPI_SEC_SIZE)) {
log_error("encrypt partition table error"); ESP_LOGE(TAG, "encrypt partition table error");
return false; return false;
} }
/* encrypt write factory bin */ /* encrypt write factory bin */
if(bs->factory.offset != 0x00) { if(bs->factory.offset != 0x00) {
log_debug("have factory bin\n"); ESP_LOGD(TAG, "have factory bin");
boot_cache_redirect(bs->factory.offset,bs->factory.size); boot_cache_redirect(bs->factory.offset, bs->factory.size);
bin_len = get_bin_len((uint32_t)MEM_CACHE(bs->factory.offset&0xffff)); bin_len = get_bin_len((uint32_t)MEM_CACHE(bs->factory.offset&0xffff));
if(bin_len != 0) { if(bin_len != 0) {
if (false == flash_encrypt_write(bs->factory.offset,bin_len)) { if (false == flash_encrypt_write(bs->factory.offset, bin_len)) {
log_error("encrypt factory bin error"); ESP_LOGE(TAG, "encrypt factory bin error");
return false; return false;
} }
} }
} }
/* encrypt write test bin */ /* encrypt write test bin */
if(bs->test.offset != 0x00) { if(bs->test.offset != 0x00) {
ets_printf("have test bin\n"); ESP_LOGD(TAG, "have test bin");
boot_cache_redirect(bs->test.offset,bs->test.size); boot_cache_redirect(bs->test.offset, bs->test.size);
bin_len = get_bin_len((uint32_t)MEM_CACHE(bs->test.offset&0xffff)); bin_len = get_bin_len((uint32_t)MEM_CACHE(bs->test.offset&0xffff));
if(bin_len != 0) { if(bin_len != 0) {
if (false == flash_encrypt_write(bs->test.offset,bin_len)) { if (false == flash_encrypt_write(bs->test.offset, bin_len)) {
log_error("encrypt test bin error"); ESP_LOGE(TAG, "encrypt test bin error");
return false; return false;
} }
} }
@ -158,33 +160,33 @@ bool flash_encrypt(bootloader_state_t *bs)
/* encrypt write ota bin */ /* encrypt write ota bin */
for (i = 0;i<16;i++) { for (i = 0;i<16;i++) {
if(bs->ota[i].offset != 0x00) { if(bs->ota[i].offset != 0x00) {
log_debug("have ota[%d] bin\n",i); ESP_LOGD(TAG, "have ota[%d] bin",i);
boot_cache_redirect(bs->ota[i].offset,bs->ota[i].size); boot_cache_redirect(bs->ota[i].offset, bs->ota[i].size);
bin_len = get_bin_len((uint32_t)MEM_CACHE(bs->ota[i].offset&0xffff)); bin_len = get_bin_len((uint32_t)MEM_CACHE(bs->ota[i].offset&0xffff));
if(bin_len != 0) { if(bin_len != 0) {
if (false == flash_encrypt_write(bs->ota[i].offset,bin_len)) { if (false == flash_encrypt_write(bs->ota[i].offset, bin_len)) {
log_error("encrypt ota bin error"); ESP_LOGE(TAG, "encrypt ota bin error");
return false; return false;
} }
} }
} }
} }
/* encrypt write ota info bin */ /* encrypt write ota info bin */
if (false == flash_encrypt_write(bs->ota_info.offset,2*SPI_SEC_SIZE)) { if (false == flash_encrypt_write(bs->ota_info.offset, 2*SPI_SEC_SIZE)) {
log_error("encrypt ota binfo error"); ESP_LOGE(TAG, "encrypt ota info error");
return false; return false;
} }
REG_SET_FIELD(EFUSE_BLK0_WDATA0_REG, EFUSE_FLASH_CRYPT_CNT, 0x04); REG_SET_FIELD(EFUSE_BLK0_WDATA0_REG, EFUSE_FLASH_CRYPT_CNT, 0x04);
REG_WRITE(EFUSE_CONF_REG, 0x5A5A); /* efuse_pgm_op_ena, force no rd/wr disable */ REG_WRITE(EFUSE_CONF_REG, 0x5A5A); /* efuse_pgm_op_ena, force no rd/wr disable */
REG_WRITE(EFUSE_CMD_REG, 0x02); /* efuse_pgm_cmd */ REG_WRITE(EFUSE_CMD_REG, 0x02); /* efuse_pgm_cmd */
while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_pagm_cmd=0 */ while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_pagm_cmd=0 */
log_warn("burn flash_crypt_cnt\n"); ESP_LOGW(TAG, "burn flash_crypt_cnt");
REG_WRITE(EFUSE_CONF_REG, 0x5AA5); /* efuse_read_op_ena, release force */ REG_WRITE(EFUSE_CONF_REG, 0x5AA5); /* efuse_read_op_ena, release force */
REG_WRITE(EFUSE_CMD_REG, 0x01); /* efuse_read_cmd */ REG_WRITE(EFUSE_CMD_REG, 0x01); /* efuse_read_cmd */
while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_read_cmd=0 */ while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_read_cmd=0 */
return true; return true;
} else { } else {
log_info("flash already encrypted.\n"); ESP_LOGI(TAG, "flash already encrypted.");
return true; return true;
} }
} }

28
components/bootloader/src/main/secure_boot.c
View file

@ -16,6 +16,7 @@
#include "esp_attr.h" #include "esp_attr.h"
#include "esp_types.h" #include "esp_types.h"
#include "esp_log.h"
#include "rom/cache.h" #include "rom/cache.h"
#include "rom/ets_sys.h" #include "rom/ets_sys.h"
@ -29,12 +30,13 @@
#include "sdkconfig.h" #include "sdkconfig.h"
#include "bootloader_log.h"
#include "bootloader_config.h" #include "bootloader_config.h"
static const char* TAG = "secure_boot";
/** /**
* @function : secure_boot_generate * @function : secure_boot_generate
* @description: generate boot abstruct & iv * @description: generate boot abstract & iv
* *
* @inputs: bool * @inputs: bool
*/ */
@ -53,17 +55,17 @@ bool secure_boot_generate(uint32_t bin_len){
spiRet = SPIEraseSector(0); spiRet = SPIEraseSector(0);
if (spiRet != SPI_FLASH_RESULT_OK) if (spiRet != SPI_FLASH_RESULT_OK)
{ {
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return false; return false;
} }
/* write iv to flash, 0x0000, 128 bytes (1024 bits) */ /* write iv to flash, 0x0000, 128 bytes (1024 bits) */
spiRet = SPIWrite(0, buf, 128); spiRet = SPIWrite(0, buf, 128);
if (spiRet != SPI_FLASH_RESULT_OK) if (spiRet != SPI_FLASH_RESULT_OK)
{ {
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return false; return false;
} }
log_debug("write iv to flash.\n"); ESP_LOGD(TAG, "write iv to flash.");
Cache_Read_Enable(0); Cache_Read_Enable(0);
/* read 4K code image from flash, for test */ /* read 4K code image from flash, for test */
for (i = 0; i < bin_len; i+=128) { for (i = 0; i < bin_len; i+=128) {
@ -77,10 +79,10 @@ bool secure_boot_generate(uint32_t bin_len){
/* write abstract to flash, 0x0080, 64 bytes (512 bits) */ /* write abstract to flash, 0x0080, 64 bytes (512 bits) */
spiRet = SPIWrite(0x80, buf, 64); spiRet = SPIWrite(0x80, buf, 64);
if (spiRet != SPI_FLASH_RESULT_OK) { if (spiRet != SPI_FLASH_RESULT_OK) {
log_error(SPI_ERROR_LOG); ESP_LOGE(TAG, SPI_ERROR_LOG);
return false; return false;
} }
log_debug("write abstract to flash.\n"); ESP_LOGD(TAG, "write abstract to flash.");
Cache_Read_Enable(0); Cache_Read_Enable(0);
return true; return true;
} }
@ -88,7 +90,7 @@ bool secure_boot_generate(uint32_t bin_len){
/** /**
* @function : secure_boot * @function : secure_boot
* @description: protect boot code inflash * @description: protect boot code in flash
* *
* @inputs: bool * @inputs: bool
*/ */
@ -96,17 +98,17 @@ bool secure_boot(void){
uint32_t bin_len = 0; uint32_t bin_len = 0;
if (REG_READ(EFUSE_BLK0_RDATA6_REG) & EFUSE_RD_ABS_DONE_0) if (REG_READ(EFUSE_BLK0_RDATA6_REG) & EFUSE_RD_ABS_DONE_0)
{ {
log_info("already secure boot !\n"); ESP_LOGD(TAG, "already secure boot !");
return true; return true;
} else { } else {
boot_cache_redirect( 0, 64*1024); boot_cache_redirect( 0, 64*1024);
bin_len = get_bin_len((uint32_t)MEM_CACHE(0x1000)); bin_len = get_bin_len((uint32_t)MEM_CACHE(0x1000));
if (bin_len == 0) { if (bin_len == 0) {
log_error("boot len is error"); ESP_LOGE(TAG, "boot len is error");
return false; return false;
} }
if (false == secure_boot_generate(bin_len)){ if (false == secure_boot_generate(bin_len)){
log_error("secure boot generate failed"); ESP_LOGE(TAG, "secure boot generate failed");
return false; return false;
} }
} }
@ -115,11 +117,11 @@ bool secure_boot(void){
REG_WRITE(EFUSE_CONF_REG, 0x5A5A); /* efuse_pgm_op_ena, force no rd/wr disable */ REG_WRITE(EFUSE_CONF_REG, 0x5A5A); /* efuse_pgm_op_ena, force no rd/wr disable */
REG_WRITE(EFUSE_CMD_REG, 0x02); /* efuse_pgm_cmd */ REG_WRITE(EFUSE_CMD_REG, 0x02); /* efuse_pgm_cmd */
while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_pagm_cmd=0 */ while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_pagm_cmd=0 */
log_warn("burn abstract_done_0\n"); ESP_LOGW(TAG, "burn abstract_done_0");
REG_WRITE(EFUSE_CONF_REG, 0x5AA5); /* efuse_read_op_ena, release force */ REG_WRITE(EFUSE_CONF_REG, 0x5AA5); /* efuse_read_op_ena, release force */
REG_WRITE(EFUSE_CMD_REG, 0x01); /* efuse_read_cmd */ REG_WRITE(EFUSE_CMD_REG, 0x01); /* efuse_read_cmd */
while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_read_cmd=0 */ while (REG_READ(EFUSE_CMD_REG)); /* wait for efuse_read_cmd=0 */
log_debug("read EFUSE_BLK0_RDATA6 %x\n", REG_READ(EFUSE_BLK0_RDATA6_REG)); ESP_LOGI(TAG, "read EFUSE_BLK0_RDATA6 %x", REG_READ(EFUSE_BLK0_RDATA6_REG));
return true; return true;
} }

254
components/esp32/cpu_start.c
View file

@ -20,8 +20,10 @@
#include "rom/ets_sys.h" #include "rom/ets_sys.h"
#include "rom/uart.h" #include "rom/uart.h"
#include "soc/cpu.h"
#include "soc/dport_reg.h" #include "soc/dport_reg.h"
#include "soc/io_mux_reg.h" #include "soc/io_mux_reg.h"
#include "soc/rtc_cntl_reg.h"
#include "freertos/FreeRTOS.h" #include "freertos/FreeRTOS.h"
#include "freertos/task.h" #include "freertos/task.h"
@ -39,194 +41,130 @@
#include "esp_event.h" #include "esp_event.h"
#include "esp_spi_flash.h" #include "esp_spi_flash.h"
#include "esp_ipc.h" #include "esp_ipc.h"
#include "esp_log.h"
static void IRAM_ATTR user_start_cpu0(void); static void IRAM_ATTR user_start_cpu0(void);
static void IRAM_ATTR call_user_start_cpu1(); static void IRAM_ATTR call_user_start_cpu1();
static void IRAM_ATTR user_start_cpu1(void); static void IRAM_ATTR user_start_cpu1(void);
void Cache_Read_Enable();
extern void ets_setup_syscalls(void); extern void ets_setup_syscalls(void);
extern esp_err_t app_main(void *ctx);
extern int __cpu1_entry_point;
extern int _bss_start; extern int _bss_start;
extern int _bss_end; extern int _bss_end;
extern int _init_start; extern int _init_start;
extern int _init_end;
extern int _iram_romjumptable_start;
extern int _iram_romjumptable_end;
extern int _iram_text_start;
extern int _iram_text_end;
/*
We arrive here after the bootloader finished loading the program from flash. The hardware is mostly uninitialized,
flash cache is down and the app CPU is in reset. We do have a stack, so we can do the initialization in C.
*/
static bool app_cpu_started = false;
void IRAM_ATTR call_user_start_cpu0() {
//Kill wdt
REG_CLR_BIT(0x3ff4808c, BIT(10)); //RTCCNTL+8C RTC_WDTCONFIG0 RTC_
REG_CLR_BIT(0x6001f048, BIT(14)); //DR_REG_BB_BASE+48
//Move exception vectors to IRAM
asm volatile (\
"wsr %0, vecbase\n" \
::"r"(&_init_start));
uartAttach();
ets_install_uart_printf();
//Make page 0 access raise an exception
//Also some other unused pages so we can catch weirdness
//ToDo: this but nicer.
asm volatile (\
"movi a4,0x00000000\n" \
"movi a5,0xf\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x80000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xa0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xc0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xe0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x20000000\n" \
"movi a5,0x0\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x40000000\n" \
"movi a5,0x2\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"isync\n" \
:::"a4","a5");
memset(&_bss_start, 0, (&_bss_end - &_bss_start) * sizeof(_bss_start));
//Initialize heap allocator
heap_alloc_caps_init();
ets_printf("Pro cpu up.\n");
#ifndef CONFIG_FREERTOS_UNICORE
ets_printf("Starting app cpu, entry point is %p\n", call_user_start_cpu1);
SET_PERI_REG_MASK(DPORT_APPCPU_CTRL_B_REG, DPORT_APPCPU_CLKGATE_EN);
CLEAR_PERI_REG_MASK(DPORT_APPCPU_CTRL_C_REG, DPORT_APPCPU_RUNSTALL);
SET_PERI_REG_MASK(DPORT_APPCPU_CTRL_A_REG, DPORT_APPCPU_RESETTING);
CLEAR_PERI_REG_MASK(DPORT_APPCPU_CTRL_A_REG, DPORT_APPCPU_RESETTING);
ets_set_appcpu_boot_addr((uint32_t)call_user_start_cpu1);
while (!app_cpu_started) {
ets_delay_us(100);
}
#else
CLEAR_PERI_REG_MASK(DPORT_APPCPU_CTRL_B_REG, DPORT_APPCPU_CLKGATE_EN);
#endif
ets_printf("Pro cpu start user code\n");
user_start_cpu0();
}
extern int _init_start;
void IRAM_ATTR call_user_start_cpu1() {
asm volatile (\
"wsr %0, vecbase\n" \
::"r"(&_init_start));
//Make page 0 access raise an exception
//Also some other unused pages so we can catch weirdness
//ToDo: this but nicer.
asm volatile (\
"movi a4,0x00000000\n" \
"movi a5,0xf\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x80000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xa0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xc0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0xe0000000\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x20000000\n" \
"movi a5,0x0\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"movi a4,0x40000000\n" \
"movi a5,0x2\n" \
"wdtlb a5,a4\n" \
"witlb a5,a4\n" \
"isync\n" \
:::"a4","a5");
ets_printf("App cpu up.\n");
app_cpu_started = 1;
user_start_cpu1();
}
extern volatile int port_xSchedulerRunning[2];
void IRAM_ATTR user_start_cpu1(void) {
// Wait for FreeRTOS initialization to finish on PRO CPU
while (port_xSchedulerRunning[0] == 0) {
;
}
ets_printf("Starting scheduler on APP CPU.\n");
xPortStartScheduler();
}
extern void (*__init_array_start)(void); extern void (*__init_array_start)(void);
extern void (*__init_array_end)(void); extern void (*__init_array_end)(void);
extern volatile int port_xSchedulerRunning[2];
static void do_global_ctors(void) { static const char* TAG = "cpu_start";
void (**p)(void); static bool app_cpu_started = false;
for(p = &__init_array_start; p != &__init_array_end; ++p)
(*p)(); /*
* We arrive here after the bootloader finished loading the program from flash. The hardware is mostly uninitialized,
* and the app CPU is in reset. We do have a stack, so we can do the initialization in C.
*/
void IRAM_ATTR call_user_start_cpu0()
{
//Kill wdt
REG_CLR_BIT(RTC_CNTL_WDTCONFIG0_REG, RTC_CNTL_WDT_FLASHBOOT_MOD_EN);
REG_CLR_BIT(0x6001f048, BIT(14)); //DR_REG_BB_BASE+48
cpu_configure_region_protection();
//Move exception vectors to IRAM
asm volatile (\
"wsr %0, vecbase\n" \
::"r"(&_init_start));
uartAttach();
ets_install_uart_printf();
memset(&_bss_start, 0, (&_bss_end - &_bss_start) * sizeof(_bss_start));
// Initialize heap allocator
heap_alloc_caps_init();
ESP_EARLY_LOGI(TAG, "Pro cpu up.");
#ifndef CONFIG_FREERTOS_UNICORE
ESP_EARLY_LOGI(TAG, "Starting app cpu, entry point is %p", call_user_start_cpu1);
SET_PERI_REG_MASK(DPORT_APPCPU_CTRL_B_REG, DPORT_APPCPU_CLKGATE_EN);
CLEAR_PERI_REG_MASK(DPORT_APPCPU_CTRL_C_REG, DPORT_APPCPU_RUNSTALL);
SET_PERI_REG_MASK(DPORT_APPCPU_CTRL_A_REG, DPORT_APPCPU_RESETTING);
CLEAR_PERI_REG_MASK(DPORT_APPCPU_CTRL_A_REG, DPORT_APPCPU_RESETTING);
ets_set_appcpu_boot_addr((uint32_t)call_user_start_cpu1);
while (!app_cpu_started) {
ets_delay_us(100);
}
#else
ESP_EARLY_LOGI(TAG, "Single core mode");
CLEAR_PERI_REG_MASK(DPORT_APPCPU_CTRL_B_REG, DPORT_APPCPU_CLKGATE_EN);
#endif
ESP_EARLY_LOGI(TAG, "Pro cpu start user code");
user_start_cpu0();
} }
extern esp_err_t app_main(void *ctx);
void user_start_cpu0(void) { void IRAM_ATTR call_user_start_cpu1()
ets_setup_syscalls(); {
do_global_ctors(); asm volatile (\
esp_ipc_init(); "wsr %0, vecbase\n" \
spi_flash_init(); ::"r"(&_init_start));
cpu_configure_region_protection();
ESP_EARLY_LOGI(TAG, "App cpu up.");
app_cpu_started = 1;
user_start_cpu1();
}
void IRAM_ATTR user_start_cpu1(void)
{
// Wait for FreeRTOS initialization to finish on PRO CPU
while (port_xSchedulerRunning[0] == 0) {
;
}
ESP_LOGI(TAG, "Starting scheduler on APP CPU.");
xPortStartScheduler();
}
static void do_global_ctors(void)
{
void (**p)(void);
for (p = &__init_array_start; p != &__init_array_end; ++p) {
(*p)();
}
}
void user_start_cpu0(void)
{
ets_setup_syscalls();
do_global_ctors();
esp_ipc_init();
spi_flash_init();
#if CONFIG_WIFI_ENABLED #if CONFIG_WIFI_ENABLED
esp_err_t ret = nvs_flash_init(5, 3); esp_err_t ret = nvs_flash_init(5, 3);
if (ret != ESP_OK) { if (ret != ESP_OK) {
printf("nvs_flash_init failed, ret=%d\n", ret); ESP_LOGE(TAG, "nvs_flash_init failed, ret=%d", ret);
} }
system_init(); system_init();
esp_event_init(NULL, NULL); esp_event_init(NULL, NULL);
tcpip_adapter_init(); tcpip_adapter_init();
#endif #endif
#if CONFIG_WIFI_ENABLED && CONFIG_WIFI_AUTO_STARTUP #if CONFIG_WIFI_ENABLED && CONFIG_WIFI_AUTO_STARTUP
#include "esp_wifi.h" #include "esp_wifi.h"
esp_wifi_startup(app_main, NULL); esp_wifi_startup(app_main, NULL);
#else #else
app_main(NULL); app_main(NULL);
#endif #endif
ets_printf("Starting scheduler on PRO CPU.\n"); ESP_LOGI(TAG, "Starting scheduler on PRO CPU.");
vTaskStartScheduler(); vTaskStartScheduler();
} }

14
components/esp32/heap_alloc_caps.c
View file

@ -17,6 +17,9 @@
#include "heap_alloc_caps.h" #include "heap_alloc_caps.h"
#include "spiram.h" #include "spiram.h"
#include "esp_log.h"
static const char* TAG = "heap_alloc_caps";
/* /*
This file, combined with a region allocator that supports tags, solves the problem that the ESP32 has RAM that's This file, combined with a region allocator that supports tags, solves the problem that the ESP32 has RAM that's
@ -147,7 +150,7 @@ static void disable_mem_region(void *from, void *to) {
regions[i].xSizeInBytes-=(uint8_t *)regEnd-(uint8_t *)from; regions[i].xSizeInBytes-=(uint8_t *)regEnd-(uint8_t *)from;
} else if (regStart<from && regEnd>to) { } else if (regStart<from && regEnd>to) {
//Range punches a hole in the region! We do not support this. //Range punches a hole in the region! We do not support this.
ets_printf("%s: region %d: hole punching is not supported!\n", i); ESP_EARLY_LOGE(TAG, "region %d: hole punching is not supported!", i);
regions[i].xTag=-1; //Just disable memory region. That'll teach them! regions[i].xTag=-1; //Just disable memory region. That'll teach them!
} }
} }
@ -204,12 +207,13 @@ void heap_alloc_caps_init() {
} }
} }
#if 1 //Change to 1 to show the regions the heap allocator is initialized with. ESP_EARLY_LOGI(TAG, "Initializing heap allocator:");
ets_printf("Initializing heap allocator:\n");
for (i=0; regions[i].xSizeInBytes!=0; i++) { for (i=0; regions[i].xSizeInBytes!=0; i++) {
if ( regions[i].xTag != -1 ) ets_printf("Region %02d: %08X len %08X tag %d\n", i, (int)regions[i].pucStartAddress, regions[i].xSizeInBytes, regions[i].xTag); if (regions[i].xTag != -1) {
ESP_EARLY_LOGI(TAG, "Region %02d: %08X len %08X tag %d", i,
(int)regions[i].pucStartAddress, regions[i].xSizeInBytes, regions[i].xTag);
}
} }
#endif
//Initialize the malloc implementation. //Initialize the malloc implementation.
vPortDefineHeapRegionsTagged( regions ); vPortDefineHeapRegionsTagged( regions );
} }

35
components/esp32/include/soc/cpu.h
View file

@ -33,4 +33,39 @@ static inline bool cpu_in_interrupt_context(void)
return (ps & PS_UM) == 0; return (ps & PS_UM) == 0;
} }
/* Functions to set page attributes for Region Protection option in the CPU.
* See Xtensa ISA Reference manual for explanation of arguments (section 4.6.3.2).
*/
static inline void cpu_write_dtlb(uint32_t vpn, unsigned attr)
{
asm volatile ("wdtlb %1, %0; dsync\n" :: "r" (vpn), "r" (attr));
}
static inline void cpu_write_itlb(unsigned vpn, unsigned attr)
{
asm volatile ("witlb %1, %0; isync\n" :: "r" (vpn), "r" (attr));
}
/* Make page 0 access raise an exception.
* Also protect some other unused pages so we can catch weirdness.
* Useful attribute values:
* 0 — cached, RW
* 2 — bypass cache, RWX (default value after CPU reset)
* 15 — no access, raise exception
*/
static inline void cpu_configure_region_protection()
{
const uint32_t pages_to_protect[] = {0x00000000, 0x80000000, 0xa0000000, 0xc0000000, 0xe0000000};
for (int i = 0; i < sizeof(pages_to_protect)/sizeof(pages_to_protect[0]); ++i) {
cpu_write_dtlb(pages_to_protect[i], 0xf);
cpu_write_itlb(pages_to_protect[i], 0xf);
}
cpu_write_dtlb(0x20000000, 0);
cpu_write_itlb(0x20000000, 0);
}
#endif #endif

48
components/log/Kconfig Normal file
View file

@ -0,0 +1,48 @@
menu "Log output"
choice LOG_DEFAULT_LEVEL
bool "Default log verbosity"
default LOG_DEFAULT_LEVEL_INFO
help
Specify how much output to see in logs by default.
You can set lower verbosity level at runtime using
esp_log_level_set function.
Note that this setting limits which log statements
are compiled into the program. So setting this to, say,
"Warning" would mean that changing log level to "Debug"
at runtime will not be possible.
config LOG_DEFAULT_LEVEL_NONE
bool "No output"
config LOG_DEFAULT_LEVEL_ERROR
bool "Error"
config LOG_DEFAULT_LEVEL_WARN
bool "Warning"
config LOG_DEFAULT_LEVEL_INFO
bool "Info"
config LOG_DEFAULT_LEVEL_DEBUG
bool "Debug"
config LOG_DEFAULT_LEVEL_VERBOSE
bool "Verbose"
endchoice
config LOG_DEFAULT_LEVEL
int
default 0 if LOG_DEFAULT_LEVEL_NONE
default 1 if LOG_DEFAULT_LEVEL_ERROR
default 2 if LOG_DEFAULT_LEVEL_WARN
default 3 if LOG_DEFAULT_LEVEL_INFO
default 4 if LOG_DEFAULT_LEVEL_DEBUG
default 5 if LOG_DEFAULT_LEVEL_VERBOSE
config LOG_COLORS
bool "Use ANSI terminal colors in log output"
default "y"
help
Enable ANSI terminal color codes in bootloader output.
In order to view these, your terminal program must support ANSI color codes.
endmenu

3
components/log/component.mk Executable file
View file

@ -0,0 +1,3 @@
COMPONENT_ADD_INCLUDEDIRS := include
include $(IDF_PATH)/make/component_common.mk

209
components/log/include/esp_log.h Normal file
View file

@ -0,0 +1,209 @@
// Copyright 2015-2016 Espressif Systems (Shanghai) PTE LTD
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
#ifndef __ESP_LOG_H__
#define __ESP_LOG_H__
#include <stdint.h>
#include <stdarg.h>
#include "sdkconfig.h"
#ifdef __cplusplus
extern "C" {
#endif
/**
* @brief Logging library
*
* Log library has two ways of managing log verbosity: compile time, set via
* menuconfig, and runtime, using esp_log_set_level function.
*
* At compile time, filtering is done using CONFIG_LOG_DEFAULT_LEVEL macro, set via
* menuconfig. All logging statments for levels higher than CONFIG_LOG_DEFAULT_LEVEL
* will be removed by the preprocessor.
*
* At run time, all logs below CONFIG_LOG_DEFAULT_LEVEL are enabled by default.
* esp_log_set_level function may be used to set logging level per module.
* Modules are identified by their tags, which are human-readable ASCII
* zero-terminated strings.
*
* How to use this library:
*
* In each C file which uses logging functionality, define TAG variable like this:
*
* static const char* TAG = "MyModule";
*
* then use one of logging macros to produce output, e.g:
*
* ESP_LOGW(TAG, "Baud rate error %.1f%%. Requested: %d baud, actual: %d baud", error * 100, baud_req, baud_real);
*
* Several macros are available for different verbosity levels:
*
* ESP_LOGE — error
* ESP_LOGW — warning
* ESP_LOGI — info
* ESP_LOGD - debug
* ESP_LOGV - verbose
*
* Additionally there is an _EARLY_ variant for each of these macros (e.g. ESP_EARLY_LOGE).
* These variants can run in startup code, before heap allocator and syscalls
* have been initialized.
* When compiling bootloader, normal ESP_LOGx macros fall back to the same implementation
* as ESP_EARLY_LOGx macros. So the only place where ESP_EARLY_LOGx have to be used explicitly
* is the early startup code, such as heap allocator initialization code.
*
* (Note that such distinction would not have been necessary if we would have an
* ets_vprintf function in the ROM. Then it would be possible to switch implementation
* from _EARLY version to normal version on the fly. Unfortunately, ets_vprintf in ROM
* has been inlined by the compiler into ets_printf, so it is not accessible outside.)
*
* To override default verbosity level at file or component scope, define LOG_LOCAL_LEVEL macro.
* At file scope, define it before including esp_log.h, e.g.:
*
* #define LOG_LOCAL_LEVEL ESP_LOG_VERBOSE
* #include "esp_log.h"
*
* At component scope, define it in component makefile:
*
* CFLAGS += -D LOG_LOCAL_LEVEL=ESP_LOG_DEBUG
*
* To configure logging output per module at runtime, add calls to esp_log_set_level function:
*
* esp_log_set_level("*", ESP_LOG_ERROR); // set all components to ERROR level
* esp_log_set_level("wifi", ESP_LOG_WARN); // enable WARN logs from WiFi stack
* esp_log_set_level("dhcpc", ESP_LOG_INFO); // enable INFO logs from DHCP client
*
*/
typedef enum {
ESP_LOG_NONE, // No log output
ESP_LOG_ERROR, // Critical errors, software module can not recover on its own
ESP_LOG_WARN, // Error conditions from which recovery measures have been taken
ESP_LOG_INFO, // Information messages which describe normal flow of events
ESP_LOG_DEBUG, // Extra information which is not necessary for normal use (values, pointers, sizes, etc).
ESP_LOG_VERBOSE // Bigger chunks of debugging information, or frequent messages which can potentially flood the output.
} esp_log_level_t;
typedef int (*vprintf_like_t)(const char *, va_list);
/**
* @brief Set log level for given tag
*
* If logging for given component has already been enabled, changes previous setting.
*
* @param tag Tag of the log entries to enable. Must be a non-NULL zero terminated string.
* Value "*" resets log level for all tags to the given value.
*
* @param level Selects log level to enable. Only logs at this and lower levels will be shown.
*/
void esp_log_level_set(const char* tag, esp_log_level_t level);
/**
* @brief Set function used to output log entries
*
* By default, log output goes to UART0. This function can be used to redirect log
* output to some other destination, such as file or network.
*
* @param func Function used for output. Must have same signature as vprintf.
*/
void esp_log_set_vprintf(vprintf_like_t func);
/**
* @brief Write message into the log
*
* This function is not intended to be used directly. Instead, use one of
* ESP_LOGE, ESP_LOGW, ESP_LOGI, ESP_LOGD, ESP_LOGV macros.
*
* This function or these macros should not be used from an interrupt.
*/
void esp_log_write(esp_log_level_t level, const char* tag, const char* format, ...) __attribute__ ((format (printf, 3, 4)));
/**
* @brief Function which returns timestamp to be used in log output
*
* This function is used in expansion of ESP_LOGx macros.
* In the 2nd stage bootloader, and at early application startup stage
* this function uses CPU cycle counter as time source. Later when
* FreeRTOS scheduler start running, it switches to FreeRTOS tick count.
*
* For now, we ignore millisecond counter overflow.
*
* @return timestamp, in milliseconds
*/
uint32_t esp_log_timestamp();
#if CONFIG_LOG_COLORS
#define LOG_COLOR_BLACK "30"
#define LOG_COLOR_RED "31"
#define LOG_COLOR_GREEN "32"
#define LOG_COLOR_BROWN "33"
#define LOG_COLOR_BLUE "34"
#define LOG_COLOR_PURPLE "35"
#define LOG_COLOR_CYAN "36"
#define LOG_COLOR(COLOR) "\033[0;" COLOR "m"
#define LOG_BOLD(COLOR) "\033[1;" COLOR "m"
#define LOG_RESET_COLOR "\033[0m"
#define LOG_COLOR_E LOG_COLOR(LOG_COLOR_RED)
#define LOG_COLOR_W LOG_COLOR(LOG_COLOR_BROWN)
#define LOG_COLOR_I LOG_COLOR(LOG_COLOR_GREEN)
#define LOG_COLOR_D
#define LOG_COLOR_V
#else //CONFIG_LOG_COLORS
#define LOG_COLOR_E
#define LOG_COLOR_W
#define LOG_COLOR_I
#define LOG_COLOR_D
#define LOG_COLOR_V
#define LOG_RESET_COLOR
#endif //CONFIG_LOG_COLORS
#define LOG_FORMAT(letter, format) LOG_COLOR_ ## letter #letter " (%d) %s: " format LOG_RESET_COLOR "\n"
#ifndef LOG_LOCAL_LEVEL
#ifndef BOOTLOADER_BUILD
#define LOG_LOCAL_LEVEL ((esp_log_level_t) CONFIG_LOG_DEFAULT_LEVEL)
#else
#define LOG_LOCAL_LEVEL ((esp_log_level_t) CONFIG_LOG_BOOTLOADER_LEVEL)
#endif
#endif
#define ESP_EARLY_LOGE( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_ERROR) { ets_printf(LOG_FORMAT(E, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_EARLY_LOGW( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_WARN) { ets_printf(LOG_FORMAT(W, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_EARLY_LOGI( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_INFO) { ets_printf(LOG_FORMAT(I, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_EARLY_LOGD( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_DEBUG) { ets_printf(LOG_FORMAT(D, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_EARLY_LOGV( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_VERBOSE) { ets_printf(LOG_FORMAT(V, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#ifndef BOOTLOADER_BUILD
#define ESP_LOGE( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_ERROR) { esp_log_write(ESP_LOG_ERROR, tag, LOG_FORMAT(E, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_LOGW( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_WARN) { esp_log_write(ESP_LOG_WARN, tag, LOG_FORMAT(W, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_LOGI( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_INFO) { esp_log_write(ESP_LOG_INFO, tag, LOG_FORMAT(I, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_LOGD( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_DEBUG) { esp_log_write(ESP_LOG_DEBUG, tag, LOG_FORMAT(D, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#define ESP_LOGV( tag, format, ... ) if (LOG_LOCAL_LEVEL >= ESP_LOG_VERBOSE) { esp_log_write(ESP_LOG_VERBOSE, tag, LOG_FORMAT(V, format), esp_log_timestamp(), tag, ##__VA_ARGS__); }
#else
#define ESP_LOGE( tag, format, ... ) ESP_EARLY_LOGE(tag, format, ##__VA_ARGS__)
#define ESP_LOGW( tag, format, ... ) ESP_EARLY_LOGW(tag, format, ##__VA_ARGS__)
#define ESP_LOGI( tag, format, ... ) ESP_EARLY_LOGI(tag, format, ##__VA_ARGS__)
#define ESP_LOGD( tag, format, ... ) ESP_EARLY_LOGD(tag, format, ##__VA_ARGS__)
#define ESP_LOGV( tag, format, ... ) ESP_EARLY_LOGV(tag, format, ##__VA_ARGS__)
#endif // BOOTLOADER_BUILD
#ifdef __cplusplus
}
#endif
#endif /* __ESP_LOG_H__ */

313
components/log/log.c Normal file
View file

@ -0,0 +1,313 @@
// Copyright 2015-2016 Espressif Systems (Shanghai) PTE LTD
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
/*
* Log library — implementation notes.
*
* Log library stores all tags provided to esp_log_set_level as a linked
* list. See uncached_tag_entry_t structure.
*
* To avoid looking up log level for given tag each time message is
* printed, this library caches pointers to tags. Because the suggested
* way of creating tags uses one 'TAG' constant per file, this caching
* should be effective. Cache is a binary min-heap of cached_tag_entry_t
* items, ordering is done on 'generation' member. In this context,
* generation is an integer which is incremented each time an operation
* with cache is performed. When cache is full, new item is inserted in
* place of an oldest item (that is, with smallest 'generation' value).
* After that, bubble-down operation is performed to fix ordering in the
* min-heap.
*
* The potential problem with wrap-around of cache generation counter is
* ignored for now. This will happen if someone happens to output more
* than 4 billion log entries, at which point wrap-around will not be
* the biggest problem.
*
*/
#ifndef BOOTLOADER_BUILD
#include <freertos/FreeRTOS.h>
#include <freertos/FreeRTOSConfig.h>
#include <freertos/task.h>
#include <freertos/semphr.h>
#endif
#include "esp_attr.h"
#include "xtensa/hal.h"
#include "soc/soc.h"
#include <stdbool.h>
#include <stdarg.h>
#include <string.h>
#include <stdlib.h>
#include <stdio.h>
#include <assert.h>
#include "esp_log.h"
#ifndef BOOTLOADER_BUILD
// Number of tags to be cached. Must be 2**n - 1, n >= 2.
#define TAG_CACHE_SIZE 31
// Maximum time to wait for the mutex in a logging statement.
#define MAX_MUTEX_WAIT_MS 10
#define MAX_MUTEX_WAIT_TICKS ((MAX_MUTEX_WAIT_MS + portTICK_PERIOD_MS - 1) / portTICK_PERIOD_MS)
// Uncomment this to enable consistency checks and cache statistics in this file.
// #define LOG_BUILTIN_CHECKS
typedef struct {
const char* tag;
uint32_t level : 3;
uint32_t generation : 29;
} cached_tag_entry_t;
typedef struct uncached_tag_entry_{
struct uncached_tag_entry_* next;
uint8_t level; // esp_log_level_t as uint8_t
char tag[0]; // beginning of a zero-terminated string
} uncached_tag_entry_t;
static esp_log_level_t s_log_default_level = ESP_LOG_VERBOSE;
static uncached_tag_entry_t* s_log_tags_head = NULL;
static uncached_tag_entry_t* s_log_tags_tail = NULL;
static cached_tag_entry_t s_log_cache[TAG_CACHE_SIZE];
static uint32_t s_log_cache_max_generation = 0;
static uint32_t s_log_cache_entry_count = 0;
static vprintf_like_t s_log_print_func = &vprintf;
static SemaphoreHandle_t s_log_mutex = NULL;
#ifdef LOG_BUILTIN_CHECKS
static uint32_t s_log_cache_misses = 0;
#endif
static inline bool get_cached_log_level(const char* tag, esp_log_level_t* level);
static inline bool get_uncached_log_level(const char* tag, esp_log_level_t* level);
static inline void add_to_cache(const char* tag, esp_log_level_t level);
static void heap_bubble_down(int index);
static inline void heap_swap(int i, int j);
static inline bool should_output(esp_log_level_t level_for_message, esp_log_level_t level_for_tag);
static inline void clear_log_level_list();
void esp_log_set_vprintf(vprintf_like_t func)
{
s_log_print_func = func;
}
void esp_log_level_set(const char* tag, esp_log_level_t level)
{
if (!s_log_mutex) {
s_log_mutex = xSemaphoreCreateMutex();
}
xSemaphoreTake(s_log_mutex, portMAX_DELAY);
// for wildcard tag, remove all linked list items and clear the cache
if (strcmp(tag, "*") == 0) {
s_log_default_level = level;
clear_log_level_list();
xSemaphoreGive(s_log_mutex);
return;
}
// allocate new linked list entry and append it to the endo of the list
size_t entry_size = offsetof(uncached_tag_entry_t, tag) + strlen(tag) + 1;
uncached_tag_entry_t* new_entry = (uncached_tag_entry_t*) malloc(entry_size);
if (!new_entry) {
xSemaphoreGive(s_log_mutex);
return;
}
new_entry->next = NULL;
new_entry->level = (uint8_t) level;
strcpy(new_entry->tag, tag);
if (s_log_tags_tail) {
s_log_tags_tail->next = new_entry;
}
s_log_tags_tail = new_entry;
if (!s_log_tags_head) {
s_log_tags_head = new_entry;
}
xSemaphoreGive(s_log_mutex);
}
void clear_log_level_list()
{
for (uncached_tag_entry_t* it = s_log_tags_head; it != NULL; ) {
uncached_tag_entry_t* next = it->next;
free(it);
it = next;
}
s_log_tags_tail = NULL;
s_log_tags_head = NULL;
s_log_cache_entry_count = 0;
s_log_cache_max_generation = 0;
#ifdef LOG_BUILTIN_CHECKS
s_log_cache_misses = 0;
#endif
}
void IRAM_ATTR esp_log_write(esp_log_level_t level,
const char* tag,
const char* format, ...)
{
if (!s_log_mutex) {
s_log_mutex = xSemaphoreCreateMutex();
}
if (xSemaphoreTake(s_log_mutex, MAX_MUTEX_WAIT_TICKS) == pdFALSE) {
return;
}
esp_log_level_t level_for_tag;
// Look for the tag in cache first, then in the linked list of all tags
if (!get_cached_log_level(tag, &level_for_tag)) {
if (!get_uncached_log_level(tag, &level_for_tag)) {
level_for_tag = s_log_default_level;
}
add_to_cache(tag, level_for_tag);
#ifdef LOG_BUILTIN_CHECKS
++s_log_cache_misses;
#endif
}
xSemaphoreGive(s_log_mutex);
if (!should_output(level, level_for_tag)) {
return;
}
va_list list;
va_start(list, format);
(*s_log_print_func)(format, list);
va_end(list);
}
static inline bool get_cached_log_level(const char* tag, esp_log_level_t* level)
{
// Look for `tag` in cache
int 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[i].generation);
#endif
if (s_log_cache[i].tag == tag) {
break;
}
}
if (i == s_log_cache_entry_count) { // Not found in cache
return false;
}
// Return level from cache
*level = (esp_log_level_t) s_log_cache[i].level;
// If cache has been filled, start taking ordering into account
// (other options are: dynamically resize cache, add "dummy" entries
// to the cache; this option was chosen because code is much simpler,
// and the unfair behavior of cache will show it self at most once, when
// it has just been filled)
if (s_log_cache_entry_count == TAG_CACHE_SIZE) {
// Update item generation
s_log_cache[i].generation = s_log_cache_max_generation++;
// Restore heap ordering
heap_bubble_down(i);
}
return true;
}
static inline void add_to_cache(const char* tag, esp_log_level_t level)
{
uint32_t generation = s_log_cache_max_generation++;
// First consider the case when cache is not filled yet.
// In this case, just add new entry at the end.
// This happens to satisfy binary min-heap ordering.
if (s_log_cache_entry_count < TAG_CACHE_SIZE) {
s_log_cache[s_log_cache_entry_count] = (cached_tag_entry_t) {
.generation = generation,
.level = level,
.tag = tag
};
++s_log_cache_entry_count;
return;
}
// Cache is full, so we replace the oldest entry (which is at index 0
// because this is a min-heap) with the new one, and do bubble-down
// operation to restore min-heap ordering.
s_log_cache[0] = (cached_tag_entry_t) {
.tag = tag,
.level = level,
.generation = generation
};
heap_bubble_down(0);
}
static inline bool get_uncached_log_level(const char* tag, esp_log_level_t* level)
{
// Walk the linked list of all tags and see if given tag is present in the list.
// This is slow because tags are compared as strings.
for (uncached_tag_entry_t* it = s_log_tags_head; it != NULL; it = it->next) {
if (strcmp(tag, it->tag) == 0) {
*level = it->level;
return true;
}
}
return false;
}
static inline bool should_output(esp_log_level_t level_for_message, esp_log_level_t level_for_tag)
{
return level_for_message <= level_for_tag;
}
static void heap_bubble_down(int index)
{
while (index < TAG_CACHE_SIZE / 2) {
int left_index = index * 2 + 1;
int right_index = left_index + 1;
int next = (s_log_cache[left_index].generation < s_log_cache[right_index].generation) ? left_index : right_index;
heap_swap(index, next);
index = next;
}
}
static inline void heap_swap(int i, int j)
{
cached_tag_entry_t tmp = s_log_cache[i];
s_log_cache[i] = s_log_cache[j];
s_log_cache[j] = tmp;
}
#endif //BOOTLOADER_BUILD
inline IRAM_ATTR uint32_t esp_log_early_timestamp()
{
return xthal_get_ccount() / (CPU_CLK_FREQ_ROM / 1000);
}
#ifndef BOOTLOADER_BUILD
uint32_t IRAM_ATTR esp_log_timestamp()
{
if (xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED) {
return esp_log_early_timestamp();
}
static uint32_t base = 0;
if (base == 0) {
base = esp_log_early_timestamp();
}
return base + xTaskGetTickCount() * (1000 / configTICK_RATE_HZ);
}
#else
uint32_t IRAM_ATTR esp_log_timestamp()
{
return esp_log_early_timestamp();
}
#endif //BOOTLOADER_BUILD