diff --git a/bl1/bl1_main.c b/bl1/bl1_main.c index c6f2caa..a5bd648 100644 --- a/bl1/bl1_main.c +++ b/bl1/bl1_main.c @@ -106,6 +106,13 @@ ******************************************************************************/ 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 @@ /* 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 @@ * 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 @@ 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 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 ca83842..51c55e0 100644 --- a/bl2/bl2_main.c +++ b/bl2/bl2_main.c @@ -59,6 +59,7 @@ * 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 @@ 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 @@ #ifdef BL32_BASE meminfo_t bl32_mem_info; + INFO("BL2: Loading BL3-2\n"); assert(bl2_to_bl31_params != NULL); /* @@ -160,6 +163,7 @@ 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 @@ 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 68bdd36..19f3774 100644 --- a/bl31/bl31_main.c +++ b/bl31/bl31_main.c @@ -71,19 +71,20 @@ ******************************************************************************/ 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 @@ /* * 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 @@ 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 c1c9aad..65c581f 100644 --- a/bl32/tsp/tsp_interrupt.c +++ b/bl32/tsp/tsp_interrupt.c @@ -55,14 +55,16 @@ 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 @@ /* 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 @@ 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 b2850e9..982bab2 100644 --- a/bl32/tsp/tsp_main.c +++ b/bl32/tsp/tsp_main.c @@ -105,6 +105,12 @@ ******************************************************************************/ 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 @@ 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_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_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_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_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 @@ 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 d2c60ef..60f8b2f 100644 --- a/common/bl_common.c +++ b/common/bl_common.c @@ -137,7 +137,7 @@ 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 @@ 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 7df229d..4262a9d 100644 --- a/drivers/io/io_fip.c +++ b/drivers/io/io_fip.c @@ -215,7 +215,7 @@ 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 2ef3bee..862bf9c 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 c614854..90a1afe 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 b146fdb..85b4c47 100644 --- a/plat/fvp/bl1_fvp_setup.c +++ b/plat/fvp/bl1_fvp_setup.c @@ -87,9 +87,6 @@ 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 c32cca9..1f695a6 100644 --- a/plat/fvp/fvp_io_storage.c +++ b/plat/fvp/fvp_io_storage.c @@ -127,7 +127,7 @@ /* 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 @@ 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 @@ 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 70f84bb..028f154 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"