On 9/8/23 15:34, Tom Rini wrote:
On Fri, Sep 08, 2023 at 12:24:10PM +0200, Michal Simek wrote:


On 9/7/23 20:14, Tom Rini wrote:
On Thu, Sep 07, 2023 at 05:30:03PM +0200, Michal Simek wrote:
Hi Simon and Tom,

I am preparing pull request and I see that CI loop is reporting issue with
sandbox trace and I have no idea what's going wrong here.

This is the first problematic commit but have no clue what it has to do with 
trace.

https://source.denx.de/u-boot/custodians/u-boot-microblaze/-/commit/8c5f80d11b29536979ac41a6087fb8938f45bbf2

If you have an access you can take a look at my queue to see that only this
job is failing.
https://source.denx.de/u-boot/custodians/u-boot-microblaze/-/pipelines

Thanks,
Michal

collected 1152 items / 1151 deselected / 1 selected
test/py/tests/test_trace.py F                                            [100%]
=================================== FAILURES ===================================
__________________________________ test_trace __________________________________
test/py/tests/test_trace.py:292: in test_trace
      check_function(cons, fname, proftool, map_fname, trace_dat)
test/py/tests/test_trace.py:117: in check_function
      out = util.run_and_log(cons, ['sh', '-c', cmd])
test/py/u_boot_utils.py:181: in run_and_log
      output = runner.run(cmd, ignore_errors=ignore_errors, stdin=stdin, 
env=env)
test/py/multiplexed_log.py:183: in run
      raise exception
E   ValueError: Exit code: 1
---------------------------- Captured stdout setup -----------------------------
/u-boot
trace: early enable at 00100000
sandbox_serial serial: pinctrl_select_state_full:
uclass_get_device_by_phandle_id: err=-19
=>

I don't get it either since I see this on master with trace options
enabled per CI:
$ ./u-boot -T arch/sandbox/dts/test.dtb
trace: early enable at 00100000
sandbox_serial serial: pinctrl_select_state_full: 
uclass_get_device_by_phandle_id: err=-19
... rest of boot proceeds ...

So the test should be failing already if that was the problem.


I don't thin it is the problematic part.

When I look at
https://source.denx.de/u-boot/u-boot/-/blob/master/tools/docker/Dockerfile?ref_type=heads#L225

clone is done from
git clone https://github.com/rostedt/trace-cmd.git /tmp/trace/trace-cmd && \

https://github.com/rostedt/trace-cmd/blob/master/README#L5

we should be using
git://git.kernel.org/pub/scm/utils/trace-cmd/trace-cmd.git instead.

I installed the latest version on my PC and run it via pytest and this is
what I am getting.
You see that trace-cmd report is returning "failed to init data".

Are we wired to any specific trace-cmd version?

Wait, no, what's going on exactly? The github repository is a mirror of
the kernel.org one. So yes, we should correct to point to the main one,
but the top of tree in both cases is commit
354dccca52e805ce1b22e2b62cbae8c265886c27.


I dig into it more.
What it is happening is that when sandbox u-boot is bigger trace.dat file is
placing information to different offset then it is recorded somewhere in header.

Wrong placement

0005b000  20 70 65 72 66 20 6d 6f  6e 6f 20 6d 6f 6e 6f 5f  | perf mono mono_|
0005b010  72 61 77 20 62 6f 6f 74  20 78 38 36 2d 74 73 63  |raw boot x86-tsc|
0005b020  0a 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
0005b030  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
*
0005c000  89 df f6 1d 00 00 00 00  dc 0f 00 00 00 00 00 00  |................|
0005c010  06 00 00 00 01 00 00 00  01 00 00 00 af e5 0a 00  |................|
0005c020  00 00 00 00 ef dc 09 00  00 00 00 00 06 00 00 00  |................|
0005c030  01 00 00 00 01 00 00 00  af e5 0a 00 00 00 00 00  |................|

Correct placement for trace-cmd

0005aee0  75 70 74 69 6d 65 20 70  65 72 66 20 6d 6f 6e 6f  |uptime perf mono|
0005aef0  20 6d 6f 6e 6f 5f 72 61  77 20 62 6f 6f 74 20 78  | mono_raw boot x|
0005af00  38 36 2d 74 73 63 0a 00  00 00 00 00 00 00 00 00  |86-tsc..........|
0005af10  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
*
0005b000  36 f8 92 3f 00 00 00 00  e0 0f 00 00 00 00 00 00  |6..?............|

And trace-cmd want to decode data available at 0x5b000 offset in both cases.

It means I expect proftool is not correctly generating offset where data is present. I don't understand how it works but I clearly see based on trace-cmd that it points to incorrect location.

Thanks,
Michal
--
Michal Simek, Ing. (M.Eng), OpenPGP -> KeyID: FE3D1F91
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel - Xilinx Microblaze
Maintainer of Linux kernel - Xilinx Zynq ARM and ZynqMP/Versal ARM64 SoCs
U-Boot custodian - Xilinx Microblaze/Zynq/ZynqMP/Versal/Versal NET SoCs
TF-A maintainer - Xilinx ZynqMP/Versal/Versal NET SoCs

Reply via email to