Rename 'Switches' to 'Count' and document metrics shown for perf
sched latency output. Also add options possible with perf sched
latency.
Initially, after seeing the output of 'perf sched latency', the term
'Switches' seemed like it's the number of context switches-in for a
particular task, but upon going through the code, it was observed that
it's actually keeping track of number of times a delay was calculated so
that it is used in calculation of the average delay.
Actually, the switches here is a subset of number of context switches-in
because there are some cases where the count is not incremented in
switch-in handler 'add_sched_in_event'. For example when a task is
switched-in while it's state is not ready to run(!= THREAD_WAIT_CPU).
commit d9340c1db3f5 ("perf sched: Display time in milliseconds, reorganize
output") changed it from the original count to switches.
So, renamed switches to count to make things a bit more clearer and
added the metrics description of latency in the document.
Signed-off-by: Madadi Vineeth Reddy <vineethr@linux.ibm.com>
---
tools/perf/Documentation/perf-sched.txt | 36 +++++++++++++++++++++++++
tools/perf/builtin-sched.c | 2 +-
2 files changed, 37 insertions(+), 1 deletion(-)
diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index 5fbe42bd599b..a216d2991b19 100644
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -20,6 +20,26 @@ There are several variants of 'perf sched':
'perf sched latency' to report the per task scheduling latencies
and other scheduling properties of the workload.
+ Example usage:
+ perf sched record -- sleep 1
+ perf sched latency
+
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ Task | Runtime ms | Count | Avg delay ms | Max delay ms | Max delay start | Max delay end |
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ perf:(2) | 2.804 ms | 66 | avg: 0.524 ms | max: 1.069 ms | max start: 254752.314960 s | max end: 254752.316029 s
+ NetworkManager:1343 | 0.372 ms | 13 | avg: 0.008 ms | max: 0.013 ms | max start: 254751.551153 s | max end: 254751.551166 s
+ kworker/1:2-xfs:4649 | 0.012 ms | 1 | avg: 0.008 ms | max: 0.008 ms | max start: 254751.519807 s | max end: 254751.519815 s
+ kworker/3:1-xfs:388 | 0.011 ms | 1 | avg: 0.006 ms | max: 0.006 ms | max start: 254751.519809 s | max end: 254751.519815 s
+ sleep:147736 | 0.938 ms | 3 | avg: 0.006 ms | max: 0.007 ms | max start: 254751.313817 s | max end: 254751.313824 s
+
+ It shows Runtime(time that a task spent actually running on the CPU),
+ Count(number of times a delay was calculated) and delay(time that a
+ task was ready to run but was kept waiting).
+
+ Tasks with the same command name are merged and the merge count is
+ given within (), However if -p option is used, pid is mentioned.
+
'perf sched script' to see a detailed trace of the workload that
was recorded (aliased to 'perf script' for now).
@@ -78,6 +98,22 @@ OPTIONS
--force::
Don't complain, do it.
+OPTIONS for 'perf sched latency'
+-------------------------------
+
+-C::
+--CPU <n>::
+ CPU to profile on.
+
+-p::
+--pids::
+ latency stats per pid instead of per command name.
+
+-s::
+--sort <key[,key2...]>::
+ sort by key(s): runtime, switch, avg, max
+ by default it's sorted by "avg ,max ,switch ,runtime".
+
OPTIONS for 'perf sched map'
----------------------------
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index b248c433529a..e66a935eab6f 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -3210,7 +3210,7 @@ static int perf_sched__lat(struct perf_sched *sched)
perf_sched__sort_lat(sched);
printf("\n -------------------------------------------------------------------------------------------------------------------------------------------\n");
- printf(" Task | Runtime ms | Switches | Avg delay ms | Max delay ms | Max delay start | Max delay end |\n");
+ printf(" Task | Runtime ms | Count | Avg delay ms | Max delay ms | Max delay start | Max delay end |\n");
printf(" -------------------------------------------------------------------------------------------------------------------------------------------\n");
next = rb_first_cached(&sched->sorted_atom_root);
--
2.39.1
sched latency output. Also add options possible with perf sched
latency.
Initially, after seeing the output of 'perf sched latency', the term
'Switches' seemed like it's the number of context switches-in for a
particular task, but upon going through the code, it was observed that
it's actually keeping track of number of times a delay was calculated so
that it is used in calculation of the average delay.
Actually, the switches here is a subset of number of context switches-in
because there are some cases where the count is not incremented in
switch-in handler 'add_sched_in_event'. For example when a task is
switched-in while it's state is not ready to run(!= THREAD_WAIT_CPU).
commit d9340c1db3f5 ("perf sched: Display time in milliseconds, reorganize
output") changed it from the original count to switches.
So, renamed switches to count to make things a bit more clearer and
added the metrics description of latency in the document.
Signed-off-by: Madadi Vineeth Reddy <vineethr@linux.ibm.com>
---
tools/perf/Documentation/perf-sched.txt | 36 +++++++++++++++++++++++++
tools/perf/builtin-sched.c | 2 +-
2 files changed, 37 insertions(+), 1 deletion(-)
diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index 5fbe42bd599b..a216d2991b19 100644
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -20,6 +20,26 @@ There are several variants of 'perf sched':
'perf sched latency' to report the per task scheduling latencies
and other scheduling properties of the workload.
+ Example usage:
+ perf sched record -- sleep 1
+ perf sched latency
+
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ Task | Runtime ms | Count | Avg delay ms | Max delay ms | Max delay start | Max delay end |
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ perf:(2) | 2.804 ms | 66 | avg: 0.524 ms | max: 1.069 ms | max start: 254752.314960 s | max end: 254752.316029 s
+ NetworkManager:1343 | 0.372 ms | 13 | avg: 0.008 ms | max: 0.013 ms | max start: 254751.551153 s | max end: 254751.551166 s
+ kworker/1:2-xfs:4649 | 0.012 ms | 1 | avg: 0.008 ms | max: 0.008 ms | max start: 254751.519807 s | max end: 254751.519815 s
+ kworker/3:1-xfs:388 | 0.011 ms | 1 | avg: 0.006 ms | max: 0.006 ms | max start: 254751.519809 s | max end: 254751.519815 s
+ sleep:147736 | 0.938 ms | 3 | avg: 0.006 ms | max: 0.007 ms | max start: 254751.313817 s | max end: 254751.313824 s
+
+ It shows Runtime(time that a task spent actually running on the CPU),
+ Count(number of times a delay was calculated) and delay(time that a
+ task was ready to run but was kept waiting).
+
+ Tasks with the same command name are merged and the merge count is
+ given within (), However if -p option is used, pid is mentioned.
+
'perf sched script' to see a detailed trace of the workload that
was recorded (aliased to 'perf script' for now).
@@ -78,6 +98,22 @@ OPTIONS
--force::
Don't complain, do it.
+OPTIONS for 'perf sched latency'
+-------------------------------
+
+-C::
+--CPU <n>::
+ CPU to profile on.
+
+-p::
+--pids::
+ latency stats per pid instead of per command name.
+
+-s::
+--sort <key[,key2...]>::
+ sort by key(s): runtime, switch, avg, max
+ by default it's sorted by "avg ,max ,switch ,runtime".
+
OPTIONS for 'perf sched map'
----------------------------
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index b248c433529a..e66a935eab6f 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -3210,7 +3210,7 @@ static int perf_sched__lat(struct perf_sched *sched)
perf_sched__sort_lat(sched);
printf("\n -------------------------------------------------------------------------------------------------------------------------------------------\n");
- printf(" Task | Runtime ms | Switches | Avg delay ms | Max delay ms | Max delay start | Max delay end |\n");
+ printf(" Task | Runtime ms | Count | Avg delay ms | Max delay ms | Max delay start | Max delay end |\n");
printf(" -------------------------------------------------------------------------------------------------------------------------------------------\n");
next = rb_first_cached(&sched->sorted_atom_root);
--
2.39.1