[PATCH 1/2] tracing: introduce TRACE_EVENT_FN_COND macro

Subsystems: the rest, tracing

STALE3897d

14 messages, 4 authors, 2015-12-14 · open the first message on its own page

[PATCH 1/2] tracing: introduce TRACE_EVENT_FN_COND macro

From: Denis Kirjanov <hidden>
Date: 2015-11-24 18:25:20

TRACE_EVENT_FN can't be used in some circumstances
like invoking trace functions from offlined CPU due
to RCU usage.

This patch adds the TRACE_EVENT_FN_COND macro
to make such trace points conditional.

Signed-off-by: Denis Kirjanov <redacted>
---
 include/linux/tracepoint.h   | 4 ++++
 include/trace/define_trace.h | 6 ++++++
 include/trace/trace_events.h | 6 ++++++
 3 files changed, 16 insertions(+)
diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index 696a339c..45b3fcf 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -493,6 +493,10 @@ extern void syscall_unregfunc(void);
 #define TRACE_EVENT_FN(name, proto, args, struct,		\
 		assign, print, reg, unreg)			\
 	DECLARE_TRACE(name, PARAMS(proto), PARAMS(args))
+#define TRACE_EVENT_FN_COND(name, proto, args, cond, struct,		\
+		assign, print, reg, unreg)			\
+	DECLARE_TRACE_CONDITION(name, PARAMS(proto),	\
+			PARAMS(args), PARAMS(cond))
 #define TRACE_EVENT_CONDITION(name, proto, args, cond,		\
 			      struct, assign, print)		\
 	DECLARE_TRACE_CONDITION(name, PARAMS(proto),		\
diff --git a/include/trace/define_trace.h b/include/trace/define_trace.h
index 2d8639e..6e3945f 100644
--- a/include/trace/define_trace.h
+++ b/include/trace/define_trace.h
@@ -40,6 +40,11 @@
 		assign, print, reg, unreg)			\
 	DEFINE_TRACE_FN(name, reg, unreg)
 
+#undef TRACE_EVENT_FN_COND
+#define TRACE_EVENT_FN_COND(name, proto, args, cond, tstruct,		\
+		assign, print, reg, unreg)			\
+	DEFINE_TRACE_FN(name, reg, unreg)
+
 #undef DEFINE_EVENT
 #define DEFINE_EVENT(template, name, proto, args) \
 	DEFINE_TRACE(name)
@@ -93,6 +98,7 @@
 
 #undef TRACE_EVENT
 #undef TRACE_EVENT_FN
+#undef TRACE_EVENT_FN_COND
 #undef TRACE_EVENT_CONDITION
 #undef DECLARE_EVENT_CLASS
 #undef DEFINE_EVENT
diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
index de996cf..170c93b 100644
--- a/include/trace/trace_events.h
+++ b/include/trace/trace_events.h
@@ -123,6 +123,12 @@ TRACE_MAKE_SYSTEM_STR();
 	TRACE_EVENT(name, PARAMS(proto), PARAMS(args),			\
 		PARAMS(tstruct), PARAMS(assign), PARAMS(print))		\
 
+#undef TRACE_EVENT_FN_COND
+#define TRACE_EVENT_FN_COND(name, proto, args, cond, tstruct,	\
+		assign, print, reg, unreg)				\
+	TRACE_EVENT_CONDITION(name, PARAMS(proto), PARAMS(args), PARAMS(cond),		\
+		PARAMS(tstruct), PARAMS(assign), PARAMS(print))		\
+
 #undef TRACE_EVENT_FLAGS
 #define TRACE_EVENT_FLAGS(name, value)					\
 	__TRACE_EVENT_FLAGS(name, value)
-- 
2.4.0

[PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Denis Kirjanov <hidden>
Date: 2015-11-24 18:25:37

./drmgr -c cpu -a -r gives the following warning:

[ 2327.035563]
RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[ 2327.035564] no locks held by swapper/12/0.
[ 2327.035565]
stack backtrace:
[ 2327.035567] CPU: 12 PID: 0 Comm: swapper/12 Tainted: G S
  4.3.0-rc3-00060-g353169a #5
  [ 2327.035568] Call Trace:
  [ 2327.035573] [c0000001d62578e0] [c0000000008977fc]
  .dump_stack+0x98/0xd4 (unreliable)
  [ 2327.035577] [c0000001d6257960] [c000000000109bd8]
  .lockdep_rcu_suspicious+0x108/0x170
  [ 2327.035580] [c0000001d62579f0] [c00000000006a1d0]
  .__trace_hcall_exit+0x2b0/0x2c0
  [ 2327.035584] [c0000001d6257ab0] [c00000000006a2e8]
  plpar_hcall_norets_trace+0x70/0x8c
  [ 2327.035588] [c0000001d6257b20] [c000000000067a14]
  .icp_hv_set_cpu_priority+0x54/0xc0
  [ 2327.035592] [c0000001d6257ba0] [c000000000066c5c]
  .xics_teardown_cpu+0x5c/0xa0
  [ 2327.035595] [c0000001d6257c20] [c0000000000747ac]
  .pseries_mach_cpu_die+0x6c/0x320
  [ 2327.035598] [c0000001d6257cd0] [c0000000000439cc]
  .cpu_die+0x3c/0x60
  [ 2327.035602] [c0000001d6257d40] [c0000000000183d8]
  .arch_cpu_idle_dead+0x28/0x40
  [ 2327.035606] [c0000001d6257db0] [c0000000000ff1dc]
  .cpu_startup_entry+0x4fc/0x560
  [ 2327.035610] [c0000001d6257ed0] [c000000000043728]
  .start_secondary+0x328/0x360
  [ 2327.035614] [c0000001d6257f90] [c000000000008a6c]
  start_secondary_prolog+0x10/0x14
  [ 2327.035620] cpu 12 (hwid 12) Ready to die...
  [ 2327.144463] cpu 13 (hwid 13) Ready to die...
  [ 2327.294180] cpu 14 (hwid 14) Ready to die...
  [ 2327.403599] cpu 15 (hwid 15) Ready to die...

  Make the hypervisor tracepoints conditional by using
  TRACE_EVENT_FN_COND

Signed-off-by: Denis Kirjanov <redacted>
---
 arch/powerpc/include/asm/trace.h | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)
diff --git a/arch/powerpc/include/asm/trace.h b/arch/powerpc/include/asm/trace.h
index 8e86b48..3dc5803 100644
--- a/arch/powerpc/include/asm/trace.h
+++ b/arch/powerpc/include/asm/trace.h
@@ -57,12 +57,14 @@ DEFINE_EVENT(ppc64_interrupt_class, timer_interrupt_exit,
 extern void hcall_tracepoint_regfunc(void);
 extern void hcall_tracepoint_unregfunc(void);
 
-TRACE_EVENT_FN(hcall_entry,
+TRACE_EVENT_FN_COND(hcall_entry,
 
 	TP_PROTO(unsigned long opcode, unsigned long *args),
 
 	TP_ARGS(opcode, args),
 
+	TP_CONDITION(cpu_online(smp_processor_id())),
+
 	TP_STRUCT__entry(
 		__field(unsigned long, opcode)
 	),
@@ -76,13 +78,15 @@ TRACE_EVENT_FN(hcall_entry,
 	hcall_tracepoint_regfunc, hcall_tracepoint_unregfunc
 );
 
-TRACE_EVENT_FN(hcall_exit,
+TRACE_EVENT_FN_COND(hcall_exit,
 
 	TP_PROTO(unsigned long opcode, unsigned long retval,
 		unsigned long *retbuf),
 
 	TP_ARGS(opcode, retval, retbuf),
 
+	TP_CONDITION(cpu_online(smp_processor_id())),
+
 	TP_STRUCT__entry(
 		__field(unsigned long, opcode)
 		__field(unsigned long, retval)
-- 
2.4.0

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Michael Ellerman <mpe@ellerman.id.au>
Date: 2015-11-26 06:39:31

On Tue, 2015-11-24 at 21:23 +0300, Denis Kirjanov wrote:
./drmgr -c cpu -a -r gives the following warning:

[ 2327.035563] RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[ 2327.035564] no locks held by swapper/12/0.
[ 2327.035565] stack backtrace:
[ 2327.035567] CPU: 12 PID: 0 Comm: swapper/12 Tainted: G S >   4.3.0-rc3-00060-g353169a #5
[ 2327.035568] Call Trace:
[ 2327.035573] [c0000001d62578e0] [c0000000008977fc] .dump_stack+0x98/0xd4 (unreliable)
[ 2327.035577] [c0000001d6257960] [c000000000109bd8] .lockdep_rcu_suspicious+0x108/0x170
[ 2327.035580] [c0000001d62579f0] [c00000000006a1d0] .__trace_hcall_exit+0x2b0/0x2c0
[ 2327.035584] [c0000001d6257ab0] [c00000000006a2e8] plpar_hcall_norets_trace+0x70/0x8c
[ 2327.035588] [c0000001d6257b20] [c000000000067a14] .icp_hv_set_cpu_priority+0x54/0xc0
[ 2327.035592] [c0000001d6257ba0] [c000000000066c5c] .xics_teardown_cpu+0x5c/0xa0
[ 2327.035595] [c0000001d6257c20] [c0000000000747ac] .pseries_mach_cpu_die+0x6c/0x320
[ 2327.035598] [c0000001d6257cd0] [c0000000000439cc] .cpu_die+0x3c/0x60
[ 2327.035602] [c0000001d6257d40] [c0000000000183d8] .arch_cpu_idle_dead+0x28/0x40
[ 2327.035606] [c0000001d6257db0] [c0000000000ff1dc] .cpu_startup_entry+0x4fc/0x560
[ 2327.035610] [c0000001d6257ed0] [c000000000043728] .start_secondary+0x328/0x360
[ 2327.035614] [c0000001d6257f90] [c000000000008a6c] start_secondary_prolog+0x10/0x14
[ 2327.035620] cpu 12 (hwid 12) Ready to die...
[ 2327.144463] cpu 13 (hwid 13) Ready to die...
[ 2327.294180] cpu 14 (hwid 14) Ready to die...
[ 2327.403599] cpu 15 (hwid 15) Ready to die...

I can't get this to hit.

I've got LOCKDEP=y, I've enabled the hcall tracepoints, and then I offline a
cpu via sysfs.

What am I missing? Or does it only hit when you use drmgr?

cheers

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Denis Kirjanov <hidden>
Date: 2015-11-26 08:15:44

On 11/26/15, Michael Ellerman [off-list ref] wrote:
On Tue, 2015-11-24 at 21:23 +0300, Denis Kirjanov wrote:
quoted
./drmgr -c cpu -a -r gives the following warning:

[ 2327.035563] RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[ 2327.035564] no locks held by swapper/12/0.
[ 2327.035565] stack backtrace:
[ 2327.035567] CPU: 12 PID: 0 Comm: swapper/12 Tainted: G S >
4.3.0-rc3-00060-g353169a #5
[ 2327.035568] Call Trace:
[ 2327.035573] [c0000001d62578e0] [c0000000008977fc] .dump_stack+0x98/0xd4
(unreliable)
[ 2327.035577] [c0000001d6257960] [c000000000109bd8]
.lockdep_rcu_suspicious+0x108/0x170
[ 2327.035580] [c0000001d62579f0] [c00000000006a1d0]
.__trace_hcall_exit+0x2b0/0x2c0
[ 2327.035584] [c0000001d6257ab0] [c00000000006a2e8]
plpar_hcall_norets_trace+0x70/0x8c
[ 2327.035588] [c0000001d6257b20] [c000000000067a14]
.icp_hv_set_cpu_priority+0x54/0xc0
[ 2327.035592] [c0000001d6257ba0] [c000000000066c5c]
.xics_teardown_cpu+0x5c/0xa0
[ 2327.035595] [c0000001d6257c20] [c0000000000747ac]
.pseries_mach_cpu_die+0x6c/0x320
[ 2327.035598] [c0000001d6257cd0] [c0000000000439cc] .cpu_die+0x3c/0x60
[ 2327.035602] [c0000001d6257d40] [c0000000000183d8]
.arch_cpu_idle_dead+0x28/0x40
[ 2327.035606] [c0000001d6257db0] [c0000000000ff1dc]
.cpu_startup_entry+0x4fc/0x560
[ 2327.035610] [c0000001d6257ed0] [c000000000043728]
.start_secondary+0x328/0x360
[ 2327.035614] [c0000001d6257f90] [c000000000008a6c]
start_secondary_prolog+0x10/0x14
[ 2327.035620] cpu 12 (hwid 12) Ready to die...
[ 2327.144463] cpu 13 (hwid 13) Ready to die...
[ 2327.294180] cpu 14 (hwid 14) Ready to die...
[ 2327.403599] cpu 15 (hwid 15) Ready to die...

I can't get this to hit.

I've got LOCKDEP=y, I've enabled the hcall tracepoints, and then I offline
a
cpu via sysfs.
I haven't tried it via sysfs. Could you share the command
so I give a try to reproduce.
What am I missing? Or does it only hit when you use drmgr?
Right, I hit it with drmgr...
cheers

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Michael Ellerman <mpe@ellerman.id.au>
Date: 2015-11-26 09:26:46

On Thu, 2015-11-26 at 11:15 +0300, Denis Kirjanov wrote:
On 11/26/15, Michael Ellerman [off-list ref] wrote:
quoted
On Tue, 2015-11-24 at 21:23 +0300, Denis Kirjanov wrote:
I can't get this to hit.

I've got LOCKDEP=y, I've enabled the hcall tracepoints, and then I offline
a cpu via sysfs.
I haven't tried it via sysfs. Could you share the command
so I give a try to reproduce.
Either manually:

$ echo 0 > /sys/devices/system/cpuN/online

Or using:

$ ppc64_cpu --cores-on=1
and/or
$ ppc64_cpu --smt=1

Which uses sysfs.

cheers

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Denis Kirjanov <hidden>
Date: 2015-11-26 20:10:55

On 11/26/15, Michael Ellerman [off-list ref] wrote:
On Thu, 2015-11-26 at 11:15 +0300, Denis Kirjanov wrote:
quoted
On 11/26/15, Michael Ellerman [off-list ref] wrote:
quoted
On Tue, 2015-11-24 at 21:23 +0300, Denis Kirjanov wrote:
I can't get this to hit.

I've got LOCKDEP=y, I've enabled the hcall tracepoints, and then I
offline
a cpu via sysfs.
quoted
I haven't tried it via sysfs. Could you share the command
so I give a try to reproduce.
Either manually:

$ echo 0 > /sys/devices/system/cpuN/online

Or using:

$ ppc64_cpu --cores-on=1
and/or
$ ppc64_cpu --smt=1
Ok, I hit the WARNING:
(the tree is dirty since I'm investigating the networking csum failure
with ipv6)
config attached.

[   88.249496] ===============================
[   88.249499] [ INFO: suspicious RCU usage. ]
[   88.249502] 4.4.0-rc2-00011-gb4f8144-dirty #20 Tainted: G S
[   88.249503] -------------------------------
[   88.249505] ./arch/powerpc/include/asm/trace.h:77 suspicious
rcu_dereference_check() usage!
[   88.249506]
other info that might help us debug this:

[   88.249508]
RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[   88.249510] no locks held by swapper/15/0.
[   88.249511]
stack backtrace:
[   88.249514] CPU: 15 PID: 0 Comm: swapper/15 Tainted: G S
  4.4.0-rc2-00011-gb4f8144-dirty #20
[   88.249516] Call Trace:
[   88.249525] [c0000005b76e38f0] [c00000000089cb00]
.dump_stack+0x98/0xd4 (unreliable)
[   88.249529] [c0000005b76e3970] [c00000000010a458]
.lockdep_rcu_suspicious+0x108/0x170
[   88.249533] [c0000005b76e3a00] [c000000000069cd0]
.__trace_hcall_entry+0x260/0x2b0
[   88.249536] [c0000005b76e3ab0] [c00000000006a0ac]
plpar_hcall_norets_trace+0x34/0x8c
[   88.249539] [c0000005b76e3b20] [c000000000067704]
.icp_hv_set_cpu_priority+0x54/0xc0
[   88.249542] [c0000005b76e3ba0] [c00000000006694c]
.xics_teardown_cpu+0x5c/0xa0
[   88.249545] [c0000005b76e3c20] [c0000000000745fc]
.pseries_mach_cpu_die+0x6c/0x320
[   88.249549] [c0000005b76e3cd0] [c0000000000438dc] .cpu_die+0x3c/0x60
[   88.249552] [c0000005b76e3d40] [c000000000018398]
.arch_cpu_idle_dead+0x28/0x40
[   88.249555] [c0000005b76e3db0] [c0000000000ffa1c]
.cpu_startup_entry+0x4fc/0x560
[   88.249558] [c0000005b76e3ed0] [c000000000043638]
.start_secondary+0x328/0x360
[   88.249562] [c0000005b76e3f90] [c000000000008a6c]
start_secondary_prolog+0x10/0x14

[   88.249564] ===============================
[   88.249564] [ INFO: suspicious RCU usage. ]
[   88.249566] 4.4.0-rc2-00011-gb4f8144-dirty #20 Tainted: G S
[   88.249566] -------------------------------
[   88.249568] ./arch/powerpc/include/asm/trace.h:77 suspicious
rcu_dereference_check() usage!
[   88.249569]
other info that might help us debug this:

[   88.249570]
RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[   88.249571] no locks held by swapper/15/0.
[   88.249572]
stack backtrace:
[   88.249574] CPU: 15 PID: 0 Comm: swapper/15 Tainted: G S
  4.4.0-rc2-00011-gb4f8144-dirty #20
[   88.249574] Call Trace:
[   88.249578] [c0000005b76e38f0] [c00000000089cb00]
.dump_stack+0x98/0xd4 (unreliable)
[   88.249581] [c0000005b76e3970] [c00000000010a458]
.lockdep_rcu_suspicious+0x108/0x170
[   88.249584] [c0000005b76e3a00] [c000000000069d10]
.__trace_hcall_entry+0x2a0/0x2b0
[   88.249587] [c0000005b76e3ab0] [c00000000006a0ac]
plpar_hcall_norets_trace+0x34/0x8c
[   88.249590] [c0000005b76e3b20] [c000000000067704]
.icp_hv_set_cpu_priority+0x54/0xc0
[   88.249593] [c0000005b76e3ba0] [c00000000006694c]
.xics_teardown_cpu+0x5c/0xa0
[   88.249596] [c0000005b76e3c20] [c0000000000745fc]
.pseries_mach_cpu_die+0x6c/0x320
[   88.249599] [c0000005b76e3cd0] [c0000000000438dc] .cpu_die+0x3c/0x60
[   88.249602] [c0000005b76e3d40] [c000000000018398]
.arch_cpu_idle_dead+0x28/0x40
[   88.249605] [c0000005b76e3db0] [c0000000000ffa1c]
.cpu_startup_entry+0x4fc/0x560
[   88.249608] [c0000005b76e3ed0] [c000000000043638]
.start_secondary+0x328/0x360
[   88.249611] [c0000005b76e3f90] [c000000000008a6c]
start_secondary_prolog+0x10/0x14

[   88.249613] ===============================
[   88.249613] [ INFO: suspicious RCU usage. ]
[   88.249615] 4.4.0-rc2-00011-gb4f8144-dirty #20 Tainted: G S
[   88.249615] -------------------------------
[   88.249617] ./arch/powerpc/include/asm/trace.h:99 suspicious
rcu_dereference_check() usage!
[   88.249617]
other info that might help us debug this:

[   88.249619]
RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[   88.249620] no locks held by swapper/15/0.
[   88.249620]
stack backtrace:
[   88.249622] CPU: 15 PID: 0 Comm: swapper/15 Tainted: G S
  4.4.0-rc2-00011-gb4f8144-dirty #20
[   88.249623] Call Trace:
[   88.249626] [c0000005b76e38e0] [c00000000089cb00]
.dump_stack+0x98/0xd4 (unreliable)
[   88.249629] [c0000005b76e3960] [c00000000010a458]
.lockdep_rcu_suspicious+0x108/0x170
[   88.249632] [c0000005b76e39f0] [c000000000069f90]
.__trace_hcall_exit+0x270/0x2c0
[   88.249635] [c0000005b76e3ab0] [c00000000006a0e8]
plpar_hcall_norets_trace+0x70/0x8c
[   88.249638] [c0000005b76e3b20] [c000000000067704]
.icp_hv_set_cpu_priority+0x54/0xc0
[   88.249641] [c0000005b76e3ba0] [c00000000006694c]
.xics_teardown_cpu+0x5c/0xa0
[   88.249644] [c0000005b76e3c20] [c0000000000745fc]
.pseries_mach_cpu_die+0x6c/0x320
[   88.249647] [c0000005b76e3cd0] [c0000000000438dc] .cpu_die+0x3c/0x60
[   88.249650] [c0000005b76e3d40] [c000000000018398]
.arch_cpu_idle_dead+0x28/0x40
[   88.249653] [c0000005b76e3db0] [c0000000000ffa1c]
.cpu_startup_entry+0x4fc/0x560
[   88.249656] [c0000005b76e3ed0] [c000000000043638]
.start_secondary+0x328/0x360
[   88.249659] [c0000005b76e3f90] [c000000000008a6c]
start_secondary_prolog+0x10/0x14

[   88.249660] ===============================
[   88.249661] [ INFO: suspicious RCU usage. ]
[   88.249662] 4.4.0-rc2-00011-gb4f8144-dirty #20 Tainted: G S
[   88.249663] -------------------------------
[   88.249664] ./arch/powerpc/include/asm/trace.h:99 suspicious
rcu_dereference_check() usage!
[   88.249665]
other info that might help us debug this:

[   88.249666]
RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[   88.249667] no locks held by swapper/15/0.
[   88.249668]
stack backtrace:
[   88.249670] CPU: 15 PID: 0 Comm: swapper/15 Tainted: G S
  4.4.0-rc2-00011-gb4f8144-dirty #20
[   88.249670] Call Trace:
[   88.249673] [c0000005b76e38e0] [c00000000089cb00]
.dump_stack+0x98/0xd4 (unreliable)
[   88.249677] [c0000005b76e3960] [c00000000010a458]
.lockdep_rcu_suspicious+0x108/0x170
[   88.249680] [c0000005b76e39f0] [c000000000069fd0]
.__trace_hcall_exit+0x2b0/0x2c0
[   88.249682] [c0000005b76e3ab0] [c00000000006a0e8]
plpar_hcall_norets_trace+0x70/0x8c
[   88.249686] [c0000005b76e3b20] [c000000000067704]
.icp_hv_set_cpu_priority+0x54/0xc0
[   88.249689] [c0000005b76e3ba0] [c00000000006694c]
.xics_teardown_cpu+0x5c/0xa0
[   88.249691] [c0000005b76e3c20] [c0000000000745fc]
.pseries_mach_cpu_die+0x6c/0x320
[   88.249694] [c0000005b76e3cd0] [c0000000000438dc] .cpu_die+0x3c/0x60
[   88.249697] [c0000005b76e3d40] [c000000000018398]
.arch_cpu_idle_dead+0x28/0x40
[   88.249700] [c0000005b76e3db0] [c0000000000ffa1c]
.cpu_startup_entry+0x4fc/0x560
[   88.249703] [c0000005b76e3ed0] [c000000000043638]
.start_secondary+0x328/0x360
[   88.249706] [c0000005b76e3f90] [c000000000008a6c]
start_secondary_prolog+0x10/0x14
ps700_1 src #

Which uses sysfs.

cheers

Re: [PATCH 1/2] tracing: introduce TRACE_EVENT_FN_COND macro

From: Denis Kirjanov <hidden>
Date: 2015-12-07 14:42:45

On 11/24/15, Denis Kirjanov [off-list ref] wrote:
TRACE_EVENT_FN can't be used in some circumstances
like invoking trace functions from offlined CPU due
to RCU usage.

This patch adds the TRACE_EVENT_FN_COND macro
to make such trace points conditional.

Signed-off-by: Denis Kirjanov <redacted>
Hi Steven,
are you going to take this series through your tree?

Thanks!
quoted hunk
---
 include/linux/tracepoint.h   | 4 ++++
 include/trace/define_trace.h | 6 ++++++
 include/trace/trace_events.h | 6 ++++++
 3 files changed, 16 insertions(+)
diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index 696a339c..45b3fcf 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -493,6 +493,10 @@ extern void syscall_unregfunc(void);
 #define TRACE_EVENT_FN(name, proto, args, struct,		\
 		assign, print, reg, unreg)			\
 	DECLARE_TRACE(name, PARAMS(proto), PARAMS(args))
+#define TRACE_EVENT_FN_COND(name, proto, args, cond, struct,		\
+		assign, print, reg, unreg)			\
+	DECLARE_TRACE_CONDITION(name, PARAMS(proto),	\
+			PARAMS(args), PARAMS(cond))
 #define TRACE_EVENT_CONDITION(name, proto, args, cond,		\
 			      struct, assign, print)		\
 	DECLARE_TRACE_CONDITION(name, PARAMS(proto),		\
diff --git a/include/trace/define_trace.h b/include/trace/define_trace.h
index 2d8639e..6e3945f 100644
--- a/include/trace/define_trace.h
+++ b/include/trace/define_trace.h
@@ -40,6 +40,11 @@
 		assign, print, reg, unreg)			\
 	DEFINE_TRACE_FN(name, reg, unreg)

+#undef TRACE_EVENT_FN_COND
+#define TRACE_EVENT_FN_COND(name, proto, args, cond, tstruct,		\
+		assign, print, reg, unreg)			\
+	DEFINE_TRACE_FN(name, reg, unreg)
+
 #undef DEFINE_EVENT
 #define DEFINE_EVENT(template, name, proto, args) \
 	DEFINE_TRACE(name)
@@ -93,6 +98,7 @@

 #undef TRACE_EVENT
 #undef TRACE_EVENT_FN
+#undef TRACE_EVENT_FN_COND
 #undef TRACE_EVENT_CONDITION
 #undef DECLARE_EVENT_CLASS
 #undef DEFINE_EVENT
diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
index de996cf..170c93b 100644
--- a/include/trace/trace_events.h
+++ b/include/trace/trace_events.h
@@ -123,6 +123,12 @@ TRACE_MAKE_SYSTEM_STR();
 	TRACE_EVENT(name, PARAMS(proto), PARAMS(args),			\
 		PARAMS(tstruct), PARAMS(assign), PARAMS(print))		\

+#undef TRACE_EVENT_FN_COND
+#define TRACE_EVENT_FN_COND(name, proto, args, cond, tstruct,	\
+		assign, print, reg, unreg)				\
+	TRACE_EVENT_CONDITION(name, PARAMS(proto), PARAMS(args), PARAMS(cond),		\
+		PARAMS(tstruct), PARAMS(assign), PARAMS(print))		\
+
 #undef TRACE_EVENT_FLAGS
 #define TRACE_EVENT_FLAGS(name, value)					\
 	__TRACE_EVENT_FLAGS(name, value)
--
2.4.0

Re: [PATCH 1/2] tracing: introduce TRACE_EVENT_FN_COND macro

From: Steven Rostedt <rostedt@goodmis.org>
Date: 2015-12-07 14:58:11

On Mon, 7 Dec 2015 17:42:42 +0300
Denis Kirjanov [off-list ref] wrote:
On 11/24/15, Denis Kirjanov [off-list ref] wrote:
quoted
TRACE_EVENT_FN can't be used in some circumstances
like invoking trace functions from offlined CPU due
to RCU usage.

This patch adds the TRACE_EVENT_FN_COND macro
to make such trace points conditional.

Signed-off-by: Denis Kirjanov <redacted>  
Hi Steven,
are you going to take this series through your tree?
Yeah, thanks for the reminder!

-- Steve

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Steven Rostedt <rostedt@goodmis.org>
Date: 2015-12-07 20:52:30

I can take this series through my tree, but I need a acked-by from a
PPC maintainer for this patch.

-- Steve


On Tue, 24 Nov 2015 21:23:39 +0300
Denis Kirjanov [off-list ref] wrote:
quoted hunk
./drmgr -c cpu -a -r gives the following warning:

[ 2327.035563]
RCU used illegally from offline CPU!
rcu_scheduler_active = 1, debug_locks = 1
[ 2327.035564] no locks held by swapper/12/0.
[ 2327.035565]
stack backtrace:
[ 2327.035567] CPU: 12 PID: 0 Comm: swapper/12 Tainted: G S
  4.3.0-rc3-00060-g353169a #5
  [ 2327.035568] Call Trace:
  [ 2327.035573] [c0000001d62578e0] [c0000000008977fc]
  .dump_stack+0x98/0xd4 (unreliable)
  [ 2327.035577] [c0000001d6257960] [c000000000109bd8]
  .lockdep_rcu_suspicious+0x108/0x170
  [ 2327.035580] [c0000001d62579f0] [c00000000006a1d0]
  .__trace_hcall_exit+0x2b0/0x2c0
  [ 2327.035584] [c0000001d6257ab0] [c00000000006a2e8]
  plpar_hcall_norets_trace+0x70/0x8c
  [ 2327.035588] [c0000001d6257b20] [c000000000067a14]
  .icp_hv_set_cpu_priority+0x54/0xc0
  [ 2327.035592] [c0000001d6257ba0] [c000000000066c5c]
  .xics_teardown_cpu+0x5c/0xa0
  [ 2327.035595] [c0000001d6257c20] [c0000000000747ac]
  .pseries_mach_cpu_die+0x6c/0x320
  [ 2327.035598] [c0000001d6257cd0] [c0000000000439cc]
  .cpu_die+0x3c/0x60
  [ 2327.035602] [c0000001d6257d40] [c0000000000183d8]
  .arch_cpu_idle_dead+0x28/0x40
  [ 2327.035606] [c0000001d6257db0] [c0000000000ff1dc]
  .cpu_startup_entry+0x4fc/0x560
  [ 2327.035610] [c0000001d6257ed0] [c000000000043728]
  .start_secondary+0x328/0x360
  [ 2327.035614] [c0000001d6257f90] [c000000000008a6c]
  start_secondary_prolog+0x10/0x14
  [ 2327.035620] cpu 12 (hwid 12) Ready to die...
  [ 2327.144463] cpu 13 (hwid 13) Ready to die...
  [ 2327.294180] cpu 14 (hwid 14) Ready to die...
  [ 2327.403599] cpu 15 (hwid 15) Ready to die...

  Make the hypervisor tracepoints conditional by using
  TRACE_EVENT_FN_COND

Signed-off-by: Denis Kirjanov <redacted>
---
 arch/powerpc/include/asm/trace.h | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)
diff --git a/arch/powerpc/include/asm/trace.h b/arch/powerpc/include/asm/trace.h
index 8e86b48..3dc5803 100644
--- a/arch/powerpc/include/asm/trace.h
+++ b/arch/powerpc/include/asm/trace.h
@@ -57,12 +57,14 @@ DEFINE_EVENT(ppc64_interrupt_class, timer_interrupt_exit,
 extern void hcall_tracepoint_regfunc(void);
 extern void hcall_tracepoint_unregfunc(void);
 
-TRACE_EVENT_FN(hcall_entry,
+TRACE_EVENT_FN_COND(hcall_entry,
 
 	TP_PROTO(unsigned long opcode, unsigned long *args),
 
 	TP_ARGS(opcode, args),
 
+	TP_CONDITION(cpu_online(smp_processor_id())),
+
 	TP_STRUCT__entry(
 		__field(unsigned long, opcode)
 	),
@@ -76,13 +78,15 @@ TRACE_EVENT_FN(hcall_entry,
 	hcall_tracepoint_regfunc, hcall_tracepoint_unregfunc
 );
 
-TRACE_EVENT_FN(hcall_exit,
+TRACE_EVENT_FN_COND(hcall_exit,
 
 	TP_PROTO(unsigned long opcode, unsigned long retval,
 		unsigned long *retbuf),
 
 	TP_ARGS(opcode, retval, retbuf),
 
+	TP_CONDITION(cpu_online(smp_processor_id())),
+
 	TP_STRUCT__entry(
 		__field(unsigned long, opcode)
 		__field(unsigned long, retval)

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Date: 2015-12-07 21:02:31

On Mon, 2015-12-07 at 15:52 -0500, Steven Rostedt wrote:
quoted
+     TP_CONDITION(cpu_online(smp_processor_id())),
+
This should probably be some kind of __raw version though, hcalls can
be called in contexts where the debug stuff in smp_processor_id() isn't
safe (or preempt enabled).

Cheers,
Ben.

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Steven Rostedt <rostedt@goodmis.org>
Date: 2015-12-07 21:34:52

On Tue, 08 Dec 2015 08:02:15 +1100
Benjamin Herrenschmidt [off-list ref] wrote:
On Mon, 2015-12-07 at 15:52 -0500, Steven Rostedt wrote:
quoted
quoted
+=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0TP_CONDITION(cpu_online(smp_processor_=
id())),
quoted
quoted
+ =20
=20
This should probably be some kind of __raw version though, hcalls can
be called in contexts where the debug stuff in smp_processor_id() isn't
safe (or preempt enabled).
=20
OK, then that needs to be updated.

-- Steve

Re: [PATCH 1/2] tracing: introduce TRACE_EVENT_FN_COND macro

From: Steven Rostedt <rostedt@goodmis.org>
Date: 2015-12-11 19:40:54

On Mon, 7 Dec 2015 17:42:42 +0300
Denis Kirjanov [off-list ref] wrote:
On 11/24/15, Denis Kirjanov [off-list ref] wrote:
quoted
TRACE_EVENT_FN can't be used in some circumstances
like invoking trace functions from offlined CPU due
to RCU usage.

This patch adds the TRACE_EVENT_FN_COND macro
to make such trace points conditional.

Signed-off-by: Denis Kirjanov <redacted>  
Hi Steven,
are you going to take this series through your tree?
I haven't gotten an ack for the powerpc side yet. I can take the
tracing patch, but I'm not pulling in powerpc without an ack from one
of the maintainers. Maybe I got it already, but I don't see it in my
INBOX in this thread.

-- Steve

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Michael Ellerman <mpe@ellerman.id.au>
Date: 2015-12-14 10:00:49

On Mon, 2015-12-07 at 16:33 -0500, Steven Rostedt wrote:
On Tue, 08 Dec 2015 08:02:15 +1100
Benjamin Herrenschmidt [off-list ref] wrote:
quoted
On Mon, 2015-12-07 at 15:52 -0500, Steven Rostedt wrote:
quoted
quoted
+     TP_CONDITION(cpu_online(smp_processor_id())),
+  
This should probably be some kind of __raw version though, hcalls can
be called in contexts where the debug stuff in smp_processor_id() isn't
safe (or preempt enabled).
OK, then that needs to be updated.
Denis, please respin with raw_smp_processor_id().

cheers

Re: [PATCH 2/2] powerpc: tracing: don't trace hcalls on offline CPUs

From: Denis Kirjanov <hidden>
Date: 2015-12-14 10:05:50

On 12/14/15, Michael Ellerman [off-list ref] wrote:
On Mon, 2015-12-07 at 16:33 -0500, Steven Rostedt wrote:
quoted
On Tue, 08 Dec 2015 08:02:15 +1100
Benjamin Herrenschmidt [off-list ref] wrote:
quoted
On Mon, 2015-12-07 at 15:52 -0500, Steven Rostedt wrote:
quoted
quoted
+     TP_CONDITION(cpu_online(smp_processor_id())),
+
This should probably be some kind of __raw version though, hcalls can
be called in contexts where the debug stuff in smp_processor_id() isn't
safe (or preempt enabled).
OK, then that needs to be updated.
Denis, please respin with raw_smp_processor_id().
Sure, I'll respin today.

Thanks!
cheers
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help