From fb3a508531227bc7fb7eee22c51d30bf2ceb15f5 Mon Sep 17 00:00:00 2001 From: Markus Armbruster Date: Fri, 25 Jan 2013 16:43:37 +0100 Subject: [PATCH 1/4] trace: Fix simple trace dropped event record for big endian We use atomic operations to keep track of dropped events. Inconveniently, GLib supports only int and void * atomics, but the counter dropped_events is uint64_t. Can't stop commit 62bab732: a quick (gint *)&dropped_events bludgeons the compiler into submission. That cast is okay only when int is exactly 64 bits wide, which it commonly isn't. If int is even wider, we clobber whatever follows dropped_events. Not worth worrying about, as none of the machines that interest us have such morbidly obese ints. That leaves the common case: int narrower than 64 bits. Harmless on little endian hosts: we just don't access the most significant bits of dropped_events. They remain zero. On big endian hosts, we use only the most significant bits of dropped_events as counter. The least significant bits remain zero. However, we write out the full value, which is the correct counter shifted left a bunch of places. Fix by changing the variables involved to int. There's another, equally suspicious-looking (gint *)&trace_idx argument to g_atomic_int_compare_and_exchange(), but that one casts unsigned *, so it's okay. But it's also superfluous, because GLib's atomic int operations work just fine for unsigned. Drop it. Signed-off-by: Markus Armbruster Reviewed-by: Laszlo Ersek Signed-off-by: Stefan Hajnoczi --- trace/simple.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/trace/simple.c b/trace/simple.c index ce17d64bd7..ccbdb6a930 100644 --- a/trace/simple.c +++ b/trace/simple.c @@ -53,7 +53,7 @@ enum { uint8_t trace_buf[TRACE_BUF_LEN]; static unsigned int trace_idx; static unsigned int writeout_idx; -static uint64_t dropped_events; +static int dropped_events; static FILE *trace_fp; static char *trace_file_name; @@ -63,7 +63,7 @@ typedef struct { uint64_t timestamp_ns; uint32_t length; /* in bytes */ uint32_t reserved; /* unused */ - uint8_t arguments[]; + uint64_t arguments[]; } TraceRecord; typedef struct { @@ -160,7 +160,7 @@ static gpointer writeout_thread(gpointer opaque) uint8_t bytes[sizeof(TraceRecord) + sizeof(uint64_t)]; } dropped; unsigned int idx = 0; - uint64_t dropped_count; + int dropped_count; size_t unused __attribute__ ((unused)); for (;;) { @@ -169,16 +169,16 @@ static gpointer writeout_thread(gpointer opaque) if (dropped_events) { dropped.rec.event = DROPPED_EVENT_ID, dropped.rec.timestamp_ns = get_clock(); - dropped.rec.length = sizeof(TraceRecord) + sizeof(dropped_events), + dropped.rec.length = sizeof(TraceRecord) + sizeof(uint64_t), dropped.rec.reserved = 0; while (1) { dropped_count = dropped_events; - if (g_atomic_int_compare_and_exchange((gint *)&dropped_events, + if (g_atomic_int_compare_and_exchange(&dropped_events, dropped_count, 0)) { break; } } - memcpy(dropped.rec.arguments, &dropped_count, sizeof(uint64_t)); + dropped.rec.arguments[0] = dropped_count; unused = fwrite(&dropped.rec, dropped.rec.length, 1, trace_fp); } @@ -220,11 +220,11 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi if (new_idx - writeout_idx > TRACE_BUF_LEN) { /* Trace Buffer Full, Event dropped ! */ - g_atomic_int_inc((gint *)&dropped_events); + g_atomic_int_inc(&dropped_events); return -ENOSPC; } - if (g_atomic_int_compare_and_exchange((gint *)&trace_idx, + if (g_atomic_int_compare_and_exchange(&trace_idx, old_idx, new_idx)) { break; } From e722d705ae7648a6bd94848319a11eb0afd58a17 Mon Sep 17 00:00:00 2001 From: Markus Armbruster Date: Fri, 25 Jan 2013 16:43:38 +0100 Subject: [PATCH 2/4] trace: Direct access of atomics is verboten, use the API The GLib Reference Manual says: It is very important that all accesses to a particular integer or pointer be performed using only this API and that different sizes of operation are not mixed or used on overlapping memory regions. Never read or assign directly from or to a value -- always use this API. Signed-off-by: Markus Armbruster Reviewed-by: Laszlo Ersek Reviewed-by: Harsh Prateek Bora Signed-off-by: Stefan Hajnoczi --- trace/simple.c | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/trace/simple.c b/trace/simple.c index ccbdb6a930..592ff483cc 100644 --- a/trace/simple.c +++ b/trace/simple.c @@ -166,13 +166,13 @@ static gpointer writeout_thread(gpointer opaque) for (;;) { wait_for_trace_records_available(); - if (dropped_events) { + if (g_atomic_int_get(&dropped_events)) { dropped.rec.event = DROPPED_EVENT_ID, dropped.rec.timestamp_ns = get_clock(); dropped.rec.length = sizeof(TraceRecord) + sizeof(uint64_t), dropped.rec.reserved = 0; while (1) { - dropped_count = dropped_events; + dropped_count = g_atomic_int_get(&dropped_events); if (g_atomic_int_compare_and_exchange(&dropped_events, dropped_count, 0)) { break; @@ -214,7 +214,7 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi uint64_t timestamp_ns = get_clock(); while (1) { - old_idx = trace_idx; + old_idx = g_atomic_int_get(&trace_idx); smp_rmb(); new_idx = old_idx + rec_len; @@ -275,7 +275,8 @@ void trace_record_finish(TraceBufferRecord *rec) record.event |= TRACE_RECORD_VALID; write_to_buffer(rec->tbuf_idx, &record, sizeof(TraceRecord)); - if ((trace_idx - writeout_idx) > TRACE_BUF_FLUSH_THRESHOLD) { + if ((g_atomic_int_get(&trace_idx) - writeout_idx) + > TRACE_BUF_FLUSH_THRESHOLD) { flush_trace_file(false); } } From b6b2c9628084f1672b92393cf84039a075a95301 Mon Sep 17 00:00:00 2001 From: Markus Armbruster Date: Fri, 25 Jan 2013 16:43:39 +0100 Subject: [PATCH 3/4] trace: Clean up the "try to update atomic until it worked" loops Signed-off-by: Markus Armbruster Reviewed-by: Laszlo Ersek Reviewed-by: Harsh Prateek Bora Signed-off-by: Stefan Hajnoczi --- trace/simple.c | 18 +++++------------- 1 file changed, 5 insertions(+), 13 deletions(-) diff --git a/trace/simple.c b/trace/simple.c index 592ff483cc..74701e3272 100644 --- a/trace/simple.c +++ b/trace/simple.c @@ -171,13 +171,10 @@ static gpointer writeout_thread(gpointer opaque) dropped.rec.timestamp_ns = get_clock(); dropped.rec.length = sizeof(TraceRecord) + sizeof(uint64_t), dropped.rec.reserved = 0; - while (1) { + do { dropped_count = g_atomic_int_get(&dropped_events); - if (g_atomic_int_compare_and_exchange(&dropped_events, - dropped_count, 0)) { - break; - } - } + } while (!g_atomic_int_compare_and_exchange(&dropped_events, + dropped_count, 0)); dropped.rec.arguments[0] = dropped_count; unused = fwrite(&dropped.rec, dropped.rec.length, 1, trace_fp); } @@ -213,7 +210,7 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi uint32_t rec_len = sizeof(TraceRecord) + datasize; uint64_t timestamp_ns = get_clock(); - while (1) { + do { old_idx = g_atomic_int_get(&trace_idx); smp_rmb(); new_idx = old_idx + rec_len; @@ -223,12 +220,7 @@ int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t datasi g_atomic_int_inc(&dropped_events); return -ENOSPC; } - - if (g_atomic_int_compare_and_exchange(&trace_idx, - old_idx, new_idx)) { - break; - } - } + } while (!g_atomic_int_compare_and_exchange(&trace_idx, old_idx, new_idx)); idx = old_idx % TRACE_BUF_LEN; From 8f44015e4600041e200506720e39de7728c5cde9 Mon Sep 17 00:00:00 2001 From: Markus Armbruster Date: Fri, 25 Jan 2013 16:43:40 +0100 Subject: [PATCH 4/4] trace: Fix location of simpletrace.py in docs Missed when commit 4c3b5a48 moved it. Signed-off-by: Markus Armbruster Reviewed-by: Laszlo Ersek Reviewed-by: Harsh Prateek Bora Signed-off-by: Stefan Hajnoczi --- docs/tracing.txt | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/docs/tracing.txt b/docs/tracing.txt index 453cc4a63d..14db3bffb4 100644 --- a/docs/tracing.txt +++ b/docs/tracing.txt @@ -23,7 +23,7 @@ for debugging, profiling, and observing execution. 4. Pretty-print the binary trace file: - ./simpletrace.py trace-events trace-* + ./scripts/simpletrace.py trace-events trace-* == Trace events == @@ -198,7 +198,7 @@ The "simple" backend produces binary trace files that can be formatted with the simpletrace.py script. The script takes the "trace-events" file and the binary trace: - ./simpletrace.py trace-events trace-12345 + ./scripts/simpletrace.py trace-events trace-12345 You must ensure that the same "trace-events" file was used to build QEMU, otherwise trace event declarations may have changed and output will not be