Re: [PATCH 4/5] perf kvm: option to print events that exceed a threshold
Em Wed, Aug 07, 2013 at 04:24:23PM -0400, David Ahern escreveu:
> On 8/7/13 3:27 PM, Arnaldo Carvalho de Melo wrote:
> >Em Mon, Aug 05, 2013 at 09:41:36PM -0400, David Ahern escreveu:
> >So 'perf trace' has a similar option:
> >
> >[acme@zoo linux]$ perf trace --help
> >
> > --duration
> > show only events with duration > N.M ms
> >
> >
> >While you used:
> >
> >>+ OPT_U64('T', "threshold", >threshold,
> >>+ "show events other than HALT that take longer than
> >>threshold usecs"),
> >
> >I prefer 'duration', and haven't assigned a single letter to it, they
> >are scarce and we have shell long option completion, what do you think?
> >
> >The term was chosen, for 'perf trace' on the original patchset:
> >
> >http://lwn.net/Articles/415728/
> No preference really. I need to send out an update to the man page.
> I can update this patch as well and re-send.
Please. I applied all the other patches, just wait a bit before I run
'male -C tools/perf -f tests/make' on my perf/core before I push it out.
- Arnaldo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH 4/5] perf kvm: option to print events that exceed a threshold
On 8/7/13 3:27 PM, Arnaldo Carvalho de Melo wrote:
Em Mon, Aug 05, 2013 at 09:41:36PM -0400, David Ahern escreveu:
This is useful to spot high latency blips. It is normal for HLT
reasons to have long exit times, so strip those from the threshold
check.
So 'perf trace' has a similar option:
[acme@zoo linux]$ perf trace --help
--duration
show only events with duration > N.M ms
While you used:
+ OPT_U64('T', "threshold", >threshold,
+ "show events other than HALT that take longer than threshold
usecs"),
I prefer 'duration', and haven't assigned a single letter to it, they
are scarce and we have shell long option completion, what do you think?
The term was chosen, for 'perf trace' on the original patchset:
http://lwn.net/Articles/415728/
- Arnaldo
No preference really. I need to send out an update to the man page. I
can update this patch as well and re-send.
David
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH 4/5] perf kvm: option to print events that exceed a threshold
Em Mon, Aug 05, 2013 at 09:41:36PM -0400, David Ahern escreveu:
> This is useful to spot high latency blips. It is normal for HLT
> reasons to have long exit times, so strip those from the threshold
> check.
So 'perf trace' has a similar option:
[acme@zoo linux]$ perf trace --help
--duration
show only events with duration > N.M ms
While you used:
> + OPT_U64('T', "threshold", >threshold,
> + "show events other than HALT that take longer than
> threshold usecs"),
I prefer 'duration', and haven't assigned a single letter to it, they
are scarce and we have shell long option completion, what do you think?
The term was chosen, for 'perf trace' on the original patchset:
http://lwn.net/Articles/415728/
- Arnaldo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH 4/5] perf kvm: option to print events that exceed a threshold
Em Mon, Aug 05, 2013 at 09:41:36PM -0400, David Ahern escreveu:
This is useful to spot high latency blips. It is normal for HLT
reasons to have long exit times, so strip those from the threshold
check.
So 'perf trace' has a similar option:
[acme@zoo linux]$ perf trace --help
SNIP
--duration float
show only events with duration N.M ms
SNIP
While you used:
+ OPT_U64('T', threshold, kvm-threshold,
+ show events other than HALT that take longer than
threshold usecs),
I prefer 'duration', and haven't assigned a single letter to it, they
are scarce and we have shell long option completion, what do you think?
The term was chosen, for 'perf trace' on the original patchset:
http://lwn.net/Articles/415728/
- Arnaldo
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH 4/5] perf kvm: option to print events that exceed a threshold
On 8/7/13 3:27 PM, Arnaldo Carvalho de Melo wrote:
Em Mon, Aug 05, 2013 at 09:41:36PM -0400, David Ahern escreveu:
This is useful to spot high latency blips. It is normal for HLT
reasons to have long exit times, so strip those from the threshold
check.
So 'perf trace' has a similar option:
[acme@zoo linux]$ perf trace --help
SNIP
--duration float
show only events with duration N.M ms
SNIP
While you used:
+ OPT_U64('T', threshold, kvm-threshold,
+ show events other than HALT that take longer than threshold
usecs),
I prefer 'duration', and haven't assigned a single letter to it, they
are scarce and we have shell long option completion, what do you think?
The term was chosen, for 'perf trace' on the original patchset:
http://lwn.net/Articles/415728/
- Arnaldo
No preference really. I need to send out an update to the man page. I
can update this patch as well and re-send.
David
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH 4/5] perf kvm: option to print events that exceed a threshold
Em Wed, Aug 07, 2013 at 04:24:23PM -0400, David Ahern escreveu:
On 8/7/13 3:27 PM, Arnaldo Carvalho de Melo wrote:
Em Mon, Aug 05, 2013 at 09:41:36PM -0400, David Ahern escreveu:
So 'perf trace' has a similar option:
[acme@zoo linux]$ perf trace --help
SNIP
--duration float
show only events with duration N.M ms
SNIP
While you used:
+ OPT_U64('T', threshold, kvm-threshold,
+ show events other than HALT that take longer than
threshold usecs),
I prefer 'duration', and haven't assigned a single letter to it, they
are scarce and we have shell long option completion, what do you think?
The term was chosen, for 'perf trace' on the original patchset:
http://lwn.net/Articles/415728/
No preference really. I need to send out an update to the man page.
I can update this patch as well and re-send.
Please. I applied all the other patches, just wait a bit before I run
'male -C tools/perf -f tests/make' on my perf/core before I push it out.
- Arnaldo
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH 4/5] perf kvm: option to print events that exceed a threshold
This is useful to spot high latency blips. It is normal for HLT
reasons to have long exit times, so strip those from the threshold
check.
Signed-off-by: David Ahern
Cc: Arnaldo Carvalho de Melo
Cc: Ingo Molnar
Cc: Frederic Weisbecker
Cc: Peter Zijlstra
Cc: Jiri Olsa
Cc: Namhyung Kim
Cc: Xiao Guangrong
Cc: Runzhen Wang
---
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 b6595e9..5edbd3b 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, >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);
+ }
+ }
+
return update_kvm_event(event, vcpu, time_diff);
}
@@ -559,7 +572,7 @@ static bool handle_kvm_event(struct perf_kvm_stat *kvm,
return handle_begin_event(kvm, vcpu_record, , sample->time);
if (kvm->events_ops->is_end_event(evsel, sample, ))
- return handle_end_event(kvm, vcpu_record, , sample->time);
+ return handle_end_event(kvm, vcpu_record, , sample);
return true;
}
@@ -1395,6 +1408,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
OPT_STRING('k', "key", >sort_key, "sort-key",
"key for sorting: sample(sort by samples number)"
" time (sort by avg time)"),
+ OPT_U64('T', "threshold", >threshold,
+ "show events other than HALT that take longer than
threshold usecs"),
OPT_END()
};
const char * const live_usage[] = {
@@ -1433,6 +1448,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
usage_with_options(live_usage, live_options);
}
+ kvm->threshold *= NSEC_PER_USEC; /* convert usec to nsec */
+
/*
* target related setups
*/
diff --git a/tools/perf/perf.h b/tools/perf/perf.h
index 32bd102..cf20187 100644
--- a/tools/perf/perf.h
+++ b/tools/perf/perf.h
@@ -125,6 +125,9 @@
#ifndef NSEC_PER_SEC
# define NSEC_PER_SEC 10ULL
#endif
+#ifndef NSEC_PER_USEC
+# define NSEC_PER_USEC 1000ULL
+#endif
static inline unsigned long long rdclock(void)
{
--
1.7.10.1
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH 4/5] perf kvm: option to print events that exceed a threshold
This is useful to spot high latency blips. It is normal for HLT
reasons to have long exit times, so strip those from the threshold
check.
Signed-off-by: David Ahern dsah...@gmail.com
Cc: Arnaldo Carvalho de Melo a...@ghostprotocols.net
Cc: Ingo Molnar mi...@kernel.org
Cc: Frederic Weisbecker fweis...@gmail.com
Cc: Peter Zijlstra pet...@infradead.org
Cc: Jiri Olsa jo...@redhat.com
Cc: Namhyung Kim namhy...@kernel.org
Cc: Xiao Guangrong xiaoguangr...@linux.vnet.ibm.com
Cc: Runzhen Wang runz...@linux.vnet.ibm.com
---
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 b6595e9..5edbd3b 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);
+ }
+ }
+
return update_kvm_event(event, vcpu, time_diff);
}
@@ -559,7 +572,7 @@ static bool handle_kvm_event(struct perf_kvm_stat *kvm,
return handle_begin_event(kvm, vcpu_record, key, sample-time);
if (kvm-events_ops-is_end_event(evsel, sample, key))
- return handle_end_event(kvm, vcpu_record, key, sample-time);
+ return handle_end_event(kvm, vcpu_record, key, sample);
return true;
}
@@ -1395,6 +1408,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
OPT_STRING('k', key, kvm-sort_key, sort-key,
key for sorting: sample(sort by samples number)
time (sort by avg time)),
+ OPT_U64('T', threshold, kvm-threshold,
+ show events other than HALT that take longer than
threshold usecs),
OPT_END()
};
const char * const live_usage[] = {
@@ -1433,6 +1448,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
usage_with_options(live_usage, live_options);
}
+ kvm-threshold *= NSEC_PER_USEC; /* convert usec to nsec */
+
/*
* target related setups
*/
diff --git a/tools/perf/perf.h b/tools/perf/perf.h
index 32bd102..cf20187 100644
--- a/tools/perf/perf.h
+++ b/tools/perf/perf.h
@@ -125,6 +125,9 @@
#ifndef NSEC_PER_SEC
# define NSEC_PER_SEC 10ULL
#endif
+#ifndef NSEC_PER_USEC
+# define NSEC_PER_USEC 1000ULL
+#endif
static inline unsigned long long rdclock(void)
{
--
1.7.10.1
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
