diff --git a/src/native/corehost/hostmisc/pal.h b/src/native/corehost/hostmisc/pal.h index 69cf8353800830..77f7c375ff34d3 100644 --- a/src/native/corehost/hostmisc/pal.h +++ b/src/native/corehost/hostmisc/pal.h @@ -252,10 +252,6 @@ namespace pal bool getcwd(string_t* recv); - inline void file_flush(FILE* f) { std::fflush(f); } - inline void err_flush() { std::fflush(stderr); } - inline void out_flush() { std::fflush(stdout); } - string_t get_current_os_rid_platform(); inline string_t get_current_os_fallback_rid() { diff --git a/src/native/corehost/hostmisc/trace.cpp b/src/native/corehost/hostmisc/trace.cpp index 4c9161e7453e2b..3e4175ca8c939e 100644 --- a/src/native/corehost/hostmisc/trace.cpp +++ b/src/native/corehost/hostmisc/trace.cpp @@ -3,6 +3,11 @@ #include "trace.h" #include +#include + +#define TRACE_VERBOSITY_WARN 2 +#define TRACE_VERBOSITY_INFO 3 +#define TRACE_VERBOSITY_VERBOSE 4 // g_trace_verbosity is used to encode COREHOST_TRACE and COREHOST_TRACE_VERBOSITY to selectively control output of // trace::warn(), trace::info(), and trace::verbose() @@ -12,10 +17,40 @@ // COREHOST_TRACE=1 COREHOST_TRACE_VERBOSITY=2 implies g_trace_verbosity = 2. // Trace "enabled". warn() and error() messages will be produced // COREHOST_TRACE=1 COREHOST_TRACE_VERBOSITY=1 implies g_trace_verbosity = 1. // Trace "enabled". error() messages will be produced static int g_trace_verbosity = 0; -static FILE * g_trace_file = stderr; -static pal::mutex_t g_trace_mutex; +static FILE * g_trace_file = nullptr; thread_local static trace::error_writer_fn g_error_writer = nullptr; +namespace +{ + class spin_lock + { + public: + spin_lock() = default; + spin_lock(const spin_lock&) = delete; + spin_lock& operator=(const spin_lock&) = delete; + + void lock() + { + uint32_t spin = 0; + while (flag.test_and_set(std::memory_order_acquire)) + { + if (spin++ % 1024 == 0) + std::this_thread::yield(); + } + } + + void unlock() + { + flag.clear(std::memory_order_release); + } + + private: + std::atomic_flag flag = ATOMIC_FLAG_INIT; + }; + + spin_lock g_trace_lock; +} + // // Turn on tracing for the corehost based on "COREHOST_TRACE" & "COREHOST_TRACEFILE" env. // @@ -50,9 +85,9 @@ bool trace::enable() } else { - std::lock_guard lock(g_trace_mutex); + std::lock_guard lock(g_trace_lock); - g_trace_file = stderr; + g_trace_file = stderr; // Trace to stderr by default if (pal::getenv(_X("COREHOST_TRACEFILE"), &tracefile_str)) { FILE *tracefile = pal::file_open(tracefile_str, _X("a")); @@ -71,7 +106,7 @@ bool trace::enable() pal::string_t trace_str; if (!pal::getenv(_X("COREHOST_TRACE_VERBOSITY"), &trace_str)) { - g_trace_verbosity = 4; // Verbose trace by default + g_trace_verbosity = TRACE_VERBOSITY_VERBOSE; // Verbose trace by default } else { @@ -93,34 +128,34 @@ bool trace::is_enabled() void trace::verbose(const pal::char_t* format, ...) { - if (g_trace_verbosity > 3) - { - std::lock_guard lock(g_trace_mutex); + if (g_trace_verbosity < TRACE_VERBOSITY_VERBOSE) + return; - va_list args; - va_start(args, format); + va_list args; + va_start(args, format); + { + std::lock_guard lock(g_trace_lock); pal::file_vprintf(g_trace_file, format, args); - va_end(args); } + va_end(args); } void trace::info(const pal::char_t* format, ...) { - if (g_trace_verbosity > 2) - { - std::lock_guard lock(g_trace_mutex); + if (g_trace_verbosity < TRACE_VERBOSITY_INFO) + return; - va_list args; - va_start(args, format); + va_list args; + va_start(args, format); + { + std::lock_guard lock(g_trace_lock); pal::file_vprintf(g_trace_file, format, args); - va_end(args); } + va_end(args); } void trace::error(const pal::char_t* format, ...) { - std::lock_guard lock(g_trace_mutex); - // Always print errors va_list args; va_start(args, format); @@ -134,33 +169,38 @@ void trace::error(const pal::char_t* format, ...) std::vector buffer(count); pal::str_vprintf(&buffer[0], count, format, dup_args); - if (g_error_writer == nullptr) - { - pal::err_fputs(buffer.data()); - } - else - { - g_error_writer(buffer.data()); - } - #if defined(_WIN32) ::OutputDebugStringW(buffer.data()); #endif - if (g_trace_verbosity && ((g_trace_file != stderr) || g_error_writer != nullptr)) { - pal::file_vprintf(g_trace_file, format, trace_args); + std::lock_guard lock(g_trace_lock); + + if (g_error_writer == nullptr) + { + pal::err_fputs(buffer.data()); + } + else + { + g_error_writer(buffer.data()); + } + + if (g_trace_verbosity && ((g_trace_file != stderr) || g_error_writer != nullptr)) + { + pal::file_vprintf(g_trace_file, format, trace_args); + } } va_end(args); } void trace::println(const pal::char_t* format, ...) { - std::lock_guard lock(g_trace_mutex); - va_list args; va_start(args, format); - pal::out_vprintf(format, args); + { + std::lock_guard lock(g_trace_lock); + pal::out_vprintf(format, args); + } va_end(args); } @@ -171,24 +211,28 @@ void trace::println() void trace::warning(const pal::char_t* format, ...) { - if (g_trace_verbosity > 1) - { - std::lock_guard lock(g_trace_mutex); + if (g_trace_verbosity < TRACE_VERBOSITY_WARN) + return; - va_list args; - va_start(args, format); + va_list args; + va_start(args, format); + { + std::lock_guard lock(g_trace_lock); pal::file_vprintf(g_trace_file, format, args); - va_end(args); } + va_end(args); } void trace::flush() { - std::lock_guard lock(g_trace_mutex); + if (g_trace_file != nullptr) + { + std::lock_guard lock(g_trace_lock); + std::fflush(g_trace_file); + } - pal::file_flush(g_trace_file); - pal::err_flush(); - pal::out_flush(); + std::fflush(stderr); + std::fflush(stdout); } trace::error_writer_fn trace::set_error_writer(trace::error_writer_fn error_writer)