On 8/5/13 2:39 AM, Xiao Guangrong wrote:
On 08/03/2013 04:05 AM, David Ahern wrote:
This is useful to spot high latency blips.
Yes, it is a good idea.
Signed-off-by: David Ahern <[email protected]>
Cc: Arnaldo Carvalho de Melo <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Xiao Guangrong <[email protected]>
Cc: Runzhen Wang <[email protected]>
---
tools/perf/builtin-kvm.c | 25 +++++++++++++++++++++----
tools/perf/perf.h | 3 +++
2 files changed, 24 insertions(+), 4 deletions(-)
diff --git a/tools/perf/builtin-kvm.c b/tools/perf/builtin-kvm.c
index 5c6e3cd..28afc05d 100644
--- a/tools/perf/builtin-kvm.c
+++ b/tools/perf/builtin-kvm.c
@@ -106,6 +106,7 @@ struct perf_kvm_stat {
u64 total_time;
u64 total_count;
u64 lost_events;
+ u64 threshold;
struct rb_root result;
@@ -470,7 +471,7 @@ static bool update_kvm_event(struct kvm_event *event, int
vcpu_id,
static bool handle_end_event(struct perf_kvm_stat *kvm,
struct vcpu_event_record *vcpu_record,
struct event_key *key,
- u64 timestamp)
+ struct perf_sample *sample)
{
struct kvm_event *event;
u64 time_begin, time_diff;
@@ -507,12 +508,24 @@ static bool handle_end_event(struct perf_kvm_stat *kvm,
vcpu_record->start_time = 0;
/* seems to happen once in a while during live mode */
- if (timestamp < time_begin) {
+ if (sample->time < time_begin) {
pr_debug("End time before begin time; skipping event.\n");
return true;
}
- time_diff = timestamp - time_begin;
+ time_diff = sample->time - time_begin;
+
+ if (kvm->threshold && time_diff > kvm->threshold) {
+ char decode[32];
+
+ kvm->events_ops->decode_key(kvm, &event->key, decode);
+ if (strcmp(decode, "HLT")) {
+ pr_info("%" PRIu64 " VM %d, vcpu %d: %s event took %" PRIu64
"usec\n",
+ sample->time, sample->pid,
vcpu_record->vcpu_id,
+ decode, time_diff/1000);
+ }
Any reason to filter HLT out? it is too frequent? But the info will be missed if
we're really interested in this event.
It is normal for HLT events to be long duration and by not stripping out
HLT events you get a flood of messages.
It is abnormal for other kvm-exit events to take considerable time and
those are the ones to emphasize to a user.
It shows the info when the events is parsed which is not very readable and
analyzable,
can we only record and print the events that cost long time (handle-time >
threshould)?
With the existing workflow -- record and then report -- those events are
dumped prior to the stats output so they can be visible.
With the live mode command the intent is to keep going. The console
output can be reviewed by scrolling up -- or redirect to a file as well
with tee. I do both options.
We could add another option -- show the high latency events only and not
the stats output.
David
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
