XXX Log to perfdb.dcol1.delphix.com by default

bpf/estat/backend-io.c

@@ -29,7 +29,6 @@ typedef struct {
 
 BPF_HASH(io_base_data, u64, io_data_t);
 
-// @@ kprobe|blk_start_request|disk_io_start
 // @@ kprobe|blk_mq_start_request|disk_io_start
 int
 disk_io_start(struct pt_regs *ctx, struct request *reqp)
@@ -44,7 +43,7 @@ disk_io_start(struct pt_regs *ctx, struct request *reqp)
 	return (0);
 }
 
-// @@ kprobe|blk_account_io_completion|disk_io_done
+// @@ kprobe|blk_account_io_done|disk_io_done
 int
 disk_io_done(struct pt_regs *ctx, struct request *reqp)
 {

bpf/estat/zvol.c

@@ -31,7 +31,6 @@
 #define	POOL (OPTARG)
 #endif
 
-
 // Structure to hold thread local data
 typedef struct {
 	u64 ts;

bpf/stbtrace/io.st

@@ -128,7 +128,7 @@ b = BPF(text=bpf_text)
 if BPF.get_kprobe_functions(b'blk_start_request'):
     b.attach_kprobe(event="blk_start_request", fn_name="disk_io_start")
 b.attach_kprobe(event="blk_mq_start_request", fn_name="disk_io_start")
-b.attach_kprobe(event="blk_account_io_completion", fn_name="disk_io_done")
+b.attach_kprobe(event="blk_account_io_done", fn_name="disk_io_done")
 
 
 helper = BCCHelper(b, BCCHelper.ANALYTICS_PRINT_MODE)

bpf/stbtrace/iscsi.st

@@ -38,8 +38,8 @@ bpf_text += """
 #define OP_NAME_LEN 6
 typedef struct {
     u64 ts;
-    u64 flags;
     u64 size;
+    u32 direction;
 } iscsi_data_t;
 
 // Key structure for scalar aggegations maps
@@ -52,7 +52,8 @@ typedef struct {
 
 HIST_KEY(iscsi_hist_key_t, iscsi_key_t);
 
-BPF_HASH(iscsi_base_data, u64, iscsi_data_t);
+BPF_HASH(iscsi_start_ts, u64, u64);
+BPF_HASH(iscsi_base_data, u32, iscsi_data_t);
 $maps:{map|
 BPF_HASH($map.name$, iscsi_key_t, $map.type$);
 }$
@@ -64,13 +65,31 @@ BPF_HASH($hist.name$, iscsi_hist_key_t, u64);
 int iscsi_target_start(struct pt_regs *ctx, struct iscsi_conn *conn,
                        struct iscsi_cmd *cmd, struct iscsi_scsi_req *hdr)
 {
-    iscsi_data_t data = {};
-    data.ts = bpf_ktime_get_ns();
-    data.flags = hdr->flags;
-    data.size = hdr->data_length;
-    iscsi_base_data.update((u64 *) &cmd, &data);
+        u64 ts = bpf_ktime_get_ns();
+        iscsi_start_ts.update((u64 *) &cmd, &ts);
 
-    return 0;
+        return (0);
+}
+
+int iscsi_target_response(struct pt_regs *ctx, struct iscsi_conn *conn,
+                          struct iscsi_cmd *cmd, int state)
+{
+        u32 tid = bpf_get_current_pid_tgid();
+        iscsi_data_t data = {};
+
+        u64 *tsp = iscsi_start_ts.lookup((u64 *) &cmd);
+        if (tsp == 0) {
+                return (0);   // missed issue
+        }
+
+        data.ts = *tsp;
+        data.size = cmd->se_cmd.data_length;
+        data.direction = cmd->data_direction;
+
+        iscsi_base_data.update(&tid, &data);
+        iscsi_start_ts.delete((u64 *) &cmd);
+
+        return (0);
 }
 
 static int aggregate_data(iscsi_data_t *data, u64 ts, char *opstr)
@@ -99,33 +118,31 @@ static int aggregate_data(iscsi_data_t *data, u64 ts, char *opstr)
     return 0;
 }
 
-int iscsi_target_end(struct pt_regs *ctx, struct iscsi_cmd *cmd)
+int iscsi_target_end(struct pt_regs *ctx)
 {
-    u64 ts = bpf_ktime_get_ns();
-    iscsi_data_t *data = iscsi_base_data.lookup((u64 *) &cmd);
-    u64 delta;
-    iscsi_key_t key = {};
-    char *opstr;
-
-    if (data == 0) {
-        return 0;   // missed issue
-    }
-
-    if (data->flags & ISCSI_FLAG_CMD_READ) {
-        aggregate_data(data, ts, READ_STR);
-    } else if (data->flags & ISCSI_FLAG_CMD_WRITE) {
-        aggregate_data(data, ts, WRITE_STR);
-    }
-    iscsi_base_data.delete((u64 *) &cmd);
-
-    return 0;
+        u64 ts = bpf_ktime_get_ns();
+        u32 tid = bpf_get_current_pid_tgid();
+        iscsi_data_t *data = iscsi_base_data.lookup(&tid);
+
+        if (data == 0) {
+                return (0);   // missed issue
+        }
+
+        if (data->direction == DMA_FROM_DEVICE) {
+                aggregate_data(data, ts, READ_STR);
+        } else if (data->direction == DMA_TO_DEVICE) {
+                aggregate_data(data, ts, WRITE_STR);
+        }
+        iscsi_base_data.delete(&tid);
+
+        return (0);
 }
-
 """  # noqa: W293
 b = BPF(text=bpf_text)
 
 b.attach_kprobe(event="iscsit_process_scsi_cmd", fn_name="iscsi_target_start")
-b.attach_kprobe(event="iscsit_build_rsp_pdu", fn_name="iscsi_target_end")
+b.attach_kprobe(event="iscsit_response_queue", fn_name="iscsi_target_response")
+b.attach_kretprobe(event="iscsit_response_queue", fn_name="iscsi_target_end")
 
 helper = BCCHelper(b, BCCHelper.ANALYTICS_PRINT_MODE)
 $maps:{map|

bpf/stbtrace/zpl.st

@@ -28,7 +28,8 @@ bpf_text += """
 #include <linux/bpf_common.h>
 #include <uapi/linux/bpf.h>
 
-#include <sys/uio.h>
+#include <sys/xvattr.h>
+#include <sys/zfs_znode.h>
 
 // Definitions for this script
 #define READ_STR "read"
@@ -67,9 +68,9 @@ BPF_HASH($hist.name$, zpl_hist_key_t, u64);
 }$
 
 // Probe functions to initialize thread local data
-int zfs_read_start(struct pt_regs *ctx, void *inode, uio_t *uio)
+int zfs_read_start(struct pt_regs *ctx, struct znode *zn, zfs_uio_t *uio,
+   int flags)
 {
-
     u32 pid = bpf_get_current_pid_tgid();
     zpl_data_t data = {};
     data.ts = bpf_ktime_get_ns();
@@ -81,9 +82,9 @@ int zfs_read_start(struct pt_regs *ctx, void *inode, uio_t *uio)
 }
 
 // Probe functions to initialize thread local data
-int zfs_write_start(struct pt_regs *ctx, void *inode, uio_t *uio)
+int zfs_write_start(struct pt_regs *ctx, struct znode *zn, zfs_uio_t *uio,
+    int flags)
 {
-
     u32 pid = bpf_get_current_pid_tgid();
     zpl_data_t data = {};
     data.ts = bpf_ktime_get_ns();

cmd/estat.py

@@ -89,6 +89,7 @@ def die(*args, **kwargs):
       -q/-Q     enable/disable latency histograms by size (default: off)
       -y/-Y     enable/disable the summary output (default: on)
       -t/-T     enable/disable emitting the summary total (default: on)
+      -j        set output mode to JSON
       -d LEVEL  set BCC debug level
       -e        emit the resulting eBPF script without executing it
 
@@ -111,7 +112,6 @@ def die(*args, **kwargs):
       particular the time spent allocating a block and time spent waiting for
       the write I/O to complete. If POOL is not specified, defaults to tracing
       the pool 'domain0'.
-
 """
 
 
@@ -149,6 +149,7 @@ def usage(msg):
 script_arg = None
 debug_level = 0
 dump_bpf = False
+output_mode = BCCHelper.ESTAT_PRINT_MODE
 
 
 class Args:
@@ -161,6 +162,7 @@ class Args:
 setattr(args, "latsize_hist", False)
 setattr(args, "summary", True)
 setattr(args, "total", True)
+setattr(args, "json", False)
 
 #
 # We use getopt rather than argparse because it is very difficult to get
@@ -170,7 +172,7 @@ class Args:
 # arguments.
 #
 try:
-    opts, rem_args = getopt.getopt(sys.argv[2:], "hmMa:lLzZqQyYnNtTd:e")
+    opts, rem_args = getopt.getopt(sys.argv[2:], "hmMa:lLjzZqQyYnNtTd:e")
 except getopt.GetoptError as err:
     die(err)
 
@@ -194,6 +196,7 @@ class Args:
         dump_bpf = True
     else:
         switches = {'-l': "lat_hist",
+                    '-j': "json",
                     '-z': "size_hist",
                     '-q': "latsize_hist",
                     '-y': "summary",
@@ -219,6 +222,9 @@ class Args:
 if not (args.lat_hist or args.size_hist or args.latsize_hist):
     args.lat_hist = True
 
+if args.json:
+    output_mode = BCCHelper.ANALYTICS_PRINT_MODE
+
 # Now that we are done parsing arguments, construct the text of the BPF program
 try:
     with open(base_dir + 'bpf/estat/' + program + '.c', 'r') as prog_file:
@@ -443,7 +449,7 @@ class Args:
                 probe_type + "'")
 
 if args.lat_hist or args.size_hist or args.summary:
-    helper1 = BCCHelper(b, BCCHelper.ESTAT_PRINT_MODE)
+    helper1 = BCCHelper(b, output_mode)
     helper1.add_key_type("name")
     helper1.add_key_type("axis")
 
@@ -465,23 +471,24 @@ class Args:
                                 "bytes")
 
 if args.latsize_hist:
-    helper2 = BCCHelper(b, BCCHelper.ESTAT_PRINT_MODE)
+    helper2 = BCCHelper(b, output_mode)
     helper2.add_aggregation("latsq", BCCHelper.LL_HISTOGRAM_AGGREGATION,
                             "microseconds")
     helper2.add_key_type("size")
     helper2.add_key_type("name")
     helper2.add_key_type("axis")
 
 if args.summary and args.total:
-    helper3 = BCCHelper(b, BCCHelper.ESTAT_PRINT_MODE)
+    helper3 = BCCHelper(b, output_mode)
     helper3.add_aggregation("opst", BCCHelper.COUNT_AGGREGATION, "iops(/s)")
     helper3.add_aggregation("datat", BCCHelper.SUM_AGGREGATION,
                             "throughput(k/s)")
     helper3.add_key_type("name")
 
 # Need real time;
-print("%-16s\n" % strftime("%D - %H:%M:%S %Z"))  # TODO deduplicate this line
-print(" Tracing enabled... Hit Ctrl-C to end.")
+if not args.json:
+    print("%-16s\n" % strftime("%D - %H:%M:%S %Z"))  # TODO deduplicate line
+    print(" Tracing enabled... Hit Ctrl-C to end.")
 
 # output
 if monitor:
@@ -508,7 +515,8 @@ class Args:
                 helper1.printall(clear_data)
             if args.summary and args.total:
                 helper3.printall(clear_data)
-            print("%-16s\n" % strftime("%D - %H:%M:%S %Z"))
+            if not args.json:
+                print("%-16s\n" % strftime("%D - %H:%M:%S %Z"))
         except Exception as e:
             die(e)
 else:

debian/control

@@ -13,6 +13,6 @@ Standards-Version: 4.1.2
 
 Package: performance-diagnostics
 Architecture: any
-Depends: python3-bcc, python3-minimal, python3-psutil
+Depends: python3-bcc, python3-minimal, python3-psutil, telegraf
 Description: eBPF-based Performance Diagnostic Tools
   A collection of eBPF-based tools for diagnosing performance issues.

debian/rules

@@ -22,3 +22,6 @@ override_dh_auto_install:
 	dh_install build/cmd/* /usr/bin
 	dh_install lib/* /usr/share/performance-diagnostics/lib
 	dh_install bpf/* /usr/share/performance-diagnostics/bpf
+	dh_install telegraf/delphix-telegraf-service telegraf/perf_playbook /usr/bin
+	dh_install telegraf/delphix-telegraf.service /lib/systemd/system
+	dh_install telegraf/telegraf* telegraf/*.sh /etc/telegraf

telegraf/delphix-telegraf-service

@@ -0,0 +1,34 @@
+#!/bin/bash
+BASE_CONFIG=/etc/telegraf/telegraf.base
+DOSE_INPUTS=/etc/telegraf/telegraf.inputs.dose
+PLAYBOOK_INPUTS=/etc/telegraf/telegraf.inputs.playbook
+PLAYBOOK_FLAG=/etc/telegraf/PLAYBOOK_ENABLED
+TELEGRAF_CONFIG=/etc/telegraf/telegraf.conf
+
+
+function engine_is_object_based() {
+	zdb -C | grep "type: 'object_store'" >/dev/null
+	[[ "$?" == "0" ]]
+}
+
+function playbook_is_enabled() {
+	[[ -f $PLAYBOOK_FLAG ]]
+}
+
+rm -f $TELEGRAF_CONFIG
+
+if engine_is_object_based; then
+	if playbook_is_enabled; then
+		cat $PLAYBOOK_INPUTS $DOSE_INPUTS $BASE_CONFIG > $TELEGRAF_CONFIG
+	else
+		cat $DOSE_INPUTS $BASE_CONFIG > $TELEGRAF_CONFIG
+	fi
+else
+	if playbook_is_enabled; then
+		cat $PLAYBOOK_INPUTS $BASE_CONFIG > $TELEGRAF_CONFIG
+	else
+		cat $BASE_CONFIG > $TELEGRAF_CONFIG
+	fi
+fi
+
+/usr/bin/telegraf -config $TELEGRAF_CONFIG

telegraf/delphix-telegraf.service

@@ -0,0 +1,18 @@
+[Unit]
+Description=Delphix Telegraf Metric Collection Agent
+Documentation=https://github.com/influxdata/telegraf
+PartOf=delphix.target
+After=delphix-platform.service
+PartOf=delphix-platform.service
+
+[Service]
+EnvironmentFile=-/etc/default/telegraf
+User=root
+ExecStart=/usr/bin/delphix-telegraf-service
+ExecReload=/bin/kill -HUP $MAINPID
+Restart=on-failure
+RestartForceExitStatus=SIGPIPE
+KillMode=control-group
+
+[Install]
+WantedBy=delphix.target

telegraf/nfs-threads.sh

@@ -0,0 +1,3 @@
+#!/bin/sh
+nfs_threads | egrep --line-buffered -v "thr"
+