Skip to content

Commit

Permalink
klockstat: Support rwsem too
Browse files Browse the repository at this point in the history
In many cases, rwsem can be a culprit for kernel lock contentions.  Add
rwsem functions to track lock hold/wait time for them.

    $ sudo klockstat -n 2 -s 3
    Tracing mutex/rwsem lock events...  Hit Ctrl-C to end
    ^C

                               Caller  Avg Wait    Count   Max Wait   Total Wait
                       mutex_lock+0x5      1422      791      15628      1125030
                  do_epoll_wait+0x1ce
            do_epoll_pwait.part.0+0xc
                              Max PID 2441, COMM murdockd

                               Caller  Avg Wait    Count   Max Wait   Total Wait
                       mutex_lock+0x5      1699      465      14471       790264
                  do_epoll_wait+0x1ce
            __x64_sys_epoll_wait+0x60
                              Max PID 1864873, COMM svw_NetThreadEv

                               Caller  Avg Hold    Count   Max Hold   Total Hold
                down_read_trylock+0x5   1888876        5    9109738      9444384
                   trylock_super+0x16
           __writeback_inodes_wb+0x8d
                              Max PID 3744442, COMM kworker/u145:6

                               Caller  Avg Hold    Count   Max Hold   Total Hold
                       mutex_lock+0x5   2350695       15    2593128     35260434
        bpf_tracing_prog_attach+0x34b
        bpf_raw_tracepoint_open+0x1c4
                              Max PID 3748530, COMM klockstat
    Exiting trace of mutex/rwsem locks
  • Loading branch information
namhyung authored and yonghong-song committed Apr 27, 2022
1 parent c390c4f commit 28f2af9
Show file tree
Hide file tree
Showing 2 changed files with 139 additions and 5 deletions.
116 changes: 115 additions & 1 deletion libbpf-tools/klockstat.bpf.c
Original file line number Diff line number Diff line change
Expand Up @@ -151,7 +151,8 @@ static void account(struct lockholder_info *li)
/*
* Multiple threads may have the same stack_id. Even though we are
* holding the lock, dynamically allocated mutexes can have the same
* callgraph but represent different locks. They will be accounted as
* callgraph but represent different locks. Also, a rwsem can be held
* by multiple readers at the same time. They will be accounted as
* the same lock, which is what we want, but we need to use atomics to
* avoid corruption, especially for the total_time variables.
*/
Expand Down Expand Up @@ -276,4 +277,117 @@ int BPF_PROG(mutex_unlock, struct mutex *lock)
return 0;
}

SEC("fentry/down_read")
int BPF_PROG(down_read, struct rw_semaphore *lock)
{
lock_contended(ctx, lock);
return 0;
}

SEC("fexit/down_read")
int BPF_PROG(down_read_exit, struct rw_semaphore *lock, long ret)
{
lock_acquired(lock);
return 0;
}

SEC("fexit/down_read_trylock")
int BPF_PROG(down_read_trylock_exit, struct rw_semaphore *lock, long ret)
{
if (ret == 1) {
lock_contended(ctx, lock);
lock_acquired(lock);
}
return 0;
}

SEC("fentry/down_read_interruptible")
int BPF_PROG(down_read_interruptible, struct rw_semaphore *lock)
{
lock_contended(ctx, lock);
return 0;
}

SEC("fexit/down_read_interruptible")
int BPF_PROG(down_read_interruptible_exit, struct rw_semaphore *lock, long ret)
{
if (ret)
lock_aborted(lock);
else
lock_acquired(lock);
return 0;
}

SEC("fentry/down_read_killable")
int BPF_PROG(down_read_killable, struct rw_semaphore *lock)
{
lock_contended(ctx, lock);
return 0;
}

SEC("fexit/down_read_killable")
int BPF_PROG(down_read_killable_exit, struct rw_semaphore *lock, long ret)
{
if (ret)
lock_aborted(lock);
else
lock_acquired(lock);
return 0;
}

SEC("fentry/up_read")
int BPF_PROG(up_read, struct rw_semaphore *lock)
{
lock_released(lock);
return 0;
}

SEC("fentry/down_write")
int BPF_PROG(down_write, struct rw_semaphore *lock)
{
lock_contended(ctx, lock);
return 0;
}

SEC("fexit/down_write")
int BPF_PROG(down_write_exit, struct rw_semaphore *lock, long ret)
{
lock_acquired(lock);
return 0;
}

SEC("fexit/down_write_trylock")
int BPF_PROG(down_write_trylock_exit, struct rw_semaphore *lock, long ret)
{
if (ret == 1) {
lock_contended(ctx, lock);
lock_acquired(lock);
}
return 0;
}

SEC("fentry/down_write_killable")
int BPF_PROG(down_write_killable, struct rw_semaphore *lock)
{
lock_contended(ctx, lock);
return 0;
}

SEC("fexit/down_write_killable")
int BPF_PROG(down_write_killable_exit, struct rw_semaphore *lock, long ret)
{
if (ret)
lock_aborted(lock);
else
lock_acquired(lock);
return 0;
}

SEC("fentry/up_write")
int BPF_PROG(up_write, struct rw_semaphore *lock)
{
lock_released(lock);
return 0;
}

char LICENSE[] SEC("license") = "GPL";
28 changes: 24 additions & 4 deletions libbpf-tools/klockstat.c
Original file line number Diff line number Diff line change
Expand Up @@ -64,12 +64,12 @@ static struct prog_env {
.iterations = 99999999,
};

const char *argp_program_version = "klockstat 0.1";
const char *argp_program_version = "klockstat 0.2";
const char *argp_program_bug_address =
"https://github.com/iovisor/bcc/tree/master/libbpf-tools";
static const char args_doc[] = "FUNCTION";
static const char program_doc[] =
"Trace mutex lock acquisition and hold times, in nsec\n"
"Trace mutex/sem lock acquisition and hold times, in nsec\n"
"\n"
"Usage: klockstat [-hRTv] [-p PID] [-t TID] [-c FUNC] [-L LOCK] [-n NR_LOCKS]\n"
" [-s NR_STACKS] [-S SORT] [-d DURATION] [-i INTERVAL]\n"
Expand Down Expand Up @@ -549,6 +549,26 @@ int main(int argc, char **argv)
"mutex_lock_killable_nested");
}

if (fentry_can_attach("down_read_nested", NULL)) {
bpf_program__set_attach_target(obj->progs.down_read, 0,
"down_read_nested");
bpf_program__set_attach_target(obj->progs.down_read_exit, 0,
"down_read_nested");
bpf_program__set_attach_target(obj->progs.down_read_killable, 0,
"down_read_killable_nested");
bpf_program__set_attach_target(obj->progs.down_read_killable_exit, 0,
"down_read_killable_nested");

bpf_program__set_attach_target(obj->progs.down_write, 0,
"down_write_nested");
bpf_program__set_attach_target(obj->progs.down_write_exit, 0,
"down_write_nested");
bpf_program__set_attach_target(obj->progs.down_write_killable, 0,
"down_write_killable_nested");
bpf_program__set_attach_target(obj->progs.down_write_killable_exit, 0,
"down_write_killable_nested");
}

err = klockstat_bpf__load(obj);
if (err) {
warn("failed to load BPF object\n");
Expand All @@ -560,7 +580,7 @@ int main(int argc, char **argv)
goto cleanup;
}

printf("Tracing mutex lock events... Hit Ctrl-C to end\n");
printf("Tracing mutex/sem lock events... Hit Ctrl-C to end\n");

for (i = 0; i < env.iterations && !exiting; i++) {
sleep(env.interval);
Expand All @@ -580,7 +600,7 @@ int main(int argc, char **argv)
}
}

printf("Exiting trace of mutex locks\n");
printf("Exiting trace of mutex/sem locks\n");

cleanup:
klockstat_bpf__destroy(obj);
Expand Down

0 comments on commit 28f2af9

Please sign in to comment.