lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite for Android: free password hash cracker in your pocket
[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <70ee3b94-1589-4d41-b68f-1ef16b4f13c4@yoseli.org>
Date: Tue, 3 Dec 2024 07:25:55 +0100
From: Jean-Michel Hautbois <jeanmichel.hautbois@...eli.org>
To: Greg Ungerer <gerg@...ux-m68k.org>, linux-m68k@...ts.linux-m68k.org
Cc: linux-kernel@...r.kernel.org, linux-trace-kernel@...r.kernel.org,
 rostedt@...dmis.org, Michael Schmitz <schmitzmic@...il.com>,
 Geert Uytterhoeven <geert@...ux-m68k.org>
Subject: Re: [PATCH RFC 2/2] arch: m68k: Add STACKTRACE support

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@...eli.org>
>>>>> ---
>>>>>   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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ