[PATCH 2/2] bootstage: Do not sort records

[Tom Rini]

On Wed, Aug 28, 2024 at 06:15:32PM +0200, Jonas Karlman wrote:
> Hi Simon,
> 
> On 2024-08-28 18:01, Simon Glass wrote:
> > Hi Jonas,
> > 
> > On Tue, 6 Aug 2024 at 15:50, Simon Glass <sjg at chromium.org> wrote:
> >>
> >> Hi Jonas,
> >>
> >> On Sat, 3 Aug 2024 at 06:42, Jonas Karlman <jonas at 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.
> 
> TF-A is vendor blob, so we have no control of it.
> 
> >>
> >>>
> >>> 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 <jonas at kwiboo.se>
> >>> ---
> >>>  common/bootstage.c | 12 ++----------
> >>>  1 file changed, 2 insertions(+), 10 deletions(-)
> >>>
> > 
> > To put this more strongly, this breaks the timing output on other boards.
> 
> Please elaborate, I cannot understand why not sorting would break output
> on other boards, are other boards adding records out of order?
> 
> Do you have an example of how this change break other boards?
> 
> > 
> > At the very least, this should be Kconfig option just enabled for
> > boards with a broken ATF.
> 
> I can add a Kconfig option, but would like to understand why other/any
> board would need to sort the records in the first place.

This got me to re-check everything and see I hadn't finished configuring
bootstage for pytest for Pi in my lab. And when building with:
CONFIG_BOOTSTAGE_STASH_ADDR=0x02400000
CONFIG_BOOTSTAGE=y
CONFIG_BOOTSTAGE_STASH=y
CONFIG_CMD_BOOTSTAGE=y

And this in the boardenv py file:

env__bootstage_cmd_file = {
    'addr': 0x2400000,
    'size': 0x1000,
    'bootstage_magic_addr': 0xb00757a3,
}

All three tests pass, with both parts of the series applied. Of course
Pi is not a great example as there's not TF-A in the loop here and
that's part of the problem equation.

And also, JFYI:
=============================== warnings summary ===============================
tests/test_bootstage.py::test_bootstage_stash
  /home/trini/labgrid-venv/lib/python3.11/site-packages/_pytest/python.py:163: PytestReturnNotNoneWarning: Expected None, but tests/test_bootstage.py::test_bootstage_stash returned (37748736, 4096), which will be an error in a future version of pytest.  Did you mean to use `assert` instead of `return`?
    warnings.warn(

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html

-- 
Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 659 bytes
Desc: not available
URL: <https://lists.denx.de/pipermail/u-boot/attachments/20240828/642d3466/attachment.sig>