tools/virtiostat: add virtiostat tool

Add a new tool virtiostat to trace VIRTIO devices IO statistics.

Although we have already had iostat(to show block device statistics),
iftop(to show network device statistics), other devices of VIRTIO
family(Ex, console, balloon, GPU and so on) also need tools for each
type. virtiostat works in virtio lower layer, and it could trace all
the devices.

Signed-off-by: zhenwei pi <[email protected]>

README.md

@@ -175,6 +175,7 @@ pair of .c and .py files, and some are directories of files.
 - tools/[uthreads](tools/lib/uthreads.py): Trace thread creation events in Java and raw pthreads. [Examples](tools/lib/uthreads_example.txt).
 - tools/[vfscount](tools/vfscount.py): Count VFS calls. [Examples](tools/vfscount_example.txt).
 - tools/[vfsstat](tools/vfsstat.py): Count some VFS calls, with column output. [Examples](tools/vfsstat_example.txt).
+- tools/[virtiostat](tools/virtiostat.py): Show VIRTIO device IO statistics. [Examples](tools/virtiostat_example.txt).
 - tools/[wakeuptime](tools/wakeuptime.py): Summarize sleep to wakeup time by waker kernel stack. [Examples](tools/wakeuptime_example.txt).
 - tools/[xfsdist](tools/xfsdist.py): Summarize XFS operation latency distribution as a histogram. [Examples](tools/xfsdist_example.txt).
 - tools/[xfsslower](tools/xfsslower.py): Trace slow XFS operations. [Examples](tools/xfsslower_example.txt).

man/man8/virtiostat.8

@@ -0,0 +1,56 @@
+.TH virtiostat 8  "2021-02-15" "USER COMMANDS"
+.SH NAME
+virtiostat \- Trace VIRTIO devices input/output statistics. Uses Linux eBPF/bcc.
+.SH SYNOPSIS
+.B virtiostat [\-h] [\-T] [\-D] [INTERVAL] [COUNT]
+.SH DESCRIPTION
+This tool traces VIRTIO devices input/output statistics. It works in lower
+layer of VIRTIO base driver, so it could trace all the devices of VIRTIO
+family. For example, we can't get IO statistics of 9p-fs in a guest virtual
+machine by iostat command, but we can analyze IO statistics by virtiostat.
+The outputing result shows In/Out SGs(scatter list operation) to represent
+positive correlation IOPS, and In/Out BW to represent throughput.
+
+Since this uses BPF, only the root user can use this tool.
+.SH REQUIREMENTS
+CONFIG_BPF and bcc.
+.SH OPTIONS
+.TP
+\-h
+Print usage message.
+.TP
+\-T
+Include a time column on output (HH:MM:SS).
+.TP
+\-D
+Show debug infomation of bpf text.
+.TP
+INTERVAL
+Print output every interval seconds.
+.TP
+COUNT
+Total count of trace in seconds.
+.SH EXAMPLES
+.TP
+Trace virtio device statistics and print 1 second summaries, 10 times:
+#
+.B virtiostat 1 10
+.SH OVERHEAD
+This traces the kernel virtqueue_add_sgs, virtqueue_add_outbuf,
+virtqueue_add_inbuf, virtqueue_add_inbuf_ctx functions.
+The rate of this depends on all the VIRTIO devices IOPS.
+.SH SOURCE
+This is from bcc.
+.IP
+https://github.com/iovisor/bcc
+.PP
+Also look in the bcc distribution for a companion _examples.txt file containing
+example usage, output, and commentary for this tool.
+.SH OS
+Linux
+.SH STABILITY
+Unstable - in development.
+.SH AUTHOR
+zhenwei pi
+.SH SEE ALSO
+iostat(1), iftop(8), funccount(8)

tools/virtiostat.py

@@ -0,0 +1,238 @@
+#!/usr/bin/python
+# @lint-avoid-python-3-compatibility-imports
+#
+# virtiostat    Show virtio devices input/output statistics.
+#               For Linux, uses BCC, eBPF.
+#
+# USAGE: virtiostat [-h] [-T] [-D] [INTERVAL] [COUNT]
+#
+# Copyright (c) 2021 zhenwei pi
+# Licensed under the Apache License, Version 2.0 (the "License")
+#
+# 13-Feb-2021  zhenwei pi  Created this.
+
+from __future__ import print_function
+from bcc import BPF
+from time import sleep, strftime
+import argparse
+
+# arguments
+examples = """examples:
+    ./virtiostat            # print 3(default) second summaries
+    ./virtiostat  1  10     # print 1 second summaries, 10 times
+    ./virtiostat -T         # show timestamps
+    ./virtiostat -D         # show debug bpf text
+"""
+parser = argparse.ArgumentParser(
+    description="Show virtio devices input/output statistics",
+    formatter_class=argparse.RawDescriptionHelpFormatter,
+    epilog=examples)
+parser.add_argument("interval", nargs="?", default=3,
+    help="output interval, in seconds")
+parser.add_argument("count", nargs="?", default=99999999,
+    help="number of outputs")
+parser.add_argument("-T", "--timestamp", action="store_true",
+    help="show timestamp on output")
+parser.add_argument("-D", "--debug", action="store_true",
+    help="print BPF program before starting (for debugging purposes)")
+parser.add_argument("--ebpf", action="store_true",
+    help=argparse.SUPPRESS)
+args = parser.parse_args()
+
+# define BPF program
+bpf_text = """
+#ifndef KBUILD_MODNAME
+#define KBUILD_MODNAME "bcc"
+#endif
+#include <linux/virtio.h>
+#include <bcc/proto.h>
+
+/* typically virtio scsi has max SGs of 6 */
+#define VIRTIO_MAX_SGS  6
+/* typically virtio blk has max SEG of 128 */
+#define SG_MAX          128
+
+typedef struct virtio_stat {
+    char driver[16];
+    char dev[12];
+    char vqname[12];
+    u32 in_sgs;
+    u32 out_sgs;
+    u64 in_bw;
+    u64 out_bw;
+} virtio_stat_t;
+
+BPF_HASH(stats, u64, virtio_stat_t);
+
+static struct scatterlist *__sg_next(struct scatterlist *sgp)
+{
+    struct scatterlist sg;
+
+    bpf_probe_read_kernel(&sg, sizeof(sg), sgp);
+    if (sg_is_last(&sg))
+        return NULL;
+
+    sgp++;
+
+    bpf_probe_read_kernel(&sg, sizeof(sg), sgp);
+    if (unlikely(sg_is_chain(&sg)))
+        sgp = sg_chain_ptr(&sg);
+
+    return sgp;
+}
+
+static u64 count_len(struct scatterlist **sgs, unsigned int num)
+{
+    u64 length = 0;
+    unsigned int i, n;
+    struct scatterlist *sgp = NULL;
+
+    for (i = 0; (i < VIRTIO_MAX_SGS) && (i < num); i++) {
+        for (n = 0, sgp = sgs[i]; sgp && (n < SG_MAX); sgp = __sg_next(sgp)) {
+            length += sgp->length;
+            n++;
+        }
+
+        /* Suggested by Yonghong Song:
+         * IndVarSimplifyPass with clang 12 may cause verifier failure:
+         *   ; for (i = 0; (i < VIRTIO_MAX_SGS) && (i < num); i++) { // Line  60
+         *   90:   15 08 15 00 00 00 00 00 if r8 == 0 goto +21
+         *   91:   bf 81 00 00 00 00 00 00 r1 = r8
+         *   92:   07 01 00 00 ff ff ff ff r1 += -1
+         *   93:   67 01 00 00 20 00 00 00 r1 <<= 32
+         *   94:   77 01 00 00 20 00 00 00 r1 >>= 32
+         *   95:   b7 02 00 00 05 00 00 00 r2 = 5
+         *   96:   2d 12 01 00 00 00 00 00 if r2 > r1 goto +1
+         *   97:   b7 08 00 00 06 00 00 00 r8 = 6
+         *   98:   b7 02 00 00 00 00 00 00 r2 = 0
+         *   99:   b7 09 00 00 00 00 00 00 r9 = 0
+         *  100:   7b 8a 68 ff 00 00 00 00 *(u64 *)(r10 - 152) = r8
+         *  101:   05 00 35 00 00 00 00 00 goto +53
+         * Note that r1 is refined by r8 is saved to stack for later use.
+         * This will give verifier u64_max loop bound and eventually cause
+         * verification failure. Workaround with the below asm code.
+         */
+#if __clang_major__ >= 7
+        asm volatile("" : "=r"(i) : "0"(i));
+#endif
+    }
+
+    return length;
+}
+
+static void record(struct virtqueue *vq, struct scatterlist **sgs,
+                   unsigned int out_sgs, unsigned int in_sgs)
+{
+    virtio_stat_t newvs = {0};
+    virtio_stat_t *vs;
+    u64 key = (u64)vq;
+    u64 in_bw = 0;
+
+    /* Workaround: separate two count_len() calls, one here and the
+     * other below. Otherwise, compiler may generate some spills which
+     * harms verifier pruning. This happens in llvm12, but not llvm4.
+     * Below code works on both cases.
+     */
+    if (in_sgs)
+        in_bw = count_len(sgs + out_sgs, in_sgs);
+
+    vs = stats.lookup(&key);
+    if (!vs) {
+        bpf_probe_read_kernel(newvs.driver, sizeof(newvs.driver), vq->vdev->dev.driver->name);
+        bpf_probe_read_kernel(newvs.dev, sizeof(newvs.dev), vq->vdev->dev.kobj.name);
+        bpf_probe_read_kernel(newvs.vqname, sizeof(newvs.vqname), vq->name);
+        newvs.out_sgs = out_sgs;
+        newvs.in_sgs = in_sgs;
+        if (out_sgs)
+            newvs.out_bw = count_len(sgs, out_sgs);
+        newvs.in_bw = in_bw;
+        stats.update(&key, &newvs);
+    } else {
+        vs->out_sgs += out_sgs;
+        vs->in_sgs += in_sgs;
+        if (out_sgs)
+            vs->out_bw += count_len(sgs, out_sgs);
+        vs->in_bw += in_bw;
+    }
+}
+
+int trace_virtqueue_add_sgs(struct pt_regs *ctx, struct virtqueue *vq,
+                            struct scatterlist **sgs, unsigned int out_sgs,
+                            unsigned int in_sgs, void *data, gfp_t gfp)
+
+{
+    record(vq, sgs, out_sgs, in_sgs);
+
+    return 0;
+}
+
+int trace_virtqueue_add_outbuf(struct pt_regs *ctx, struct virtqueue *vq,
+                              struct scatterlist *sg, unsigned int num,
+                              void *data, gfp_t gfp)
+{
+    record(vq, &sg, 1, 0);
+
+    return 0;
+}
+
+int trace_virtqueue_add_inbuf(struct pt_regs *ctx, struct virtqueue *vq,
+                             struct scatterlist *sg, unsigned int num,
+                             void *data, gfp_t gfp)
+{
+    record(vq, &sg, 0, 1);
+
+    return 0;
+}
+
+int trace_virtqueue_add_inbuf_ctx(struct pt_regs *ctx, struct virtqueue *vq,
+                                  struct scatterlist *sg, unsigned int num,
+                                  void *data, void *_ctx, gfp_t gfp)
+{
+    record(vq, &sg, 0, 1);
+
+    return 0;
+}
+"""
+
+# debug mode: print bpf text
+if args.debug:
+    print(bpf_text)
+
+# dump mode: print bpf text and exit
+if args.ebpf:
+    print(bpf_text)
+    exit()
+
+# load BPF program
+b = BPF(text=bpf_text)
+b.attach_kprobe(event="virtqueue_add_sgs", fn_name="trace_virtqueue_add_sgs")
+b.attach_kprobe(event="virtqueue_add_outbuf", fn_name="trace_virtqueue_add_outbuf")
+b.attach_kprobe(event="virtqueue_add_inbuf", fn_name="trace_virtqueue_add_inbuf")
+b.attach_kprobe(event="virtqueue_add_inbuf_ctx", fn_name="trace_virtqueue_add_inbuf_ctx")
+
+print("Tracing virtio devices statistics ... Hit Ctrl-C to end.")
+
+# start main loop
+exiting = 0 if args.interval else 1
+seconds = 0
+while (1):
+    try:
+        sleep(int(args.interval))
+        seconds = seconds + int(args.interval)
+    except KeyboardInterrupt:
+        exiting = 1
+
+    if args.timestamp:
+        print("%-8s\n" % strftime("%H:%M:%S"), end="")
+    else:
+        print("--------", end="\n")
+
+    print("%14s %8s %10s %7s %7s %14s %14s" % ("Driver", "Device", "VQ Name", "In SGs", "Out SGs", "In BW", "Out BW"))
+    stats = b.get_table("stats")
+    for k, v in sorted(stats.items(), key=lambda vs: vs[1].dev):
+        print("%14s %8s %10s %7d %7d %14d %14d" % (v.driver, v.dev, v.vqname, v.in_sgs, v.out_sgs, v.in_bw, v.out_bw))
+
+    stats.clear()
+
+    if exiting or seconds >= int(args.count):
+        exit()

tools/virtiostat_example.txt

@@ -0,0 +1,46 @@
+Demonstrations of virtiostat, the Linux eBPF/bcc version.
+
+
+This program traces virtio devices to analyze the IO operations and
+throughput. For example, guest side mounts a 9p fs, and we can't get
+io statistics by `iostat` command any more. In this scenario, we can
+only get statistics from VIRTIO layer instead of block layer.
+
+Example
+#./virtiostat -T
+Tracing virtio devices statistics ... Hit Ctrl-C to end.
+14:48:30
+        Driver   Device    VQ Name  In SGs Out SGs          In BW         Out BW
+    virtio_net  virtio0    input.0  260669       0      406743040              0
+    virtio_net  virtio0   output.0       0    9873              0         833344
+    virtio_blk  virtio4      req.0      28      46            448         278976
+  9pnet_virtio  virtio6   requests   99083   99354        1883687      137537263
+14:48:33
+        Driver   Device    VQ Name  In SGs Out SGs          In BW         Out BW
+    virtio_net  virtio0    input.0  260718       0      406819328              0
+    virtio_net  virtio0   output.0       0    7139              0         562355
+    virtio_blk  virtio4      req.0      11      18            176         110768
+  9pnet_virtio  virtio6   requests   91520   91141        1737364      125320785
+
+
+Full USAGE:
+
+#./virtiostat -h
+usage: virtiostat.py [-h] [-T] [-D] [interval] [count]
+
+Show virtio devices input/output statistics
+
+positional arguments:
+  interval         output interval, in seconds
+  count            number of outputs
+
+optional arguments:
+  -h, --help       show this help message and exit
+  -T, --timestamp  show timestamp on output
+  -D, --debug      print BPF program before starting (for debugging purposes)
+
+examples:
+    ./virtiostat            # print 3(default) second summaries
+    ./virtiostat  1  10     # print 1 second summaries, 10 times
+    ./virtiostat -T         # show timestamps
+    ./virtiostat -D         # show debug bpf text