Skip to content

Commit

Permalink
perf lock: Do not discard broken lock stats
Browse files Browse the repository at this point in the history
Currently it discards a lock_stat for a lock instance when there's a
broken lock_seq_stat in a single task for the lock.  But it also means
that the existing (and later) valid lock stat info for that lock will
be discarded as well.

This is not ideal since we can lose many valuable info because of a
single failure.  Actually those failures are indepent to the existing
stat.  So we can only discard the broken lock_seq_stat but keep the
valid lock_stat.

The discarded lock_seq_stat will be reallocated in a subsequent event
with SEQ_STATE_UNINITIALIZED which will be ignored until it see the
start of the next sequence.  So it should be ok just free it.

Before:

  $ perf lock report -F acquired,contended,avg_wait

  Warning:
  Processed 1401603 events and lost 18 chunks!

  Check IO/CPU overload!

                  Name   acquired  contended   avg wait (ns)

         rcu_read_lock     251225          0               0
   &(ei->i_block_re...       8731          0               0
   &sb->s_type->i_l...       8731          0               0
    hrtimer_bases.lock       5261          0               0
    hrtimer_bases.lock       2626          0               0
    hrtimer_bases.lock       1953          0               0
    hrtimer_bases.lock       1382          0               0
      cpu_hotplug_lock       1350          0               0
    hrtimer_bases.lock       1273          0               0
    hrtimer_bases.lock       1269          0               0
    hrtimer_bases.lock       1198          0               0
   ...

New:
                  Name   acquired  contended   avg wait (ns)

         rcu_read_lock     251225          0               0
   tk_core.seq.seqc...      54074          0               0
          &xa->xa_lock      17470          0               0
        &ei->i_es_lock      17464          0               0
       &ei->i_raw_lock       9391          0               0
   &mapping->privat...       8734          0               0
       &ei->i_data_sem       8731          0               0
   &(ei->i_block_re...       8731          0               0
   &sb->s_type->i_l...       8731          0               0
   jiffies_seq.seqc...       6953          0               0
        &mm->mmap_lock       6889          0               0
             balancing       5768          0               0
    hrtimer_bases.lock       5261          0               0
   ...

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20220521010811.932703-1-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
  • Loading branch information
Namhyung Kim authored and Arnaldo Carvalho de Melo committed May 23, 2022
1 parent 12aeaab commit 79d9333
Showing 1 changed file with 25 additions and 39 deletions.
64 changes: 25 additions & 39 deletions tools/perf/builtin-lock.c
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,7 @@ struct lock_stat {
u64 wait_time_min;
u64 wait_time_max;

int discard; /* flag of blacklist */
int broken; /* flag of blacklist */
int combined;
};

Expand Down Expand Up @@ -384,9 +384,6 @@ static void combine_lock_stats(struct lock_stat *st)
ret = !!st->name - !!p->name;

if (ret == 0) {
if (st->discard)
goto out;

p->nr_acquired += st->nr_acquired;
p->nr_contended += st->nr_contended;
p->wait_time_total += st->wait_time_total;
Expand All @@ -399,10 +396,7 @@ static void combine_lock_stats(struct lock_stat *st)
if (p->wait_time_max < st->wait_time_max)
p->wait_time_max = st->wait_time_max;

/* now it got a new !discard record */
p->discard = 0;

out:
p->broken |= st->broken;
st->combined = 1;
return;
}
Expand All @@ -415,15 +409,6 @@ static void combine_lock_stats(struct lock_stat *st)

rb_link_node(&st->rb, parent, rb);
rb_insert_color(&st->rb, &sorted);

if (st->discard) {
st->nr_acquired = 0;
st->nr_contended = 0;
st->wait_time_total = 0;
st->avg_wait_time = 0;
st->wait_time_min = ULLONG_MAX;
st->wait_time_max = 0;
}
}

static void insert_to_result(struct lock_stat *st,
Expand Down Expand Up @@ -560,8 +545,6 @@ static int report_lock_acquire_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
if (ls->discard)
return 0;

ts = thread_stat_findnew(sample->tid);
if (!ts)
Expand Down Expand Up @@ -599,9 +582,11 @@ static int report_lock_acquire_event(struct evsel *evsel,
case SEQ_STATE_ACQUIRING:
case SEQ_STATE_CONTENDED:
broken:
/* broken lock sequence, discard it */
ls->discard = 1;
bad_hist[BROKEN_ACQUIRE]++;
/* broken lock sequence */
if (!ls->broken) {
ls->broken = 1;
bad_hist[BROKEN_ACQUIRE]++;
}
list_del_init(&seq->list);
free(seq);
goto end;
Expand Down Expand Up @@ -629,8 +614,6 @@ static int report_lock_acquired_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
if (ls->discard)
return 0;

ts = thread_stat_findnew(sample->tid);
if (!ts)
Expand All @@ -657,9 +640,11 @@ static int report_lock_acquired_event(struct evsel *evsel,
case SEQ_STATE_RELEASED:
case SEQ_STATE_ACQUIRED:
case SEQ_STATE_READ_ACQUIRED:
/* broken lock sequence, discard it */
ls->discard = 1;
bad_hist[BROKEN_ACQUIRED]++;
/* broken lock sequence */
if (!ls->broken) {
ls->broken = 1;
bad_hist[BROKEN_ACQUIRED]++;
}
list_del_init(&seq->list);
free(seq);
goto end;
Expand Down Expand Up @@ -688,8 +673,6 @@ static int report_lock_contended_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
if (ls->discard)
return 0;

ts = thread_stat_findnew(sample->tid);
if (!ts)
Expand All @@ -709,9 +692,11 @@ static int report_lock_contended_event(struct evsel *evsel,
case SEQ_STATE_ACQUIRED:
case SEQ_STATE_READ_ACQUIRED:
case SEQ_STATE_CONTENDED:
/* broken lock sequence, discard it */
ls->discard = 1;
bad_hist[BROKEN_CONTENDED]++;
/* broken lock sequence */
if (!ls->broken) {
ls->broken = 1;
bad_hist[BROKEN_CONTENDED]++;
}
list_del_init(&seq->list);
free(seq);
goto end;
Expand Down Expand Up @@ -740,8 +725,6 @@ static int report_lock_release_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
if (ls->discard)
return 0;

ts = thread_stat_findnew(sample->tid);
if (!ts)
Expand All @@ -767,9 +750,11 @@ static int report_lock_release_event(struct evsel *evsel,
case SEQ_STATE_ACQUIRING:
case SEQ_STATE_CONTENDED:
case SEQ_STATE_RELEASED:
/* broken lock sequence, discard it */
ls->discard = 1;
bad_hist[BROKEN_RELEASE]++;
/* broken lock sequence */
if (!ls->broken) {
ls->broken = 1;
bad_hist[BROKEN_RELEASE]++;
}
goto free_seq;
default:
BUG_ON("Unknown state of lock sequence found!\n");
Expand Down Expand Up @@ -854,10 +839,11 @@ static void print_result(void)
bad = total = 0;
while ((st = pop_from_result())) {
total++;
if (st->discard) {
if (st->broken)
bad++;
if (!st->nr_acquired)
continue;
}

bzero(cut_name, 20);

if (strlen(st->name) < 20) {
Expand Down

0 comments on commit 79d9333

Please sign in to comment.