fabi/Xenia-Canary
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
Files
382dd8860f713088a18b478ca1c2def72c6f9b44
Xenia-Canary/src/xenia/base/logging.cc
Sandy Carter 382dd8860f [threading] Change thread names to suit pthread 
Shorten names to 16.
Rename Win32 to Windowing.
Shorten GraphicsSystem thread names due to 16 length limit of pthread.
Without this change, both show up as GraphicsSystem.
Remove redundant "Worker" and "Thread" from names.
Remove redundant thread handle from thread name.
2020-11-15 11:12:05 -06:00

345 lines
10 KiB
C++
Raw Blame History

/**
******************************************************************************
* Xenia : Xbox 360 Emulator Research Project *
******************************************************************************
* Copyright 2020 Ben Vanik. All rights reserved. *
* Released under the BSD license - see LICENSE in the root for more details. *
******************************************************************************
*/
#include "xenia/base/logging.h"
#include <atomic>
#include <mutex>
#include <vector>
#include "third_party/disruptorplus/include/disruptorplus/multi_threaded_claim_strategy.hpp"
#include "third_party/disruptorplus/include/disruptorplus/ring_buffer.hpp"
#include "third_party/disruptorplus/include/disruptorplus/sequence_barrier.hpp"
#include "third_party/disruptorplus/include/disruptorplus/spin_wait_strategy.hpp"
#include "xenia/base/atomic.h"
#include "xenia/base/cvar.h"
#include "xenia/base/debugging.h"
#include "xenia/base/filesystem.h"
#include "xenia/base/main.h"
#include "xenia/base/math.h"
#include "xenia/base/memory.h"
#include "xenia/base/ring_buffer.h"
#include "xenia/base/string.h"
#include "xenia/base/threading.h"
// For MessageBox:
// TODO(benvanik): generic API? logging_win.cc?
#if XE_PLATFORM_WIN32
#include "xenia/base/platform_win.h"
#endif // XE_PLATFORM_WIN32
#include "third_party/fmt/include/fmt/format.h"
DEFINE_path(
log_file, "",
"Logs are written to the given file (specify stdout for command line)",
"Logging");
DEFINE_bool(log_to_debugprint, false, "Dump the log to DebugPrint.", "Logging");
DEFINE_bool(flush_log, true, "Flush log file after each log line batch.",
"Logging");
DEFINE_int32(
log_level, 2,
"Maximum level to be logged. (0=error, 1=warning, 2=info, 3=debug)",
"Logging");
namespace dp = disruptorplus;
namespace xe {
class Logger;
Logger* logger_ = nullptr;
struct LogLine {
size_t buffer_length;
uint32_t thread_id;
uint16_t _pad_0; // (2b) padding
uint8_t _pad_1; // (1b) padding
char prefix_char;
};
thread_local char thread_log_buffer_[64 * 1024];
class Logger {
public:
explicit Logger(const std::string_view app_name)
: file_(nullptr),
running_(true),
wait_strategy_(),
claim_strategy_(kBlockCount, wait_strategy_),
consumed_(wait_strategy_) {
claim_strategy_.add_claim_barrier(consumed_);
if (cvars::log_file.empty()) {
// Default to app name.
auto file_name = fmt::format("{}.log", app_name);
auto file_path = std::filesystem::path(file_name);
xe::filesystem::CreateParentFolder(file_path);
file_ = xe::filesystem::OpenFile(file_path, "wt");
} else {
if (cvars::log_file == "stdout") {
file_ = stdout;
} else {
xe::filesystem::CreateParentFolder(cvars::log_file);
file_ = xe::filesystem::OpenFile(cvars::log_file, "wt");
}
}
write_thread_ =
xe::threading::Thread::Create({}, [this]() { WriteThread(); });
write_thread_->set_name("Logging Writer");
}
~Logger() {
running_ = false;
xe::threading::Wait(write_thread_.get(), true);
fflush(file_);
fclose(file_);
}
private:
static const size_t kBufferSize = 8 * 1024 * 1024;
uint8_t buffer_[kBufferSize];
static const size_t kBlockSize = 256;
static const size_t kBlockCount = kBufferSize / kBlockSize;
static const size_t kBlockIndexMask = kBlockCount - 1;
static const size_t kClaimStrategyFootprint =
sizeof(std::atomic<dp::sequence_t>[kBlockCount]);
static size_t BlockOffset(dp::sequence_t sequence) {
return (sequence & kBlockIndexMask) * kBlockSize;
}
static size_t BlockCount(size_t byte_size) {
return (byte_size + (kBlockSize - 1)) / kBlockSize;
}
dp::spin_wait_strategy wait_strategy_;
dp::multi_threaded_claim_strategy<dp::spin_wait_strategy> claim_strategy_;
dp::sequence_barrier<dp::spin_wait_strategy> consumed_;
FILE* file_;
std::atomic<bool> running_;
std::unique_ptr<xe::threading::Thread> write_thread_;
void Write(const char* buf, size_t size) {
if (file_) {
fwrite(buf, 1, size, file_);
}
if (cvars::log_to_debugprint) {
debugging::DebugPrint("{}", std::string_view(buf, size));
}
}
void WriteThread() {
RingBuffer rb(buffer_, kBufferSize);
size_t idle_loops = 0;
dp::sequence_t next_sequence = 0;
dp::sequence_t last_sequence = -1;
size_t desired_count = 1;
while (true) {
// We want one block to find out how many blocks we need or we know how
// many blocks needed for at least one log line.
auto next_range = dp::sequence_range(next_sequence, desired_count);
auto available_sequence = claim_strategy_.wait_until_published(
next_range.last(), last_sequence);
auto available_difference =
dp::difference(available_sequence, next_sequence);
size_t read_count = 0;
if (available_difference > 0 &&
static_cast<size_t>(available_difference) >= desired_count) {
auto available_range = dp::sequence_range(
next_sequence, static_cast<size_t>(available_difference));
auto available_count = available_range.size();
rb.set_write_offset(BlockOffset(available_range.end()));
for (size_t i = available_range.first(); i != available_range.end();) {
rb.set_read_offset(BlockOffset(i));
LogLine line;
rb.Read(&line, sizeof(line));
auto needed_count = BlockCount(sizeof(LogLine) + line.buffer_length);
if (read_count + needed_count > available_count) {
// More blocks are needed for a complete line.
desired_count = needed_count;
break;
} else {
// Enough blocks to read this log line, advance by that many.
read_count += needed_count;
i += needed_count;
char prefix[] = {
line.prefix_char,
'>',
' ',
'?', // Thread ID gets placed here (8 chars).
'?',
'?',
'?',
'?',
'?',
'?',
'?',
' ',
0,
};
fmt::format_to_n(prefix + 3, sizeof(prefix) - 3, "{:08X}",
line.thread_id);
Write(prefix, sizeof(prefix) - 1);
if (line.buffer_length) {
// Get access to the line data - which may be split in the ring
// buffer - and write it out in parts.
auto line_range = rb.BeginRead(line.buffer_length);
Write(reinterpret_cast<const char*>(line_range.first),
line_range.first_length);
if (line_range.second_length) {
Write(reinterpret_cast<const char*>(line_range.second),
line_range.second_length);
}
// Always ensure there is a newline.
char last_char =
line_range.second
? line_range.second[line_range.second_length - 1]
: line_range.first[line_range.first_length - 1];
if (last_char != '\n') {
const char suffix[1] = {'\n'};
Write(suffix, 1);
}
rb.EndRead(std::move(line_range));
} else {
// Always ensure there is a newline.
const char suffix[1] = {'\n'};
Write(suffix, 1);
}
}
}
}
if (read_count) {
// Advance by the number of blocks we read.
auto read_range = dp::sequence_range(next_sequence, read_count);
next_sequence = read_range.end();
last_sequence = read_range.last();
consumed_.publish(read_range.last());
desired_count = 1;
if (cvars::flush_log) {
fflush(file_);
}
idle_loops = 0;
} else {
if (!running_) {
break;
}
if (idle_loops >= 1000) {
// Introduce a waiting period.
xe::threading::Sleep(std::chrono::milliseconds(50));
} else {
idle_loops++;
}
}
}
}
public:
void AppendLine(uint32_t thread_id, const char prefix_char,
const char* buffer_data, size_t buffer_length) {
size_t count = BlockCount(sizeof(LogLine) + buffer_length);
auto range = claim_strategy_.claim(count);
assert_true(range.size() == count);
RingBuffer rb(buffer_, kBufferSize);
rb.set_write_offset(BlockOffset(range.first()));
rb.set_read_offset(BlockOffset(range.end()));
LogLine line = {};
line.buffer_length = buffer_length;
line.thread_id = thread_id;
line.prefix_char = prefix_char;
rb.Write(&line, sizeof(LogLine));
rb.Write(buffer_data, buffer_length);
claim_strategy_.publish(range);
}
};
void InitializeLogging(const std::string_view app_name) {
auto mem = memory::AlignedAlloc<Logger>(0x10);
logger_ = new (mem) Logger(app_name);
}
void ShutdownLogging() {
Logger* logger = logger_;
logger_ = nullptr;
logger->~Logger();
memory::AlignedFree(logger);
}
bool logging::internal::ShouldLog(LogLevel log_level) {
return logger_ != nullptr &&
static_cast<int32_t>(log_level) <= cvars::log_level;
}
std::pair<char*, size_t> logging::internal::GetThreadBuffer() {
return {thread_log_buffer_, sizeof(thread_log_buffer_)};
}
void logging::internal::AppendLogLine(LogLevel log_level,
const char prefix_char, size_t written) {
if (!ShouldLog(log_level) || !written) {
return;
}
logger_->AppendLine(xe::threading::current_thread_id(), prefix_char,
thread_log_buffer_, written);
}
void logging::AppendLogLine(LogLevel log_level, const char prefix_char,
const std::string_view str) {
if (!internal::ShouldLog(log_level) || !str.size()) {
return;
}
logger_->AppendLine(xe::threading::current_thread_id(), prefix_char,
str.data(), str.size());
}
void FatalError(const std::string_view str) {
logging::AppendLogLine(LogLevel::Error, 'X', str);
#if XE_PLATFORM_WIN32
if (!xe::has_console_attached()) {
MessageBoxW(NULL, (LPCWSTR)xe::to_utf16(str).c_str(), L"Xenia Error",
MB_OK | MB_ICONERROR | MB_APPLMODAL | MB_SETFOREGROUND);
}
#endif // WIN32
ShutdownLogging();
std::exit(1);
}
} // namespace xe
Reference in New Issue View Git Blame Copy Permalink