Skip to content

Commit

Permalink
Swap DTRACE_PROBE* with Linux tracepoints
Browse files Browse the repository at this point in the history 
This patch leverages Linux tracepoints from within the ZFS on Linux
code base. It also refactors the debug code to bring it back in sync
with Illumos.

The information exported via tracepoints can be used for a variety of
reasons (e.g. debugging, tuning, general exploration/understanding,
etc). It is advantageous to use Linux tracepoints as the mechanism to
export this kind of information (as opposed to something else) for a
number of reasons:

    * A number of external tools can make use of our tracepoints
      "automatically" (e.g. perf, systemtap)
    * Tracepoints are designed to be extremely cheap when disabled
    * It's one of the "accepted" ways to export this kind of
      information; many other kernel subsystems use tracepoints too.

Unfortunately, though, there are a few caveats as well:

    * Linux tracepoints appear to only be available to GPL licensed
      modules due to the way certain kernel functions are exported.
      Thus, to actually make use of the tracepoints introduced by this
      patch, one might have to patch and re-compile the kernel;
      exporting the necessary functions to non-GPL modules.

    * Prior to upstream kernel version v3.14-rc6-30-g66cc69e, Linux
      tracepoints are not available for unsigned kernel modules
      (tracepoints will get disabled due to the module's 'F' taint).
      Thus, one either has to sign the zfs kernel module prior to
      loading it, or use a kernel versioned v3.14-rc6-30-g66cc69e or
      newer.

Assuming the above two requirements are satisfied, lets look at an
example of how this patch can be used and what information it exposes
(all commands run as 'root'):

    # list all zfs tracepoints available

    $ ls /sys/kernel/debug/tracing/events/zfs
    enable              filter              zfs_arc__delete
    zfs_arc__evict      zfs_arc__hit        zfs_arc__miss
    zfs_l2arc__evict    zfs_l2arc__hit      zfs_l2arc__iodone
    zfs_l2arc__miss     zfs_l2arc__read     zfs_l2arc__write
    zfs_new_state__mfu  zfs_new_state__mru

    # enable all zfs tracepoints, clear the tracepoint ring buffer

    $ echo 1 > /sys/kernel/debug/tracing/events/zfs/enable
    $ echo 0 > /sys/kernel/debug/tracing/trace

    # import zpool called 'tank', inspect tracepoint data (each line was
    # truncated, they're too long for a commit message otherwise)

    $ zpool import tank
    $ cat /sys/kernel/debug/tracing/trace | head -n35
    # tracer: nop
    #
    # entries-in-buffer/entries-written: 1219/1219   #P:8
    #
    #                              _-----=> irqs-off
    #                             / _----=> need-resched
    #                            | / _---=> hardirq/softirq
    #                            || / _--=> preempt-depth
    #                            ||| /     delay
    #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
    #              | |       |   ||||       |         |
            lt-zpool-30132 [003] .... 91344.200050: zfs_arc__miss: hdr...
          z_rd_int/0-30156 [003] .... 91344.200611: zfs_new_state__mru...
            lt-zpool-30132 [003] .... 91344.201173: zfs_arc__miss: hdr...
          z_rd_int/1-30157 [003] .... 91344.201756: zfs_new_state__mru...
            lt-zpool-30132 [003] .... 91344.201795: zfs_arc__miss: hdr...
          z_rd_int/2-30158 [003] .... 91344.202099: zfs_new_state__mru...
            lt-zpool-30132 [003] .... 91344.202126: zfs_arc__hit: hdr ...
            lt-zpool-30132 [003] .... 91344.202130: zfs_arc__hit: hdr ...
            lt-zpool-30132 [003] .... 91344.202134: zfs_arc__hit: hdr ...
            lt-zpool-30132 [003] .... 91344.202146: zfs_arc__miss: hdr...
          z_rd_int/3-30159 [003] .... 91344.202457: zfs_new_state__mru...
            lt-zpool-30132 [003] .... 91344.202484: zfs_arc__miss: hdr...
          z_rd_int/4-30160 [003] .... 91344.202866: zfs_new_state__mru...
            lt-zpool-30132 [003] .... 91344.202891: zfs_arc__hit: hdr ...
            lt-zpool-30132 [001] .... 91344.203034: zfs_arc__miss: hdr...
          z_rd_iss/1-30149 [001] .... 91344.203749: zfs_new_state__mru...
            lt-zpool-30132 [001] .... 91344.203789: zfs_arc__hit: hdr ...
            lt-zpool-30132 [001] .... 91344.203878: zfs_arc__miss: hdr...
          z_rd_iss/3-30151 [001] .... 91344.204315: zfs_new_state__mru...
            lt-zpool-30132 [001] .... 91344.204332: zfs_arc__hit: hdr ...
            lt-zpool-30132 [001] .... 91344.204337: zfs_arc__hit: hdr ...
            lt-zpool-30132 [001] .... 91344.204352: zfs_arc__hit: hdr ...
            lt-zpool-30132 [001] .... 91344.204356: zfs_arc__hit: hdr ...
            lt-zpool-30132 [001] .... 91344.204360: zfs_arc__hit: hdr ...

To highlight the kind of detailed information that is being exported
using this infrastructure, I've taken the first tracepoint line from the
output above and reformatted it such that it fits in 80 columns:

    lt-zpool-30132 [003] .... 91344.200050: zfs_arc__miss:
        hdr {
            dva 0x1:0x40082
            birth 15491
            cksum0 0x163edbff3a
            flags 0x640
            datacnt 1
            type 1
            size 2048
            spa 3133524293419867460
            state_type 0
            access 0
            mru_hits 0
            mru_ghost_hits 0
            mfu_hits 0
            mfu_ghost_hits 0
            l2_hits 0
            refcount 1
        } bp {
            dva0 0x1:0x40082
            dva1 0x1:0x3000e5
            dva2 0x1:0x5a006e
            cksum 0x163edbff3a:0x75af30b3dd6:0x1499263ff5f2b:0x288bd118815e00
            lsize 2048
        } zb {
            objset 0
            object 0
            level -1
            blkid 0
        }

For the specific tracepoint shown here, 'zfs_arc__miss', data is
exported detailing the arc_buf_hdr_t (hdr), blkptr_t (bp), and
zbookmark_t (zb) that caused the ARC miss (down to the exact DVA!).
This kind of precise and detailed information can be extremely valuable
when trying to answer certain kinds of questions.

For anybody unfamiliar but looking to build on this, I found the XFS
source code along with the following three web links to be extremely
helpful:

    * http://lwn.net/Articles/379903/
    * http://lwn.net/Articles/381064/
    * http://lwn.net/Articles/383362/

I should also node the more "boring" aspects of this patch:

    * The ZFS_LINUX_COMPILE_IFELSE autoconf macro was modified to
       support a sixth paramter. This parameter is used to populate the
       contents of the new conftest.h file. If no sixth parameter is
       provided, conftest.h will be empty.

    * The ZFS_LINUX_TRY_COMPILE_HEADER autoconf macro was introduced.
      This macro is nearly identical to the ZFS_LINUX_TRY_COMPILE macro,
      except it has support for a fifth option that is then passed as
      the sixth parameter to ZFS_LINUX_COMPILE_IFELSE.

These autoconf changes were needed to test the availability of the Linux
tracepoint macros. Due to the odd nature of the Linux tracepoint macro
API, a separate ".h" must be created (the path and filename is used
internally by the kernel's define_trace.h file).

    * The HAVE_DECLARE_EVENT_CLASS autoconf macro was introduced. This
      is to determine if we can safely enable the Linux tracepoint
      functionality. We need to selectively disable the tracepoint code
      due to the kernel exporting certain functions as GPL only. Without
      this check, the build process will fail at link time.

In addition, the SET_ERROR macro was modified into a tracepoint as well.
To do this, the 'sdt.h' file was moved into the 'include/sys' directory
and now contains a userspace portion and a kernel space portion. The
dprintf and zfs_dbgmsg* interfaces are now implemented as tracepoint as
well.

Signed-off-by: Prakash Surya <[email protected]>
Signed-off-by: Ned Bass <[email protected]>
Signed-off-by: Brian Behlendorf <[email protected]>
  • Loading branch information
@behlendorf
Prakash Surya authored and behlendorf committed Nov 17, 2014
1 parent 5024046 commit 0b39b9f
Show file tree
Hide file tree
Showing 15 changed files with 1,361 additions and 161 deletions.
59 changes: 59 additions & 0 deletions config/kernel-declare-event-class.m4
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,59 @@
dnl #
dnl # Ensure the DECLARE_EVENT_CLASS macro is available to non-GPL modules.
dnl #
AC_DEFUN([ZFS_AC_KERNEL_DECLARE_EVENT_CLASS], [
tmp_flags="$EXTRA_KCFLAGS"
EXTRA_KCFLAGS="-I\$(src)"
AC_MSG_CHECKING([whether DECLARE_EVENT_CLASS() is available])
ZFS_LINUX_TRY_COMPILE_HEADER([
#include <linux/module.h>
MODULE_LICENSE(ZFS_META_LICENSE);
#define CREATE_TRACE_POINTS
#include "conftest.h"
],[
trace_zfs_autoconf_event_one(1UL);
trace_zfs_autoconf_event_two(2UL);
],[
AC_MSG_RESULT(yes)
AC_DEFINE(HAVE_DECLARE_EVENT_CLASS, 1,
[DECLARE_EVENT_CLASS() is available])
],[
AC_MSG_RESULT(no)
],[
#if !defined(_CONFTEST_H) || defined(TRACE_HEADER_MULTI_READ)
#define _CONFTEST_H
#undef TRACE_SYSTEM
#define TRACE_SYSTEM zfs
#include <linux/tracepoint.h>
DECLARE_EVENT_CLASS(zfs_autoconf_event_class,
TP_PROTO(unsigned long i),
TP_ARGS(i),
TP_STRUCT__entry(
__field(unsigned long, i)
),
TP_fast_assign(
__entry->i = i;
),
TP_printk("i = %lu", __entry->i)
);
#define DEFINE_AUTOCONF_EVENT(name) \
DEFINE_EVENT(zfs_autoconf_event_class, name, \
TP_PROTO(unsigned long i), \
TP_ARGS(i))
DEFINE_AUTOCONF_EVENT(zfs_autoconf_event_one);
DEFINE_AUTOCONF_EVENT(zfs_autoconf_event_two);
#endif /* _CONFTEST_H */
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
#define TRACE_INCLUDE_FILE conftest
#include <trace/define_trace.h>
])
EXTRA_KCFLAGS="$tmp_flags"
])
32 changes: 28 additions & 4 deletions config/kernel.m4
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ AC_DEFUN([ZFS_AC_CONFIG_KERNEL], [
ZFS_AC_SPL
ZFS_AC_TEST_MODULE
ZFS_AC_KERNEL_CONFIG
ZFS_AC_KERNEL_DECLARE_EVENT_CLASS
ZFS_AC_KERNEL_BDEV_BLOCK_DEVICE_OPERATIONS
ZFS_AC_KERNEL_BLOCK_DEVICE_OPERATIONS_RELEASE_VOID
ZFS_AC_KERNEL_TYPE_FMODE_T
Expand Down Expand Up @@ -506,9 +507,18 @@ AC_DEFUN([ZFS_AC_KERNEL_CONFIG_DEBUG_LOCK_ALLOC], [
])

dnl #
dnl # ZFS_LINUX_CONFTEST
dnl # ZFS_LINUX_CONFTEST_H
dnl #
AC_DEFUN([ZFS_LINUX_CONFTEST], [
AC_DEFUN([ZFS_LINUX_CONFTEST_H], [
cat - <<_ACEOF >conftest.h
$1
_ACEOF
])

dnl #
dnl # ZFS_LINUX_CONFTEST_C
dnl #
AC_DEFUN([ZFS_LINUX_CONFTEST_C], [
cat confdefs.h - <<_ACEOF >conftest.c
$1
_ACEOF
Expand All @@ -534,13 +544,14 @@ dnl #
dnl # ZFS_LINUX_COMPILE_IFELSE / like AC_COMPILE_IFELSE
dnl #
AC_DEFUN([ZFS_LINUX_COMPILE_IFELSE], [
m4_ifvaln([$1], [ZFS_LINUX_CONFTEST([$1])])
m4_ifvaln([$1], [ZFS_LINUX_CONFTEST_C([$1])])
m4_ifvaln([$6], [ZFS_LINUX_CONFTEST_H([$6])], [ZFS_LINUX_CONFTEST_H([])])
rm -Rf build && mkdir -p build && touch build/conftest.mod.c
echo "obj-m := conftest.o" >build/Makefile
modpost_flag=''
test "x$enable_linux_builtin" = xyes && modpost_flag='modpost=true' # fake modpost stage
AS_IF(
[AC_TRY_COMMAND(cp conftest.c build && make [$2] -C $LINUX_OBJ EXTRA_CFLAGS="-Werror $EXTRA_KCFLAGS" $ARCH_UM M=$PWD/build $modpost_flag) >/dev/null && AC_TRY_COMMAND([$3])],
[AC_TRY_COMMAND(cp conftest.c conftest.h build && make [$2] -C $LINUX_OBJ EXTRA_CFLAGS="-Werror $EXTRA_KCFLAGS" $ARCH_UM M=$PWD/build $modpost_flag) >/dev/null && AC_TRY_COMMAND([$3])],
[$4],
[_AC_MSG_LOG_CONFTEST m4_ifvaln([$5],[$5])]
)
Expand Down Expand Up @@ -627,3 +638,16 @@ AC_DEFUN([ZFS_LINUX_TRY_COMPILE_SYMBOL], [
fi
fi
])

dnl #
dnl # ZFS_LINUX_TRY_COMPILE_HEADER
dnl # like ZFS_LINUX_TRY_COMPILE, except the contents conftest.h are
dnl # provided via the fifth parameter
dnl #
AC_DEFUN([ZFS_LINUX_TRY_COMPILE_HEADER],
[ZFS_LINUX_COMPILE_IFELSE(
[AC_LANG_SOURCE([ZFS_LANG_PROGRAM([[$1]], [[$2]])])],
[modules],
[test -s build/conftest.o],
[$3], [$4], [AC_LANG_SOURCE([$5])])
])
2 changes: 2 additions & 0 deletions include/sys/Makefile.am
View file
Original file line number Diff line number Diff line change
Expand Up @@ -40,11 +40,13 @@ COMMON_H = \
$(top_srcdir)/include/sys/rrwlock.h \
$(top_srcdir)/include/sys/sa.h \
$(top_srcdir)/include/sys/sa_impl.h \
$(top_srcdir)/include/sys/sdt.h \
$(top_srcdir)/include/sys/spa_boot.h \
$(top_srcdir)/include/sys/space_map.h \
$(top_srcdir)/include/sys/space_reftree.h \
$(top_srcdir)/include/sys/spa.h \
$(top_srcdir)/include/sys/spa_impl.h \
$(top_srcdir)/include/sys/trace.h \
$(top_srcdir)/include/sys/txg.h \
$(top_srcdir)/include/sys/txg_impl.h \
$(top_srcdir)/include/sys/u8_textprep_data.h \
Expand Down
70 changes: 70 additions & 0 deletions include/sys/sdt.h
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
/*
* CDDL HEADER START
*
* The contents of this file are subject to the terms of the
* Common Development and Distribution License, Version 1.0 only
* (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
*/
/*
* Copyright 2007 Sun Microsystems, Inc. All rights reserved.
* Use is subject to license terms.
*/

#ifndef _SYS_SDT_H
#define _SYS_SDT_H

#ifndef _KERNEL

#define ZFS_PROBE(a) ((void) 0)
#define ZFS_PROBE1(a, c) ((void) 0)
#define ZFS_PROBE2(a, c, e) ((void) 0)
#define ZFS_PROBE3(a, c, e, g) ((void) 0)
#define ZFS_PROBE4(a, c, e, g, i) ((void) 0)
#define ZFS_SET_ERROR(err) ((void) 0)

#else

#if defined(HAVE_DECLARE_EVENT_CLASS)

#include <sys/trace.h>

/*
* The set-error SDT probe is extra static, in that we declare its fake
* function literally, rather than with the DTRACE_PROBE1() macro. This is
* necessary so that SET_ERROR() can evaluate to a value, which wouldn't
* be possible if it required multiple statements (to declare the function
* and then call it).
*
* SET_ERROR() uses the comma operator so that it can be used without much
* additional code. For example, "return (EINVAL);" becomes
* "return (SET_ERROR(EINVAL));". Note that the argument will be evaluated
* twice, so it should not have side effects (e.g. something like:
* "return (SET_ERROR(log_error(EINVAL, info)));" would log the error twice).
*/
#define SET_ERROR(err) \
(trace_zfs_set__error(__FILE__, __func__, __LINE__, err), err)

#else

#undef SET_ERROR
#define SET_ERROR(err) (err)

#endif /* HAVE_DECLARE_EVENT_CLASS */

#endif /* _KERNEL */

#endif /* _SYS_SDT_H */
Loading

4 comments on commit 0b39b9f

@cburroughs
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does the kernel upstream ocnsider the GPL export only flags on the neccisary functions an oversite or intentional policy?

@prakashsurya
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't know, but I'd be interested in the answer if you can get in contact with a linux kernel developer. Either way, it's a damn shame.. There's some neat debugging, performance analysis, and just general sysadmin tools that we could build around tracepoints; but nope, they're limited to GPL modules :(

@cburroughs
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't have any special way to ask besides the LKML and I'm not even sure how to intelligenlty phrase the question for the LKML. I'm just a user who wants to trace all the things.

Perhaps @ryao would know since I think he has interacted with the kernel devs before.

@behlendorf
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll ask around a bit at the upcoming Linux foundation collaboration summit. Many of the key kernel developers attend so it'll be a good place to determine if this is something which can be changed.

Please sign in to comment.