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

[Jan Kiszka <jan.kiszka@siemens.com>]

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).

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.

Jan

-- 
Siemens AG, Corporate Technology, CT T DE IT 1
Corporate Competence Center Embedded Linux