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.

Sign up for GitHub

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

[backport][rls-v3.8-pc] common: verbose: update logic for printing verbose headers #2906

Merged
merged 2 commits into from
Mar 18, 2025
Merged

[backport][rls-v3.8-pc] common: verbose: update logic for printing verbose headers #2906

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
6c21b6b
common: verbose: update logic for printing verbose headers
avmanerikar Feb 27, 2025
9b12a67
xe: ocl: update verbose checks for logging opencl warnings
avmanerikar Feb 27, 2025
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
96 changes: 50 additions & 46 deletions src/common/verbose.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -85,7 +85,15 @@ static constexpr char verbose_version[] = "v1";

static setting_t<uint32_t> verbose {0};

void print_header(const filter_status_t &filter_status) noexcept {
// Component filters help manage verbose output by parsing and printing for
// matching components. The filter status is tracked from verbose initializaton,
// allowing queries for the component type during verbose printing.
filter_status_t &filter_status() {
static filter_status_t filter_status;
return filter_status;
}

void print_header() noexcept {
static std::atomic_flag version_printed = ATOMIC_FLAG_INIT;
if (!version_printed.test_and_set()) {
verbose_printf("info,oneDNN v%d.%d.%d (commit %s)\n",
Expand Down Expand Up @@ -150,16 +158,16 @@ void print_header(const filter_status_t &filter_status) noexcept {
"mode,implementation,backend,exec_time\n",
get_verbose_timestamp() ? "timestamp," : "");
#endif
if (filter_status.status == filter_status_t::flags::valid)
if (filter_status().status == filter_status_t::flags::valid)
verbose_printf(
"common,info,filter format is enabled, hit components: "
"%s\n",
filter_status.components.c_str());
else if (filter_status.status == filter_status_t::flags::invalid)
filter_status().components.c_str());
else if (filter_status().status == filter_status_t::flags::invalid)
verbose_printf(
"common,error,filter format is ill-formed and is not "
"applied, error: %s\n",
filter_status.err_msg.c_str());
filter_status().err_msg.c_str());
}
}

Expand All @@ -171,8 +179,6 @@ uint32_t get_verbose(verbose_t::flag_kind verbosity_kind,
#endif
// we print all verbose by default
static int flags = component_t::all;
// record filter parsing result to instruct verbose printing
static filter_status_t filter_status;

if (!verbose.initialized()) {
// Assumes that all threads see the same environment
Expand Down Expand Up @@ -201,56 +207,55 @@ uint32_t get_verbose(verbose_t::flag_kind verbosity_kind,
std::strtol(s.c_str() + 10, nullptr, 10));
};

auto update_filter = [&](const std::string &s,
filter_status_t &filter_status) -> int {
auto update_filter = [&](const std::string &s) -> int {
int k = component_t::none;
try {
std::regex regexp = std::regex(s);

#define REGEX_SEARCH(k, component, regexp, filter_status) \
#define REGEX_SEARCH(k, component, regexp) \
if (std::regex_search("" #component "", regexp)) { \
(k) |= component_t::component; \
(filter_status).components += "" #component ","; \
filter_status().components += "" #component ","; \
}
REGEX_SEARCH(k, primitive, regexp, filter_status);
REGEX_SEARCH(k, reorder, regexp, filter_status);
REGEX_SEARCH(k, shuffle, regexp, filter_status);
REGEX_SEARCH(k, concat, regexp, filter_status);
REGEX_SEARCH(k, sum, regexp, filter_status);
REGEX_SEARCH(k, convolution, regexp, filter_status);
REGEX_SEARCH(k, deconvolution, regexp, filter_status);
REGEX_SEARCH(k, eltwise, regexp, filter_status);
REGEX_SEARCH(k, lrn, regexp, filter_status);
REGEX_SEARCH(k, batch_normalization, regexp, filter_status);
REGEX_SEARCH(k, inner_product, regexp, filter_status);
REGEX_SEARCH(k, rnn, regexp, filter_status);
REGEX_SEARCH(k, binary, regexp, filter_status);
REGEX_SEARCH(k, matmul, regexp, filter_status);
REGEX_SEARCH(k, resampling, regexp, filter_status);
REGEX_SEARCH(k, pooling, regexp, filter_status);
REGEX_SEARCH(k, reduction, regexp, filter_status);
REGEX_SEARCH(k, prelu, regexp, filter_status);
REGEX_SEARCH(k, softmax, regexp, filter_status);
REGEX_SEARCH(k, layer_normalization, regexp, filter_status);
REGEX_SEARCH(k, group_normalization, regexp, filter_status);
REGEX_SEARCH(k, graph, regexp, filter_status);
REGEX_SEARCH(k, gemm_api, regexp, filter_status);
REGEX_SEARCH(k, ukernel, regexp, filter_status);
REGEX_SEARCH(k, primitive, regexp);
REGEX_SEARCH(k, reorder, regexp);
REGEX_SEARCH(k, shuffle, regexp);
REGEX_SEARCH(k, concat, regexp);
REGEX_SEARCH(k, sum, regexp);
REGEX_SEARCH(k, convolution, regexp);
REGEX_SEARCH(k, deconvolution, regexp);
REGEX_SEARCH(k, eltwise, regexp);
REGEX_SEARCH(k, lrn, regexp);
REGEX_SEARCH(k, batch_normalization, regexp);
REGEX_SEARCH(k, inner_product, regexp);
REGEX_SEARCH(k, rnn, regexp);
REGEX_SEARCH(k, binary, regexp);
REGEX_SEARCH(k, matmul, regexp);
REGEX_SEARCH(k, resampling, regexp);
REGEX_SEARCH(k, pooling, regexp);
REGEX_SEARCH(k, reduction, regexp);
REGEX_SEARCH(k, prelu, regexp);
REGEX_SEARCH(k, softmax, regexp);
REGEX_SEARCH(k, layer_normalization, regexp);
REGEX_SEARCH(k, group_normalization, regexp);
REGEX_SEARCH(k, graph, regexp);
REGEX_SEARCH(k, gemm_api, regexp);
REGEX_SEARCH(k, ukernel, regexp);
#undef REGEX_SEARCH
} catch (const std::exception &e) {
filter_status.status = filter_status_t::flags::invalid;
filter_status.err_msg = e.what();
filter_status().status = filter_status_t::flags::invalid;
filter_status().err_msg = e.what();
return component_t::all;
}

// filter enabled and at least one component is hit
if (!filter_status.components.empty()) {
if (!filter_status().components.empty()) {
// pop out the last comma
filter_status.components.pop_back();
filter_status.status = filter_status_t::flags::valid;
filter_status().components.pop_back();
filter_status().status = filter_status_t::flags::valid;
} else {
filter_status.status = filter_status_t::flags::invalid;
filter_status.err_msg
filter_status().status = filter_status_t::flags::invalid;
filter_status().err_msg
= "component with name \'" + s + "\' not found";
}
return k;
Expand All @@ -267,9 +272,7 @@ uint32_t get_verbose(verbose_t::flag_kind verbosity_kind,
// update filter flags
if (tok.rfind("filter=", 0) == 0) {
auto filter_str = tok.substr(7);
if (!filter_str.empty()) {
flags = update_filter(filter_str, filter_status);
}
if (!filter_str.empty()) { flags = update_filter(filter_str); }
}
if (pos_en == std::string::npos) break;
}
Expand All @@ -287,7 +290,6 @@ uint32_t get_verbose(verbose_t::flag_kind verbosity_kind,
int result = verbose.get() & verbosity_kind;
if (verbosity_kind == verbose_t::debuginfo)
result = verbose_t::get_debuginfo(verbose.get());
if (result) print_header(filter_status);
bool filter_result = flags & filter_kind;
return filter_result ? result : 0;
}
Expand Down Expand Up @@ -1655,6 +1657,8 @@ void verbose_printf_impl(const char *raw_fmt_str, verbose_t::flag_kind kind) {
return;
#endif

if (get_verbose(kind)) print_header();

const auto &fmt_str = prepend_identifier_and_version(raw_fmt_str);

#ifdef DNNL_EXPERIMENTAL_LOGGING
Expand Down
8 changes: 4 additions & 4 deletions src/gpu/intel/ocl/engine.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -153,16 +153,16 @@ status_t create_ocl_kernel_from_cache_blob(const engine_t *ocl_engine,
cl_int maybe_print_debug_info(
cl_int err_, cl_program program, cl_device_id dev) {
// Return error code if verbose is not enabled.
if (!get_verbose(verbose_t::error) && !get_verbose(verbose_t::warn))
return err_;
bool is_err = get_verbose(verbose_t::error) && err_ != CL_SUCCESS;
bool is_warn = get_verbose(verbose_t::warn);

if (!is_err && !is_warn) return err_;

size_t log_length = 0;
auto err = clGetProgramBuildInfo(
program, dev, CL_PROGRAM_BUILD_LOG, 0, nullptr, &log_length);
gpu_assert(err == CL_SUCCESS);

bool is_err = get_verbose(verbose_t::error) && err_ != status::success;
bool is_warn = get_verbose(verbose_t::warn);
if (log_length > 1 && (is_err || is_warn)) {
std::vector<char> log_buf(log_length);
err = clGetProgramBuildInfo(program, dev, CL_PROGRAM_BUILD_LOG,
Expand Down