Re: [Qemu-devel] [PATCH 2/3] Tracepoint, buffer & monitor framework
On Tue, May 25, 2010 at 7:20 PM, Prerna Saxena wrote: >> Some added lines of code use tabs for indentation, 4 space indentation >> should >> be used. >> >> +struct tracepoint { >> + char *name; /* Tracepoint name */ >> + uint8_t trace_id; /* numerical ID */ >> >> Maximum 256 tracepoints in QEMU? A limit of 65536 is less likely to >> be an issue in the future. >> > > No, this field describes the maximum tracepoints for a given hash queue. I see now, thanks. > I'll work on merging this circular buffer + monitor-based reader as a > backend for your proposed tracer. Would it be a good idea to have two trace > buffers -- when one is full, it gets written to disk ; while the second is > used to log traces. In a double-buffering approach there are finite resources. There needs to be a case for when the write-out buffer hasn't been written yet and the active trace buffer becomes full. I think in that case the active buffer should start overwriting the oldest entry. > I think the monitor interface for reading traces can be retained as is. > Also, I'd implemented the monitor interface for enabling/disabling data > logging for a given tracepoint (for a running guest) Not sure if this is > supported in the set of patches you've posted ? It might be a good to have > feature. The "disable" trace event feature in my tracing backends patchset allows statically disabling a trace event. It doesn't support enabling/disabling trace events at runtime, which is left up to the backend. The motivation for the "disable" attribute in the trace-events file is to allow completely disabling a trace event without having to remove it from trace-events *and* removing trace_*() calls in QEMU source code. It's a handy way of completely knocking out a trace event. Thanks for your patches, Stefan
Re: [Qemu-devel] [PATCH 2/3] Tracepoint, buffer & monitor framework
Hi Stefan, Thanks for having a look. As I'd mentioned, this patchset is *work in progress*, which explains the dummy comments and coding style violations at places :) I was merely sharing a draft of what my approach is -- so that we can work together on how much of it can add to the trace framework you've proposed. On 05/25/2010 05:10 PM, Stefan Hajnoczi wrote: I think this is too much work. Let each tracepoint have its own global struct tracepoint so it can directly reference it using tracepoint_##name - no hash lookup needed. Add the QLIST_ENTRY directly to struct tracepoint so the tracepoint register/unregister code can assign ids and look up tracepoints by name. No critical path code needs to do name lookups and the hash table can disappear. I had employed a combination of hash (derived from name) and an ID (which is the offset within a hash bucket where the tracepoint details are stored) to determine tracepoint information for a given name. Your suggestion to eliminate name queries is good, let me see how much of this can be scaled down. +#define DECLARE_TRACE(name, tproto, tstruct) \ + struct __trace_struct_##name { \ + tstruct \ + }; \ Should this struct be packed so more fields can fit? Yes, indeed. Thanks for reminding ! +trace_queue->trace_buffer[tmp].metadata.write_complete = 0; This is not guaranteed to work without memory barriers. There is no way for the trace consumer to block until there is more data available. The synchronization needs to consider writing traces to a file, which has different constraints than dumping the current contents of the trace buffer. We're missing a way to trace to a file. That could be done in binary or text. It would be easier in text because we already have the format strings and don't need a unique ID mapping in an external binary parsing tool. OK, at the time of working on this I hadnt really thought of dumping traces in a file. It meant too much of IO latency that such tracing would bring in. My idea of a tracer entailed buffer based logging with a simple reader(see last) Making data available after crash is also useful. The easiest way is to dump the trace buffer from the core dump using gdb. However, we'd need some way of making sense of the bytes. That could be done by reading the tracepoint_lib structures from the core dump. Agree. (The way I do trace recovery from a core dump in my simple tracer is to binary dump the trace buffer from the core dump. Since the trace buffer contents are normally written out to file unchanged anyway, the simpletrace.py script can read the dumped trace buffer like a normal trace file.) Nitpicks: As I mentioned, this is work in progress so you'd have seen quite a lot of violations. Thanks for pointing those out, I'll clean those up for whatever approach we choose to use :) Some added lines of code use tabs for indentation, 4 space indentation should be used. +struct tracepoint { + char *name; /* Tracepoint name */ + uint8_t trace_id; /* numerical ID */ Maximum 256 tracepoints in QEMU? A limit of 65536 is less likely to be an issue in the future. No, this field describes the maximum tracepoints for a given hash queue. + void __trace_print_##name(Monitor *mon, void *data) \ + { \ + struct __trace_struct_##name *entry; \ + \ + if(!entry)\ + return; \ This does not work, entry is not initialized. Typo ! should've been : if(!data) +#define DO_TRACE(name, args...)\ + trace_##name(args); This macro is unused? A relic that needs to be cleaned :) +/* In essence, the structure becomes : + * struct tracepoint_lib { This comment will get out of sync easily. + qemu_malloc(sizeof(struct tracepoint_lib)); + +if (!new_entry) + return NULL;/* No memory */ qemu_malloc() does not return NULL on out-of-memory, it aborts the program. Same for allocating new_entry->entry.name. Wondering how I forgot that ! thanks for reminding. +new_entry->entry.name = (char*)qemu_malloc(strlen(name)+1); +if(!new_entry->entry.name) + return NULL; + +strncpy(new_entry->entry.name, name, strlen(name)+1); Perhaps just strdup() instead of manual qemu_malloc()/strncpy(). Stefan I'll work on merging this circular buffer + monitor-based reader as a backend for your proposed tracer. Would it be a good idea to have two trace buffers -- when one is full, it gets written to disk ; while the second is used to log traces. I think
Re: [Qemu-devel] [PATCH 2/3] Tracepoint, buffer & monitor framework
+#define DEFINE_TRACE(name, tproto, tassign, tprint)\ + void trace_##name(tproto) \ + { \ + unsigned int hash;\ + char tpname[] = __stringify(name);\ + struct tracepoint *tp;\ + struct __trace_struct_##name var, *entry; \ + \ + hash = tdb_hash(tpname); \ + tp = find_tracepoint_by_name(tpname); \ + if (tp == NULL || !tp->state) \ + return; \ + \ + entry = &var; \ + tassign \ + \ + write_trace_to_buffer(&qemu_buf, hash, tp->trace_id, \ + entry, sizeof(struct __trace_struct_##name)); \ + } \ I think this is too much work. Let each tracepoint have its own global struct tracepoint so it can directly reference it using tracepoint_##name - no hash lookup needed. Add the QLIST_ENTRY directly to struct tracepoint so the tracepoint register/unregister code can assign ids and look up tracepoints by name. No critical path code needs to do name lookups and the hash table can disappear. +#define DECLARE_TRACE(name, tproto, tstruct) \ + struct __trace_struct_##name { \ + tstruct \ + }; \ Should this struct be packed so more fields can fit? +trace_queue->trace_buffer[tmp].metadata.write_complete = 0; This is not guaranteed to work without memory barriers. There is no way for the trace consumer to block until there is more data available. The synchronization needs to consider writing traces to a file, which has different constraints than dumping the current contents of the trace buffer. We're missing a way to trace to a file. That could be done in binary or text. It would be easier in text because we already have the format strings and don't need a unique ID mapping in an external binary parsing tool. Making data available after crash is also useful. The easiest way is to dump the trace buffer from the core dump using gdb. However, we'd need some way of making sense of the bytes. That could be done by reading the tracepoint_lib structures from the core dump. (The way I do trace recovery from a core dump in my simple tracer is to binary dump the trace buffer from the core dump. Since the trace buffer contents are normally written out to file unchanged anyway, the simpletrace.py script can read the dumped trace buffer like a normal trace file.) Nitpicks: Some added lines of code use tabs for indentation, 4 space indentation should be used. +{ +.name = "tracepoint", +.args_type = "", +.params = "", +.help = "show contents of trace buffer", Copy-pasted, .help not updated. @@ -145,6 +147,10 @@ struct Monitor { #ifdef CONFIG_DEBUG_MONITOR int print_calls_nr; #endif +#ifdef CONFIG_QEMU_TRACE +struct DebugBuffer *qemu_buf_ptr; +#endif + QError *error; QLIST_HEAD(,mon_fd_t) fds; QLIST_ENTRY(Monitor) entry; Would TraceBuffer be a more appropriate name for DebugBuffer? qemu_buf_ptr is vague, perhaps trace_buf is more clear? I'm not sure I understand the reason for qemu_buf_ptr. There is already a global qemu_buf and qemu_buf_ptr is a pointer to that? +if(!strncmp(tp_state, "on", 3)) [...] + if(!strncmp(tp_state, "off", 4)) "on" with 3 and "off" with 4 are equivalent to strcmp(). "on" with 2 and "off" with 3 would allow for any suffix after the matched string. +#else /* CONFIG_QEMU_TRACE */ +static void do_tracepoint_status(Monitor *mon, const QDict *qdict) +{ +monitor_printf(mon, "Internal tracing not compiled\n"); +} +#endif "tracepoint" has this !CONFIG_QEMU_TRACE function but "trace" doesn't. +#define INCREMENT_INDEX(HEAD,IDX) (HEAD->IDX++) % HEAD->buf_size [...] +if ((trace_queue->last + 1) % trace_queue->buf_size +== trace_queue->first) + trace_queue->first = INCREMENT_INDEX(trace_queue, first); +trace_queue->last = INCREMENT_INDEX(trace_queue, last); Slightly safer macro: #define NEXT_INDEX(HEAD,IDX) (((HEAD)->IDX + 1) % (HEAD)->buf_size) [...] if (NEXT_INDEX(trace_queue, last) == trace_queue->first) trace_queue->first = NEXT_INDEX(trace_queue, first); trace_queue->last = NEXT_INDEX(trace_queue, last); +tmp = trace_queue->last; Instead of using tmp: D
[Qemu-devel] [PATCH 2/3] Tracepoint, buffer & monitor framework
Patch that implements tracepoint framework + trace buffer + monitor support. tracing can be enabled at compile time using --enable-trace switch, which compiles tracing support(all of these). Monitor commands introduced : 1. info trace : to see contents of trace buffer. 2. info tracepoints : to see available tracepoints and their status. 3. trace [on|off] : to enable / disable trace data collection. 4. tracepoint ABC [on|off] : to enable / disable traces from a specific tracepoint, eg ABC -- Prerna Saxena Linux Technology Centre, IBM Systems and Technology Lab, Bangalore, India Signed-off by : Prerna (pre...@linux.vnet.ibm.com) Index: qemu/monitor.c === --- qemu.orig/monitor.c +++ qemu/monitor.c @@ -55,7 +55,9 @@ #include "json-streamer.h" #include "json-parser.h" #include "osdep.h" - +#ifdef CONFIG_QEMU_TRACE +#include "tracepoint.h" +#endif //#define DEBUG //#define DEBUG_COMPLETION @@ -145,6 +147,10 @@ struct Monitor { #ifdef CONFIG_DEBUG_MONITOR int print_calls_nr; #endif +#ifdef CONFIG_QEMU_TRACE +struct DebugBuffer *qemu_buf_ptr; +#endif + QError *error; QLIST_HEAD(,mon_fd_t) fds; QLIST_ENTRY(Monitor) entry; @@ -1198,6 +1204,63 @@ static void do_log(Monitor *mon, const Q cpu_set_log(mask); } +#ifdef CONFIG_QEMU_TRACE +static void do_trace(Monitor *mon, const QDict *qdict) +{ +const char *option = qdict_get_try_str(qdict, "option"); +if (!option || !strncmp(option, "on", 3)) { + mon->qemu_buf_ptr = &qemu_buf; +initialize_buffer(mon->qemu_buf_ptr); +} else if (!strncmp(option, "off", 4)) { + mon->qemu_buf_ptr->enabled = 0; +} else { +monitor_printf(mon, "Invalid option %s\n", option); +} +} + +static void do_tracepoint_status(Monitor *mon, const QDict *qdict) +{ +uint8_t status_num; +struct tracepoint *t; +const char *tp_name = qdict_get_str(qdict, "name"); +const char *tp_state = qdict_get_str(qdict, "option"); + +if(!mon->qemu_buf_ptr || !mon->qemu_buf_ptr->enabled) { +monitor_printf(mon, "Tracing disabled. Use \"trace on\" before this\n"); + return; +} +if(!strncmp(tp_state, "on", 3)) + status_num = 1; +else { + if(!strncmp(tp_state, "off", 4)) + status_num = 0; + else { + monitor_printf(mon, "Invalid option : %s. Use [on|off]\n", +tp_state); + return; + } + } +t = find_tracepoint_by_name(tp_name); +if(t == NULL) { +monitor_printf(mon, "Tracepoint %s does not exist\n", tp_name); + return; + } +if(t->state == status_num) { +monitor_printf(mon, "State of Tracepoint %s is already %s\n", + tp_name, tp_state); + return; + } +/* Do I need a spin_lock here ? */ +t->state = status_num; +return; +} +#else /* CONFIG_QEMU_TRACE */ +static void do_tracepoint_status(Monitor *mon, const QDict *qdict) +{ +monitor_printf(mon, "Internal tracing not compiled\n"); +} +#endif + static void do_singlestep(Monitor *mon, const QDict *qdict) { const char *option = qdict_get_try_str(qdict, "option"); @@ -2170,6 +2233,42 @@ static void do_info_profile(Monitor *mon } #endif +#ifdef CONFIG_QEMU_TRACE + +static void qemu_dump_trace(Monitor *mon, struct DebugEntry *data) +{ +int i; + +char *iter = (char *)data; +for (i=0; iqemu_buf_ptr || !mon->qemu_buf_ptr->enabled) + return; + +while(1) { + if(!read_trace_from_buffer(mon->qemu_buf_ptr, &data)) + break ; + /* qemu_dump_trace() is a simple hex dump */ +// qemu_dump_trace(mon, &data); + print_trace(&data, mon); +}; +return; +} +#else /* CONFIG_QEMU_TRACE */ +static void do_info_trace(Monitor *mon) +{ +monitor_printf(mon, "Internal tracing not compiled\n"); +} +#endif + /* Capture support */ static QLIST_HEAD (capture_list_head, CaptureState) capture_head; @@ -2779,6 +2878,20 @@ static const mon_cmd_t info_cmds[] = { .mhandler.info = do_info_roms, }, { +.name = "trace", +.args_type = "", +.params = "", +.help = "show contents of trace buffer", +.mhandler.info = do_info_trace, +}, +{ +.name = "tracepoint", +.args_type = "", +.params = "", +.help = "show contents of trace buffer", +.mhandler.info = do_info_tracepoint, +}, +{ .name = NULL, }, }; @@ -4633,6 +4746,9 @@ void monitor_init(CharDriverState *chr, QLIST_INSERT_HEAD(&mon_list, mon, entry); if (!default_mon || (flags & MONITOR_IS_DEFAULT)) default_mon = mon; + +/* Disable trace buffer unless enabled */ +mon->qemu_buf_ptr = NULL; } static void bdrv_password_cb(Monitor *mon, const char *password, void *opaque) Index: qemu/trace-buffer.c === --- /dev/null +++ qemu/trace-buffer.c @@ -0,0 +1,111 @@ +/* + * Trace buffer implementation for QEMU. + * + * Cop