Hi Peter，
Sorry for the late response.
>
> > diff --git a/include/linux/sched.h b/include/linux/sched.h index
> > 93ecd930efd3..edb622c40a90 100644
> > --- a/include/linux/sched.h
> > +++ b/include/linux/sched.h
> > @@ -1324,6 +1324,13 @@ struct task_struct {
> > /* CPU-specific state of this task: */
> > struct thread_struct thread;
> >
> > + /* Task wake up time stamp */
> > + u64 ts_wakeup;
> > + /* Previous task switch out time stamp */
> > + u64 pre_ts_end;
> > + /* Next task switch in time stamp */
> > + u64 next_ts_start;
> > + bool wakeup_state;
> > /*
> > * WARNING: on x86, 'thread_struct' contains a variable-sized
> > * structure. It *MUST* be at the end of 'task_struct'.
>
> ^^^ did you read that comment?
Sorry for my carelessness.
>
> > diff --git a/include/trace/events/sched.h
> > b/include/trace/events/sched.h index fec25b9cfbaf..e99c6d573a42 100644
> > --- a/include/trace/events/sched.h
> > +++ b/include/trace/events/sched.h
> > @@ -183,6 +183,72 @@ TRACE_EVENT(sched_switch,
> > __entry->next_comm, __entry->next_pid, __entry->next_prio) );
> >
> > +DECLARE_EVENT_CLASS(sched_latency_template,
> > +
> > + TP_PROTO(bool preempt,
> > + struct task_struct *prev,
> > + struct task_struct *next,
> > + u64 time),
> > +
> > + TP_ARGS(preempt, prev, next, time),
> > +
> > + TP_STRUCT__entry(
> > + __array( char, prev_comm, TASK_COMM_LEN )
> > + __field( pid_t, prev_pid )
> > + __field( int, prev_prio )
> > + __field( long, prev_state )
> > + __array( char, next_comm, TASK_COMM_LEN )
> > + __field( pid_t, next_pid )
> > + __field( int, next_prio )
> > + __field( u64, time )
> > + ),
> > +
> > + TP_fast_assign(
> > + memcpy(__entry->next_comm, next->comm, TASK_COMM_LEN);
> > + __entry->prev_pid = prev->pid;
> > + __entry->prev_prio = prev->prio;
> > + __entry->prev_state = __trace_sched_switch_state(preempt,
> > prev);
> > + memcpy(__entry->prev_comm, prev->comm, TASK_COMM_LEN);
> > + __entry->next_pid = next->pid;
> > + __entry->next_prio = next->prio;
> > + __entry->time = time;
> > + /* XXX SCHED_DEADLINE */
> > + ),
> > +
> > + TP_printk("prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==>
> > next_comm=%s next_pid=%d next_prio=%d passed
> time=%llu (ns)",
> > + __entry->prev_comm, __entry->prev_pid, __entry->prev_prio,
> > +
> > + (__entry->prev_state & (TASK_REPORT_MAX - 1)) ?
> > + __print_flags(__entry->prev_state & (TASK_REPORT_MAX - 1),
> > "|",
> > + { TASK_INTERRUPTIBLE, "S" },
> > + { TASK_UNINTERRUPTIBLE, "D" },
> > + { __TASK_STOPPED, "T" },
> > + { __TASK_TRACED, "t" },
> > + { EXIT_DEAD, "X" },
> > + { EXIT_ZOMBIE, "Z" },
> > + { TASK_PARKED, "P" },
> > + { TASK_DEAD, "I" }) :
> > + "R",
> > +
> > + __entry->prev_state & TASK_REPORT_MAX ? "+" : "",
> > + __entry->next_comm, __entry->next_pid, __entry->next_prio,
> > + __entry->time)
> > +);
>
> NAK, that tracepoint is already broken, we don't want to proliferate the
> broken.
Sorry, What the meaning that tracepoint is already broken?
Maybe I need to explain the reason that why I add two trace point.
when using perf tool or Ftrace sysfs to capture the task wake-up latency and
the task leaving running queue time, usually the trace data is too large and
the CPU utilization rate is too high in the process due to a lot of disk write.
Sometimes even the disk is full, the issue still does not reproduced that above
two time exceed a certain threshold. So I added two trace points, using filter
we can only record the abnormal trace that includes wakeup latency and leaving
running time larger than an threshold.
Or do you have better solution?
>
> > diff --git a/kernel/sched/core.c b/kernel/sched/core.c index
> > 8471a0f7eb32..b5a1928dc948 100644
> > --- a/kernel/sched/core.c
> > +++ b/kernel/sched/core.c
> > @@ -2464,6 +2464,8 @@ static void ttwu_do_wakeup(struct rq *rq, struct
> > task_struct *p, int wake_flags, {
> > check_preempt_curr(rq, p, wake_flags);
> > p->state = TASK_RUNNING;
> > + p->ts_wakeup = local_clock();
> > + p->wakeup_state = true;
> > trace_sched_wakeup(p);
> >
> > #ifdef CONFIG_SMP
>
> NAK, userless overhead.
When sched switch, we do not know the next task previous state and wakeup
timestamp, so I record the task previous state if it is waken from sleep.
And then it can calculate the wakeup latency when task switch.
>
> > @@ -2846,6 +2848,8 @@ try_to_wake_up(struct task_struct *p, unsigned int
> > state, int wake_flags)
> > success = 1;
> > trace_sched_waking(p);
> > p->state = TASK_RUNNING;
> > + p->ts_wakeup = local_clock();
> > + p->wakeup_state = true;
> > trace_sched_wakeup(p);
> > goto out;
> > }
>
> idem
>
>
> > @@ -3355,6 +3362,8 @@ void wake_up_new_task(struct task_struct *p)
> > post_init_entity_util_avg(p);
> >
> > activate_task(rq, p, ENQUEUE_NOCLOCK);
> > + p->ts_wakeup = local_clock();
> > + p->wakeup_state = true;
> > trace_sched_wakeup_new(p);
> > check_preempt_curr(rq, p, WF_FORK);
> > #ifdef CONFIG_SMP
>
> idem
>
> > @@ -4521,8 +4530,19 @@ static void __sched notrace __schedule(bool
> > preempt)
> >
> > psi_sched_switch(prev, next, !task_on_rq_queued(prev));
> >
> > + next->next_ts_start = prev->pre_ts_end = local_clock();
> > +
> > trace_sched_switch(preempt, prev, next);
> >
> > + if (next->ts_wakeup && next->wakeup_state) {
> > + trace_sched_wakeup_latency(preempt, prev, next,
> > + next->next_ts_start - next->ts_wakeup);
> > + next->wakeup_state = false;
> > + }
> > +
> > + trace_sched_leave_running_time(preempt, prev,
> > + next, next->next_ts_start - next->pre_ts_end);
> > +
> > /* Also unlocks the rq: */
> > rq = context_switch(rq, prev, next, &rf);
> > } else {
>
> This really isn't ever going to happen.
