On Fri, 6 Dec 2024 at 03:11, Jerome Forissier
<jerome.foriss...@linaro.org> wrote:
>
> When converting a U-Boot trace records file to ftrace function graph
> format for use by trace-cmd ('proftool -f funcgraph dump-ftrace'), the
> time associated to each function is incorrectly saved in microseconds
> instead of nanoseconds. Multuply the value by 1000 to fix the issue.
>
> With this change, the trace-cmd output looks consistent. Here is an
> example with udelay(25) added to mem_malloc_init() as a test case:
>
> $ ./tools/proftool -m System.map -t /tmp/trace.bin -f funcgraph \
> dump-ftrace -o /tmp/trace.dat
> $ trace-cmd report /tmp/trace.dat >/tmp/trace.log
> $ vi /tmp/trace.log
> [...]
> u-boot-1 [000] 6.719659: funcgraph_entry: |
> mem_malloc_init() {
> u-boot-1 [000] 6.719659: funcgraph_entry: |
> udelay() {
> u-boot-1 [000] 6.719660: funcgraph_entry: |
> schedule() {
> u-boot-1 [000] 6.719660: funcgraph_entry: |
> cyclic_run() {
> u-boot-1 [000] 6.719660: funcgraph_entry: 1.000 us |
> cyclic_get_list();
> u-boot-1 [000] 6.719661: funcgraph_exit: 1.000 us |
> }
> u-boot-1 [000] 6.719661: funcgraph_exit: 1.000 us |
> }
> u-boot-1 [000] 6.719661: funcgraph_entry: |
> __udelay() {
> u-boot-1 [000] 6.719662: funcgraph_entry: 0.000 us |
> usec_to_tick();
> u-boot-1 [000] 6.719687: funcgraph_exit: + 26.000 us |
> }
> u-boot-1 [000] 6.719687: funcgraph_exit: + 28.000 us |
> }
> u-boot-1 [000] 6.719687: funcgraph_entry: # 37971.000 us |
> memset();
> u-boot-1 [000] 6.757658: funcgraph_exit: # 37999.000 us |
> }
> u-boot-1 [000] 6.757658: funcgraph_exit: # 38000.000 us | }
>
> In the above dump, the udelay() call is reported as taking 26 us which
> is consistent with the timestamps (6.719687 - 6.719659 = 0.000026).
> Without this patch we would have "0.026 us" instead of "+ 26.000 us".
>
> Signed-off-by: Jerome Forissier <jerome.foriss...@linaro.org>
> ---
> tools/proftool.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
Reviewed-by: Simon Glass <s...@chromium.org>
