Re: [tip:sched/core] sched: Add wait, sleep and iowait accounting tracepoints

Peter Zijlstra
2009-08-03T14:39:15Z

On Mon, 2009-08-03 at 15:24 +0200, Ingo Molnar wrote:
> * tip-bot for Peter Zijlstra <a.p.zijlstra@chello.nl> wrote:
>
> > Commit-ID: 5f3e60fb2a0e05cdaf9b59acb0bb249bb1e96362
> > Gitweb: http://git.kernel.org/tip/5f3e60fb2a0e05cdaf9b59acb0bb249bb1e96362
> > Author: Peter Zijlstra <a.p.zijlstra@chello.nl>
> > AuthorDate: Thu, 23 Jul 2009 20:13:26 +0200
> > Committer: Ingo Molnar <mingo@elte.hu>
> > CommitDate: Mon, 3 Aug 2009 14:35:37 +0200
>
> > --- a/kernel/sched_fair.c
> > +++ b/kernel/sched_fair.c
> > @@ -546,6 +546,11 @@ update_stats_wait_end(struct cfs_rq *cfs_rq, struct sched_entity *se)
> > schedstat_set(se->wait_sum, se->wait_sum +
> > rq_of(cfs_rq)->clock - se->wait_start);
> > schedstat_set(se->wait_start, 0);
> > +
> > + if (entity_is_task(se)) {
> > + trace_sched_stat_wait(task_of(se),
> > + rq_of(cfs_rq)->clock - se->wait_start);
> > + }
>
> FYI, this doesnt build with !SCHEDSTATS. I suspect we shold maintain
> se->wait_start unconditionally.

Also noticed that we have this TASK_INTERRUPTIBLE vs
TASK_UNINTERRUPTIBLE split in sleep vs block which I overlooked the
other day.

Since all the other trace_sched_stat tracepoints are under
CONFIG_SCHEDSTAT I fixed the above error by adding ifdefs.

This probably wants folding back into the original patch.

Signed-off-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
---
include/trace/events/sched.h | 36 ++++++++++++++++++++++++++++++++----
kernel/sched_fair.c | 3 +++
2 files changed, 35 insertions(+), 4 deletions(-)

diff --git a/include/trace/events/sched.h b/include/trace/events/sched.h
index a4c369e..c201b51 100644
--- a/include/trace/events/sched.h
+++ b/include/trace/events/sched.h
@@ -376,8 +376,7 @@ TRACE_EVENT(sched_stat_wait,
);

/*
- * Tracepoint for accounting sleep time (time the task is not runnable,
- * including iowait, see below).
+ * Tracepoint for accounting sleep time, TASK_INTERRUPTIBLE
*/
TRACE_EVENT(sched_stat_sleep,

@@ -406,8 +405,37 @@ TRACE_EVENT(sched_stat_sleep,
);

/*
- * Tracepoint for accounting iowait time (time the task is not runnable
- * due to waiting on IO to complete).
+ * Tracepoint for accounting block time, TASK_UNINTERRUPTIBLE
+ * (including iowait).
+ */
+TRACE_EVENT(sched_stat_block,
+
+ TP_PROTO(struct task_struct *tsk, u64 delay),
+
+ TP_ARGS(tsk, delay),
+
+ TP_STRUCT__entry(
+ __array( char, comm, TASK_COMM_LEN )
+ __field( pid_t, pid )
+ __field( u64, delay )
+ ),
+
+ TP_fast_assign(
+ memcpy(__entry->comm, tsk->comm, TASK_COMM_LEN);
+ __entry->pid = tsk->pid;
+ __entry->delay = delay;
+ )
+ TP_perf_assign(
+ __perf_count(delay);
+ ),
+
+ TP_printk("task: %s:%d block: %Lu [ns]",
+ __entry->comm, __entry->pid,
+ (unsigned long long)__entry->delay)
+);
+
+/*
+ * Tracepoint for accounting iowait time, TASK_UNINTERRUPTIBLE
*/
TRACE_EVENT(sched_stat_iowait,

diff --git a/kernel/sched_fair.c b/kernel/sched_fair.c
index 0e4d6c5..abc8e6c 100644
--- a/kernel/sched_fair.c
+++ b/kernel/sched_fair.c
@@ -540,6 +540,7 @@ static void update_stats_enqueue(struct cfs_rq *cfs_rq, struct sched_entity *se)
static void
update_stats_wait_end(struct cfs_rq *cfs_rq, struct sched_entity *se)
{
+#ifdef CONFIG_SCHEDSTATS
schedstat_set(se->wait_max, max(se->wait_max,
rq_of(cfs_rq)->clock - se->wait_start));
schedstat_set(se->wait_count, se->wait_count + 1);
@@ -551,6 +552,7 @@ update_stats_wait_end(struct cfs_rq *cfs_rq, struct sched_entity *se)
trace_sched_stat_wait(task_of(se),
rq_of(cfs_rq)->clock - se->wait_start);
}
+#endif
}

static inline void
@@ -664,6 +666,7 @@ static void enqueue_sleeper(struct cfs_rq *cfs_rq, struct sched_entity *se)
se->iowait_count++;
trace_sched_stat_iowait(tsk, delta);
}
+ trace_sched_stat_block(tsk, delta);

/*
* Blocking time is in units of nanosecs, so shift by