Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[emulator] improve emulator logging performance #333

Closed
wants to merge 2 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
62 changes: 31 additions & 31 deletions .github/passed/v1024l8b2-test/debug/passed.json
Original file line number Diff line number Diff line change
Expand Up @@ -144,16 +144,16 @@
"vluxseg8ei16.v-codegen": 10673,
"vluxseg8ei32.v-codegen": 5350,
"vluxseg8ei8.v-codegen": 19493,
"vmacc.vv-codegen": 43678,
"vmacc.vx-codegen": 119289,
"vmacc.vv-codegen": 43680,
"vmacc.vx-codegen": 116642,
"vmadc.vi-codegen": 52084,
"vmadc.vim-codegen": 50942,
"vmadc.vv-codegen": 16267,
"vmadc.vvm-codegen": 18182,
"vmadc.vx-codegen": 67405,
"vmadc.vxm-codegen": 73757,
"vmadd.vv-codegen": 43678,
"vmadd.vx-codegen": 119289,
"vmadd.vv-codegen": 43680,
"vmadd.vx-codegen": 116642,
"vmand.mm-codegen": 15637,
"vmandn.mm-codegen": 15637,
"vmax.vv-codegen": 38466,
Expand Down Expand Up @@ -200,14 +200,14 @@
"vmsne.vv-codegen": 39939,
"vmsne.vx-codegen": 144294,
"vmsof.m-codegen": 1007,
"vmul.vv-codegen": 38550,
"vmul.vx-codegen": 159646,
"vmulh.vv-codegen": 38550,
"vmulh.vx-codegen": 159646,
"vmulhsu.vv-codegen": 38550,
"vmulhsu.vx-codegen": 159646,
"vmulhu.vv-codegen": 38550,
"vmulhu.vx-codegen": 159646,
"vmul.vv-codegen": 38466,
"vmul.vx-codegen": 155966,
"vmulh.vv-codegen": 38466,
"vmulh.vx-codegen": 155966,
"vmulhsu.vv-codegen": 38466,
"vmulhsu.vx-codegen": 155966,
"vmulhu.vv-codegen": 38466,
"vmulhu.vx-codegen": 155966,
"vmv.s.x-codegen": 759,
"vmv.v.i-codegen": 25764,
"vmv.v.v-codegen": 11858,
Expand All @@ -225,10 +225,10 @@
"vnclipu.wi-codegen": 61631,
"vnclipu.wv-codegen": 18337,
"vnclipu.wx-codegen": 84824,
"vnmsac.vv-codegen": 43678,
"vnmsac.vx-codegen": 119289,
"vnmsub.vv-codegen": 43678,
"vnmsub.vx-codegen": 119289,
"vnmsac.vv-codegen": 43680,
"vnmsac.vx-codegen": 116642,
"vnmsub.vv-codegen": 43680,
"vnmsub.vx-codegen": 116642,
"vnsra.wi-codegen": 61631,
"vnsra.wv-codegen": 18337,
"vnsra.wx-codegen": 84824,
Expand Down Expand Up @@ -286,8 +286,8 @@
"vsll.vv-codegen": 38550,
"vsll.vx-codegen": 118978,
"vsm.v-codegen": 276,
"vsmul.vv-codegen": 38550,
"vsmul.vx-codegen": 118978,
"vsmul.vv-codegen": 38466,
"vsmul.vx-codegen": 116398,
"vsoxei16.v-codegen": 16092,
"vsoxei32.v-codegen": 11996,
"vsoxei8.v-codegen": 21779,
Expand Down Expand Up @@ -407,19 +407,19 @@
"vwaddu.vx-codegen": 89464,
"vwaddu.wv-codegen": 22975,
"vwaddu.wx-codegen": 108533,
"vwmacc.vv-codegen": 28732,
"vwmacc.vx-codegen": 107197,
"vwmaccsu.vv-codegen": 28732,
"vwmaccsu.vx-codegen": 107197,
"vwmaccu.vv-codegen": 28732,
"vwmaccu.vx-codegen": 107197,
"vwmaccus.vx-codegen": 107197,
"vwmul.vv-codegen": 20180,
"vwmul.vx-codegen": 127420,
"vwmulsu.vv-codegen": 20180,
"vwmulsu.vx-codegen": 127420,
"vwmulu.vv-codegen": 20180,
"vwmulu.vx-codegen": 127420,
"vwmacc.vv-codegen": 28702,
"vwmacc.vx-codegen": 106982,
"vwmaccsu.vv-codegen": 28702,
"vwmaccsu.vx-codegen": 106982,
"vwmaccu.vv-codegen": 28702,
"vwmaccu.vx-codegen": 106982,
"vwmaccus.vx-codegen": 106982,
"vwmul.vv-codegen": 20212,
"vwmul.vx-codegen": 127468,
"vwmulsu.vv-codegen": 20212,
"vwmulsu.vx-codegen": 127468,
"vwmulu.vv-codegen": 20212,
"vwmulu.vx-codegen": 127468,
"vwredsum.vs-codegen": 19461,
"vwredsumu.vs-codegen": 19461,
"vwsub.vv-codegen": 20212,
Expand Down
135 changes: 8 additions & 127 deletions emulator/src/spdlog-ext.cc
Original file line number Diff line number Diff line change
Expand Up @@ -8,106 +8,8 @@
#include <sstream>
#include <string>

#include <spdlog/async.h>
#include <spdlog/common.h>
#include <spdlog/sinks/basic_file_sink.h>
#include <spdlog/sinks/stdout_sinks.h>
#include <spdlog/spdlog.h>

#include "spdlog-ext.h"

/**
* Get environment variable by the given `env` key or fallback to a default
* value.
*/
std::string getenv_or(const char *env, std::string fallback) {
char *env_var = std::getenv(env);
if (env_var && strlen(env_var) > 0) {
return std::string{env_var};
}

return fallback;
}

/**
* Get environment variable and split them into std::vector by the given
* `delimiter`
*/
std::set<std::string> get_set_from_env(const char *env, const char delimiter) {
std::set<std::string> set;

auto raw = getenv_or(env, "");
if (raw.empty()) {
return set;
}

std::stringstream ss(raw);
std::string token;
// Use `delimiter` instead of '\n' to split element in string.
while (std::getline(ss, token, delimiter)) {
set.insert(token);
}

return set;
}

/**
* Filter logging message by module type. Filter should be set by environment
* `EMULATOR_BLACKLIST_MODULE` and `EMULATOR_WHITELIST_MODULE`. Module should be
* separate by column `,`. When you set both env, only blacklist will have
* effect.
*/
class ConsoleSink : public spdlog::sinks::base_sink<std::mutex> {
private:
std::set<std::string> blacklist;
std::set<std::string> whitelist;

bool is_expected_module(std::string &module) {
if (!blacklist.empty() && blacklist.find(module) != blacklist.end()) {
return false;
}
if (!whitelist.empty() && whitelist.find(module) == whitelist.end()) {
return false;
}

return true;
}

public:
ConsoleSink()
: blacklist{get_set_from_env("EMULATOR_BLACKLIST_MODULE", ',')},
whitelist{get_set_from_env("EMULATOR_WHITELIST_MODULE", ',')} {}

protected:
void sink_it_(const spdlog::details::log_msg &msg) override {
auto data = std::string(msg.payload.data(), msg.payload.size());
// Don't touch error message
if (msg.level == spdlog::level::info) {
std::string module_name;
try {
json payload = json::parse(data);
payload["name"].get_to(module_name);
} catch (const json::parse_error &ex) {
throw std::runtime_error(
fmt::format("Fail to convert msg {} to json: {}", data, ex.what()));
} catch (const json::type_error &ex) {
throw std::runtime_error(
fmt::format("Fail to get field name from: {}", data));
}

if (!is_expected_module(module_name)) {
return;
}
}

spdlog::memory_buf_t formatted;
spdlog::sinks::base_sink<std::mutex>::formatter_->format(msg, formatted);
// stdout will be captured by mill, so we need to print them into stderr
std::cerr << fmt::to_string(formatted);
}

void flush_() override { std::cerr << std::flush; }
};
#include "vbridge_impl.h"

/**
* Create two logging sink, one for creating JSON format logging file, another
Expand All @@ -117,36 +19,11 @@ class ConsoleSink : public spdlog::sinks::base_sink<std::mutex> {
void setup_logger() {
std::string log_path = getenv_or("EMULATOR_LOG_PATH", "emulator-log.json");

// Pre-process the file so that after program exit, it can be a valid JSON
// array.
spdlog::file_event_handlers f_handlers;
f_handlers.after_open = [](spdlog::filename_t _, std::FILE *fstream) {
fputs("[\n", fstream);
};
f_handlers.after_close = [](spdlog::filename_t log_path) {
std::ifstream old_log_file(log_path);
std::ofstream temp_file("temp-log.json");
std::string line;
while (std::getline(old_log_file, line)) {
temp_file << line;
}
// Drop the last ','
temp_file.seekp(-1, std::ios::cur);
temp_file.write("]\n", 2);
temp_file.close();
old_log_file.close();
std::filesystem::rename("temp-log.json", log_path);
};
auto file_sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>(
log_path, /*truncate=*/true, f_handlers);
// Basic logging information, other data are nested in the `log` attribute
// set.
file_sink->set_pattern(
"{ \"timestamp\": \"%E\", \"level\": \"%l\", \"log\": %v },");
auto file_sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>(log_path, /*truncate=*/true);
file_sink->set_pattern("%v");

auto console_sink = std::make_shared<ConsoleSink>();
// %T: "23:55:59" (We don't need other information.)
console_sink->set_pattern("%T %v");
console_sink->set_pattern("- %v");

// One thread with 8192 queue size
spdlog::init_thread_pool(8192, 1);
Expand All @@ -169,3 +46,7 @@ void setup_logger() {

return;
}

uint64_t JsonLogger::get_cycle() {
return vbridge_impl_instance.get_t();
}
Loading