[Qemu-devel] [PATCH 0/2] improve tracing

Vladimir Sementsov-Ogievskiy posted 2 patches 8 years, 3 months ago
Patches applied successfully (tree, apply log)
git fetch https://github.com/patchew-project/qemu tags/patchew/20170721143149.43721-1-vsementsov@virtuozzo.com
Test FreeBSD passed
Test checkpatch passed
Test s390x passed
monitor.c                     |  6 +++---
scripts/tracetool/format/h.py | 13 +++++++------
2 files changed, 10 insertions(+), 9 deletions(-)
[Qemu-devel] [PATCH 0/2] improve tracing
Posted by Vladimir Sementsov-Ogievskiy 8 years, 3 months ago
Current trace system have a drawback: parameters of trace functions
are calculated even if corresponding tracepoint is disabled. Also, it
looks like trace function are not actually inlined by compiler (at
least for me).

Here is a fix proposal: move from function call to macros. Patch 02
is an example, of how to reduce extra calculations with help of
patch 01.

Vladimir Sementsov-Ogievskiy (2):
  trace: do not calculate arguments for disabled trace-points
  monitor: improve tracing in handle_qmp_command

 monitor.c                     |  6 +++---
 scripts/tracetool/format/h.py | 13 +++++++------
 2 files changed, 10 insertions(+), 9 deletions(-)

-- 
2.11.1


Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Lluís Vilanova 8 years, 3 months ago
Vladimir Sementsov-Ogievskiy writes:

> Current trace system have a drawback: parameters of trace functions
> are calculated even if corresponding tracepoint is disabled. Also, it
> looks like trace function are not actually inlined by compiler (at
> least for me).

> Here is a fix proposal: move from function call to macros. Patch 02
> is an example, of how to reduce extra calculations with help of
> patch 01.

The tracing functions *were* inlined last time I checked, although things
changed quite a lot since then. Not sure that will make a lot of difference in
terms of overall performance (needs measuring).

As for arguments, each trace event has a define TRACE_{NAME}_ENABLED that you
can use for that purpose. If this is not explained in tracing.txt, that is a
documentation bug.


Thanks,
  Lluis

Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Vladimir Sementsov-Ogievskiy 8 years, 3 months ago
21.07.2017 20:04, Lluís Vilanova wrote:
> Vladimir Sementsov-Ogievskiy writes:
>
>> Current trace system have a drawback: parameters of trace functions
>> are calculated even if corresponding tracepoint is disabled. Also, it
>> looks like trace function are not actually inlined by compiler (at
>> least for me).
>> Here is a fix proposal: move from function call to macros. Patch 02
>> is an example, of how to reduce extra calculations with help of
>> patch 01.
> The tracing functions *were* inlined last time I checked, although things
> changed quite a lot since then. Not sure that will make a lot of difference in
> terms of overall performance (needs measuring).
>
> As for arguments, each trace event has a define TRACE_{NAME}_ENABLED that you
> can use for that purpose. If this is not explained in tracing.txt, that is a
> documentation bug.

These macroses are about enable/disable traces statically. I'm saying 
about dynamic disable/enable.

>
>
> Thanks,
>    Lluis


-- 
Best regards,
Vladimir


Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Lluís Vilanova 8 years, 3 months ago
Vladimir Sementsov-Ogievskiy writes:

> 21.07.2017 20:04, Lluís Vilanova wrote:
>> Vladimir Sementsov-Ogievskiy writes:
>> 
>>> Current trace system have a drawback: parameters of trace functions
>>> are calculated even if corresponding tracepoint is disabled. Also, it
>>> looks like trace function are not actually inlined by compiler (at
>>> least for me).
>>> Here is a fix proposal: move from function call to macros. Patch 02
>>> is an example, of how to reduce extra calculations with help of
>>> patch 01.
>> The tracing functions *were* inlined last time I checked, although things
>> changed quite a lot since then. Not sure that will make a lot of difference in
>> terms of overall performance (needs measuring).
>> 
>> As for arguments, each trace event has a define TRACE_{NAME}_ENABLED that you
>> can use for that purpose. If this is not explained in tracing.txt, that is a
>> documentation bug.

> These macroses are about enable/disable traces statically. I'm saying about
> dynamic disable/enable.

Aha, I see. I think most events get passed already-calculated variables (usually
for other purposes), so I don't think it will have much of a performance
impact. Did you measure it?


Thanks,
  Lluis

Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Denis V. Lunev 8 years, 3 months ago
On 07/24/2017 02:07 PM, Lluís Vilanova wrote:
> Vladimir Sementsov-Ogievskiy writes:
>
>> 21.07.2017 20:04, Lluís Vilanova wrote:
>>> Vladimir Sementsov-Ogievskiy writes:
>>>
>>>> Current trace system have a drawback: parameters of trace functions
>>>> are calculated even if corresponding tracepoint is disabled. Also, it
>>>> looks like trace function are not actually inlined by compiler (at
>>>> least for me).
>>>> Here is a fix proposal: move from function call to macros. Patch 02
>>>> is an example, of how to reduce extra calculations with help of
>>>> patch 01.
>>> The tracing functions *were* inlined last time I checked, although things
>>> changed quite a lot since then. Not sure that will make a lot of difference in
>>> terms of overall performance (needs measuring).
>>>
>>> As for arguments, each trace event has a define TRACE_{NAME}_ENABLED that you
>>> can use for that purpose. If this is not explained in tracing.txt, that is a
>>> documentation bug.
>> These macroses are about enable/disable traces statically. I'm saying about
>> dynamic disable/enable.
> Aha, I see. I think most events get passed already-calculated variables (usually
> for other purposes), so I don't think it will have much of a performance
> impact. Did you measure it?
>
>
> Thanks,
>   Lluis
The idea is that we can add more complex stuff after the patch.
QMP command log is a very good example of that.

Actually at our opinion macro will be safe but much better
from the point of side-effects - arguments will never be evaluated
until the trace happened.

Den

Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Stefan Hajnoczi 8 years, 3 months ago
On Fri, Jul 21, 2017 at 08:04:17PM +0300, Lluís Vilanova wrote:
> Vladimir Sementsov-Ogievskiy writes:
> 
> > Current trace system have a drawback: parameters of trace functions
> > are calculated even if corresponding tracepoint is disabled. Also, it
> > looks like trace function are not actually inlined by compiler (at
> > least for me).
> 
> > Here is a fix proposal: move from function call to macros. Patch 02
> > is an example, of how to reduce extra calculations with help of
> > patch 01.
> 
> The tracing functions *were* inlined last time I checked, although things
> changed quite a lot since then. Not sure that will make a lot of difference in
> terms of overall performance (needs measuring).
> 
> As for arguments, each trace event has a define TRACE_{NAME}_ENABLED that you
> can use for that purpose. If this is not explained in tracing.txt, that is a
> documentation bug.

It is described in docs/devel/tracing.txt:

In addition, there might be cases where relatively complex computations must be
performed to generate values that are only used as arguments for a trace
function. In these cases you can use the macro 'TRACE_${EVENT_NAME}_ENABLED' to
guard such computations and avoid its compilation when the event is disabled:

    #include "trace.h"  /* needed for trace event prototype */
    
    void *qemu_vmalloc(size_t size)
    {
        void *ptr;
        size_t align = QEMU_VMALLOC_ALIGN;
    
        if (size < align) {
            align = getpagesize();
        }
        ptr = qemu_memalign(align, size);
        if (TRACE_QEMU_VMALLOC_ENABLED) { /* preprocessor macro */
            void *complex;
            /* some complex computations to produce the 'complex' value */
            trace_qemu_vmalloc(size, ptr, complex);
        }
        return ptr;
    }
Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Stefan Hajnoczi 8 years, 3 months ago
On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
> Current trace system have a drawback: parameters of trace functions
> are calculated even if corresponding tracepoint is disabled. Also, it
> looks like trace function are not actually inlined by compiler (at
> least for me).
> 
> Here is a fix proposal: move from function call to macros. Patch 02
> is an example, of how to reduce extra calculations with help of
> patch 01.
> 
> Vladimir Sementsov-Ogievskiy (2):
>   trace: do not calculate arguments for disabled trace-points
>   monitor: improve tracing in handle_qmp_command

Please use the TRACE_FOO_ENABLED macro instead of putting computation
inside the trace event arguments.  This makes the code cleaner and
easier to read.
Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Denis V. Lunev 8 years, 3 months ago
On 07/24/2017 02:34 PM, Stefan Hajnoczi wrote:
> On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
>> Current trace system have a drawback: parameters of trace functions
>> are calculated even if corresponding tracepoint is disabled. Also, it
>> looks like trace function are not actually inlined by compiler (at
>> least for me).
>>
>> Here is a fix proposal: move from function call to macros. Patch 02
>> is an example, of how to reduce extra calculations with help of
>> patch 01.
>>
>> Vladimir Sementsov-Ogievskiy (2):
>>   trace: do not calculate arguments for disabled trace-points
>>   monitor: improve tracing in handle_qmp_command
> Please use the TRACE_FOO_ENABLED macro instead of putting computation
> inside the trace event arguments.  This makes the code cleaner and
> easier to read.
At our opinion this ENABLED is compile time check while the option
could be tuned in runtime. Thus normally it would normally be
enabled while the trace is silent.

So, under load, we will have extra allocation, copying the command buffer,
freeing memory without actual trace. In order to fix that we should
do something like

if (trace_event_get_state(TRACE_HANDLE_QMP_COMMAND)) {
   req_json = qobject_to_json(req);
   trace_handle_qmp_command(mon, req_json);
   QDECREF(req_json);
}

which is possible, but at our (me + Vova) opinion is ugly.
That is why we are proposing to switch to macro, which
will not require such tweaking.

Arguments will be only evaluated when necessary and we
will not have side-effects if the tracepoint is compile time
enabled and run-time disabled.

Though if the code above is acceptable, we can send the
patch with it. No problem.

Den


Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Lluís Vilanova 8 years, 3 months ago
Denis V Lunev writes:

> On 07/24/2017 02:34 PM, Stefan Hajnoczi wrote:
>> On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
>>> Current trace system have a drawback: parameters of trace functions
>>> are calculated even if corresponding tracepoint is disabled. Also, it
>>> looks like trace function are not actually inlined by compiler (at
>>> least for me).
>>> 
>>> Here is a fix proposal: move from function call to macros. Patch 02
>>> is an example, of how to reduce extra calculations with help of
>>> patch 01.
>>> 
>>> Vladimir Sementsov-Ogievskiy (2):
>>> trace: do not calculate arguments for disabled trace-points
>>> monitor: improve tracing in handle_qmp_command
>> Please use the TRACE_FOO_ENABLED macro instead of putting computation
>> inside the trace event arguments.  This makes the code cleaner and
>> easier to read.
> At our opinion this ENABLED is compile time check while the option
> could be tuned in runtime. Thus normally it would normally be
> enabled while the trace is silent.

> So, under load, we will have extra allocation, copying the command buffer,
> freeing memory without actual trace. In order to fix that we should
> do something like

> if (trace_event_get_state(TRACE_HANDLE_QMP_COMMAND)) {
>    req_json = qobject_to_json(req);
>    trace_handle_qmp_command(mon, req_json);
>    QDECREF(req_json);
> }

> which is possible, but at our (me + Vova) opinion is ugly.
> That is why we are proposing to switch to macro, which
> will not require such tweaking.

> Arguments will be only evaluated when necessary and we
> will not have side-effects if the tracepoint is compile time
> enabled and run-time disabled.

> Though if the code above is acceptable, we can send the
> patch with it. No problem.

I completely get your point, but:

* I'm not sure it will have much of a performance impact.
* It is not obvious what's going to happen just by looking at the code of the
  calling site.

I prefer to minimize the use of macros, even if that makes a few trace event
calls to be a bit more verbose, as in your example above. Also, I quite dislike
the new style you propose:

  trace_handle_qmp_command(mon,
                           qstring_get_str(req_json = qobject_to_json(req)));
  QDECREF(req_json);


Cheers,
  Lluis

Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Denis V. Lunev 8 years, 3 months ago
On 07/24/2017 05:43 PM, Lluís Vilanova wrote:
> Denis V Lunev writes:
>
>> On 07/24/2017 02:34 PM, Stefan Hajnoczi wrote:
>>> On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
>>>> Current trace system have a drawback: parameters of trace functions
>>>> are calculated even if corresponding tracepoint is disabled. Also, it
>>>> looks like trace function are not actually inlined by compiler (at
>>>> least for me).
>>>>
>>>> Here is a fix proposal: move from function call to macros. Patch 02
>>>> is an example, of how to reduce extra calculations with help of
>>>> patch 01.
>>>>
>>>> Vladimir Sementsov-Ogievskiy (2):
>>>> trace: do not calculate arguments for disabled trace-points
>>>> monitor: improve tracing in handle_qmp_command
>>> Please use the TRACE_FOO_ENABLED macro instead of putting computation
>>> inside the trace event arguments.  This makes the code cleaner and
>>> easier to read.
>> At our opinion this ENABLED is compile time check while the option
>> could be tuned in runtime. Thus normally it would normally be
>> enabled while the trace is silent.
>> So, under load, we will have extra allocation, copying the command buffer,
>> freeing memory without actual trace. In order to fix that we should
>> do something like
>> if (trace_event_get_state(TRACE_HANDLE_QMP_COMMAND)) {
>>    req_json = qobject_to_json(req);
>>    trace_handle_qmp_command(mon, req_json);
>>    QDECREF(req_json);
>> }
>> which is possible, but at our (me + Vova) opinion is ugly.
>> That is why we are proposing to switch to macro, which
>> will not require such tweaking.
>> Arguments will be only evaluated when necessary and we
>> will not have side-effects if the tracepoint is compile time
>> enabled and run-time disabled.
>> Though if the code above is acceptable, we can send the
>> patch with it. No problem.
> I completely get your point, but:
>
> * I'm not sure it will have much of a performance impact.
> * It is not obvious what's going to happen just by looking at the code of the
>   calling site.
>
> I prefer to minimize the use of macros, even if that makes a few trace event
> calls to be a bit more verbose, as in your example above. Also, I quite dislike
> the new style you propose:
>
>   trace_handle_qmp_command(mon,
>                            qstring_get_str(req_json = qobject_to_json(req)));
>   QDECREF(req_json);
>
>
> Cheers,
>   Lluis
This is a matter of overall performance. For example I can have 500 VMs.
In order to manage them, f.e. tweak balloon I have to collect statistics.
This happens 1 time/10 sec/VM. Libvirt issues the following

494665@1486641285.213042:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-balloon"
494665@1486641285.214181:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "qom-get"
494665@1486641285.214792:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-hotpluggable-cpus"
494665@1486641285.215283:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-cpus"
494665@1486641285.216153:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-blockstats"
494665@1486641285.216827:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-block"

We will have 300 commands in a second in all VMs. This is not that small
load. OK. I do think that I'll lost 2-3-5 percents of one host CPU due
to this allocation/free/copy. There are no measurements unfortunately.
At my opinion this matters.

Den



Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Lluís Vilanova 8 years, 3 months ago
Denis V Lunev writes:

> On 07/24/2017 05:43 PM, Lluís Vilanova wrote:
>> Denis V Lunev writes:
>> 
>>> On 07/24/2017 02:34 PM, Stefan Hajnoczi wrote:
>>>> On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
>>>>> Current trace system have a drawback: parameters of trace functions
>>>>> are calculated even if corresponding tracepoint is disabled. Also, it
>>>>> looks like trace function are not actually inlined by compiler (at
>>>>> least for me).
>>>>> 
>>>>> Here is a fix proposal: move from function call to macros. Patch 02
>>>>> is an example, of how to reduce extra calculations with help of
>>>>> patch 01.
>>>>> 
>>>>> Vladimir Sementsov-Ogievskiy (2):
>>>>> trace: do not calculate arguments for disabled trace-points
>>>>> monitor: improve tracing in handle_qmp_command
>>>> Please use the TRACE_FOO_ENABLED macro instead of putting computation
>>>> inside the trace event arguments.  This makes the code cleaner and
>>>> easier to read.
>>> At our opinion this ENABLED is compile time check while the option
>>> could be tuned in runtime. Thus normally it would normally be
>>> enabled while the trace is silent.
>>> So, under load, we will have extra allocation, copying the command buffer,
>>> freeing memory without actual trace. In order to fix that we should
>>> do something like
>>> if (trace_event_get_state(TRACE_HANDLE_QMP_COMMAND)) {
>>> req_json = qobject_to_json(req);
>>> trace_handle_qmp_command(mon, req_json);
>>> QDECREF(req_json);
>>> }
>>> which is possible, but at our (me + Vova) opinion is ugly.
>>> That is why we are proposing to switch to macro, which
>>> will not require such tweaking.
>>> Arguments will be only evaluated when necessary and we
>>> will not have side-effects if the tracepoint is compile time
>>> enabled and run-time disabled.
>>> Though if the code above is acceptable, we can send the
>>> patch with it. No problem.
>> I completely get your point, but:
>> 
>> * I'm not sure it will have much of a performance impact.
>> * It is not obvious what's going to happen just by looking at the code of the
>> calling site.
>> 
>> I prefer to minimize the use of macros, even if that makes a few trace event
>> calls to be a bit more verbose, as in your example above. Also, I quite dislike
>> the new style you propose:
>> 
>> trace_handle_qmp_command(mon,
>> qstring_get_str(req_json = qobject_to_json(req)));
>> QDECREF(req_json);
>> 
>> 
>> Cheers,
>> Lluis
> This is a matter of overall performance. For example I can have 500 VMs.
> In order to manage them, f.e. tweak balloon I have to collect statistics.
> This happens 1 time/10 sec/VM. Libvirt issues the following

> 494665@1486641285.213042:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-balloon"
> 494665@1486641285.214181:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "qom-get"
> 494665@1486641285.214792:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-hotpluggable-cpus"
> 494665@1486641285.215283:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-cpus"
> 494665@1486641285.216153:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-blockstats"
> 494665@1486641285.216827:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-block"

> We will have 300 commands in a second in all VMs. This is not that small
> load. OK. I do think that I'll lost 2-3-5 percents of one host CPU due
> to this allocation/free/copy. There are no measurements unfortunately.
> At my opinion this matters.

Sorry for beating the point, but I just want to make sure we're on the same
page. The example above (with the state check) and the one you propose in your
patch have exactly the same performance.

The change is then only in coding style, and I think the macros you propose make
the code harder to understand:

  trace_handle_qmp_command(mon,
                           qstring_get_str(req_json = qobject_to_json(req)));
  QDECREF(req_json);

If qobject_to_json() had any side-effect, it is not obvious why it would happen
only when tracing of that event is dynaically enabled. IMO that's a recipe for
errors.


Cheers,
  Lluis

Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Stefan Hajnoczi 8 years, 3 months ago
On Mon, Jul 24, 2017 at 07:32:29PM +0300, Lluís Vilanova wrote:
> Denis V Lunev writes:
> 
> > On 07/24/2017 05:43 PM, Lluís Vilanova wrote:
> >> Denis V Lunev writes:
> >> 
> >>> On 07/24/2017 02:34 PM, Stefan Hajnoczi wrote:
> >>>> On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
> >>>>> Current trace system have a drawback: parameters of trace functions
> >>>>> are calculated even if corresponding tracepoint is disabled. Also, it
> >>>>> looks like trace function are not actually inlined by compiler (at
> >>>>> least for me).
> >>>>> 
> >>>>> Here is a fix proposal: move from function call to macros. Patch 02
> >>>>> is an example, of how to reduce extra calculations with help of
> >>>>> patch 01.
> >>>>> 
> >>>>> Vladimir Sementsov-Ogievskiy (2):
> >>>>> trace: do not calculate arguments for disabled trace-points
> >>>>> monitor: improve tracing in handle_qmp_command
> >>>> Please use the TRACE_FOO_ENABLED macro instead of putting computation
> >>>> inside the trace event arguments.  This makes the code cleaner and
> >>>> easier to read.
> >>> At our opinion this ENABLED is compile time check while the option
> >>> could be tuned in runtime. Thus normally it would normally be
> >>> enabled while the trace is silent.
> >>> So, under load, we will have extra allocation, copying the command buffer,
> >>> freeing memory without actual trace. In order to fix that we should
> >>> do something like
> >>> if (trace_event_get_state(TRACE_HANDLE_QMP_COMMAND)) {
> >>> req_json = qobject_to_json(req);
> >>> trace_handle_qmp_command(mon, req_json);
> >>> QDECREF(req_json);
> >>> }
> >>> which is possible, but at our (me + Vova) opinion is ugly.
> >>> That is why we are proposing to switch to macro, which
> >>> will not require such tweaking.
> >>> Arguments will be only evaluated when necessary and we
> >>> will not have side-effects if the tracepoint is compile time
> >>> enabled and run-time disabled.
> >>> Though if the code above is acceptable, we can send the
> >>> patch with it. No problem.
> >> I completely get your point, but:
> >> 
> >> * I'm not sure it will have much of a performance impact.
> >> * It is not obvious what's going to happen just by looking at the code of the
> >> calling site.
> >> 
> >> I prefer to minimize the use of macros, even if that makes a few trace event
> >> calls to be a bit more verbose, as in your example above. Also, I quite dislike
> >> the new style you propose:
> >> 
> >> trace_handle_qmp_command(mon,
> >> qstring_get_str(req_json = qobject_to_json(req)));
> >> QDECREF(req_json);
> >> 
> >> 
> >> Cheers,
> >> Lluis
> > This is a matter of overall performance. For example I can have 500 VMs.
> > In order to manage them, f.e. tweak balloon I have to collect statistics.
> > This happens 1 time/10 sec/VM. Libvirt issues the following
> 
> > 494665@1486641285.213042:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-balloon"
> > 494665@1486641285.214181:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "qom-get"
> > 494665@1486641285.214792:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-hotpluggable-cpus"
> > 494665@1486641285.215283:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-cpus"
> > 494665@1486641285.216153:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-blockstats"
> > 494665@1486641285.216827:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-block"
> 
> > We will have 300 commands in a second in all VMs. This is not that small
> > load. OK. I do think that I'll lost 2-3-5 percents of one host CPU due
> > to this allocation/free/copy. There are no measurements unfortunately.
> > At my opinion this matters.
> 
> Sorry for beating the point, but I just want to make sure we're on the same
> page. The example above (with the state check) and the one you propose in your
> patch have exactly the same performance.
> 
> The change is then only in coding style, and I think the macros you propose make
> the code harder to understand:
> 
>   trace_handle_qmp_command(mon,
>                            qstring_get_str(req_json = qobject_to_json(req)));
>   QDECREF(req_json);
> 
> If qobject_to_json() had any side-effect, it is not obvious why it would happen
> only when tracing of that event is dynaically enabled. IMO that's a recipe for
> errors.

I agree and this is why I said "cleaner and easier to read".  Side
effects in macro/function arguments are prone to bugs.

Stefan
Re: [Qemu-devel] [PATCH 0/2] improve tracing
Posted by Philippe Mathieu-Daudé 8 years, 3 months ago
On 07/24/2017 09:17 AM, Denis V. Lunev wrote:
> On 07/24/2017 02:34 PM, Stefan Hajnoczi wrote:
>> On Fri, Jul 21, 2017 at 05:31:47PM +0300, Vladimir Sementsov-Ogievskiy wrote:
>>> Current trace system have a drawback: parameters of trace functions
>>> are calculated even if corresponding tracepoint is disabled. Also, it
>>> looks like trace function are not actually inlined by compiler (at
>>> least for me).
>>>
>>> Here is a fix proposal: move from function call to macros. Patch 02
>>> is an example, of how to reduce extra calculations with help of
>>> patch 01.
>>>
>>> Vladimir Sementsov-Ogievskiy (2):
>>>    trace: do not calculate arguments for disabled trace-points
>>>    monitor: improve tracing in handle_qmp_command
>> Please use the TRACE_FOO_ENABLED macro instead of putting computation
>> inside the trace event arguments.  This makes the code cleaner and
>> easier to read.
> At our opinion this ENABLED is compile time check while the option
> could be tuned in runtime. Thus normally it would normally be
> enabled while the trace is silent.
> 
> So, under load, we will have extra allocation, copying the command buffer,
> freeing memory without actual trace. In order to fix that we should
> do something like
> 
> if (trace_event_get_state(TRACE_HANDLE_QMP_COMMAND)) {
>     req_json = qobject_to_json(req);
>     trace_handle_qmp_command(mon, req_json);
>     QDECREF(req_json);
> }
> 
> which is possible, but at our (me + Vova) opinion is ugly.

It seems to me much cleaner/easier to read than your patch, I really 
prefer this way. It is so nice/useful that it deserves to be starred as 
an example in docs/devel/tracing.txt :)

> That is why we are proposing to switch to macro, which
> will not require such tweaking.
> 
> Arguments will be only evaluated when necessary and we
> will not have side-effects if the tracepoint is compile time
> enabled and run-time disabled.
> 
> Though if the code above is acceptable, we can send the
> patch with it. No problem.
> 
> Den