Hi Jonas,
On Sat, 3 Aug 2024 at 06:42, Jonas Karlman <jo...@kwiboo.se> wrote:
>
> The timer counter on Rockchip SoCs may be reset in TF-A, this may cause
> the bootstage records to be printed out of order and with an incorrect
> elapsed time.
Eek can we just fix TF-A? That seems like a bug.
>
> Fix this by not sorting the bootstage records.
>
> Before on a Radxa ZERO 3W (RK3566) board:
>
> => bootstage report
> Timer summary in microseconds (12 records):
> Mark Elapsed Stage
> 0 0 reset
> 7,436 7,436 board_init_f
> 164,826 157,390 SPL
> 375,392 210,566 end phase
> 423,909 48,517 board_init_r
> 472,973 49,064 eth_common_init
> 476,848 3,875 main_loop
> 477,003 155 cli_loop
>
> Accumulated time:
> 7,181 of_live
> 14,739 dm_spl
> 15,029 dm_r
> 315,150 dm_f
>
> With this the records can be printed in chronological order when the
> counter is reset and SPL and board_init_r records show correct elapsed
> time.
>
> => bootstage report
> Timer summary in microseconds (12 records):
> Mark Elapsed Stage
> 0 0 reset
> 164,437 164,437 SPL
> 375,023 210,586 end phase
> 7,437 7,437 board_init_f
> 424,390 416,953 board_init_r
> 473,515 49,125 eth_common_init
> 477,402 3,887 main_loop
> 477,571 169 cli_loop
>
> Accumulated time:
> 14,734 dm_spl
> 315,646 dm_f
> 7,339 of_live
> 14,977 dm_r
>
> For the tested board external TPL and BROM take ~164 ms to initialize
> DRAM and load SPL, SPL take ~210ms to load images from FIT and U-Boot
> proper take ~477ms to reach cli prompt.
>
> Signed-off-by: Jonas Karlman <jo...@kwiboo.se>
> ---
> common/bootstage.c | 12 ++----------
> 1 file changed, 2 insertions(+), 10 deletions(-)
>
> diff --git a/common/bootstage.c b/common/bootstage.c
> index 49acc9078a6d..80168e965b12 100644
> --- a/common/bootstage.c
> +++ b/common/bootstage.c
> @@ -249,6 +249,8 @@ static uint32_t print_time_record(struct bootstage_record
> *rec, uint32_t prev)
> printf("%11s", "");
> print_grouped_ull(rec->time_us, BOOTSTAGE_DIGITS);
> } else {
> + if (prev > rec->time_us)
> + prev = 0;
> print_grouped_ull(rec->time_us, BOOTSTAGE_DIGITS);
> print_grouped_ull(rec->time_us - prev, BOOTSTAGE_DIGITS);
> }
> @@ -257,13 +259,6 @@ static uint32_t print_time_record(struct
> bootstage_record *rec, uint32_t prev)
> return rec->time_us;
> }
>
> -static int h_compare_record(const void *r1, const void *r2)
> -{
> - const struct bootstage_record *rec1 = r1, *rec2 = r2;
> -
> - return rec1->time_us > rec2->time_us ? 1 : -1;
> -}
> -
> #ifdef CONFIG_OF_LIBFDT
> /**
> * Add all bootstage timings to a device tree.
> @@ -342,9 +337,6 @@ void bootstage_report(void)
>
> prev = print_time_record(rec, 0);
>
> - /* Sort records by increasing time */
> - qsort(data->record, data->rec_count, sizeof(*rec), h_compare_record);
> -
> for (i = 1, rec++; i < data->rec_count; i++, rec++) {
> if (rec->id && !rec->start_us)
> prev = print_time_record(rec, prev);
> --
> 2.45.2
>
Regards,
SImon
