top-threads: a script for viewing real-time runqueue latency per thread
Tags: troubleshooting, performance, linux, observability
Published: 2020-07-22 14:29:15

A few years ago, when I was working at [Despegar] (Argentina) I wrote a little `python` script that helped me a lot observing and identifying issues related to CPU usage.

{% github cspinetta/top-threads no-readme %}

It's a user-friendly command-line interface that provides a dynamic real-time view of the active threads for a given process with stats of CPU, disk and *scheduling*.

The metrics make it really powerful is those related to scheduling: time spent on the cpu / on the runqueue.

### Why?

In some cases it's interesting to know how much time the threads spend *trying to get onto CPU*, instead of *being on CPU*. This type of information can be easily obtained with tracing tools like [perf] and [BCC], but these tools require *root privilege*, something that is often not available in production servers, so you can't use them for troubleshooting.

### What came up?

I ended up developing a script in `Python` that allows me to visualize in real-time *the run queue latency per task* by reading the [/proc/{pid}/schedstat] file.

In fact, it shows some extra stats:

* CPU usage: _total_, _%usr_, _%system_, _%guest_ and _%wait_
* Disk usage: kB read per second and kB written per second
* Scheduler stats:
  - time spent on the cpu.
  - time spent waiting on a run queue (_runqueue latency_)
  - number of *timeslices* run on the current CPU.
* Java details: in case the target is a Java process that can be attached with `jstack`, some extra details is shown such as thread name and stack traces.

It requires:

* `Python 3`
* [systat]

It only works in `Linux` since it uses [/proc/{pid}/schedstat] to get scheduling stats.

### How to use it?

I kept the code in a single file, so it's as easy as downloading the script:

```bash
wget -O top_threads.py 'https://github.com/cspinetta/top-threads/releases/download/0.0.1/top_threads.py' \
  && chmod +x top_threads.py
```

Example of usages:

```bash
# watch <pid>'s threads with default values
./top_threads.py -p <pid>

# print output in the terminal
./top_threads.py -p <pid> --display terminal

# sorting by run queue latency
./top_threads.py -p <pid> --sort rq

# in case a java process, change the number of stack traces to display
./top_threads.py -p <pid> --max-stack-depth 10

# enable debug log for troubleshooting
./top_threads.py -p <pid> --debug
```

**Some things to keep in mind:**
* The first output is with stats from the first execution of the process.
* `--display refresh` provides a view similar to `top` or `watch` (the default) while `terminal` prints the output on each iteration in the terminal like `pidstat`.

### What is a good use case for this tool?

I often use this script when I have to analyze a performance problem at thread level and I want to inspect the dynamic usage of CPU or Disk.

Some questions this tool helps me to answer:

* Which thread is eating the entire CPU?
* How long are the threads waiting to take the CPU?
* What threads are using the disk right now?

### Example in pictures

* With `--display refresh` (the default):

![Top Java Threads Refresh](https://dev-to-uploads.s3.amazonaws.com/i/228lkptniqw0jp8syx49.png)

* With `--display terminal`:

![Top Java Threads in Terminal](https://dev-to-uploads.s3.amazonaws.com/i/r3pbcs11uzd1d4okvjds.png)

### Usage

```bash
usage: top_threads.py [-h] -p PID [-n [NUMBER]]
                      [--max-stack-depth [STACK_SIZE]]
                      [--sort [{cpu,rq,disk,disk-rd,disk-wr}]]
                      [--display [{terminal,refresh}]] [--no-jstack] [--debug]

Tool for analysing active Threads

optional arguments:
  -h, --help            show this help message and exit
  -p PID                Process ID
  -n [NUMBER]           Number of threads to show per sample. Default: 10
  --max-stack-depth [STACK_SIZE], -m [STACK_SIZE]
                        Max number of stack frames (only when jstack can be
                        used). Default: 1
  --sort [{cpu,rq,disk,disk-rd,disk-wr}], -s [{cpu,rq,disk,disk-rd,disk-wr}]
                        Field used for sorting. Default: cpu
  --display [{terminal,refresh}], -d [{terminal,refresh}]
                        Select the way to display the info: terminal or
                        refresh. Default: refresh
  --no-jstack           Turn off usage of jstack to retrieve thread info like
                        name and stack
  --debug               Turn on logs for debugging purposes

```

[Despegar]: https://www.linkedin.com/company/despegar/
[/proc/{pid}/schedstat]: https://www.kernel.org/doc/html/latest/scheduler/sched-stats.html#proc-pid-schedstat
[systat]: https://github.com/sysstat/sysstat
[pidstat]: https://linux.die.net/man/1/pidstat
[jstack]: https://docs.oracle.com/javase/9/tools/jstack.htm#JSWOR748
[perf]: https://perf.wiki.kernel.org/index.php/Main_Page
[BCC]: https://github.com/iovisor/bcc