Re: [Qemu-devel] trace: timestamps, core IDs, and file creation

[Stefan Hajnoczi]

On Wed, Jan 13, 2016 at 03:13:02PM -0800, Hollis Blanchard wrote:
> Hi Stefan, I've been starting to use qemu tracing and found it quite useful.
> I have a couple comments about the trace events in general:

Sorry for the late reply.

> The event timestamps are host time (get_clock()). I'm correlating qemu
> events with other logs (using icount), so host time is unhelpful. Could we
> use cpu_get_clock() instead? (Trace events are used in other tools like
> qemu-io, where guest time doesn't exist, and there we could continue to use
> get_clock().)

It must be possible to trace code while the guest CPUs are stopped, so
cpu_get_clock() on own breaks existing users.

If the CPU clock is more convenient for you, perhaps you can add an
option to use that clocksource?

> When trying to understand multi-core guest behavior, it's pretty important
> to know which core is performing the traced action (e.g. MMIO). Would it
> make sense to automatically embed the core index, like the timestamp, or do
> you think it should be encoded in each individual tracepoint?

I think that Lluís has some of this stuff automated in his TCG tracing
work.  He has added special trace event types for TCG that can be
planted at code generation time as well as TB execution time.  They can
include the vcpu number automatically IIRC.

Regarding I/O emulation, we have to be careful because architecturally
some types of devices (e.g. PCI devices) don't have the concept of which
core is performing an action.  QEMU takes advantage of that with
ioeventfd where a lightweight vmexit simply marks an eventfd file
descriptor readable in the kernel and quickly returns back to vcpu
execution.  Another QEMU thread monitors the eventfd and processes the
notification and there is no concept of the current vcpu at that point.

It might be easiest to include the vcpu id in the trace event explicitly
for now.

> Right now, the simple tracepoint backend creates a trace file even when no
> events are active and no -trace options are present. Compounding the
> situation, omitting "-trace file=foo" results in the directory being
> littered with trace-NNNN files... could we create the file only when tracing
> is activated? And maybe with a more predictable name?

It should be possible to create the file only if traces are actually
generated.  I guess this wasn't done for simplicity and because the
write-out thread needs to empty the ring buffer as quickly as possible
to avoid dropping trace data.

The names contains the QEMU pid.  Although the pid isn't predictable it
is useful for correlating with system logs, host performance tools, etc.

You can override the name with -trace file=foo.log if you want.

Do you have an idea for another automatic file naming scheme?

Stefan

signature.asc
Description: PGP signature