Re: [Qemu-devel] [PATCH 1/2] trace: Add simple tracing support

[Anthony Liguori]

On 05/21/2010 11:52 AM, Jan Kiszka wrote:
> Anthony Liguori wrote:
>    
> > On 05/21/2010 08:46 AM, Jan Kiszka wrote:
> >      
> > > Anthony Liguori wrote:
> > >
> > >        
> > > > On 05/21/2010 04:42 AM, Stefan Hajnoczi wrote:
> > > >
> > > >          
> > > > > Trace events should be defined in trace.h.  Events are written to
> > > > > /tmp/trace.log and can be formatted using trace.py.  Remember to add
> > > > > events to trace.py for pretty-printing.
> > > > >
> > > > > Signed-off-by: Stefan Hajnoczi<address@hidden>
> > > > > ---
> > > > >     Makefile.objs |    2 +-
> > > > >     trace.c       |   64
> > > > > +++++++++++++++++++++++++++++++++++++++++++++++++++++++++
> > > > >     trace.h       |    9 ++++++++
> > > > >     trace.py      |   30 ++++++++++++++++++++++++++
> > > > >     4 files changed, 104 insertions(+), 1 deletions(-)
> > > > >     create mode 100644 trace.c
> > > > >     create mode 100644 trace.h
> > > > >     create mode 100755 trace.py
> > > > >
> > > > > diff --git a/Makefile.objs b/Makefile.objs
> > > > > index acbaf22..307e989 100644
> > > > > --- a/Makefile.objs
> > > > > +++ b/Makefile.objs
> > > > > @@ -8,7 +8,7 @@ qobject-obj-y += qerror.o
> > > > >     # block-obj-y is code used by both qemu system emulation and qemu-img
> > > > >
> > > > >     block-obj-y = cutils.o cache-utils.o qemu-malloc.o qemu-option.o
> > > > > module.o
> > > > > -block-obj-y += nbd.o block.o aio.o aes.o osdep.o qemu-config.o
> > > > > +block-obj-y += nbd.o block.o aio.o aes.o osdep.o qemu-config.o trace.o
> > > > >     block-obj-$(CONFIG_POSIX) += posix-aio-compat.o
> > > > >     block-obj-$(CONFIG_LINUX_AIO) += linux-aio.o
> > > > >
> > > > > diff --git a/trace.c b/trace.c
> > > > > new file mode 100644
> > > > > index 0000000..2fec4d3
> > > > > --- /dev/null
> > > > > +++ b/trace.c
> > > > > @@ -0,0 +1,64 @@
> > > > > +#include<stdlib.h>
> > > > > +#include<stdio.h>
> > > > > +#include "trace.h"
> > > > > +
> > > > > +typedef struct {
> > > > > +    unsigned long event;
> > > > > +    unsigned long x1;
> > > > > +    unsigned long x2;
> > > > > +    unsigned long x3;
> > > > > +    unsigned long x4;
> > > > > +    unsigned long x5;
> > > > > +} TraceRecord;
> > > > > +
> > > > > +enum {
> > > > > +    TRACE_BUF_LEN = 64 * 1024 / sizeof(TraceRecord),
> > > > > +};
> > > > > +
> > > > > +static TraceRecord trace_buf[TRACE_BUF_LEN];
> > > > > +static unsigned int trace_idx;
> > > > > +static FILE *trace_fp;
> > > > > +
> > > > > +static void trace(TraceEvent event, unsigned long x1,
> > > > > +                  unsigned long x2, unsigned long x3,
> > > > > +                  unsigned long x4, unsigned long x5) {
> > > > > +    TraceRecord *rec =&trace_buf[trace_idx];
> > > > > +    rec->event = event;
> > > > > +    rec->x1 = x1;
> > > > > +    rec->x2 = x2;
> > > > > +    rec->x3 = x3;
> > > > > +    rec->x4 = x4;
> > > > > +    rec->x5 = x5;
> > > > > +
> > > > > +    if (++trace_idx == TRACE_BUF_LEN) {
> > > > > +        trace_idx = 0;
> > > > > +
> > > > > +        if (!trace_fp) {
> > > > > +            trace_fp = fopen("/tmp/trace.log", "w");
> > > > > +        }
> > > > > +        if (trace_fp) {
> > > > > +            size_t result = fwrite(trace_buf, sizeof trace_buf, 1,
> > > > > trace_fp);
> > > > > +            result = result;
> > > > > +        }
> > > > > +    }
> > > > > +}
> > > > >
> > > > >
> > > > >            
> > > > It is probably worth while to read trace points via the monitor or
> > > > through some other mechanism.  My concern would be that writing even 64k
> > > > out to disk would introduce enough performance overhead mainly because
> > > > it runs lock-step with the guest's VCPU.
> > > >
> > > > Maybe it's worth adding a thread that syncs the ring to disk if we want
> > > > to write to disk?
> > > >
> > > >          
> > > That's not what QEMU should worry about. If somehow possible, let's push
> > > this into the hands of a (user space) tracing framework, ideally one
> > > that is already designed for such requirements. E.g. there exists quite
> > > useful work in the context of LTTng (user space RCU for application
> > > tracing).
> > >
> > >        
> >    From what I understand, none of the current kernel approaches to
> > userspace tracing have much momentum at the moment.
> >
> >      
> > > We may need simple stubs for the case that no such framework is (yet)
> > > available. But effort should focus on a QEMU infrastructure to add
> > > useful tracepoints to the code. Specifically when tracing over KVM, you
> > > usually need information about kernel states as well, so you depend on
> > > an integrated approach, not Yet Another Log File.
> > >
> > >        
> > I think the simple code that Stefan pasted gives us 95% of what we need.
> >      
> IMHO not 95%, but it is a start.
>    

I'm not opposed to using a framework, but I'd rather have an equivalent 
to kvm_stat tomorrow than wait 3 years for LTTng to not get merged.

So let's have a dirt-simple tracing mechanism and focus on adding useful 
trace points.  Then when we have a framework we can use, we can just 
convert the tracepoints to the new framework.

Regards,

Anthony Liguori

> I would just like to avoid that too much efforts are spent on
> re-inventing smart trace buffers, trace daemons, or trace visualization
> tools. Then better pick up some semi-perfect approach (e.g. [1], it
> unfortunately still seems to lack kernel integration) and drive it
> according to our needs.
>
> Jan
>
> [1] http://lttng.org/ust
>
>