From 289c28a8f5954bd548e6ab9ac8515479981fb6d1 Mon Sep 17 00:00:00 2001 From: Dan Handley Date: Fri, 8 Aug 2014 14:36:42 +0100 Subject: [PATCH 1/2] Add concept of console output log levels Create new LOG_LEVEL build option, which controls the amount of console output compiled into the build. This should be one of the following: 0 (LOG_LEVEL_NONE) 10 (LOG_LEVEL_NOTICE) 20 (LOG_LEVEL_ERROR) 30 (LOG_LEVEL_WARNING) 40 (LOG_LEVEL_INFO) 50 (LOG_LEVEL_VERBOSE) All log output up to and including the log level is compiled into the build. The default value is 40 in debug builds and 20 in release builds. Complement the existing INFO, WARN and ERROR console output macros with NOTICE and VERBOSE macros, which are conditionally compiled in depending on the value of LOG_LEVEL. Fixes ARM-software/tf-issues#232 Change-Id: I951e2f333e7b90fc4b1060741d9a6db699d5aa72 --- Makefile | 7 ++++++ docs/user-guide.md | 13 ++++++++++ include/common/debug.h | 57 +++++++++++++++++++++++++++++++----------- 3 files changed, 63 insertions(+), 14 deletions(-) diff --git a/Makefile b/Makefile index fef89c2e8..60ef86425 100644 --- a/Makefile +++ b/Makefile @@ -80,8 +80,12 @@ export Q ifneq (${DEBUG}, 0) BUILD_TYPE := debug + # Use LOG_LEVEL_INFO by default for debug builds + LOG_LEVEL := 40 else BUILD_TYPE := release + # Use LOG_LEVEL_NOTICE by default for release builds + LOG_LEVEL := 20 endif # Default build string (git branch and commit) @@ -213,6 +217,9 @@ $(eval $(call add_define,ARM_GIC_ARCH)) $(eval $(call assert_boolean,ASM_ASSERTION)) $(eval $(call add_define,ASM_ASSERTION)) +# Process LOG_LEVEL flag +$(eval $(call add_define,LOG_LEVEL)) + ASFLAGS += -nostdinc -ffreestanding -Wa,--fatal-warnings \ -Werror -Wmissing-include-dirs \ -mgeneral-regs-only -D__ASSEMBLY__ \ diff --git a/docs/user-guide.md b/docs/user-guide.md index ef5de7144..00de3e50e 100644 --- a/docs/user-guide.md +++ b/docs/user-guide.md @@ -146,6 +146,19 @@ performed. * `DEBUG`: Chooses between a debug and release build. It can take either 0 (release) or 1 (debug) as values. 0 is the default +* `LOG_LEVEL`: Chooses the log level, which controls the amount of console log + output compiled into the build. This should be one of the following: + + 0 (LOG_LEVEL_NONE) + 10 (LOG_LEVEL_NOTICE) + 20 (LOG_LEVEL_ERROR) + 30 (LOG_LEVEL_WARNING) + 40 (LOG_LEVEL_INFO) + 50 (LOG_LEVEL_VERBOSE) + + All log output up to and including the log level is compiled into the build. + The default value is 40 in debug builds and 20 in release builds. + * `NS_TIMER_SWITCH`: Enable save and restore for non-secure timer register contents upon world switch. It can take either 0 (don't save and restore) or 1 (do save and restore). 0 is the default. An SPD could set this to 1 if it diff --git a/include/common/debug.h b/include/common/debug.h index 3f5655ba8..a8dcb8da3 100644 --- a/include/common/debug.h +++ b/include/common/debug.h @@ -33,24 +33,53 @@ #include -/* If building the project with DEBUG disabled the INFO and WARN macros - * won't produce any output. The ERROR macro is always enabled. - * The format expected is the same as for printf(). - * INFO("Info %s.\n", "message") -> INFO: Info message. - * WARN("Warning %s.\n", "message") -> WARN: Warning message. - * ERROR("Error %s.\n", "message") -> ERROR: Error message. - * - * TODO : add debug levels. +/* The log output macros print output to the console. These macros produce + * compiled log output only if the LOG_LEVEL defined in the makefile (or the + * make command line) is greater or equal than the level required for that + * type of log output. + * The format expected is the same as for printf(). For example: + * INFO("Info %s.\n", "message") -> INFO: Info message. + * WARN("Warning %s.\n", "message") -> WARNING: Warning message. */ -#if DEBUG - #define INFO(...) tf_printf("INFO: " __VA_ARGS__) - #define WARN(...) tf_printf("WARN: " __VA_ARGS__) + +#define LOG_LEVEL_NONE 0 +#define LOG_LEVEL_ERROR 10 +#define LOG_LEVEL_NOTICE 20 +#define LOG_LEVEL_WARNING 30 +#define LOG_LEVEL_INFO 40 +#define LOG_LEVEL_VERBOSE 50 + + +#if LOG_LEVEL >= LOG_LEVEL_NOTICE +# define NOTICE(...) tf_printf("NOTICE: " __VA_ARGS__) #else - #define INFO(...) - #define WARN(...) +# define NOTICE(...) +#endif + +#if LOG_LEVEL >= LOG_LEVEL_ERROR +# define ERROR(...) tf_printf("ERROR: " __VA_ARGS__) +#else +# define ERROR(...) +#endif + +#if LOG_LEVEL >= LOG_LEVEL_WARNING +# define WARN(...) tf_printf("WARNING: " __VA_ARGS__) +#else +# define WARN(...) +#endif + +#if LOG_LEVEL >= LOG_LEVEL_INFO +# define INFO(...) tf_printf("INFO: " __VA_ARGS__) +#else +# define INFO(...) +#endif + +#if LOG_LEVEL >= LOG_LEVEL_VERBOSE +# define VERBOSE(...) tf_printf("VERBOSE: " __VA_ARGS__) +#else +# define VERBOSE(...) #endif -#define ERROR(...) tf_printf("ERROR: " __VA_ARGS__) void __dead2 do_panic(void); #define panic() do_panic() From 6ad2e461f0cd6de5aefd89fa0ba7acf2c293b8c2 Mon Sep 17 00:00:00 2001 From: Dan Handley Date: Tue, 29 Jul 2014 17:14:00 +0100 Subject: [PATCH 2/2] Rationalize console log output Fix the following issues with the console log output: * Make sure the welcome string is the first thing in the log output (during normal boot). * Prefix each message with the BL image name so it's clear which BL the output is coming from. * Ensure all output is wrapped in one of the log output macros so it can be easily compiled out if necessary. Change some of the INFO() messages to VERBOSE(), especially in the TSP. * Create some extra NOTICE() and INFO() messages during cold boot. * Remove all usage of \r in log output. Fixes ARM-software/tf-issues#231 Change-Id: Ib24f7acb36ce64bbba549f204b9cde2dbb46c8a3 --- bl1/bl1_main.c | 46 +++++++++--------- bl2/bl2_main.c | 10 ++-- bl31/bl31_main.c | 17 +++++-- bl32/tsp/tsp_interrupt.c | 30 +++++++----- bl32/tsp/tsp_main.c | 86 ++++++++++++++++++--------------- common/bl_common.c | 12 ++--- drivers/io/io_fip.c | 2 +- lib/stdlib/abort.c | 6 +-- lib/stdlib/assert.c | 2 +- plat/fvp/bl1_fvp_setup.c | 3 -- plat/fvp/fvp_io_storage.c | 6 +-- plat/fvp/include/platform_def.h | 2 +- 12 files changed, 120 insertions(+), 102 deletions(-) diff --git a/bl1/bl1_main.c b/bl1/bl1_main.c index c6f2caadf..a5bd648c0 100644 --- a/bl1/bl1_main.c +++ b/bl1/bl1_main.c @@ -106,6 +106,13 @@ void bl1_init_bl2_mem_layout(const meminfo_t *bl1_mem_layout, ******************************************************************************/ void bl1_main(void) { + /* Announce our arrival */ + NOTICE(FIRMWARE_WELCOME_STR); + NOTICE("BL1: %s\n", version_string); + NOTICE("BL1: %s\n", build_message); + + INFO("BL1: RAM 0x%lx - 0x%lx\n", BL1_RAM_BASE, BL1_RAM_LIMIT); + #if DEBUG unsigned long sctlr_el3 = read_sctlr_el3(); #endif @@ -128,11 +135,6 @@ void bl1_main(void) /* Perform platform setup in BL1. */ bl1_platform_setup(); - /* Announce our arrival */ - tf_printf(FIRMWARE_WELCOME_STR); - tf_printf("%s\n", version_string); - tf_printf("%s\n", build_message); - SET_PARAM_HEAD(&bl2_image_info, PARAM_IMAGE_BINARY, VERSION_1, 0); SET_PARAM_HEAD(&bl2_ep, PARAM_EP, VERSION_1, 0); @@ -150,7 +152,7 @@ void bl1_main(void) * TODO: print failure to load BL2 but also add a tzwdog timer * which will reset the system eventually. */ - tf_printf("Failed to load boot loader stage 2 (BL2) firmware.\n"); + ERROR("Failed to load BL2 firmware.\n"); panic(); } /* @@ -165,14 +167,13 @@ void bl1_main(void) bl1_plat_set_bl2_ep_info(&bl2_image_info, &bl2_ep); bl2_ep.args.arg1 = (unsigned long)bl2_tzram_layout; - tf_printf("Booting trusted firmware boot loader stage 2\n"); -#if DEBUG - tf_printf("BL2 address = 0x%llx\n", + NOTICE("BL1: Booting BL2\n"); + INFO("BL1: BL2 address = 0x%llx\n", (unsigned long long) bl2_ep.pc); - tf_printf("BL2 cpsr = 0x%x\n", bl2_ep.spsr); - tf_printf("BL2 memory layout address = 0x%llx\n", - (unsigned long long) bl2_tzram_layout); -#endif + INFO("BL1: BL2 spsr = 0x%x\n", bl2_ep.spsr); + VERBOSE("BL1: BL2 memory layout address = 0x%llx\n", + (unsigned long long) bl2_tzram_layout); + bl1_run_bl2(&bl2_ep); return; @@ -184,14 +185,13 @@ void bl1_main(void) ******************************************************************************/ void display_boot_progress(entry_point_info_t *bl31_ep_info) { - tf_printf("Booting trusted firmware boot loader stage 3\n\r"); -#if DEBUG - tf_printf("BL31 address = 0x%llx\n", (unsigned long long)bl31_ep_info->pc); - tf_printf("BL31 cpsr = 0x%llx\n", (unsigned long long)bl31_ep_info->spsr); - tf_printf("BL31 params address = 0x%llx\n", - (unsigned long long)bl31_ep_info->args.arg0); - tf_printf("BL31 plat params address = 0x%llx\n", - (unsigned long long)bl31_ep_info->args.arg1); -#endif - return; + NOTICE("BL1: Booting BL3-1\n"); + INFO("BL1: BL3-1 address = 0x%llx\n", + (unsigned long long)bl31_ep_info->pc); + INFO("BL1: BL3-1 spsr = 0x%llx\n", + (unsigned long long)bl31_ep_info->spsr); + INFO("BL1: BL3-1 params address = 0x%llx\n", + (unsigned long long)bl31_ep_info->args.arg0); + INFO("BL1: BL3-1 plat params address = 0x%llx\n", + (unsigned long long)bl31_ep_info->args.arg1); } diff --git a/bl2/bl2_main.c b/bl2/bl2_main.c index ca8384265..51c55e01c 100644 --- a/bl2/bl2_main.c +++ b/bl2/bl2_main.c @@ -59,6 +59,7 @@ static int load_bl30(void) * The entry point information is not relevant in this case as the AP * won't execute the BL3-0 image. */ + INFO("BL2: Loading BL3-0\n"); bl2_plat_get_bl30_meminfo(&bl30_mem_info); e = load_image(&bl30_mem_info, BL30_IMAGE_NAME, @@ -87,6 +88,7 @@ static int load_bl31(bl31_params_t *bl2_to_bl31_params, meminfo_t *bl2_tzram_layout; int e; + INFO("BL2: Loading BL3-1\n"); assert(bl2_to_bl31_params != NULL); assert(bl31_ep_info != NULL); @@ -125,6 +127,7 @@ static int load_bl32(bl31_params_t *bl2_to_bl31_params) #ifdef BL32_BASE meminfo_t bl32_mem_info; + INFO("BL2: Loading BL3-2\n"); assert(bl2_to_bl31_params != NULL); /* @@ -160,6 +163,7 @@ static int load_bl33(bl31_params_t *bl2_to_bl31_params) meminfo_t bl33_mem_info; int e; + INFO("BL2: Loading BL3-3\n"); assert(bl2_to_bl31_params != NULL); bl2_plat_get_bl33_meminfo(&bl33_mem_info); @@ -189,15 +193,15 @@ void bl2_main(void) entry_point_info_t *bl31_ep_info; int e; + NOTICE("BL2: %s\n", version_string); + NOTICE("BL2: %s\n", build_message); + /* Perform remaining generic architectural setup in S-EL1 */ bl2_arch_setup(); /* Perform platform setup in BL2 */ bl2_platform_setup(); - tf_printf("BL2 %s\n", version_string); - tf_printf("BL2 %s\n", build_message); - /* * Load the subsequent bootloader images */ diff --git a/bl31/bl31_main.c b/bl31/bl31_main.c index 68bdd367f..19f377436 100644 --- a/bl31/bl31_main.c +++ b/bl31/bl31_main.c @@ -71,19 +71,20 @@ void bl31_lib_init(void) ******************************************************************************/ void bl31_main(void) { + NOTICE("BL3-1: %s\n", version_string); + NOTICE("BL3-1: %s\n", build_message); + /* Perform remaining generic architectural setup from EL3 */ bl31_arch_setup(); /* Perform platform setup in BL1 */ bl31_platform_setup(); - tf_printf("BL31 %s\n", version_string); - tf_printf("BL31 %s\n", build_message); - /* Initialise helper libraries */ bl31_lib_init(); /* Initialize the runtime services e.g. psci */ + INFO("BL3-1: Initializing runtime services\n"); runtime_svc_init(); /* Clean caches before re-entering normal world */ @@ -102,9 +103,10 @@ void bl31_main(void) /* * If SPD had registerd an init hook, invoke it. */ - if (bl32_init) + if (bl32_init) { + INFO("BL3-1: Initializing BL3-2\n"); (*bl32_init)(); - + } /* * We are ready to enter the next EL. Prepare entry into the image * corresponding to the desired security state after the next ERET. @@ -148,6 +150,11 @@ void bl31_prepare_next_image_entry(void) assert(next_image_info); assert(image_type == GET_SECURITY_STATE(next_image_info->h.attr)); + INFO("BL3-1: Preparing for EL3 exit to %s world\n", + (image_type == SECURE) ? "secure" : "normal"); + INFO("BL3-1: Next image address = 0x%llx\n", + (unsigned long long) next_image_info->pc); + INFO("BL3-1: Next image spsr = 0x%x\n", next_image_info->spsr); cm_init_context(read_mpidr_el1(), next_image_info); cm_prepare_el3_exit(image_type); } diff --git a/bl32/tsp/tsp_interrupt.c b/bl32/tsp/tsp_interrupt.c index c1c9aad2f..65c581f65 100644 --- a/bl32/tsp/tsp_interrupt.c +++ b/bl32/tsp/tsp_interrupt.c @@ -55,14 +55,16 @@ void tsp_update_sync_fiq_stats(uint32_t type, uint64_t elr_el3) if (type == TSP_HANDLE_FIQ_AND_RETURN) tsp_stats[linear_id].sync_fiq_ret_count++; +#if LOG_LEVEL >= LOG_LEVEL_VERBOSE spin_lock(&console_lock); - tf_printf("TSP: cpu 0x%x sync fiq request from 0x%llx \n\r", - mpidr, elr_el3); - INFO("cpu 0x%x: %d sync fiq requests, %d sync fiq returns\n", - mpidr, - tsp_stats[linear_id].sync_fiq_count, - tsp_stats[linear_id].sync_fiq_ret_count); + VERBOSE("TSP: cpu 0x%x sync fiq request from 0x%llx\n", + mpidr, elr_el3); + VERBOSE("TSP: cpu 0x%x: %d sync fiq requests, %d sync fiq returns\n", + mpidr, + tsp_stats[linear_id].sync_fiq_count, + tsp_stats[linear_id].sync_fiq_ret_count); spin_unlock(&console_lock); +#endif } /******************************************************************************* @@ -99,13 +101,14 @@ int32_t tsp_fiq_handler(void) /* Update the statistics and print some messages */ tsp_stats[linear_id].fiq_count++; +#if LOG_LEVEL >= LOG_LEVEL_VERBOSE spin_lock(&console_lock); - tf_printf("TSP: cpu 0x%x handled fiq %d \n\r", + VERBOSE("TSP: cpu 0x%x handled fiq %d\n", mpidr, id); - INFO("cpu 0x%x: %d fiq requests \n", + VERBOSE("TSP: cpu 0x%x: %d fiq requests\n", mpidr, tsp_stats[linear_id].fiq_count); spin_unlock(&console_lock); - +#endif return 0; } @@ -115,11 +118,12 @@ int32_t tsp_irq_received(void) uint32_t linear_id = platform_get_core_pos(mpidr); tsp_stats[linear_id].irq_count++; +#if LOG_LEVEL >= LOG_LEVEL_VERBOSE spin_lock(&console_lock); - tf_printf("TSP: cpu 0x%x received irq\n\r", mpidr); - INFO("cpu 0x%x: %d irq requests \n", - mpidr, tsp_stats[linear_id].irq_count); + VERBOSE("TSP: cpu 0x%x received irq\n", mpidr); + VERBOSE("TSP: cpu 0x%x: %d irq requests\n", + mpidr, tsp_stats[linear_id].irq_count); spin_unlock(&console_lock); - +#endif return TSP_PREEMPTED; } diff --git a/bl32/tsp/tsp_main.c b/bl32/tsp/tsp_main.c index b2850e9d4..982bab2fb 100644 --- a/bl32/tsp/tsp_main.c +++ b/bl32/tsp/tsp_main.c @@ -105,6 +105,12 @@ static tsp_args_t *set_smc_args(uint64_t arg0, ******************************************************************************/ uint64_t tsp_main(void) { + NOTICE("TSP: %s\n", version_string); + NOTICE("TSP: %s\n", build_message); + INFO("TSP: Total memory base : 0x%x\n", (unsigned long)BL32_TOTAL_BASE); + INFO("TSP: Total memory size : 0x%x bytes\n", + (unsigned long)(BL32_TOTAL_LIMIT - BL32_TOTAL_BASE)); + uint64_t mpidr = read_mpidr(); uint32_t linear_id = platform_get_core_pos(mpidr); @@ -119,18 +125,14 @@ uint64_t tsp_main(void) tsp_stats[linear_id].eret_count++; tsp_stats[linear_id].cpu_on_count++; +#if LOG_LEVEL >= LOG_LEVEL_INFO spin_lock(&console_lock); - tf_printf("TSP %s\n", version_string); - tf_printf("TSP %s\n", build_message); - INFO("Total memory base : 0x%x\n", (unsigned long)BL32_TOTAL_BASE); - INFO("Total memory size : 0x%x bytes\n", - (unsigned long)(BL32_TOTAL_LIMIT - BL32_TOTAL_BASE)); - INFO("cpu 0x%x: %d smcs, %d erets %d cpu on requests\n", mpidr, + INFO("TSP: cpu 0x%x: %d smcs, %d erets %d cpu on requests\n", mpidr, tsp_stats[linear_id].smc_count, tsp_stats[linear_id].eret_count, tsp_stats[linear_id].cpu_on_count); spin_unlock(&console_lock); - +#endif return (uint64_t) &tsp_vector_table; } @@ -152,14 +154,15 @@ tsp_args_t *tsp_cpu_on_main(void) tsp_stats[linear_id].eret_count++; tsp_stats[linear_id].cpu_on_count++; +#if LOG_LEVEL >= LOG_LEVEL_INFO spin_lock(&console_lock); - tf_printf("SP: cpu 0x%x turned on\n\r", mpidr); - INFO("cpu 0x%x: %d smcs, %d erets %d cpu on requests\n", mpidr, - tsp_stats[linear_id].smc_count, - tsp_stats[linear_id].eret_count, - tsp_stats[linear_id].cpu_on_count); + INFO("TSP: cpu 0x%x turned on\n", mpidr); + INFO("TSP: cpu 0x%x: %d smcs, %d erets %d cpu on requests\n", mpidr, + tsp_stats[linear_id].smc_count, + tsp_stats[linear_id].eret_count, + tsp_stats[linear_id].cpu_on_count); spin_unlock(&console_lock); - +#endif /* Indicate to the SPD that we have completed turned ourselves on */ return set_smc_args(TSP_ON_DONE, 0, 0, 0, 0, 0, 0, 0); } @@ -192,14 +195,15 @@ tsp_args_t *tsp_cpu_off_main(uint64_t arg0, tsp_stats[linear_id].eret_count++; tsp_stats[linear_id].cpu_off_count++; +#if LOG_LEVEL >= LOG_LEVEL_INFO spin_lock(&console_lock); - tf_printf("SP: cpu 0x%x off request\n\r", mpidr); - INFO("cpu 0x%x: %d smcs, %d erets %d cpu off requests\n", mpidr, - tsp_stats[linear_id].smc_count, - tsp_stats[linear_id].eret_count, - tsp_stats[linear_id].cpu_off_count); + INFO("TSP: cpu 0x%x off request\n", mpidr); + INFO("TSP: cpu 0x%x: %d smcs, %d erets %d cpu off requests\n", mpidr, + tsp_stats[linear_id].smc_count, + tsp_stats[linear_id].eret_count, + tsp_stats[linear_id].cpu_off_count); spin_unlock(&console_lock); - +#endif /* Indicate to the SPD that we have completed this request */ return set_smc_args(TSP_OFF_DONE, 0, 0, 0, 0, 0, 0, 0); @@ -234,14 +238,17 @@ tsp_args_t *tsp_cpu_suspend_main(uint64_t power_state, tsp_stats[linear_id].eret_count++; tsp_stats[linear_id].cpu_suspend_count++; +#if LOG_LEVEL >= LOG_LEVEL_INFO spin_lock(&console_lock); - tf_printf("SP: cpu 0x%x suspend request. power state: 0x%x\n\r", - mpidr, power_state); - INFO("cpu 0x%x: %d smcs, %d erets %d cpu suspend requests\n", mpidr, - tsp_stats[linear_id].smc_count, - tsp_stats[linear_id].eret_count, - tsp_stats[linear_id].cpu_suspend_count); + INFO("TSP: cpu 0x%x suspend request. power state: 0x%x\n", + mpidr, power_state); + INFO("TSP: cpu 0x%x: %d smcs, %d erets %d cpu suspend requests\n", + mpidr, + tsp_stats[linear_id].smc_count, + tsp_stats[linear_id].eret_count, + tsp_stats[linear_id].cpu_suspend_count); spin_unlock(&console_lock); +#endif /* Indicate to the SPD that we have completed this request */ return set_smc_args(TSP_SUSPEND_DONE, 0, 0, 0, 0, 0, 0, 0); @@ -272,15 +279,17 @@ tsp_args_t *tsp_cpu_resume_main(uint64_t suspend_level, tsp_stats[linear_id].eret_count++; tsp_stats[linear_id].cpu_resume_count++; +#if LOG_LEVEL >= LOG_LEVEL_INFO spin_lock(&console_lock); - tf_printf("SP: cpu 0x%x resumed. suspend level %d \n\r", - mpidr, suspend_level); - INFO("cpu 0x%x: %d smcs, %d erets %d cpu suspend requests\n", mpidr, - tsp_stats[linear_id].smc_count, - tsp_stats[linear_id].eret_count, - tsp_stats[linear_id].cpu_suspend_count); + INFO("TSP: cpu 0x%x resumed. suspend level %d\n", + mpidr, suspend_level); + INFO("TSP: cpu 0x%x: %d smcs, %d erets %d cpu suspend requests\n", + mpidr, + tsp_stats[linear_id].smc_count, + tsp_stats[linear_id].eret_count, + tsp_stats[linear_id].cpu_suspend_count); spin_unlock(&console_lock); - +#endif /* Indicate to the SPD that we have completed this request */ return set_smc_args(TSP_RESUME_DONE, 0, 0, 0, 0, 0, 0, 0); } @@ -304,18 +313,17 @@ tsp_args_t *tsp_smc_handler(uint64_t func, uint64_t service_args[2]; uint64_t mpidr = read_mpidr(); uint32_t linear_id = platform_get_core_pos(mpidr); - const char *smc_type; /* Update this cpu's statistics */ tsp_stats[linear_id].smc_count++; tsp_stats[linear_id].eret_count++; - smc_type = ((func >> 31) & 1) == 1 ? "fast" : "standard"; - - tf_printf("SP: cpu 0x%x received %s smc 0x%x\n", read_mpidr(), smc_type, func); - INFO("cpu 0x%x: %d smcs, %d erets\n", mpidr, - tsp_stats[linear_id].smc_count, - tsp_stats[linear_id].eret_count); + INFO("TSP: cpu 0x%x received %s smc 0x%x\n", read_mpidr(), + ((func >> 31) & 1) == 1 ? "fast" : "standard", + func); + INFO("TSP: cpu 0x%x: %d smcs, %d erets\n", mpidr, + tsp_stats[linear_id].smc_count, + tsp_stats[linear_id].eret_count); /* Render secure services and obtain results here */ results[0] = arg1; diff --git a/common/bl_common.c b/common/bl_common.c index d2c60eff8..60f8b2f7d 100644 --- a/common/bl_common.c +++ b/common/bl_common.c @@ -137,7 +137,7 @@ void reserve_mem(uint64_t *free_base, size_t *free_size, if (pos == BOTTOM) *free_base = addr + size; - INFO("Reserved %u bytes (discarded %u bytes %s)\n", + VERBOSE("Reserved %u bytes (discarded %u bytes %s)\n", reserved_size, discard_size, pos == TOP ? "above" : "below"); } @@ -146,15 +146,13 @@ static void dump_load_info(unsigned long image_load_addr, unsigned long image_size, const meminfo_t *mem_layout) { -#if DEBUG - tf_printf("Trying to load image at address 0x%lx, size = 0x%lx\r\n", + INFO("Trying to load image at address 0x%lx, size = 0x%lx\n", image_load_addr, image_size); - tf_printf("Current memory layout:\r\n"); - tf_printf(" total region = [0x%lx, 0x%lx]\r\n", mem_layout->total_base, + INFO("Current memory layout:\n"); + INFO(" total region = [0x%lx, 0x%lx]\n", mem_layout->total_base, mem_layout->total_base + mem_layout->total_size); - tf_printf(" free region = [0x%lx, 0x%lx]\r\n", mem_layout->free_base, + INFO(" free region = [0x%lx, 0x%lx]\n", mem_layout->free_base, mem_layout->free_base + mem_layout->free_size); -#endif } /* Generic function to return the size of an image */ diff --git a/drivers/io/io_fip.c b/drivers/io/io_fip.c index 7df229d3d..4262a9de4 100644 --- a/drivers/io/io_fip.c +++ b/drivers/io/io_fip.c @@ -215,7 +215,7 @@ static int fip_dev_init(io_dev_info_t *dev_info, const uintptr_t init_params) WARN("Firmware Image Package header check failed.\n"); result = IO_FAIL; } else { - INFO("FIP header looks OK.\n"); + VERBOSE("FIP header looks OK.\n"); } } diff --git a/lib/stdlib/abort.c b/lib/stdlib/abort.c index 2ef3beeaf..862bf9c4b 100644 --- a/lib/stdlib/abort.c +++ b/lib/stdlib/abort.c @@ -28,13 +28,13 @@ * POSSIBILITY OF SUCH DAMAGE. */ -#include +#include /* * This is a basic implementation. This could be improved. */ void abort (void) { - printf("ABORT\n\r"); - while(1); + ERROR("ABORT\n"); + panic(); } diff --git a/lib/stdlib/assert.c b/lib/stdlib/assert.c index c614854f6..90a1afe50 100644 --- a/lib/stdlib/assert.c +++ b/lib/stdlib/assert.c @@ -36,6 +36,6 @@ void __assert (const char *function, const char *file, unsigned int line, const char *assertion) { - tf_printf("ASSERT: %s <%d> : %s\n\r", function, line, assertion); + tf_printf("ASSERT: %s <%d> : %s\n", function, line, assertion); while(1); } diff --git a/plat/fvp/bl1_fvp_setup.c b/plat/fvp/bl1_fvp_setup.c index b146fdb70..85b4c47d0 100644 --- a/plat/fvp/bl1_fvp_setup.c +++ b/plat/fvp/bl1_fvp_setup.c @@ -87,9 +87,6 @@ void bl1_early_platform_setup(void) BL1_RAM_BASE, bl1_size); - INFO("BL1: 0x%lx - 0x%lx [size = %u]\n", BL1_RAM_BASE, BL1_RAM_LIMIT, - bl1_size); - /* Initialize the platform config for future decision making */ fvp_config_setup(); } diff --git a/plat/fvp/fvp_io_storage.c b/plat/fvp/fvp_io_storage.c index c32cca928..1f695a6db 100644 --- a/plat/fvp/fvp_io_storage.c +++ b/plat/fvp/fvp_io_storage.c @@ -127,7 +127,7 @@ static int open_fip(const uintptr_t spec) /* See if a Firmware Image Package is available */ result = io_dev_init(fip_dev_handle, (uintptr_t)FIP_IMAGE_NAME); if (result == IO_SUCCESS) { - INFO("Using FIP\n"); + VERBOSE("Using FIP\n"); /*TODO: Check image defined in spec is present in FIP. */ } return result; @@ -143,7 +143,7 @@ static int open_memmap(const uintptr_t spec) if (result == IO_SUCCESS) { result = io_open(memmap_dev_handle, spec, &local_image_handle); if (result == IO_SUCCESS) { - /* INFO("Using Memmap IO\n"); */ + VERBOSE("Using Memmap IO\n"); io_close(local_image_handle); } } @@ -161,7 +161,7 @@ static int open_semihosting(const uintptr_t spec) if (result == IO_SUCCESS) { result = io_open(sh_dev_handle, spec, &local_image_handle); if (result == IO_SUCCESS) { - INFO("Using Semi-hosting IO\n"); + VERBOSE("Using Semi-hosting IO\n"); io_close(local_image_handle); } } diff --git a/plat/fvp/include/platform_def.h b/plat/fvp/include/platform_def.h index 70f84bbee..028f15405 100644 --- a/plat/fvp/include/platform_def.h +++ b/plat/fvp/include/platform_def.h @@ -47,7 +47,7 @@ /* Size of cacheable stacks */ #define PLATFORM_STACK_SIZE 0x800 -#define FIRMWARE_WELCOME_STR "Booting trusted firmware boot loader stage 1\n\r" +#define FIRMWARE_WELCOME_STR "Booting Trusted Firmware\n" /* Trusted Boot Firmware BL2 */ #define BL2_IMAGE_NAME "bl2.bin"