cpu/hotplug: Add cpuhp_latency trace event

Add ftrace event trace_cpuhp_latency to track cpu
hotplug latency and this entry is useful in power,
performance and debug analysis.

Change-Id: Ie6b2a91027c665ccaf6325b0836bb629a4e91dd7
Signed-off-by: Prasad Sodagudi <psodagud@codeaurora.org>

include/trace/events/cpuhp.h

@@ -6,6 +6,7 @@
 #define _TRACE_CPUHP_H
 
 #include <linux/tracepoint.h>
+#include <linux/sched/clock.h>
 
 TRACE_EVENT(cpuhp_enter,
 
@@ -89,6 +90,34 @@ TRACE_EVENT(cpuhp_exit,
 		  __entry->cpu, __entry->state, __entry->idx,  __entry->ret)
 );
 
+TRACE_EVENT(cpuhp_latency,
+
+	TP_PROTO(unsigned int cpu, unsigned int state,
+		 u64 start_time,  int ret),
+
+	TP_ARGS(cpu, state, start_time, ret),
+
+	TP_STRUCT__entry(
+		__field(unsigned int,	cpu)
+		__field(unsigned int,	state)
+		__field(u64,		time)
+		__field(int,		ret)
+	),
+
+	TP_fast_assign(
+		__entry->cpu	= cpu;
+		__entry->state	= state;
+		__entry->time	= div64_u64(sched_clock() - start_time, 1000);
+		__entry->ret	= ret;
+	),
+
+	TP_printk(" cpu:%d state:%s latency:%llu USEC ret: %d",
+		__entry->cpu, __entry->state ? "online" : "offline",
+		__entry->time, __entry->ret)
+);
+
+
+
 #endif
 
 /* This part must be outside protection */

kernel/cpu.c

@@ -33,6 +33,7 @@
 #include <trace/events/power.h>
 #define CREATE_TRACE_POINTS
 #include <trace/events/cpuhp.h>
+#include <linux/sched/clock.h>
 
 #include "smpboot.h"
 
@@ -856,6 +857,7 @@ static int __ref _cpu_down(unsigned int cpu, int tasks_frozen,
 {
 	struct cpuhp_cpu_state *st = per_cpu_ptr(&cpuhp_state, cpu);
 	int prev_state, ret = 0;
+	u64 start_time = 0;
 
 	if (num_online_cpus() == 1)
 		return -EBUSY;
@@ -864,6 +866,8 @@ static int __ref _cpu_down(unsigned int cpu, int tasks_frozen,
 		return -EINVAL;
 
 	cpus_write_lock();
+	if (trace_cpuhp_latency_enabled())
+		start_time = sched_clock();
 
 	cpuhp_tasks_frozen = tasks_frozen;
 
@@ -902,6 +906,7 @@ static int __ref _cpu_down(unsigned int cpu, int tasks_frozen,
 	}
 
 out:
+	trace_cpuhp_latency(cpu, 0, start_time, ret);
 	cpus_write_unlock();
 	/*
 	 * Do post unplug cleanup. This is still protected against
@@ -986,8 +991,11 @@ static int _cpu_up(unsigned int cpu, int tasks_frozen, enum cpuhp_state target)
 	struct cpuhp_cpu_state *st = per_cpu_ptr(&cpuhp_state, cpu);
 	struct task_struct *idle;
 	int ret = 0;
+	u64 start_time = 0;
 
 	cpus_write_lock();
+	if (trace_cpuhp_latency_enabled())
+		start_time = sched_clock();
 
 	if (!cpu_present(cpu)) {
 		ret = -EINVAL;
@@ -1035,6 +1043,7 @@ static int _cpu_up(unsigned int cpu, int tasks_frozen, enum cpuhp_state target)
 	target = min((int)target, CPUHP_BRINGUP_CPU);
 	ret = cpuhp_up_callbacks(cpu, st, target);
 out:
+	trace_cpuhp_latency(cpu, 1, start_time, ret);
 	cpus_write_unlock();
 	return ret;
 }