kvm: add flightrecorder script

The kvm kernel module includes a number of trace events which can be
useful when debugging system behavior.  Even on production systems these
trace events can be used to observe guest behavior and identify the
source of problems.

The kvm_flightrecorder script is a command-line wrapper for the
/sys/kernel/debug/tracing interface.  Kernel symbols do not need to be
installed.

This script captures a fixed-size buffer of KVM trace events.  Recent
events overwrite the oldest events when the buffer size is exceeded and
it is possible to leave KVM tracing enabled for any period of time with
just a fixed-size buffer.  If the buffer is large enough this script is
a useful tool for collecting detailed information after an issue occurs
with a guest.  Hence the name "flight recorder".

The script can also be used in 'tail' mode to simply view KVM trace
events as they occur.  This is handy for development and to ensure that
the guest is indeed running.

Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
---
 scripts/kvm/kvm_flightrecorder |  126 ++++++++++++++++++++++++++++++++++++++++
 1 files changed, 126 insertions(+), 0 deletions(-)
 create mode 100755 scripts/kvm/kvm_flightrecorder

On 03/09/2012 08:13 AM, Stefan Hajnoczi wrote:
> The kvm kernel module includes a number of trace events which can be
> useful when debugging system behavior.  Even on production systems these
> trace events can be used to observe guest behavior and identify the
> source of problems.
>
> The kvm_flightrecorder script is a command-line wrapper for the
> /sys/kernel/debug/tracing interface.  Kernel symbols do not need to be
> installed.
>
> This script captures a fixed-size buffer of KVM trace events.  Recent
> events overwrite the oldest events when the buffer size is exceeded and
> it is possible to leave KVM tracing enabled for any period of time with
> just a fixed-size buffer.  If the buffer is large enough this script is
> a useful tool for collecting detailed information after an issue occurs
> with a guest.  Hence the name "flight recorder".
>
> The script can also be used in 'tail' mode to simply view KVM trace
> events as they occur.  This is handy for development and to ensure that
> the guest is indeed running.
>
> Signed-off-by: Stefan Hajnoczi<stefanha@linux.vnet.ibm.com>
> ---
>   scripts/kvm/kvm_flightrecorder |  126 ++++++++++++++++++++++++++++++++++++++++
>   1 files changed, 126 insertions(+), 0 deletions(-)
>   create mode 100755 scripts/kvm/kvm_flightrecorder

I assume this should go through uq/master...

Thanks for sending this out.

Regards,

Anthony Liguori

>
> diff --git a/scripts/kvm/kvm_flightrecorder b/scripts/kvm/kvm_flightrecorder
> new file mode 100755
> index 0000000..7fb1c2d
> --- /dev/null
> +++ b/scripts/kvm/kvm_flightrecorder
> @@ -0,0 +1,126 @@
> +#!/usr/bin/env python
> +#
> +# KVM Flight Recorder - ring buffer tracing script
> +#
> +# Copyright (C) 2012 IBM Corp
> +#
> +# Author: Stefan Hajnoczi<stefanha@linux.vnet.ibm.com>
> +#
> +# This script provides a command-line interface to kvm ftrace and is designed
> +# to be used as a flight recorder that is always running.  To start in-memory
> +# recording:
> +#
> +# sudo kvm_flightrecorder start 8192  # 8 MB per-cpu ring buffers
> +#
> +# The per-cpu ring buffer size can be given in KB as an optional argument to
> +# the 'start' subcommand.
> +#
> +# To stop the flight recorder:
> +#
> +# sudo kvm_flightrecorder stop
> +#
> +# To dump the contents of the flight recorder (this can be done when the
> +# recorder is stopped or while it is running):
> +#
> +# sudo kvm_flightrecorder dump>/path/to/dump.txt
> +#
> +# To observe the trace while it is running, use the 'tail' subcommand:
> +#
> +# sudo kvm_flightrecorder tail
> +#
> +# Note that the flight recorder may impact overall system performance by
> +# consuming CPU cycles.  No disk I/O is performed since the ring buffer holds a
> +# fixed-size in-memory trace.
> +
> +import sys
> +import os
> +
> +tracing_dir = '/sys/kernel/debug/tracing'
> +
> +def trace_path(*args):
> +    return os.path.join(tracing_dir, *args)
> +
> +def write_file(path, data):
> +    open(path, 'wb').write(data)
> +
> +def enable_event(subsystem, event, enable):
> +    write_file(trace_path('events', subsystem, event, 'enable'), '1' if enable else '0')
> +
> +def enable_subsystem(subsystem, enable):
> +    write_file(trace_path('events', subsystem, 'enable'), '1' if enable else '0')
> +
> +def start_tracing():
> +    enable_subsystem('kvm', True)
> +    write_file(trace_path('tracing_on'), '1')
> +
> +def stop_tracing():
> +    write_file(trace_path('tracing_on'), '0')
> +    enable_subsystem('kvm', False)
> +    write_file(trace_path('events', 'enable'), '0')
> +    write_file(trace_path('current_tracer'), 'nop')
> +
> +def dump_trace():
> +    tracefile = open(trace_path('trace'), 'r')
> +    try:
> +        lines = True
> +        while lines:
> +            lines = tracefile.readlines(64 * 1024)
> +            sys.stdout.writelines(lines)
> +    except KeyboardInterrupt:
> +        pass
> +
> +def tail_trace():
> +    try:
> +        for line in open(trace_path('trace_pipe'), 'r'):
> +            sys.stdout.write(line)
> +    except KeyboardInterrupt:
> +        pass
> +
> +def usage():
> +    print 'Usage: %s start [buffer_size_kb] | stop | dump | tail' % sys.argv[0]
> +    print 'Control the KVM flight recorder tracing.'
> +    sys.exit(0)
> +
> +def main():
> +    if len(sys.argv)<  2:
> +        usage()
> +
> +    cmd = sys.argv[1]
> +    if cmd == '--version':
> +        print 'kvm_flightrecorder version 1.0'
> +        sys.exit(0)
> +
> +    if not os.path.isdir(tracing_dir):
> +        print 'Unable to tracing debugfs directory, try:'
> +        print 'mount -t debugfs none /sys/kernel/debug'
> +        sys.exit(1)
> +    if not os.access(tracing_dir, os.W_OK):
> +        print 'Unable to write to tracing debugfs directory, please run as root'
> +        sys.exit(1)
> +
> +    if cmd == 'start':
> +        stop_tracing() # clean up first
> +
> +        if len(sys.argv) == 3:
> +            try:
> +                buffer_size_kb = int(sys.argv[2])
> +            except ValueError:
> +                print 'Invalid per-cpu trace buffer size in KB'
> +                sys.exit(1)
> +            write_file(trace_path('buffer_size_kb'), str(buffer_size_kb))
> +            print 'Per-CPU ring buffer size set to %d KB' % buffer_size_kb
> +
> +        start_tracing()
> +        print 'KVM flight recorder enabled'
> +    elif cmd == 'stop':
> +        stop_tracing()
> +        print 'KVM flight recorder disabled'
> +    elif cmd == 'dump':
> +        dump_trace()
> +    elif cmd == 'tail':
> +        tail_trace()
> +    else:
> +        usage()
> +
> +if __name__ == '__main__':
> +    sys.exit(main())

On 03/09/2012 04:13 PM, Stefan Hajnoczi wrote:
> The kvm kernel module includes a number of trace events which can be
> useful when debugging system behavior.  Even on production systems these
> trace events can be used to observe guest behavior and identify the
> source of problems.
>
> The kvm_flightrecorder script is a command-line wrapper for the
> /sys/kernel/debug/tracing interface.  Kernel symbols do not need to be
> installed.
>
> This script captures a fixed-size buffer of KVM trace events.  Recent
> events overwrite the oldest events when the buffer size is exceeded and
> it is possible to leave KVM tracing enabled for any period of time with
> just a fixed-size buffer.  If the buffer is large enough this script is
> a useful tool for collecting detailed information after an issue occurs
> with a guest.  Hence the name "flight recorder".
>
> The script can also be used in 'tail' mode to simply view KVM trace
> events as they occur.  This is handy for development and to ensure that
> the guest is indeed running.
>
>

Have you considered updating trace-cmd or perf-something instead?  While
each of these tools are useful we miss out on combining capabilities. 
For example you could 'perf probe' a dynamic tracepoint and flightrecord
it together with kvm tracepoints.

On Mon, Mar 12, 2012 at 02:08:10PM +0200, Avi Kivity wrote:
> On 03/09/2012 04:13 PM, Stefan Hajnoczi wrote:
> > The kvm kernel module includes a number of trace events which can be
> > useful when debugging system behavior.  Even on production systems these
> > trace events can be used to observe guest behavior and identify the
> > source of problems.
> >
> > The kvm_flightrecorder script is a command-line wrapper for the
> > /sys/kernel/debug/tracing interface.  Kernel symbols do not need to be
> > installed.
> >
> > This script captures a fixed-size buffer of KVM trace events.  Recent
> > events overwrite the oldest events when the buffer size is exceeded and
> > it is possible to leave KVM tracing enabled for any period of time with
> > just a fixed-size buffer.  If the buffer is large enough this script is
> > a useful tool for collecting detailed information after an issue occurs
> > with a guest.  Hence the name "flight recorder".
> >
> > The script can also be used in 'tail' mode to simply view KVM trace
> > events as they occur.  This is handy for development and to ensure that
> > the guest is indeed running.
> >
> >
> 
> Have you considered updating trace-cmd or perf-something instead?  While
> each of these tools are useful we miss out on combining capabilities. 
> For example you could 'perf probe' a dynamic tracepoint and flightrecord
> it together with kvm tracepoints.

This script is ideal in situations where you want to ask someone who is
not a developer to collect information.  They sometimes don't want to
install software but running a small Python script is okay.  So that's
the background of this tool.

That said, I agree that integrating flightrecorder mode into perf would
be very nice.  I'm not sure I'll be able to come up with patches soon
but if someone is interested in doing this that would be fantastic.

Stefan

On 03/12/2012 04:48 PM, Stefan Hajnoczi wrote:
> That said, I agree that integrating flightrecorder mode into perf would
> be very nice.  I'm not sure I'll be able to come up with patches soon
> but if someone is interested in doing this that would be fantastic.
>

I'm in the same boat - my comment could be applied with no modification
to kvm_stat.  Diving into perf requires some courage (and time).

On Fri, Mar 09, 2012 at 02:13:40PM +0000, Stefan Hajnoczi wrote:
> The kvm kernel module includes a number of trace events which can be
> useful when debugging system behavior.  Even on production systems these
> trace events can be used to observe guest behavior and identify the
> source of problems.
> 
> The kvm_flightrecorder script is a command-line wrapper for the
> /sys/kernel/debug/tracing interface.  Kernel symbols do not need to be
> installed.
> 
> This script captures a fixed-size buffer of KVM trace events.  Recent
> events overwrite the oldest events when the buffer size is exceeded and
> it is possible to leave KVM tracing enabled for any period of time with
> just a fixed-size buffer.  If the buffer is large enough this script is
> a useful tool for collecting detailed information after an issue occurs
> with a guest.  Hence the name "flight recorder".
> 
> The script can also be used in 'tail' mode to simply view KVM trace
> events as they occur.  This is handy for development and to ensure that
> the guest is indeed running.
> 
> Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
> ---
>  scripts/kvm/kvm_flightrecorder |  126 ++++++++++++++++++++++++++++++++++++++++
>  1 files changed, 126 insertions(+), 0 deletions(-)
>  create mode 100755 scripts/kvm/kvm_flightrecorder

Applied to uq/master, thanks.