lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:   Sat, 9 May 2020 12:16:30 +0200
From:   Paul Menzel <pmenzel@...gen.mpg.de>
To:     Steven Rostedt <rostedt@...dmis.org>,
        Ingo Molnar <mingo@...nel.org>
Cc:     linux-kernel@...r.kernel.org
Subject: ftrace: function radeon_init not traceable

Dear Linux folks,


Linux master and Linux 5.6.7 (from Debian Sid/unstable) are used.

Instrumenting Linux’ start-up time, I’d like to trace the init function 
of the Radeon graphics driver `radeon_init()` (built as a module).

     drivers/gpu/drm/radeon/radeon_drv.c:static int __init radeon_init(void)
     drivers/gpu/drm/radeon/radeon_drv.c:module_init(radeon_init);

With `initcall_debug` I can see:

     [    1.079920] calling  radeon_init+0x0/0x1000 [radeon] @ 138
     [    1.663200] initcall radeon_init+0x0/0x1000 [radeon] returned 0 
after 129346 usecs

With `function_graph` as the trace, I am adding the string below to the 
Linux kernel CLI.

     initcall_debug log_buf_len=32M trace_buf_size=57074K 
trace_clock=global 
trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,funcgraph-duration,funcgraph-proc,funcgraph-tail,nofuncgraph-overhead,context-info,graph-time 
ftrace=function_graph ftrace_graph_max_depth=1 
ftrace_graph_filter=radeon_init

But ftrace “rejects” that:

     [    0.075538] ftrace: allocating 30958 entries in 61 pages
     [    0.084542] ftrace: allocated 61 pages with 5 groups
     [    0.094184] ftrace: function radeon_init not traceable

I believe it worked in the past. Is there a way to trace that init function?

Despite the function not being traceable, the trace file is still 
filled. I’d would have expected to be empty.

```
# tracer: function_graph
#
#     TIME        CPU  TASK/PID         DURATION 
FUNCTION CALLS
#      |          |     |    |           |   |                     |   | 
   |   |
     2.910887 |   0)    <idle>-0    |   2.662 us    |  local_touch_nmi();
     2.910888 |   0)    <idle>-0    |   0.497 us    |  local_touch_nmi();
     2.910888 |   0)    <idle>-0    |   0.346 us    |  local_touch_nmi();
     2.910888 |   1)   systemd-1    |   1.440 us    |  __text_poke();
     2.910888 |   1)   systemd-1    |   0.588 us    |  __text_poke();
     2.910888 |   1)   systemd-1    |   0.556 us    |  __text_poke();
     2.910888 |   1)   systemd-1    |   0.489 us    |  __text_poke();
[…]
     2.910889 |   1)   systemd-1    |   0.530 us    |  __text_poke();
     2.910889 |   0)    <idle>-0    |   0.473 us    |  do_sync_core();
     2.910889 |   1)   systemd-1    |   0.572 us    |  do_sync_core();
     2.910889 |   0)    <idle>-0    |   0.365 us    | 
arch_cpu_idle_enter();
     2.910889 |   1)   systemd-1    |   0.830 us    |  __text_poke();
     2.910889 |   0)    <idle>-0    | ! 278.143 us  |  arch_cpu_idle();
     2.910889 |   1)   systemd-1    |   0.582 us    |  __text_poke();
[…]
```


Kind regards,

Paul

View attachment "20200509-linux-5.7-rc4-with-prints.txt" of type "text/plain" (172037 bytes)

Powered by blists - more mailing lists