Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[richard clark]

Hi,
There's a smp_call_function_single(10, ipi_cb_func, &data_info, 1)
called by the init function of my kmod, then I ipi traces this
smp_call_function_single(...) with below cmdline:

# echo 0 > /sys/kernel/debug/tracing/tracing_on; echo >
/sys/kernel/debug/tracing/trace; echo 'reason=="Function call
interrupts"' > /sys/kernel/debug/tracing/events/ipi/filter; echo 1 >
/sys/kernel/debug/tracing/events/ipi/ipi_raise/enable; echo 1 >
/sys/kernel/debug/tracing/events/ipi/ipi_entry/enable; echo 1 >
/sys/kernel/debug/tracing/tracing_on; taskset -c 0 insmod
/kmods/ipi_test.ko; echo 0 > /sys/kernel/debug/tracing/tracing_on;
echo 0 > /sys/kernel/debug/tracing/events/ipi/ipi_raise/enable; echo 0
> /sys/kernel/debug/tracing/events/ipi/ipi_entry/enable; echo >
/sys/kernel/debug/tracing/events/ipi/filter; cat
/sys/kernel/debug/tracing/trace

The trace output as below:

# tracer: nop
#
# entries-in-buffer/entries-written: 28/28   #P:12
#
#                                _-------=> irqs-off/BH-disabled
#                               / _------=> need-resched
#                              | / _-----=> need-resched-lazy
#                              || / _----=> hardirq/softirq
#                              ||| / _---=> preempt-depth
#                              |||| / _--=> preempt-lazy-depth
#                              ||||| / _-=> migrate-disable
#                              |||||| /     delay
#           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
#              | |         |   |||||||      |         |

          <idle>-0       [009] dn.h2..   555.400822: ipi_raise:
target_mask=00000000,00000002 (Function call interrupts)
          <idle>-0       [001] d..h1..   555.400832: ipi_entry:
(Function call interrupts)
          insmod-1644    [000] ....1..   555.401628: ipi_raise:
target_mask=00000000,00000ffe (Function call interrupts)
          <idle>-0       [001] d..h1..   555.401630: ipi_entry:
(Function call interrupts)
          <idle>-0       [009] d..h1..   555.401631: ipi_entry:
(Function call interrupts)
          <idle>-0       [011] d..h1..   555.401633: ipi_entry:
(Function call interrupts)
          <idle>-0       [003] d..h1..   555.401633: ipi_entry:
(Function call interrupts)
          <idle>-0       [008] d..h1..   555.401633: ipi_entry:
(Function call interrupts)
          <idle>-0       [002] d..h1..   555.401634: ipi_entry:
(Function call interrupts)
          <idle>-0       [010] d..h1..   555.401634: ipi_entry:
(Function call interrupts)
          <idle>-0       [004] d..h1..   555.401635: ipi_entry:
(Function call interrupts)
          <idle>-0       [005] d..h1..   555.401635: ipi_entry:
(Function call interrupts)
          <idle>-0       [006] d..h1..   555.401635: ipi_entry:
(Function call interrupts)
          <idle>-0       [007] d..h1..   555.401635: ipi_entry:
(Function call interrupts)
          insmod-1644    [000] ....1..   555.401643: ipi_raise:
target_mask=00000000,00000ffe (Function call interrupts)
          <idle>-0       [001] d..h1..   555.401644: ipi_entry:
(Function call interrupts)
          <idle>-0       [002] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [003] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [004] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [006] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [005] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [007] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [008] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [009] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [010] d..h1..   555.401645: ipi_entry:
(Function call interrupts)
          <idle>-0       [011] d..h1..   555.401646: ipi_entry:
(Function call interrupts)
          insmod-1644    [000] ....1..   555.401908: ipi_raise:
target_mask=00000000,00000400 (Function call interrupts)
          <idle>-0       [010] d..h1..   555.401911: ipi_entry:
(Function call interrupts)

I am curious why there're two IPI broadcasts to all the other
cpus(1-11) before the real smp_call_function_single(10) trace
event(the last two lines of the above trace output), any comments
about that?

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[Marc Zyngier]

On Thu, 27 Jun 2024 10:26:05 +0100,
richard clark <richard.xnu.clark@gmail.com> wrote:
> 
> Hi,
> There's a smp_call_function_single(10, ipi_cb_func, &data_info, 1)
> called by the init function of my kmod, then I ipi traces this
> smp_call_function_single(...) with below cmdline:
> 
> # echo 0 > /sys/kernel/debug/tracing/tracing_on; echo >
> /sys/kernel/debug/tracing/trace; echo 'reason=="Function call
> interrupts"' > /sys/kernel/debug/tracing/events/ipi/filter; echo 1 >
> /sys/kernel/debug/tracing/events/ipi/ipi_raise/enable; echo 1 >
> /sys/kernel/debug/tracing/events/ipi/ipi_entry/enable; echo 1 >
> /sys/kernel/debug/tracing/tracing_on; taskset -c 0 insmod
> /kmods/ipi_test.ko; echo 0 > /sys/kernel/debug/tracing/tracing_on;
> echo 0 > /sys/kernel/debug/tracing/events/ipi/ipi_raise/enable; echo 0
> > /sys/kernel/debug/tracing/events/ipi/ipi_entry/enable; echo >
> /sys/kernel/debug/tracing/events/ipi/filter; cat
> /sys/kernel/debug/tracing/trace
> 
> The trace output as below:
> 
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 28/28   #P:12
> #
> #                                _-------=> irqs-off/BH-disabled
> #                               / _------=> need-resched
> #                              | / _-----=> need-resched-lazy
> #                              || / _----=> hardirq/softirq
> #                              ||| / _---=> preempt-depth
> #                              |||| / _--=> preempt-lazy-depth
> #                              ||||| / _-=> migrate-disable
> #                              |||||| /     delay
> #           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
> #              | |         |   |||||||      |         |
> 
>           <idle>-0       [009] dn.h2..   555.400822: ipi_raise:
> target_mask=00000000,00000002 (Function call interrupts)
>           <idle>-0       [001] d..h1..   555.400832: ipi_entry:
> (Function call interrupts)
>           insmod-1644    [000] ....1..   555.401628: ipi_raise:
> target_mask=00000000,00000ffe (Function call interrupts)
>           <idle>-0       [001] d..h1..   555.401630: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [009] d..h1..   555.401631: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [011] d..h1..   555.401633: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [003] d..h1..   555.401633: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [008] d..h1..   555.401633: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [002] d..h1..   555.401634: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [010] d..h1..   555.401634: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [004] d..h1..   555.401635: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [005] d..h1..   555.401635: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [006] d..h1..   555.401635: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [007] d..h1..   555.401635: ipi_entry:
> (Function call interrupts)
>           insmod-1644    [000] ....1..   555.401643: ipi_raise:
> target_mask=00000000,00000ffe (Function call interrupts)
>           <idle>-0       [001] d..h1..   555.401644: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [002] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [003] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [004] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [006] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [005] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [007] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [008] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [009] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [010] d..h1..   555.401645: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [011] d..h1..   555.401646: ipi_entry:
> (Function call interrupts)
>           insmod-1644    [000] ....1..   555.401908: ipi_raise:
> target_mask=00000000,00000400 (Function call interrupts)
>           <idle>-0       [010] d..h1..   555.401911: ipi_entry:
> (Function call interrupts)
> 
> I am curious why there're two IPI broadcasts to all the other
> cpus(1-11) before the real smp_call_function_single(10) trace
> event(the last two lines of the above trace output), any comments
> about that?

You may want to enable stack trace recording and find out for yourself
where these ipi_raise() calls are coming from.

	M.

-- 
Without deviation from the norm, progress is not possible.

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[Steven Rostedt]

On Thu, 27 Jun 2024 11:38:58 +0100
Marc Zyngier <maz@kernel.org> wrote:

> You may want to enable stack trace recording and find out for yourself
> where these ipi_raise() calls are coming from.

Try trace-cmd:

  # trace-cmd start -e ipi_raise -R 'stacktrace if reason=="Function call interrupts"'
  # taskset -c 0 insmod /kmods/ipi_test.ko
  # trace-cmd stop
  # trace-cmd show

-- Steve

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[richard clark]

Hi M. & Steve:

On Thu, Jun 27, 2024 at 10:12 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Thu, 27 Jun 2024 11:38:58 +0100
> Marc Zyngier <maz@kernel.org> wrote:
>
> > You may want to enable stack trace recording and find out for yourself
> > where these ipi_raise() calls are coming from.
>
> Try trace-cmd:
>
>   # trace-cmd start -e ipi_raise -R 'stacktrace if reason=="Function call interrupts"'
>   # taskset -c 0 insmod /kmods/ipi_test.ko
>   # trace-cmd stop
>   # trace-cmd show
>
          insmod-3169    [000] ....1.. 51869.953886: ipi_raise:
target_mask=00000000,00000ffe (Function call interrupts)
          insmod-3169    [000] ....2.. 51869.953887: <stack trace>
 => trace_event_raw_event_ipi_raise
 => smp_cross_call
 => arch_send_call_function_ipi_mask
 => smp_call_function_many_cond
 => kick_all_cpus_sync
 => load_module
 => __do_sys_finit_module
 => __arm64_sys_finit_module
 => invoke_syscall
 => el0_svc_common.constprop.0
 => do_el0_svc
 => el0_svc
 => el0t_64_sync_handler
 => el0t_64_sync
          insmod-3169    [000] ....1.. 51869.953897: ipi_raise:
target_mask=00000000,00000ffe (Function call interrupts)
          insmod-3169    [000] ....2.. 51869.953898: <stack trace>
 => trace_event_raw_event_ipi_raise
 => smp_cross_call
 => arch_send_call_function_ipi_mask
 => smp_call_function_many_cond
 => kick_all_cpus_sync
 => load_module
 => __do_sys_finit_module
 => __arm64_sys_finit_module
 => invoke_syscall
 => el0_svc_common.constprop.0
 => do_el0_svc
 => el0_svc
 => el0t_64_sync_handler
 => el0t_64_sync
          insmod-3169    [000] ....1.. 51869.954145: ipi_raise:
target_mask=00000000,00000080 (Function call interrupts)
          insmod-3169    [000] ....2.. 51869.954146: <stack trace>
 => trace_event_raw_event_ipi_raise
 => smp_cross_call
 => arch_send_call_function_single_ipi
 => send_call_function_single_ipi
 => generic_exec_single
 => smp_call_function_single
 => run_smp_call_function_test
 => ipi_lat_init
 => do_one_initcall
 => do_init_module
 => load_module

Ah, the first two IPIs raised from the load_module() ->
flush_module_icache() -> flush_icache_range() -> kick_all_cpus_sync()
-> smp_call_function(do_nothing, NULL, 1) chain.
Very powerful and great tool :) Thanks guys!

> -- Steve

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[richard clark]

Hi Steven,

On Thu, Jun 27, 2024 at 10:12 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Thu, 27 Jun 2024 11:38:58 +0100
> Marc Zyngier <maz@kernel.org> wrote:
>
> > You may want to enable stack trace recording and find out for yourself
> > where these ipi_raise() calls are coming from.
>
> Try trace-cmd:
>
>   # trace-cmd start -e ipi_raise -R 'stacktrace if reason=="Function call interrupts"'
>   # taskset -c 0 insmod /kmods/ipi_test.ko
>   # trace-cmd stop
>   # trace-cmd show
>
I found that the 'stacktrace' seems like a stick bit. Run the above
'# trace-cmd start -e ipi_raise -R 'stacktrace if reason=="Function
call interrupts"' ... command sequence, then
# trace-cmd start -e ipi -f 'reason=="Function call interrupts"' -v -e
ipi_exit; taskset -c 0 insmod /kmods/ipi_lat.ko; trace-cmd stop;
trace-cmd show; trace-cmd clear;
The output is:

          insmod-1746    [000] dn.h1..   928.400039: ipi_raise:
target_mask=00000000,000000ffe (Function call interrupts)
          insmod-1746    [000] dn.h2..   928.400042: <stack trace>
 => trace_event_raw_event_ipi_raise
 => smp_cross_call
 => arch_send_call_function_single_ipi
 => send_call_function_single_ipi
...
Actually, the behavior hoped like this(no stacktrace):

          insmod-1677    [000] ....1..   473.474846: ipi_raise:
target_mask=00000000,00000ffe (Function call interrupts)
          <idle>-0       [002] d..h1..   473.474848: ipi_entry:
(Function call interrupts)
          <idle>-0       [003] d..h1..   473.474849: ipi_entry:
(Function call interrupts)
          ...
          insmod-1677    [000] ....1..   473.474859: ipi_raise:
target_mask=00000000,00000ffe (Function call interrupts)
          <idle>-0       [001] d..h1..   473.474861: ipi_entry:
(Function call interrupts) magic=0x55aa55aa
          ...

I tried to add '# trace-cmd stack --stop/reset' before the above
command, but it did not work. Any help to disable the 'stacktrace' in
this scenario?

> -- Steve

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[Steven Rostedt]

On Fri, 28 Jun 2024 18:21:25 +0800
richard clark <richard.xnu.clark@gmail.com> wrote:

> Hi Steven,
> 
> On Thu, Jun 27, 2024 at 10:12 PM Steven Rostedt <rostedt@goodmis.org> wrote:
> >
> > On Thu, 27 Jun 2024 11:38:58 +0100
> > Marc Zyngier <maz@kernel.org> wrote:
> >  
> > > You may want to enable stack trace recording and find out for yourself
> > > where these ipi_raise() calls are coming from.  
> >
> > Try trace-cmd:
> >
> >   # trace-cmd start -e ipi_raise -R 'stacktrace if reason=="Function call interrupts"'
> >   # taskset -c 0 insmod /kmods/ipi_test.ko
> >   # trace-cmd stop
> >   # trace-cmd show
> >  
> I found that the 'stacktrace' seems like a stick bit. Run the above
> '# trace-cmd start -e ipi_raise -R 'stacktrace if reason=="Function
> call interrupts"' ... command sequence, then
> # trace-cmd start -e ipi -f 'reason=="Function call interrupts"' -v -e
> ipi_exit; taskset -c 0 insmod /kmods/ipi_lat.ko; trace-cmd stop;
> trace-cmd show; trace-cmd clear;
> The output is:
> 
>           insmod-1746    [000] dn.h1..   928.400039: ipi_raise:
> target_mask=00000000,000000ffe (Function call interrupts)
>           insmod-1746    [000] dn.h2..   928.400042: <stack trace>
>  => trace_event_raw_event_ipi_raise
>  => smp_cross_call
>  => arch_send_call_function_single_ipi
>  => send_call_function_single_ipi  
> ...
> Actually, the behavior hoped like this(no stacktrace):
> 
>           insmod-1677    [000] ....1..   473.474846: ipi_raise:
> target_mask=00000000,00000ffe (Function call interrupts)
>           <idle>-0       [002] d..h1..   473.474848: ipi_entry:
> (Function call interrupts)
>           <idle>-0       [003] d..h1..   473.474849: ipi_entry:
> (Function call interrupts)
>           ...
>           insmod-1677    [000] ....1..   473.474859: ipi_raise:
> target_mask=00000000,00000ffe (Function call interrupts)
>           <idle>-0       [001] d..h1..   473.474861: ipi_entry:
> (Function call interrupts) magic=0x55aa55aa
>           ...
> 
> I tried to add '# trace-cmd stack --stop/reset' before the above
> command, but it did not work. Any help to disable the 'stacktrace' in
> this scenario?

 trace-cmd reset

will put everything back. But yeah, I need to fix it so that it's easier to
reset triggers.

-- Steve

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[Russell King (Oracle)]

On Fri, Jun 28, 2024 at 06:21:25PM +0800, richard clark wrote:
> The output is:
> 
>           insmod-1746    [000] dn.h1..   928.400039: ipi_raise:
> target_mask=00000000,000000ffe (Function call interrupts)
>           insmod-1746    [000] dn.h2..   928.400042: <stack trace>
>  => trace_event_raw_event_ipi_raise
>  => smp_cross_call
>  => arch_send_call_function_single_ipi
>  => send_call_function_single_ipi

I'm not sure whether the above is misproperly pasted or not, but if it
is correct, it shows a problem.

We can see from the first line that the target mask covers CPUs 1..11.
However, the call chain is for arch_send_call_function_single_ipi(),
which does:

	smp_cross_call(cpumask_of(cpu), IPI_CALL_FUNC);

and cpumask_of(cpu) should only ever contain a single bit, and not
multiple bits which the output above suggests it does!

-- 
RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
FTTP is here! 80Mbps down 10Mbps up. Decent connectivity at last!

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[richard clark]

On Fri, Jun 28, 2024 at 9:13 PM Russell King (Oracle)
<linux@armlinux.org.uk> wrote:
>
> On Fri, Jun 28, 2024 at 06:21:25PM +0800, richard clark wrote:
> > The output is:
> >
> >           insmod-1746    [000] dn.h1..   928.400039: ipi_raise:
> > target_mask=00000000,000000ffe (Function call interrupts)
> >           insmod-1746    [000] dn.h2..   928.400042: <stack trace>
> >  => trace_event_raw_event_ipi_raise
> >  => smp_cross_call
> >  => arch_send_call_function_single_ipi
> >  => send_call_function_single_ipi
>
> I'm not sure whether the above is misproperly pasted or not, but if it
> is correct, it shows a problem.
>
Ah, you're right. Indeed it's pasted improperly, pls ignore it peacefully :)
>
> We can see from the first line that the target mask covers CPUs 1..11.
> However, the call chain is for arch_send_call_function_single_ipi(),
> which does:
>
>         smp_cross_call(cpumask_of(cpu), IPI_CALL_FUNC);
>
> and cpumask_of(cpu) should only ever contain a single bit, and not
> multiple bits which the output above suggests it does!
>
> --
> RMK's Patch system: https://www.armlinux.org.uk/developer/patches/
> FTTP is here! 80Mbps down 10Mbps up. Decent connectivity at last!

Re: Will smp_call_function_single(cpu, ...) broadcast IPI to all other cpus?

[richard clark]

On Fri, Jun 28, 2024 at 8:40 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Fri, 28 Jun 2024 18:21:25 +0800
> richard clark <richard.xnu.clark@gmail.com> wrote:
>
>  trace-cmd reset
>
> will put everything back. But yeah, I need to fix it so that it's easier to
> reset triggers.

works! Thanks steve.

>
> -- Steve