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

[release/6.0-staging] Fix AV in host from tracing on exit #101260

Merged
merged 4 commits into from
Apr 29, 2024
Merged

[release/6.0-staging] Fix AV in host from tracing on exit #101260

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
a7af1a7
Fix AV in host from tracing on exit
elinor-fung Oct 25, 2022
0c22cda
Use spin lock
elinor-fung Oct 25, 2022
403b594
Yield when spinning
elinor-fung Oct 26, 2022
cb23085
Avoid locking during host trace flush when not necessary (#77765)
elinor-fung Nov 2, 2022
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
4 changes: 0 additions & 4 deletions src/native/corehost/hostmisc/pal.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()
{
Expand Down
130 changes: 87 additions & 43 deletions src/native/corehost/hostmisc/trace.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,11 @@

#include "trace.h"
#include <mutex>
#include <thread>

#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()
Expand All @@ -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.
//
Expand Down Expand Up @@ -50,9 +85,9 @@ bool trace::enable()
}
else
{
std::lock_guard<pal::mutex_t> lock(g_trace_mutex);
std::lock_guard<spin_lock> 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"));
Expand All @@ -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
{
Expand All @@ -93,34 +128,34 @@ bool trace::is_enabled()

void trace::verbose(const pal::char_t* format, ...)
{
if (g_trace_verbosity > 3)
{
std::lock_guard<pal::mutex_t> 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<spin_lock> 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<pal::mutex_t> 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<spin_lock> 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<pal::mutex_t> lock(g_trace_mutex);

// Always print errors
va_list args;
va_start(args, format);
Expand All @@ -134,33 +169,38 @@ void trace::error(const pal::char_t* format, ...)
std::vector<pal::char_t> 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<spin_lock> 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<pal::mutex_t> lock(g_trace_mutex);

va_list args;
va_start(args, format);
pal::out_vprintf(format, args);
{
std::lock_guard<spin_lock> lock(g_trace_lock);
pal::out_vprintf(format, args);
}
va_end(args);
}

Expand All @@ -171,24 +211,28 @@ void trace::println()

void trace::warning(const pal::char_t* format, ...)
{
if (g_trace_verbosity > 1)
{
std::lock_guard<pal::mutex_t> 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<spin_lock> lock(g_trace_lock);
pal::file_vprintf(g_trace_file, format, args);
va_end(args);
}
va_end(args);
}

void trace::flush()
{
std::lock_guard<pal::mutex_t> lock(g_trace_mutex);
if (g_trace_file != nullptr)
{
std::lock_guard<spin_lock> 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)
Expand Down
Loading