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 <s...@chromium.org> wrote: > >> > >> 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. > > 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 <jo...@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
signature.asc
Description: PGP signature