| Message ID | 20241021-add-m68k-tracing-support-v1-1-0883d704525b@yoseli.org (mailing list archive) |
|---|---|
| State | Handled Elsewhere |
| Headers | show |
| Series | Add basic tracing support for m68k | expand |
On Mon, 21 Oct 2024 11:44:42 +0200 Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > The TRACE_IRQFLAGS_SUPPORT requires the architecture to call > trace_hardirqs_off() when interrupts are disabled and > trace_hardirqs_on() when they are enabled. > Add those calls to do_IRQ function. > > Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> > --- > arch/m68k/Kconfig | 1 + > arch/m68k/kernel/irq.c | 2 ++ > 2 files changed, 3 insertions(+) > > diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig > index cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d 100644 > --- a/arch/m68k/Kconfig > +++ b/arch/m68k/Kconfig > @@ -39,6 +39,7 @@ config M68K > select OLD_SIGSUSPEND3 > select UACCESS_MEMCPY if !MMU > select ZONE_DMA > + select TRACE_IRQFLAGS_SUPPORT > > config CPU_BIG_ENDIAN > def_bool y > diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c > index 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 100644 > --- a/arch/m68k/kernel/irq.c > +++ b/arch/m68k/kernel/irq.c > @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs *regs) > { > struct pt_regs *oldregs = set_irq_regs(regs); > > + trace_hardirqs_off(); > irq_enter(); > generic_handle_irq(irq); > irq_exit(); > + trace_hardirqs_on(); This part of the patch shouldn't be needed because those shoudl be called by irq_enter() and irq_exit(). Does this not work if you don't have these? -- Steve > > set_irq_regs(oldregs); > } >
Hi Steve, On 22/10/2024 07:28, Steven Rostedt wrote: > On Mon, 21 Oct 2024 11:44:42 +0200 > Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > >> The TRACE_IRQFLAGS_SUPPORT requires the architecture to call >> trace_hardirqs_off() when interrupts are disabled and >> trace_hardirqs_on() when they are enabled. >> Add those calls to do_IRQ function. >> >> Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> >> --- >> arch/m68k/Kconfig | 1 + >> arch/m68k/kernel/irq.c | 2 ++ >> 2 files changed, 3 insertions(+) >> >> diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig >> index cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d 100644 >> --- a/arch/m68k/Kconfig >> +++ b/arch/m68k/Kconfig >> @@ -39,6 +39,7 @@ config M68K >> select OLD_SIGSUSPEND3 >> select UACCESS_MEMCPY if !MMU >> select ZONE_DMA >> + select TRACE_IRQFLAGS_SUPPORT >> >> config CPU_BIG_ENDIAN >> def_bool y >> diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c >> index 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 100644 >> --- a/arch/m68k/kernel/irq.c >> +++ b/arch/m68k/kernel/irq.c >> @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs *regs) >> { >> struct pt_regs *oldregs = set_irq_regs(regs); >> >> + trace_hardirqs_off(); >> irq_enter(); >> generic_handle_irq(irq); >> irq_exit(); >> + trace_hardirqs_on(); > > This part of the patch shouldn't be needed because those shoudl be > called by irq_enter() and irq_exit(). Does this not work if you don't > have these? Thanks for your quick review ! Indeed, it works without those lines, so the patch is now a one-liner :-). I will wait for the second part to be reviewed before sending v2. JM
On Tue, 22 Oct 2024 07:42:10 +0200 Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > > This part of the patch shouldn't be needed because those shoudl be > > called by irq_enter() and irq_exit(). Does this not work if you don't > > have these? > > Thanks for your quick review ! \o/ > Indeed, it works without those lines, so the patch is now a one-liner > :-). I will wait for the second part to be reviewed before sending v2. I don't know enough about m68k to review that patch. Just incase you were expecting me to review it. -- Steve
Hi Steve, On 10/22/24 10:30, Steven Rostedt wrote: > On Tue, 22 Oct 2024 07:42:10 +0200 > Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > >>> This part of the patch shouldn't be needed because those shoudl be >>> called by irq_enter() and irq_exit(). Does this not work if you don't >>> have these? >> >> Thanks for your quick review ! > > \o/ > >> Indeed, it works without those lines, so the patch is now a one-liner >> :-). I will wait for the second part to be reviewed before sending v2. > > I don't know enough about m68k to review that patch. Just incase you > were expecting me to review it. I was not really expecting you to review the m68k one no :-). I think I have other issues which might have impact on ftrace too. For instance, when I launch cyclictest I have a warning about HRTIMERS: # cyclictest -p 99 WARN: stat /dev/cpu_dma_latency failed: No such file or directory WARN: High resolution timers not available policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245 T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 Max: 3516 The latencies are quite high... But regarding ftrace it seems that the trace is not able to give me more than a microsecond precision. I addded a few trace_printk() in a driver of mine and I get: irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt: Received 2 bytes irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt: Received 2 bytes irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: dspi_interrupt irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: TX FIFO overflow irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: Restart FIFO Do you have any clue ? Thanks ! JM
Jean-Michel, thanks for your patches! Am 21.10.2024 um 22:44 schrieb Jean-Michel Hautbois: > The TRACE_IRQFLAGS_SUPPORT requires the architecture to call > trace_hardirqs_off() when interrupts are disabled and > trace_hardirqs_on() when they are enabled. > Add those calls to do_IRQ function. You will also have to add these calls to the three sites in arch/m68k/coldfire/head.S where interrupts are enabled or disabled. Here: > ENTRY(system_call) > SAVE_ALL_SYS > move #0x2000,%sr /* enable intrs again */ > GET_CURRENT(%d2) and here: > ret_from_exception: > move #0x2700,%sr /* disable intrs */ > btst #5,%sp@(PT_OFF_SR) /* check if returning to kernel */ > jeq Luser_return /* if so, skip resched, signals */ and here: > Lwork_to_do: > movel %a0@(TINFO_FLAGS),%d1 /* get thread_info->flags */ > move #0x2000,%sr /* enable intrs again */ > btst #TIF_NEED_RESCHED,%d1 > jne reschedule There's one similar site in arch/m68k/kernel/head.S (ret_from_exception) where interrupts are enabled that would need a similar change, if you want to enable this for all m68k. Registers %d0-%d5 and %a0-%a2 are saved on the stack at this point and can be clobbered if need be. Cheers, Michael > > Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> > --- > arch/m68k/Kconfig | 1 + > arch/m68k/kernel/irq.c | 2 ++ > 2 files changed, 3 insertions(+) > > diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig > index cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d 100644 > --- a/arch/m68k/Kconfig > +++ b/arch/m68k/Kconfig > @@ -39,6 +39,7 @@ config M68K > select OLD_SIGSUSPEND3 > select UACCESS_MEMCPY if !MMU > select ZONE_DMA > + select TRACE_IRQFLAGS_SUPPORT > > config CPU_BIG_ENDIAN > def_bool y > diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c > index 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 100644 > --- a/arch/m68k/kernel/irq.c > +++ b/arch/m68k/kernel/irq.c > @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs *regs) > { > struct pt_regs *oldregs = set_irq_regs(regs); > > + trace_hardirqs_off(); > irq_enter(); > generic_handle_irq(irq); > irq_exit(); > + trace_hardirqs_on(); > > set_irq_regs(oldregs); > } >
Hi Michael, On 23/10/2024 05:53, Michael Schmitz wrote: > Jean-Michel, > > thanks for your patches! > > Am 21.10.2024 um 22:44 schrieb Jean-Michel Hautbois: >> The TRACE_IRQFLAGS_SUPPORT requires the architecture to call >> trace_hardirqs_off() when interrupts are disabled and >> trace_hardirqs_on() when they are enabled. >> Add those calls to do_IRQ function. > > You will also have to add these calls to the three sites in arch/m68k/ > coldfire/head.S where interrupts are enabled or disabled. Thanks for this ! I prepared a v2 with those calls added. I am wondering if my second patch is ok, I think it is not, could you please review it ? There may already be something related to the stack in the assembly part useful to implement arch_stack_walk() in a different way ? > > Here: >> ENTRY(system_call) >> SAVE_ALL_SYS >> move #0x2000,%sr /* enable intrs again */ >> GET_CURRENT(%d2) > > and here: >> ret_from_exception: >> move #0x2700,%sr /* disable intrs */ >> btst #5,%sp@(PT_OFF_SR) /* check if returning to >> kernel */ >> jeq Luser_return /* if so, skip resched, >> signals */ > > and here: >> Lwork_to_do: >> movel %a0@(TINFO_FLAGS),%d1 /* get thread_info->flags */ >> move #0x2000,%sr /* enable intrs again */ >> btst #TIF_NEED_RESCHED,%d1 >> jne reschedule > > There's one similar site in arch/m68k/kernel/head.S (ret_from_exception) > where interrupts are enabled that would need a similar change, if you > want to enable this for all m68k. I won't be able to test it though ;-). I see there are a few interrupts disabling in arch/m68k/include/asm/entry.h too ? > > Registers %d0-%d5 and %a0-%a2 are saved on the stack at this point and > can be clobbered if need be. I don't know if they need to be clobbered... Thanks, JM > > Cheers, > > Michael > > >> >> Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> >> --- >> arch/m68k/Kconfig | 1 + >> arch/m68k/kernel/irq.c | 2 ++ >> 2 files changed, 3 insertions(+) >> >> diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig >> index >> cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d 100644 >> --- a/arch/m68k/Kconfig >> +++ b/arch/m68k/Kconfig >> @@ -39,6 +39,7 @@ config M68K >> select OLD_SIGSUSPEND3 >> select UACCESS_MEMCPY if !MMU >> select ZONE_DMA >> + select TRACE_IRQFLAGS_SUPPORT >> >> config CPU_BIG_ENDIAN >> def_bool y >> diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c >> index >> 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 100644 >> --- a/arch/m68k/kernel/irq.c >> +++ b/arch/m68k/kernel/irq.c >> @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs *regs) >> { >> struct pt_regs *oldregs = set_irq_regs(regs); >> >> + trace_hardirqs_off(); >> irq_enter(); >> generic_handle_irq(irq); >> irq_exit(); >> + trace_hardirqs_on(); >> >> set_irq_regs(oldregs); >> } >>
Hi Jean-Michel, Am 23.10.2024 um 18:53 schrieb Jean-Michel Hautbois: > Hi Michael, > > On 23/10/2024 05:53, Michael Schmitz wrote: >> Jean-Michel, >> >> thanks for your patches! >> >> Am 21.10.2024 um 22:44 schrieb Jean-Michel Hautbois: >>> The TRACE_IRQFLAGS_SUPPORT requires the architecture to call >>> trace_hardirqs_off() when interrupts are disabled and >>> trace_hardirqs_on() when they are enabled. >>> Add those calls to do_IRQ function. >> >> You will also have to add these calls to the three sites in arch/m68k/ >> coldfire/head.S where interrupts are enabled or disabled. > > Thanks for this ! I prepared a v2 with those calls added. I am wondering Good - > if my second patch is ok, I think it is not, could you please review it I'll have to read up on how arch_stack_walk is supposed to work - have never seen that code before. > ? There may already be something related to the stack in the assembly > part useful to implement arch_stack_walk() in a different way ? I doubt it >> >> Here: >>> ENTRY(system_call) >>> SAVE_ALL_SYS >>> move #0x2000,%sr /* enable intrs again */ >>> GET_CURRENT(%d2) >> >> and here: >>> ret_from_exception: >>> move #0x2700,%sr /* disable intrs */ >>> btst #5,%sp@(PT_OFF_SR) /* check if returning to >>> kernel */ >>> jeq Luser_return /* if so, skip resched, >>> signals */ >> >> and here: >>> Lwork_to_do: >>> movel %a0@(TINFO_FLAGS),%d1 /* get thread_info->flags */ >>> move #0x2000,%sr /* enable intrs again */ >>> btst #TIF_NEED_RESCHED,%d1 >>> jne reschedule >> >> There's one similar site in arch/m68k/kernel/head.S >> (ret_from_exception) where interrupts are enabled that would need a >> similar change, if you want to enable this for all m68k. > > I won't be able to test it though ;-). > I see there are a few interrupts disabling in > arch/m68k/include/asm/entry.h too ? Right - that's different in the coldfire stack save/restore macros. I missed that before. Looks like wherever SAVE_ALL_SYS, SAVE_ALL_INT and RESTORE_USER are used, calls to trace_irqs_on/off() are required as well. RESTORE_USER only restores the IPL in the CONFIG_COLDFIRE_SW_A7, which makes this a little tricky ... you might have to add these calls to the macros to get the correct behaviour. > >> >> Registers %d0-%d5 and %a0-%a2 are saved on the stack at this point and >> can be clobbered if need be. > > I don't know if they need to be clobbered... I meant to say that if you need registers to prepare function arguments for trace_irqs_on/off() on the stack, these can be used. But that may not be necessary in this case. Cheers, Michael > > Thanks, > JM > >> >> Cheers, >> >> Michael >> >> >>> >>> Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> >>> --- >>> arch/m68k/Kconfig | 1 + >>> arch/m68k/kernel/irq.c | 2 ++ >>> 2 files changed, 3 insertions(+) >>> >>> diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig >>> index >>> cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d >>> 100644 >>> --- a/arch/m68k/Kconfig >>> +++ b/arch/m68k/Kconfig >>> @@ -39,6 +39,7 @@ config M68K >>> select OLD_SIGSUSPEND3 >>> select UACCESS_MEMCPY if !MMU >>> select ZONE_DMA >>> + select TRACE_IRQFLAGS_SUPPORT >>> >>> config CPU_BIG_ENDIAN >>> def_bool y >>> diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c >>> index >>> 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 >>> 100644 >>> --- a/arch/m68k/kernel/irq.c >>> +++ b/arch/m68k/kernel/irq.c >>> @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs *regs) >>> { >>> struct pt_regs *oldregs = set_irq_regs(regs); >>> >>> + trace_hardirqs_off(); >>> irq_enter(); >>> generic_handle_irq(irq); >>> irq_exit(); >>> + trace_hardirqs_on(); >>> >>> set_irq_regs(oldregs); >>> } >>> >
On Tue, 22 Oct 2024 11:21:34 +0200 Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > > I was not really expecting you to review the m68k one no :-). > I think I have other issues which might have impact on ftrace too. > For instance, when I launch cyclictest I have a warning about HRTIMERS: > # cyclictest -p 99 > WARN: stat /dev/cpu_dma_latency failed: No such file or directory > WARN: High resolution timers not available > policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245 > > T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 Max: > 3516 > > The latencies are quite high... Yes, if you don't have high resolution timers, the latency will be high. > > But regarding ftrace it seems that the trace is not able to give me more > than a microsecond precision. I addded a few trace_printk() in a driver > of mine and I get: > irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt: > Received 2 bytes > irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt: > Received 2 bytes > irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: > dspi_interrupt > irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: TX > FIFO overflow > irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: > Restart FIFO > > Do you have any clue ? Yes. The ring buffer clock is dependent on the architecture's clock. By default, it uses whatever the scheduler clock uses. If the scheduler clock is 1ms resolution, so will the tracing data be. -- Steve
Hi, On 23.10.2024 8.53, Jean-Michel Hautbois wrote: ... >> There's one similar site in arch/m68k/kernel/head.S >> (ret_from_exception) where interrupts are enabled that would need a >> similar change, if you want to enable this for all m68k. > > I won't be able to test it though ;-). > I see there are a few interrupts disabling in > arch/m68k/include/asm/entry.h too ? I would suggest using Hatari for testing it, as that emulates real HW more accurately than Aranym, and provides better debugging & profiling utilities than either Aranym or real HW [1], especially for kernel side. (Because ColdFire is close to m68k, Hatari can help in debugging also issues that are in Linux code they share.) Here are detailed and IMHO easy instructions on how to do that: https://hatari.tuxfamily.org/doc/m68k-linux.txt I'd recommend using Git HEAD of Hatari [2] for testing though, because there was a recent fix to handling prefetch during bus errors, when 030 MMU is enabled, and without that fix, prefetch + cache emulation would need to to be disabled for user-space to work correctly. If you disable those (--compatible off --cycle-exact off), you can start with Hatari version from Linux distros though... (You can mail me directly if you have problems with Hatari. Getting ftrace working on m68k would be interesting.) - Eero [1] https://hatari.tuxfamily.org/doc/debugger.html [2] Upstream: https://git.tuxfamily.org/hatari/hatari.git/ or mirror: https://github.com/hatari/hatari/
Hi Michael, On 23/10/2024 09:30, Michael Schmitz wrote: > Hi Jean-Michel, > > Am 23.10.2024 um 18:53 schrieb Jean-Michel Hautbois: >> Hi Michael, >> >> On 23/10/2024 05:53, Michael Schmitz wrote: >>> Jean-Michel, >>> >>> thanks for your patches! >>> >>> Am 21.10.2024 um 22:44 schrieb Jean-Michel Hautbois: >>>> The TRACE_IRQFLAGS_SUPPORT requires the architecture to call >>>> trace_hardirqs_off() when interrupts are disabled and >>>> trace_hardirqs_on() when they are enabled. >>>> Add those calls to do_IRQ function. >>> >>> You will also have to add these calls to the three sites in arch/m68k/ >>> coldfire/head.S where interrupts are enabled or disabled. >> >> Thanks for this ! I prepared a v2 with those calls added. I am wondering > > Good - > >> if my second patch is ok, I think it is not, could you please review it > > I'll have to read up on how arch_stack_walk is supposed to work - have > never seen that code before. > >> ? There may already be something related to the stack in the assembly >> part useful to implement arch_stack_walk() in a different way ? > > I doubt it > >>> >>> Here: >>>> ENTRY(system_call) >>>> SAVE_ALL_SYS >>>> move #0x2000,%sr /* enable intrs again */ >>>> GET_CURRENT(%d2) >>> >>> and here: >>>> ret_from_exception: >>>> move #0x2700,%sr /* disable intrs */ >>>> btst #5,%sp@(PT_OFF_SR) /* check if returning to >>>> kernel */ >>>> jeq Luser_return /* if so, skip resched, >>>> signals */ >>> >>> and here: >>>> Lwork_to_do: >>>> movel %a0@(TINFO_FLAGS),%d1 /* get thread_info->flags */ >>>> move #0x2000,%sr /* enable intrs again */ >>>> btst #TIF_NEED_RESCHED,%d1 >>>> jne reschedule >>> >>> There's one similar site in arch/m68k/kernel/head.S >>> (ret_from_exception) where interrupts are enabled that would need a >>> similar change, if you want to enable this for all m68k. >> >> I won't be able to test it though ;-). >> I see there are a few interrupts disabling in >> arch/m68k/include/asm/entry.h too ? > > Right - that's different in the coldfire stack save/restore macros. I > missed that before. > > Looks like wherever SAVE_ALL_SYS, SAVE_ALL_INT and RESTORE_USER are > used, calls to trace_irqs_on/off() are required as well. > > RESTORE_USER only restores the IPL in the CONFIG_COLDFIRE_SW_A7, which > makes this a little tricky ... you might have to add these calls to the > macros to get the correct behaviour. > Sadly, not that straightforward. I have this patch right now: diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig index b2a3093af677..fc4a2d124514 100644 --- a/arch/m68k/Kconfig +++ b/arch/m68k/Kconfig @@ -41,6 +41,7 @@ config M68K select ZONE_DMA select ARCH_SUPPORTS_RT select IRQ_FORCED_THREADING + select TRACE_IRQFLAGS_SUPPORT config CPU_BIG_ENDIAN def_bool y diff --git a/arch/m68k/coldfire/entry.S b/arch/m68k/coldfire/entry.S index 4ea08336e2fb..fbdc4404f29e 100644 --- a/arch/m68k/coldfire/entry.S +++ b/arch/m68k/coldfire/entry.S @@ -57,6 +57,9 @@ enosys: ENTRY(system_call) SAVE_ALL_SYS move #0x2000,%sr /* enable intrs again */ +#ifdef CONFIG_TRACE_IRQFLAGS + jbsr trace_hardirqs_on +#endif GET_CURRENT(%d2) cmpl #NR_syscalls,%d0 @@ -99,6 +102,9 @@ ENTRY(system_call) addql #4,%sp ret_from_exception: +#ifdef CONFIG_TRACE_IRQFLAGS + jbsr trace_hardirqs_off +#endif move #0x2700,%sr /* disable intrs */ btst #5,%sp@(PT_OFF_SR) /* check if returning to kernel */ jeq Luser_return /* if so, skip resched, signals */ @@ -140,6 +146,9 @@ Lreturn: Lwork_to_do: movel %a0@(TINFO_FLAGS),%d1 /* get thread_info->flags */ move #0x2000,%sr /* enable intrs again */ +#ifdef CONFIG_TRACE_IRQFLAGS + jbsr trace_hardirqs_on +#endif btst #TIF_NEED_RESCHED,%d1 jne reschedule But it fails when init is called: [ 5.313000] Run /bin/bash as init process [ 5.314000] with arguments: [ 5.315000] /bin/bash [ 5.316000] with environment: [ 5.317000] HOME=/ [ 5.318000] TERM=linux [ 5.684000] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b [ 5.684000] CPU: 0 UID: 0 PID: 1 Comm: bash Not tainted 6.12.0-rc4-00049-g4393ca34ead3 #364 [ 5.684000] Stack from 41a03e18: [ 5.684000] 41a03e18 41540187 41540187 0000000a ffffffff 415a8fb4 4140dd90 41416588 [ 5.684000] 41540187 4140d5de 4102ba84 4100b19c 4100b1a8 00000000 41a38000 4102ba3a [ 5.684000] 41a03ea0 4100c34a 4150e87e 0000000b 0000000b 41a03f80 0000000a 41a3c0d4 [ 5.684000] 41a02000 400004d8 41a08000 4102ba3a 4102ba84 00000000 00000000 000000ff [ 5.684000] 00000000 00000000 41a03ef4 4100cb82 0000000b 0000000b 41a03f80 41a03f6c [ 5.684000] 41016cd2 0000000b 41a03f6c 0000001d 00000026 0000048c ffffffff 00000006 [ 5.684000] Call Trace: [<4140dd90>] _printk+0x0/0x18 [ 5.684000] [<41416588>] dump_stack+0xc/0x10 [ 5.684000] [<4140d5de>] panic+0xf2/0x2d4 [ 5.684000] [<4102ba84>] preempt_count_sub+0x0/0x2e [ 5.684000] [<4100b19c>] arch_local_irq_enable+0x0/0xc [ 5.684000] [<4100b1a8>] arch_irqs_disabled+0x0/0x10 [ 5.684000] [<4102ba3a>] preempt_count_add+0x0/0x1e [ 5.684000] [<4100c34a>] do_exit+0x266/0x930 [ 5.684000] [<4102ba3a>] preempt_count_add+0x0/0x1e [ 5.684000] [<4102ba84>] preempt_count_sub+0x0/0x2e [ 5.684000] [<4100cb82>] do_group_exit+0x26/0xba [ 5.684000] [<41016cd2>] get_signal+0x60e/0x76c [ 5.684000] [<410044e8>] test_ti_thread_flag+0x0/0x14 [ 5.684000] [<4102ba94>] preempt_count_sub+0x10/0x2e [ 5.684000] [<41004b68>] do_notify_resume+0x3a/0x4c6 [ 5.684000] [<41015d52>] force_sig_fault_to_task+0x32/0x3e [ 5.684000] [<41015d72>] force_sig_fault+0x14/0x1a [ 5.684000] [<41005606>] buserr_c+0x9a/0x188 [ 5.684000] [<410065fc>] Lsignal_return+0x14/0x24 [ 5.684000] [<410065de>] Lwork_to_do+0xe/0x18 [ 5.684000] [ 5.684000] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b ]--- JM >> >>> >>> Registers %d0-%d5 and %a0-%a2 are saved on the stack at this point and >>> can be clobbered if need be. >> >> I don't know if they need to be clobbered... > > I meant to say that if you need registers to prepare function arguments > for trace_irqs_on/off() on the stack, these can be used. But that may > not be necessary in this case. > > Cheers, > > Michael > > >> >> Thanks, >> JM >> >>> >>> Cheers, >>> >>> Michael >>> >>> >>>> >>>> Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> >>>> --- >>>> arch/m68k/Kconfig | 1 + >>>> arch/m68k/kernel/irq.c | 2 ++ >>>> 2 files changed, 3 insertions(+) >>>> >>>> diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig >>>> index >>>> cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d >>>> 100644 >>>> --- a/arch/m68k/Kconfig >>>> +++ b/arch/m68k/Kconfig >>>> @@ -39,6 +39,7 @@ config M68K >>>> select OLD_SIGSUSPEND3 >>>> select UACCESS_MEMCPY if !MMU >>>> select ZONE_DMA >>>> + select TRACE_IRQFLAGS_SUPPORT >>>> >>>> config CPU_BIG_ENDIAN >>>> def_bool y >>>> diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c >>>> index >>>> 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 >>>> 100644 >>>> --- a/arch/m68k/kernel/irq.c >>>> +++ b/arch/m68k/kernel/irq.c >>>> @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs >>>> *regs) >>>> { >>>> struct pt_regs *oldregs = set_irq_regs(regs); >>>> >>>> + trace_hardirqs_off(); >>>> irq_enter(); >>>> generic_handle_irq(irq); >>>> irq_exit(); >>>> + trace_hardirqs_on(); >>>> >>>> set_irq_regs(oldregs); >>>> } >>>> >>
Hi Steve, On 23/10/2024 10:47, Steven Rostedt wrote: > On Tue, 22 Oct 2024 11:21:34 +0200 > Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > >> >> I was not really expecting you to review the m68k one no :-). >> I think I have other issues which might have impact on ftrace too. >> For instance, when I launch cyclictest I have a warning about HRTIMERS: >> # cyclictest -p 99 >> WARN: stat /dev/cpu_dma_latency failed: No such file or directory >> WARN: High resolution timers not available >> policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245 >> >> T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 Max: >> 3516 >> >> The latencies are quite high... > > Yes, if you don't have high resolution timers, the latency will be high. > According to my config, I should have those: CONFIG_HIGH_RES_TIMERS=y >> >> But regarding ftrace it seems that the trace is not able to give me more >> than a microsecond precision. I addded a few trace_printk() in a driver >> of mine and I get: >> irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt: >> Received 2 bytes >> irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt: >> Received 2 bytes >> irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: >> dspi_interrupt >> irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: TX >> FIFO overflow >> irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: >> Restart FIFO >> >> Do you have any clue ? > > Yes. The ring buffer clock is dependent on the architecture's clock. By > default, it uses whatever the scheduler clock uses. If the scheduler > clock is 1ms resolution, so will the tracing data be. By default. So, I could change it to mono_raw for instance :-). It seems that timerlat is ok with it ! irq/178-UART-99 [000] D.h1. 95.766649: #27138 context irq timer_latency 525376 ns timerlat/0-235 [000] ..... 95.766826: #27138 context thread timer_latency 697920 ns <idle>-0 [000] dnh1. 95.767682: #27139 context irq timer_latency 559616 ns timerlat/0-235 [000] ..... 95.767839: #27139 context thread timer_latency 713216 ns <idle>-0 [000] dnh1. 95.768701: #27140 context irq timer_latency 577984 ns timerlat/0-235 [000] ..... 95.768861: #27140 context thread timer_latency 734656 ns irq/178-UART-99 [000] d.h1. 95.769671: #27141 context irq timer_latency 548736 ns timerlat/0-235 [000] ..... 95.769838: #27141 context thread timer_latency 711552 ns irq/178-UART-99 [000] D.h1. 95.770664: #27142 context irq timer_latency 540992 ns timerlat/0-235 [000] ..... 95.770841: #27142 context thread timer_latency 713024 ns > > -- Steve >
Hi Jean-Michel, On Wed, Oct 23, 2024 at 11:07 AM Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > On 23/10/2024 10:47, Steven Rostedt wrote: > > On Tue, 22 Oct 2024 11:21:34 +0200 > > Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > >> I was not really expecting you to review the m68k one no :-). > >> I think I have other issues which might have impact on ftrace too. > >> For instance, when I launch cyclictest I have a warning about HRTIMERS: > >> # cyclictest -p 99 > >> WARN: stat /dev/cpu_dma_latency failed: No such file or directory > >> WARN: High resolution timers not available > >> policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245 > >> > >> T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 Max: > >> 3516 > >> > >> The latencies are quite high... > > > > Yes, if you don't have high resolution timers, the latency will be high. > > According to my config, I should have those: > CONFIG_HIGH_RES_TIMERS=y Does your hardware have a high resolution timer, and do you have a driver for it? $ git grep hrtimer -- arch/m68k/ $ Gr{oetje,eeting}s, Geert
On Wed, 23 Oct 2024 10:59:42 +0200 Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: > > Sadly, not that straightforward. > I have this patch right now: > diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig > index b2a3093af677..fc4a2d124514 100644 > --- a/arch/m68k/Kconfig > +++ b/arch/m68k/Kconfig > @@ -41,6 +41,7 @@ config M68K > select ZONE_DMA > select ARCH_SUPPORTS_RT > select IRQ_FORCED_THREADING > + select TRACE_IRQFLAGS_SUPPORT > > config CPU_BIG_ENDIAN > def_bool y > diff --git a/arch/m68k/coldfire/entry.S b/arch/m68k/coldfire/entry.S > index 4ea08336e2fb..fbdc4404f29e 100644 > --- a/arch/m68k/coldfire/entry.S > +++ b/arch/m68k/coldfire/entry.S > @@ -57,6 +57,9 @@ enosys: > ENTRY(system_call) > SAVE_ALL_SYS > move #0x2000,%sr /* enable intrs again */ > +#ifdef CONFIG_TRACE_IRQFLAGS > + jbsr trace_hardirqs_on > +#endif Note, the trace_hardirqs_on/off() needs to be done when interrupts are disabled. That is: __local_irq_disable(); trace_hardirqs_off(); [..] trace_hardirqs_on(); __local_irq_enable(); I don't know the m68k assembly, but from the comments it looks like you are calling these with interrupts enabled. -- Steve > GET_CURRENT(%d2) > > cmpl #NR_syscalls,%d0 > @@ -99,6 +102,9 @@ ENTRY(system_call) > addql #4,%sp > > ret_from_exception: > +#ifdef CONFIG_TRACE_IRQFLAGS > + jbsr trace_hardirqs_off > +#endif > move #0x2700,%sr /* disable intrs */ > btst #5,%sp@(PT_OFF_SR) /* check if returning to kernel */ > jeq Luser_return /* if so, skip resched, signals */ > @@ -140,6 +146,9 @@ Lreturn: > Lwork_to_do: > movel %a0@(TINFO_FLAGS),%d1 /* get thread_info->flags */ > move #0x2000,%sr /* enable intrs again */ > +#ifdef CONFIG_TRACE_IRQFLAGS > + jbsr trace_hardirqs_on > +#endif > btst #TIF_NEED_RESCHED,%d1 > jne reschedule > > But it fails when init is called: > [ 5.313000] Run /bin/bash as init process > [ 5.314000] with arguments: > [ 5.315000] /bin/bash > [ 5.316000] with environment: > [ 5.317000] HOME=/ > [ 5.318000] TERM=linux > [ 5.684000] Kernel panic - not syncing: Attempted to kill init! > exitcode=0x0000000b > [ 5.684000] CPU: 0 UID: 0 PID: 1 Comm: bash Not tainted > 6.12.0-rc4-00049-g4393ca34ead3 #364 > [ 5.684000] Stack from 41a03e18: > [ 5.684000] 41a03e18 41540187 41540187 0000000a ffffffff > 415a8fb4 4140dd90 41416588 > [ 5.684000] 41540187 4140d5de 4102ba84 4100b19c 4100b1a8 > 00000000 41a38000 4102ba3a > [ 5.684000] 41a03ea0 4100c34a 4150e87e 0000000b 0000000b > 41a03f80 0000000a 41a3c0d4 > [ 5.684000] 41a02000 400004d8 41a08000 4102ba3a 4102ba84 > 00000000 00000000 000000ff > [ 5.684000] 00000000 00000000 41a03ef4 4100cb82 0000000b > 0000000b 41a03f80 41a03f6c > [ 5.684000] 41016cd2 0000000b 41a03f6c 0000001d 00000026 > 0000048c ffffffff 00000006 > [ 5.684000] Call Trace: [<4140dd90>] _printk+0x0/0x18 > [ 5.684000] [<41416588>] dump_stack+0xc/0x10 > [ 5.684000] [<4140d5de>] panic+0xf2/0x2d4 > [ 5.684000] [<4102ba84>] preempt_count_sub+0x0/0x2e > [ 5.684000] [<4100b19c>] arch_local_irq_enable+0x0/0xc > [ 5.684000] [<4100b1a8>] arch_irqs_disabled+0x0/0x10 > [ 5.684000] [<4102ba3a>] preempt_count_add+0x0/0x1e > [ 5.684000] [<4100c34a>] do_exit+0x266/0x930 > [ 5.684000] [<4102ba3a>] preempt_count_add+0x0/0x1e > [ 5.684000] [<4102ba84>] preempt_count_sub+0x0/0x2e > [ 5.684000] [<4100cb82>] do_group_exit+0x26/0xba > [ 5.684000] [<41016cd2>] get_signal+0x60e/0x76c > [ 5.684000] [<410044e8>] test_ti_thread_flag+0x0/0x14 > [ 5.684000] [<4102ba94>] preempt_count_sub+0x10/0x2e > [ 5.684000] [<41004b68>] do_notify_resume+0x3a/0x4c6 > [ 5.684000] [<41015d52>] force_sig_fault_to_task+0x32/0x3e > [ 5.684000] [<41015d72>] force_sig_fault+0x14/0x1a > [ 5.684000] [<41005606>] buserr_c+0x9a/0x188 > [ 5.684000] [<410065fc>] Lsignal_return+0x14/0x24 > [ 5.684000] [<410065de>] Lwork_to_do+0xe/0x18 > [ 5.684000] > [ 5.684000] ---[ end Kernel panic - not syncing: Attempted to kill > init! exitcode=0x0000000b ]--- > > > JM > > >> > >>> > >>> Registers %d0-%d5 and %a0-%a2 are saved on the stack at this point and > >>> can be clobbered if need be. > >> > >> I don't know if they need to be clobbered... > > > > I meant to say that if you need registers to prepare function arguments > > for trace_irqs_on/off() on the stack, these can be used. But that may > > not be necessary in this case. > > > > Cheers, > > > > Michael > > > > > >> > >> Thanks, > >> JM > >> > >>> > >>> Cheers, > >>> > >>> Michael > >>> > >>> > >>>> > >>>> Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> > >>>> --- > >>>> arch/m68k/Kconfig | 1 + > >>>> arch/m68k/kernel/irq.c | 2 ++ > >>>> 2 files changed, 3 insertions(+) > >>>> > >>>> diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig > >>>> index > >>>> cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d > >>>> 100644 > >>>> --- a/arch/m68k/Kconfig > >>>> +++ b/arch/m68k/Kconfig > >>>> @@ -39,6 +39,7 @@ config M68K > >>>> select OLD_SIGSUSPEND3 > >>>> select UACCESS_MEMCPY if !MMU > >>>> select ZONE_DMA > >>>> + select TRACE_IRQFLAGS_SUPPORT > >>>> > >>>> config CPU_BIG_ENDIAN > >>>> def_bool y > >>>> diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c > >>>> index > >>>> 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 > >>>> 100644 > >>>> --- a/arch/m68k/kernel/irq.c > >>>> +++ b/arch/m68k/kernel/irq.c > >>>> @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs > >>>> *regs) > >>>> { > >>>> struct pt_regs *oldregs = set_irq_regs(regs); > >>>> > >>>> + trace_hardirqs_off(); > >>>> irq_enter(); > >>>> generic_handle_irq(irq); > >>>> irq_exit(); > >>>> + trace_hardirqs_on(); > >>>> > >>>> set_irq_regs(oldregs); > >>>> } > >>>> > >>
Hi Geert, On 23/10/2024 11:13, Geert Uytterhoeven wrote: > Hi Jean-Michel, > > On Wed, Oct 23, 2024 at 11:07 AM Jean-Michel Hautbois > <jeanmichel.hautbois@yoseli.org> wrote: >> On 23/10/2024 10:47, Steven Rostedt wrote: >>> On Tue, 22 Oct 2024 11:21:34 +0200 >>> Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: >>>> I was not really expecting you to review the m68k one no :-). >>>> I think I have other issues which might have impact on ftrace too. >>>> For instance, when I launch cyclictest I have a warning about HRTIMERS: >>>> # cyclictest -p 99 >>>> WARN: stat /dev/cpu_dma_latency failed: No such file or directory >>>> WARN: High resolution timers not available >>>> policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245 >>>> >>>> T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 Max: >>>> 3516 >>>> >>>> The latencies are quite high... >>> >>> Yes, if you don't have high resolution timers, the latency will be high. >> >> According to my config, I should have those: >> CONFIG_HIGH_RES_TIMERS=y > > Does your hardware have a high resolution timer, and do you have > a driver for it? > > $ git grep hrtimer -- arch/m68k/ > $ > No, there is nothing with hrtimer. But, the architecture has four dma timers, with a 8ns resolution at 125MHz says the documentation. I will try to find a way to implement the missing part. Thanks, JM > Gr{oetje,eeting}s, > > Geert >
Hi Geert, all, On 23/10/2024 11:31, Jean-Michel Hautbois wrote: > Hi Geert, > > On 23/10/2024 11:13, Geert Uytterhoeven wrote: >> Hi Jean-Michel, >> >> On Wed, Oct 23, 2024 at 11:07 AM Jean-Michel Hautbois >> <jeanmichel.hautbois@yoseli.org> wrote: >>> On 23/10/2024 10:47, Steven Rostedt wrote: >>>> On Tue, 22 Oct 2024 11:21:34 +0200 >>>> Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> wrote: >>>>> I was not really expecting you to review the m68k one no :-). >>>>> I think I have other issues which might have impact on ftrace too. >>>>> For instance, when I launch cyclictest I have a warning about >>>>> HRTIMERS: >>>>> # cyclictest -p 99 >>>>> WARN: stat /dev/cpu_dma_latency failed: No such file or directory >>>>> WARN: High resolution timers not available >>>>> policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245 >>>>> >>>>> T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 >>>>> Max: >>>>> 3516 >>>>> >>>>> The latencies are quite high... >>>> >>>> Yes, if you don't have high resolution timers, the latency will be >>>> high. >>> >>> According to my config, I should have those: >>> CONFIG_HIGH_RES_TIMERS=y >> >> Does your hardware have a high resolution timer, and do you have >> a driver for it? >> >> $ git grep hrtimer -- arch/m68k/ >> $ >> > > No, there is nothing with hrtimer. But, the architecture has four dma > timers, with a 8ns resolution at 125MHz says the documentation. I will > try to find a way to implement the missing part. > I gave it a hacky try. And it seems to be *a lot* better: # cyclictest -p 99 -l 10000 WARN: stat /dev/cpu_dma_latency failed: No such file or directory policy: fifo: loadavg: 1.18 0.71 0.33 1/122 258 T: 0 ( 258) P:99 I:1000 C: 10000 Min: 118 Act: 1104 Avg: 418 Max: 1858 I will try to clean it a bit for another patch set :-). Thanks, JM
diff --git a/arch/m68k/Kconfig b/arch/m68k/Kconfig index cc26df907bfe3c8143a931d259eceabb16af7411..ab3375475721fa63418c40d4ba6ac76679ebc77d 100644 --- a/arch/m68k/Kconfig +++ b/arch/m68k/Kconfig @@ -39,6 +39,7 @@ config M68K select OLD_SIGSUSPEND3 select UACCESS_MEMCPY if !MMU select ZONE_DMA + select TRACE_IRQFLAGS_SUPPORT config CPU_BIG_ENDIAN def_bool y diff --git a/arch/m68k/kernel/irq.c b/arch/m68k/kernel/irq.c index 9ab4f550342e5de11c528f55781432675ffd66bf..74cf60ebbc4bca51f3caa4046dbd2bdb02355711 100644 --- a/arch/m68k/kernel/irq.c +++ b/arch/m68k/kernel/irq.c @@ -21,9 +21,11 @@ asmlinkage void do_IRQ(int irq, struct pt_regs *regs) { struct pt_regs *oldregs = set_irq_regs(regs); + trace_hardirqs_off(); irq_enter(); generic_handle_irq(irq); irq_exit(); + trace_hardirqs_on(); set_irq_regs(oldregs); }
The TRACE_IRQFLAGS_SUPPORT requires the architecture to call trace_hardirqs_off() when interrupts are disabled and trace_hardirqs_on() when they are enabled. Add those calls to do_IRQ function. Signed-off-by: Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org> --- arch/m68k/Kconfig | 1 + arch/m68k/kernel/irq.c | 2 ++ 2 files changed, 3 insertions(+)