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

["Denis V. Lunev" <den@openvz.org>]

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