Re: [PATCH] ftrace: Show timings of how long nop patching took

[Christophe Leroy <christophe.leroy@csgroup.eu>]

Le 02/12/2024 à 21:05, Steven Rostedt a écrit :
> On Mon, 2 Dec 2024 08:37:19 +0200
> Mike Rapoport <rppt@kernel.org> wrote:
> 
>>>> On powerpc I get:
>>>>
>>>> 25850 pages:14 groups: 3
>>>> ftrace boot update time = 0 (ns)
>>>> ftrace module total update time = 0 (ns)
>>>
>>> Hmm, does powerpc support "trace_clock_local()" at early boot? I
>>> probably can just switch from using "ftrace_now()" to using
>>> ktime_get_real_ts64(). Hmm.
>>
>> The calls to timekeeping_init() and time_init() are after ftrace_init() so
>> unless an architecture sets up some clock in setup_arch() like x86 does
>> there won't be a clock to use.
> 
> Hmm, maybe I should add:
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index be62f0ea1814..362a125d7bcc 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -8588,14 +8588,23 @@ tracing_read_dyn_info(struct file *filp, char __user *ubuf,
>   		return -ENOMEM;
>   
>   	r = scnprintf(buf, DYN_INFO_BUF_SIZE,
> -		      "%ld pages:%ld groups: %ld\n"
> -		      "ftrace boot update time = %llu (ns)\n"
> -		      "ftrace module total update time = %llu (ns)\n",
> +		      "%ld pages:%ld groups: %ld\n",
>   		      ftrace_update_tot_cnt,
>   		      ftrace_number_of_pages,
> -		      ftrace_number_of_groups,
> -		      ftrace_update_time,
> -		      ftrace_total_mod_time);
> +		      ftrace_number_of_groups);
> +
> +	if (ftrace_update_time) {
> +		r += scnprintf(buf + r, DYN_INFO_BUF_SIZE - r,
> +			       "ftrace boot update time = %llu (ns)\n",
> +			       ftrace_update_time);
> +	} else {
> +		r += scnprintf(buf + r, DYN_INFO_BUF_SIZE - r,
> +			       "ftrace boot update time = [Unavailable]\n");
> +	}
> +
> +	r += scnprintf(buf + r, DYN_INFO_BUF_SIZE - r,
> +		       "ftrace module total update time = %llu (ns)\n",
> +		       ftrace_total_mod_time);
>   
>   	ret = simple_read_from_buffer(ubuf, cnt, ppos, buf, r);
>   	kfree(buf);
> 
> Which should turn the above to:
> 
>    25850 pages:14 groups: 3
>    ftrace boot update time = [Unavailable]
>    ftrace module total update time = 0 (ns)
> 
> Which should at least make it not confusing.

Well. Maybe, but at the end what we need is the measured value, if it 
only works on x86 it is just pointless, isn't it ?

trace_clock_local() calls sched_clock()

I don't know about other architectures, but on powerpc sched_clock() is:

	notrace unsigned long long sched_clock(void)
	{
		return mulhdu(get_tb() - boot_tb, tb_to_ns_scale) << tb_to_ns_shift;
	}

boot_tb, tb_to_ns_scale and tb_to_ns_shift are not known before 
time_init() is called.

But get_tb() returns a valid value already so it is possible to get the 
ticks and do the calculation later with tb_to_ns()


> 
> I'm assuming that the module timings are zero because no modules were loaded?

Indeed I don't even have CONFIG_MODULES, maybe the complete line should 
be removed in that case.

Christophe