Received-SPF: pass (google.com: domain of linux-kernel+bounces-49238-linux.lists.archive=gmail.com@vger.kernel.org designates 139.178.88.99 as permitted sender) client-ip=139.178.88.99;
Date: Fri, 2 Feb 2024 15:04:03 +0900
From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
To: Ahmad Fatoum <a.fatoum@pengutronix.de>
Cc: linux-trace-kernel@vger.kernel.org, "linux-kernel@vger.kernel.org"
 <linux-kernel@vger.kernel.org>, Pengutronix Kernel Team
 <kernel@pengutronix.de>
Subject: Re: Boot-time dumping of ftrace fuctiongraph buffer
Message-Id: <20240202150403.7ccc4126dbeaad8bdf77c384@kernel.org>
In-Reply-To: <d33e5271-219d-4b8e-be5a-8903219d7fd6@pengutronix.de>
References: <d33e5271-219d-4b8e-be5a-8903219d7fd6@pengutronix.de>
Precedence: bulk
Mime-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit

Hi Ahmad,

On Thu, 1 Feb 2024 13:21:37 +0100
Ahmad Fatoum <a.fatoum@pengutronix.de> wrote:

> Hello,
> 
> I semi-regularly debug probe failures. For drivers that use dev_err_probe
> rigorously, this is a quick matter: The probe function records a deferral reason
> and if the deferral persists, deferred_probe_timeout_work_func() will print
> the collected reasons, even if PID 1 is never started.
> 
> For drivers that don't call dev_err_probe, I find myself sometimes doing printf
> debugging inside the probe function.
> 
> I would like to replace this with the function graph tracer:
> 
>   - record the probe function, configured over kernel command line
>     (The device indefinitely deferring probe is printed to the console,
>      so I know what I am looking for on the next boot)
> 
>   - Dump the function graph trace
> 
>   - See if the last call before (non-devm) cleanup is getting a clock, a GPIO,
>     a regulator or w/e.

What kind of information you prints by the printk()?
If the target (suspicious driver probe function) is obvious, you can use kprobe
event and tp_printk. Or, even if you don't know, if you are sure which function
is the starting/ending point, you can use bootconfig to record the specific part
of execution in the ring buffer, and dump it as Steve said.

In Documentation/trace/boottime-trace.rst, there is an example.
-----
With the trigger action and kprobes, you can trace function-graph while
a function is called. For example, this will trace all function calls in
the pci_proc_init()::

  ftrace {
        tracing_on = 0
        tracer = function_graph
        event.kprobes {
                start_event {
                        probes = "pci_proc_init"
                        actions = "traceon"
                }
                end_event {
                        probes = "pci_proc_init%return"
                        actions = "traceoff"
                }
        }
  }
-----

Thank you,

> 
> For this to be maximally useful, I need to configure this not only at boot-time,
> but also dump the ftrace buffer at boot time. Probe deferral can hinder the kernel from
> calling init and providing a shell, where I could read /sys/kernel/tracing/trace.
> 
> I found following two mechanisms that looked relevant, but seem not to
> do exactly what I want:
> 
>   - tp_printk: seems to be related to trace points only and not usable
>     for the function graph output
> 
>   - dump_on_oops: I don't get an Oops if probe deferral times out, but maybe
>     one could patch the kernel to check a oops_on_probe_deferral or dump_on_probe_deferral
>     kernel command line parameter in deferred_probe_timeout_work_func()?
> 
> 
> Is there existing support that I am missing? Any input on whether this
> would be a welcome feature to have?
> 
> Thanks!
> 
> Cheers,
> Ahmad
>     
> -- 
> Pengutronix e.K.                           |                             |
> Steuerwalder Str. 21                       | http://www.pengutronix.de/  |
> 31137 Hildesheim, Germany                  | Phone: +49-5121-206917-0    |
> Amtsgericht Hildesheim, HRA 2686           | Fax:   +49-5121-206917-5555 |
>  


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>