Fix instruction logging backend context tracing.

- Add extra LOG_EVENT_CTX_OP_SETUP variant of the OP_SWITCH context update
event.
  This is propagated even when tracing is off and can be used to setup the
  context information before tracing starts.
- Fix statistics trace state reset when tracing is paused and when the
  active context changes.
- Add a subclass for QEMU context tracks. This follows the pattern of perfetto
  ThreadTrack and ProcessTrack.
- Add events to RISC-V target.

accel/tcg/log_instr.c

@@ -157,6 +157,13 @@ static inline void emit_start_event(cpu_log_entry_t *entry, target_ulong pc)
     event.state.pc = pc;
     /* Start events always have incomplete instruction data */
     entry->flags &= ~LI_FLAG_HAS_INSTR_DATA;
+    /*
+     * Also update PC to the one given in the start event.
+     * This ensures that the pc field is always correct, even on the first
+     * incomplete entry of the trace, where the start trigger occurs.
+     * XXX-AM: Does this mean that we can do away with the state.pc field?
+     */
+    entry->pc = pc;
 
     g_array_append_val(entry->events, event);
 }

include/qemu/log_instr.h

@@ -115,7 +115,13 @@ typedef struct {
 
 typedef enum {
     /* Switch context from the current to the new (proc, thread, compartment) ID */
-    LOG_EVENT_CTX_OP_SWITCH = 1
+    LOG_EVENT_CTX_OP_SWITCH = 1,
+    /*
+     * Same as LOG_EVENT_CTX_OP_SWITCH but should bypass tracing activation status,
+     * Meaning that these events will reach the backend even when tracing is off.
+     * This is useful setup the correct context identifier before switching on tracing.
+     */
+    LOG_EVENT_CTX_OP_SETUP = 2
 } log_event_ctx_update_op_t;
 
 /*
@@ -126,6 +132,7 @@ typedef struct {
     uint64_t pid;    /* Process ID */
     uint64_t tid;    /* Thread ID */
     uint64_t cid;    /* Compartment ID */
+    qemu_log_instr_cpu_mode_t mode; /* CPU mode */
 } log_event_ctx_update_t;
 
 /*

target/riscv/cpu.h

@@ -737,6 +737,30 @@ static inline const char *cpu_get_mode_name(qemu_log_instr_cpu_mode_t mode)
         return riscv_cpu_mode_names[mode];
     return "<invalid>";
 }
+
+/*
+ * Currently this is not required by the instruction logging backend, it
+ * is used internally in the target to get the correct code for the mode.
+ */
+static inline qemu_log_instr_cpu_mode_t cpu_priv_to_mode(target_ulong priv)
+{
+    qemu_log_instr_cpu_mode_t mode;
+
+    switch (priv) {
+    case PRV_M:
+        mode = RISCV_LOG_INSTR_CPU_M;
+        break;
+    case PRV_S:
+        mode = RISCV_LOG_INSTR_CPU_S;
+        break;
+    case PRV_H:
+        mode = RISCV_LOG_INSTR_CPU_H;
+        break;
+    default:
+        mode = RISCV_LOG_INSTR_CPU_U;
+    }
+    return mode;
+}
 #endif
 
 int riscv_csrrw(CPURISCVState *env, int csrno, target_ulong *ret_value,

target/riscv/cpu_helper.c

@@ -339,22 +339,7 @@ void riscv_cpu_set_mode(CPURISCVState *env, target_ulong newpriv)
     env->load_res = -1;
 
 #ifdef CONFIG_TCG_LOG_INSTR
-    qemu_log_instr_cpu_mode_t mode;
-
-    switch (newpriv) {
-    case PRV_M:
-        mode = RISCV_LOG_INSTR_CPU_M;
-        break;
-    case PRV_S:
-        mode = RISCV_LOG_INSTR_CPU_S;
-        break;
-    case PRV_H:
-        mode = RISCV_LOG_INSTR_CPU_H;
-        break;
-    default:
-        mode = RISCV_LOG_INSTR_CPU_U;
-    }
-    qemu_log_instr_mode_switch(env, mode, cpu_get_recent_pc(env));
+    qemu_log_instr_mode_switch(env, cpu_priv_to_mode(newpriv), cpu_get_recent_pc(env));
 #endif
 }
 

target/riscv/op_helper_log_instr.c

@@ -73,16 +73,19 @@ void HELPER(riscv_log_instr_event)(CPURISCVState *env, target_ulong pc)
 {
     log_event_t event;
 
-    if (!qemu_log_instr_enabled(env))
+    event.id = get_gpr_value(env, 10);
+    if (!qemu_log_instr_enabled(env) &&
+        (event.id != LOG_EVENT_CTX_UPDATE || event.ctx_update.op != LOG_EVENT_CTX_OP_SETUP))
         return;
 
-    event.id = get_gpr_value(env, 10);
     switch (event.id) {
     case LOG_EVENT_CTX_UPDATE:
+    case LOG_EVENT_CTX_OP_SETUP:
         event.ctx_update.op = get_gpr_value(env, 11);
         event.ctx_update.pid = get_gpr_value(env, 12);
         event.ctx_update.tid = get_gpr_value(env, 13);
         event.ctx_update.cid = get_gpr_value(env, 14);
+        event.ctx_update.mode = cpu_priv_to_mode(env->priv);
         break;
     default:
         warn_report("Unsupported event ID for TCG instr logging %d", event.id);

trace_extra/guest_context_tracker.cc

@@ -32,69 +32,28 @@
 #include "trace_extra/guest_context_tracker.hh"
 
 namespace {
-
-struct qemu_context_track : public perfetto::Track
-{
-    const uint64_t pid;
-    const uint64_t tid;
-    const uint64_t cid;
-
-    using qemu_ctx_id = std::tuple<uint64_t, uint64_t, uint64_t>;
-
-    static std::shared_ptr<qemu_context_track>
-    make_context_track(uint64_t pid, uint64_t tid, uint64_t cid)
-    {
-        return std::make_shared<qemu_context_track>(pid, tid, cid);
-    }
-
-    qemu_ctx_id
-    get_id() const
-    {
-        return std::make_tuple(pid, tid, cid);
-    }
-
-    perfetto::protos::gen::TrackDescriptor
-    Serialize() const
-    {
-        auto desc = Track::Serialize();
-        auto qemu_desc = desc.mutable_qemu_context();
-        qemu_desc->set_pid(pid);
-        qemu_desc->set_tid(tid);
-        qemu_desc->set_cid(cid);
-        return desc;
-    }
-
-    qemu_context_track(uint64_t pid, uint64_t tid, uint64_t cid)
-            : perfetto::Track(cheri::gen_track_uuid(), perfetto::Track()), pid(pid), tid(tid), cid(cid)
-    {}
-
-    ~qemu_context_track()
-    {
-        perfetto::TrackEvent::EraseTrackDescriptor(*this);
-    }
-};
-
 /*
  * Dynamically created tracks.
  * Here we do not commit to a hierarchical model of process/thread, as context
  * events are guest-driven. Instead we defer any hierarchical interpretation of
  * the context identifier to post-processing.
  */
 std::mutex tracks_lock;
-std::map<qemu_context_track::qemu_ctx_id, std::shared_ptr<qemu_context_track>> tracks;
+std::map<cheri::qemu_context_track::qemu_ctx_id, std::shared_ptr<cheri::qemu_context_track>> tracks;
 } /* anonymous */
 
 namespace std {
 /*
  * Make the qemu track ID hashable
  */
-template<> struct hash<qemu_context_track::qemu_ctx_id>
+template<> struct hash<cheri::qemu_context_track::qemu_ctx_id>
 {
-    std::size_t operator()(const qemu_context_track::qemu_ctx_id& key) const noexcept
+    std::size_t operator()(const cheri::qemu_context_track::qemu_ctx_id& key) const noexcept
     {
         return (std::hash<uint64_t>{}(std::get<0>(key)) ^
                 std::hash<uint64_t>{}(std::get<1>(key)) ^
-                std::hash<uint64_t>{}(std::get<2>(key)));
+                std::hash<uint64_t>{}(std::get<2>(key)) ^
+                std::hash<uint64_t>{}(std::get<3>(key)));
 
     }
 };
@@ -112,6 +71,50 @@ gen_track_uuid()
     return (next_track_id++);
 }
 
+perfetto::protos::pbzero::ModeSwitch
+qemu_cpu_mode_to_trace(qemu_log_instr_cpu_mode_t mode)
+{
+    // NOTE: We rely on the fact that the protobuf enum ModeSwitch
+    // uses the same numbering as qemu_log_instr_cpu_mode_t
+    return static_cast<perfetto::protos::pbzero::ModeSwitch>(mode);
+}
+
+/* static */
+std::shared_ptr<qemu_context_track>
+qemu_context_track::make_context_track(qemu_ctx_id key)
+{
+    return std::make_shared<qemu_context_track>(key);
+}
+
+    qemu_context_track::qemu_ctx_id
+    qemu_context_track::get_id() const
+    {
+        return std::make_tuple(pid, tid, cid, mode);
+    }
+
+perfetto::protos::gen::TrackDescriptor
+qemu_context_track::Serialize() const
+{
+    auto desc = Track::Serialize();
+    auto qemu_desc = desc.mutable_qemu_context();
+    qemu_desc->set_pid(pid);
+    qemu_desc->set_tid(tid);
+    qemu_desc->set_cid(cid);
+    // qemu_desc->set_mode(mode); // TODO not yet in cheri-perfetto
+    return desc;
+}
+
+qemu_context_track::qemu_context_track(qemu_ctx_id key)
+        : perfetto::Track(cheri::gen_track_uuid(), perfetto::Track()),
+          pid(std::get<0>(key)), tid(std::get<1>(key)), cid(std::get<2>(key)),
+          mode(std::get<3>(key))
+{}
+
+qemu_context_track::~qemu_context_track()
+{
+    perfetto::TrackEvent::EraseTrackDescriptor(*this);
+}
+
 guest_context_tracker::guest_context_tracker(int cpu_id) :
         cpu_track_(perfetto::Track::Global(gen_track_uuid()))
 {
@@ -121,6 +124,36 @@ guest_context_tracker::guest_context_tracker(int cpu_id) :
     perfetto::TrackEvent::SetTrackDescriptor(cpu_track_, desc);
 }
 
+void
+guest_context_tracker::mode_update(perfetto::protos::pbzero::ModeSwitch new_mode)
+{
+    if (ctx_track_ == nullptr)
+        return;
+
+    auto key = ctx_track_->get_id();
+    std::get<3>(key) = new_mode;
+    /* Check if we have a track for this mode */
+    std::shared_ptr<qemu_context_track> track;
+    {
+        std::lock_guard<std::mutex> tracks_guard(tracks_lock);
+        auto found_track_iter = tracks.find(key);
+        if (found_track_iter == tracks.end()) {
+            track = qemu_context_track::make_context_track(key);
+            auto desc = track->Serialize();
+            desc.set_name("CTX " + std::to_string(track->pid) + ":" +
+                          std::to_string(track->tid) + ":" +
+                          std::to_string(track->cid) + ":" +
+                          std::to_string(track->mode));
+            perfetto::TrackEvent::SetTrackDescriptor(*track, desc);
+            tracks.emplace(key, track);
+        } else {
+            /* Existing context */
+            track = found_track_iter->second;
+        }
+    }
+    ctx_track_ = track;
+}
+
 void
 guest_context_tracker::context_update(const log_event_ctx_update_t *evt)
 {
@@ -130,32 +163,33 @@ guest_context_tracker::context_update(const log_event_ctx_update_t *evt)
      * Find or create the track associated with the new context and set it as the current
      * context track on the CPU. This will be used to log per-context events.
      * XXX-AM: Currently it is assumed that contexts are unique, this is clearly not the case
-     * with PID/TID reuse and we should do something to detect this. This is mostly relevant
+     * with PID/TID reuse and we should do something to detect this. This seems mostly relevant
      * only for long-lived traces.
      */
 
+    auto mode = qemu_cpu_mode_to_trace(evt->mode);
     /* Fetch the tracks for the new context */
-    std::lock_guard<std::mutex> tracks_guard(tracks_lock);
-    qemu_context_track::qemu_ctx_id key = std::make_tuple(evt->pid, evt->tid, evt->cid);
-    auto ctx_track_iter = tracks.find(key);
+    qemu_context_track::qemu_ctx_id key = std::make_tuple(evt->pid, evt->tid, evt->cid, mode);
     std::shared_ptr<qemu_context_track> track;
-    if (ctx_track_iter == tracks.end()) {
-        /* New context */
-        track = qemu_context_track::make_context_track(evt->pid, evt->tid, evt->cid);
-        auto desc = track->Serialize();
-        desc.set_name("CTX " + std::to_string(evt->pid) + ":" +
-                      std::to_string(evt->tid) + ":" +
-                      std::to_string(evt->cid));
-        perfetto::TrackEvent::SetTrackDescriptor(*track, desc);
-        tracks.emplace(key, track);
-    } else {
-        /* Existing context */
-        track = ctx_track_iter->second;
+    {
+        std::lock_guard<std::mutex> tracks_guard(tracks_lock);
+        auto ctx_track_iter = tracks.find(key);
+        if (ctx_track_iter == tracks.end()) {
+            /* New context */
+            track = qemu_context_track::make_context_track(key);
+            auto desc = track->Serialize();
+            desc.set_name("CTX " + std::to_string(evt->pid) + ":" +
+                          std::to_string(evt->tid) + ":" +
+                          std::to_string(evt->cid) + ":" +
+                          std::to_string(mode));
+            perfetto::TrackEvent::SetTrackDescriptor(*track, desc);
+            tracks.emplace(key, track);
+        } else {
+            /* Existing context */
+            track = ctx_track_iter->second;
+        }
     }
     ctx_track_ = track;
-    /* XXX-AM: for debugging, remove */
-    TRACE_EVENT_INSTANT("sched", "switch", cpu_track_,
-                        "pid", evt->pid, "tid", evt->tid, "cid", evt->cid);
 }
 
 perfetto::Track&

trace_extra/guest_context_tracker.hh

@@ -35,6 +35,29 @@
 
 namespace cheri
 {
+
+struct qemu_context_track : public perfetto::Track
+{
+
+    using cpu_mode_type = perfetto::protos::pbzero::ModeSwitch;
+    /* (pid, tid, cid, mode) */
+    using qemu_ctx_id = std::tuple<uint64_t, uint64_t, uint64_t, cpu_mode_type>;
+
+    const uint64_t pid;
+    const uint64_t tid;
+    const uint64_t cid;
+    const cpu_mode_type mode;
+
+    static std::shared_ptr<qemu_context_track> make_context_track(qemu_ctx_id key);
+
+    qemu_ctx_id get_id() const;
+
+    perfetto::protos::gen::TrackDescriptor Serialize() const;
+
+    qemu_context_track(qemu_ctx_id key);
+    ~qemu_context_track();
+};
+
 /*
  * Track current guest context associated to a CPU.
  * This allows to charge events to the correct context by recording
@@ -55,10 +78,11 @@ namespace cheri
 class guest_context_tracker
 {
     perfetto::Track cpu_track_;
-    std::shared_ptr<perfetto::Track> ctx_track_;
+    std::shared_ptr<qemu_context_track> ctx_track_;
   public:
     guest_context_tracker(int cpu_id);
     void context_update(const log_event_ctx_update_t *evt);
+    void mode_update(perfetto::protos::pbzero::ModeSwitch new_mode);
     perfetto::Track& get_cpu_track();
     perfetto::Track& get_ctx_track();
 };
@@ -70,4 +94,7 @@ class guest_context_tracker
  */
 unsigned long gen_track_uuid();
 
+perfetto::protos::pbzero::ModeSwitch
+qemu_cpu_mode_to_trace(qemu_log_instr_cpu_mode_t mode);
+
 } /* cheri */