[Development] QtCS 2017 logging/tracing session notes

[Christian Gagneraud]

On 12 October 2017 at 10:10, Arnaud Clère
<arnaud.clere at minmaxmedical.com> wrote:
> Regarding the ParTraP language, currently, you need to parse, transform and classify
> unstructured traces in a JSON form to be able to use it. JSON will remain the pivot format
> between trace stores and tools so, if ETW or whatever native format is used to store
> traces, there must be a conversion tool... Stay tuned!

LTT uses the "Common Trace Format":

See http://diamon.org/ctf/

Worth reading as well:
http://www.efficios.com/pub/linuxcon2010/presentation-linuxcon-trace-format-2010.pdf
https://www.ibm.com/developerworks/community/blogs/fe313521-2e95-46f2-817d-44a4f27eba32/entry/howto_tracing_with_lttng?lang=en
https://www.slideshare.net/ennael/2013-kernel-recipeslttgtkwave


> I will now try to answer the ones regarding modmed... and digress to explain what IMO we should
>  examine and discuss regarding Qt tracing.
> 1/ Avoid numeric and binary data formatting by offering a serializable binary format.
> 2/ Avoid memory allocations.
> 3/ Limit indirection levels from tracepoint to output.

I think these 3 points come for free with LTT/CTF.

The CTF Trace Stream Description Language (TSDL) could be useful to
modmedLog, traced structures could be defined in TSDL language.
Run-time support code could be generated from this.
Your "bind" mechanism could then be be used to
populate/serialise/queue the traces?
See http://diamon.org/ctf/#spec7

CTF is used for other tooling such as linux perf framework, ftrace,
and certainly more.

Given that CTF is an open standard, there should not be any issues to
convert  them to JSON, thought I'm not sure this is the most efficient
way to deal with massive amount of traces.

> Regarding your concerns about locks, there must be some mechanism to avoid mixing
>  events from multiple threads but native APIs certainly provide very efficient solutions.
> On our side, if we avoid dynamic allocations, we should be able to avoid 99% of the
> locks by writing in a reasonably large buffer before sending the result to native APIs.
> Would that be enough?

My point here is that the Qt logging framework is not appropriate
simply b/c it was not design for high perf tracing.
LTT/CTF have a very high throughput, with minimal impact on the
observed system .
These tools are *at least* an order of magnitude faster than an
instrumenting profiler (source: some slides, sorry I forgot the url).

I've just ran a 20s LTT session (kernel traces only) in which i just
started QtCreator. I ended up with 300+MB of binary traces. I could
not notice any slow down whatsoever during the tracing session. CTF
traces can be arbitrary simple or complex.
Eg. just an example:
event {
        name = "syscall_exit_epoll_ctl";
        id = 503;
        stream_id = 0;
        fields := struct {
                integer { size = 64; align = 8; signed = 1; encoding =
none; base = 10; } _ret;
        };
};

event {
        name = "syscall_exit_epoll_wait";
        id = 502;
        stream_id = 0;
        fields := struct {
                integer { size = 64; align = 8; signed = 1; encoding =
none; base = 10; } _ret;
                integer { size = 32; align = 8; signed = 0; encoding =
none; base = 10; } _fds_length;
                integer { size = 8; align = 8; signed = 0; encoding =
none; base = 10; } _overflow;
                struct {
                        struct {
                                integer { size = 64; align = 8; signed
= 0; encoding = none; base = 16; } _u64;
                                integer { size = 32; align = 8; signed
= 0; encoding = none; base = 10; } _fd;
                        }_data_union;
                        integer { size = 32; align = 8; signed = 0;
encoding = none; base = 16; } _raw_events;
                        struct {
                                integer { size = 1; align = 1; signed
= 0; encoding = none; base = 10; } _EPOLLIN;
                                integer { size = 1; align = 1; signed
= 0; encoding = none; base = 10; } _EPOLLPRI;
                                integer { size = 1; align = 1; signed
= 0; encoding = none; base = 10; } _EPOLLOUT;
                                integer { size = 1; align = 1; signed
= 0; encoding = none; base = 10; } _EPOLLERR;
                                integer { size = 4; align = 1; signed
= 0; encoding = none; base = 10; } _padding;
                        }_events;
                } _fds[ _fds_length ];
        };
};

Net_dev traces are way more complicated than the above, see
https://pastebin.com/bAebsWr6

Anyway, enough about LTT/CTF, I'll try to spend some time on the
windows ETW (https://msdn.microsoft.com/en-us/library/windows/desktop/bb968803(v=vs.85).aspx)

Chris

PS:
I am unable to clone any repo from your forge. HTTPS times out and SSH
gives me a  permission denied.

OT:
I saw recently ARM Streamline in action, it's quite impressive,
horse-work seems to be implemented in kernel space, but you can as
well profile user-space applications or mix both:
https://developer.arm.com/products/software-development-tools/ds-5-development-studio/streamline
https://github.com/ARM-software/gator