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

[Stefan Hajnoczi]

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
> 
> > address@hidden:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name 
> > "query-balloon"
> > address@hidden:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "qom-get"
> > address@hidden:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name 
> > "query-hotpluggable-cpus"
> > address@hidden:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name "query-cpus"
> > address@hidden:handle_qmp_command mon 0x7f7fbce6bea0 cmd_name 
> > "query-blockstats"
> > address@hidden: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

signature.asc
Description: PGP signature