diff --git a/ipemu/csrc/elf.cc b/ipemu/csrc/elf.cc index 223783cf04..c6a1e3f402 100644 --- a/ipemu/csrc/elf.cc +++ b/ipemu/csrc/elf.cc @@ -2,40 +2,126 @@ #include #include +#include -simple_sim::load_elf_result_t simple_sim::load_elf(const std::string &fname) { +// convert little-endian integral type to host-endian +template +T from_le(T value) { + static_assert(std::is_integral::value, "T must be an integral type"); + + if constexpr (sizeof(T) == 1) { + return value; + } else if constexpr (sizeof(T) == 2) { + return le16toh(value); + } else if constexpr (sizeof(T) == 4) { + return le32toh(value); + } else if constexpr (sizeof(T) == 8) { + return le64toh(value); + } else { + static_assert(sizeof(T) <= 8, "Unsupported type size"); + } +} + +void copy_from_fs(std::ifstream &ifs, std::streamoff offset, std::streamoff size, void *dst) { + ifs.clear(); + ifs.seekg(offset); + ifs.read(reinterpret_cast(dst), size); +} + +template +T read_from_fs(std::ifstream &ifs, std::streamoff offset) { + T t{}; + copy_from_fs(ifs, offset, sizeof(T), &t); + return t; +} + +simple_sim::load_elf_result_t simple_sim::load_elf32_little_endian(const std::string &fname) { try { std::ifstream fs(fname, std::ios::binary); fs.exceptions(std::ios::failbit); - Elf32_Ehdr ehdr; - fs.read(reinterpret_cast(&ehdr), sizeof(ehdr)); - CHECK(ehdr.e_machine == EM_RISCV && ehdr.e_type == ET_EXEC && - ehdr.e_ident[EI_CLASS] == ELFCLASS32, - "ehdr check failed when loading elf"); - CHECK_EQ(ehdr.e_phentsize, sizeof(elf32_phdr), - "ehdr.e_phentsize does not equal to elf32_phdr"); - - for (size_t i = 0; i < ehdr.e_phnum; i++) { - auto phdr_offset = ehdr.e_phoff + i * ehdr.e_phentsize; - Elf32_Phdr phdr; - fs.seekg((long)phdr_offset) - .read(reinterpret_cast(&phdr), sizeof(phdr)); - if (phdr.p_type == PT_LOAD) { - CHECK(phdr.p_paddr + phdr.p_filesz < mem_size, + auto ehdr = read_from_fs(fs, 0); + CHECK(std::memcmp(ehdr.e_ident, ELFMAG, SELFMAG) == 0, "elf magic not match"); + CHECK(ehdr.e_machine == EM_RISCV, "elf not in RISCV"); + CHECK(ehdr.e_type == ET_EXEC, "elf not executable"); + CHECK(ehdr.e_ident[EI_DATA] == ELFDATA2LSB, "elf not little endian"); + CHECK(ehdr.e_ident[EI_CLASS] == ELFCLASS32, "elf not in 32bit"); + + for (size_t i = 0; i < from_le(ehdr.e_phnum); i++) { + auto phdr_offset = from_le(ehdr.e_phoff) + i * from_le(ehdr.e_phentsize); + auto phdr = read_from_fs(fs, (std::streamoff) phdr_offset); + if (from_le(phdr.p_type) == PT_LOAD) { + auto paddr = from_le(phdr.p_paddr); + auto filesz = from_le(phdr.p_filesz); + + CHECK(paddr + filesz < mem_size, "phdr p_paddr + p_filesz check failed"); - fs.seekg((long)phdr.p_offset) - .read(reinterpret_cast(&mem[phdr.p_paddr]), phdr.p_filesz); - Log("LoadElfResult") - .with("segment", i) - .with("phdr_offset", fmt::format("{:08X}", phdr.p_offset)) - .with("paddr_range", fmt::format("{:08X}-{:08X}", phdr.p_paddr, - phdr.p_paddr + phdr.p_memsz)) - .trace(); + fs.clear(); + fs.seekg(from_le(phdr.p_offset)) + .read(reinterpret_cast(&mem[paddr]), filesz); + Log("LoadElf") + .with("segment", i) + .with("phdr_offset", fmt::format("{:08X}", phdr.p_offset)) + .with("paddr_range", fmt::format("{:08X}-{:08X}", phdr.p_paddr, + phdr.p_paddr + phdr.p_memsz)) + .warn(); } } + + // read section string section + auto shoff = from_le(ehdr.e_shoff); + auto shentsize = from_le(ehdr.e_shentsize); + auto shstrndx = from_le(ehdr.e_shstrndx); + auto section_string_shdr_offset = shoff + shstrndx * shentsize; + auto section_string_shdr = read_from_fs(fs, section_string_shdr_offset); + std::vector section_string_table(from_le(section_string_shdr.sh_size)); + copy_from_fs(fs, + from_le(section_string_shdr.sh_offset), + from_le(section_string_shdr.sh_size), + section_string_table.data()); + + // iterate over section headers to find the symbol string table + std::vector string_table; + for (int i = 0; i < from_le(ehdr.e_shnum); ++i) { + auto shdr = read_from_fs(fs, shoff + i * shentsize); + if (from_le(shdr.sh_type) == SHT_STRTAB && + std::string(§ion_string_table[from_le(shdr.sh_name)]) == ".strtab") { + Log("size").with("size", shdr.sh_size).warn(); + string_table.resize(from_le(shdr.sh_size)); + copy_from_fs(fs, from_le(shdr.sh_offset), from_le(shdr.sh_size), string_table.data()); + } + } + + if (string_table.empty()) { + Log("LoadElf").warn("failed to find .strtab"); + } else { + // iterate over section headers to find the symbol table + for (int i = 0; i < from_le(ehdr.e_shnum); ++i) { + auto shdr = read_from_fs(fs, shoff + i * shentsize); + if (from_le(shdr.sh_type) == SHT_SYMTAB && std::string(§ion_string_table[shdr.sh_name]) == ".symtab") { + auto entsize = from_le(shdr.sh_entsize); + unsigned int num_sym = from_le(shdr.sh_size) / entsize; + for (int j = 0; j < num_sym; ++j) { + auto offset = from_le(shdr.sh_offset) + j * entsize; + auto sym = read_from_fs(fs, (std::streamoff) offset); + + if (ELF32_ST_TYPE(from_le(sym.st_info)) == STT_FUNC) { // Only considering function symbols + // read the name from the string table + std::string name(&string_table.at(from_le(sym.st_name))); + function_symtab[from_le(sym.st_value)] = {.name = name, .info = from_le(sym.st_info)}; // Add to map + } + } + break; + } + } + } + return {.entry_addr = ehdr.e_entry}; - } catch (std::ios_base::failure &) { - throw std::system_error{errno, std::generic_category(), fname}; + } catch (std::ios_base::failure &f) { + Log("LoadElf") + .with("errno", errno) + .with("fname", fname) + .with("reason", f.what()) + .fatal(); } } diff --git a/ipemu/csrc/simple_sim.h b/ipemu/csrc/simple_sim.h index d9063b8c68..175350baeb 100644 --- a/ipemu/csrc/simple_sim.h +++ b/ipemu/csrc/simple_sim.h @@ -15,6 +15,12 @@ class simple_sim : public simif_t { uartlite uart; reg_t uart_addr = 0x10000000; + struct function_sym { + std::string name; + uint8_t info; + }; + std::map function_symtab; + public: explicit simple_sim(size_t mem_size) : mem_size(mem_size) { mem = new char[mem_size]; @@ -25,7 +31,8 @@ class simple_sim : public simif_t { struct load_elf_result_t { uint32_t entry_addr; }; - load_elf_result_t load_elf(const std::string &fname); + + load_elf_result_t load_elf32_little_endian(const std::string &fname); // should return NULL for MMIO addresses char *addr_to_mem(reg_t addr) override { @@ -71,5 +78,12 @@ class simple_sim : public simif_t { // maybe nothing to do } - const char *get_symbol(uint64_t addr) override { FATAL("Unimplemented"); } + const char *get_symbol(uint64_t addr) override { + auto find = this->function_symtab.find(addr); + if (find != this->function_symtab.end()) { + return find->second.name.c_str(); + } else { + return nullptr; + } + } }; diff --git a/ipemu/csrc/spdlog_ext.cc b/ipemu/csrc/spdlog_ext.cc index 75822d2378..21c91ac5ce 100644 --- a/ipemu/csrc/spdlog_ext.cc +++ b/ipemu/csrc/spdlog_ext.cc @@ -60,6 +60,7 @@ ConsoleSink::ConsoleSink() { whitelist = get_set_from_env("EMULATOR_LOG_WHITELIST", ','); whitelist.insert("DPIInitCosim"); whitelist.insert("SpikeStep"); + whitelist.insert("FunctionCall"); whitelist.insert("SimulationExit"); whitelist.insert("DPIPeekIssue"); whitelist.insert("DPIPokeInst"); @@ -75,6 +76,10 @@ inline bool ConsoleSink::is_module_enabled(const std::string &module) { void ConsoleSink::sink_it_(const spdlog::details::log_msg &msg) { json payload = json::parse(msg.payload); + if (msg.level < this->level()) { + return; + } + // filter message matching the current level if (msg.level == this->level()) { if (!is_module_enabled(payload["_module"])) return; @@ -82,37 +87,45 @@ void ConsoleSink::sink_it_(const spdlog::details::log_msg &msg) { fmt::text_style level_color; switch (msg.level) { - case spdlog::level::debug: - case spdlog::level::trace: - level_color = fmt::fg(fmt::color::gray); - break; - case spdlog::level::info: - level_color = fmt::fg(fmt::color::white); - break; - case spdlog::level::warn: - level_color = fmt::fg(fmt::color::yellow); - break; - case spdlog::level::err: - level_color = fmt::fg(fmt::color::red); + case spdlog::level::debug: + case spdlog::level::trace: + level_color = fmt::fg(fmt::color::gray); + break; + case spdlog::level::info: + level_color = fmt::fg(fmt::color::white); + break; + case spdlog::level::warn: + level_color = fmt::fg(fmt::color::yellow); + break; + case spdlog::level::err: + level_color = fmt::fg(fmt::color::red); + break; + case spdlog::level::critical: + level_color = fmt::bg(fmt::color::red) | fmt::fg(fmt::color::white); + break; + default: + level_color = fmt::fg(fmt::color::white); break; - case spdlog::level::critical: - level_color = fmt::bg(fmt::color::red) | fmt::fg(fmt::color::white); - break; - default: - level_color = fmt::fg(fmt::color::white); - break; } std::cerr << fmt::format("{} {}", fmt::styled(payload["_cycle"].get(), level_color), fmt::styled(payload["_module"].get(), fmt::fg(fmt::color::violet)) - ); + ); if (payload.contains("_msg")) { std::cerr << fmt::format(" {}", fmt::styled(payload["_msg"].get(), fmt::fg(fmt::color::green))); } if (payload.contains("_with")) { std::cerr << fmt::format(" {}", fmt::styled(payload["_with"].dump(), fmt::fg(fmt::color::gray))); } + if (msg.level > spdlog::level::err) { + std::cerr << "\n"; + const auto frames = vbridge_impl_instance.frames; + for (auto frame = frames.rbegin(); frame != frames.rend(); frame++) { + std::cerr << fmt::format(fmt::fg(fmt::color::gray), " call by {}(...) at {:08X}\n", + frame->func_name, frame->func_addr); + } + } std::cerr << "\n"; } @@ -160,7 +173,7 @@ JsonLogger::JsonLogger(bool no_logging, bool no_file_logging, bool no_console_lo } } -JsonLogger::JsonLogger(): do_logging(false) { } +JsonLogger::JsonLogger() : do_logging(false) {} // We can only implement a class method with template inside the class // declaration diff --git a/ipemu/csrc/vbridge_impl.cc b/ipemu/csrc/vbridge_impl.cc index c4eeb78bdf..93636925a4 100644 --- a/ipemu/csrc/vbridge_impl.cc +++ b/ipemu/csrc/vbridge_impl.cc @@ -40,7 +40,7 @@ void VBridgeImpl::dpiInitCosim() { proc.get_state()->sstatus->write(proc.get_state()->sstatus->read() | SSTATUS_VS | SSTATUS_FS); - auto load_result = sim.load_elf(bin); + auto load_result = sim.load_elf32_little_endian(bin); proc.get_state()->pc = load_result.entry_addr; @@ -369,6 +369,7 @@ std::optional VBridgeImpl::spike_step() { clear_state(proc); + reg_t old_pc = state->pc; reg_t new_pc; if (event) { auto &se = event.value(); @@ -386,13 +387,39 @@ std::optional VBridgeImpl::spike_step() { new_pc = fetch.func(&proc, fetch.insn, state->pc); se.log_arch_changes(); } else { + auto disasm = proc.get_disassembler()->disassemble(fetch.insn); Log("SpikeStep") .with("pc", fmt::format("{:08X}", state->pc)) .with("bits", fmt::format("{:08X}", fetch.insn.bits())) - .with("disasm", proc.get_disassembler()->disassemble(fetch.insn)) + .with("disasm", disasm) .with("spike_cycles", spike_cycles) .info("spike run scalar insn"); new_pc = fetch.func(&proc, fetch.insn, state->pc); + + if (disasm == "ret" && new_pc == frames.back().return_addr) { + Log("FunctionCall") + .with("old_pc", fmt::format("{:08X}", old_pc)) + .with("new_pc", fmt::format("{:08X}", new_pc)) + .with("spike_cycles", spike_cycles) + .with("depth", frames.size()) + .info("return"); + frames.pop_back(); + } + } + + if (new_pc - state->pc != 2 && new_pc - state->pc != 4) { + auto sym_find = sim.get_symbol(new_pc); + if (sym_find != nullptr) { + Log("FunctionCall") + .with("func_name", sym_find) + .with("old_pc", fmt::format("{:08X}", old_pc)) + .with("new_pc", fmt::format("{:08X}", new_pc)) + .with("spike_cycles", spike_cycles) + .with("depth", frames.size()) + .info("call"); + reg_t return_addr = state->XPR[1]; + frames.emplace_back(CallFrame{sym_find, new_pc, return_addr, spike_cycles}); + } } // Bypass CSR insns commitlog stuff. diff --git a/ipemu/csrc/vbridge_impl.h b/ipemu/csrc/vbridge_impl.h index d560e8fe04..64e0652048 100644 --- a/ipemu/csrc/vbridge_impl.h +++ b/ipemu/csrc/vbridge_impl.h @@ -265,6 +265,15 @@ class VBridgeImpl { int64_t spike_cycles = 0; + struct CallFrame { + std::string func_name; + reg_t func_addr; + reg_t return_addr; + int64_t spike_cycle; + }; + std::vector frames; + friend class ConsoleSink; + std::optional create_spike_event(insn_fetch_t fetch); std::optional spike_step();