Dear Steven,
Thank you for your quick response. Am 11.05.20 um 20:58 schrieb Steven Rostedt:
On Sat, 9 May 2020 12:16:30 +0200 Paul Menzel wrote:
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?Did it every work for modules? radeon_init() isn't in the symbol table at boot up. [ 15.066951] systemd-journald[124]: Successfully sent stream file descriptor to service manager. [ 15.098265] hub 1-0:1.0: USB hub found [ 15.104006] systemd-journald[124]: Successfully sent stream file descriptor to service manager. [ 15.112965] hub 1-0:1.0: 2 ports detected [ 15.118116] probe of 1-0:1.0 returned 1 after 19873 usecs [ 15.124007] calling radeon_init+0x0/0x1000 [radeon] @ 133 The radeon_init is called after systemd is running, so it is definitely from a module. Perhaps you had it built in before?
You are right. Probably I did. Can you suggest how to set up ftrace to trace a module?
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(); […] ```Probably because the filtering failed, so there is no filter.
Is that the intended behavior? Or should nothing be traced? Kind regards, Paul

