lkml.org 
[lkml]   [2007]   [Jul]   [3]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    Date
    From
    Subject[patch 2/4] Linux Kernel Markers - Add kconfig menus for the marker code
    With the increasing complexity of today's user-space application and the wide
    deployment of SMP systems, the users need an increasing understanding of the
    behavior and performance of a system across multiple processes/different
    execution contexts/multiple CPUs. In applications such as large clusters
    (Google, IBM), video acquisition (Autodesk), embedded real-time systems (Wind
    River, Monta Vista, Sony) or sysadmin/programmer-type tasks (SystemTAP from
    Redhat), a tool that permits tracing of kernel-user space interaction becomes
    necessary.

    Usage of such tools have been made to successfully pinpoint problems such as:
    latency issues in a user-space video acquisition application, slowdown
    problems in large clusters due to a switch to a different filesystems with a
    different cache size, abnormal Linux scheduler latency (just to name a few
    that I have personally investigated).

    The currently existing solutions does not give a system-wide overview of what
    - and when - things are happening on the system. Ptracing a program works
    with few processes, but quickly becomes useless when it comes to keeping track
    of many processes.

    Bugs occuring because of bad interaction of such complex systems can be very
    hard to find due to the fact that they occur rarely (sometimes once a week on
    hundreds of machines). One can therefore only hope at having the best
    conditions to statistically reproduce the bug while extracting information
    from the system. Some bugs have been successfully found at Google using their
    ktrace tracer only because they could enable it on production machines and
    therefore recreate the same context where the bug happened.

    Therefore, it makes sense to offer an instrumentation set of the most relevant
    events occurring in the Linux that can have the smallest performance cost
    possible when not active while not requiring a reboot of a production system
    to activate. This is essentially what the markers are providing.

    Since we cannot limit the growth of the Linux kernel, nor can we pre-determine
    each and every "interesting" instrumentation within each subsystem and driver,
    it is sensible to let this task to the persons who knows the best their code.
    Adding instrumentation should therefore be as easy as adding and maintaining a
    "printk" in the kernel code from the developer's point of view.

    Towards a complete tracing mechanism in the Linux kernel, the markers are only
    one step forward. The following step is to connect probes to those markers
    that will record the tracing information in buffers exported to user-space,
    organized in timestamped "events". Probe callbacks are responsible for
    serializing the information passed as parameter to the markers (described by
    the format string) into the events. A control mechanism to activate/stop the
    tracing is required, as well as a daemon that maps the buffers to write them
    to disk or send them through the network.

    Keeping track of the events also requires a centralized infrastructure : the
    idea is to assign a unique ID to each event so they can be later recognized in
    the trace. Keeping in mind that recording the complete instrumentation site
    name string for each event would be more that inefficient, assigning a numeric
    unique identifier makes sense.

    Finally, support for gathering events coming from user-space, with a minimal
    performance impact, is very useful to see the interaction between the system's
    execution contexts.

    The last steps are currently implemented in Linux Trace Toolkit Next
    Generation (LTTng).

    The SystemTAP project could clearly benefit from such an infrastructure for
    tracing. In addition, they would be providing support for dynamic addition of
    kernel probes through breakpoints/jumps when possible, with the associated
    restrictions (accessing local variables, reentrancy, speed).




    This marker infrastructure is a hook-callback mechanism. It is meant to have
    an impact as low as possible on the system performances when no callback
    (probe) is connected so markers (hooks) can be compiled into a production
    kernel without noticeable slowdown.

    Why use the markers instead of kprobes?

    The rationale behind this mechanism the following :

    1 - It makes sense to have instrumentation (for tracing, profiling)
    within the kernel source tree so that it can follow its evolution.
    Other options, such as kprobes, imply maintaining an external set of
    instrumentation that must be adapted to each kernel version.
    Although it may make sense for distributions, it is not well suited
    for kernel developers, since they rarely work on a major
    distribution image.
    2 - kprobes, although being a very good attempt at providing a dynamic
    hooking mechanism that has no impact when disabled, suffers from
    important limitations :
    a - It cannot access local variables of a function at a particular
    point within its body that will be consistent thorough the kernel
    versions without involving a lot of recurrent hair-pulling.
    b - Kprobes is slow, since it involves going though a trap each time
    a probe site is executed. Even though the djprobes project made a
    good effort to make things faster, it cannot currently instrument
    fully-preemptible kernels and does not solve (1), (2a) and (2c).
    c - On the reentrancy side, going though a trap (thus playing with
    interrupt enable/disable) and taking spinlocks are not suited to
    some code paths, i.e. :
    kernel/lockdep.c, printk (within the lockdep_on()/lockdep_off()).
    It must be understood that some code paths interesting for
    instrumentation often present a particular reentrancy challenge.

    Some more details :

    The probe callback connection to its markers is done dynamically. A predicted
    branch (see the immediate values infrastructure) is used to skip the hook stack
    setup and function call when the marker is "disabled" (no probe is connected).
    Further optimizations can be implemented for each architecture to make this
    branch faster.

    Instrumentation of a subsystem becomes therefore a straightforward task. One
    has to add instrumentation within the key locations of the kernel code in the
    following form :

    trace_mark(subsystem_event, "%d %p", myint, myptr);


    Jim Keniston <jkenisto@us.ibm.com> adds:

    kprobes remains a vital foundation for SystemTap. But markers are attactive
    as an alternate source of trace/debug info. Here's why:

    1. Markers will live in the kernel and presumably be kept up to date by
    the maintainers of the enclosing code. We have a growing set of tapsets
    (probe libraries), each of which "knows" the source code for a certain area
    of the kernel. Whenever the underlying kernel code changes (e.g., a
    function or one of its args disappears or is renamed), there's a chance
    that the tapset will become invalid until we bring it back in sync with the
    kernel. As you can imagine, maintaining tapsets separate from the kernel
    source is a maintenance headache. Markers could mitigate this.

    2. Because the kernel code is highly optimized, the kernel's dwarf info
    doesn't always accurately reflect which variables have which values on
    which lines (sometimes even upon entry to a function). A marker is a way
    to ensure that values of interest are available to SystemTap at marked
    points.

    3. Sometimes the overhead of a kprobe probepoint is too much (either in
    terms of time or locking) for the particular hotspot we want to probe.


    In OLS2006 proceedings, vol. 1
    http://www.linuxsymposium.org/2006/linuxsymposium_procv1.pdf

    Frank C. Eigler, from SystemTAP, presents its "static probing markers"
    (pp. 261-268) in his paper "Problem Solving With Systemtap".

    He explains the advantages :

    "In exchange for this effort, systemtap marker-based probes are faster and
    more precise than kprobes. The better precision comes from not having to
    covet the compiler's favours. Such fickle favours include retaining
    clean boundaries in the instruction stream between interesting statements,
    and precisely describing positions of variables in the stack frame. Since
    markers don't rely on debugging information, neither favour is required,
    and the compiler can channel its charms into unabated optimization. The
    speed advantage comes from using direct call instructions rather than int 3
    breakpoints to dispatch to the systemtap handlers. We will see below just
    how big a difference this makes."

    He does a comparison of his "simple" marker solution with kprobes (his simple
    solution looks like my generic markers, but with a major race condition). I
    also posted numbers about the markers performance impact a few months ago in
    the initial thread. I can dig into my emails to find them for you if you
    consider it important for the Changelog.

    He concludes with :

    "To the extent that is true, we propose that these groups consider using a
    shared pool of static markers as the basic kernel-side instrumentation
    mechanism. If they prove to have as low dormant cost and as high active
    performance as initial experience suggests, perhaps this could motivate the
    various tracing efforts and kernel subsystem developers to finally join
    forces. Let's designate standard trace/probe points once and for all.
    Tracing backends can attach to these markers the same way systemtap would.
    There would be no need for them to maintain kernel patches any more.
    Let's think about it."


    This patch:

    Add Kconfig menus for the marker code.

    [bunk@stusta.de: Never ever select MODULES]
    Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@polymtl.ca>
    CC: Adrian Bunk <bunk@stusta.de>
    ---

    arch/alpha/Kconfig | 2 ++
    arch/arm/Kconfig | 2 ++
    arch/arm26/Kconfig | 2 ++
    arch/avr32/Kconfig.debug | 7 +++++++
    arch/cris/Kconfig | 2 ++
    arch/frv/Kconfig | 2 ++
    arch/h8300/Kconfig | 2 ++
    arch/i386/Kconfig | 2 ++
    arch/ia64/Kconfig | 2 ++
    arch/m32r/Kconfig | 2 ++
    arch/m68k/Kconfig | 2 ++
    arch/m68knommu/Kconfig | 2 ++
    arch/mips/Kconfig | 2 ++
    arch/parisc/Kconfig | 2 ++
    arch/powerpc/Kconfig | 2 ++
    arch/ppc/Kconfig | 2 ++
    arch/s390/Kconfig | 2 ++
    arch/sh/Kconfig | 2 ++
    arch/sh64/Kconfig | 2 ++
    arch/sparc/Kconfig | 2 ++
    arch/sparc64/Kconfig | 2 ++
    arch/um/Kconfig | 2 ++
    arch/v850/Kconfig | 2 ++
    arch/x86_64/Kconfig | 2 ++
    arch/xtensa/Kconfig | 2 ++
    kernel/Kconfig.marker | 7 +++++++
    26 files changed, 62 insertions(+)

    Index: linux-2.6-lttng/arch/alpha/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/alpha/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/alpha/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -657,6 +657,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/alpha/Kconfig.debug"
    Index: linux-2.6-lttng/arch/arm/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/arm/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/arm/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -1050,6 +1050,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/arm/Kconfig.debug"
    Index: linux-2.6-lttng/arch/arm26/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/arm26/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/arm26/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -248,6 +248,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/arm26/Kconfig.debug"
    Index: linux-2.6-lttng/arch/cris/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/cris/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/cris/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -202,6 +202,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/cris/Kconfig.debug"
    Index: linux-2.6-lttng/arch/frv/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/frv/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/frv/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -379,6 +379,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/frv/Kconfig.debug"
    Index: linux-2.6-lttng/arch/h8300/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/h8300/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/h8300/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -227,6 +227,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/h8300/Kconfig.debug"
    Index: linux-2.6-lttng/arch/i386/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/i386/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/i386/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -1237,6 +1237,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endif # INSTRUMENTATION

    source "arch/i386/Kconfig.debug"
    Index: linux-2.6-lttng/arch/ia64/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/ia64/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/ia64/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -596,6 +596,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/ia64/Kconfig.debug"
    Index: linux-2.6-lttng/arch/m32r/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/m32r/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/m32r/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -412,6 +412,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/m32r/Kconfig.debug"
    Index: linux-2.6-lttng/arch/m68k/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/m68k/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/m68k/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -683,6 +683,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/m68k/Kconfig.debug"
    Index: linux-2.6-lttng/arch/m68knommu/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/m68knommu/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/m68knommu/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -672,6 +672,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/m68knommu/Kconfig.debug"
    Index: linux-2.6-lttng/arch/mips/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/mips/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/mips/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -1961,6 +1961,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/mips/Kconfig.debug"
    Index: linux-2.6-lttng/arch/parisc/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/parisc/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/parisc/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -273,6 +273,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/parisc/Kconfig.debug"
    Index: linux-2.6-lttng/arch/powerpc/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/powerpc/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/powerpc/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -908,6 +908,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/powerpc/Kconfig.debug"
    Index: linux-2.6-lttng/arch/ppc/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/ppc/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/ppc/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -1457,6 +1457,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/ppc/Kconfig.debug"
    Index: linux-2.6-lttng/arch/s390/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/s390/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/s390/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -549,6 +549,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/s390/Kconfig.debug"
    Index: linux-2.6-lttng/arch/sh/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/sh/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/sh/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -725,6 +725,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/sh/Kconfig.debug"
    Index: linux-2.6-lttng/arch/sh64/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/sh64/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/sh64/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -288,6 +288,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/sh64/Kconfig.debug"
    Index: linux-2.6-lttng/arch/sparc/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/sparc/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/sparc/Kconfig 2007-06-15 16:14:10.000000000 -0400
    @@ -315,6 +315,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/sparc/Kconfig.debug"
    Index: linux-2.6-lttng/arch/sparc64/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/sparc64/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/sparc64/Kconfig 2007-06-15 16:14:11.000000000 -0400
    @@ -441,6 +441,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/sparc64/Kconfig.debug"
    Index: linux-2.6-lttng/arch/um/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/um/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/um/Kconfig 2007-06-15 16:14:11.000000000 -0400
    @@ -339,6 +339,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/um/Kconfig.debug"
    Index: linux-2.6-lttng/arch/v850/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/v850/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/v850/Kconfig 2007-06-15 16:14:11.000000000 -0400
    @@ -335,6 +335,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/v850/Kconfig.debug"
    Index: linux-2.6-lttng/arch/x86_64/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/x86_64/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/x86_64/Kconfig 2007-06-15 16:14:11.000000000 -0400
    @@ -795,6 +795,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/x86_64/Kconfig.debug"
    Index: linux-2.6-lttng/arch/xtensa/Kconfig
    ===================================================================
    --- linux-2.6-lttng.orig/arch/xtensa/Kconfig 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/xtensa/Kconfig 2007-06-15 16:14:11.000000000 -0400
    @@ -255,6 +255,8 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    endmenu

    source "arch/xtensa/Kconfig.debug"
    Index: linux-2.6-lttng/kernel/Kconfig.marker
    ===================================================================
    --- /dev/null 1970-01-01 00:00:00.000000000 +0000
    +++ linux-2.6-lttng/kernel/Kconfig.marker 2007-06-15 16:14:11.000000000 -0400
    @@ -0,0 +1,7 @@
    +# Code markers configuration
    +
    +config MARKERS
    + bool "Activate markers"
    + help
    + Place an empty function call at each marker site. Can be
    + dynamically changed for a probe function.
    Index: linux-2.6-lttng/arch/avr32/Kconfig.debug
    ===================================================================
    --- linux-2.6-lttng.orig/arch/avr32/Kconfig.debug 2007-06-15 16:14:02.000000000 -0400
    +++ linux-2.6-lttng/arch/avr32/Kconfig.debug 2007-06-15 16:14:11.000000000 -0400
    @@ -9,6 +9,9 @@
    menu "Instrumentation Support"
    depends on EXPERIMENTAL

    +menu "Instrumentation Support"
    + depends on EXPERIMENTAL
    +
    config KPROBES
    bool "Kprobes"
    depends on DEBUG_KERNEL
    @@ -21,6 +24,10 @@

    source "kernel/Kconfig.immediate"

    +source "kernel/Kconfig.marker"
    +
    +endmenu
    +
    endmenu

    endmenu
    --
    Mathieu Desnoyers
    Computer Engineering Ph.D. Student, Ecole Polytechnique de Montreal
    OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F BA06 3F25 A8FE 3BAE 9A68
    -
    To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
    the body of a message to majordomo@vger.kernel.org
    More majordomo info at http://vger.kernel.org/majordomo-info.html
    Please read the FAQ at http://www.tux.org/lkml/

    \
     
     \ /
      Last update: 2007-07-03 19:23    [W:0.050 / U:62.332 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site