diff --git a/chip/lm4/keyboard_scan.c b/chip/lm4/keyboard_scan.c index 3729a304f5..2966713768 100644 --- a/chip/lm4/keyboard_scan.c +++ b/chip/lm4/keyboard_scan.c @@ -160,7 +160,7 @@ static uint32_t clear_matrix_interrupt_status(void) { static void wait_for_interrupt(void) { - uart_printf("[kbscan %s()]\n", __func__); + uart_puts("[KB wait]\n"); /* Assert all outputs would trigger un-wanted interrupts. * Clear them before enable interrupt. */ @@ -175,7 +175,7 @@ static void wait_for_interrupt(void) static void enter_polling_mode(void) { - uart_printf("[kbscan %s()]\n", __func__); + uart_puts("[KB poll]\n"); LM4_GPIO_IM(KB_SCAN_ROW_GPIO) = 0; /* 0: disable interrupt */ select_column(COLUMN_TRI_STATE_ALL); } @@ -210,7 +210,7 @@ static void print_raw_state(const char *msg) { int c; - uart_printf("[%s:", msg); + uart_printf("[KB %s:", msg); for (c = 0; c < KB_COLS; c++) { if (raw_state[c]) uart_printf(" %02x", raw_state[c]); @@ -279,7 +279,7 @@ static int check_keys_changed(void) } if (change) - print_raw_state("KB raw state"); + print_raw_state("raw state"); out: /* Count number of key pressed */ @@ -370,7 +370,7 @@ void keyboard_scan_task(void) { int key_press_timer = 0; - print_raw_state("KB init state"); + print_raw_state("init state"); if (recovery_key_pressed) uart_puts("[KB recovery key pressed at init!]\n"); diff --git a/chip/lm4/watchdog.c b/chip/lm4/watchdog.c index ccc6e63b72..5a3080dcdb 100644 --- a/chip/lm4/watchdog.c +++ b/chip/lm4/watchdog.c @@ -141,6 +141,11 @@ int watchdog_init(int period_ms) /* Low priority task to reload the watchdog */ void watchdog_task(void) { + /* Print when the watchdog task starts. This is the lowest priority + * task, so this only starts once all other tasks have gotten a chance + * to do their task inits and have gone to sleep. */ + uart_printf("[watchdog task started at %d us]\n", get_time().le.lo); + while (1) { #ifdef BOARD_bds gpio_set_level(GPIO_DEBUG_LED, 1); diff --git a/chip/stm32l/watchdog.c b/chip/stm32l/watchdog.c index 4a1cd7f6d2..9d66ea75b7 100644 --- a/chip/stm32l/watchdog.c +++ b/chip/stm32l/watchdog.c @@ -58,6 +58,11 @@ int watchdog_init(int period_ms) /* Low priority task to reload the watchdog */ void watchdog_task(void) { + /* Print when the watchdog task starts. This is the lowest priority + * task, so this only starts once all other tasks have gotten a chance + * to do their task inits and have gone to sleep. */ + uart_printf("[watchdog task started at %d us]\n", get_time().le.lo); + while (1) { #ifdef BOARD_discovery gpio_set_level(GPIO_GREEN_LED, 1); diff --git a/common/charge_state.c b/common/charge_state.c index fb2e565025..088f43669f 100644 --- a/common/charge_state.c +++ b/common/charge_state.c @@ -308,25 +308,17 @@ static enum power_state state_error(void) /* Debug output */ if (error_flags != last_error_flags) { - uart_printf("errors : %02x\n", error_flags); - uart_printf("previous : %02x\n", last_error_flags); - last_error_flags = error_flags; - uart_printf("ac : %d\n", ac); - uart_puts("charger\n"); - if (ac) - if (error_flags & (F_CHG_V | F_CHG_I)) - uart_puts(" error\n"); - else - uart_puts(" ok\n"); - else - uart_puts(" offline\n"); + uart_printf("[Charge error flags %02x -> %02x; AC=%d", + last_error_flags, error_flags, ac); - uart_puts("battery\n"); - uart_printf(" voltage: %5d\n", bat_v); - uart_printf(" current: %5d\n", bat_i); - uart_printf(" temp : %5d\n", (bat_temp - 2731) / 10); - uart_printf(" des_vol: %5d\n", desired_v); - uart_printf(" des_cur: %5d\n", desired_i); + if (error_flags & (F_CHG_V | F_CHG_I)) + uart_puts(", charger error"); + + uart_printf(", battery V=%d I=%d T=%d Vwant=%d Iwant=%d]\n", + bat_v, bat_i, (bat_temp - 2731) / 10, + desired_v, desired_i); + + last_error_flags = error_flags; } *memmap_batt_flags = batt_flags; @@ -392,7 +384,7 @@ void charge_state_machine_task(void) } if (new_state) - uart_printf("CHARGE: %s --> %s\n", + uart_printf("[Charge state %s -> %s]\n", _state_name[current_state], _state_name[new_state]); diff --git a/common/main.c b/common/main.c index 887312f6e5..50c5b6d63d 100644 --- a/common/main.c +++ b/common/main.c @@ -45,8 +45,11 @@ int main(void) * source we need to calibrate the internal oscillator. */ system_pre_init(); - /* Set the CPU clocks / PLLs */ + /* Set the CPU clocks / PLLs and timer */ clock_init(); + timer_init(); + /* The timer used by get_time() is now started, so everything after + * this can be benchmarked. */ /* Do system, gpio, and vboot pre-initialization so we can jump to * another image if necessary. This must be done as early as @@ -60,7 +63,6 @@ int main(void) #ifdef CONFIG_TASK_WATCHDOG watchdog_init(1100); #endif - timer_init(); uart_init(); system_init(); #ifdef CONFIG_TASK_KEYSCAN @@ -94,8 +96,11 @@ int main(void) peci_init(); #endif - /* Print the reset cause */ - uart_printf("\n\n--- Chrome EC initialized! ---\n"); + /* Print the init time and reset cause. Init time isn't completely + * accurate because it can't take into account the time for the first + * few module inits, but it'll at least catch the majority of them. */ + uart_printf("\n\n--- Chrome EC initialized in %d us ---\n", + get_time().le.lo); uart_printf("build: %s\n", system_get_build_info()); uart_printf("(image: %s, last reset: %s)\n", system_get_image_copy_string(),