Skip to content

Commit

Permalink
libbpf-tools/klockstat: accept lock addr as well as lock name
Browse files Browse the repository at this point in the history
The following PR added printing for lock addr and name in max acq/hold times:

* iovisor#4188

This is how it looks like:

```
$ sudo ./klockstat -d 5 -c down_ -n 2 -s 2 -S hld_total -p 39643
Tracing mutex/sem lock events...  Hit Ctrl-C to end

                               Caller  Avg Wait    Count   Max Wait   Total Wait
                        down_read+0x5    8.0 us    10685    83.2 ms      85.0 ms
           kernfs_iop_permission+0x27
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)

                               Caller  Avg Wait    Count   Max Wait   Total Wait
                        down_read+0x5    2.1 us    36025    71.1 ms      76.8 ms
           kernfs_iop_permission+0x27
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)

                               Caller  Avg Hold    Count   Max Hold   Total Hold
               down_read_killable+0x5    8.2 us    19386   297.7 us     158.1 ms
                     iterate_dir+0x52
                              Max PID 39643, COMM cadvisor, Lock no-ksym (0xffff9477eec5f1a8)

                               Caller  Avg Hold    Count   Max Hold   Total Hold
                        down_read+0x5    209 ns    82630     8.9 us      17.3 ms
             kernfs_fop_readdir+0x115
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)
```

Previously it was possible to filter on lock name only:

```
$ sudo ./klockstat -d 5 -c down_ -n 2 -s 2 -S hld_total -p 39643 -L kernfs_rwsem
Tracing mutex/sem lock events...  Hit Ctrl-C to end

                               Caller  Avg Wait    Count   Max Wait   Total Wait
                        down_read+0x5    1.5 us    32126    41.3 ms      46.9 ms
           kernfs_iop_permission+0x27
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)

                               Caller  Avg Wait    Count   Max Wait   Total Wait
                        down_read+0x5    156 ns    66104    94.6 us      10.3 ms
             kernfs_fop_readdir+0x115
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)

                               Caller  Avg Hold    Count   Max Hold   Total Hold
                        down_read+0x5    305 ns    66104    97.8 us      20.2 ms
             kernfs_fop_readdir+0x115
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)

                               Caller  Avg Hold    Count   Max Hold   Total Hold
                        down_read+0x5    115 ns    32126     5.5 us       3.7 ms
           kernfs_iop_permission+0x27
                              Max PID 39643, COMM cadvisor, Lock kernfs_rwsem (0xffffffff89f87e00)
Exiting trace of mutex/sem locks
```

Now it's also possible to filter on lock addr:

```
$ sudo ./klockstat -d 5 -c down_ -n 2 -s 2 -S hld_total -p 39643 -L 0xffff9477eec5f1a8
Tracing mutex/sem lock events...  Hit Ctrl-C to end

                               Caller  Avg Wait    Count   Max Wait   Total Wait
               down_read_killable+0x5    227 ns       68     1.0 us      15.4 us
                     iterate_dir+0x52
                              Max PID 39643, COMM cadvisor, Lock no-ksym (0xffff9477eec5f1a8)

                               Caller  Avg Hold    Count   Max Hold   Total Hold
               down_read_killable+0x5  191.5 us       68   238.3 us      13.0 ms
                     iterate_dir+0x52
                              Max PID 39643, COMM cadvisor, Lock no-ksym (0xffff9477eec5f1a8)
```

This is useful for locks that are per process, like `mmap_lock`.
  • Loading branch information
bobrik authored and yonghong-song committed Sep 6, 2022
1 parent 23f16da commit 857cf50
Showing 1 changed file with 8 additions and 2 deletions.
10 changes: 8 additions & 2 deletions libbpf-tools/klockstat.c
Original file line number Diff line number Diff line change
Expand Up @@ -83,7 +83,7 @@ static const char program_doc[] =
" klockstat -t 181 # trace thread 181 only\n"
" klockstat -c pipe_ # print only for lock callers with 'pipe_'\n"
" # prefix\n"
" klockstat -L cgroup_mutex # trace the cgroup_mutex lock only\n"
" klockstat -L cgroup_mutex # trace the cgroup_mutex lock only (accepts addr too)\n"
" klockstat -S acq_count # sort lock acquired results by acquire count\n"
" klockstat -S hld_total # sort lock held results by total held time\n"
" klockstat -S acq_count,hld_total # combination of above\n"
Expand Down Expand Up @@ -114,11 +114,17 @@ static const struct argp_option opts[] = {
{},
};

static void *parse_lock_addr(const char *lock_name) {
unsigned long lock_addr;

return sscanf(lock_name, "0x%lx", &lock_addr) ? (void*)lock_addr : NULL;
}

static void *get_lock_addr(struct ksyms *ksyms, const char *lock_name)
{
const struct ksym *ksym = ksyms__get_symbol(ksyms, lock_name);

return ksym ? (void*)ksym->addr : NULL;
return ksym ? (void*)ksym->addr : parse_lock_addr(lock_name);
}

const char *get_lock_name(struct ksyms *ksyms, unsigned long addr)
Expand Down

0 comments on commit 857cf50

Please sign in to comment.