diff --git a/accel/tcg/log_instr_json.c b/accel/tcg/log_instr_json.c index 7fc0774b14..80dec851c4 100644 --- a/accel/tcg/log_instr_json.c +++ b/accel/tcg/log_instr_json.c @@ -275,6 +275,9 @@ void emit_json_entry(CPUArchState *env, cpu_log_entry_t *entry) case LOG_EVENT_REGDUMP: emit_json_evt_regdump(&event->reg_dump, js_evt); break; + case LOG_EVENT_COUNTER: + /* TODO Unimpl */ + break; default: assert(0 && "unknown event ID"); } diff --git a/accel/tcg/log_instr_protobuf.c b/accel/tcg/log_instr_protobuf.c index 31743277d7..1e630a1541 100644 --- a/accel/tcg/log_instr_protobuf.c +++ b/accel/tcg/log_instr_protobuf.c @@ -226,6 +226,8 @@ static void emit_protobuf_event(log_event_t *evtinfo, QEMULogEntryEvt **pb_evt) emit_protobuf_reginfo(rinfo, pb_regs); } } break; + case LOG_EVENT_COUNTER: + break; default: assert(0 && "unknown event ID"); } diff --git a/accel/tcg/log_instr_text.c b/accel/tcg/log_instr_text.c index 522327dd94..743bbb17ad 100644 --- a/accel/tcg/log_instr_text.c +++ b/accel/tcg/log_instr_text.c @@ -121,6 +121,7 @@ void emit_text_instr(CPUArchState *env, cpu_log_entry_t *entry) const log_event_t *event; const char *log_state_op; int i, j; + bool incremental; if (entry->flags & LI_FLAG_HAS_INSTR_DATA) { /* Dump CPU-ID:ASID + address */ @@ -227,6 +228,14 @@ void emit_text_instr(CPUArchState *env, cpu_log_entry_t *entry) &g_array_index(event->reg_dump.gpr, log_reginfo_t, j); emit_text_reg(r); } + break; + case LOG_EVENT_COUNTER: + incremental = log_event_counter_incremental(event->counter.flags); + qemu_log("Counter %s %s[%d]: %lx\n", (incremental) ? "INC" : "ABS", + event->counter.name, + log_event_counter_slot(event->counter.flags), + event->counter.value); + break; default: assert(0 && "unknown event ID"); } diff --git a/include/exec/log_instr_perfetto.h b/include/exec/log_instr_perfetto.h index 122acd93f6..ee5a41dc26 100644 --- a/include/exec/log_instr_perfetto.h +++ b/include/exec/log_instr_perfetto.h @@ -62,7 +62,8 @@ PERFETTO_DEFINE_CATEGORIES( perfetto::Category("trap").SetDescription("CPU trap events"), perfetto::Category("sched").SetDescription("Scheduling events"), perfetto::Category("marker").SetDescription( - "Guest trace timestamp markers")); + "Guest trace timestamp markers"), + perfetto::Category("counter").SetDescription("Guest-driven counters")); #endif /* diff --git a/include/qemu/log_instr.h b/include/qemu/log_instr.h index 48a8783ff0..31f738d94b 100644 --- a/include/qemu/log_instr.h +++ b/include/qemu/log_instr.h @@ -47,6 +47,8 @@ #define QEMU_LOG_PRINTF_BUF_DEPTH 32 /* Early flush if buffer gets this full. */ #define QEMU_LOG_PRINTF_FLUSH_BARRIER 32 +/* Max name size for qemu counters and other events */ +#define QEMU_LOG_EVENT_MAX_NAMELEN 64 /* * Instruction logging format @@ -113,6 +115,7 @@ typedef enum { LOG_EVENT_CTX_UPDATE = 1, LOG_EVENT_MARKER = 2, LOG_EVENT_REGDUMP = 3, + LOG_EVENT_COUNTER = 4, } log_event_id_t; /* @@ -159,6 +162,20 @@ typedef struct { GArray *gpr; } log_event_regdump_t; +/* + * Counter event. + * This represents an arbitrary named counter. Generally driven from the + * guest OS via NOPs, but can also be generated internally. + */ +typedef struct { + char name[QEMU_LOG_EVENT_MAX_NAMELEN]; + int64_t value; + uint64_t flags; +} log_event_counter_t; + +#define log_event_counter_slot(flags) (flags & 0xffff) +#define log_event_counter_incremental(flags) ((flags >> 32) & 0x01) + /* * Trace event. * This records arbitrary higher-level events associated with instruction @@ -180,6 +197,7 @@ typedef struct { log_event_ctx_update_t ctx_update; log_event_regdump_t reg_dump; uint64_t marker; + log_event_counter_t counter; }; } log_event_t; @@ -241,9 +259,9 @@ typedef struct qemu_log_instr_stats { uint64_t trace_stop; } qemu_log_instr_stats_t; -#define QEMU_LOG_INSTR_INC_STAT(cpu_state, stat) \ - do { \ - cpu_state->stats.stat++; \ +#define QEMU_LOG_INSTR_INC_STAT(cpu_state, stat) \ + do { \ + cpu_state->stats.stat++; \ } while (0) /* diff --git a/target/riscv/helper.h b/target/riscv/helper.h index c030dee4b5..09c54114a8 100644 --- a/target/riscv/helper.h +++ b/target/riscv/helper.h @@ -83,7 +83,6 @@ DEF_HELPER_3(sc_c_cap, tl, env, i32, i32) DEF_HELPER_FLAGS_3(riscv_log_gpr_write, TCG_CALL_NO_RWG, void, env, i32, tl) DEF_HELPER_FLAGS_4(riscv_log_instr, TCG_CALL_NO_RWG, void, env, tl, i32, i32) DEF_HELPER_FLAGS_2(riscv_log_instr_event, TCG_CALL_NO_RWG, void, env, tl) -DEF_HELPER_FLAGS_1(riscv_log_instr_regdump, TCG_CALL_NO_RWG, void, env) #endif /* Special functions */ diff --git a/target/riscv/op_helper_log_instr.c b/target/riscv/op_helper_log_instr.c index a0554eeefc..a50a5a54b9 100644 --- a/target/riscv/op_helper_log_instr.c +++ b/target/riscv/op_helper_log_instr.c @@ -45,6 +45,29 @@ #define get_gpr_value(env, regnum) (env->gpr[regnum]) #endif +/* + * Read a null-terminated guest string without requiring a strlen() in + * the guest. This is probably slower but does not perturb guest call-graph. + */ +static int read_guest_cstring(CPURISCVState *env, target_ulong vaddr, + char *buffer, size_t maxlen) +{ + int ret = 0; + + buffer[maxlen - 1] = '\0'; + while (maxlen > 1) { + ret = cpu_memory_rw_debug(env_cpu(env), vaddr, buffer, 1, false); + if (ret != 0 || *buffer == '\0') { + break; + } + maxlen--; + vaddr++; + buffer++; + } + + return ret; +} + void HELPER(riscv_log_gpr_write)(CPURISCVState *env, uint32_t regnum, target_ulong value) { @@ -78,6 +101,8 @@ void HELPER(riscv_log_instr)(CPURISCVState *env, target_ulong pc, void HELPER(riscv_log_instr_event)(CPURISCVState *env, target_ulong pc) { log_event_t event; + target_ulong vaddr; + int ret; event.id = get_gpr_value(env, 10); @@ -96,6 +121,19 @@ void HELPER(riscv_log_instr_event)(CPURISCVState *env, target_ulong pc) case LOG_EVENT_REGDUMP: cpu_log_instr_event_regdump(env, &event); break; + case LOG_EVENT_COUNTER: + vaddr = get_gpr_value(env, 11); + ret = read_guest_cstring(env, vaddr, (char *)event.counter.name, + sizeof(event.counter.name)); + if (ret != 0) { + warn_report("LOG EVENT HELPER: Could not read guest string at" + " vaddr 0x" TARGET_FMT_lx "\r\n", + vaddr); + return; + } + event.counter.value = (int64_t)get_gpr_value(env, 12); + event.counter.flags = get_gpr_value(env, 13); + break; default: warn_report("Unsupported event ID for TCG instr logging %d", event.id); @@ -139,17 +177,3 @@ bool cpu_log_instr_event_regdump(CPURISCVState *env, log_event_t *event) return false; } - -/* - * Emit a register dump event. - * Only dump general purpose registers for now. No fpu, vector or CPU registers. - */ -void HELPER(riscv_log_instr_regdump)(CPURISCVState *env) -{ - log_event_t event; - - if (qemu_log_instr_enabled(env)) { - cpu_log_instr_event_regdump(env, &event); - qemu_log_instr_event(env, &event); - } -} diff --git a/trace_extra/cheri-perfetto b/trace_extra/cheri-perfetto index 98682fd0e4..2bbdf5a6cc 160000 --- a/trace_extra/cheri-perfetto +++ b/trace_extra/cheri-perfetto @@ -1 +1 @@ -Subproject commit 98682fd0e432c44ac54e637922f22e13786325da +Subproject commit 2bbdf5a6ccddbee6df68dbd16c7c6e136bddd6d6 diff --git a/trace_extra/guest_context_tracker.cc b/trace_extra/guest_context_tracker.cc index bb6313a64e..cb590acd1b 100644 --- a/trace_extra/guest_context_tracker.cc +++ b/trace_extra/guest_context_tracker.cc @@ -37,13 +37,12 @@ namespace cheri /* * Dynamically created tracks and track data. - * The tracks lock protects both tracks and ctx_data. + * The track_state_lock must be held for updating the track_state map. */ -std::mutex tracks_lock; -std::unordered_map, - cheri::tuple_hasher> - tracks; +std::mutex track_state_lock; +std::unordered_map, + tuple_hasher> + track_state_map; /* Helper to generate unique IDs for dynamic tracks */ unsigned long gen_track_uuid() @@ -61,16 +60,24 @@ qemu_cpu_mode_to_trace(qemu_log_instr_cpu_mode_t mode) return static_cast(mode); } -/* static */ -std::shared_ptr -qemu_context_track::make_context_track(qemu_ctx_id key) +qemu_cpu_track::qemu_cpu_track(int id) + : perfetto::Track(gen_track_uuid(), perfetto::Track()), cpu_id(id) { - return std::make_shared(key); } -qemu_context_track::qemu_ctx_id qemu_context_track::get_id() const +perfetto::protos::gen::TrackDescriptor qemu_cpu_track::Serialize() const { - return std::make_tuple(pid, tid, cid, mode); + auto desc = Track::Serialize(); + std::string name("CPU " + std::to_string(cpu_id)); + desc.set_name(name); + return desc; +} + +void qemu_cpu_track::Serialize( + perfetto::protos::pbzero::TrackDescriptor *desc) const +{ + auto bytes = Serialize().SerializeAsString(); + desc->AppendRawProtoBytes(bytes.data(), bytes.size()); } perfetto::protos::gen::TrackDescriptor qemu_context_track::Serialize() const @@ -81,58 +88,54 @@ perfetto::protos::gen::TrackDescriptor qemu_context_track::Serialize() const cheri_desc->set_tid(tid); cheri_desc->set_cid(cid); cheri_desc->set_el(mode); + desc.set_name("CTX " + std::to_string(pid) + ":" + std::to_string(tid) + + ":" + std::to_string(cid) + ":" + std::to_string(mode)); return desc; } +void qemu_context_track::Serialize( + perfetto::protos::pbzero::TrackDescriptor *desc) const +{ + auto bytes = Serialize().SerializeAsString(); + desc->AppendRawProtoBytes(bytes.data(), bytes.size()); +} + qemu_context_track::qemu_context_track(qemu_ctx_id key) - : perfetto::Track(cheri::gen_track_uuid(), perfetto::Track()), + : perfetto::Track(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() +qemu_ctx_id qemu_context_track::get_id() const { - perfetto::TrackEvent::EraseTrackDescriptor(*this); + return std::make_tuple(pid, tid, cid, mode); } -guest_context_tracker::guest_context_tracker(int cpu_id) - : cpu_track_(perfetto::Track::Global(gen_track_uuid())) -{ - std::string track_name("CPU " + std::to_string(cpu_id)); - auto desc = cpu_track_.Serialize(); - desc.set_name(track_name); - perfetto::TrackEvent::SetTrackDescriptor(cpu_track_, desc); -} +guest_context_tracker::guest_context_tracker(int cpu_id) : cpu_state(cpu_id) {} void guest_context_tracker::mode_update( perfetto::protos::pbzero::QEMULogEntryModeSwitch new_mode) { - if (ctx_track_ == nullptr) + if (ctx_state == nullptr) return; - auto key = ctx_track_->get_id(); + auto key = ctx_state->track.get_id(); std::get<3>(key) = new_mode; /* Check if we have a track for this mode */ - std::shared_ptr track; + std::shared_ptr state; { - std::lock_guard 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); + std::lock_guard track_state_guard(track_state_lock); + auto it = track_state_map.find(key); + if (it == track_state_map.end()) { + state = std::make_shared(key); + track_state_map.emplace(key, state); } else { /* Existing context */ - track = found_track_iter->second; + state = it->second; } } - ctx_track_ = track; + ctx_state = state; } void guest_context_tracker::context_update(const log_event_ctx_update_t *evt) @@ -150,59 +153,44 @@ void guest_context_tracker::context_update(const log_event_ctx_update_t *evt) auto mode = qemu_cpu_mode_to_trace(evt->mode); /* Fetch the tracks for the new context */ - qemu_context_track::qemu_ctx_id key = - std::make_tuple(evt->pid, evt->tid, evt->cid, mode); - std::shared_ptr track; + qemu_ctx_id key = std::make_tuple(evt->pid, evt->tid, evt->cid, mode); + std::shared_ptr state; { - std::lock_guard 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); + std::lock_guard track_state_guard(track_state_lock); + auto it = track_state_map.find(key); + if (it == track_state_map.end()) { + state = std::make_shared(key); + track_state_map.emplace(key, state); } else { /* Existing context */ - track = ctx_track_iter->second; + state = it->second; } } - ctx_track_ = track; + ctx_state = state; } void guest_context_tracker::flush_all_ctx_data() { /* Flush per-CPU stats */ - cpu_ctx_data_.stats.flush(cpu_track_); - for (auto &id_and_track : tracks) { - qemu_context_data &ctx_data = id_and_track.second->ctx_data; - ctx_data.stats.flush(*id_and_track.second); + cpu_state.stats.flush(cpu_state.track); + std::lock_guard track_state_guard(track_state_lock); + for (auto id_and_state : track_state_map) { + qemu_stats &stats = id_and_state.second->stats; + stats.flush(id_and_state.second->track); } } -perfetto::Track &guest_context_tracker::get_cpu_track() +qemu_fallback_state *guest_context_tracker::get_cpu_state() { - return cpu_track_; -} - -perfetto::Track &guest_context_tracker::get_ctx_track() -{ - if (ctx_track_) - return *ctx_track_; - else - return cpu_track_; + return &cpu_state; } -qemu_context_data &guest_context_tracker::get_ctx_data() +qemu_tracker_state *guest_context_tracker::get_ctx_state() { - if (ctx_track_) - return ctx_track_->ctx_data; + if (ctx_state) + return ctx_state.get(); else - return cpu_ctx_data_; + return &cpu_state; } } // namespace cheri diff --git a/trace_extra/guest_context_tracker.hh b/trace_extra/guest_context_tracker.hh index 67804a7f6c..9169693da2 100644 --- a/trace_extra/guest_context_tracker.hh +++ b/trace_extra/guest_context_tracker.hh @@ -29,6 +29,7 @@ #pragma once #include +#include #include #include #include @@ -39,35 +40,84 @@ namespace cheri { +using cpu_mode_type = perfetto::protos::pbzero::QEMULogEntryModeSwitch; +/* (pid, tid, cid, mode) */ +using qemu_ctx_id = std::tuple; + /* - * Per-context data. - * This is allocated and switched together with the context track. + * Custom track representing a QEMU guest context. */ -struct qemu_context_data { - qemu_stats stats; -}; - struct qemu_context_track : public perfetto::Track { - - using cpu_mode_type = perfetto::protos::pbzero::QEMULogEntryModeSwitch; - /* (pid, tid, cid, mode) */ - using qemu_ctx_id = std::tuple; - const uint64_t pid; const uint64_t tid; const uint64_t cid; const cpu_mode_type mode; - qemu_context_data ctx_data; - - static std::shared_ptr - make_context_track(qemu_ctx_id key); qemu_ctx_id get_id() const; + perfetto::protos::gen::TrackDescriptor Serialize() const; + void Serialize(perfetto::protos::pbzero::TrackDescriptor *desc) const; + qemu_context_track(qemu_ctx_id key); +}; + +/* + * Custom track representing a QEMU vcpu. + */ +struct qemu_cpu_track : public perfetto::Track { + const int cpu_id; perfetto::protos::gen::TrackDescriptor Serialize() const; + void Serialize(perfetto::protos::pbzero::TrackDescriptor *desc) const; + qemu_cpu_track(int id); +}; - qemu_context_track(qemu_ctx_id key); - ~qemu_context_track(); +/* + * Common CPU and context data. + */ +struct qemu_tracker_state { + qemu_stats stats; + + virtual perfetto::Track *get_track() = 0; + virtual ~qemu_tracker_state() = default; +}; + +struct qemu_context_state : public qemu_tracker_state { + qemu_context_track track; + + qemu_context_state(qemu_ctx_id id) : track(id) + { + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); + } + + ~qemu_context_state() + { + perfetto::TrackEvent::EraseTrackDescriptor(track); + } + + perfetto::Track *get_track() + { + return &track; + } +}; + +struct qemu_fallback_state : public qemu_tracker_state { + qemu_cpu_track track; + + qemu_fallback_state(int id) : track(id) + { + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); + } + + ~qemu_fallback_state() + { + perfetto::TrackEvent::EraseTrackDescriptor(track); + } + + perfetto::Track *get_track() + { + return &track; + } }; /* @@ -95,21 +145,18 @@ struct qemu_context_track : public perfetto::Track { */ class guest_context_tracker { - /* CPU track for events not assigned (or assignable) to a single context */ - perfetto::Track cpu_track_; - /* context data for the CPU track */ - qemu_context_data cpu_ctx_data_; - /* Currently active context track */ - std::shared_ptr ctx_track_; + /* CPU tracks and fallback data */ + qemu_fallback_state cpu_state; + /* Currently active context data */ + std::shared_ptr ctx_state; public: guest_context_tracker(int cpu_id); void context_update(const log_event_ctx_update_t *evt); void mode_update(perfetto::protos::pbzero::QEMULogEntryModeSwitch new_mode); void flush_all_ctx_data(); - perfetto::Track &get_cpu_track(); - perfetto::Track &get_ctx_track(); - qemu_context_data &get_ctx_data(); + qemu_fallback_state *get_cpu_state(); + qemu_tracker_state *get_ctx_state(); }; /* diff --git a/trace_extra/meson.build b/trace_extra/meson.build index e63051a749..b391ddca81 100644 --- a/trace_extra/meson.build +++ b/trace_extra/meson.build @@ -5,8 +5,8 @@ qemutrace_ss = ss.source_set() if config_all.has_key('CONFIG_TCG_LOG_INSTR') and config_all.has_key('CONFIG_TRACE_PERFETTO') qemutrace_ss.add(dependency('boost', modules: ['filesystem', 'system'])) qemutrace_ss.add(files('trace_perfetto.cc', 'trace_stats.cc', - 'guest_context_tracker.cc', - 'cheri-perfetto/sdk/perfetto.cc')) + 'guest_context_tracker.cc', 'trace_counters.cc', + 'cheri-perfetto/sdk/perfetto.cc')) endif qemutrace_ss = qemutrace_ss.apply(config_all, strict: false) diff --git a/trace_extra/trace_counters.cc b/trace_extra/trace_counters.cc new file mode 100644 index 0000000000..4e094ed7e0 --- /dev/null +++ b/trace_extra/trace_counters.cc @@ -0,0 +1,163 @@ +/*- + * Copyright (c) 2022 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#include +#include "trace_extra/trace_counters.hh" +#include "trace_extra/guest_context_tracker.hh" + +namespace cheri +{ + +namespace +{ +/* + * Global counter state. + */ +qemu_counters_state global_counters; + +} // namespace + +qemu_counter_track::qemu_counter_track(uint64_t uuid_, qemu_counter_id id) + : perfetto::Track(uuid_, perfetto::Track()), name(std::get<0>(id)), + slot(std::get<1>(id)) +{ +} + +perfetto::protos::gen::TrackDescriptor qemu_counter_track::Serialize() const +{ + auto desc = Track::Serialize(); + /* TODO process custom trace descriptor in trace processor */ + desc.set_name(name + ":" + std::to_string(slot)); + auto *counter_desc = desc.mutable_counter(); + /* TODO fill counter descriptor with optional data */ + return desc; +} + +void qemu_counter_track::Serialize( + perfetto::protos::pbzero::TrackDescriptor *desc) const +{ + auto bytes = Serialize().SerializeAsString(); + desc->AppendRawProtoBytes(bytes.data(), bytes.size()); +} + +qemu_counter::qemu_counter(qemu_counter_id id, int64_t reset) + : track(gen_track_uuid(), id), value(reset) +{ + auto desc = track.Serialize(); + perfetto::TrackEvent::SetTrackDescriptor(track, desc); +} + +qemu_counter::~qemu_counter() +{ + perfetto::TrackEvent::EraseTrackDescriptor(track); +} + +void qemu_counter::emit(int64_t sample) const +{ + PERFETTO_INTERNAL_TRACK_EVENT( + "counter", /*name=*/nullptr, + perfetto::protos::pbzero::TrackEvent::TYPE_COUNTER, track, + [&](perfetto::EventContext ctx) { + auto *event = ctx.event(); + event->set_counter_value(value); + }); +} + +bool qemu_counters_state::try_set(qemu_counter_id id, int64_t value) +{ + std::shared_lock lock(mutex); + auto it = counters.find(id); + if (it != counters.end()) { + it->second->value = value; + it->second->emit(value); + return false; + } + return true; +} + +boost::optional +qemu_counters_state::try_fetch_add(qemu_counter_id id, int64_t value) +{ + std::shared_lock lock(mutex); + auto it = counters.find(id); + if (it != counters.end()) { + value = it->second->value.fetch_add(value); + it->second->emit(value); + return value; + } + return boost::none; +} + +void qemu_counters_state::set(qemu_counter_id id, int64_t value) +{ + if (try_set(id, value)) { + /* Upgrade lock for insert */ + std::unique_lock lock(mutex); + auto it = counters.find(id); + if (it == counters.end()) { + auto counter = std::make_unique(id, value); + auto emplaced = counters.emplace(id, std::move(counter)); + it = emplaced.first; + } else { + it->second->value = value; + } + it->second->emit(value); + } +} + +int64_t qemu_counters_state::inc(qemu_counter_id id, int64_t value) +{ + auto result = try_fetch_add(id, value); + if (!result) { + /* Upgrade lock for insert */ + std::unique_lock lock(mutex); + auto it = counters.find(id); + if (it == counters.end()) { + auto counter = std::make_unique(id, value); + auto emplaced = counters.emplace(id, std::move(counter)); + it = emplaced.first; + } else { + value = it->second->value.fetch_add(value); + } + it->second->emit(value); + return value; + } + return result.value(); +} + +void global_counter_inc_emit(qemu_counter_id id, int64_t value) +{ + global_counters.inc(id, value); +} + +void global_counter_set_emit(qemu_counter_id id, int64_t value) +{ + global_counters.set(id, value); +} + +} // namespace cheri diff --git a/trace_extra/trace_counters.hh b/trace_extra/trace_counters.hh new file mode 100644 index 0000000000..ab3bd6c453 --- /dev/null +++ b/trace_extra/trace_counters.hh @@ -0,0 +1,112 @@ +/*- + * Copyright (c) 2022 Alfredo Mazzinghi + * All rights reserved. + * + * This software was developed by SRI International and the University of + * Cambridge Computer Laboratory (Department of Computer Science and + * Technology) under DARPA contract HR0011-18-C-0016 ("ECATS"), as part of the + * DARPA SSITH research programme. + * + * @BERI_LICENSE_HEADER_START@ + * + * Licensed to BERI Open Systems C.I.C. (BERI) under one or more contributor + * license agreements. See the NOTICE file distributed with this work for + * additional information regarding copyright ownership. BERI licenses this + * file to you under the BERI Hardware-Software License, Version 1.0 (the + * "License"); you may not use this file except in compliance with the + * License. You may obtain a copy of the License at: + * + * http://www.beri-open-systems.org/legal/license-1-0.txt + * + * Unless required by applicable law or agreed to in writing, Work distributed + * under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR + * CONDITIONS OF ANY KIND, either express or implied. See the License for the + * specific language governing permissions and limitations under the License. + * + * @BERI_LICENSE_HEADER_END@ + */ + +#pragma once + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "trace_extra/tuple_index.hh" + +namespace cheri +{ + +/* (counter_name, counter_slot) */ +using qemu_counter_id = std::tuple; + +/* + * Custom track representing a dynamically allocated counter. + * This is very similar to perfetto::CounterTrack but sadly it can not + * be subclassed cleanly, does not support dynamic naming and does not yet + * support incremental counters. + */ +class qemu_counter_track : public perfetto::Track +{ + const std::string name; + const unsigned int slot; + + public: + void Serialize(perfetto::protos::pbzero::TrackDescriptor *) const; + perfetto::protos::gen::TrackDescriptor Serialize() const; + qemu_counter_track(uint64_t uuid_, qemu_counter_id id); +}; + +struct qemu_counter { + qemu_counter_track track; + std::atomic value; + + void emit(int64_t sample) const; + qemu_counter(qemu_counter_id id, int64_t reset); + qemu_counter(const qemu_counter &other) = delete; + ~qemu_counter(); +}; + +/* + * Manage blocks of named counters. + * This can be reused at multiple levels: there is a global set of counters + * for events that are common to the system, a per-cpu set of counters that + * emit on the CPU tracks and a per-context set of counters that are context + * switched by the context manager and emit on the per-context counter tracks. + */ +class qemu_counters_state +{ + /* The lock only protects find, insert, remove. Value updates are done + * with atomics, so we do not need to get an exclusive lock to update + * counter values. + */ + std::shared_timed_mutex mutex; + std::unordered_map, + tuple_hasher> + counters; + + bool try_set(qemu_counter_id id, int64_t value); + boost::optional try_fetch_add(qemu_counter_id id, int64_t value); + + public: + qemu_counters_state() {} + + /* Set counter value or create new counter, emit the counter value */ + void set(qemu_counter_id id, int64_t value); + /* Increment counter value or create new counter, emit the counter value */ + int64_t inc(qemu_counter_id id, int64_t value); +}; + +/* Increment counter and emit value to trace, for incremental counter handling + */ +void global_counter_inc_emit(qemu_counter_id id, int64_t value); +/* Set counter value and emit, for absolute counter handling */ +void global_counter_set_emit(qemu_counter_id id, int64_t value); + +} // namespace cheri diff --git a/trace_extra/trace_perfetto.cc b/trace_extra/trace_perfetto.cc index 35d83f0b6c..503f4cc781 100644 --- a/trace_extra/trace_perfetto.cc +++ b/trace_extra/trace_perfetto.cc @@ -51,6 +51,7 @@ #include "exec/log_instr_internal.h" #include "exec/log_instr_perfetto.h" #include "trace_extra/trace_stats.hh" +#include "trace_extra/trace_counters.hh" #include "trace_extra/guest_context_tracker.hh" PERFETTO_TRACK_EVENT_STATIC_STORAGE(); @@ -59,6 +60,7 @@ namespace fs = boost::filesystem; namespace { +using namespace cheri; /* Tracing session pointer */ std::unique_ptr session; @@ -77,26 +79,26 @@ std::unique_ptr sched_track; */ struct perfetto_backend_data { // Per-CPU control track. This records tracing control events. - perfetto::Track ctrl_track_; + perfetto::Track ctrl_track; // Tracker that resolves the current context scheduled on a CPU - cheri::guest_context_tracker ctx_tracker_; + cheri::guest_context_tracker ctx_tracker; /* * Cached copy of the logging activation status. * It is easier to keep a cached copy here than exposing the loglevel_active * flag to the C++ interface. */ - bool loglevel_active_; + bool loglevel_active; perfetto_backend_data(int cpu_id) - : ctrl_track_(perfetto::Track::Global(cheri::gen_track_uuid())), - ctx_tracker_(cpu_id) + : ctrl_track(perfetto::Track::Global(cheri::gen_track_uuid())), + ctx_tracker(cpu_id) { std::string track_name("CPU " + std::to_string(cpu_id) + " ctrl"); - auto desc = ctrl_track_.Serialize(); + auto desc = ctrl_track.Serialize(); desc.set_name(track_name); - perfetto::TrackEvent::SetTrackDescriptor(ctrl_track_, desc); + perfetto::TrackEvent::SetTrackDescriptor(ctrl_track, desc); } }; @@ -144,6 +146,11 @@ bool perfetto_start_tracing(void) session->Setup(cfg); session->StartBlocking(); + /* + * XXX there something wrong with initialization as we still emit a QEMU + * process and thread tracks. Would be nice to avoid that. + */ + perfetto::ProcessTrack qemu_proc = perfetto::ProcessTrack::Current(); auto desc = qemu_proc.Serialize(); desc.mutable_process()->set_process_name("qemu"); @@ -176,12 +183,88 @@ void trace_cap_register(perfetto::protos::pbzero::QEMULogEntryCapability *cap, cap->set_otype(perfetto_cap_otype(chandle)); } +/* + * Handle tracing control event. Returns true if the event changes the trace + * enable state (i.e. start or stop). + */ +bool process_state_event(perfetto_backend_data *data, log_event_t *evt) +{ + bool has_startstop_event = false; + auto *state = data->ctx_tracker.get_ctx_state(); + + switch (evt->state.next_state) { + case LOG_EVENT_STATE_FLUSH: + TRACE_EVENT_INSTANT("ctrl", "flush", data->ctrl_track); + data->ctx_tracker.flush_all_ctx_data(); + perfetto::TrackEvent::Flush(); + break; + case LOG_EVENT_STATE_START: + state->stats.unpause(*state->get_track(), evt->state.pc); + TRACE_EVENT_BEGIN("ctrl", "tracing", data->ctrl_track); + has_startstop_event = true; + break; + case LOG_EVENT_STATE_STOP: + state->stats.pause(*state->get_track(), evt->state.pc); + TRACE_EVENT_END("ctrl", data->ctrl_track); + has_startstop_event = true; + break; + default: + assert(false && "Invalid state event"); + } + return has_startstop_event; +} + +/* + * Handle context switch events + */ +void process_context_event(perfetto_backend_data *data, + cpu_log_entry_handle entry, log_event_t *evt) +{ + auto *state = data->ctx_tracker.get_ctx_state(); + + /* Swap current context. */ + if (evt->ctx_update.op == LOG_EVENT_CTX_OP_SWITCH) { + state->stats.pause(*state->get_track(), perfetto_log_entry_pc(entry)); + data->ctx_tracker.context_update(&evt->ctx_update); + /* Reload data and track as context_update will have changed them */ + state = data->ctx_tracker.get_ctx_state(); + state->stats.unpause(*state->get_track(), perfetto_log_entry_pc(entry)); + } +} + +/* + * Handle trace markers. + * These are always emitted on the CPU tracks. + */ +void process_marker_event(perfetto_backend_data *data, log_event_t *evt) +{ + auto *cpu_state = data->ctx_tracker.get_cpu_state(); + + TRACE_EVENT_INSTANT("marker", "guest", *cpu_state->get_track(), + [&](perfetto::EventContext ctx) { + auto *qemu_arg = ctx.event()->set_qemu(); + qemu_arg->set_marker(evt->marker); + }); +} + +/* + * Handle counters. + */ +void process_counter_event(perfetto_backend_data *data, log_event_t *evt) +{ + qemu_counter_id cnt_id = std::make_tuple( + evt->counter.name, log_event_counter_slot(evt->counter.flags)); + if (log_event_counter_incremental(evt->counter.flags)) { + global_counter_inc_emit(cnt_id, evt->counter.value); + } else { + global_counter_set_emit(cnt_id, evt->counter.value); + } +} + void process_events(perfetto_backend_data *data, cpu_log_entry_handle entry) { int nevents = perfetto_log_entry_events(entry); - bool have_startstop_event = false; - auto *ctx_data = &data->ctx_tracker_.get_ctx_data(); - auto *ctx_track = &data->ctx_tracker_.get_ctx_track(); + bool has_startstop_event = false; /* * Note: LOG_EVENT_STATE events are emitted even when tracing is disabled. @@ -190,65 +273,37 @@ void process_events(perfetto_backend_data *data, cpu_log_entry_handle entry) for (int i = 0; i < nevents; i++) { log_event_t *evt = perfetto_log_event(entry, i); switch (evt->id) { - case LOG_EVENT_STATE: { - switch (evt->state.next_state) { - case LOG_EVENT_STATE_FLUSH: - TRACE_EVENT_INSTANT("ctrl", "flush", data->ctrl_track_); - data->ctx_tracker_.flush_all_ctx_data(); - perfetto::TrackEvent::Flush(); - break; - case LOG_EVENT_STATE_START: - ctx_data->stats.unpause(*ctx_track, evt->state.pc); - TRACE_EVENT_BEGIN("ctrl", "tracing", data->ctrl_track_); - have_startstop_event = true; - break; - case LOG_EVENT_STATE_STOP: - ctx_data->stats.pause(*ctx_track, evt->state.pc); - TRACE_EVENT_END("ctrl", data->ctrl_track_); - have_startstop_event = true; - break; - default: - assert(false && "Invalid state event"); - } - } break; - case LOG_EVENT_CTX_UPDATE: { - /* Swap current context. */ - if (evt->ctx_update.op == LOG_EVENT_CTX_OP_SWITCH) { - ctx_data->stats.pause(*ctx_track, perfetto_log_entry_pc(entry)); - data->ctx_tracker_.context_update(&evt->ctx_update); - /* Reload data and track as context_update will have changed - * them */ - ctx_data = &data->ctx_tracker_.get_ctx_data(); - ctx_track = &data->ctx_tracker_.get_ctx_track(); - ctx_data->stats.unpause(*ctx_track, - perfetto_log_entry_pc(entry)); - } - } break; - case LOG_EVENT_MARKER: { - auto cpu_track = data->ctx_tracker_.get_cpu_track(); - TRACE_EVENT_INSTANT("marker", "guest", cpu_track, - [&](perfetto::EventContext ctx) { - auto *qemu_arg = ctx.event()->set_qemu(); - qemu_arg->set_marker(evt->marker); - }); - } break; + case LOG_EVENT_STATE: + has_startstop_event = process_state_event(data, evt); + break; + case LOG_EVENT_CTX_UPDATE: + process_context_event(data, entry, evt); + break; + case LOG_EVENT_MARKER: + process_marker_event(data, evt); + break; case LOG_EVENT_REGDUMP: break; + case LOG_EVENT_COUNTER: + process_counter_event(data, evt); + break; default: assert(false && "Invalid event identifier"); } } + auto *state = data->ctx_tracker.get_ctx_state(); + if (perfetto_log_entry_flags(entry) & LI_FLAG_MODE_SWITCH) { auto mode = cheri::qemu_cpu_mode_to_trace( perfetto_log_entry_next_cpu_mode(entry)); // XXX-AM: consider making the mode switch an event, possibly with its // own separate pc signaling the PC of the next instruction we are // landing to? - ctx_data->stats.pause(*ctx_track, perfetto_log_entry_pc(entry)); - data->ctx_tracker_.mode_update(mode); - ctx_data = &data->ctx_tracker_.get_ctx_data(); - ctx_track = &data->ctx_tracker_.get_ctx_track(); - ctx_data->stats.unpause(*ctx_track, perfetto_log_entry_pc(entry)); + state->stats.pause(*state->get_track(), perfetto_log_entry_pc(entry)); + data->ctx_tracker.mode_update(mode); + /* reload possibly updated state and track */ + state = data->ctx_tracker.get_ctx_state(); + state->stats.unpause(*state->get_track(), perfetto_log_entry_pc(entry)); } /* @@ -257,9 +312,9 @@ void process_events(perfetto_backend_data *data, cpu_log_entry_handle entry) * histograms. This avoids having to keep a shadow copy of the tracing state * in the backend. */ - if (!have_startstop_event && + if (!has_startstop_event && (perfetto_log_entry_flags(entry) & LI_FLAG_HAS_INSTR_DATA) != 0) - ctx_data->stats.process_instr(*ctx_track, entry); + state->stats.process_instr(*state->get_track(), entry); } void process_instr(perfetto_backend_data *data, cpu_log_entry_handle entry) @@ -270,8 +325,9 @@ void process_instr(perfetto_backend_data *data, cpu_log_entry_handle entry) * same track/category: e.g. mode swtich, interrupt information and modified * registers? */ + auto *state = data->ctx_tracker.get_ctx_state(); TRACE_EVENT_INSTANT( - "instructions", "stream", data->ctx_tracker_.get_ctx_track(), + "instructions", "stream", *state->get_track(), [&](perfetto::EventContext ctx) { auto *qemu_arg = ctx.event()->set_qemu(); auto *instr = qemu_arg->set_instr();