[PULL 10/10] replay: add tracing events

Paolo Bonzini posted 10 patches 12 hours ago
Maintainers: Paolo Bonzini <pbonzini@redhat.com>, "Alex Bennée" <alex.bennee@linaro.org>, Thomas Huth <thuth@redhat.com>, "Michael S. Tsirkin" <mst@redhat.com>, "Marc-André Lureau" <marcandre.lureau@redhat.com>, "Daniel P. Berrangé" <berrange@redhat.com>, "Philippe Mathieu-Daudé" <philmd@linaro.org>, John Snow <jsnow@redhat.com>, Cleber Rosa <crosa@redhat.com>, Cameron Esfahani <dirty@apple.com>, Roman Bolshakov <rbolshakov@ddn.com>, Phil Dennis-Jordan <phil@philjordan.eu>, Wei Liu <wei.liu@kernel.org>, Richard Henderson <richard.henderson@linaro.org>, Eduardo Habkost <eduardo@habkost.net>
[PULL 10/10] replay: add tracing events
Posted by Paolo Bonzini 12 hours ago
The replay subsystem does not provide any way to see what's going on
and how the replay events interleave with other things happening in QEMU.

Add trace events to improve debuggability; to avoid having too many
events reimplement all functions in terms of (non-traced) replay_getc
and replay_putc and add a single trace event for each datum that is
extracted or written.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
---
 meson.build              |  1 +
 replay/trace.h           |  1 +
 replay/replay-internal.c | 70 ++++++++++++++++++++++++++++++----------
 replay/trace-events      | 12 +++++++
 4 files changed, 67 insertions(+), 17 deletions(-)
 create mode 100644 replay/trace.h
 create mode 100644 replay/trace-events

diff --git a/meson.build b/meson.build
index df4460035c3..95fcec9ba15 100644
--- a/meson.build
+++ b/meson.build
@@ -3678,6 +3678,7 @@ if have_system
     'hw/gpio',
     'migration',
     'net',
+    'replay',
     'system',
     'ui',
     'hw/remote',
diff --git a/replay/trace.h b/replay/trace.h
new file mode 100644
index 00000000000..39ff481742e
--- /dev/null
+++ b/replay/trace.h
@@ -0,0 +1 @@
+#include "trace/trace-replay.h"
diff --git a/replay/replay-internal.c b/replay/replay-internal.c
index c2a7200339f..4839f2b6321 100644
--- a/replay/replay-internal.c
+++ b/replay/replay-internal.c
@@ -15,6 +15,7 @@
 #include "replay-internal.h"
 #include "qemu/error-report.h"
 #include "qemu/main-loop.h"
+#include "trace.h"
 
 /* Mutex to protect reading and writing events to the log.
    data_kind and has_unread_data are also protected
@@ -44,7 +45,7 @@ static void replay_read_error(void)
     exit(1);
 }
 
-void replay_put_byte(uint8_t byte)
+static void replay_putc(uint8_t byte)
 {
     if (replay_file) {
         if (putc(byte, replay_file) == EOF) {
@@ -53,29 +54,45 @@ void replay_put_byte(uint8_t byte)
     }
 }
 
+void replay_put_byte(uint8_t byte)
+{
+    trace_replay_put_byte(byte);
+    replay_putc(byte);
+}
+
 void replay_put_event(uint8_t event)
 {
+    trace_replay_put_event(event);
     assert(event < EVENT_COUNT);
-    replay_put_byte(event);
+    replay_putc(event);
 }
 
 
 void replay_put_word(uint16_t word)
 {
-    replay_put_byte(word >> 8);
-    replay_put_byte(word);
+    trace_replay_put_word(word);
+    replay_putc(word >> 8);
+    replay_putc(word);
 }
 
 void replay_put_dword(uint32_t dword)
 {
-    replay_put_word(dword >> 16);
-    replay_put_word(dword);
+    int i;
+
+    trace_replay_put_dword(dword);
+    for (i = 24; i >= 0; i -= 8) {
+        replay_putc(dword >> i);
+    }
 }
 
 void replay_put_qword(int64_t qword)
 {
-    replay_put_dword(qword >> 32);
-    replay_put_dword(qword);
+    int i;
+
+    trace_replay_put_qword(qword);
+    for (i = 56; i >= 0; i -= 8) {
+        replay_putc(qword >> i);
+    }
 }
 
 void replay_put_array(const uint8_t *buf, size_t size)
@@ -88,7 +105,7 @@ void replay_put_array(const uint8_t *buf, size_t size)
     }
 }
 
-uint8_t replay_get_byte(void)
+static uint8_t replay_getc(void)
 {
     uint8_t byte = 0;
     if (replay_file) {
@@ -101,36 +118,52 @@ uint8_t replay_get_byte(void)
     return byte;
 }
 
+uint8_t replay_get_byte(void)
+{
+    uint8_t byte = replay_getc();
+    trace_replay_get_byte(byte);
+    return byte;
+}
+
 uint16_t replay_get_word(void)
 {
     uint16_t word = 0;
     if (replay_file) {
-        word = replay_get_byte();
-        word = (word << 8) + replay_get_byte();
+        word = replay_getc();
+        word = (word << 8) + replay_getc();
     }
 
+    trace_replay_get_word(word);
     return word;
 }
 
 uint32_t replay_get_dword(void)
 {
     uint32_t dword = 0;
+    int i;
+
     if (replay_file) {
-        dword = replay_get_word();
-        dword = (dword << 16) + replay_get_word();
+        for (i = 24; i >= 0; i -= 8) {
+            dword |= replay_getc() << i;
+        }
     }
 
+    trace_replay_get_dword(dword);
     return dword;
 }
 
 int64_t replay_get_qword(void)
 {
-    int64_t qword = 0;
+    uint64_t qword = 0;
+    int i;
+
     if (replay_file) {
-        qword = replay_get_dword();
-        qword = (qword << 32) + replay_get_dword();
+        for (i = 56; i >= 0; i -= 8) {
+            qword |= (uint64_t)replay_getc() << i;
+        }
     }
 
+    trace_replay_get_qword(qword);
     return qword;
 }
 
@@ -172,10 +205,12 @@ void replay_check_error(void)
 
 void replay_fetch_data_kind(void)
 {
+    trace_replay_fetch_data_kind();
     if (replay_file) {
         if (!replay_state.has_unread_data) {
-            replay_state.data_kind = replay_get_byte();
+            replay_state.data_kind = replay_getc();
             replay_state.current_event++;
+            trace_replay_get_event(replay_state.current_event, replay_state.data_kind);
             if (replay_state.data_kind == EVENT_INSTRUCTION) {
                 replay_state.instruction_count = replay_get_dword();
             }
@@ -246,6 +281,7 @@ void replay_advance_current_icount(uint64_t current_icount)
     int diff = (int)(current_icount - replay_state.current_icount);
 
     /* Time can only go forward */
+    trace_replay_advance_current_icount(replay_state.current_icount, diff);
     assert(diff >= 0);
 
     if (replay_mode == REPLAY_MODE_RECORD) {
diff --git a/replay/trace-events b/replay/trace-events
new file mode 100644
index 00000000000..e9c887a6c57
--- /dev/null
+++ b/replay/trace-events
@@ -0,0 +1,12 @@
+replay_put_byte(uint8_t event) "%02x"
+replay_put_event(uint8_t event) "%02x"
+replay_put_word(uint16_t event) "%04x"
+replay_put_dword(uint32_t event) "%08x"
+replay_put_qword(uint64_t event) "%016" PRIx64
+replay_get_byte(uint8_t byte) "%02x"
+replay_get_word(uint16_t word) "%04x"
+replay_get_dword(uint32_t dword) "%08x"
+replay_get_qword(uint64_t qword) "%016" PRIx64
+replay_fetch_data_kind(void) ""
+replay_get_event(uint32_t current, uint8_t data) "#%u data=%02x"
+replay_advance_current_icount(uint64_t current_icount, int diff) "current=%" PRIu64 " diff=%d"
-- 
2.51.1