* [Qemu-devel] trace: timestamps, core IDs, and file creation @ 2016-01-13 23:13 Hollis Blanchard 2016-02-08 15:30 ` Stefan Hajnoczi 2016-02-08 18:01 ` Alex Bennée 0 siblings, 2 replies; 11+ messages in thread From: Hollis Blanchard @ 2016-01-13 23:13 UTC (permalink / raw) To: Stefan Hajnoczi; +Cc: QEMU Developers 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: 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().) 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? 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? -- Hollis Blanchard Mentor Graphics Emulation Division ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] trace: timestamps, core IDs, and file creation 2016-01-13 23:13 [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard @ 2016-02-08 15:30 ` Stefan Hajnoczi 2016-02-08 16:29 ` Lluís Vilanova ` (2 more replies) 2016-02-08 18:01 ` Alex Bennée 1 sibling, 3 replies; 11+ messages in thread From: Stefan Hajnoczi @ 2016-02-08 15:30 UTC (permalink / raw) To: Hollis Blanchard; +Cc: QEMU Developers [-- Attachment #1: Type: text/plain, Size: 2824 bytes --] 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 [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] trace: timestamps, core IDs, and file creation 2016-02-08 15:30 ` Stefan Hajnoczi @ 2016-02-08 16:29 ` Lluís Vilanova 2016-02-08 18:51 ` [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted Hollis Blanchard 2016-02-08 19:59 ` [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard 2 siblings, 0 replies; 11+ messages in thread From: Lluís Vilanova @ 2016-02-08 16:29 UTC (permalink / raw) To: Stefan Hajnoczi; +Cc: Hollis Blanchard, QEMU Developers Stefan Hajnoczi writes: > 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? Hmmmm, what about abusing the "vcpu" event property I sent to automatically emit the vCPU icount? We could make that a compile-time option. This also makes me think that the print format for the vCPU can be auto-generated by tracetool (it must now be set explicitly), so that what's printed can be easily interchanged. We can make that a follow-up series. >> 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. Yup, that's the last series I sent, which hasn't been reviewed yet: https://lists.gnu.org/archive/html/qemu-devel/2016-01/msg05996.html If any event (including outside tcg code) has a pointer to the "guilty" vCPU, support for showing the vCPU can be easily added. > 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. See the two responses above. Cheers, Lluis ^ permalink raw reply [flat|nested] 11+ messages in thread
* [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted. 2016-02-08 15:30 ` Stefan Hajnoczi 2016-02-08 16:29 ` Lluís Vilanova @ 2016-02-08 18:51 ` Hollis Blanchard 2016-02-08 20:02 ` Alex Bennée ` (2 more replies) 2016-02-08 19:59 ` [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard 2 siblings, 3 replies; 11+ messages in thread From: Hollis Blanchard @ 2016-02-08 18:51 UTC (permalink / raw) To: qemu-devel; +Cc: stefanha, Hollis Blanchard Previously, trace record files (created by st_set_trace_file_enabled(true)) were created by the simple backend at initialization time, even if no events were actually enabled. As a consequence, the working directory would become littered with trace-PID files just by enabling the simple backend at configure time, even when no -trace options were used. --- I've been using this to avoid creation of empty trace record files. I haven't done any scientific performance studies, but an extra function call/conditional/return when recording every trace event doesn't seem to have any noticeable effect. Signed-off-by: Hollis Blanchard <hollis_blanchard@mentor.com> --- trace/simple.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/trace/simple.c b/trace/simple.c index 3fdcc82..67ccc3c 100644 --- a/trace/simple.c +++ b/trace/simple.c @@ -209,6 +209,8 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi uint64_t event_u64 = event; uint64_t timestamp_ns = get_clock(); + st_set_trace_file_enabled(true); + do { old_idx = g_atomic_int_get(&trace_idx); smp_rmb(); @@ -320,6 +322,7 @@ void st_set_trace_file_enabled(bool enable) */ void st_set_trace_file(const char *file) { + /* Tracing will be re-enabled when the next event is written. */ st_set_trace_file_enabled(false); g_free(trace_file_name); @@ -330,8 +333,6 @@ void st_set_trace_file(const char *file) } else { trace_file_name = g_strdup_printf("%s", file); } - - st_set_trace_file_enabled(true); } void st_print_trace_file_status(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) -- 1.9.1 ^ permalink raw reply related [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted. 2016-02-08 18:51 ` [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted Hollis Blanchard @ 2016-02-08 20:02 ` Alex Bennée 2016-02-15 15:52 ` Stefan Hajnoczi 2016-02-15 15:54 ` Stefan Hajnoczi 2 siblings, 0 replies; 11+ messages in thread From: Alex Bennée @ 2016-02-08 20:02 UTC (permalink / raw) To: Hollis Blanchard; +Cc: stefanha, qemu-devel Hollis Blanchard <hollis_blanchard@mentor.com> writes: > Previously, trace record files (created by st_set_trace_file_enabled(true)) > were created by the simple backend at initialization time, even if no events > were actually enabled. > > As a consequence, the working directory would become littered with trace-PID > files just by enabling the simple backend at configure time, even when no > -trace options were used. > > --- > I've been using this to avoid creation of empty trace record files. I haven't > done any scientific performance studies, but an extra function > call/conditional/return when recording every trace event doesn't seem to have > any noticeable effect. > > Signed-off-by: Hollis Blanchard <hollis_blanchard@mentor.com> > --- > trace/simple.c | 5 +++-- > 1 file changed, 3 insertions(+), 2 deletions(-) > > diff --git a/trace/simple.c b/trace/simple.c > index 3fdcc82..67ccc3c 100644 > --- a/trace/simple.c > +++ b/trace/simple.c > @@ -209,6 +209,8 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi > uint64_t event_u64 = event; > uint64_t timestamp_ns = get_clock(); > > + st_set_trace_file_enabled(true); > + > do { > old_idx = g_atomic_int_get(&trace_idx); > smp_rmb(); > @@ -320,6 +322,7 @@ void st_set_trace_file_enabled(bool enable) > */ > void st_set_trace_file(const char *file) > { > + /* Tracing will be re-enabled when the next event is written. */ > st_set_trace_file_enabled(false); > > g_free(trace_file_name); > @@ -330,8 +333,6 @@ void st_set_trace_file(const char *file) > } else { > trace_file_name = g_strdup_printf("%s", file); > } > - > - st_set_trace_file_enabled(true); > } This fixes the "make check" bug I reported: http://lists.nongnu.org/archive/html/qemu-devel/2016-02/msg01811.html because by not enabling the file it doesn't attempt to flush it before the test has started. However as it is a side-effect of the patch there may be a better solution. However have a: Tested-by: Alex Bennée <alex.bennee@linaro.org> -- Alex Bennée ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted. 2016-02-08 18:51 ` [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted Hollis Blanchard 2016-02-08 20:02 ` Alex Bennée @ 2016-02-15 15:52 ` Stefan Hajnoczi 2016-02-15 15:54 ` Stefan Hajnoczi 2 siblings, 0 replies; 11+ messages in thread From: Stefan Hajnoczi @ 2016-02-15 15:52 UTC (permalink / raw) To: Hollis Blanchard; +Cc: qemu-devel [-- Attachment #1: Type: text/plain, Size: 1858 bytes --] On Mon, Feb 08, 2016 at 10:51:55AM -0800, Hollis Blanchard wrote: > Previously, trace record files (created by st_set_trace_file_enabled(true)) > were created by the simple backend at initialization time, even if no events > were actually enabled. > > As a consequence, the working directory would become littered with trace-PID > files just by enabling the simple backend at configure time, even when no > -trace options were used. > > --- > I've been using this to avoid creation of empty trace record files. I haven't > done any scientific performance studies, but an extra function > call/conditional/return when recording every trace event doesn't seem to have > any noticeable effect. > > Signed-off-by: Hollis Blanchard <hollis_blanchard@mentor.com> > --- > trace/simple.c | 5 +++-- > 1 file changed, 3 insertions(+), 2 deletions(-) > > diff --git a/trace/simple.c b/trace/simple.c > index 3fdcc82..67ccc3c 100644 > --- a/trace/simple.c > +++ b/trace/simple.c > @@ -209,6 +209,8 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi > uint64_t event_u64 = event; > uint64_t timestamp_ns = get_clock(); > > + st_set_trace_file_enabled(true); trace_record_start() can be called from multiple threads. st_set_trace_file_enabled() is not thread-safe. One way to solve this is to use a read memory barrier to fetch trace_fp. If it's NULL then acquire trace_lock and recheck (in case another thread has modified it since). Now continue with the rest of st_set_trace_file_enabled() to open the file. If multiple threads pile up they will just wait for trace_lock until the first thread has completed opening the file. Or you could use try_lock instead and return -EBUSY to drop those events similar to the -ENOSPC error case in trace_record_start(). Stefan [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted. 2016-02-08 18:51 ` [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted Hollis Blanchard 2016-02-08 20:02 ` Alex Bennée 2016-02-15 15:52 ` Stefan Hajnoczi @ 2016-02-15 15:54 ` Stefan Hajnoczi 2 siblings, 0 replies; 11+ messages in thread From: Stefan Hajnoczi @ 2016-02-15 15:54 UTC (permalink / raw) To: Hollis Blanchard; +Cc: qemu-devel [-- Attachment #1: Type: text/plain, Size: 1038 bytes --] On Mon, Feb 08, 2016 at 10:51:55AM -0800, Hollis Blanchard wrote: > Previously, trace record files (created by st_set_trace_file_enabled(true)) > were created by the simple backend at initialization time, even if no events > were actually enabled. > > As a consequence, the working directory would become littered with trace-PID > files just by enabling the simple backend at configure time, even when no > -trace options were used. > > --- > I've been using this to avoid creation of empty trace record files. I haven't > done any scientific performance studies, but an extra function > call/conditional/return when recording every trace event doesn't seem to have > any noticeable effect. > > Signed-off-by: Hollis Blanchard <hollis_blanchard@mentor.com> > --- > trace/simple.c | 5 +++-- > 1 file changed, 3 insertions(+), 2 deletions(-) By the way, thanks for the patch. I didn't see it because my maintainership scripts use my stefanha@redhat.com email account that is listed in ./MAINTAINERS. Stefan [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] trace: timestamps, core IDs, and file creation 2016-02-08 15:30 ` Stefan Hajnoczi 2016-02-08 16:29 ` Lluís Vilanova 2016-02-08 18:51 ` [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted Hollis Blanchard @ 2016-02-08 19:59 ` Hollis Blanchard 2016-02-15 15:29 ` Stefan Hajnoczi 2 siblings, 1 reply; 11+ messages in thread From: Hollis Blanchard @ 2016-02-08 19:59 UTC (permalink / raw) To: Stefan Hajnoczi; +Cc: QEMU Developers, vilanova [-- Attachment #1: Type: text/plain, Size: 4537 bytes --] On 02/08/2016 07:30 AM, Stefan Hajnoczi wrote: > On Wed, Jan 13, 2016 at 03:13:02PM -0800, Hollis Blanchard wrote: >> 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? "Breaks"? Is that because every trace record is assumed to have a unique timestamp? Who makes that assumption? Qemu's tracing infrastructure works fine without it... Hmm, an option. I guess if you want to debug Qemu behavior, like "why are block operations taking so long", seeing host time is the most important thing. However, if you want debug visibility into guest behavior, like "how long did I run with IRQs disabled", guest time is the most important thing. I'm not sure when a developer should be forced to make that decision...? >> 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. Neat. > 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. Yeah, by "MMIO" I was thinking in particular of memory.c instrumentation, which almost always executes in the context of a vcpu. I'm not sure a vcpu property could work there. cpu_physical_memory_rw() may be executed by a machine init function, before any VCPUs are running. To handle that, I have a hack like this in memory_region_read_accessor(): int cpu_index = -1; if (current_cpu) cpu_index = current_cpu->cpu_index; trace_memory_region_ops_read(cpu_index, mr, addr, tmp, size); ... and then my analysis tools, which display guest activity, know to ignore events with cpu_index==-1. I'm not sure if a vcpu property could or should do the same...? > It might be easiest to include the vcpu id in the trace event explicitly > for now. Mmm hmm. That could cause a lot of churn to the current set of trace events, but they seem to be mostly IO operations that execute outside VCPU context. >> 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? "qemu.trace" or something static. If the log is important, the user will copy it anyways to give it a descriptive name, e.g. "out_of_memory.trace". If the log is not important, it should be overwritten by the next run; otherwise the workflow becomes: qemu-system-... args args args ls trace-* rm trace-NNNN qemu-system-... args args args ls trace-* rm trace-MMMM Hollis Blanchard Mentor Graphics Emulation Division [-- Attachment #2: Type: text/html, Size: 5980 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] trace: timestamps, core IDs, and file creation 2016-02-08 19:59 ` [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard @ 2016-02-15 15:29 ` Stefan Hajnoczi 0 siblings, 0 replies; 11+ messages in thread From: Stefan Hajnoczi @ 2016-02-15 15:29 UTC (permalink / raw) To: Hollis Blanchard; +Cc: QEMU Developers, vilanova [-- Attachment #1: Type: text/plain, Size: 5406 bytes --] On Mon, Feb 08, 2016 at 11:59:00AM -0800, Hollis Blanchard wrote: > On 02/08/2016 07:30 AM, Stefan Hajnoczi wrote: > >On Wed, Jan 13, 2016 at 03:13:02PM -0800, Hollis Blanchard wrote: > >>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? > > "Breaks"? Is that because every trace record is assumed to have a unique > timestamp? Who makes that assumption? Qemu's tracing infrastructure works > fine without it... It breaks existing users in the sense that the timestamp will not be valid while vCPUs are paused. Today you can trace any part of QEMU and the timestamps will be valid even while vCPUs are paused (e.g. migration after vm_stop()). Having valid timestamps is important for performance analysis so the time between two trace events can be calculated. > Hmm, an option. I guess if you want to debug Qemu behavior, like "why are > block operations taking so long", seeing host time is the most important > thing. However, if you want debug visibility into guest behavior, like "how > long did I run with IRQs disabled", guest time is the most important thing. > I'm not sure when a developer should be forced to make that decision...? When invoking QEMU (qemu -trace clocksource=vcpu). It's not ideal, but should be good enough for using the simple trace backend during development. In this case the developer knows what information they want from tracing so they can decide whether to use cpu time or wall clock time at startup. > >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. > > Yeah, by "MMIO" I was thinking in particular of memory.c instrumentation, > which almost always executes in the context of a vcpu. > > I'm not sure a vcpu property could work there. cpu_physical_memory_rw() may > be executed by a machine init function, before any VCPUs are running. To > handle that, I have a hack like this in memory_region_read_accessor(): > > int cpu_index = -1; > if (current_cpu) > cpu_index = current_cpu->cpu_index; > trace_memory_region_ops_read(cpu_index, mr, addr, tmp, size); > > ... and then my analysis tools, which display guest activity, know to ignore > events with cpu_index==-1. > > I'm not sure if a vcpu property could or should do the same...? Your cpu_index = -1 trick seems fine to me. I'd merge it. Another corner case: KVM's coalesced MMIO ring. MMIO does not necessarily happen in the vcpu context that caused it. Most of the time it will but I think SMP guests could violate this. Guest MMIO writes to coalesced MMIO physical memory regions are accumulated in the ring buffer instead of being dispatched by memory.c right away. QEMU flushes the ring eventually and executes the buffered writes. See kvm-all.c:kvm_flush_coalesced_mmio_buffer(). > >It might be easiest to include the vcpu id in the trace event explicitly > >for now. > > Mmm hmm. That could cause a lot of churn to the current set of trace events, > but they seem to be mostly IO operations that execute outside VCPU context. > > >>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? > > "qemu.trace" or something static. If the log is important, the user will > copy it anyways to give it a descriptive name, e.g. "out_of_memory.trace". > If the log is not important, it should be overwritten by the next run; > otherwise the workflow becomes: > > qemu-system-... args args args > ls trace-* > rm trace-NNNN > qemu-system-... args args args > ls trace-* > rm trace-MMMM Then use -trace file=qemu.trace :). Stefan [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 473 bytes --] ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] trace: timestamps, core IDs, and file creation 2016-01-13 23:13 [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard 2016-02-08 15:30 ` Stefan Hajnoczi @ 2016-02-08 18:01 ` Alex Bennée 2016-02-08 18:34 ` Alex Bennée 1 sibling, 1 reply; 11+ messages in thread From: Alex Bennée @ 2016-02-08 18:01 UTC (permalink / raw) To: Hollis Blanchard; +Cc: Stefan Hajnoczi, QEMU Developers Hollis Blanchard <hollis_blanchard@mentor.com> writes: > 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: > <snip> > 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? Yeah I've run into trouble when running "make check" with the simple backend enabled. I'm not sure exactly what mechanism breaks the test but it seems to me an invocation like: ./x86_64-softmmu/qemu-system-x86_64 -qtest unix:/tmp/qtest-9458.sock,nowait -qtest-log /dev/null -qmp unix:/tmp/qtest-9458.qmp,nowait -machine accel=qtest -display none -M pc -device pc-testdev Shouldn't be generating anything unless an explicit file is set. AFAICT 41fc57e44ed64cd4ab5393d83624afd897dabd4f is triggering the default file behaviour. I'm still digging into this. -- Alex Bennée ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [Qemu-devel] trace: timestamps, core IDs, and file creation 2016-02-08 18:01 ` Alex Bennée @ 2016-02-08 18:34 ` Alex Bennée 0 siblings, 0 replies; 11+ messages in thread From: Alex Bennée @ 2016-02-08 18:34 UTC (permalink / raw) To: Hollis Blanchard; +Cc: Stefan Hajnoczi, QEMU Developers Alex Bennée <alex.bennee@linaro.org> writes: > Hollis Blanchard <hollis_blanchard@mentor.com> writes: > >> 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: >> > <snip> >> 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? > > Yeah I've run into trouble when running "make check" with the simple > backend enabled. I'm not sure exactly what mechanism breaks the test but > it seems to me an invocation like: > > ./x86_64-softmmu/qemu-system-x86_64 -qtest > unix:/tmp/qtest-9458.sock,nowait -qtest-log /dev/null -qmp > unix:/tmp/qtest-9458.qmp,nowait -machine accel=qtest -display none -M > pc -device pc-testdev > > Shouldn't be generating anything unless an explicit file is set. > > AFAICT 41fc57e44ed64cd4ab5393d83624afd897dabd4f is triggering the > default file behaviour. > > I'm still digging into this. OK ignore me, that commit breaks "make check" but not while spamming the trace-files. That must be later in my tree. -- Alex Bennée ^ permalink raw reply [flat|nested] 11+ messages in thread
end of thread, other threads:[~2016-02-15 15:54 UTC | newest] Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2016-01-13 23:13 [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard 2016-02-08 15:30 ` Stefan Hajnoczi 2016-02-08 16:29 ` Lluís Vilanova 2016-02-08 18:51 ` [Qemu-devel] [PATCH] trace: only create simple backend trace files when an event is emitted Hollis Blanchard 2016-02-08 20:02 ` Alex Bennée 2016-02-15 15:52 ` Stefan Hajnoczi 2016-02-15 15:54 ` Stefan Hajnoczi 2016-02-08 19:59 ` [Qemu-devel] trace: timestamps, core IDs, and file creation Hollis Blanchard 2016-02-15 15:29 ` Stefan Hajnoczi 2016-02-08 18:01 ` Alex Bennée 2016-02-08 18:34 ` Alex Bennée
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).