Re: [PATCH RFC 2/2] arch: m68k: Add STACKTRACE support
From: Jean-Michel Hautbois
Date: Tue Dec 03 2024 - 01:26:08 EST
Hi Greg,
On 03/12/2024 00:01, Greg Ungerer wrote:
Hi JM,
On 3/12/24 00:52, Jean-Michel Hautbois wrote:
On 02/12/2024 15:41, Greg Ungerer wrote:
On 27/11/24 21:26, Jean-Michel Hautbois wrote:
On 21/10/2024 11:44, Jean-Michel Hautbois wrote:
In order to use tracing, implement a basic arch_stack_walk() based on
the one in PowerPC.
Tested on a M54418 coldfire.
Well, I said it was tested, but it was only compile tested basically.
AFAICT now, I think it is not working as when I use wakeup_rt as a
tracer, I don't have the stack trace:
# wakeup_rt latency trace v1.1.5 on 6.12.0-10380-gb66f06337b66-dirty
# --------------------------------------------------------------------
# latency: 2000 us, #18/18, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
# -----------------
# | task: irq/100-enet-fe-118 (uid:0 nice:0 policy:1 rt_prio:50)
# -----------------
#
# _------=> CPU#
# / _-----=> irqs-off/BH-disabled
# | / _----=> need-resched
# || / _---=> hardirq/softirq
# ||| / _--=> preempt-depth
# |||| / _-=> migrate-disable
# ||||| / delay
# cmd pid |||||| time | caller
# \ / |||||| \ | /
kworker/-11 0dnh5. 0us : 11:120:R + [000] 22:
98:R irq_work/0
kworker/-11 0dnh5. 0us : <stack trace>
kworker/-11 0dnh5. 0us : 0
kworker/-11 0d..3. 0us : __schedule
kworker/-11 0d..3. 0us : 11:120:R ==> [000] 22:
98:R irq_work/0
kworker/-11 0d..3. 0us : <stack trace>
telnetd-229 0Dnh4. 0us : 229:120:R + [000]
118: 49:R irq/100-enet-fe
telnetd-229 0Dnh4. 0us : <stack trace>
telnetd-229 0Dnh4. 0us : 0
telnetd-229 0D..3. 0us : __schedule
telnetd-229 0D..3. 0us : 229:120:R ==> [000]
118: 49:R irq/100-enet-fe
telnetd-229 0D..3. 0us : <stack trace>
telnetd-229 0dn.5. 0us : 229:120:R + [000]
118: 49:R irq/100-enet-fe
telnetd-229 0dn.5. 0us : <stack trace>
telnetd-229 0dn.5. 0us#: 0
telnetd-229 0d..3. 2000us : __schedule
telnetd-229 0d..3. 2000us : 229:120:R ==> [000]
118: 49:R irq/100-enet-fe
telnetd-229 0d..3. 2000us : <stack trace>
Geert, Greg, and maybe other highly skilled m68k people, could you
please help me with this particular function :-) ?
Thanks !
JM
Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@xxxxxxxxxx>
---
arch/m68k/Kconfig | 5 ++++
arch/m68k/kernel/Makefile | 1 +
arch/m68k/kernel/stacktrace.c | 70 ++++++++++++++++++++++++++++++
++ +++++++++++
3 files changed, 76 insertions(+)
diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig
index
ab3375475721fa63418c40d4ba6ac76679ebc77d..7142f9759181a90269ae1ba9e682d331ee2ddbf6 100644
--- a/arch/m68k/Kconfig
+++ b/arch/m68k/Kconfig
@@ -40,6 +40,7 @@ config M68K
select UACCESS_MEMCPY if !MMU
select ZONE_DMA
select TRACE_IRQFLAGS_SUPPORT
+ select ARCH_STACKWALK
config CPU_BIG_ENDIAN
def_bool y
@@ -107,6 +108,10 @@ config BOOTINFO_PROC
Say Y to export the bootinfo used to boot the kernel in a
"bootinfo" file in procfs. This is useful with kexec.
+config STACKTRACE_SUPPORT
+ bool
+ default y
+
menu "Platform setup"
source "arch/m68k/Kconfig.cpu"
diff --git a/arch/m68k/kernel/Makefile b/arch/m68k/kernel/Makefile
index
f335bf3268a108a45bab079fbf0a1c8ead9beb71..4efe92af0b711b19cb1d5129f74e67a739e289b1 100644
--- a/arch/m68k/kernel/Makefile
+++ b/arch/m68k/kernel/Makefile
@@ -31,3 +31,4 @@ obj-$(CONFIG_UBOOT) += uboot.o
obj-$(CONFIG_EARLY_PRINTK) += early_printk.o
+obj-y += stacktrace.o
diff --git a/arch/m68k/kernel/stacktrace.c b/arch/m68k/kernel/
stacktrace.c
new file mode 100644
index
0000000000000000000000000000000000000000..06c7459373bd25b3bb3540cfe2a909259c1db3ce
--- /dev/null
+++ b/arch/m68k/kernel/stacktrace.c
@@ -0,0 +1,70 @@
+// SPDX-License-Identifier: GPL-2.0
+
+/*
+ * Stack trace utility functions etc.
+ *
+ * Copyright 2024 Jean-Michel Hautbois, Yoseli SAS.
+ */
+
+#include <asm/current.h>
+#include <asm/ptrace.h>
+#include <linux/sched.h>
+#include <linux/sched/task_stack.h>
+#include <linux/stacktrace.h>
+
+static inline unsigned long current_stack_frame(void)
+{
+ unsigned long sp;
+
+ asm volatile("movl %%sp, %0" : "=r"(sp));
+ return sp;
+}
If I am understanding what this is intended to do then this is
probably not right.
This will be returning the current stack pointer, which will almost
certainly not
be the current stack frame pointer. This will be the top of stack at
the call site,
which will be after the pushed locals and saved registers at the very
least for m68k.
Does your kernel config have CONFIG_FRAME_POINTER enabled?
The default for m68k is usually disabled. Without this there won't be a
chain of frame pointers to follow like the code is trying to do below in
arch_stack_walk().
Sorry for my preceding mail, it *is* better:
# tail -10 trace
# |||| / _-=> migrate-disable
# ||||| / delay
# cmd pid |||||| time | caller
# \ / |||||| \ | /
<idle>-0 0dnh5. 11us+: 0:120:R + [000] 119:
49:R irq/104-enet-fe
<idle>-0 0dnh5. 42us+: <stack trace>
<idle>-0 0dnh5. 57us!: wake_up_process <-
__handle_irq_event_percpu
<idle>-0 0d..3. 282us+: __schedule <-schedule_idle
<idle>-0 0d..3. 302us+: 0:120:R ==> [000] 119:
49:R irq/104-enet-fe
<idle>-0 0d..3. 325us : <stack trace>
Oh, yeah, there is more required.
The current_stack_frame() function needs to change to actually return
with the start of the frame pointer chain. You need it to look like this:
static inline unsigned long current_stack_frame(void)
{
unsigned long sp;
asm volatile("movl %%fp, %0" : "=r"(sp));
return sp;
}
Note that it is returning the "%fp" register - the current frame pointer.
Oh, thank you for this !
It is now really helpful !
# cd /sys/kernel/debug/tracing/
# echo wakeup_rt > current_tracer
# echo 1 > tracing_on
# echo 0 > tracing_max_latency
# chrt -f 5 sleep 1
# echo 0 > tracing_on
# cat trace
# tracer: wakeup_rt
#
# wakeup_rt latency trace v1.1.5 on 6.13.0-rc1-00093-g2b74d5f38b38-dirty
# --------------------------------------------------------------------
# latency: 405 us, #6/6, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
# -----------------
# | task: irq/100-enet-fe-118 (uid:0 nice:0 policy:1 rt_prio:50)
# -----------------
#
# _------=> CPU#
# / _-----=> irqs-off/BH-disabled
# | / _----=> need-resched
# || / _---=> hardirq/softirq
# ||| / _--=> preempt-depth
# |||| / _-=> migrate-disable
# ||||| / delay
# cmd pid |||||| time | caller
# \ / |||||| \ | /
telnetd-229 0Dnh4. 13us+: 229:120:R + [000] 118:
49:R irq/100-enet-fe
telnetd-229 0Dnh4. 53us+: <stack trace>
=> __trace_stack
=> probe_wakeup
=> try_to_wake_up
=> wake_up_process
=> __handle_irq_event_percpu
=> handle_irq_event
=> handle_level_irq
=> generic_handle_irq
=> do_IRQ
=> inthandler
=> ip_finish_output2
=> __ip_finish_output
=> ip_output
=> __ip_queue_xmit
=> ip_queue_xmit
=> __tcp_transmit_skb
=> tcp_write_xmit
=> __tcp_push_pending_frames
=> tcp_push
=> tcp_sendmsg_locked
=> tcp_sendmsg
=> inet_sendmsg
=> sock_write_iter
=> vfs_write
=> ksys_write
=> sys_write
=> system_call
telnetd-229 0Dnh4. 68us!: wake_up_process
<-__handle_irq_event_percpu
telnetd-229 0D..3. 348us+: __schedule <-preempt_schedule_irq
telnetd-229 0D..3. 368us+: 229:120:R ==> [000] 118:
49:R irq/100-enet-fe
telnetd-229 0D..3. 395us : <stack trace>
=> __trace_stack
=> probe_wakeup_sched_switch
=> __schedule
=> preempt_schedule_irq
=> Lkernel_return
=> ip_finish_output2
=> __ip_finish_output
=> ip_output
=> __ip_queue_xmit
=> ip_queue_xmit
=> __tcp_transmit_skb
=> tcp_write_xmit
=> __tcp_push_pending_frames
=> tcp_push
=> tcp_sendmsg_locked
=> tcp_sendmsg
=> inet_sendmsg
=> sock_write_iter
=> vfs_write
=> ksys_write
=> sys_write
=> system_call
I will use it and see if I can have more informations but, this makes
ftrace working nicely now, and I will submit a real patch now !
Thanks,
JM