Re: [RFC PATCH v2 0/4] simpletrace : support var num of args and strings.

Mathieu Desnoyers <[email protected]> Mon, 9 Jan 2012 19:14:53 -0500
Newsgroups gmane.comp.emulators.qemu,gmane.linux.kernel.tracing
Message-ID <20120110001453.GA8203@Krystal>
* Harsh Bora ([email protected]) wrote:
> On 01/09/2012 09:31 PM, Mathieu Desnoyers wrote:
>> * Harsh Prateek Bora ([email protected]) wrote:
>>> Existing simple trace can log upto 6 args per trace event and does not
>>> support strings in trace record format. Introducing new trace format as
>>> discussed earlier on list to support variable number/size of arguments.
>>> (Ref: http://lists.gnu.org/archive/html/qemu-devel/2011-11/msg03426.htm=
l)
>>>
>>> Basic testing of this patch is successful. Stress testing not yet done.
>>>
>>> Apply patches, then run:
>>>
>>> make distclean
>>> ./configure with --enable-trace-backend=3Dsimple
>>> make
>>> sudo make install
>>>
>>> Sample tracelog showing strings support:
>>> [harsh@harshbora v9fs]$ scripts/simpletrace.py trace-events trace-23261
>>> v9fs_version 0.000 tag=3D65535 id=3D100 msize=3D8192 version=3D9P2000.L
>>> v9fs_version_return 17.530 tag=3D65535 id=3D100 msize=3D8192 version=3D=
9P2000.L
>>> v9fs_attach 180.121 tag=3D1 id=3D104 fid=3D0 afid=3D18446744073709551615
>>> uname=3Dnobody aname=3D
>>>
>>>
>>> Note: LTTng ust backend is broken in upstream qemu, therefore tracetool=
=2Epy
>>> doesnt support ust backend as of now. IIUC, ust's trace event APIs are =
under
>>> development and not yet stable.
>>
>> Hi,
>>
>> FYI, the LTTng-UST TRACEPOINT_EVENT API is very much stable as of now.
>> Even though we are still in LTTng-UST 2.0 prereleases, the fact that we
>> started the round of discussions on this API last summer makes us
>> confident that from this point on we should not have to change it.
>>
>> Moreover, I would like to know if the old UST 0.x (0.16 is the latest)
>> is broken wrt qemu, or if this is just for LTTng-2.0 UST support ?
>> UST 0.x instrumentation is not supposed to have broken wrt qemu.
>>
>
> Hi,
> Thanks for an early response. I had tried building with ust 0.16 and it =
=20
> gives compilation errors, specially for trace events with 'void'=20
> argument:
>
>   CC    osdep.o
> In file included from osdep.c:49:
> trace.h: In function =E2=80=98__trace_ust_slavio_misc_update_irq_raise=E2=
=80=99:
> trace.h:277: error: =E2=80=98void=E2=80=99 must be the only parameter
> trace.h:277: error: expected expression before =E2=80=98)=E2=80=99 token
> trace.h:277: error: too many arguments to function =E2=80=98(void (*)(voi=
d =20
> *))__tp_it_func=E2=80=99
> trace.h: At top level:
> trace.h:277: error: =E2=80=98void=E2=80=99 must be the only parameter
> trace.h:277: error: =E2=80=98void=E2=80=99 must be the only parameter
> In file included from osdep.c:49:
> trace.h: In function =E2=80=98__trace_ust_slavio_misc_update_irq_lower=E2=
=80=99:
> trace.h:280: error: =E2=80=98void=E2=80=99 must be the only parameter
> trace.h:280: error: expected expression before =E2=80=98)=E2=80=99 token
> trace.h:280: error: too many arguments to function =E2=80=98(void (*)(voi=
d =20
> *))__tp_it_func=E2=80=99
>
>
>  I am not sure which interface is supposed to be used for void arguments=
=20
> in ust 0.16.

Looking at scripts/tracetool:

linetoh_ust()
{
    local name args argnames
    name=3D$(get_name "$1")
    args=3D$(get_args "$1")
    argnames=3D$(get_argnames "$1", ",")

    cat <<EOF
DECLARE_TRACE(ust_$name, TP_PROTO($args), TP_ARGS($argnames));
#define trace_$name trace_ust_$name
EOF
}

for those tracepoints with argument "void", DECLARE_TRACE_NOARGS should
be used for UST 0.16. Similar for:

DEFINE_TRACE(ust_$name); -> DEFINE_TRACE_NOARGS(ust_$name);

> Moreover, if ust 2.0 uses different interfaces, we might=20
> want to use the latest one.

Note that this kind of special-case won't be needed with LTTng-UST 2.0
TRACEPOINT_EVENT. In place of DECLARE_TRACE, one would use:

TRACEPOINT_EVENT(qemu_kvm, $name,
        TP_ARGS($args),
        TP_FIELDS()
)

Note that I notice that some care will need to be taken to generate the
TP_FIELDS() from your existing trace-events file, an example:

g_realloc(void *ptr, size_t size, void *newptr)

would have to be translated to:

TRACE_EVENT(qemu_kvm, g_realloc,
        TP_ARGS(void *, ptr, size_t, size, void *, newptr),
        TP_FIELDS(
                ctf_integer_hex(void *, ptr, ptr)
                ctf_integer(size_t, size, size)
                ctf_integer_hex(void *, newptr, newptr)
        )
)
=20
Note that the bright side is that the tracepoint probe does not need to
be hand-coded anymore, and there is no need to use the markers anymore
neither, which makes the tracer much faster.

For most of your fields (using %p, %d style format strings), you should
use ctf_integer or ctf_integer_hex (the latter lets the trace viewer
know that the data should be printed as hexadecimal).
You will likely need to detect the %s format strings you have there and
translate them into ctf_string(field, field) too. You can have a look at
lttng-ust tests/hello/*.[ch] for examples.

The call which would have looked like trace_qemu_kvm_g_realloc() in UST
0.x should now be done with:

  tracepoint(qemu_kvm, g_realloc, ptr, size, newptr);

This is needed to (very soon) add support for sdt.h in LTTng-UST 2.0, so
systemtap and gdb can hook into tracepoints declared by lttng-ust 2.0.

Best regards,

Mathieu

>
> regards,
> Harsh
>
>> Best regards,
>>
>> Mathieu
>>
>>>
>>> Version History:
>>>
>>> v2:
>>> - Updated tracetool.py to support nop, stderr, dtrace backend
>>>
>>> v1:
>>> - Working protoype with tracetool.py converted only for simpletrace bac=
kend
>>>
>>> Harsh Prateek Bora (4):
>>>    Converting tracetool.sh to tracetool.py
>>>    Makefile and configure changes for tracetool.py
>>>    simpletrace-v2: Handle variable number/size of elements per trace
>>>      record.
>>>    simpletrace.py: updated log reader script to handle new log format
>>>
>>>   Makefile.objs          |    6 +-
>>>   Makefile.target        |   10 +-
>>>   configure              |    4 +-
>>>   monitor.c              |    2 +-
>>>   scripts/simpletrace.py |  110 ++++++++++-
>>>   scripts/tracetool.py   |  505 +++++++++++++++++++++++++++++++++++++++=
+++++++++
>>>   trace/simple.c         |  178 ++++++-----------
>>>   trace/simple.h         |   31 +++-
>>>   8 files changed, 702 insertions(+), 144 deletions(-)
>>>   create mode 100755 scripts/tracetool.py
>>>
>>
>

--=20
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com