lkml.org 
[lkml]   [2013]   [Aug]   [14]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    From
    Subject[PATCH 01/21] perf kvm: Option to print events that exceed a duration
    Date
    From: David Ahern <dsahern@gmail.com>

    This is useful to spot high latency blips. It is normal for HLT reasons
    to have long exit times, so strip those from the duration check.

    v2: changed threshold to duration per acme's request

    Signed-off-by: David Ahern <dsahern@gmail.com>
    Cc: Frederic Weisbecker <fweisbec@gmail.com>
    Cc: Ingo Molnar <mingo@kernel.org>
    Cc: Jiri Olsa <jolsa@redhat.com>
    Cc: Namhyung Kim <namhyung@kernel.org>
    Cc: Peter Zijlstra <peterz@infradead.org>
    Cc: Runzhen Wang <runzhen@linux.vnet.ibm.com>
    Cc: Xiao Guangrong <xiaoguangrong@linux.vnet.ibm.com>
    Link: http://lkml.kernel.org/r/1375926999-75129-1-git-send-email-dsahern@gmail.com
    Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.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 2ceec81..fa2f3d7 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 duration;

    const char *pid_str;
    struct intlist *pid_list;
    @@ -473,7 +474,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;
    @@ -510,12 +511,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->duration && time_diff > kvm->duration) {
    + 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);
    }

    @@ -562,7 +575,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;
    }
    @@ -1429,6 +1442,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(0, "duration", &kvm->duration,
    + "show events other than HALT that take longer than duration usecs"),
    OPT_END()
    };
    const char * const live_usage[] = {
    @@ -1467,6 +1482,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
    usage_with_options(live_usage, live_options);
    }

    + kvm->duration *= 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 1000000000ULL
    #endif
    +#ifndef NSEC_PER_USEC
    +# define NSEC_PER_USEC 1000ULL
    +#endif

    static inline unsigned long long rdclock(void)
    {
    --
    1.8.1.4


    \
     
     \ /
      Last update: 2013-08-16 07:01    [W:4.413 / U:0.092 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site