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

[Anthony Liguori <anthony@codemonkey.ws>]

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<stefanha@linux.vnet.ibm.com>
>>>>> ---
>>>>>     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
>
>