Skip to content

Commit

Permalink
Add ability to log from the tracing layer directly rather than use XPTI
Browse files Browse the repository at this point in the history
  • Loading branch information
@callumfare
callumfare committed May 22, 2024
1 parent 0b302e6 commit 66706a2
Show file tree
Hide file tree
Showing 7 changed files with 1,356 additions and 30 deletions.
10 changes: 10 additions & 0 deletions scripts/templates/trcddi.cpp.mako
View file
Original file line number Diff line number Diff line change
Expand Up @@ -45,10 +45,16 @@ namespace ur_tracing_layer
${th.make_pfncb_param_type(n, tags, obj)} params = { &${",&".join(th.make_param_lines(n, tags, obj, format=["name"]))} };
uint64_t instance = context.notify_begin(${th.make_func_etor(n, tags, obj)}, "${th.make_func_name(n, tags, obj)}", &params);

context.logger.info("---> ${th.make_func_name(n, tags, obj)}");

${x}_result_t result = ${th.make_pfn_name(n, tags, obj)}( ${", ".join(th.make_param_lines(n, tags, obj, format=["name"]))} );

context.notify_end(${th.make_func_etor(n, tags, obj)}, "${th.make_func_name(n, tags, obj)}", &params, &result, instance);

std::ostringstream args_str;
ur::extras::printFunctionParams(args_str, ${th.make_func_etor(n, tags, obj)}, &params);
context.logger.info("({}) -> {};\n", args_str.str(), result);

return result;
}
%if 'condition' in obj:
Expand Down Expand Up @@ -112,6 +118,10 @@ namespace ur_tracing_layer
return result;
}

// Recreate the logger in case env variables have been modified between
// program launch and the call to `urLoaderInit`
logger = logger::create_logger("tracing", true, true);

ur_tracing_layer::context.codelocData = codelocData;

%for tbl in th.get_pfntables(specs, meta, n, tags):
Expand Down
21 changes: 12 additions & 9 deletions source/common/logger/ur_logger.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,8 @@

namespace logger {

Logger create_logger(std::string logger_name, bool skip_prefix = false);
Logger create_logger(std::string logger_name, bool skip_prefix = false,
bool skip_linebreak = false);

inline Logger &get_logger(std::string name = "common") {
static Logger logger = create_logger(std::move(name));
Expand Down Expand Up @@ -105,7 +106,8 @@ template <typename T> inline std::string toHex(T t) {
/// - flush level: error, meaning that only error messages are guaranteed
/// to be printed immediately as they occur
/// - output: stderr
inline Logger create_logger(std::string logger_name, bool skip_prefix) {
inline Logger create_logger(std::string logger_name, bool skip_prefix,
bool skip_linebreak) {
std::transform(logger_name.begin(), logger_name.end(), logger_name.begin(),
::toupper);
std::stringstream env_var_name;
Expand All @@ -121,7 +123,7 @@ inline Logger create_logger(std::string logger_name, bool skip_prefix) {
auto map = getenv_to_map(env_var_name.str().c_str());
if (!map.has_value()) {
return Logger(std::make_unique<logger::StderrSink>(
std::move(logger_name), skip_prefix));
std::move(logger_name), skip_prefix, skip_linebreak));
}

auto kv = map->find("level");
Expand Down Expand Up @@ -150,19 +152,20 @@ inline Logger create_logger(std::string logger_name, bool skip_prefix) {
<< map->begin()->first
<< "'. Default logger options are set.";
return Logger(std::make_unique<logger::StderrSink>(
std::move(logger_name), skip_prefix));
std::move(logger_name), skip_prefix, skip_linebreak));
}

sink =
values.size() == 2
? sink_from_str(logger_name, values[0], values[1], skip_prefix)
: sink_from_str(logger_name, values[0], "", skip_prefix);
sink = values.size() == 2
? sink_from_str(logger_name, values[0], values[1],
skip_prefix, skip_linebreak)
: sink_from_str(logger_name, values[0], "", skip_prefix,
skip_linebreak);
} catch (const std::invalid_argument &e) {
std::cerr << "Error when creating a logger instance from the '"
<< env_var_name.str() << "' environment variable:\n"
<< e.what() << std::endl;
return Logger(std::make_unique<logger::StderrSink>(
std::move(logger_name), skip_prefix));
std::move(logger_name), skip_prefix, skip_linebreak));
}
sink->setFlushLevel(flush_level);

Expand Down
1 change: 1 addition & 0 deletions source/common/logger/ur_logger_details.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ class Logger {
Logger(logger::Level level, std::unique_ptr<logger::Sink> sink)
: level(level), sink(std::move(sink)) {}

Logger &operator=(Logger &&) = default;
~Logger() = default;

void setLevel(logger::Level level) { this->level = level; }
Expand Down
51 changes: 32 additions & 19 deletions source/common/logger/ur_sinks.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,8 +39,10 @@ class Sink {
std::ostream *ostream;
logger::Level flush_level;

Sink(std::string logger_name, bool skip_prefix = false)
: logger_name(std::move(logger_name)), skip_prefix(skip_prefix) {
Sink(std::string logger_name, bool skip_prefix = false,
bool skip_linebreak = false)
: logger_name(std::move(logger_name)), skip_prefix(skip_prefix),
skip_linebreak(skip_linebreak) {
ostream = nullptr;
flush_level = logger::Level::ERR;
}
Expand All @@ -56,6 +58,7 @@ class Sink {
private:
std::string logger_name;
bool skip_prefix;
bool skip_linebreak;
std::mutex output_mutex;
const char *error_prefix = "Log message syntax error: ";

Expand Down Expand Up @@ -83,7 +86,9 @@ class Sink {
}
}
}
buffer << "\n";
if (!skip_linebreak) {
buffer << "\n";
}
}

template <typename Arg, typename... Args>
Expand Down Expand Up @@ -129,14 +134,15 @@ class Sink {

class StdoutSink : public Sink {
public:
StdoutSink(std::string logger_name, bool skip_prefix = false)
: Sink(std::move(logger_name), skip_prefix) {
StdoutSink(std::string logger_name, bool skip_prefix = false,
bool skip_linebreak = false)
: Sink(std::move(logger_name), skip_prefix, skip_linebreak) {
this->ostream = &std::cout;
}

StdoutSink(std::string logger_name, Level flush_lvl,
bool skip_prefix = false)
: StdoutSink(std::move(logger_name), skip_prefix) {
bool skip_prefix = false, bool skip_linebreak = false)
: StdoutSink(std::move(logger_name), skip_prefix, skip_linebreak) {
this->flush_level = flush_lvl;
}

Expand All @@ -145,13 +151,15 @@ class StdoutSink : public Sink {

class StderrSink : public Sink {
public:
StderrSink(std::string logger_name, bool skip_prefix = false)
: Sink(std::move(logger_name), skip_prefix) {
StderrSink(std::string logger_name, bool skip_prefix = false,
bool skip_linebreak = false)
: Sink(std::move(logger_name), skip_prefix, skip_linebreak) {
this->ostream = &std::cerr;
}

StderrSink(std::string logger_name, Level flush_lvl, bool skip_prefix)
: StderrSink(std::move(logger_name), skip_prefix) {
StderrSink(std::string logger_name, Level flush_lvl, bool skip_prefix,
bool skip_linebreak)
: StderrSink(std::move(logger_name), skip_prefix, skip_linebreak) {
this->flush_level = flush_lvl;
}

Expand All @@ -161,8 +169,8 @@ class StderrSink : public Sink {
class FileSink : public Sink {
public:
FileSink(std::string logger_name, filesystem::path file_path,
bool skip_prefix = false)
: Sink(std::move(logger_name), skip_prefix) {
bool skip_prefix = false, bool skip_linebreak = false)
: Sink(std::move(logger_name), skip_prefix, skip_linebreak) {
ofstream = std::ofstream(file_path);
if (!ofstream.good()) {
std::stringstream ss;
Expand All @@ -174,8 +182,10 @@ class FileSink : public Sink {
}

FileSink(std::string logger_name, filesystem::path file_path,
Level flush_lvl, bool skip_prefix = false)
: FileSink(std::move(logger_name), std::move(file_path), skip_prefix) {
Level flush_lvl, bool skip_prefix = false,
bool skip_linebreak = false)
: FileSink(std::move(logger_name), std::move(file_path), skip_prefix,
skip_linebreak) {
this->flush_level = flush_lvl;
}

Expand All @@ -188,14 +198,17 @@ class FileSink : public Sink {
inline std::unique_ptr<Sink> sink_from_str(std::string logger_name,
std::string name,
filesystem::path file_path = "",
bool skip_prefix = false) {
bool skip_prefix = false,
bool skip_linebreak = false) {
if (name == "stdout" && file_path.empty()) {
return std::make_unique<logger::StdoutSink>(logger_name, skip_prefix);
return std::make_unique<logger::StdoutSink>(logger_name, skip_prefix,
skip_linebreak);
} else if (name == "stderr" && file_path.empty()) {
return std::make_unique<logger::StderrSink>(logger_name, skip_prefix);
return std::make_unique<logger::StderrSink>(logger_name, skip_prefix,
skip_linebreak);
} else if (name == "file" && !file_path.empty()) {
return std::make_unique<logger::FileSink>(logger_name, file_path,
skip_prefix);
skip_prefix, skip_linebreak);
}

throw std::invalid_argument(
Expand Down
4 changes: 2 additions & 2 deletions source/loader/layers/tracing/ur_tracing_layer.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ constexpr auto STREAM_VER_MINOR = UR_MINOR_VERSION(UR_API_VERSION_CURRENT);
static thread_local xpti_td *activeEvent;

///////////////////////////////////////////////////////////////////////////////
context_t::context_t() {
context_t::context_t() : logger(logger::create_logger("tracing", true, true)) {
xptiFrameworkInitialize();

call_stream_id = xptiRegisterStream(CALL_STREAM_NAME);
Expand All @@ -37,7 +37,7 @@ context_t::context_t() {
streamv.str().data());
}

bool context_t::isAvailable() const { return xptiTraceEnabled(); }
bool context_t::isAvailable() const { return true; }

void context_t::notify(uint16_t trace_type, uint32_t id, const char *name,
void *args, ur_result_t *resultp, uint64_t instance) {
Expand Down
2 changes: 2 additions & 0 deletions source/loader/layers/tracing/ur_tracing_layer.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
#ifndef UR_TRACING_LAYER_H
#define UR_TRACING_LAYER_H 1

#include "logger/ur_logger.hpp"
#include "ur_ddi.h"
#include "ur_proxy_layer.hpp"
#include "ur_util.hpp"
Expand All @@ -25,6 +26,7 @@ class __urdlllocal context_t : public proxy_layer_context_t {
public:
ur_dditable_t urDdiTable = {};
codeloc_data codelocData;
logger::Logger logger;

context_t();
~context_t();
Expand Down
Loading

0 comments on commit 66706a2

Please sign in to comment.