Add tracepoints for taskq entry lifetime events

This adds some new DTRACE_PROBE* endpoints so that we can observe taskq
latencies on a system. Additionally, a new "taskqlatency.bt" script is
added to do this observation via "bpftrace". Lastly, a "zfs-trace.sh"
script is added to wrap "bpftrace" with the proper options required to
run and use "taskqlatency.bt".

For example, with these changes in place, a user can run the following:

    $ cd ./contrib/bpftrace
    $ sudo ./zfs-trace.sh taskqlatency.bt
    Attaching 6 probes...
    ^C

Here's some example output, showing latency information for time spent
executing the taskq entry's function:

    @exec_lat_us[dp_sync_taskq, userquota_updates_task]:
    [2, 4)                 5 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [4, 8)                 0 |                                                    |
    [8, 16)                1 |@@@@@@@@@@                                          |
    [16, 32)               2 |@@@@@@@@@@@@@@@@@@@@                                |

    @exec_lat_us[z_wr_int_h, zio_execute]:
    [8, 16)               16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [16, 32)               2 |@@@@@@                                              |

    @exec_lat_us[z_wr_iss_h, zio_execute]:
    [16, 32)               4 |@@@@@@@@@@@@@@@@                                    |
    [32, 64)              13 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [64, 128)              1 |@@@@                                                |

    @exec_lat_us[z_ioctl_int, zio_execute]:
    [2, 4)                 1 |@@@@                                                |
    [4, 8)                11 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [8, 16)                8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@               |

    @exec_lat_us[dp_sync_taskq, sync_dnodes_task]:
    [2, 4)                 1 |@@@@@@                                              |
    [4, 8)                 7 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@       |
    [8, 16)                8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [16, 32)               2 |@@@@@@@@@@@@@                                       |
    [32, 64)               4 |@@@@@@@@@@@@@@@@@@@@@@@@@@                          |
    [64, 128)              1 |@@@@@@                                              |
    [128, 256)             0 |                                                    |
    [256, 512)             1 |@@@@@@

Here's some example output, showing latency information for time spent
waiting on the taskq, prior to starting execution of entry's function:

    @queue_lat_us[dp_sync_taskq]:
    [2, 4)                 1 |@@@@                                                |
    [4, 8)                 7 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                      |
    [8, 16)                2 |@@@@@@@@                                            |
    [16, 32)               3 |@@@@@@@@@@@@@                                       |
    [32, 64)              12 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [64, 128)              6 |@@@@@@@@@@@@@@@@@@@@@@@@@@                          |
    [128, 256)             0 |                                                    |
    [256, 512)             1 |@@@@                                                |

    @queue_lat_us[z_wr_iss]:
    [4, 8)                 4 |@@@@                                                |
    [8, 16)               13 |@@@@@@@@@@@@@@@                                     |
    [16, 32)               6 |@@@@@@@                                             |
    [32, 64)               2 |@@                                                  |
    [64, 128)             12 |@@@@@@@@@@@@@@                                      |
    [128, 256)            15 |@@@@@@@@@@@@@@@@@@                                  |
    [256, 512)            33 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@             |
    [512, 1K)             27 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                    |
    [1K, 2K)               7 |@@@@@@@@                                            |
    [2K, 4K)              14 |@@@@@@@@@@@@@@@@                                    |
    [4K, 8K)              14 |@@@@@@@@@@@@@@@@                                    |
    [8K, 16K)             23 |@@@@@@@@@@@@@@@@@@@@@@@@@@@                         |
    [16K, 32K)            43 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|

    @queue_lat_us[z_wr_int]:
    [2, 4)                10 |@@@@@                                               |
    [4, 8)                71 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@           |
    [8, 16)               88 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
    [16, 32)              50 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                       |
    [32, 64)              65 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@              |
    [64, 128)             43 |@@@@@@@@@@@@@@@@@@@@@@@@@                           |
    [128, 256)            19 |@@@@@@@@@@@                                         |
    [256, 512)             3 |@                                                   |
    [512, 1K)              1 |                                                    |

Reviewed by: Brad Lewis <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Prakash Surya <[email protected]>
Closes #9525

3 files changed, 93 insertions, 0 deletions

diff --git a/include/os/linux/spl/sys/Makefile.am b/include/os/linux/spl/sys/Makefile.am
index 251542118..e3df4edae 100644
--- a/include/os/linux/spl/sys/Makefile.am
+++ b/include/os/linux/spl/sys/Makefile.am
@@ -46,6 +46,7 @@ KERNEL_H = \
 	$(top_srcdir)/include/os/linux/spl/sys/timer.h \
 	$(top_srcdir)/include/os/linux/spl/sys/trace.h \
 	$(top_srcdir)/include/os/linux/spl/sys/trace_spl.h \
+	$(top_srcdir)/include/os/linux/spl/sys/trace_taskq.h \
 	$(top_srcdir)/include/os/linux/spl/sys/tsd.h \
 	$(top_srcdir)/include/os/linux/spl/sys/types32.h \
 	$(top_srcdir)/include/os/linux/spl/sys/types.h \
diff --git a/include/os/linux/spl/sys/trace_spl.h b/include/os/linux/spl/sys/trace_spl.h
index 6b50d546b..bffd91d91 100644
--- a/include/os/linux/spl/sys/trace_spl.h
+++ b/include/os/linux/spl/sys/trace_spl.h
@@ -22,6 +22,9 @@
 #ifndef _OS_LINUX_SPL_TRACE_H
 #define	_OS_LINUX_SPL_TRACE_H
 
+#include <sys/taskq.h>
+
 #include <sys/trace.h>
+#include <sys/trace_taskq.h>
 
 #endif
diff --git a/include/os/linux/spl/sys/trace_taskq.h b/include/os/linux/spl/sys/trace_taskq.h
new file mode 100644
index 000000000..dbbb3c4c7
--- /dev/null
+++ b/include/os/linux/spl/sys/trace_taskq.h
@@ -0,0 +1,89 @@
+/*
+ * CDDL HEADER START
+ *
+ * The contents of this file are subject to the terms of the
+ * Common Development and Distribution License (the "License").
+ * You may not use this file except in compliance with the License.
+ *
+ * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
+ * or http://www.opensolaris.org/os/licensing.
+ * See the License for the specific language governing permissions
+ * and limitations under the License.
+ *
+ * When distributing Covered Code, include this CDDL HEADER in each
+ * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
+ * If applicable, add the following below this CDDL HEADER, with the
+ * fields enclosed by brackets "[]" replaced with your own identifying
+ * information: Portions Copyright [yyyy] [name of copyright owner]
+ *
+ * CDDL HEADER END
+ */
+
+#if defined(_KERNEL)
+#if defined(HAVE_DECLARE_EVENT_CLASS)
+
+#undef TRACE_SYSTEM
+#define	TRACE_SYSTEM zfs
+
+#undef TRACE_SYSTEM_VAR
+#define	TRACE_SYSTEM_VAR zfs_taskq
+
+#if !defined(_TRACE_TASKQ_H) || defined(TRACE_HEADER_MULTI_READ)
+#define	_TRACE_TASKQ_H
+
+#include <linux/tracepoint.h>
+#include <sys/types.h>
+
+/*
+ * Generic support for single argument tracepoints of the form:
+ *
+ * DTRACE_PROBE1(...,
+ *     taskq_ent_t *, ...);
+ */
+/* BEGIN CSTYLED */
+DECLARE_EVENT_CLASS(zfs_taskq_ent_class,
+	TP_PROTO(taskq_ent_t *taskq_ent),
+	TP_ARGS(taskq_ent),
+	TP_STRUCT__entry(
+	    __field(taskq_ent_t *,	taskq_ent)
+	),
+	TP_fast_assign(
+	    __entry->taskq_ent	= taskq_ent;
+	),
+	TP_printk("taskq_ent %p", __entry->taskq_ent)
+);
+/* END CSTYLED */
+
+/* BEGIN CSTYLED */
+#define DEFINE_TASKQ_EVENT(name) \
+DEFINE_EVENT(zfs_taskq_ent_class, name, \
+	TP_PROTO(taskq_ent_t *taskq_ent), \
+	TP_ARGS(taskq_ent))
+/* END CSTYLED */
+DEFINE_TASKQ_EVENT(zfs_taskq_ent__birth);
+DEFINE_TASKQ_EVENT(zfs_taskq_ent__start);
+DEFINE_TASKQ_EVENT(zfs_taskq_ent__finish);
+
+#endif /* _TRACE_TASKQ_H */
+
+#undef TRACE_INCLUDE_PATH
+#undef TRACE_INCLUDE_FILE
+#define	TRACE_INCLUDE_PATH sys
+#define	TRACE_INCLUDE_FILE trace_taskq
+#include <trace/define_trace.h>
+
+#else
+
+/*
+ * When tracepoints are not available, a DEFINE_DTRACE_PROBE* macro is
+ * needed for each DTRACE_PROBE.  These will be used to generate stub
+ * tracing functions and prototypes for those functions.  See
+ * include/os/linux/spl/sys/trace.h.
+ */
+
+DEFINE_DTRACE_PROBE1(taskq_ent__birth);
+DEFINE_DTRACE_PROBE1(taskq_ent__start);
+DEFINE_DTRACE_PROBE1(taskq_ent__finish);
+
+#endif /* HAVE_DECLARE_EVENT_CLASS */
+#endif /* _KERNEL */