Steven, I just send v2 of this one that has applied your 2 suggestions.
Please check. Thanks!

On Tue, Jan 15, 2019 at 10:25:00PM -0500, Steven Rostedt wrote:

On Tue,  1 Jan 2019 23:46:13 +0800
Changbin Du [off-list ref] wrote:

quoted

This align the behavior of wakeup tracers with irqsoff latency tracer
that we record stacktrace at the beginning and end of waking up. The
stacktrace shows us what is happening in the kernel.

OK, so I've applied (locally) all of the patches in this series except
this one.

quoted

Signed-off-by: Changbin Du <redacted>
---
 kernel/trace/trace_sched_wakeup.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index da5b6e012840..0ec136d408ff 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c

@@ -474,6 +474,8 @@ probe_wakeup_sched_switch(void *ignore, bool preempt,
 	data = per_cpu_ptr(wakeup_trace->trace_buffer.data, wakeup_cpu);
 
 	__trace_function(wakeup_trace, CALLER_ADDR0, CALLER_ADDR1, flags, pc);
+	/* Skip 2 functions to get to the task switch function */
+	__trace_stack(wakeup_trace, flags, 2, pc);

1) Just put in zero for skip. I found that with all the new updates to
the unwinders, you can never get this number right :-(, as well as with
gcc playing games, and retpolines and all that jazz.

quoted

 	tracing_sched_switch_trace(wakeup_trace, prev, next, flags, pc);

2) Have the stack trace go after the sched_switch trace, otherwise it
looks funny:

      285 us |   5)    <idle>-0    |  dN.2 |   1.632 us    |    }
      286 us |   5)    <idle>-0    |  d..3 |   0.000 us    |  __schedule();
  <idle>-0       5d..3  299us : <stack trace>
 => schedule_idle
 => do_idle
 => cpu_startup_entry
 => start_secondary
 => secondary_startup_64
      299 us |   5)    <idle>-0    |  d..3 |               |  /*      0:120:R ==> [005]   811: 98:R i915/signal:0 */

Note, I removed the skip and moved the trace and it looks like this:

      180 us |   3)    <idle>-0    |  dN.2 |   0.944 us    |    }
      181 us |   3)    <idle>-0    |  d..3 |   0.000 us    |  __schedule();
      181 us |   3)    <idle>-0    |  d..3 |               |  /*      0:120:R ==> [003]    25:  0:R migration/3 */
  <idle>-0       3d..3  195us : <stack trace>
 => probe_wakeup_sched_switch
 => __schedule
 => schedule_idle
 => do_idle
 => cpu_startup_entry
 => start_secondary
 => secondary_startup_64

Yeah, it shows the "probe_wakeup_sched" but its better to show too much
than not enough. I've had a hard time debugging some kernels because
the skip was too high.

Please resend this patch with the above updates. Just this patch.

Thanks!

-- Steve

quoted

 
 	T0 = data->preempt_timestamp;

@@ -593,6 +595,8 @@ probe_wakeup(void *ignore, struct task_struct *p)
 	 * it should be safe to use it here.
 	 */
 	__trace_function(wakeup_trace, CALLER_ADDR1, CALLER_ADDR2, flags, pc);
+	/* Skip 2 functions to get to the task wakeup function */
+	__trace_stack(wakeup_trace, flags, 2, pc);
 
 out_locked:
 	arch_spin_unlock(&wakeup_lock);

-- 
Cheers,
Changbin Du