| Message ID | 20250305015505.14493-1-shijie@os.amperecomputing.com (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | [resend] tracepoint: Print the function symbol when tracepoint_debug is set | expand |
On 2025-03-04 20:55, Huang Shijie wrote: > When tracepoint_debug is set, we may get the output in kernel log: > [ 380.013843] Probe 0 : 00000000f0d68cda > > It is not readable, so change to print the function symbol. > After this patch, the output may becomes: > [ 54.930567] Probe 0 : perf_trace_sched_wakeup_template What would it print if the address is corrupted ? Perhaps we could do like the backtrace code and print e.g. [<00000000f0d68cda>] perf_trace_sched_wakeup_template+0xNN/0xMM ? I don't care about the actual layout, but removing the address from the formatted output appears to be removing useful data in debug situations. Thanks, Mathieu > > Reviewed-by: Christoph Lameter <cl@linux.com> > Signed-off-by: Huang Shijie <shijie@os.amperecomputing.com> > --- > kernel/tracepoint.c | 2 +- > 1 file changed, 1 insertion(+), 1 deletion(-) > > diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c > index 1848ce7e2976..82bef4b9400a 100644 > --- a/kernel/tracepoint.c > +++ b/kernel/tracepoint.c > @@ -127,7 +127,7 @@ static void debug_print_probes(struct tracepoint_func *funcs) > return; > > for (i = 0; funcs[i].func; i++) > - printk(KERN_DEBUG "Probe %d : %p\n", i, funcs[i].func); > + printk(KERN_DEBUG "Probe %d : %ps\n", i, funcs[i].func); > } > > static struct tracepoint_func *
On Wed, 5 Mar 2025 08:53:43 -0500 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote: > On 2025-03-04 20:55, Huang Shijie wrote: > > When tracepoint_debug is set, we may get the output in kernel log: > > [ 380.013843] Probe 0 : 00000000f0d68cda > > > > It is not readable, so change to print the function symbol. > > After this patch, the output may becomes: > > [ 54.930567] Probe 0 : perf_trace_sched_wakeup_template > > What would it print if the address is corrupted ? > > Perhaps we could do like the backtrace code and print e.g. > > [<00000000f0d68cda>] perf_trace_sched_wakeup_template+0xNN/0xMM > > ? > > I don't care about the actual layout, but removing the address > from the formatted output appears to be removing useful data > in debug situations. > Perhaps this can use "%pS" which shows both the function entry and the offset. If no function is found, it ends up being the same as "%p". Also, it's likely that the "%p" is hashed here and one couldn't use it to debug either. -- Steve
On 2025/3/5 23:47, Steven Rostedt wrote: > On Wed, 5 Mar 2025 08:53:43 -0500 > Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote: > >> On 2025-03-04 20:55, Huang Shijie wrote: >>> When tracepoint_debug is set, we may get the output in kernel log: >>> [ 380.013843] Probe 0 : 00000000f0d68cda >>> >>> It is not readable, so change to print the function symbol. >>> After this patch, the output may becomes: >>> [ 54.930567] Probe 0 : perf_trace_sched_wakeup_template >> What would it print if the address is corrupted ? >> >> Perhaps we could do like the backtrace code and print e.g. >> >> [<00000000f0d68cda>] perf_trace_sched_wakeup_template+0xNN/0xMM >> >> ? >> >> I don't care about the actual layout, but removing the address >> from the formatted output appears to be removing useful data >> in debug situations. >> > Perhaps this can use "%pS" which shows both the function entry and the okay, I can change it to use "%pS" in next version if we think it is good enough: [ 55.225555] Probe 0 : perf_trace_sched_wakeup_template+0x0/0x20 Thanks Huang Shijie
On 2025/3/5 21:53, Mathieu Desnoyers wrote: > On 2025-03-04 20:55, Huang Shijie wrote: >> When tracepoint_debug is set, we may get the output in kernel log: >> [ 380.013843] Probe 0 : 00000000f0d68cda >> >> It is not readable, so change to print the function symbol. >> After this patch, the output may becomes: >> [ 54.930567] Probe 0 : perf_trace_sched_wakeup_template > > What would it print if the address is corrupted ? > > Perhaps we could do like the backtrace code and print e.g. > > [<00000000f0d68cda>] perf_trace_sched_wakeup_template+0xNN/0xMM If we want this format, we can change code to: --- kernel/tracepoint.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c index abfd0ac1177f..5a5041f32cc8 100644 --- a/kernel/tracepoint.c +++ b/kernel/tracepoint.c @@ -127,7 +127,8 @@ static void debug_print_probes(struct tracepoint_func *funcs) return; for (i = 0; funcs[i].func; i++) - printk(KERN_DEBUG "Probe %d : %p\n", i, funcs[i].func); + printk(KERN_DEBUG "Probe %d : [ %p ] %pS\n", + i, funcs[i].func, funcs[i].func); } The output will look like: [ 63.818829] Probe 0 : [ 0000000032848d41 ] perf_trace_sched_wakeup_template+0x0/0x20 [ 63.819287] Probe 0 : [ 00000000fe8cca4d ] perf_trace_sched_switch+0x0/0x20 [ 65.325638] Probe 0 : [ 0000000032848d41 ] perf_trace_sched_wakeup_template+0x0/0x20 [ 65.695631] Probe 0 : [ 00000000fe8cca4d ] perf_trace_sched_switch+0x0/0x20 Thanks Huang Shijie
On Thu, 6 Mar 2025 11:37:38 +0800 Shijie Huang <shijie@amperemail.onmicrosoft.com> wrote: > diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c > index abfd0ac1177f..5a5041f32cc8 100644 > --- a/kernel/tracepoint.c > +++ b/kernel/tracepoint.c > @@ -127,7 +127,8 @@ static void debug_print_probes(struct > tracepoint_func *funcs) > return; > > for (i = 0; funcs[i].func; i++) > - printk(KERN_DEBUG "Probe %d : %p\n", i, funcs[i].func); > + printk(KERN_DEBUG "Probe %d : [ %p ] %pS\n", > + i, funcs[i].func, funcs[i].func); > } > > > The output will look like: > > [ 63.818829] Probe 0 : [ 0000000032848d41 ] > perf_trace_sched_wakeup_template+0x0/0x20 > [ 63.819287] Probe 0 : [ 00000000fe8cca4d ] > perf_trace_sched_switch+0x0/0x20 > [ 65.325638] Probe 0 : [ 0000000032848d41 ] > perf_trace_sched_wakeup_template+0x0/0x20 > [ 65.695631] Probe 0 : [ 00000000fe8cca4d ] > perf_trace_sched_switch+0x0/0x20 I'm fine either way. Mathieu, what's your preference? Although the above shows a hashed %p. Is that even useful? -- Steve
On 2025-03-06 10:13, Steven Rostedt wrote: > On Thu, 6 Mar 2025 11:37:38 +0800 > Shijie Huang <shijie@amperemail.onmicrosoft.com> wrote: > >> diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c >> index abfd0ac1177f..5a5041f32cc8 100644 >> --- a/kernel/tracepoint.c >> +++ b/kernel/tracepoint.c >> @@ -127,7 +127,8 @@ static void debug_print_probes(struct >> tracepoint_func *funcs) >> return; >> >> for (i = 0; funcs[i].func; i++) >> - printk(KERN_DEBUG "Probe %d : %p\n", i, funcs[i].func); >> + printk(KERN_DEBUG "Probe %d : [ %p ] %pS\n", >> + i, funcs[i].func, funcs[i].func); >> } >> >> >> The output will look like: >> >> [ 63.818829] Probe 0 : [ 0000000032848d41 ] >> perf_trace_sched_wakeup_template+0x0/0x20 >> [ 63.819287] Probe 0 : [ 00000000fe8cca4d ] >> perf_trace_sched_switch+0x0/0x20 >> [ 65.325638] Probe 0 : [ 0000000032848d41 ] >> perf_trace_sched_wakeup_template+0x0/0x20 >> [ 65.695631] Probe 0 : [ 00000000fe8cca4d ] >> perf_trace_sched_switch+0x0/0x20 > > I'm fine either way. Mathieu, what's your preference? > > Although the above shows a hashed %p. Is that even useful? The hashed %p is not really useful. I think we could just print %Sb e.g. from core-api/printk-formats.rst: %pSb versatile_init+0x0/0x110 [module_name ed5019fdf5e53be37cb1ba7899292d7e143b259e] AFAIU, when the kallsyms_lookup_buildid fails, it prints the raw address instead (see __sprint_symbol). Thanks, Mathieu
On 2025/3/7 0:37, Mathieu Desnoyers wrote: > > I think we could just print %Sb > > e.g. from core-api/printk-formats.rst: > > %pSb versatile_init+0x0/0x110 [module_name > ed5019fdf5e53be37cb1ba7899292d7e143b259e] > > AFAIU, when the kallsyms_lookup_buildid fails, it prints the raw > address instead > (see __sprint_symbol). okay, I will use "%pSb" in version v2 later. Thanks Huang Shijie
diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c index 1848ce7e2976..82bef4b9400a 100644 --- a/kernel/tracepoint.c +++ b/kernel/tracepoint.c @@ -127,7 +127,7 @@ static void debug_print_probes(struct tracepoint_func *funcs) return; for (i = 0; funcs[i].func; i++) - printk(KERN_DEBUG "Probe %d : %p\n", i, funcs[i].func); + printk(KERN_DEBUG "Probe %d : %ps\n", i, funcs[i].func); } static struct tracepoint_func *
When tracepoint_debug is set, we may get the output in kernel log: [ 380.013843] Probe 0 : 00000000f0d68cda It is not readable, so change to print the function symbol. After this patch, the output may becomes: [ 54.930567] Probe 0 : perf_trace_sched_wakeup_template Reviewed-by: Christoph Lameter <cl@linux.com> Signed-off-by: Huang Shijie <shijie@os.amperecomputing.com> --- kernel/tracepoint.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)