tools/biolatency: Extend average/total value

Sometimes log2 range is not enough for throughput tuning.
Especially a little difference in performance downgrade.

Also, this extension uses two bpf helper bpf_map_lookup_elem().
It's a cost on embedded system, therefore it's better to be an option.

Signed-off-by: Edward Wu <edwardwu@realtek.com>

diff --git a/man/man8/biolatency.8 b/man/man8/biolatency.8
index c303eec0b804416471d3d5330b1c06aaaed0651c..c13f6c8ad036a070e169508cd5f607ddbdc6a713 100644 (file)
--- a/man/man8/biolatency.8
+++ b/man/man8/biolatency.8
@@ -2,7 +2,7 @@
 .SH NAME
 biolatency \- Summarize block device I/O latency as a histogram.
 .SH SYNOPSIS
-.B biolatency [\-h] [\-F] [\-T] [\-Q] [\-m] [\-D] [interval [count]]
+.B biolatency [\-h] [\-F] [\-T] [\-Q] [\-m] [\-D] [\-e] [interval [count]]
 .SH DESCRIPTION
 biolatency traces block device I/O (disk I/O), and records the distribution
 of I/O latency (time). This is printed as a histogram either on Ctrl-C, or
@@ -39,6 +39,9 @@ Print a histogram per set of I/O flags.
 \-j
 Print a histogram dictionary
 .TP
+\-e
+Show extension summary(total, average)
+.TP
 interval
 Output interval, in seconds.
 .TP
@@ -70,6 +73,10 @@ Show a latency histogram for each disk device separately:
 Show a latency histogram in a dictionary format:
 #
 .B biolatency \-j
+.TP
+Also show extension summary(total, average):
+#
+.B biolatency \-e
 .SH FIELDS
 .TP
 usecs

diff --git a/tools/biolatency.py b/tools/biolatency.py
index 28386babe00b8981f342217930485b03f5b82fc1..0599609b8d11715608f8a110ba5f646c3dfc8478 100755 (executable)
--- a/tools/biolatency.py
+++ b/tools/biolatency.py
@@ -4,7 +4,7 @@
 # biolatency    Summarize block device I/O latency as a histogram.
 #       For Linux, uses BCC, eBPF.
 #
-# USAGE: biolatency [-h] [-T] [-Q] [-m] [-D] [interval] [count]
+# USAGE: biolatency [-h] [-T] [-Q] [-m] [-D] [-e] [interval] [count]
 #
 # Copyright (c) 2015 Brendan Gregg.
 # Licensed under the Apache License, Version 2.0 (the "License")
@@ -26,6 +26,7 @@ examples = """examples:
     ./biolatency -D                 # show each disk device separately
     ./biolatency -F                 # show I/O flags separately
     ./biolatency -j                 # print a dictionary
+    ./biolatency -e                 # show extension summary(total, average)
 """
 parser = argparse.ArgumentParser(
     description="Summarize block device I/O latency as a histogram",
@@ -41,6 +42,8 @@ parser.add_argument("-D", "--disks", action="store_true",
     help="print a histogram per disk device")
 parser.add_argument("-F", "--flags", action="store_true",
     help="print a histogram per set of I/O flags")
+parser.add_argument("-e", "--extension", action="store_true",
+    help="summarize average/total value")
 parser.add_argument("interval", nargs="?", default=99999999,
     help="output interval, in seconds")
 parser.add_argument("count", nargs="?", default=99999999,
@@ -73,6 +76,11 @@ typedef struct flag_key {
     u64 slot;
 } flag_key_t;
 
+typedef struct ext_val {
+    u64 total;
+    u64 count;
+} ext_val_t;
+
 BPF_HASH(start, struct request *);
 STORAGE
 
@@ -95,6 +103,9 @@ int trace_req_done(struct pt_regs *ctx, struct request *req)
         return 0;   // missed issue
     }
     delta = bpf_ktime_get_ns() - *tsp;
+
+    EXTENSION
+
     FACTOR
 
     // store as histogram
@@ -112,25 +123,43 @@ if args.milliseconds:
 else:
     bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000;')
     label = "usecs"
+
+storage_str = ""
+store_str = ""
 if args.disks:
-    bpf_text = bpf_text.replace('STORAGE',
-        'BPF_HISTOGRAM(dist, disk_key_t);')
-    bpf_text = bpf_text.replace('STORE',
-        'disk_key_t key = {.slot = bpf_log2l(delta)}; ' +
-        'void *__tmp = (void *)req->rq_disk->disk_name; ' +
-        'bpf_probe_read_kernel(&key.disk, sizeof(key.disk), __tmp); ' +
-        'dist.increment(key);')
+    storage_str += "BPF_HISTOGRAM(dist, disk_key_t);"
+    store_str += """
+    disk_key_t key = {.slot = bpf_log2l(delta)};
+    void *__tmp = (void *)req->rq_disk->disk_name;
+    bpf_probe_read(&key.disk, sizeof(key.disk), __tmp);
+    dist.increment(key);
+    """
 elif args.flags:
-    bpf_text = bpf_text.replace('STORAGE',
-        'BPF_HISTOGRAM(dist, flag_key_t);')
-    bpf_text = bpf_text.replace('STORE',
-        'flag_key_t key = {.slot = bpf_log2l(delta)}; ' +
-        'key.flags = req->cmd_flags; ' +
-        'dist.increment(key);')
+    storage_str += "BPF_HISTOGRAM(dist, flag_key_t);"
+    store_str += """
+    flag_key_t key = {.slot = bpf_log2l(delta)};
+    key.flags = req->cmd_flags;
+    dist.increment(key);
+    """
 else:
-    bpf_text = bpf_text.replace('STORAGE', 'BPF_HISTOGRAM(dist);')
-    bpf_text = bpf_text.replace('STORE',
-        'dist.increment(bpf_log2l(delta));')
+    storage_str += "BPF_HISTOGRAM(dist);"
+    store_str += "dist.increment(bpf_log2l(delta));"
+
+if args.extension:
+    storage_str += "BPF_ARRAY(extension, ext_val_t, 1);"
+    bpf_text = bpf_text.replace('EXTENSION', """
+    u32 index = 0;
+    ext_val_t *ext_val = extension.lookup(&index);
+    if (ext_val) {
+        lock_xadd(&ext_val->total, delta);
+        lock_xadd(&ext_val->count, 1);
+    }
+    """)
+else:
+    bpf_text = bpf_text.replace('EXTENSION', '')
+bpf_text = bpf_text.replace("STORAGE", storage_str)
+bpf_text = bpf_text.replace("STORE", store_str)
+
 if debug or args.ebpf:
     print(bpf_text)
     if args.ebpf:
@@ -203,6 +232,8 @@ def flags_print(flags):
 # output
 exiting = 0 if args.interval else 1
 dist = b.get_table("dist")
+if args.extension:
+    extension = b.get_table("extension")
 while (1):
     try:
         sleep(int(args.interval))
@@ -226,9 +257,20 @@ while (1):
             
         if args.flags:
             dist.print_log2_hist(label, "flags", flags_print)
-
         else:
             dist.print_log2_hist(label, "disk")
+        if args.extension:
+            total = extension[0].total
+            counts = extension[0].count
+            if counts > 0:
+                if label == 'msecs':
+                    total /= 1000000
+                elif label == 'usecs':
+                    total /= 1000
+                avg = total / counts
+                print("\navg = %ld %s, total: %ld %s, count: %ld\n" %
+                      (total / counts, label, total, label, counts))
+            extension.clear()
 
     dist.clear()
 

diff --git a/tools/biolatency_example.txt b/tools/biolatency_example.txt
old mode 100644 (file)
new mode 100755 (executable)
index e710090..a88136b
--- a/tools/biolatency_example.txt
+++ b/tools/biolatency_example.txt
@@ -292,6 +292,32 @@ flags = Priority-Metadata-Write
 These can be handled differently by the storage device, and this mode lets us
 examine their performance in isolation.
 
+
+The -e option shows extension summary(total, average)
+For example:
+# ./biolatency.py -e
+^C
+     usecs               : count     distribution
+         0 -> 1          : 0        |                                        |
+         2 -> 3          : 0        |                                        |
+         4 -> 7          : 0        |                                        |
+         8 -> 15         : 0        |                                        |
+        16 -> 31         : 0        |                                        |
+        32 -> 63         : 0        |                                        |
+        64 -> 127        : 4        |***********                             |
+       128 -> 255        : 2        |*****                                   |
+       256 -> 511        : 4        |***********                             |
+       512 -> 1023       : 14       |****************************************|
+      1024 -> 2047       : 0        |                                        |
+      2048 -> 4095       : 1        |**                                      |
+
+avg = 663 usecs, total: 16575 usecs, count: 25
+
+Sometimes 512 -> 1023 usecs is not enough for throughput tuning.
+Especially a little difference in performance downgrade.
+By this extension, we know the value in log2 range is about 663 usecs.
+
+
 The -j option prints a dictionary of the histogram.
 For example:
 
@@ -342,6 +368,7 @@ optional arguments:
   -m, --milliseconds  millisecond histogram
   -D, --disks         print a histogram per disk device
   -F, --flags         print a histogram per set of I/O flags
+  -e, --extension     also show extension summary(total, average)
   -j, --json          json output
 
 examples:
@@ -352,3 +379,4 @@ examples:
     ./biolatency -D                 # show each disk device separately
     ./biolatency -F                 # show I/O flags separately
     ./biolatency -j                 # print a dictionary
+    ./biolatency -e                 # show extension summary(total, average)